InnoDB assertion: sync levels should be > 298 but a level is 297 w wsrep_log_conflicts

[Teemu Ollakka]

Debug 5.6 build crashes with multimaster sqlgen load when wsrep_log_conflicts=ON:

LD_PRELOAD=~/lib/libglb.so GLB_BIND="gw:3307" GLB_TARGETS="gw:3311,gw:3312,gw:3313" sqlgen --host gw --port 3307 --duration 3600

InnoDB: sync levels should be > 298 but a level is 297
Mutex created at trx0trx.cc 108
InnoDB: Locked mutex: addr 0x7f1fa40377b0 thread 139774330287872 file /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/lock/lock0lock.cc line 2445
InnoDB: sync_thread_levels_g(array, 298) does not hold!
2014-04-09 07:28:24 7f1fbf4e3700 InnoDB: Assertion failure in thread 139774330287872 in file sync0sync.cc line 1171

Backtrace:

#0 0x00007fd0518aef0c in __pthread_kill (threadid=<optimized out>, signo=6)
    at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:62
#1 0x0000000000ad2645 in my_write_core (sig=6)
    at /home/teemu/work/bzr/codership-mysql/5.6/mysys/stacktrace.c:422
#2 0x000000000073e2e1 in handle_fatal_signal (sig=6)
    at /home/teemu/work/bzr/codership-mysql/5.6/sql/signal_handler.cc:248
#3 <signal handler called>
#4 0x00007fd050cf2f77 in __GI_raise (sig=sig@entry=6)
    at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#5 0x00007fd050cf65e8 in __GI_abort () at abort.c:90
#6 0x0000000000cb9c01 in sync_thread_add_level (latch=0x25a49c8,
    level=298, relock=0)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/sync/sync0sync.cc:1171
#7 0x0000000000cb8e55 in mutex_set_debug_info (mutex=0x25a49c8,
    file_name=0xff3b50 "/home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/lock/lock0lock.cc", line=1642)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/sync/sync0sync.cc:614
#8 0x0000000000baacd9 in mutex_enter_func (mutex=0x25a49c8,
    file_name=0xff3b50 "/home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/lock/lock0lock.cc", line=1642)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/include/sync0sync.ic:217
#9 0x0000000000baada3 in pfs_mutex_enter_func (mutex=0x25a49c8,
    file_name=0xff3b50 "/home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/lock/lock0lock.cc", line=1642)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/include/sync0sync.ic:253
#10 0x0000000000bb2567 in wsrep_kill_victim (trx=0x7fcffc016b38,
    lock=0x7fcfec008498)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/lock/lock0lock.cc:1642
#11 0x0000000000bb27c3 in lock_rec_other_has_conflicting (mode=1027,
    block=0x7fd027d5c040, heap_no=3, trx=0x7fcffc016b38)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/lock/lock0lock.cc:1706
#12 0x0000000000bb466a in lock_rec_lock_slow (impl=0, mode=1027,
    block=0x7fd027d5c040, heap_no=3, index=0x7fd004042738,
    thr=0x7fcffc012fe0)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/lock/lock0lock.cc:2472
#13 0x0000000000bb49ca in lock_rec_lock (impl=0, mode=1027,
    block=0x7fd027d5c040, heap_no=3, index=0x7fd004042738,
    thr=0x7fcffc012fe0)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/lock/lock0lock.cc:2558
#14 0x0000000000bbef0d in lock_clust_rec_read_check_and_lock (flags=0,
    block=0x7fd027d5c040, rec=0x7fd02828c0a9 "\200", index=0x7fd004042738,
    offsets=0x7fd030679300, mode=LOCK_X, gap_mode=1024, thr=0x7fcffc012fe0)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/lock/lock0lock.cc:6750
#15 0x0000000000c84e35 in sel_set_rec_lock (block=0x7fd027d5c040,
    rec=0x7fd02828c0a9 "\200", index=0x7fd004042738,
    offsets=0x7fd030679300, mode=3, type=1024, thr=0x7fcffc012fe0)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/row/row0sel.cc:1011
#16 0x0000000000c8b8b3 in row_search_for_mysql (
    buf=0x7fcffc00f500 "\341\001", mode=2, prebuilt=0x7fcffc0128a8,
    match_mode=1, direction=0)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/row/row0sel.cc:4503
#17 0x0000000000b616ac in ha_innobase::index_read (this=0x7fcffc010420,
    buf=0x7fcffc00f500 "\341\001", key_ptr=0x7fcffc00f888 "\001",
    key_len=4, find_flag=HA_READ_KEY_EXACT)
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/handler/ha_innodb.cc:8134
#18 0x0000000000b62710 in ha_innobase::rnd_pos (this=0x7fcffc010420,
    buf=0x7fcffc00f500 "\341\001", pos=0x7fcffc00f888 "\001")
    at /home/teemu/work/bzr/codership-mysql/5.6/storage/innobase/handler/ha_innodb.cc:8636
#19 0x000000000064c6dc in handler::ha_rnd_pos (this=0x7fcffc010420,
    buf=0x7fcffc00f500 "\341\001", pos=0x7fcffc00f888 "\001")
---Type <return> to continue, or q <return> to quit---
    at /home/teemu/work/bzr/codership-mysql/5.6/sql/handler.cc:2785
#20 0x0000000000657e7b in handler::rnd_pos_by_record (this=0x7fcffc010420,
    record=0x7fcffc00f500 "\341\001")
    at /home/teemu/work/bzr/codership-mysql/5.6/sql/handler.h:2320
#21 0x0000000000a3ea62 in Rows_log_event::do_index_scan_and_update (
    this=0x7fcffc040e40, rli=0x7fcffc00bb90)
    at /home/teemu/work/bzr/codership-mysql/5.6/sql/log_event.cc:10409
#22 0x0000000000a40c91 in Rows_log_event::do_apply_event (
    this=0x7fcffc040e40, rli=0x7fcffc00bb90)
    at /home/teemu/work/bzr/codership-mysql/5.6/sql/log_event.cc:11211
#23 0x0000000000a2bb08 in Log_event::apply_event (this=0x7fcffc040e40,
    rli=0x7fcffc00bb90)
    at /home/teemu/work/bzr/codership-mysql/5.6/sql/log_event.cc:3078
#24 0x000000000063e859 in wsrep_apply_events (thd=0x7fcffc0009a0,
    events_buf=0x7fd043441454, buf_len=0)
    at /home/teemu/work/bzr/codership-mysql/5.6/sql/wsrep_applier.cc:150
#25 0x000000000063ee41 in wsrep_apply_cb (ctx=0x7fcffc0009a0,
    buf=0x7fd043441454, buf_len=315, flags=1, meta=0x7fd03067d0c0)
    at /home/teemu/work/bzr/codership-mysql/5.6/sql/wsrep_applier.cc:226
#26 0x00007fd04b91bcfd in apply_wscoll (
    recv_ctx=recv_ctx@entry=0x7fcffc0009a0,
    apply_cb=apply_cb@entry=0x63ecbc <wsrep_apply_cb(void*, void const*, unsigned long, unsigned int, wsrep_trx_meta const*)>, trx=..., meta=...)
    at galera/src/replicator_smm.cpp:46
#27 0x00007fd04b91bfcf in apply_trx_ws (
    recv_ctx=recv_ctx@entry=0x7fcffc0009a0,
    apply_cb=0x63ecbc <wsrep_apply_cb(void*, void const*, unsigned long, unsigned int, wsrep_trx_meta const*)>,
    commit_cb=0x63f276 <wsrep_commit_cb(void*, unsigned int, wsrep_trx_meta const*, bool*, bool)>, trx=..., meta=...) at galera/src/replicator_smm.cpp:87
#28 0x00007fd04b91d769 in galera::ReplicatorSMM::apply_trx (
    this=this@entry=0x21c99c0, recv_ctx=recv_ctx@entry=0x7fcffc0009a0,
    trx=trx@entry=0x7fcffc004730) at galera/src/replicator_smm.cpp:515
#29 0x00007fd04b91fb87 in galera::ReplicatorSMM::process_trx (
    this=0x21c99c0, recv_ctx=0x7fcffc0009a0, trx=0x7fcffc004730)
    at galera/src/replicator_smm.cpp:1150
#30 0x00007fd04b90b206 in galera::GcsActionSource::dispatch (
    this=this@entry=0x21c9f80, recv_ctx=recv_ctx@entry=0x7fcffc0009a0,
    act=..., exit_loop=@0x7fd03067d7fd: false)
    at galera/src/gcs_action_source.cpp:111
#31 0x00007fd04b90b3de in galera::GcsActionSource::process (this=0x21c9f80,
    recv_ctx=0x7fcffc0009a0, exit_loop=@0x7fd03067d7fd: false)
    at galera/src/gcs_action_source.cpp:170
#32 0x00007fd04b9201eb in galera::ReplicatorSMM::async_recv (
    this=0x21c99c0, recv_ctx=0x7fcffc0009a0)
    at galera/src/replicator_smm.cpp:390
#33 0x00007fd04b92b91d in galera_recv (gh=<optimized out>,
    recv_ctx=<optimized out>) at galera/src/wsrep_provider.cpp:213
#34 0x000000000064087a in wsrep_replication_process (thd=0x7fcffc0009a0)
    at /home/teemu/work/bzr/codership-mysql/5.6/sql/wsrep_thd.cc:309
#35 0x000000000061db35 in start_wsrep_THD (
    arg=0x6407b3 <wsrep_replication_process(THD*)>)
    at /home/teemu/work/bzr/codership-mysql/5.6/sql/mysqld.cc:5349
#36 0x00007fd0518a9f6e in start_thread (arg=0x7fd03067f700)
    at pthread_create.c:311
#37 0x00007fd050db69cd in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

[Raghavendra D Prabhu (raghavendra-prabhu)]

Related to (and possible duplicate of) https://bugs.launchpad.net/percona-xtradb-cluster/+bug/1293624