Not the answer you need?
Register and ask your own question!

Cluster hang with wsrep: initiating replication for write set

edwhedwh ContributorCurrent User Role Novice
I have a 3 node cluster. This morning the cluster wasn't working. In SHOW PROCESSLIST, 2 of the 3 nodes had many instances of requests showing:

wsrep: initiating replication for write set

I had to shut the cluster down and rebootstrap. Any suggestions?

Comments

  • edwhedwh Contributor Current User Role Novice
    Saw another occurrence of this. Anyone?
  • burnleyburnley Entrant Inactive User Role Beginner
    Seeing the same issue the 2nd time in 2 days, 3 nodes cluster (2 db + 1 arbitrator). At the moment can't write to any of the databases, any insert stalls.

    Running on CentOS 7.4 with:
    Percona-XtraDB-Cluster-server-57-5.7.19-29.22.1.el7.x86_64
    Percona-XtraDB-Cluster-garbd-57-5.7.19-29.22.1.el7.x86_64
    Percona-XtraDB-Cluster-shared-57-5.7.19-29.22.1.el7.x86_64
    Percona-XtraDB-Cluster-test-57-5.7.19-29.22.1.el7.x86_64
    Percona-XtraDB-Cluster-devel-57-5.7.19-29.22.1.el7.x86_64
    Percona-XtraDB-Cluster-client-57-5.7.19-29.22.1.el7.x86_64
    Percona-XtraDB-Cluster-shared-compat-57-5.7.19-29.22.1.el7.x86_64

    mysql> show variables like '%version%';
    +
    +
    +
    | Variable_name | Value |
    +
    +
    +
    | innodb_version | 5.7.19-17 |
    | protocol_version | 10 |
    | slave_type_conversions | |
    | tls_version | TLSv1,TLSv1.1,TLSv1.2 |
    | version | 5.7.19-17-57-log |
    | version_comment | Percona XtraDB Cluster (GPL), Release rel17, Revision c10027a, WSREP version 29.22, wsrep_29.22 |
    | version_compile_machine | x86_64 |
    | version_compile_os | Linux |
    +
    +
    +

    show processlist:
    Id User Host db Command Time State Info Rows_sent Rows_examined
    1 system user NULL Sleep 85394 wsrep: applier idle NULL 0 0
    2 system user NULL Sleep 85394 wsrep: aborter idle NULL 0 0
    5 system user NULL Sleep 85392 wsrep: applier idle NULL 0 0
    6 system user NULL Sleep 85392 wsrep: applier idle NULL 0 0
    7 system user NULL Sleep 85392 wsrep: applier idle NULL 0 0
    8 system user NULL Sleep 85392 wsrep: applier idle NULL 0 0
    9 system user NULL Sleep 85392 wsrep: applier idle NULL 0 0
    10 system user NULL Sleep 85392 wsrep: applier idle NULL 0 0
    11 system user NULL Sleep 85392 wsrep: applier idle NULL 0 0
    56821 mydb1_testdb 10.3.0.205:53618 mydb1_live_testdb Query 4100 wsrep: initiating replication for write set (-1) INSERT INTO tblactivitylog (`date`,`description`,`user`,`userid`,`ipaddr`) VALUES ('20171013111426', 0 0
    56822 mydb1_testdb 10.3.0.205:53620 mydb1_live_testdb Sleep 4100 NULL 0 0
    56856 mydb1_testdb 10.3.0.205:53694 mydb1_live_testdb Sleep 4086 NULL 0 0
    56857 mydb1_testdb 10.3.0.205:53696 mydb1_live_testdb Query 4086 wsrep: initiating replication for write set (-1) UPDATE `modlivehelp_requests` SET `useragent` = 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 0 1
    56872 mydb1_testdb 10.3.0.205:53698 mydb1_live_testdb Query 4065 wsrep: initiating replication for write set (-1) UPDATE tbltransientdata SET `data`='2017-10-13 11:15:01',`expires`='1508026501' WHERE name='lastCron 0 1
    56873 mydb1_testdb 10.3.0.205:53700 mydb1_live_testdb Sleep 4065 NULL 0 0
    56915 mydb1_testdb 10.3.0.205:53704 mydb1_live_testdb Execute 3954 wsrep: initiating replication for write set (-1) update `tbltask_status` set `last_run` = ?, `updated_at` = ? where `id` = ? 0 1
    57013 newdb2_testdb 10.3.0.63:54696 newdb2_testdb Query 557 wsrep: initiating replication for write set (-1) insert into tblcustomfieldsvalues (fieldid, relid, `value`) value (11902, 1704, '123456789') 0 0
    58419 db2_testdb 10.3.0.247:43538 db2_testdb Query 1890 wsrep: initiating replication for write set (-1) INSERT INTO `ddns_externalcalls_tracking` (`module`, `action`, `item_id`, `reference`, `request`, `s00
    58422 newdb2_testdb 10.3.0.230:58806 newdb2_testdb Execute 1889 wsrep: initiating replication for write set (-1) INSERT INTO tbladminlog (`adminusername`,`logintime`,`lastvisit`,`ipaddress`,`sessionid`) VALUES ('y00
    58465 newdb2_testdb 10.3.0.230:58904 newdb2_testdb Execute 1835 wsrep: initiating replication for write set (-1) INSERT INTO tbladminlog (`adminusername`,`logintime`,`lastvisit`,`ipaddress`,`sessionid`) VALUES ('i00
    58699 db2_testdb 10.3.0.247:43590 db2_testdb Query 1549 wsrep: initiating replication for write set (-1) INSERT INTO tblactivitylog (`date`,`description`,`user`,`userid`,`ipaddr`) VALUES ('20171013115657',00
    58763 db2_testdb 10.3.0.66:56243 db2_testdb Query 1491 wsrep: initiating replication for write set (-1) /* ApplicationName=PhpStorm 2017.2.4 */ INSERT INTO `ddns_externalcalls_tracking` ( `module`, `actio 0 0
    58766 root localhost mydb1_testdb Query 1432 wsrep: initiating replication for write set (-1) INSERT INTO tblactivitylog (`date`,`description`,`user`,`userid`,`ipaddr`) VALUES ('20171013111426', 0 0
    59520 newdb2_testdb 10.3.0.230:33130 newdb2_testdb Execute 384 wsrep: initiating replication for write set (-1) update `tblclients` set `lastlogin` = ?, `updated_at` = ?, `pwresetexpiry` = ? where `id` = ? 0 1
    59583 newdb2_testdb 10.3.0.63:55244 newdb2_testdb Sleep 89 NULL 0 0
    59584 newdb2_testdb 10.3.0.63:55246 newdb2_testdb Sleep 89 NULL 3 15
    59789 root localhost NULL Query 0 starting show processlist 0 0

    Using "wsrep_debug=ON" I see:
    [...]
    2017-10-13T12:24:27.675260+10:00 59856 [Note] WSREP: set_query_id(), assigned new next trx id: 234483
    2017-10-13T12:24:27.715554+10:00 59857 [Note] WSREP: set_query_id(), assigned new next trx id: 234486
    2017-10-13T12:24:28.150407+10:00 59584 [Note] WSREP: set_query_id(), assigned new next trx id: 234489
    2017-10-13T12:24:28.151376+10:00 59584 [Note] WSREP: Cleaning up wsrep-transaction for local query: SELECT a.id, c.email, a.domain, d.id, e.`value` FROM tblhosting a
    LEFT JOIN tblproducts b ON b.id = a.packageid
    LEFT JOIN tblclients c ON a.userid = c.id
    LEFT JOIN tblcustomfields d ON a.packageid = d.relid and d.`type` = 'product' and d.fieldname = 'Weebly Site ID'
    LEFT JOIN tblcustomfieldsvalues e ON e.fieldid = d.id and e.relid = a.id
    WHERE b.gid = 5 AND a.id in (12701,12732)
    LIMIT 0, 1000
    2017-10-13T12:24:30.680499+10:00 59858 [Note] WSREP: set_query_id(), assigned new next trx id: 234493
    2017-10-13T12:24:30.714697+10:00 59859 [Note] WSREP: set_query_id(), assigned new next trx id: 234496
    2017-10-13T12:24:33.677191+10:00 59860 [Note] WSREP: set_query_id(), assigned new next trx id: 234499
    2017-10-13T12:24:33.716849+10:00 59861 [Note] WSREP: set_query_id(), assigned new next trx id: 234502
    2017-10-13T12:24:36.676546+10:00 59862 [Note] WSREP: set_query_id(), assigned new next trx id: 234505
    [...]
  • krunalbauskarkrunalbauskar Advisor Inactive User Role Novice
    Seems like nothing is progressing. Do you want to check innodb show status output and findout what is blocking things.
  • burnleyburnley Entrant Inactive User Role Beginner
    Sure, the locking problem is very easy to replicate using WHMCS 7.1.2, every time I'm loading the admin area I see 2 transactions that are taking tens of seconds to execute:

    | InnoDB | |
    =====================================
    2017-10-25 10:15:06 0x7fb5680ae700 INNODB MONITOR OUTPUT
    =====================================
    Per second averages calculated from the last 24 seconds
    BACKGROUND THREAD
    srv_master_thread loops: 155 srv_active, 0 srv_shutdown, 2729 srv_idle
    srv_master_thread log flush and writes: 2884
    SEMAPHORES
    OS WAIT ARRAY INFO: reservation count 4520
    OS WAIT ARRAY INFO: signal count 4299
    RW-shared spins 0, rounds 2654, OS waits 1558
    RW-excl spins 0, rounds 1228, OS waits 61
    RW-sx spins 24, rounds 720, OS waits 18
    Spin rounds per wait: 2654.00 RW-shared, 1228.00 RW-excl, 30.00 RW-sx
    TRANSACTIONS
    Trx id counter 8980906
    Purge done for trx's n:o < 8980904 undo n:o < 0 state: running but idle
    History list length 34
    LIST OF TRANSACTIONS FOR EACH SESSION:
    ---TRANSACTION 421894274614296, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274613088, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274611880, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274610672, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274609464, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274608256, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274607048, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274605840, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274604632, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 8980905, ACTIVE 11 sec fetching rows
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 1136, 3 row lock(s)
    MySQL thread id 2248, OS thread handle 140418998040320, query id 10008 192.168.1.205 cheaper_whmcs updating
    UPDATE tbladdonmodules SET `value`='a:17:{i:12;i:1376287256;i:11;i:1494835472;i:9;i:1497308070;i:2;i:1494808535;i:10;i:1500273990;i:3;i:1503278454;i:4;i:1493868026;i:14;i:1395814433;i:15;i:1364342130;i:16;i:1494554870;i:17;i:1381364192;i:7;i:1447996150;i:18;i:1406093635;i:19;i:1508886895;i:21;i:1473544536;i:20;i:1508796162;i:22;i:1493860993;}' WHERE module='staffboard' AND setting='lastviewed'
    TRX HAS BEEN WAITING 11 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 6491 page no 3 n bits 160 index GEN_CLUST_INDEX of table `cheaper_live_whmcs`.`tbladdonmodules` trx id 8980905 lock_mode X locks rec but not gap waiting
    ---TRANSACTION 8970244, ACTIVE 2827 sec
    5 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 5
    MySQL thread id 2, OS thread handle 140419312752384, query id 7043 wsrep: committed write set (2489081)
    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
    5805 OS file reads, 37808 OS file writes, 9132 OS fsyncs
    0.00 reads/s, 0 avg bytes/read, 0.46 writes/s, 0.37 fsyncs/s
    INSERT BUFFER AND ADAPTIVE HASH INDEX
    Ibuf: size 1, free list len 12, seg size 14, 0 merges
    merged operations:
    insert 0, delete mark 0, delete 0
    discarded operations:
    insert 0, delete mark 0, delete 0
    Hash table size 398491, node heap has 24 buffer(s)
    Hash table size 398491, node heap has 27 buffer(s)
    Hash table size 398491, node heap has 8 buffer(s)
    Hash table size 398491, node heap has 21 buffer(s)
    Hash table size 398491, node heap has 35 buffer(s)
    Hash table size 398491, node heap has 1 buffer(s)
    Hash table size 398491, node heap has 4 buffer(s)
    Hash table size 398491, node heap has 1 buffer(s)
    0.75 hash searches/s, 0.37 non-hash searches/s
    ---
    LOG
    ---
    Log sequence number 18972910373
    Log flushed up to 18972910373
    Pages flushed up to 18972910373
    Last checkpoint at 18972910364
    Max checkpoint age 80826164
    Checkpoint age target 78300347
    Modified age 0
    Checkpoint age 9
    0 pending log flushes, 0 pending chkp writes
    5877 log i/o's done, 0.25 log i/o's/second
    BUFFER POOL AND MEMORY
    Total large memory allocated 1676673024
    Dictionary memory allocated 3511796
    Internal hash tables (constant factor + variable factor)
    Adaptive hash index 27519552 (25503424 + 2016128)
    Page hash 1594504 (buffer pool 0 only)
    Dictionary cache 9887652 (6375856 + 3511796)
    File system 1140504 (812272 + 328232)
    Lock system 3997640 (3985144 + 12496)
    Recovery system 0 (0 + 0)
    Buffer pool size 98292
    Buffer pool size, bytes 1610416128
    Free buffers 67973
    Database pages 30198
    Old database pages 11127
    Modified db pages 0
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 1, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 4808, created 25390, written 29275
    0.00 reads/s, 0.00 creates/s, 0.17 writes/s
    Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
    Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
    LRU len: 30198, 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
    2 RW transactions active inside InnoDB
    Process ID=2116, Main thread ID=140419006433024, state: sleeping
    Number of rows inserted 715931, updated 1469, deleted 0, read 1652559
    0.00 inserts/s, 0.04 updates/s, 0.00 deletes/s, 3380.15 reads/s
    END OF INNODB MONITOR OUTPUT
    ============================

    The 2nd transaction in the next post.
  • burnleyburnley Entrant Inactive User Role Beginner
    | InnoDB | |
    =====================================
    2017-10-25 10:16:34 0x7fb5680ae700 INNODB MONITOR OUTPUT
    =====================================
    Per second averages calculated from the last 26 seconds
    BACKGROUND THREAD
    srv_master_thread loops: 157 srv_active, 0 srv_shutdown, 2814 srv_idle
    srv_master_thread log flush and writes: 2971
    SEMAPHORES
    OS WAIT ARRAY INFO: reservation count 4528
    OS WAIT ARRAY INFO: signal count 4307
    RW-shared spins 0, rounds 2660, OS waits 1561
    RW-excl spins 0, rounds 1258, OS waits 62
    RW-sx spins 24, rounds 720, OS waits 18
    Spin rounds per wait: 2660.00 RW-shared, 1258.00 RW-excl, 30.00 RW-sx
    TRANSACTIONS
    Trx id counter 8980913
    Purge done for trx's n:o < 8980911 undo n:o < 0 state: running but idle
    History list length 37
    LIST OF TRANSACTIONS FOR EACH SESSION:
    ---TRANSACTION 421894274614296, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274613088, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274611880, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274610672, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274609464, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274608256, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274607048, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274605840, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 421894274604632, not started
    0 lock struct(s), heap size 1136, 0 row lock(s)
    ---TRANSACTION 8980912, ACTIVE 44 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
    MySQL thread id 2248, OS thread handle 140418998040320, query id 10336 192.168.1.205 cheaper_whmcs updating
    UPDATE tbltransientdata SET `data`='{"result":"success","checks":{"success":[{"name":"phpSettings","type":"PHP","severityLevel":"notice","body":"Your PHP environment uses a valid timezone."},{"name":"installedCurlVersion","type":"PHP","severityLevel":"notice","body":"You currently have version <strong>7.56.0<\\/strong> of cURL installed. This version uses a secure cipher list."},{"name":"curlSecureTLS","type":"WHMCS","severityLevel":"notice","body":"<p>cURL reports that it does support Secure TLS 1.1 and 1.2<\\/p>"},{"name":"sessionSup ------- TRX HAS BEEN WAITING 44 SEC FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 6618 page no 6 n bits 80 index PRIMARY of table `cheaper_live_whmcs`.`tbltransientdata` trx id 8980912 lock_mode X locks rec but not gap waiting ------------------ ---TRANSACTION 8970244, ACTIVE 2915 sec 5 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 5 MySQL thread id 2, OS thread handle 140419312752384, query id 7043 wsrep: committed write set (2489081) -------- 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 5805 OS file reads, 37839 OS file writes, 9150 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, 0 merges merged operations: insert 0, delete mark 0, delete 0 discarded operations: insert 0, delete mark 0, delete 0 Hash table size 398491, node heap has 24 buffer(s) Hash table size 398491, node heap has 27 buffer(s) Hash table size 398491, node heap has 8 buffer(s) Hash table size 398491, node heap has 21 buffer(s) Hash table size 398491, node heap has 35 buffer(s) Hash table size 398491, node heap has 1 buffer(s) Hash table size 398491, node heap has 4 buffer(s) Hash table size 398491, node heap has 1 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 18972914466 Log flushed up to 18972914466 Pages flushed up to 18972914466 Last checkpoint at 18972914457 Max checkpoint age 80826164 Checkpoint age target 78300347 Modified age 0 Checkpoint age 9 0 pending log flushes, 0 pending chkp writes 5887 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total large memory allocated 1676673024 Dictionary memory allocated 3511796 Internal hash tables (constant factor + variable factor) Adaptive hash index 27519552 (25503424 + 2016128) Page hash 1594504 (buffer pool 0 only) Dictionary cache 9887652 (6375856 + 3511796) File system 1140504 (812272 + 328232) Lock system 3997640 (3985144 + 12496) Recovery system 0 (0 + 0) Buffer pool size 98292 Buffer pool size, bytes 1610416128 Free buffers 67973 Database pages 30198 Old database pages 11127 Modified db pages 0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 1, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 4808, created 25390, written 29293 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: 30198, 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 2 RW transactions active inside InnoDB Process ID=2116, Main thread ID=140419006433024, state: sleeping Number of rows inserted 715933, updated 1472, deleted 0, read 1733581 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================
  • burnleyburnley Entrant Inactive User Role Beginner
    Another deadlock today, same nodes. Might be related to a brief loss of power in the test environment this cluster is running. rpm -qa Percona-XtraDB-Cluster* 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 | InnoDB | | ===================================== 2017-11-15 11:19:24 0x7f5d53fbe700 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 36 seconds
    BACKGROUND THREAD
    srv_master_thread loops: 276 srv_active, 0 srv_shutdown, 2670 srv_idle srv_master_thread log flush and writes: 2946
    SEMAPHORES
    OS WAIT ARRAY INFO: reservation count 1475 OS WAIT ARRAY INFO: signal count 1462 RW-shared spins 0, rounds 1172, OS waits 585 RW-excl spins 0, rounds 570, OS waits 19 RW-sx spins 0, rounds 0, OS waits 0 Spin rounds per wait: 1172.00 RW-shared, 570.00 RW-excl, 0.00 RW-sx
    TRANSACTIONS
    Trx id counter 9148965 Purge done for trx's n:o < 9148462 undo n:o < 0 state: running but idle History list length 31 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 421516122552848, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122548016, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122545600, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122516608, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122531104, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122543184, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122537144, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122589088, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122587880, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122586672, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122585464, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122584256, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122583048, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122581840, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122580632, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122579424, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122578216, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122577008, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122538352, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122528688, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122523856, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122550432, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122549224, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122574592, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122570968, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122568552, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122566136, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122563720, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122561304, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122558888, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122556472, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122554056, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122551640, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122539560, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122546808, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122544392, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122541976, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122534728, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122532312, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122529896, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122527480, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122525064, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122522648, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122519024, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122514192, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122512984, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421516122511776, not started 0 lock struct(s), heap size 1136, 0 row lock(s) (continues in the next post)
  • burnleyburnley Entrant Inactive User Role Beginner
    ---TRANSACTION 9148963, ACTIVE 22 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)
    MySQL thread id 3317, OS thread handle 140038812378880, query id 38646 192.168.1.205 cheaper_whmcs updating
    UPDATE tbltransientdata SET `data`='2017-11-15 11:19:02',`expires`='1510877942' WHERE name='lastCronInvocationTime'
    TRX HAS BEEN WAITING 22 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 6621 page no 4 n bits 88 index name of table `cheaper_live_whmcs`.`tbltransientdata` trx id 9148963 lock_mode X locks rec but not gap waiting
    ---TRANSACTION 9148961, ACTIVE 31 sec starting index read
    mysql tables in use 1, locked 1
    LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)
    MySQL thread id 3245, OS thread handle 140038885476096, query id 38594 192.168.1.205 cheaper_whmcs updating
    UPDATE tbltransientdata SET `data`='2017-11-15 11:18:53',`expires`='1510706593' WHERE name='lastNotificationDailyCronOutOfSync'
    TRX HAS BEEN WAITING 31 SEC FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 6621 page no 4 n bits 88 index name of table `cheaper_live_whmcs`.`tbltransientdata` trx id 9148961 lock_mode X locks rec but not gap waiting
    ---TRANSACTION 9148517, ACTIVE 605 sec
    mysql tables in use 1, locked 1
    2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
    MySQL thread id 2827, OS thread handle 140038810781440, query id 33524 192.168.1.205 cheaper_whmcs wsrep: initiating replication for write set (-1)
    UPDATE `modlivehelp_requests` SET `useragent` = 'Mozilla/5.0 (iPad; CPU OS 11_0 like Mac OS X) AppleWebKit/604.1.38 (KHTML, like Gecko) Version/11.0 Mobile/15A372 Safari/604.1', `refresh` = '2017-11-15 11:09:19' WHERE `id` = '1013'
    ---TRANSACTION 9148499, ACTIVE 745 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 2696, OS thread handle 140038886541056, query id 32792 192.168.1.205 cheaper_whmcs wsrep: initiating replication for write set (-1)
    INSERT INTO tbladminlog (`adminusername`,`logintime`,`lastvisit`,`ipaddres s`,`sessionid`) VALUES ('admin_cheaper','20171115110659','2017111511065 9','192.168.1.66','474ec96a56fb0a9fcb15632e1553511 2')
    ---TRANSACTION 9148478, ACTIVE 991 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 2476, OS thread handle 140038887073536, query id 31702 192.168.1.205 cheaper_whmcs wsrep: initiating replication for write set (-1)
    UPDATE tbltransientdata SET `data`='2017-11-15 11:02:53',`expires`='1510705633' WHERE name='lastNotificationDailyCronOutOfSync'
    ---TRANSACTION 9148472, ACTIVE 1102 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 2430, OS thread handle 140038888670976, query id 31330 192.168.1.205 cheaper_whmcs wsrep: initiating replication for write set (-1)
    UPDATE tbltransientdata SET `data`='2017-11-15 11:01:02',`expires`='1510876862' WHERE name='lastCronInvocationTime'
    ---TRANSACTION 9148469, ACTIVE 1114 sec
    mysql tables in use 1, locked 1
    2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
    MySQL thread id 2419, OS thread handle 140038899459840, query id 31262 192.168.1.205 cheaper_whmcs wsrep: initiating replication for write set (-1)
    UPDATE `modlivehelp_requests` SET `useragent` = 'Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/61.0.3163.100 Safari/537.36', `refresh` = '2017-11-15 11:00:50' WHERE `id` = '1072'
    ---TRANSACTION 9148467, ACTIVE 1118 sec
    mysql tables in use 1, locked 1
    2 lock struct(s), heap size 1136, 1 row lock(s), undo log entries 1
    MySQL thread id 2414, OS thread handle 140039019747072, query id 31230 192.168.1.205 cheaper_whmcs wsrep: initiating replication for write set (-1)
    UPDATE `modlivehelp_requests` SET `useragent` = 'Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko/20100101 Firefox/57.0', `refresh` = '2017-11-15 11:00:46' WHERE `id` = '1069'
    ---TRANSACTION 9148465, ACTIVE 1127 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 2328, OS thread handle 140038899193600, query id 31186 192.168.1.205 cheaper_whmcs wsrep: initiating replication for write set (-1)
    INSERT INTO tblactivitylog (`date`,`description`,`user`,`userid`,`ipaddr`) VALUES ('20171115110037','Cron Job: Suspending Service - Service ID: 2040','System','0','')
    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
    29698 OS file reads, 4709 OS file writes, 2461 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, 80 merges
    merged operations:
    insert 91, delete mark 0, delete 0
    discarded operations:
    insert 0, delete mark 0, delete 0
    Hash table size 398491, node heap has 6 buffer(s)
    Hash table size 398491, node heap has 3 buffer(s)
    Hash table size 398491, node heap has 33 buffer(s)
    Hash table size 398491, node heap has 1 buffer(s)
    Hash table size 398491, node heap has 23 buffer(s)
    Hash table size 398491, node heap has 4 buffer(s)
    Hash table size 398491, node heap has 1 buffer(s)
    Hash table size 398491, node heap has 32 buffer(s)
    0.00 hash searches/s, 0.50 non-hash searches/s
    ---
    LOG
    ---
    Log sequence number 19319919024
    Log flushed up to 19319919024
    Pages flushed up to 19319919024
    Last checkpoint at 19319919015
    Max checkpoint age 80826164
    Checkpoint age target 78300347
    Modified age 0
    Checkpoint age 9
    0 pending log flushes, 0 pending chkp writes
    1834 log i/o's done, 0.00 log i/o's/second
    BUFFER POOL AND MEMORY
    Total large memory allocated 1676673024
    Dictionary memory allocated 1851224
    Internal hash tables (constant factor + variable factor)
    Adaptive hash index 27224640 (25503424 + 1721216)
    Page hash 1594504 (buffer pool 0 only)
    Dictionary cache 8227080 (6375856 + 1851224)
    File system 1141928 (812272 + 329656)
    Lock system 4048760 (3985144 + 63616)
    Recovery system 0 (0 + 0)
    Buffer pool size 98292
    Buffer pool size, bytes 1610416128
    Free buffers 68622
    Database pages 29567
    Old database pages 10934
    Modified db pages 0
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 1, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 29465, created 102, written 2660
    0.00 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
    Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
    LRU len: 29567, 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
    9 RW transactions active inside InnoDB
    Process ID=12778, Main thread ID=140040915093248, state: sleeping
    Number of rows inserted 4314, updated 434, deleted 0, read 933014
    0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.81 reads/s
    END OF INNODB MONITOR OUTPUT
    ============================
  • burnleyburnley Entrant Inactive User Role Beginner
    ... and another deadlock, same cluster, one of those days I guess :)

    | 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:o < 0 undo n:o < 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.168.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","languageCod e":"ar","countryCode":"AR","localisedName":"\\u062 7\\u0644\\u0639\\u0631\\u0628\\u064a\\u0629"},{"lo cale":"az_AZ","language":"azerbaijani","languageCo de":"az","countryCode":"AZ","localisedName":"Azerb 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 ============================
Sign In or Register to comment.

MySQL, InnoDB, MariaDB and MongoDB are trademarks of their respective owners.
Copyright ©2005 - 2020 Percona LLC. All rights reserved.