Percona XtraDB Cluster - HA scalable solution for MySQL

trx tries to abort slave trx

Reported by Teemu Ollakka on 2013-03-21
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
MySQL patches by Codership
Status tracked in 5.6
5.5
High
Seppo Jaakola
5.6
High
Seppo Jaakola
Percona XtraDB Cluster
Status tracked in Trunk
5.6
Undecided
Unassigned
Trunk
Undecided
Unassigned

Bug Description

Branch https://code.launchpad.net/~codership/codership-mysql/5.5-23, revision 3858

Cluster setup: Three nodes in using shm for data directories. Each node was configured with wsrep_slave_threads=4.

Sqlgen load: LD_PRELOAD=/home/teemu/lib/libglb.so GLB_BIND="gw:3307" GLB_TARGETS="gw:3311 gw:3312 gw:3313" ./bin/sqlgen --user test --pswd testpass --host gw --port 3307 --users 64 --duration 600 --tables 1 --rows 100 --stat-interval 99999999 >& /dev/null

Occasionally one of the nodes crashes with error:

130321 12:09:07 [ERROR] WSREP: Trx 17411 tries to abort slave trx 17419. This could be caused by:
        1) unsupported configuration options combination, please check documentation.
        2) a bug in the code.
        3) a database corruption.
 Node consistency compromized, need to abort. Restart the node to resync with cluster.

Aborting thread (seqno 17411):

Thread 1 (Thread 0x7f2c47964700 (LWP 31640)):
#0 __pthread_kill (threadid=<optimized out>, signo=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:63
#1 0x00000000006a2359 in handle_fatal_signal (sig=6)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/signal_handler.cc:247
#2 <signal handler called>
#3 0x00007f2c6438f425 in __GI_raise (sig=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#4 0x00007f2c64392b8b in __GI_abort () at abort.c:91
#5 0x00000000007ee1e8 in wsrep_abort_slave_trx (bf_seqno=<optimized out>, victim_seqno=<optimized out>)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/handler/ha_innodb.cc:12248
#6 0x00000000007eeed4 in wsrep_innobase_kill_one_trx (bf_thd_ptr=<optimized out>, bf_trx=<optimized out>,
    victim_trx=0x7f2c2800e7e8, signal=1)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/handler/ha_innodb.cc:12402
#7 0x00000000008c41d3 in lock_rec_other_has_conflicting (mode=<optimized out>, block=<optimized out>,
    heap_no=<optimized out>, trx=<optimized out>)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/lock/lock0lock.c:1611
#8 0x00000000008c8ced in lock_rec_convert_impl_to_expl (block=<optimized out>,
    rec=0x7f2c626f6a42 "\032\020Yf\006D\346?\200", index=0x7f2c2000c2e8, offsets=0x7f2c4795eb00)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/lock/lock0lock.c:5669
#9 0x00000000008c9cc5 in lock_sec_rec_read_check_and_lock (flags=<optimized out>, block=0x7f2c61e1ae00,
    rec=0x7f2c626f6a42 "\032\020Yf\006D\346?\200", index=0x7f2c2000c2e8, offsets=<optimized out>, mode=LOCK_X, gap_mode=0,
    thr=0x7f2c24035d00) at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/lock/lock0lock.c:5877
#10 0x00000000005049f1 in row_ins_set_exclusive_rec_lock (type=<optimized out>, block=<optimized out>, rec=<optimized out>,
    index=<optimized out>, offsets=<optimized out>, thr=<optimized out>)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/row/row0ins.c:1203
#11 0x0000000000505119 in row_ins_scan_sec_index_for_duplicate (index=0x7f2c2000c2e8, entry=0x7f2bc01a3f58,
    thr=0x7f2c24035d00) at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/row/row0ins.c:1752
#12 0x00000000008f8139 in row_ins_index_entry_low (mode=2, index=0x7f2c2000c2e8, entry=0x7f2bc01a3f58, thr=0x7f2c24035d00,
    n_ext=0) at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/row/row0ins.c:2102
#13 0x00000000008fbcce in row_ins_index_entry (thr=0x7f2c24035d00, entry=<optimized out>, index=0x7f2c2000c2e8,
    n_ext=<optimized out>, foreign=<optimized out>)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/row/row0ins.c:2301
#14 row_ins_index_entry_step (thr=0x7f2c24035d00, node=<optimized out>)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/row/row0ins.c:2389
#15 row_ins (thr=<optimized out>, node=<optimized out>)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/row/row0ins.c:2521
#16 row_ins_step (thr=0x7f2c24035d00)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/row/row0ins.c:2638
#17 0x00000000008007de in row_insert_for_mysql (mysql_rec=<optimized out>, prebuilt=0x7f2c24034ea8)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/row/row0mysql.c:1245
#18 0x00000000007e905a in ha_innobase::write_row (this=0x7f2c240558d0, record=0x7f2c240426c0 "\341\027")
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/handler/ha_innodb.cc:5619
#19 0x00000000006a9d58 in handler::ha_write_row (this=0x7f2c240558d0, buf=0x7f2c240426c0 "\341\027")
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/handler.cc:5257
#20 0x000000000074ddf9 in Rows_log_event::write_row (this=0x7f2bc01f7a20, rli=0x7f2bc01f3900, overwrite=false)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/log_event.cc:9242
#21 0x000000000074e188 in Write_rows_log_event::do_exec_row (this=0x7f2bc01f7a20, rli=0x7f2bc01f3900)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/log_event.cc:9413
#22 0x0000000000744914 in Rows_log_event::do_apply_event (this=0x7f2bc01f7a20, rli=0x7f2bc01f3900)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/log_event.cc:8054
#23 0x000000000058b3be in apply_event (rli=<optimized out>, this=0x7f2bc01f7a20)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/log_event.h:1139
#24 wsrep_apply_rbr (thd=0x4f71fc0, rbr_buf=<optimized out>, buf_len=0)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_parse.cc:7900
#25 0x0000000000591dc7 in wsrep_apply_cb (ctx=0x4f71fc0, buf=0x7f2bc02c904b, buf_len=167, global_seqno=<optimized out>)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_parse.cc:7979
#26 0x00007f2c5657d46f in apply_wscoll (trx=..., apply_cb=0x591d40 <wsrep_apply_cb(void*, void const*, unsigned long, long)>,
    recv_ctx=0x4f71fc0) at galera/src/replicator_smm.cpp:41
#27 apply_trx_ws (recv_ctx=0x4f71fc0, apply_cb=0x591d40 <wsrep_apply_cb(void*, void const*, unsigned long, long)>,
    commit_cb=0x59d1f0 <wsrep_commit_cb(void*, long, bool)>, trx=...) at galera/src/replicator_smm.cpp:83
#28 0x00007f2c5658203f in galera::ReplicatorSMM::replay_trx (this=0x35caad0, trx=0x7f2bc02ee5d0, trx_ctx=0x4f71fc0)
    at galera/src/replicator_smm.cpp:821
#29 0x00007f2c56599bd6 in galera_replay_trx (gh=<optimized out>, trx_handle=<optimized out>, recv_ctx=0x4f71fc0)
    at galera/src/wsrep_provider.cpp:661
#30 0x000000000058df1c in wsrep_replay_transaction (thd=0x4f71fc0)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_parse.cc:5975
#31 0x000000000059a898 in wsrep_mysql_parse (thd=0x4f71fc0, rawbuf=0x7f2bc0186550 "COMMIT", length=6,
    parser_state=0x7f2c47963210) at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_parse.cc:6050
#32 0x000000000059bff7 in dispatch_command (command=COM_QUERY, thd=0x4f71fc0, packet=<optimized out>,
    packet_length=1201025784) at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_parse.cc:1212
#33 0x000000000059c60d in do_command (thd=0x4f71fc0)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_parse.cc:869
#34 0x000000000063eb95 in do_handle_one_connection (thd_arg=<optimized out>)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_connect.cc:878
#35 0x000000000063edac in handle_one_connection (arg=0x4f71fc0)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_connect.cc:790
#36 0x00007f2c6471fe9a in start_thread (arg=0x7f2c47964700) at pthread_create.c:308
#37 0x00007f2c6444ccbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#38 0x0000000000000000 in ?? ()

Victim thread (seqno 17419):

#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1 0x00000000008e2741 in os_cond_wait (mutex=0x306a7e0, cond=0x306a818)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/os/os0sync.c:207
#2 os_event_wait_low (event=0x306a7e0, reset_sig_count=<optimized out>)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/os/os0sync.c:609
#3 0x00000000008215b7 in sync_array_wait_event (arr=0x3022530, index=1)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/sync/sync0arr.c:458
#4 0x0000000000823006 in mutex_spin_wait (mutex=0x306a788,
    file_name=0xacde88 "/home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/srv/srv0srv.c", line=1793)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/sync/sync0sync.c:643
#5 0x000000000081a7aa in mutex_enter_func (line=1793,
    file_name=0xacde88 "/home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/srv/srv0srv.c",
    mutex=0x306a788) at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/include/sync0sync.ic:222
#6 pfs_mutex_enter_func (line=1793,
    file_name=0xacde88 "/home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/srv/srv0srv.c",
    mutex=0x306a788) at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/include/sync0sync.ic:251
#7 srv_suspend_mysql_thread (thr=0x7f2c1400a100)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/srv/srv0srv.c:1793
#8 0x00000000007ff8a8 in row_mysql_handle_errors (new_err=0x7f2c604b0020, trx=0x7f2c2800e7e8, thr=<optimized out>,
    savept=<optimized out>) at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/row/row0mysql.c:598
#9 0x000000000080081a in row_insert_for_mysql (mysql_rec=<optimized out>, prebuilt=0x7f2c140092a8)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/row/row0mysql.c:1254
#10 0x00000000007e905a in ha_innobase::write_row (this=0x7f2c14016e90, record=0x7f2c1400b9f0 "\341\033")
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/storage/innobase/handler/ha_innodb.cc:5619
#11 0x00000000006a9d58 in handler::ha_write_row (this=0x7f2c14016e90, buf=0x7f2c1400b9f0 "\341\033")
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/handler.cc:5257
#12 0x000000000074ddf9 in Rows_log_event::write_row (this=0x7f2c280606b0, rli=0x7f2c2800b060, overwrite=false)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/log_event.cc:9242
#13 0x000000000074e188 in Write_rows_log_event::do_exec_row (this=0x7f2c280606b0, rli=0x7f2c2800b060)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/log_event.cc:9413
#14 0x0000000000744914 in Rows_log_event::do_apply_event (this=0x7f2c280606b0, rli=0x7f2c2800b060)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/log_event.cc:8054
#15 0x000000000058b3be in apply_event (rli=<optimized out>, this=0x7f2c280606b0)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/log_event.h:1139
#16 wsrep_apply_rbr (thd=0x7f2c28000990, rbr_buf=<optimized out>, buf_len=0)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_parse.cc:7900
#17 0x0000000000591dc7 in wsrep_apply_cb (ctx=0x7f2c28000990, buf=0x7f2c4890c635, buf_len=167, global_seqno=<optimized out>)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_parse.cc:7979
#18 0x00007f2c5657d46f in apply_wscoll (trx=..., apply_cb=0x591d40 <wsrep_apply_cb(void*, void const*, unsigned long, long)>,
    recv_ctx=0x7f2c28000990) at galera/src/replicator_smm.cpp:41
#19 apply_trx_ws (recv_ctx=0x7f2c28000990, apply_cb=0x591d40 <wsrep_apply_cb(void*, void const*, unsigned long, long)>,
    commit_cb=0x59d1f0 <wsrep_commit_cb(void*, long, bool)>, trx=...) at galera/src/replicator_smm.cpp:83
#20 0x00007f2c56583060 in galera::ReplicatorSMM::apply_trx (this=<optimized out>, recv_ctx=0x7f2c28000990, trx=0x7f2c28061110)
    at galera/src/replicator_smm.cpp:470
#21 0x00007f2c56583830 in galera::ReplicatorSMM::process_trx (this=0x35caad0, recv_ctx=0x7f2c28000990, trx=0x7f2c28061110)
    at galera/src/replicator_smm.cpp:1058
#22 0x00007f2c565607c4 in galera::GcsActionSource::dispatch (this=0x35cb058, recv_ctx=0x7f2c28000990, act=...)
    at galera/src/gcs_action_source.cpp:111
#23 0x00007f2c56561393 in galera::GcsActionSource::process (this=0x35cb058, recv_ctx=0x7f2c28000990)
    at galera/src/gcs_action_source.cpp:169
#24 0x00007f2c5658536d in async_recv (recv_ctx=0x7f2c28000990, this=0x35caad0) at galera/src/replicator_smm.cpp:375
#25 galera::ReplicatorSMM::async_recv (this=0x35caad0, recv_ctx=0x7f2c28000990) at galera/src/replicator_smm.cpp:356
#26 0x00007f2c56598d0e in galera_recv (gh=<optimized out>, recv_ctx=<optimized out>) at galera/src/wsrep_provider.cpp:201
#27 0x00000000005920aa in wsrep_replication_process (thd=0x7f2c28000990)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/sql_parse.cc:8132
#28 0x00000000005184de in start_wsrep_THD (arg=0x592060)
    at /home/teemu/codership/galera/bzr/codership-mysql/5.5-23/sql/mysqld.cc:4416
#29 0x00007f2c6471fe9a in start_thread (arg=0x7f2c604b4700) at pthread_create.c:308
#30 0x00007f2c6444ccbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#31 0x0000000000000000 in ?? ()

Teemu Ollakka (teemu-ollakka) wrote :

This is quite likely a regression introduced in https://code.launchpad.net/~codership/codership-mysql/5.5-23 rev 3858, could not reproduce the issue with rev 3857 even after several attempts.

description: updated
Changed in percona-xtradb-cluster:
milestone: none → 5.5.30-23.7.4
Seppo Jaakola (seppo-jaakola) wrote :
Download full text (6.0 KiB)

testing with debug build, 20 users, I get another assert crash:

#0 __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:63
#1 0x00000000008fb46d in my_write_core (sig=6) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/mysys/stacktrace.c:433
#2 0x0000000000781a1a in handle_fatal_signal (sig=6) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/sql/signal_handler.cc:247
#3 <signal handler called>
#4 0x00007f10c64723e5 in __GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#5 0x00007f10c6475b4b in __GI_abort () at abort.c:92
#6 0x0000000000a23dcc in lock_rec_queue_validate (block=0x7f10a389c058, rec=0x7f10a536c396 "\217\264^\241#\255\327?\200", index=0x7f1084034768, offsets=0x7f1091490390) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/lock/lock0lock.c:5238
#7 0x0000000000a253e7 in lock_sec_rec_read_check_and_lock (flags=0, block=0x7f10a389c058, rec=0x7f10a536c396 "\217\264^\241#\255\327?\200", index=0x7f1084034768, offsets=0x7f1091490390, mode=LOCK_X, gap_mode=0, thr=0x52e2150) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/lock/lock0lock.c:5885
#8 0x0000000000a5d3a8 in row_ins_set_exclusive_rec_lock (type=0, block=0x7f10a389c058, rec=0x7f10a536c396 "\217\264^\241#\255\327?\200", index=0x7f1084034768, offsets=0x7f1091490390, thr=0x52e2150) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/row/row0ins.c:1203
#9 0x0000000000a5e3bf in row_ins_scan_sec_index_for_duplicate (index=0x7f1084034768, entry=0x532b0b0, thr=0x52e2150) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/row/row0ins.c:1752
#10 0x0000000000a5ed9f in row_ins_index_entry_low (mode=2, index=0x7f1084034768, entry=0x532b0b0, n_ext=0, thr=0x52e2150) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/row/row0ins.c:2102
#11 0x0000000000a5f52c in row_ins_index_entry (index=0x7f1084034768, entry=0x532b0b0, n_ext=0, foreign=1, thr=0x52e2150) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/row/row0ins.c:2301
#12 0x0000000000a5f8b3 in row_ins_index_entry_step (node=0x52e1ea0, thr=0x52e2150) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/row/row0ins.c:2389
#13 0x0000000000a5fb72 in row_ins (node=0x52e1ea0, thr=0x52e2150) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/row/row0ins.c:2521
#14 0x0000000000a5fe77 in row_ins_step (thr=0x52e2150) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/row/row0ins.c:2638
#15 0x0000000000961659 in row_insert_for_mysql (mysql_rec=0x5439d40 "\341\035", prebuilt=0x52e16e8) at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/row/row0mysql.c:1245
#16 0x000000000093a965 in ha_innobase::write_row (this=0x53deff0, record=0x5439d40 "\341\035") at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/storage/innobase/handler/ha_innodb.cc:5619
#17 0x000000000078bbee in handler::ha_write_row (this=0x53deff0, buf=0x5439d40 "\341\035") at /home/seppo/work/wsrep/wsrep-5.5-23-new/wsrep-5.5-23/sql/handler.cc:5257
#18 0x000000000085107f in Rows_log_event::...

Read more...

Changed in codership-mysql:
status: New → Confirmed
importance: Undecided → High
assignee: nobody → Seppo Jaakola (seppo-jaakola)
milestone: none → 5.5.30-23.7.4
Changed in codership-mysql:
status: Confirmed → In Progress
Seppo Jaakola (seppo-jaakola) wrote :

BF transactions cannot be subject to lock conversion. This has been fixed in revision: http://bazaar.launchpad.net/~codership/codership-mysql/5.5-23/revision/3859

Seppo Jaakola (seppo-jaakola) wrote :

This problem was triggered by an upstream fix for: http://bugs.mysql.com/bug.php?id=59354. This bug report has a reproducible test case attached.

Changed in codership-mysql:
status: In Progress → Fix Committed
Changed in percona-xtradb-cluster:
status: New → Fix Released
Changed in codership-mysql:
status: Fix Committed → Fix Released
Seppo Jaakola (seppo-jaakola) wrote :

Fix merged into wsrep-5.6 from wsrep-5.5-23 in revision: http://bazaar.launchpad.net/~codership/codership-mysql/5.6/revision/3977

Alex Recarey (ar-u) wrote :

Hi, I am running latest version PXC (Server version: 5.6.15-62.0-log) and I have just had this same error. The node crashes and needs a full SST to be back up and running.

"2014-03-31 05:33:37 14134 [ERROR] WSREP: Trx 999204 tries to abort slave trx 999205. This could be caused by:..."

The rest of the situation is very similar to the above poster. I can provide any information necessary and I believe that the bug should be reopened.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.