MySQL 5.6.2 binary log option 'binlog_rows_query_log_events' crashes a cluster

[Derek Downey]

Running a 2-node test-setup of PXC 5.6.15-63.0 and Galera 3.4(r176), if I enable 'binlog_rows_query_log_events' and issue an insert on one node, the second node crashes leaving the first in non-Primary.

Test case:
  - 5.6.2+ server, galera 3.4 provider
  - binary logging enabled, with log-slave-updates (eg, for a async slave off cluster)
  - enable session level binlog_rows_query_log_events (to see statement that generated RBR event)
  - Insert a row into a table.

Expected result:
  - Galera can handle the extra information from 'binlog_rows_query_log_events' and continue normally

Actual result:
  - Cluster crashes with signal 11

Notes and error logs attached

[Raghavendra D Prabhu (raghavendra-prabhu)]

bt
#0 0x00000000008b48bd in Relay_log_info::cleanup_context (this=this@entry=0x7fff7800bed0, thd=thd@entry=0x7fff78000990, error=error@entry=false) at /tmp/bld1/Percona-Server/sql/rpl_rli.cc:1473
#1 0x000000000087a406 in rows_event_stmt_cleanup (rli=rli@entry=0x7fff7800bed0, thd=0x7fff78000990) at /tmp/bld1/Percona-Server/sql/log_event.cc:11421
#2 0x000000000088786c in Rows_log_event::do_apply_event (this=0x7fff7800f970, rli=0x7fff7800bed0) at /tmp/bld1/Percona-Server/sql/log_event.cc:11329
#3 0x0000000000882ea6 in Log_event::apply_event (this=this@entry=0x7fff7800f970, rli=0x7fff7800bed0) at /tmp/bld1/Percona-Server/sql/log_event.cc:2997
#4 0x000000000063557d in wsrep_apply_events (thd=thd@entry=0x7fff78000990, events_buf=events_buf@entry=0x7fffcf51c797, buf_len=0, buf_len@entry=250) at /tmp/bld1/Percona-Server/sql/wsrep_applier.cc:150
#5 0x0000000000635a5f in wsrep_apply_cb (ctx=0x7fff78000990, buf=0x7fffcf51c797, buf_len=250, flags=<optimized out>, meta=<optimized out>) at /tmp/bld1/Percona-Server/sql/wsrep_applier.cc:226
#6 0x00007fffd769f158 in galera::TrxHandle::apply (this=this@entry=0x7fff7800f430, recv_ctx=recv_ctx@entry=0x7fff78000990,
    apply_cb=apply_cb@entry=0x635990 <wsrep_apply_cb(void*, void const*, unsigned long, unsigned int, wsrep_trx_meta const*)>, meta=...) at galera/src/trx_handle.cpp:304
#7 0x00007fffd76d818d in apply_trx_ws (recv_ctx=recv_ctx@entry=0x7fff78000990, apply_cb=0x635990 <wsrep_apply_cb(void*, void const*, unsigned long, unsigned int, wsrep_trx_meta const*)>,
    commit_cb=0x635bc0 <wsrep_commit_cb(void*, unsigned int, wsrep_trx_meta const*, bool*, bool)>, trx=..., meta=...) at galera/src/replicator_smm.cpp:39
#8 0x00007fffd76da360 in galera::ReplicatorSMM::apply_trx (this=this@entry=0x1462440, recv_ctx=recv_ctx@entry=0x7fff78000990, trx=trx@entry=0x7fff7800f430) at galera/src/replicator_smm.cpp:419
#9 0x00007fffd76dce9e in galera::ReplicatorSMM::process_trx (this=0x1462440, recv_ctx=0x7fff78000990, trx=0x7fff7800f430) at galera/src/replicator_smm.cpp:1210
#10 0x00007fffd76bc019 in galera::GcsActionSource::dispatch (this=this@entry=0x1462a28, recv_ctx=recv_ctx@entry=0x7fff78000990, act=..., exit_loop=@0x7fffbc490310: false) at galera/src/gcs_action_source.cpp:118
#11 0x00007fffd76bcf0c in galera::GcsActionSource::process (this=0x1462a28, recv_ctx=0x7fff78000990, exit_loop=@0x7fffbc490310: false) at galera/src/gcs_action_source.cpp:177
#12 0x00007fffd76dd0bb in galera::ReplicatorSMM::async_recv (this=0x1462440, recv_ctx=0x7fff78000990) at galera/src/replicator_smm.cpp:354
#13 0x00007fffd76eb218 in galera_recv (gh=<optimized out>, recv_ctx=<optimized out>) at galera/src/wsrep_provider.cpp:231
#14 0x00000000006362f6 in wsrep_replication_process (thd=0x7fff78000990) at /tmp/bld1/Percona-Server/sql/wsrep_thd.cc:309
#15 0x0000000000620ca0 in start_wsrep_THD (arg=0x6362a0 <wsrep_replication_process(THD*)>) at /tmp/bld1/Percona-Server/sql/mysqld.cc:5502
#16 0x00007ffff7bc5124 in start_thread () from /usr/lib/libpthread.so.0
#17 0x00007ffff60004bd in clone () from /usr/lib/libc.so.6
(gdb) bt full
#0 0x00000000008b48bd in Relay_log_info::cleanup_context (this=this@entry=0x7fff7800bed0, thd=thd@entry=0x...

[Andrey Ilyin (jemmix)]

Is this a PXC bug or an upstream bug? It seems as though it has been reported upstream (https://bugs.launchpad.net/codership-mysql/+bug/1309707) but apparently they don't use that tracker anymore and use GitHub instead. I haven't managed to find any similar issues over there: https://github.com/codership/mysql-wsrep/issues?q=

It seems that the upstream report has been lost in communication here. If this is indeed an upstream issue, can you report it on GitHub, please?

Thank you!

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXC-1672