Search code examples
mysqltransactionsmariadbinnodb

WordPress database error Lock wait timeout exceeded; try restarting transaction for query UPDATE wp_wppa_session


Good day! I am currently receiving this error in my error_logs in CWP:

WordPress database error Lock wait timeout exceeded; try restarting transaction for query UPDATE wp_wppa_session

I have searched for some answers and found this question.

I searched for a process that takes a lot of time and killed it as suggested from the above link:

| 42454 | user | localhost | database | Sleep   |  513 |          | NULL

But after some time, this same process kept on showing again. In addition, I have found the additional processes:

UPDATE wp_wppa_session SET data = 'a:20:{s:4:\"ajax\";s:1:\"0\";s:20:\"display_searchstrin

which kept on flooding my process list. These two processes kept on flooding my database which makes my local website load so slow and sometimes causes an Internal Server Error.

Is there something I should do or configure with the wp_wppa_session? Is this the reason why I am flooded with a lot of processes?

UPDATE

This is the command that is showing in my MySQL Live Process Load

| Id   | User          | Host      | db           | Command | Time | State    | Info    
| 3676 | user          | localhost | db           | Query   | 1    | updating | UPDATE wp_wppa_session SET count = 71 WHERE id = 0                                      | 0.000    |
| 4414 | user          | localhost | db           | Query   | 6    | updating  | UPDATE wp_wppa_session SET data = 'a:20: s:4:\"ajax\";i:3;s:20:\"display_searchstring\";s: | 0.000    |
| 2315 | user          | localhost | db           | Sleep   | 703  |          |

Error_Logs Output

[Tue Oct 06 16:42:47.691914 2020] [:error] [pid 1418:tid 140633796732672] [client 58.69.125.124:11148] WordPress database error Server shutdown in progress for query UPDATE wp_wppa_session\r, referer: http://slsu.edu.ph/wp-admin/post.php?post=8999&action=edit&tab=course_settings
[Tue Oct 06 16:42:47.692313 2020] [:error] [pid 1419:tid 140633754769152] [client 114.119.131.116:30688] \t\t\t\t\t\t\t SET data = 'a:20:{s:4:\\"ajax\\";s:1:\\"0\\";s:20:\\"display_searchstring\\";s:0:\\"\\";s:13:\\"has_searchbox\\";b:0;s:2:\\"id\\";s:1:\\"0\\";s:12:\\"is_wppa_tree\\";b:0;s:7:\\"isrobot\\";b:0;s:4:\\"page\\";i:1;s:7:\\"rem_url\\";a:0:{}s:7:\\"rootbox\\";b:0;s:11:\\"search_root\\";s:0:\\"\\";s:6:\\"subbox\\";b:0;s:10:\\"superalbum\\";s:1:\\"0\\";s:11:\\"supersearch\\";s:0:\\"\\";s:9:\\"superview\\";s:6:\\"thumbs\\";s:4:\\"uris\\";a:1:{i:0;s:38:\\"8:42 /main/report-of-disbursement-2017\\";}s:16:\\"use_searchstring\\";s:0:\\"\\";s:4:\\"user\\";s:15:\\"114.119.131.116\\";s:6:\\"wfcart\\";N;s:8:\\"randseed\\";i:1549;s:12:\\"randseedtime\\";i:1601973758;}'\r
[Tue Oct 06 16:42:47.692419 2020] [:error] [pid 1419:tid 140633754769152] [client 114.119.131.116:30688] \t\t\t\t\t\t\t WHERE id = 0 made by shutdown_action_hook, do_action('shutdown'), WP_Hook->do_action, WP_Hook->apply_filters, wppa_session_end, wppa_save_session

INNODB STATUS

| InnoDB |      |
=====================================
2020-10-07 08:26:50 7fa622d52700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 7 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 6661 srv_active, 0 srv_shutdown, 48587 srv_idle
srv_master_thread log flush and writes: 55248
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 120295
--Thread 140351423641344 has waited at buf0flu.cc line 1903 for 1.0000 seconds t                                                                                        he semaphore:
Mutex at 0x7fa645483d30 '&buf_pool->flush_state_mutex', lock var 1
Last time reserved by thread 140351536850688 in file not yet reserved line 0, wa                                                                                        iters flag 1
--Thread 140351415248640 has waited at buf0flu.cc line 1903 for 1.0000 seconds t                                                                                        he semaphore:
Mutex at 0x7fa645483d30 '&buf_pool->flush_state_mutex', lock var 1
Last time reserved by thread 140351536850688 in file not yet reserved line 0, wa                                                                                        iters flag 1
OS WAIT ARRAY INFO: signal count 130124
Mutex spin waits 455655, rounds 1884512, OS waits 46773
RW-shared spins 35029, rounds 1012877, OS waits 27805
RW-excl spins 46443, rounds 1833895, OS waits 40830
Spin rounds per wait: 4.14 mutex, 28.92 RW-shared, 39.49 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 10183618
Purge done for trx's n:o < 10183618 undo n:o < 0 state: running but idle
History list length 2
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 12173, OS thread handle 0x7fa622d52700, query id 462934 localhos                                                                                        t root init
SHOW ENGINE INNODB STATUS
---TRANSACTION 10183484, not started flushing log
mysql tables in use 1, locked 1
MySQL thread id 12205, OS thread handle 0x7fa632b68700, query id 462811 localhos                                                                                        t slsu21_slsu21 query end
UPDATE wp_wppa_session
                                                                           SET c                                                                                        ount = 51 WHERE id = 0
---TRANSACTION 10183476, not started flushing log
mysql tables in use 1, locked 1
MySQL thread id 12201, OS thread handle 0x7fa632bb3700, query id 462803 localhos                                                                                        t slsu21_slsu21 query end
UPDATE wp_wppa_session
                                                          SET data = 'a:20:{s:4:                                                                                        \"ajax\";s:1:\"0\";s:20:\"display_searchstring\";s:0:\"\";s:13:\"has_searchbox\"                                                                                        ;b:0;s:2:\"id\";s:1:\"0\";s:12:\"is_wppa_tree\";b:0;s:7:\"isrobot\";b:1;s:4:\"pa                                                                                        ge\";i:39;s:8:\"randseed\";i:1546;s:12:\"randseedtime\";i:1602030407;s:7:\"rem_u                                                                                        rl\";a:0:{}s:7:\"rootbox\";b:0;s:11:\"search_root\";s:0:\"\";s:6:\"subbox\";b:0;                                                                                        s:10:\"superalbum\";s:1:\"0\";s:11:\"supersearch\";s:0:\"\";s:9:\"superview\";s:                                                                                        6:\"thumbs\";s:4:\"uris\";a:39:{i:0;s:55:\"12:23 /wp-content/uploads/2015/09/sls                                                                                        u_logo-300x300.png\";i:1;s:7:\"12:23 /\";i:2;s:7:\"12:24 /\";i:3;
---TRANSACTION 9771523, not started
MySQL thread id 1, OS thread handle 0x7fa64ab49700, query id 0 Waiting for reque                                                                                        sts
---TRANSACTION 10183615, ACTIVE 1 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 10 lock struct(s), heap size 2936, 1 row lock(s)
MySQL thread id 12200, OS thread handle 0x7fa629def700, query id 462933 localhos                                                                                        t slsu21_slsu21 updating
UPDATE wp_wppa_session
                                                          SET data = 'a:20:{s:4:                                                                                        \"ajax\";s:1:\"0\";s:20:\"display_searchstring\";s:0:\"\";s:13:\"has_searchbox\"                                                                                        ;b:0;s:2:\"id\";s:1:\"0\";s:12:\"is_wppa_tree\";b:0;s:7:\"isrobot\";b:1;s:4:\"pa                                                                                        ge\";i:38;s:8:\"randseed\";i:1544;s:12:\"randseedtime\";i:1602030405;s:7:\"rem_u                                                                                        rl\";a:0:{}s:7:\"rootbox\";b:0;s:11:\"search_root\";s:0:\"\";s:6:\"subbox\";b:0;                                                                                        s:10:\"superalbum\";s:1:\"0\";s:11:\"supersearch\";s:0:\"\";s:9:\"superview\";s:                                                                                        6:\"thumbs\";s:4:\"uris\";a:38:{i:0;s:55:\"12:23 /wp-content/uploads/2015/09/sls                                                                                        u_logo-300x300.png\";i:1;s:7:\"12:23 /\";i:2;s:7:\"12:24 /\";i:3;
Trx #rec lock waits 3 #table lock waits 0
Trx total rec lock wait time 9 SEC
Trx total table lock wait time 0 SEC
------- TRX HAS BEEN WAITING 1 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 144 page no 5530 n bits 72 index `GEN_CLUST_INDEX` of tabl                                                                                        e `slsu21sample`.`wp_wppa_session` trx table locks 1 total table locks 6  trx id                                                                                         10183615 lock_mode X waiting lock hold time 1 wait time before grant 0
------------------
---TRANSACTION 10183547, ACTIVE 2 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 12 lock struct(s), heap size 2936, 1 row lock(s)
MySQL thread id 12206, OS thread handle 0x7fa6449a0700, query id 462871 localhos                                                                                        t slsu21_slsu21 updating
UPDATE wp_wppa_session
                                                                           SET c                                                                                        ount = 51 WHERE id = 0
Trx #rec lock waits 1 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
------- TRX HAS BEEN WAITING 2 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 144 page no 5530 n bits 72 index `GEN_CLUST_INDEX` of tabl                                                                                        e `slsu21sample`.`wp_wppa_session` trx table locks 1 total table locks 6  trx id                                                                                         10183547 lock_mode X waiting lock hold time 1 wait time before grant 0
------------------
---TRANSACTION 10183501, ACTIVE 3 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 12 lock struct(s), heap size 2936, 1 row lock(s)
MySQL thread id 12204, OS thread handle 0x7fa64aa68700, query id 462824 localhos                                                                                        t slsu21_slsu21 updating
UPDATE wp_wppa_session
                                                          SET data = 'a:20:{s:4:                                                                                        \"ajax\";s:1:\"0\";s:20:\"display_searchstring\";s:0:\"\";s:13:\"has_searchbox\"                                                                                        ;b:0;s:2:\"id\";s:1:\"0\";s:12:\"is_wppa_tree\";b:0;s:7:\"isrobot\";b:1;s:4:\"pa                                                                                        ge\";i:38;s:8:\"randseed\";i:1505;s:12:\"randseedtime\";i:1602030366;s:7:\"rem_u                                                                                        rl\";a:0:{}s:7:\"rootbox\";b:0;s:11:\"search_root\";s:0:\"\";s:6:\"subbox\";b:0;                                                                                        s:10:\"superalbum\";s:1:\"0\";s:11:\"supersearch\";s:0:\"\";s:9:\"superview\";s:                                                                                        6:\"thumbs\";s:4:\"uris\";a:38:{i:0;s:55:\"12:23 /wp-content/uploads/2015/09/sls                                                                                        u_logo-300x300.png\";i:1;s:7:\"12:23 /\";i:2;s:7:\"12:24 /\";i:3;
Trx #rec lock waits 2 #table lock waits 0
Trx total rec lock wait time 2 SEC
Trx total table lock wait time 0 SEC
------- TRX HAS BEEN WAITING 3 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 144 page no 5530 n bits 72 index `GEN_CLUST_INDEX` of tabl                                                                                        e `slsu21sample`.`wp_wppa_session` trx table locks 1 total table locks 6  trx id                                                                                         10183501 lock_mode X waiting lock hold time 1 wait time before grant 0
------------------
---TRANSACTION 10183500, ACTIVE 3 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 12 lock struct(s), heap size 2936, 1 row lock(s)
MySQL thread id 12203, OS thread handle 0x7fa63295b700, query id 462823 localhos                                                                                        t slsu21_slsu21 updating
UPDATE wp_wppa_session
                                                          SET data = 'a:20:{s:4:                                                                                        \"ajax\";s:1:\"0\";s:20:\"display_searchstring\";s:0:\"\";s:13:\"has_searchbox\"                                                                                        ;b:0;s:2:\"id\";s:1:\"0\";s:12:\"is_wppa_tree\";b:0;s:7:\"isrobot\";b:1;s:4:\"pa                                                                                        ge\";i:38;s:8:\"randseed\";i:1505;s:12:\"randseedtime\";i:1602030366;s:7:\"rem_u                                                                                        rl\";a:0:{}s:7:\"rootbox\";b:0;s:11:\"search_root\";s:0:\"\";s:6:\"subbox\";b:0;                                                                                        s:10:\"superalbum\";s:1:\"0\";s:11:\"supersearch\";s:0:\"\";s:9:\"superview\";s:                                                                                        6:\"thumbs\";s:4:\"uris\";a:38:{i:0;s:55:\"12:23 /wp-content/uploads/2015/09/sls                                                                                        u_logo-300x300.png\";i:1;s:7:\"12:23 /\";i:2;s:7:\"12:24 /\";i:3;
Trx #rec lock waits 2 #table lock waits 0
Trx total rec lock wait time 6 SEC
Trx total table lock wait time 0 SEC
------- TRX HAS BEEN WAITING 3 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 144 page no 5530 n bits 72 index `GEN_CLUST_INDEX` of tabl                                                                                        e `slsu21sample`.`wp_wppa_session` trx table locks 1 total table locks 6  trx id                                                                                         10183500 lock_mode X waiting lock hold time 1 wait time before grant 0
------------------
---TRANSACTION 10183499, ACTIVE 3 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 12 lock struct(s), heap size 2936, 1 row lock(s)
MySQL thread id 12197, OS thread handle 0x7fa6448bf700, query id 462822 localhos                                                                                        t slsu21_slsu21 updating
UPDATE wp_wppa_session
                                                          SET data = 'a:20:{s:4:                                                                                        \"ajax\";s:1:\"0\";s:20:\"display_searchstring\";s:0:\"\";s:13:\"has_searchbox\"                                                                                        ;b:0;s:2:\"id\";s:1:\"0\";s:12:\"is_wppa_tree\";b:0;s:7:\"isrobot\";b:1;s:4:\"pa                                                                                        ge\";i:38;s:8:\"randseed\";i:1505;s:12:\"randseedtime\";i:1602030366;s:7:\"rem_u                                                                                        rl\";a:0:{}s:7:\"rootbox\";b:0;s:11:\"search_root\";s:0:\"\";s:6:\"subbox\";b:0;                                                                                        s:10:\"superalbum\";s:1:\"0\";s:11:\"supersearch\";s:0:\"\";s:9:\"superview\";s:                                                                                        6:\"thumbs\";s:4:\"uris\";a:38:{i:0;s:55:\"12:23 /wp-content/uploads/2015/09/sls                                                                                        u_logo-300x300.png\";i:1;s:7:\"12:23 /\";i:2;s:7:\"12:24 /\";i:3;
Trx #rec lock waits 4 #table lock waits 0
Trx total rec lock wait time 13 SEC
Trx total table lock wait time 0 SEC
------- TRX HAS BEEN WAITING 3 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 144 page no 5530 n bits 72 index `GEN_CLUST_INDEX` of tabl                                                                                        e `slsu21sample`.`wp_wppa_session` trx table locks 1 total table locks 6  trx id                                                                                         10183499 lock_mode X waiting lock hold time 1 wait time before grant 0
------------------
---TRANSACTION 10183496, ACTIVE 3 sec updating or deleting
mysql tables in use 1, locked 1
40 lock struct(s), heap size 6544, 214 row lock(s), undo log entries 177
MySQL thread id 12202, OS thread handle 0x7fa632910700, query id 462819 localhos                                                                                        t slsu21_slsu21 updating
UPDATE wp_wppa_session
                                                          SET data = 'a:20:{s:4:                                                                                        \"ajax\";s:1:\"0\";s:20:\"display_searchstring\";s:0:\"\";s:13:\"has_searchbox\"                                                                                        ;b:0;s:2:\"id\";s:1:\"0\";s:12:\"is_wppa_tree\";b:0;s:7:\"isrobot\";b:1;s:4:\"pa                                                                                        ge\";i:39;s:8:\"randseed\";i:1505;s:12:\"randseedtime\";i:1602030366;s:7:\"rem_u                                                                                        rl\";a:0:{}s:7:\"rootbox\";b:0;s:11:\"search_root\";s:0:\"\";s:6:\"subbox\";b:0;                                                                                        s:10:\"superalbum\";s:1:\"0\";s:11:\"supersearch\";s:0:\"\";s:9:\"superview\";s:                                                                                        6:\"thumbs\";s:4:\"uris\";a:39:{i:0;s:55:\"12:23 /wp-content/uploads/2015/09/sls                                                                                        u_logo-300x300.png\";i:1;s:7:\"12:23 /\";i:2;s:7:\"12:24 /\";i:3;
Trx #rec lock waits 2 #table lock waits 0
Trx total rec lock wait time 9 SEC
Trx total table lock wait time 0 SEC
--------
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: complete io for buf page (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 1; buffer pool: 1
402196 OS file reads, 2644774 OS file writes, 113928 OS fsyncs
24.71 reads/s, 16384 avg bytes/read, 311.96 writes/s, 15.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 14, seg size 16, 18 merges
merged operations:
 insert 6, delete mark 214, delete 113
discarded operations:
 insert 0, delete mark 0, delete 0
405.66 hash searches/s, 1771.89 non-hash searches/s
---
LOG
---
Log sequence number 1621794988506
Log flushed up to   1621789731409
Pages flushed up to 1621719211657
Last checkpoint at  1621717428755
Max checkpoint age    80826164
Checkpoint age target 78300347
Modified age          75776849
Checkpoint age        77559751
1 pending log writes, 0 pending chkp writes
34408 log i/o's done, 6.29 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 140574720; in additional pool allocated 0
Total memory allocated by read views 1448
Internal hash tables (constant factor + variable factor)
    Adaptive hash index 2348640         (2213368 + 135272)
    Page hash           139112 (buffer pool 0 only)
    Dictionary cache    987448  (554768 + 432680)
    File system         939040  (812272 + 126768)
    Lock system         355536  (332872 + 22664)
    Recovery system     0       (0 + 0)
Dictionary memory allocated 432680
Buffer pool size        8191
Buffer pool size, bytes 134201344
Free buffers            734
Database pages          7449
Old database pages      2729
Modified db pages       3021
Percent of dirty pages(LRU & free pages): 36.913
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 1, flush list 2, single page 0
Pages made young 2078449, not young 6582871
4.71 youngs/s, 408.80 non-youngs/s
Pages read 402050, created 1215951, written 2555270
24.71 reads/s, 247.11 creates/s, 299.96 writes/s
Buffer pool hit rate 999 / 1000, young-making rate 0 / 1000 not 7 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 7449, unzip_LRU len: 0
I/O sum[18274]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
6 RW transactions active inside InnoDB
0 RO transactions active inside InnoDB
6 out of 1000 descriptors used
Main thread process no. 1309, id 140351478150912, state: sleeping
Number of rows inserted 3114, updated 13991202, deleted 2911, read 201211675
0.14 inserts/s, 4242.68 updates/s, 0.29 deletes/s, 32621.05 reads/s
Number of system rows inserted 0, updated 0, deleted 0, read 2
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

Solution

  • Ok. So I have done what @nbk told me to do, I have removed all the unnecessary updates in my database and finally, the flooding stopped.