MySQL patches by Codership

Enabling wsrep_log_conflicts dynamically causes node to hang

Bug #1293624 reported by Jay Janssen on 2014-03-17

This bug affects 1 person

	Status	Importance	Assigned to	Milestone
MySQL patches by Codership	Confirmed	Undecided	Unassigned
Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC	Status tracked in 5.6
5.5	Invalid	Undecided	Unassigned
5.6	Fix Released	Undecided	Unassigned	Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC 5.6.15-25.5

Bug Description

Scenario:

3 node cluster, PXC 5.6

[root@node1 ~]# rpm -qa | grep -i percona
Percona-Server-shared-51-5.1.72-rel14.10.597.rhel6.x86_64
Percona-XtraDB-Cluster-galera-3-3.3-1.203.rhel6.x86_64
percona-toolkit-2.2.5-2.noarch
percona-xtrabackup-2.1.7-721.rhel6.x86_64
Percona-XtraDB-Cluster-56-5.6.15-25.4.731.rhel6.x86_64
Percona-XtraDB-Cluster-shared-56-5.6.15-25.3.706.rhel6.x86_64
Percona-XtraDB-Cluster-client-56-5.6.15-25.4.731.rhel6.x86_64
Percona-XtraDB-Cluster-server-56-5.6.15-25.4.731.rhel6.x86_64

I am doing this experiment:

# Create a test table
node1 mysql> create table test.deadlocks( i int unsigned not null primary key, j varchar(32) );
node1 mysql> insert into test.deadlocks values ( 1, NULL );

node1 mysql> begin; update test.deadlocks set j="node1" where i=1;

# Before commit, go to node3 in a separate window:
node3 mysql> begin; update test.deadlocks set j="node3" where i=1;
node3 mysql> commit;

node1 mysql> commit;
node1 mysql> select * from test.deadlocks;

This works fine, but if I do this on node1 and re-do the experiment:

node1 mysql> set global wsrep_log_conflicts=ON;

the commit on node1 hangs indefinitely.

node1 mysql> set global wsrep_log_conflicts=ON;
Query OK, 0 rows affected (0.00 sec)

node1 mysql> begin;
Query OK, 0 rows affected (0.00 sec)

node1 mysql> update test.deadlocks set j="node1" where i=1; Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0

node1 mysql> commit;
^CCtrl-C -- sending "KILL QUERY 19" to server ...
^C^C^C^C^C

I get this in the log:

2014-03-17 15:07:15 32710 [Note] WSREP: cluster conflict due to certification failure for threads:
2014-03-17 15:07:15 32710 [Note] WSREP: Victim thread:
THD: 19, mode: local, state: executing, conflict: cert failure, seqno: 213333
SQL: commit

I have to kill the node after this to get it back to a healthy state.

Related branches

lp://staging/percona-xtradb-cluster

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-03-17:

With UNIV_DEBUG:

2014-03-17 21:24:14 54487 [Note] WSREP: TO BEGIN: -1, 0 : create table test.deadlocks( i int unsigned not null primary key, j varchar(32) )
2014-03-17 21:24:14 54487 [Note] WSREP: TO BEGIN: 561466, 2
2014-03-17 21:24:14 54487 [Note] WSREP: TO END: 561466, 2 : create table test.deadlocks( i int unsigned not null primary key, j varchar(32) )
2014-03-17 21:24:14 54487 [Note] WSREP: TO END: 561466
########################################
DEADLOCK of threads detected!
Mutex 0x3fc2748 owned by thread 140133248501504 file /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc line 2456
--Thread 140133248501504 has waited at lock0lock.cc line 1642 for 0.0000 seconds the semaphore:
Mutex at 0x3fc2748 '&trx_sys->mutex', lock var 1
Last time reserved in file /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc line 2456, waiters flag 1
########################################
2014-03-17 21:26:05 7f73507f8700 InnoDB: Assertion failure in thread 140133248501504 in file sync0arr.cc line 426
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
15:56:05 UTC - mysqld got signal 6 ;

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-03-17:

Download full text (10.3 KiB)

This is due to wsrep_log_conflicts logic in PXC tree (not in codership tree).

However, using codership conflict logic here leads to

2014-03-17 22:15:01 13605 [Note] WSREP: Provider paused at f7e31510-9958-11e3-82f8-abba51ecd1d8:561479 (5)
2014-03-17 22:15:03 13605 [Note] WSREP: resuming provider at 5
2014-03-17 22:15:03 13605 [Note] WSREP: Provider resumed.
2014-03-17 22:15:03 13605 [Note] WSREP: 0.0 (Arch1): State transfer to 1.0 (Arch2) complete.
2014-03-17 22:15:03 13605 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 561479)
2014-03-17 22:15:03 13605 [Note] WSREP: Member 0 (Arch1) synced with group.
2014-03-17 22:15:03 13605 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 561479)
2014-03-17 22:15:03 13605 [Note] WSREP: Synchronized with group, ready for connections
2014-03-17 22:15:03 13605 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
WSREP_SST: [INFO] Total time on donor: 0 seconds (20140317 22:15:03.272)
[Thread 0x7fff7effd700 (LWP 13917) exited]
2014-03-17 22:15:09 13605 [Note] WSREP: 1.0 (Arch2): State transfer from 0.0 (Arch1) complete.
2014-03-17 22:15:09 13605 [Note] WSREP: Member 1 (Arch2) synced with group.
2014-03-17 22:15:43 13605 [Note] WSREP: cluster conflict due to high priority abort for threads:
2014-03-17 22:15:43 13605 [Note] WSREP: Winning thread:
   THD: 3, mode: applier, state: executing, conflict: no conflict, seqno: 561481
   SQL: (null)
2014-03-17 22:15:43 13605 [Note] WSREP: Victim thread:
   THD: 5, mode: local, state: idle, conflict: no conflict, seqno: -1
   SQL: (null)
2014-03-17 22:15:43 13605 [Note] WSREP: BF kill (1, seqno: 561481), victim: (5) trx: 1792773
2014-03-17 22:15:43 13605 [Note] WSREP: Aborting query: void
2014-03-17 22:15:43 13605 [Note] WSREP: kill IDLE for 1792773
2014-03-17 22:15:43 13605 [Note] WSREP: enqueuing trx abort for (5)
2014-03-17 22:15:43 13605 [Note] WSREP: signaling aborter
2014-03-17 22:15:43 13605 [Note] WSREP: WSREP rollback thread wakes for signal
2014-03-17 22:15:43 13605 [Note] WSREP: client rollback due to BF abort for (5), query: (null)
2014-03-17 22:15:43 13605 [Note] WSREP: WSREP rollbacker aborted thd: (5 140736823138048)
2014-03-17 22:15:45 13605 [Note] WSREP: Deadlock error for: (null)
InnoDB: sync levels should be > 298 but a level is 297
Mutex '&trx->mutex'
InnoDB: Locked mutex: addr 0x7fffb8037a80 thread 140736630683392 file /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc line 2455
InnoDB: sync_thread_levels_g(array, 298) does not hold!
2014-03-17 22:16:05 7fffcce0f700 InnoDB: Assertion failure in thread 140736630683392 in file sync0sync.cc line 1268
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.

But, this is only in UNIV_DEBUG.

#0 0x00007ffff5f5e389 in raise () from /usr/lib/libc.so.6
#1 0x00007ffff5f5f788 in abort () from /usr/...

This is due to wsrep_log_conflicts logic in PXC tree (not in codership tree).

However, using codership conflict logic here leads to

2014-03-17 22:15:01 13605 [Note] WSREP: Provider paused at f7e31510-9958-11e3-82f8-abba51ecd1d8:561479 (5)
2014-03-17 22:15:03 13605 [Note] WSREP: resuming provider at 5
2014-03-17 22:15:03 13605 [Note] WSREP: Provider resumed.
2014-03-17 22:15:03 13605 [Note] WSREP: 0.0 (Arch1): State transfer to 1.0 (Arch2) complete.
2014-03-17 22:15:03 13605 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 561479)
2014-03-17 22:15:03 13605 [Note] WSREP: Member 0 (Arch1) synced with group.
2014-03-17 22:15:03 13605 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 561479)
2014-03-17 22:15:03 13605 [Note] WSREP: Synchronized with group, ready for connections
2014-03-17 22:15:03 13605 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
WSREP_SST: [INFO] Total time on donor: 0 seconds (20140317 22:15:03.272)
[Thread 0x7fff7effd700 (LWP 13917) exited]
2014-03-17 22:15:09 13605 [Note] WSREP: 1.0 (Arch2): State transfer from 0.0 (Arch1) complete.
2014-03-17 22:15:09 13605 [Note] WSREP: Member 1 (Arch2) synced with group.
2014-03-17 22:15:43 13605 [Note] WSREP: cluster conflict due to high priority abort for threads:
2014-03-17 22:15:43 13605 [Note] WSREP: Winning thread:
   THD: 3, mode: applier, state: executing, conflict: no conflict, seqno: 561481
   SQL: (null)
2014-03-17 22:15:43 13605 [Note] WSREP: Victim thread:
   THD: 5, mode: local, state: idle, conflict: no conflict, seqno: -1
   SQL: (null)
2014-03-17 22:15:43 13605 [Note] WSREP: BF kill (1, seqno: 561481), victim: (5) trx: 1792773
2014-03-17 22:15:43 13605 [Note] WSREP: Aborting query: void
2014-03-17 22:15:43 13605 [Note] WSREP: kill IDLE for 1792773
2014-03-17 22:15:43 13605 [Note] WSREP: enqueuing trx abort for (5)
2014-03-17 22:15:43 13605 [Note] WSREP: signaling aborter
2014-03-17 22:15:43 13605 [Note] WSREP: WSREP rollback thread wakes for signal
2014-03-17 22:15:43 13605 [Note] WSREP: client rollback due to BF abort for (5), query: (null)
2014-03-17 22:15:43 13605 [Note] WSREP: WSREP rollbacker aborted thd: (5 140736823138048)
2014-03-17 22:15:45 13605 [Note] WSREP: Deadlock error for: (null)
InnoDB: sync levels should be > 298 but a level is 297
Mutex '&trx->mutex'
InnoDB: Locked mutex: addr 0x7fffb8037a80 thread 140736630683392 file /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc line 2455
InnoDB: sync_thread_levels_g(array, 298) does not hold!
2014-03-17 22:16:05 7fffcce0f700  InnoDB: Assertion failure in thread 140736630683392 in file sync0sync.cc line 1268
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.

But, this is only in UNIV_DEBUG.

#0  0x00007ffff5f5e389 in raise () from /usr/lib/libc.so.6
#1  0x00007ffff5f5f788 in abort () from /usr/lib/libc.so.6
#2  0x0000000000a93e44 in sync_array_wait_event (arr=0x16d3630, index=0) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/sync/sync0arr.cc:426
#3  0x0000000000a96fd0 in mutex_spin_wait (_mutex=0x2d85708, high_priority=high_priority@entry=false,
    file_name=file_name@entry=0xd62920 "/media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc", line=1642)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/sync/sync0sync.cc:671
#4  0x00000000009d6ca6 in mutex_enter_func (mutex=<optimized out>, file_name=file_name@entry=0xd62920 "/media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc",
    line=<optimized out>) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/include/sync0sync.ic:273
#5  0x00000000009d6d70 in pfs_mutex_enter_func (mutex=0x2d85708, file_name=file_name@entry=0xd62920 "/media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc",
    line=line@entry=1642) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/include/sync0sync.ic:350
#6  0x00000000009dc86b in wsrep_kill_victim (trx=0x7fffb8037a78, lock=0x7fff50024ac0) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc:1642
#7  0x00000000009dcee9 in lock_rec_other_has_conflicting (mode=mode@entry=1027, block=block@entry=0x7fff98bb1258, heap_no=heap_no@entry=7, trx=trx@entry=0x7fffb8037a78)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc:1706
#8  0x00000000009e1c6d in lock_rec_lock_slow (impl=0, impl@entry=140736280623736, mode=mode@entry=1027, block=block@entry=0x7fff98bb1258, heap_no=heap_no@entry=7, index=index@entry=0x7fff50024fc8,
    thr=thr@entry=0x7fff5001c848) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc:2486
#9  0x00000000009e1e36 in lock_rec_lock (impl=140736280623736, impl@entry=0, mode=mode@entry=1027, block=block@entry=0x7fff98bb1258, heap_no=heap_no@entry=7, index=index@entry=0x7fff50024fc8,
    thr=thr@entry=0x7fff5001c848) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc:2580
#10 0x00000000009e2928 in lock_clust_rec_read_check_and_lock (flags=flags@entry=0, block=block@entry=0x7fff98bb1258, rec=rec@entry=0x7fffb790c10a "", index=index@entry=0x7fff50024fc8,
    offsets=offsets@entry=0x7fffcce0b700, mode=mode@entry=LOCK_X, gap_mode=gap_mode@entry=1024, thr=thr@entry=0x7fff5001c848)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc:6827
#11 0x0000000000a6fc74 in sel_set_rec_lock (block=0x7fff98bb1258, rec=rec@entry=0x7fffb790c10a "", index=index@entry=0x7fff50024fc8, offsets=offsets@entry=0x7fffcce0b700, mode=mode@entry=3, type=type@entry=1024,
    thr=thr@entry=0x7fff5001c848) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/row/row0sel.cc:1012
#12 0x0000000000a741f2 in row_search_for_mysql (buf=buf@entry=0x7fff5001b900 "\377\004", mode=mode@entry=2, prebuilt=0x7fff5001be78, match_mode=match_mode@entry=1, direction=direction@entry=0)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/row/row0sel.cc:4506
#13 0x00000000009aed11 in ha_innobase::index_read (this=0x7fff50019bd0, buf=0x7fff5001b900 "\377\004", key_ptr=<optimized out>, key_len=<optimized out>, find_flag=<optimized out>)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/handler/ha_innodb.cc:8693
#14 0x000000000099987b in ha_innobase::rnd_pos (this=0x7fff50019bd0, buf=0x7fff5001b900 "\377\004", pos=0x7fff5001bb90 "\004")
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/handler/ha_innodb.cc:9225
#15 0x000000000064fa10 in handler::ha_rnd_pos (this=0x7fff50019bd0, buf=0x7fff5001b900 "\377\004", pos=0x7fff5001bb90 "\004") at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/sql/handler.cc:2824
#16 0x000000000090eee8 in Rows_log_event::do_index_scan_and_update (this=this@entry=0x7fffb8037770, rli=rli@entry=0x7fffb800bef0)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/sql/log_event.cc:10445
#17 0x0000000000911c34 in Rows_log_event::do_apply_event (this=0x7fffb8037770, rli=0x7fffb800bef0) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/sql/log_event.cc:11247
#18 0x000000000090b7de in Log_event::apply_event (this=this@entry=0x7fffb8037770, rli=0x7fffb800bef0) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/sql/log_event.cc:2997
#19 0x0000000000643989 in wsrep_apply_events (thd=thd@entry=0x7fffb80009a0, events_buf=events_buf@entry=0x7fffcff17b6c, buf_len=0, buf_len@entry=172)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/sql/wsrep_applier.cc:150
#20 0x0000000000643eef in wsrep_apply_cb (ctx=0x7fffb80009a0, buf=0x7fffcff17b6c, buf_len=172, flags=<optimized out>, meta=<optimized out>)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/sql/wsrep_applier.cc:226
#21 0x00007fffd809b758 in galera::TrxHandle::apply (this=this@entry=0x7fffb8036a20, recv_ctx=recv_ctx@entry=0x7fffb80009a0,
    apply_cb=apply_cb@entry=0x643e20 <wsrep_apply_cb(void*, void const*, unsigned long, unsigned int, wsrep_trx_meta const*)>, meta=...) at galera/src/trx_handle.cpp:304
#22 0x00007fffd80d462d in apply_trx_ws (recv_ctx=recv_ctx@entry=0x7fffb80009a0, apply_cb=0x643e20 <wsrep_apply_cb(void*, void const*, unsigned long, unsigned int, wsrep_trx_meta const*)>,
    commit_cb=0x644050 <wsrep_commit_cb(void*, unsigned int, wsrep_trx_meta const*, bool*, bool)>, trx=..., meta=...) at galera/src/replicator_smm.cpp:39
#23 0x00007fffd80d6800 in galera::ReplicatorSMM::apply_trx (this=this@entry=0x1678290, recv_ctx=recv_ctx@entry=0x7fffb80009a0, trx=trx@entry=0x7fffb8036a20) at galera/src/replicator_smm.cpp:419
#24 0x00007fffd80d933e in galera::ReplicatorSMM::process_trx (this=0x1678290, recv_ctx=0x7fffb80009a0, trx=0x7fffb8036a20) at galera/src/replicator_smm.cpp:1210
#25 0x00007fffd80b84b9 in galera::GcsActionSource::dispatch (this=this@entry=0x1678878, recv_ctx=recv_ctx@entry=0x7fffb80009a0, act=..., exit_loop=@0x7fffcce0e2e0: false) at galera/src/gcs_action_source.cpp:118
#26 0x00007fffd80b93ac in galera::GcsActionSource::process (this=0x1678878, recv_ctx=0x7fffb80009a0, exit_loop=@0x7fffcce0e2e0: false) at galera/src/gcs_action_source.cpp:177
#27 0x00007fffd80d955b in galera::ReplicatorSMM::async_recv (this=0x1678290, recv_ctx=0x7fffb80009a0) at galera/src/replicator_smm.cpp:354
#28 0x00007fffd80e7618 in galera_recv (gh=<optimized out>, recv_ctx=<optimized out>) at galera/src/wsrep_provider.cpp:231
#29 0x0000000000644671 in wsrep_replication_process (thd=0x7fffb80009a0) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/sql/wsrep_thd.cc:309
#30 0x000000000062e74f in start_wsrep_THD (arg=0x644600 <wsrep_replication_process(THD*)>) at /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/sql/mysqld.cc:5502
#31 0x00007ffff7bc70a2 in start_thread () from /usr/lib/libpthread.so.0
#32 0x00007ffff600ed1d in clone () from /usr/lib/libc.so.6

Revision history for this message

Alex Yurchenko (ayurchen) wrote on 2014-03-17:

confirmed for coderhsip-mysql 5.6 branch

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-03-17:

Download full text (6.8 KiB)

Fixed as follows:

diff:
=== modified file 'Percona-Server/storage/innobase/lock/lock0lock.cc'
--- Percona-Server/storage/innobase/lock/lock0lock.cc 2014-03-09 13:26:24 +0000
+++ Percona-Server/storage/innobase/lock/lock0lock.cc 2014-03-17 19:19:58 +0000
@@ -1639,7 +1639,6 @@
                        is in the queue*/
                } else if (lock->trx != trx) {
                        if (wsrep_log_conflicts) {
- mutex_enter(&trx_sys->mutex);
                                if (bf_this)
                                        fputs("\n*** Priority TRANSACTION:\n",
                                              stderr);
@@ -1656,7 +1655,6 @@
                                              stderr);
                                trx_print_latched(stderr, lock->trx, 3000);

- mutex_exit(&trx_sys->mutex);
fputs("*** WAITING FOR THIS LOCK TO BE GRANTED:\n",
stderr);

------------------------------------------------------------
revno: 752
fixes bug: https://launchpad.net/bugs/1293624
committer: Raghavendra D Prabhu <email address hidden>
branch nick: pxc56
timestamp: Tue 2014-03-18 00:49:58 +0530
message:
Bug#1293624: Enabling wsrep_log_conflicts dynamically causes node to hang

Fix merge regression of Bug#1234382 from codership-5.6 tree.

This merge caused double acquisition of trx_sys->mutex.

There are issues with codership fix of trx_sys->mutex acquisition in wsrep_kill_victim.

  =======================
  query: (null)
  2014-03-17 22:15:43 13605 [Note] WSREP: WSREP rollbacker aborted thd: (5 140736823138048)
  2014-03-17 22:15:45 13605 [Note] WSREP: Deadlock error for: (null)
  InnoDB: sync levels should be > 298 but a level is 297
  Mutex '&trx->mutex'
  InnoDB: Locked mutex: addr 0x7fffb8037a80 thread 140736630683392 file /media/Oort/ncode/percona-xtradb-cluster/pxc56/Percona-Server/storage/innobase/lock/lock0lock.cc line 2455
  InnoDB: sync_thread_levels_g(array, 298) does not hold!
  2014-03-17 22:16:05 7fffcce0f700 InnoDB: Assertion failure in thread 140736630683392 in file sync0sync.cc line 1268
  InnoDB: We intentionally generate a memory trap.
  InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
  InnoDB: If you get repeated assertion failures or crashes, even
  InnoDB: immediately after the mysqld startup, there may be
  InnoDB: corruption in the InnoDB tablespace. Please refer to
  InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
  InnoDB: about forcing recovery.

====================================

This is because, it violates the latching order :

#define SYNC_TRX_SYS 298
#define SYNC_TRX 297

from sync0sync.h

ie. always trx_sys->mutex before trx->mutex.

The fixes introduced in earlier revision 490 does this by acquiring trx_sys->mutex much higher in lock_rec_lock_slow.

However, wsrep_log_conflicts in wsrep_kill_victim is not completely thread-safe.

It is called from several locations:

wsrep_kill_victim(GLOBAL_SYMBOL_REF,0)
-lock_rec_other_has_conflicting(Percona-Server/storage...

Fixed as follows:

diff:
=== modified file 'Percona-Server/storage/innobase/lock/lock0lock.cc'
--- Percona-Server/storage/innobase/lock/lock0lock.cc   2014-03-09 13:26:24 +0000
+++ Percona-Server/storage/innobase/lock/lock0lock.cc   2014-03-17 19:19:58 +0000
@@ -1639,7 +1639,6 @@
                        is in the queue*/
                } else if (lock->trx != trx) {
                        if (wsrep_log_conflicts) {
-                               mutex_enter(&trx_sys->mutex);
                                if (bf_this)
                                        fputs("\n*** Priority TRANSACTION:\n",
                                              stderr);
@@ -1656,7 +1655,6 @@
                                              stderr);
                                trx_print_latched(stderr, lock->trx, 3000);

-                               mutex_exit(&trx_sys->mutex);
                                fputs("*** WAITING FOR THIS LOCK TO BE GRANTED:\n",
                                      stderr);

------------------------------------------------------------
revno: 752
fixes bug: https://launchpad.net/bugs/1293624
committer: Raghavendra D Prabhu <raghavendra.prabhu@percona.com>
branch nick: pxc56
timestamp: Tue 2014-03-18 00:49:58 +0530
message:
  Bug#1293624: Enabling wsrep_log_conflicts dynamically causes node to hang

Fix merge regression of Bug#1234382 from codership-5.6 tree.

This merge caused double acquisition of trx_sys->mutex.

There are issues with codership  fix of trx_sys->mutex acquisition in wsrep_kill_victim.

====================================

This is because, it violates the latching order :

#define SYNC_TRX_SYS          298
  #define SYNC_TRX              297

from sync0sync.h

ie. always trx_sys->mutex before trx->mutex.

The fixes introduced in earlier revision 490 does this by acquiring trx_sys->mutex much higher  in lock_rec_lock_slow.

However, wsrep_log_conflicts in wsrep_kill_victim is not completely thread-safe.

It is called from several locations:

wsrep_kill_victim(GLOBAL_SYMBOL_REF,0)
          -lock_rec_other_has_conflicting(Percona-Server/storage/innobase/lock/lock0lock.cc,1704)
                  --lock_rec_lock_slow(Percona-Server/storage/innobase/lock/lock0lock.cc,2484)
                          ---lock_rec_lock(Percona-Server/storage/innobase/lock/lock0lock.cc,2577)
                  --lock_rec_lock_slow(Percona-Server/storage/innobase/lock/lock0lock.cc,2488)
                          ---lock_rec_lock(Percona-Server/storage/innobase/lock/lock0lock.cc,2577)
                  --lock_rec_insert_check_and_lock(Percona-Server/storage/innobase/lock/lock0lock.cc,6367)
                          ---nonnull(Percona-Server/storage/innobase/btr/btr0cur.cc,1270)
          -lock_table_other_has_incompatible(Percona-Server/storage/innobase/lock/lock0lock.cc,4732)
                  --lock_table(Percona-Server/storage/innobase/lock/lock0lock.cc,4791)
                          ---main(Percona-Server/client/mysqlimport.c,697)
                          ---truncate_table(Percona-Server/sql/sql_truncate.cc,453)
                          ---ib_table_lock(Percona-Server/storage/innobase/api/api0api.cc,3461)
                          ---ib_trx_lock_table_with_retry(Percona-Server/storage/innobase/api/api0misc.cc,81)
                          ---fill_innodb_locks_from_cache(Percona-Server/storage/innobase/handler/i_s.cc,972)
                          ---fill_innodb_locks_from_cache(Percona-Server/storage/innobase/handler/i_s.cc,973)
                          ---row_ins_foreign_check_on_constraint(Percona-Server/storage/innobase/row/row0ins.cc,1138)
                          ---row_ins_check_foreign_constraint(Percona-Server/storage/innobase/row/row0ins.cc,1543)
                          ---row_ins_step(Percona-Server/storage/innobase/row/row0ins.cc,3335)
                          ---row_merge_lock_table(Percona-Server/storage/innobase/row/row0merge.cc,2515)
                          ---row_lock_table_autoinc_for_mysql(Percona-Server/storage/innobase/row/row0mysql.cc,1119)
                          ---row_lock_table_for_mysql(Percona-Server/storage/innobase/row/row0mysql.cc,1191)
                          ---row_lock_table_for_mysql(Percona-Server/storage/innobase/row/row0mysql.cc,1195)
                          ---row_mysql_lock_table(Percona-Server/storage/innobase/row/row0mysql.cc,3126)
                          ---row_sel_step(Percona-Server/storage/innobase/row/row0sel.cc,2088)
                          ---row_search_for_mysql(Percona-Server/storage/innobase/row/row0sel.cc,4085)
                          ---row_upd_step(Percona-Server/storage/innobase/row/row0upd.cc,2964)
                          ---i_s_locks_row_validate(Percona-Server/storage/innobase/trx/trx0i_s.cc,431)
                          ---fill_locks_row(Percona-Server/storage/innobase/trx/trx0i_s.cc,810)
                          ---fill_locks_row(Percona-Server/storage/innobase/trx/trx0i_s.cc,815)
                  --lock_table_ix_resurrect(Percona-Server/storage/innobase/lock/lock0lock.cc,4845)
                          ---lock_rec_expl_exist_on_page(Percona-Server/storage/innobase/include/lock0lock.h,475)
                          ---trx_resurrect_table_locks(Percona-Server/storage/innobase/trx/trx0trx.cc,662)
                  --lock_table_queue_validate(Percona-Server/storage/innobase/lock/lock0lock.cc,5884)
                          ---lock_validate_table_locks(Percona-Server/storage/innobase/lock/lock0lock.cc,6142)

However, note, that trx_print_latched is a read-only procedure, and
  while there is a risk of crash due to non-existent transaction, that can
  be ruled out due to semantics of wsrep_kill_victim acting only on active
  transactions.

However, for future, this logic needs to be moved to much higher level like srv_printf_innodb_monitor.

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-03-19:

Download full text (10.8 KiB)

Another fix done for this:

------------------------------------------------------------
revno: 754
committer: Raghavendra D Prabhu <email address hidden>
branch nick: pxc56
timestamp: Wed 2014-03-19 02:59:01 +0530
message:
Bug#1293624: Fix another issue with wsrep_log_conflicts.

This time it is taking trx_sys->mutex in following stack:

  # 2014-03-17T16:51:33 [2733] #6 0x0000000000ce86c8 in trx_print_latched (f=0x7f8fd8612860, trx=0x7f8d60032cc8, max_query_len=3000) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/ce
   ntos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/trx/trx0trx.cc:2072
   # 2014-03-17T16:51:33 [2733] #7 0x0000000000baea95 in wsrep_kill_victim (trx=0x7f8d60032cc8, lock=0x7f8d640cef00) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-
   XtraDB-Cluster-5.6.15/storage/innobase/lock/lock0lock.cc:1648
   # 2014-03-17T16:51:33 [2733] #8 0x0000000000baec7c in lock_rec_other_has_conflicting (mode=2563, block=0x7f8e7d2e8e28, heap_no=1, trx=0x7f8d60032cc8) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE
   /debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/lock/lock0lock.cc:1704
   # 2014-03-17T16:51:33 [2733] #9 0x0000000000bb9eb7 in lock_rec_insert_check_and_lock (flags=0, rec=0x7f8ead03c088 "\200", block=0x7f8e7d2e8e28, index=0x7f8d3c05a3e8, thr=0x7f8d3c06adb0, mtr=0x7f8fb876b130, inher
   it=0x7f8fb876b040) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/lock/lock0lock.cc:6367
   # 2014-03-17T16:51:33 [2733] #10 0x0000000000d1d3bf in btr_cur_ins_lock_and_undo (flags=0, cursor=0x7f8fb876b600, entry=0x7f8d580727f8, thr=0x7f8d3c06adb0, mtr=0x7f8fb876b130, inherit=0x7f8fb876b040) at /mnt/work
   space/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/btr/btr0cur.cc:1272
   # 2014-03-17T16:51:33 [2733] #11 0x0000000000d1dba4 in btr_cur_optimistic_insert (flags=0, cursor=0x7f8fb876b600, offsets=0x7f8fb876b698, heap=0x7f8fb876b110, entry=0x7f8d580727f8, rec=0x7f8fb876b690, big_rec=0x7
   f8fb876b688, n_ext=0, thr=0x7f8d3c06adb0, mtr=0x7f8fb876b130) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/btr/btr0cur.cc
   :1510
   # 2014-03-17T16:51:33 [2733] #12 0x0000000000c46774 in row_ins_sec_index_entry_low (flags=0, mode=2, index=0x7f8d3c05a3e8, offsets_heap=0x7f8d600a2e00, heap=0x7f8d600a9330, entry=0x7f8d580727f8, trx_id=0, thr=0x7 f8d3c06adb0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/row/row0ins.cc:2812
   # 2014-03-17T16:51:33 [2733] #13 0x0000000000c46e47 in row_ins_sec_index_entry (index=0x7f8d3c05a3e8, entry=0x7f8d580727f8, thr=0x7f8d3c06adb0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/ label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/row/row0ins.cc:2997
   # 2014-03-17T16:51:33 [2733] #14 0x0000000000c46f38 i...

Another fix done for this:

------------------------------------------------------------
revno: 754
committer: Raghavendra D Prabhu <raghavendra.prabhu@percona.com>
branch nick: pxc56
timestamp: Wed 2014-03-19 02:59:01 +0530
message:
  Bug#1293624: Fix another issue with wsrep_log_conflicts.
  
  This time it is taking trx_sys->mutex in following stack:
  
  
  # 2014-03-17T16:51:33 [2733] #6  0x0000000000ce86c8 in trx_print_latched (f=0x7f8fd8612860, trx=0x7f8d60032cc8, max_query_len=3000) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/ce
   ntos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/trx/trx0trx.cc:2072
   # 2014-03-17T16:51:33 [2733] #7  0x0000000000baea95 in wsrep_kill_victim (trx=0x7f8d60032cc8, lock=0x7f8d640cef00) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-
   XtraDB-Cluster-5.6.15/storage/innobase/lock/lock0lock.cc:1648
   # 2014-03-17T16:51:33 [2733] #8  0x0000000000baec7c in lock_rec_other_has_conflicting (mode=2563, block=0x7f8e7d2e8e28, heap_no=1, trx=0x7f8d60032cc8) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE
   /debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/lock/lock0lock.cc:1704
   # 2014-03-17T16:51:33 [2733] #9  0x0000000000bb9eb7 in lock_rec_insert_check_and_lock (flags=0, rec=0x7f8ead03c088 "\200", block=0x7f8e7d2e8e28, index=0x7f8d3c05a3e8, thr=0x7f8d3c06adb0, mtr=0x7f8fb876b130, inher
   it=0x7f8fb876b040) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/lock/lock0lock.cc:6367
   # 2014-03-17T16:51:33 [2733] #10 0x0000000000d1d3bf in btr_cur_ins_lock_and_undo (flags=0, cursor=0x7f8fb876b600, entry=0x7f8d580727f8, thr=0x7f8d3c06adb0, mtr=0x7f8fb876b130, inherit=0x7f8fb876b040) at /mnt/work
   space/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/btr/btr0cur.cc:1272
   # 2014-03-17T16:51:33 [2733] #11 0x0000000000d1dba4 in btr_cur_optimistic_insert (flags=0, cursor=0x7f8fb876b600, offsets=0x7f8fb876b698, heap=0x7f8fb876b110, entry=0x7f8d580727f8, rec=0x7f8fb876b690, big_rec=0x7
   f8fb876b688, n_ext=0, thr=0x7f8d3c06adb0, mtr=0x7f8fb876b130) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/btr/btr0cur.cc
   :1510
   # 2014-03-17T16:51:33 [2733] #12 0x0000000000c46774 in row_ins_sec_index_entry_low (flags=0, mode=2, index=0x7f8d3c05a3e8, offsets_heap=0x7f8d600a2e00, heap=0x7f8d600a9330, entry=0x7f8d580727f8, trx_id=0, thr=0x7 f8d3c06adb0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/row/row0ins.cc:2812
   # 2014-03-17T16:51:33 [2733] #13 0x0000000000c46e47 in row_ins_sec_index_entry (index=0x7f8d3c05a3e8, entry=0x7f8d580727f8, thr=0x7f8d3c06adb0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/ label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/row/row0ins.cc:2997
   # 2014-03-17T16:51:33 [2733] #14 0x0000000000c46f38 in row_ins_index_entry (index=0x7f8d3c05a3e8, entry=0x7f8d580727f8, thr=0x7f8d3c06adb0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/labe l_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/row/row0ins.cc:3032
   # 2014-03-17T16:51:33 [2733] #15 0x0000000000c47213 in row_ins_index_entry_step (node=0x7f8d3c06ab10, thr=0x7f8d3c06adb0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/P ercona-XtraDB-Cluster-5.6.15/storage/innobase/row/row0ins.cc:3107
   # 2014-03-17T16:51:33 [2733] #16 0x0000000000c4751e in row_ins (node=0x7f8d3c06ab10, thr=0x7f8d3c06adb0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Clu ster-5.6.15/storage/innobase/row/row0ins.cc:3247
   # 2014-03-17T16:51:33 [2733] #17 0x0000000000c478a7 in row_ins_step (thr=0x7f8d3c06adb0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/stor age/innobase/row/row0ins.cc:3372
   # 2014-03-17T16:51:33 [2733] #18 0x0000000000c5f34d in row_insert_for_mysql (mysql_rec=0x7f8d3c06ec60 "\357\241\002", prebuilt=0x7f8d3c06a348) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/l abel_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/row/row0mysql.cc:1313
   # 2014-03-17T16:51:33 [2733] #19 0x0000000000b5a524 in ha_innobase::write_row (this=0x7f8d3c0662e0, record=0x7f8d3c06ec60 "\357\241\002") at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_ exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/storage/innobase/handler/ha_innodb.cc:7618
   # 2014-03-17T16:51:33 [2733] #20 0x000000000066d8c9 in handler::ha_write_row (this=0x7f8d3c0662e0, buf=0x7f8d3c06ec60 "\357\241\002") at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/ centos6-64/Percona-XtraDB-Cluster-5.6.15/sql/handler.cc:7588
   # 2014-03-17T16:51:33 [2733] #21 0x0000000000a629eb in Write_rows_log_event::write_row (this=0x7f8d60056980, rli=0x7f8d600a0170, overwrite=false) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debu g/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/sql/log_event.cc:12495
   # 2014-03-17T16:51:33 [2733] #22 0x0000000000a62b68 in Write_rows_log_event::do_exec_row (this=0x7f8d60056980, rli=0x7f8d600a0170) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/cen tos6-64/Percona-XtraDB-Cluster-5.6.15/sql/log_event.cc:12684
   # 2014-03-17T16:51:33 [2733] #23 0x0000000000a5bf1e in Rows_log_event::do_apply_row (this=0x7f8d60056980, rli=0x7f8d600a0170) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6- 64/Percona-XtraDB-Cluster-5.6.15/sql/log_event.cc:10126
   # 2014-03-17T16:51:33 [2733] #24 0x0000000000a5edd7 in Rows_log_event::do_apply_event (this=0x7f8d60056980, rli=0x7f8d600a0170) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos 6-64/Percona-XtraDB-Cluster-5.6.15/sql/log_event.cc:11247
   # 2014-03-17T16:51:33 [2733] #25 0x0000000000a49e00 in Log_event::apply_event (this=0x7f8d60056980, rli=0x7f8d600a0170) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Per cona-XtraDB-Cluster-5.6.15/sql/log_event.cc:3076
   # 2014-03-17T16:51:33 [2733] #26 0x000000000065571c in wsrep_apply_events (thd=0x12f34da0, events_buf=0x7f8fac136e37, buf_len=0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/cento s6-64/Percona-XtraDB-Cluster-5.6.15/sql/wsrep_applier.cc:150
   # 2014-03-17T16:51:33 [2733] #27 0x0000000000655c7c in wsrep_apply_cb (ctx=0x12f34da0, buf=0x7f8fac136e37, buf_len=243, flags=1, meta=0x7f8fb876e250) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/ debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/sql/wsrep_applier.cc:226
   # 2014-03-17T16:51:33 [2733] #28 0x00007f8fd57cc211 in galera::TrxHandle::apply (this=0x7f8d60082be0, recv_ctx=0x12f34da0, apply_cb=0x655b29 <wsrep_apply_cb(void*, void const*, size_t, uint32_t, wsrep_trx_meta_t  const*)>, meta=...) at galera/src/trx_handle.cpp:304
   # 2014-03-17T16:51:33 [2733] #29 0x00007f8fd5805345 in apply_trx_ws (recv_ctx=0x12f34da0, apply_cb=0x655b29 <wsrep_apply_cb(void*, void const*, size_t, uint32_t, wsrep_trx_meta_t const*)>, commit_cb=0x656073 <wsr ep_commit_cb(void*, uint32_t, wsrep_trx_meta_t const*, wsrep_bool_t*, bool)>, trx=..., meta=...) at galera/src/replicator_smm.cpp:39
   # 2014-03-17T16:51:33 [2733] #30 0x00007f8fd5805c0e in galera::ReplicatorSMM::replay_trx (this=0x1e48390, trx=0x7f8d60082be0, trx_ctx=0x12f34da0) at galera/src/replicator_smm.cpp:848
   # 2014-03-17T16:51:33 [2733] #31 0x00007f8fd58177bc in galera_replay_trx (gh=<value optimized out>, trx_handle=<value optimized out>, recv_ctx=0x12f34da0) at galera/src/wsrep_provider.cpp:301
   # 2014-03-17T16:51:33 [2733] #32 0x0000000000656fba in wsrep_replay_transaction (thd=0x12f34da0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6 .15/sql/wsrep_thd.cc:230
   # 2014-03-17T16:51:33 [2733] #33 0x0000000000817a0c in wsrep_mysql_parse (thd=0x12f34da0, rawbuf=0x7f8d60004c50 " \342\202\001", length=200, parser_state=0x7f8fb876f770) at /mnt/workspace/build-xtradb-cluster-bin aries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/sql/sql_parse.cc:6954
   # 2014-03-17T16:51:33 [2733] #34 0x0000000000808979 in dispatch_command (command=COM_QUERY, thd=0x12f34da0, packet=0x12f39381 "REPLACE INTO `table1000_innodb_int` ( `col_int` ) SELECT `col_char_12_key` FROM `tabl e100_innodb_key_pk_parts_2_int` AS X  ORDER BY `col_char_12`,`col_char_12_key`,`col_int`,`col_int_key`,`pk` LIMIT 8", packet_length=200) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_e xp/centos6-64/Percona-XtraDB-Cluster-5.6.15/sql/sql_parse.cc:1630
   # 2014-03-17T16:51:33 [2733] #35 0x0000000000807203 in do_command (thd=0x12f34da0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15/sql/sql_pa rse.cc:1133
   # 2014-03-17T16:51:33 [2733] #36 0x00000000007cdccd in do_handle_one_connection (thd_arg=0x12f34da0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster -5.6.15/sql/sql_connect.cc:1557
   # 2014-03-17T16:51:33 [2733] #37 0x00000000007cd7b4 in handle_one_connection (arg=0x12f34da0) at /mnt/workspace/build-xtradb-cluster-binaries-56/BUILD_TYPE/debug/label_exp/centos6-64/Percona-XtraDB-Cluster-5.6.15 /sql/sql_connect.cc:1461
   # 2014-03-17T16:51:33 [2733] #38 0x00007f8fd9e10851 in start_thread () from /lib64/libpthread.so.0
   # 2014-03-17T16:51:33 [2733] #39 0x00007f8fd836d94d in clone () from /lib64/libc.so.6
diff:
=== modified file 'Percona-Server/storage/innobase/lock/lock0lock.cc'
--- Percona-Server/storage/innobase/lock/lock0lock.cc	2014-03-17 19:19:58 +0000
+++ Percona-Server/storage/innobase/lock/lock0lock.cc	2014-03-18 21:29:01 +0000
@@ -6364,6 +6364,8 @@
 	on the successor, which produced an unnecessary deadlock. */
 
 #ifdef WITH_WSREP
+        if (wsrep_log_conflicts)
+                mutex_enter(&trx_sys->mutex);
 	if ((c_lock = (lock_t *)lock_rec_other_has_conflicting(
 		    static_cast<enum lock_mode>(
 			    LOCK_X | LOCK_GAP | LOCK_INSERT_INTENTION),
@@ -6374,6 +6376,8 @@
 			    LOCK_X | LOCK_GAP | LOCK_INSERT_INTENTION),
 		    block, next_rec_heap_no, trx)) {
 #endif /* WITH_WSREP */
+                if (wsrep_log_conflicts)
+                        mutex_exit(&trx_sys->mutex);
 		/* Note that we may get DB_SUCCESS also here! */
 		trx_mutex_enter(trx);
 
@@ -6389,6 +6393,8 @@
 
 		trx_mutex_exit(trx);
 	} else {
+                if (wsrep_log_conflicts)
+                        mutex_exit(&trx_sys->mutex);
 		err = DB_SUCCESS;
 	}

Revision history for this message

Shahriyar Rzayev (rzayev-sehriyar) wrote on 2018-01-18:

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

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

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