Percona-XtraDB Cluster server-57 5.7.19 deadlocks with WHMCS 7

Bug #1732313 reported by Burnley
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC
Fix Committed
Undecided
Unassigned

Bug Description

CentOS 7.4 running as Xen domUs. Latest packages set:
Percona-XtraDB-Cluster-server-57-5.7.19-29.22.3.el7.x86_64
Percona-XtraDB-Cluster-garbd-57-5.7.19-29.22.3.el7.x86_64
Percona-XtraDB-Cluster-shared-57-5.7.19-29.22.3.el7.x86_64
Percona-XtraDB-Cluster-test-57-5.7.19-29.22.3.el7.x86_64
Percona-XtraDB-Cluster-shared-compat-57-5.7.19-29.22.3.el7.x86_64
Percona-XtraDB-Cluster-client-57-5.7.19-29.22.3.el7.x86_64
Percona-XtraDB-Cluster-devel-57-5.7.19-29.22.3.el7.x86_64

Two nodes and an arbitrator, all using ext4 with the default mount options:
/dev/xvda1 on / type ext4 (rw,relatime,data=ordered)

Several posts including "SHOW ENGINE InnoDB STATUS" here:
https://www.percona.com/forums/questions-discussions/percona-xtradb-cluster/48497-cluster-hang-with-wsrep-initiating-replication-for-write-set

The deadlocks are random, here's the latest one:

| InnoDB | |
=====================================
2017-11-15 12:17:41 0x7fc9cc0a7700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 10 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 10 srv_active, 0 srv_shutdown, 2805 srv_idle
srv_master_thread log flush and writes: 2815
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 15
OS WAIT ARRAY INFO: signal count 15
RW-shared spins 0, rounds 23, OS waits 11
RW-excl spins 0, rounds 1, OS waits 1
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 23.00 RW-shared, 1.00 RW-excl, 0.00 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 9150116
Purge done for trx's n < 0 undo n < 0 state: running but idle
History list length 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421981788381968, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 9149460, ACTIVE 781 sec
mysql tables in use 1, locked 1
1 lock struct(s), heap size 1136, 0 row lock(s), undo log entries 1
MySQL thread id 1379, OS thread handle 140504688125696, query id 4286 192.168.1.230 newib_whmcs wsrep: initiating replication for write set (-1)
INSERT INTO tbladminlog (`adminusername`,`logintime`,`lastvisit`,`ipaddres s`,`sessionid`) VALUES ('ib_admin','20171115120440','20171115120440','1 92.168.1.66','06984989bc1ab463aa79ff046f988964')
---TRANSACTION 9149454, ACTIVE 838 sec
mysql tables in use 1, locked 1
1 lock struct(s), heap size 1136, 0 row lock(s), undo log entries 1
MySQL thread id 1336, OS thread handle 140504688924416, query id 4068 192.168.1.230 newib_whmcs wsrep: initiating replication for write set (-1)
INSERT INTO tbladminlog (`adminusername`,`logintime`,`lastvisit`,`ipaddres s`,`sessionid`) VALUES ('admin2','20171115120343','20171115120343','192.1 68.1 .63','4b9a16fb34dfbb87d5e0ee7d0c714c18')
---TRANSACTION 9149448, ACTIVE 909 sec
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 1286, OS thread handle 140504688658176, query id 3858 192.168.1.230 newib_whmcs wsrep: initiating replication for write set (-1)
UPDATE tbltransientdata SET `data`='{"hash":"1a5852cff3a5895f4137334d4a3d1b93" ,"locales":[{"locale":"ar_AR","language":"arabic","language Cod e":"ar","countryCode":"AR","localisedName":"\\u 062 7\\u0644\\u0639\\u0631\\u0628\\u064a\\u0629"},{"lo cale":"az_AZ","language":"azerbaijani","languageCo de":"az","countryCode":"AZ","localisedName":"Aze rb aijani"},{"locale":"ca_AD","language":"catalan","l anguageCode":"ca","countryCode":"AD","localisedNam e":"Catal\\u00e0"},{"locale":"zh_TW","language" :"c hinese","languageCode":"zh","co
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
18003 OS file reads, 113 OS file writes, 48 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 12, seg size 14, 1 merges
merged operations:
insert 1, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 398491, node heap has 2 buffer(s)
Hash table size 398491, node heap has 2 buffer(s)
Hash table size 398491, node heap has 1 buffer(s)
Hash table size 398491, node heap has 1 buffer(s)
Hash table size 398491, node heap has 0 buffer(s)
Hash table size 398491, node heap has 0 buffer(s)
Hash table size 398491, node heap has 0 buffer(s)
Hash table size 398491, node heap has 2 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 19319928631
Log flushed up to 19319928631
Pages flushed up to 19319928631
Last checkpoint at 19319928622
Max checkpoint age 80826164
Checkpoint age target 78300347
Modified age 0
Checkpoint age 9
0 pending log flushes, 0 pending chkp writes
34 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 1676673024
Dictionary memory allocated 1928014
Internal hash tables (constant factor + variable factor)
Adaptive hash index 25668160 (25503424 + 164736)
Page hash 1594504 (buffer pool 0 only)
Dictionary cache 8303870 (6375856 + 1928014)
File system 1141928 (812272 + 329656)
Lock system 3989688 (3985144 + 4544)
Recovery system 0 (0 + 0)
Buffer pool size 98292
Buffer pool size, bytes 1610416128
Free buffers 80678
Database pages 17606
Old database pages 6519
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 17569, created 37, written 62
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 17606, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
3 RW transactions active inside InnoDB
Process ID=13419, Main thread ID=140504839718656, state: sleeping
Number of rows inserted 4323, updated 1, deleted 0, read 172076
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

Tags: deadlock
affects: percona-server → percona-xtradb-cluster
Revision history for this message
Krunal Bauskar (krunal-bauskar) wrote :

From the description, it sounds like you are hitting following issue
https://jira.percona.com/browse/PXC-877

The issue is already fixed on trunk and will be part of next PXC release.

Changed in percona-xtradb-cluster:
status: New → Fix Committed
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

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

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

Other bug subscribers

Remote bug watches

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