SUMMARY Quite often I'm running into transaction deadlocks when I delete spam email via `shift + delete`. When that happens a dialog pops up with an (infinite) progress bar saying "please wait while the message is transferred". The only way to get out of this situation is to cancel the operation, then quit kontact/kmail and restart it. It seems like that's enough to fix the deadlock, afterwards - i.e. even without a mariadb/akonadi restart - I can usually delete the spam with `shift + delete` just fine. STEPS TO REPRODUCE 1. start akonadi with mariadb 2. open kmail/kontact 3. shift + delete spam mail OBSERVED RESULT infinite progress bar in dialog In `journalctl -xe` I found these messages when it happened just now: ``` Mär 21 10:45:19 agathebauer kmail[1317]: org.kde.pim.akonadicore: Received response with a different tag! Mär 21 10:46:20 agathebauer akonadi_maildispatcher_agent[1586]: void SendJob::setFrom(const QString &from) "mail@milianw.de" Mär 21 10:46:20 agathebauer akonadi_maildispatcher_agent[1586]: d->m_returnPath "<mail@milianw.de>" Mär 21 10:46:20 agathebauer akonadiserver[1305]: org.kde.pim.akonadiserver: QueryBuilder::exec(): database reported transaction deadlock, retrying transaction Mär 21 10:46:20 agathebauer akonadiserver[1305]: org.kde.pim.akonadiserver: "Deadlock found when trying to get lock; try restarting transaction QMYSQL3: Unable to execute statement" Mär 21 10:46:20 agathebauer akonadi_imap_resource[1583]: org.kde.pim.imapresource: "Connection to server lost." ``` I then connected to the akonadi socket with `mariadb` and ran `SHOW ENGINE INNODB STATUS`. This gave me the following output: ``` | InnoDB | | ===================================== 2021-03-21 10:57:00 0x7fdc8ddf1640 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 2 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 135 srv_active, 0 srv_shutdown, 3646 srv_idle srv_master_thread log flush and writes: 3781 ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 75 OS WAIT ARRAY INFO: signal count 757 RW-shared spins 92, rounds 1706, OS waits 33 RW-excl spins 241, rounds 874, OS waits 23 RW-sx spins 0, rounds 0, OS waits 0 Spin rounds per wait: 18.54 RW-shared, 3.63 RW-excl, 0.00 RW-sx ------------------------ LATEST DETECTED DEADLOCK ------------------------ 2021-03-21 10:54:33 0x7fdc8f529640 *** (1) TRANSACTION: TRANSACTION 2784938, ACTIVE 0 sec starting index read mysql tables in use 6, locked 6 LOCK WAIT 3 lock struct(s), heap size 1128, 2 row lock(s) MySQL thread id 88, OS thread handle 140585223026240, query id 48135 localhost milian Updating UPDATE PimItemTable SET atime = ? WHERE ( ( PimItemTable.id = ? ) ) *** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 26 page no 7928 n bits 192 index PRIMARY of table `akonadi`.`pimitemtable` trx id 2784938 lock_mode X locks rec but not gap waiting Record lock, heap no 19 PHYSICAL RECORD: n_fields 13; compact format; info bits 0 0: len 8; hex 8000000000127f07; asc ;; 1: len 6; hex 000000000000; asc ;; 2: len 7; hex 80000000000000; asc ;; 3: len 4; hex 80000001; asc ;; 4: len 5; hex 3337323334; asc 37234;; 5: SQL NULL; 6: SQL NULL; 7: len 8; hex 8000000000000081; asc ;; 8: len 8; hex 8000000000000003; asc ;; 9: len 4; hex 605709c9; asc `W ;; 10: len 4; hex 605709c9; asc `W ;; 11: len 1; hex 80; asc ;; 12: len 8; hex 800000000000716b; asc qk;; *** (2) TRANSACTION: TRANSACTION 2784936, ACTIVE 0 sec starting index read mysql tables in use 6, locked 6 6 lock struct(s), heap size 1128, 3 row lock(s), undo log entries 1 MySQL thread id 89, OS thread handle 140585274086976, query id 48139 localhost milian Updating UPDATE PimItemTable SET rev = ?, remoteId = ?, remoteRevision = ?, gid = ?, collectionId = ?, mimeTypeId = ?, datetime = ?, atime = ?, dirty = ?, size = ? WHERE ( id = ? ) *** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 26 page no 7928 n bits 192 index PRIMARY of table `akonadi`.`pimitemtable` trx id 2784936 lock_mode X locks rec but not gap Record lock, heap no 19 PHYSICAL RECORD: n_fields 13; compact format; info bits 0 0: len 8; hex 8000000000127f07; asc ;; 1: len 6; hex 000000000000; asc ;; 2: len 7; hex 80000000000000; asc ;; 3: len 4; hex 80000001; asc ;; 4: len 5; hex 3337323334; asc 37234;; 5: SQL NULL; 6: SQL NULL; 7: len 8; hex 8000000000000081; asc ;; 8: len 8; hex 8000000000000003; asc ;; 9: len 4; hex 605709c9; asc `W ;; 10: len 4; hex 605709c9; asc `W ;; 11: len 1; hex 80; asc ;; 12: len 8; hex 800000000000716b; asc qk;; *** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 26 page no 7650 n bits 1112 index PimItemTable_idSortIndex of table `akonadi`.`pimitemtable` trx id 2784936 lock_mode X locks rec but not gap waiting Record lock, heap no 948 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 0: len 8; hex 8000000000127f07; asc ;; *** WE ROLL BACK TRANSACTION (1) ------------ TRANSACTIONS ------------ Trx id counter 2784989 Purge done for trx's n:o < 2784989 undo n:o < 0 state: running History list length 4 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 422060467078680, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467121320, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467117056, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467112792, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467082944, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467061624, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467108528, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467104264, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467100000, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467095736, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467091472, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467087208, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467074416, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467070152, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467065888, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467155432, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467057360, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467053096, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467048832, not started 0 lock struct(s), heap size 1128, 0 row lock(s) ---TRANSACTION 422060467044568, not started 0 lock struct(s), heap size 1128, 0 row lock(s) -------- FILE I/O -------- Pending normal aio reads: Pending flushes (fsync) log: 0; buffer pool: 0 277927 OS file reads, 1101 OS file writes, 206 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 5, free list len 544, seg size 550, 26 merges merged operations: insert 82, delete mark 154, delete 133 discarded operations: insert 0, delete mark 0, delete 0 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 8488738784 Log flushed up to 8488738784 Pages flushed up to 8488068579 Last checkpoint at 8488068460 0 pending log flushes, 0 pending chkp writes 635 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total large memory allocated 136314880 Dictionary memory allocated 909864 Buffer pool size 8065 Free buffers 0 Database pages 8065 Old database pages 2957 Modified db pages 275 Percent of dirty pages(LRU & free pages): 3.409 Max dirty pages percent: 90.000 Pending reads 0 Pending writes: LRU 0, flush list 0 Pages made young 8037, not young 14011713 0.00 youngs/s, 0.00 non-youngs/s Pages read 277884, created 173, written 455 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: 8065, unzip_LRU len: 0 I/O sum[25]:cur[0], unzip sum[0]:cur[0] -------------- ROW OPERATIONS -------------- 0 read views open inside InnoDB Process ID=0, Main thread ID=0, state: sleeping Number of rows inserted 484, updated 681, deleted 269, read 27172097 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s Number of system rows inserted 0, updated 0, deleted 0, read 0 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ ``` EXPECTED RESULT no deadlock SOFTWARE/OS VERSIONS Linux/KDE Plasma: 5.10.24-1-lts KDE Plasma Version: 5.21.3 KDE Frameworks Version: 5.21.3 Qt Version: 5.15.2 mariadb 15.1
This annoying problem occurs as well with postgres (which I use as backend), even in latest version, and independent if I use shift-del or just delete. aonadictl fsck|vaccum does not help, partly restarting the akonadi server helps, but thats not granted. If one lets me know how I can debug that issue, happy to do! Operating System: openSUSE Tumbleweed 20240416 KDE Plasma Version: 6.0.3 KDE Frameworks Version: 6.1.0 Qt Version: 6.7.0