Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss

Bug#1010576: akonadi-server: Akonadi/Kontact hangs after resuming from standby

64 views
Skip to first unread message

CH

unread,
May 4, 2022, 2:50:03 PM5/4/22
to
Package: akonadi-server
Version: 4:21.12.3-2
Severity: normal
X-Debbugs-Cc: gi...@leonde.de

Dear Maintainer,

kontact reliably gets unusable after resmuing from standby. I've been using
kontact for years, and I think this started with the update of KDE Framework to
5.90,
The UI is still responsive, but accessing mails or switching folders does not
have any effect. Switching to a different folder will display a progress page
and a spinning cog as the folder icon, but nothing else will ever happen, even
after hours. Quitting Kontact also doesn't work in this situation, I have to
kill it.

To get kontact working after resuming, I have to
- kill kontact
- stop akonadi
- kill mariadb
- start kontact

What does not help is:
- kill kontact
- start kontact
(same situation as before)

Neither:
- kill kontact
- stop akonadi
- start kontact

(This fails because akonadictl stop does not terminate mariadb. It does delete
the socket file though, so the new akonadi instance cannot talk to it).

Note that when kontact/akonadi hangs after resume, I can access mariadb just
fine. It's just that the chain mariadb <-> akonadi <-> kontact is somehow
broken.

Thanks!


-- System Information:
Debian Release: bookworm/sid
APT prefers unstable
APT policy: (500, 'unstable')
Architecture: amd64 (x86_64)

Kernel: Linux 5.17.0-1-amd64 (SMP w/8 CPU threads; PREEMPT)
Kernel taint flags: TAINT_OOT_MODULE, TAINT_UNSIGNED_MODULE
Locale: LANG=de_DE.UTF-8, LC_CTYPE=de_DE.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages akonadi-server depends on:
ii akonadi-backend-mysql 4:21.12.3-2
ii libaccounts-qt5-1 1.16-2
ii libc6 2.33-7
ii libgcc-s1 12-20220428-1
ii libkf5akonadiprivate5abi2 [libkf5akonadiprivate5-21.12] 4:21.12.3-2
ii libkf5akonadiwidgets5abi1 [libkf5akonadiwidgets5-21.12] 4:21.12.3-2
ii libkf5configcore5 5.90.0-1
ii libkf5coreaddons5 5.90.0-1
ii libkf5crash5 5.90.0-1
ii libkf5i18n5 5.90.0-1
ii libqt5core5a 5.15.2+dfsg-16+b1
ii libqt5dbus5 5.15.2+dfsg-16+b1
ii libqt5gui5 5.15.2+dfsg-16+b1
ii libqt5network5 5.15.2+dfsg-16+b1
ii libqt5sql5 5.15.2+dfsg-16+b1
ii libqt5widgets5 5.15.2+dfsg-16+b1
ii libqt5xml5 5.15.2+dfsg-16+b1
ii libstdc++6 12-20220428-1

akonadi-server recommends no packages.

Versions of packages akonadi-server suggests:
ii akonadi-backend-mysql 4:21.12.3-2
pn akonadi-backend-postgresql <none>
pn akonadi-backend-sqlite <none>

-- no debconf information

Frank Mehnert

unread,
May 6, 2022, 4:30:04 PM5/6/22
to
Exact same behavior here. I have this behavior for about 6-8 weeks. After each resume I have to stop akonadi and then kill mariadb (normal kill is nossible due to apparmor, only kill -9 works). After that, akonadi works again.

Thanks!

gi...@leonde.de

unread,
May 7, 2022, 3:00:03 AM5/7/22
to
Exactly, but be careful with kill -9. I once broke my database with it such that mariadb would not even start anymore. I had to delete the entire directory and let akonadi recreate it from scratch.

Frank Mehnert

unread,
May 30, 2022, 3:10:03 PM5/30/22
to
I really wonder if this hang has something to do with a dedicated setup
because not many users seem to be affected. Nevertheless the bug is really
annoying.

gi...@leonde.de

unread,
Jun 9, 2022, 4:20:03 PM6/9/22
to

I collected some information that might help with debugging, unfortunately some output uses German localization, I can translate these if needed:


In the shell where I started akonadi with akonadictl start, I got this output (many

lines duplicated and removed for brevity):


"Das Objekt existiert nicht am Pfad »/org/freedesktop/NetworkManager/ActiveConnection/2«"

[...]

org.kde.pim.kimap: Connection to server lost  QAbstractSocket::HostNotFoundError

[...]

QIODevice::write (QSslSocket): device not open

org.kde.pim.kimap: Connection to server lost  QAbstractSocket::NetworkError

org.kde.pim.kimap: Connection to server lost  QAbstractSocket::NetworkError

org.kde.pim.kimap: Connection to server lost  QAbstractSocket::HostNotFoundError

org.kde.pim.kimap: Connection to server lost  QAbstractSocket::HostNotFoundError

[...]

"Das Objekt existiert nicht am Pfad »/org/freedesktop/NetworkManager/ActiveConnection/2«"

[...]

QIODevice::write (QSslSocket): device not open

org.kde.pim.kimap: Connection to server lost  QAbstractSocket::RemoteHostClosedError

org.kde.pim.kimap: Connection to server lost  QAbstractSocket::NetworkError

[...]

"Das Objekt existiert nicht am Pfad »/org/freedesktop/NetworkManager/ActiveConnection/2«"

[...]

QIODevice::write (QSslSocket): device not open

"Das Objekt existiert nicht am Pfad »/org/freedesktop/NetworkManager/ActiveConnection/2«"

[...]

QIODevice::write (QSslSocket): device not open

org.kde.pim.akonadiserver.search: Executing search "kontact-2268689595-SearchSession"

org.kde.pim.akonadiserver.search: Search  "kontact-2268689595-SearchSession" done (without remote search)

org.kde.pim.akonadiserver.search: Executing search "kontact-2268689595-SearchSession"

org.kde.pim.akonadiserver.search: Search  "kontact-2268689595-SearchSession" done (without remote search)

org.kde.pim.akonadiserver.search: Executing search "kontact-2268689595-SearchSession"

[...]

org.kde.pim.akonadiserver: QueryBuilder::exec(): database reported transaction timeout, retrying transaction

org.kde.pim.akonadiserver: "Lock wait timeout exceeded; try restarting transaction QMYSQL3: Der Befehl konnte nicht ausgeführt werden"

org.kde.pim.akonadiserver: QueryBuilder::exec(): database reported transaction timeout, retrying transaction

org.kde.pim.akonadiserver: "Lock wait timeout exceeded; try restarting transaction QMYSQL3: Der Befehl konnte nicht ausgeführt werden"



stracing akonadiserver shows this for example:


[pid 110942] write(10, "\1\0\0\0\0\0\0\0", 8) = 8

[pid 110942] poll([{fd=10, events=POLLIN}, {fd=26, events=POLLIN}, {fd=28, events=POLLIN}, {fd=36, events=POLLIN}, {fd=38, events=POLLIN}, {fd=42, events=POLLIN}, {fd=47, events=POLLIN}, {fd=52, events=POLLIN}, {fd=61, events=POLLIN}, {fd=69, events=POLLIN}, {fd=76, events=POLLIN}, {fd=77, events=POLLIN}, {fd=79, events=POLLIN}, {fd=86, events=POLLIN}, {fd=89, events=POLLIN}, {fd=90, events=POLLIN}, {fd=95, events=POLLIN}, {fd=96, events=POLLIN}, {fd=99, events=POLLIN}, {fd=100, events=POLLIN}, {fd=110, events=POLLIN}, {fd=114, events=POLLIN}, {fd=116, events=POLLIN}, {fd=121, events=POLLIN}, {fd=122, events=POLLIN}, {fd=125, events=POLLIN}, {fd=126, events=POLLIN}, {fd=129, events=POLLIN}, {fd=132, events=POLLIN}, {fd=136, events=POLLIN}, {fd=142, events=POLLIN}, {fd=146, events=POLLIN}, ...], 46, 48) = 1 ([{fd=10, revents=POLLIN}])

[pid 110942] read(10, "\2\0\0\0\0\0\0\0", 16) = 8

[pid 110942] poll([{fd=10, events=POLLIN}, {fd=26, events=POLLIN}, {fd=28, events=POLLIN}, {fd=36, events=POLLIN}, {fd=38, events=POLLIN}, {fd=42, events=POLLIN}, {fd=47, events=POLLIN}, {fd=52, events=POLLIN}, {fd=61, events=POLLIN}, {fd=69, events=POLLIN}, {fd=76, events=POLLIN}, {fd=77, events=POLLIN}, {fd=79, events=POLLIN}, {fd=86, events=POLLIN}, {fd=89, events=POLLIN}, {fd=90, events=POLLIN}, {fd=95, events=POLLIN}, {fd=96, events=POLLIN}, {fd=99, events=POLLIN}, {fd=100, events=POLLIN}, {fd=110, events=POLLIN}, {fd=114, events=POLLIN}, {fd=116, events=POLLIN}, {fd=121, events=POLLIN}, {fd=122, events=POLLIN}, {fd=125, events=POLLIN}, {fd=126, events=POLLIN}, {fd=129, events=POLLIN}, {fd=132, events=POLLIN}, {fd=136, events=POLLIN}, {fd=142, events=POLLIN}, {fd=146, events=POLLIN}, ...], 46, 47) = 0 (Timeout)


[...]


[pid 110942] read(89, "\3\0\0\0\0\0\0\0u\0\20\0\0\377\377\377\377\377\377\377\377\0\0\0\0\1\0\0\0\25\0\0"..., 70) = 70

[pid 110942] write(10, "\1\0\0\0\0\0\0\0", 8) = 8

[pid 110942] ppoll([{fd=89, events=POLLIN|POLLOUT}], 1, {tv_sec=30, tv_nsec=0}, NULL, 8) = 1 ([{fd=89, revents=POLLOUT}], left {tv_sec=29, tv_nsec=999996833})

[pid 110942] write(89, "\3\0\0\0\0\0\0\0\365\0\0\0\0\377\377\377\377", 17) = 17

[pid 110942] write(10, "\1\0\0\0\0\0\0\0", 8) = 8

[pid 110942] poll([{fd=10, events=POLLIN}, {fd=26, events=POLLIN}, {fd=28, events=POLLIN}, {fd=36, events=POLLIN}, {fd=38, events=POLLIN}, {fd=42, events=POLLIN}, {fd=47, events=POLLIN}, {fd=52, events=POLLIN}, {fd=61, events=POLLIN}, {fd=69, events=POLLIN}, {fd=76, events=POLLIN}, {fd=77, events=POLLIN}, {fd=79, events=POLLIN}, {fd=86, events=POLLIN}, {fd=89, events=POLLIN}, {fd=90, events=POLLIN}, {fd=95, events=POLLIN}, {fd=96, events=POLLIN}, {fd=99, events=POLLIN}, {fd=100, events=POLLIN}, {fd=110, events=POLLIN}, {fd=114, events=POLLIN}, {fd=116, events=POLLIN}, {fd=121, events=POLLIN}, {fd=122, events=POLLIN}, {fd=125, events=POLLIN}, {fd=126, events=POLLIN}, {fd=129, events=POLLIN}, {fd=132, events=POLLIN}, {fd=136, events=POLLIN}, {fd=142, events=POLLIN}, {fd=146, events=POLLIN}, ...], 46, 51) = 1 ([{fd=10, revents=POLLIN}])

[pid 110942] read(10, "\2\0\0\0\0\0\0\0", 16) = 8

[pid 110942] poll([{fd=10, events=POLLIN}, {fd=26, events=POLLIN}, {fd=28, events=POLLIN}, {fd=36, events=POLLIN}, {fd=38, events=POLLIN}, {fd=42, events=POLLIN}, {fd=47, events=POLLIN}, {fd=52, events=POLLIN}, {fd=61, events=POLLIN}, {fd=69, events=POLLIN}, {fd=76, events=POLLIN}, {fd=77, events=POLLIN}, {fd=79, events=POLLIN}, {fd=86, events=POLLIN}, {fd=89, events=POLLIN}, {fd=90, events=POLLIN}, {fd=95, events=POLLIN}, {fd=96, events=POLLIN}, {fd=99, events=POLLIN}, {fd=100, events=POLLIN}, {fd=110, events=POLLIN}, {fd=114, events=POLLIN}, {fd=116, events=POLLIN}, {fd=121, events=POLLIN}, {fd=122, events=POLLIN}, {fd=125, events=POLLIN}, {fd=126, events=POLLIN}, {fd=129, events=POLLIN}, {fd=132, events=POLLIN}, {fd=136, events=POLLIN}, {fd=142, events=POLLIN}, {fd=146, events=POLLIN}, ...], 46, 50) = 0 (Timeout)


[...]


[pid 110942] read(89, "\3\0\0\0\0\0\0\0u\0\20\0\0\377\377\377\377\377\377\377\377\0\0\0\0\1\0\0\0\25\0\0"..., 70) = 70

[pid 110942] write(10, "\1\0\0\0\0\0\0\0", 8) = 8

[pid 110942] ppoll([{fd=89, events=POLLIN|POLLOUT}], 1, {tv_sec=30, tv_nsec=0}, NULL, 8) = 1 ([{fd=89, revents=POLLOUT}], left {tv_sec=29, tv_nsec=999996833})

[pid 110942] write(89, "\3\0\0\0\0\0\0\0\365\0\0\0\0\377\377\377\377", 17) = 17

[pid 110942] write(10, "\1\0\0\0\0\0\0\0", 8) = 8

[pid 110942] poll([{fd=10, events=POLLIN}, {fd=26, events=POLLIN}, {fd=28, events=POLLIN}, {fd=36, events=POLLIN}, {fd=38, events=POLLIN}, {fd=42, events=POLLIN}, {fd=47, events=POLLIN}, {fd=52, events=POLLIN}, {fd=61, events=POLLIN}, {fd=69, events=POLLIN}, {fd=76, events=POLLIN}, {fd=77, events=POLLIN}, {fd=79, events=POLLIN}, {fd=86, events=POLLIN}, {fd=89, events=POLLIN}, {fd=90, events=POLLIN}, {fd=95, events=POLLIN}, {fd=96, events=POLLIN}, {fd=99, events=POLLIN}, {fd=100, events=POLLIN}, {fd=110, events=POLLIN}, {fd=114, events=POLLIN}, {fd=116, events=POLLIN}, {fd=121, events=POLLIN}, {fd=122, events=POLLIN}, {fd=125, events=POLLIN}, {fd=126, events=POLLIN}, {fd=129, events=POLLIN}, {fd=132, events=POLLIN}, {fd=136, events=POLLIN}, {fd=142, events=POLLIN}, {fd=146, events=POLLIN}, ...], 46, 51) = 1 ([{fd=10, revents=POLLIN}])

[pid 110942] read(10, "\2\0\0\0\0\0\0\0", 16) = 8

[pid 110942] poll([{fd=10, events=POLLIN}, {fd=26, events=POLLIN}, {fd=28, events=POLLIN}, {fd=36, events=POLLIN}, {fd=38, events=POLLIN}, {fd=42, events=POLLIN}, {fd=47, events=POLLIN}, {fd=52, events=POLLIN}, {fd=61, events=POLLIN}, {fd=69, events=POLLIN}, {fd=76, events=POLLIN}, {fd=77, events=POLLIN}, {fd=79, events=POLLIN}, {fd=86, events=POLLIN}, {fd=89, events=POLLIN}, {fd=90, events=POLLIN}, {fd=95, events=POLLIN}, {fd=96, events=POLLIN}, {fd=99, events=POLLIN}, {fd=100, events=POLLIN}, {fd=110, events=POLLIN}, {fd=114, events=POLLIN}, {fd=116, events=POLLIN}, {fd=121, events=POLLIN}, {fd=122, events=POLLIN}, {fd=125, events=POLLIN}, {fd=126, events=POLLIN}, {fd=129, events=POLLIN}, {fd=132, events=POLLIN}, {fd=136, events=POLLIN}, {fd=142, events=POLLIN}, {fd=146, events=POLLIN}, ...], 46, 50) = 0 (Timeout)


where these are the fds:


/proc/110844/fd/3 -> 'anon_inode:[eventfd]'

/proc/110844/fd/10 -> 'anon_inode:[eventfd]'

/proc/110844/fd/12 -> 'socket:[1607100]'

/proc/110844/fd/13 -> 'socket:[1607099]'

/proc/110844/fd/15 -> 'anon_inode:[pidfd]'



in systemd journal I get these entries on akonadi startup:


Mai 17 14:00:55 nb-carsten2 audit[112786]: AVC apparmor="DENIED" operation="signal" profile="/usr/bin/akonadiserver" pid=112786 comm="akonadiserver" requested_mask="send" denied_mask="send" signal=term peer="unconfined"

Mai 17 14:00:55 nb-carsten2 kernel: audit: type=1400 audit(1652788855.201:5271): apparmor="DENIED" operation="signal" profile="/usr/bin/akonadiserver" pid=112786 comm="akonadiserver" requested_mask="send" denied_mask="send" signal=term peer="unconfined"

Mai 17 14:00:58 nb-carsten2 audit[112786]: AVC apparmor="DENIED" operation="signal" profile="/usr/bin/akonadiserver" pid=112786 comm="akonadiserver" requested_mask="send" denied_mask="send" signal=kill peer="unconfined"

Mai 17 14:00:58 nb-carsten2 kernel: audit: type=1400 audit(1652788858.205:5272): apparmor="DENIED" operation="signal" profile="/usr/bin/akonadiserver" pid=112786 comm="akonadiserver" requested_mask="send" denied_mask="send" signal=kill peer="unconfined"

Mai 17 14:00:58 nb-carsten2 org.freedesktop.Akonadi.Control[112783]: org.kde.pim.akonadicontrol: Application '/usr/bin/akonadiserver' exited normally...



and from longer ago (LOTS of these):


Apr 22 21:16:48 myhost dbus-daemon[2012]: [session uid=1000 pid=2012] The maximum number of pending replies for ":1.3368" (uid=1000 pid=239452 comm="/usr/bin/akonadi_imap_resource --identifier akonad") has been reached (max_replies_per_connection=50000)


I have these dbus processes (+ system messagebus)

Mai17   1:12 /usr/bin/dbus-daemon --session --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only

Mai17   0:12 /usr/bin/gmenudbusmenuproxy

Mai17   0:01 /usr/bin/dbus-daemon --config-file=/usr/share/defaults/at-spi2/accessibility.conf --nofork --print-address 11 --address=unix:path=/run/user/1000/at-spi/bus_0110849


And in .xsession-errors, I find this (alas, without timestamps, so maybe legit):


org.kde.pim.akonadicore: "QLocalSocket: Die Verbindung wurde von der Gegenseite geschlossen" "/run/user/1000/akonadi/akonadiserver-cmd.socket"

org.kde.pim.akonadicore: "QLocalSocket: Die Verbindung wurde von der Gegenseite geschlossen" "/run/user/1000/akonadi/akonadiserver-cmd.socket"

org.kde.pim.akonadicore: Socket error occurred: "QLocalSocket: Die Verbindung wurde von der Gegenseite geschlossen"

org.kde.pim.akonadicore: Socket error occurred: "QLocalSocket: Die Verbindung wurde von der Gegenseite geschlossen"

org.kde.pim.akonadicore: "QLocalSocket: Die Verbindung wurde von der Gegenseite geschlossen" "/run/user/1000/akonadi/akonadiserver-ntf.socket"


gi...@leonde.de

unread,
Jun 9, 2022, 4:50:03 PM6/9/22
to
Note that my previous message on https://bugs.debian.org/cgi-bin/
bugreport.cgi?bug=1010576 is incomplete, please see the referenced Message
Part 2 (https://bugs.debian.org/cgi-bin/bugreport.cgi?
att=1;bug=1010576;msg=25) for the full contents.

gi...@leonde.de

unread,
Jun 13, 2022, 5:20:03 PM6/13/22
to
It seems to me that indeed akonadiserver is the culprit. I kept kontact
running and only stopped akonadiserver, killed mariadb and resarted
akonadiserver. Then kontact started to work again.

More info: I suspect that this is due to a deadlock in the db updates,
akonadiserver even logs this:
org.kde.pim.akonadiserver: "Deadlock found when trying to get lock; try
restarting transaction QMYSQL3: Der Befehl konnte nicht ausgeführt werden"

So I had a look at mariadb like this:
mysql --socket=/run/user/1000/akonadi/mysql.socket

MariaDB [(none)]> show engine innodb status;
[...]
------------------------
LATEST DETECTED DEADLOCK
------------------------
2022-06-13 07:24:55 0x7f8a1c681640
*** (1) TRANSACTION:
TRANSACTION 78342, ACTIVE 0 sec starting index read
mysql tables in use 6, locked 6
LOCK WAIT 6 lock struct(s), heap size 1128, 3 row lock(s), undo log entries 1
MariaDB thread id 41, OS thread handle 140231158797888, query id 165472
localhost user Updating
UPDATE PimItemTable SET rev = ?, remoteId = ?, remoteRevision = ?, gid = ?,
collectionId = ?, mimeTypeId = ?, datetime = ?, atime = ?, dirty = ?, size = ?
WHERE ( id = ? )
*** WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 9 page no 3493 n bits 1080 index
PimItemTable_idSortIndex of table `akonadi`.`pimitemtable` trx id 78342
lock_mode X locks rec but not gap waiting
Record lock, heap no 855 PHYSICAL RECORD: n_fields 1; compact format; info
bits 0
0: len 8; hex 800000000004cb8d; asc ;;

*** CONFLICTING WITH:
RECORD LOCKS space id 9 page no 3493 n bits 1080 index
PimItemTable_idSortIndex of table `akonadi`.`pimitemtable` trx id 78344
lock_mode X locks rec but not gap
Record lock, heap no 855 PHYSICAL RECORD: n_fields 1; compact format; info
bits 0
0: len 8; hex 800000000004cb8d; asc ;;


*** (2) TRANSACTION:
TRANSACTION 78344, 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)
MariaDB thread id 40, OS thread handle 140231159105088, query id 165015
localhost user Updating
UPDATE PimItemTable SET atime = ? WHERE ( ( PimItemTable.id = ? ) )
*** WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 9 page no 3872 n bits 208 index PRIMARY of table
`akonadi`.`pimitemtable` trx id 78344 lock_mode X locks rec but not gap
waiting
Record lock, heap no 169 PHYSICAL RECORD: n_fields 13; compact format; info
bits 0
0: len 8; hex 800000000004cb8d; asc ;;
1: len 6; hex 000000013205; asc 2 ;;
2: len 7; hex 730000080d03f1; asc s ;;
3: len 4; hex 80000001; asc ;;
4: len 5; hex 3834383038; asc 84808;;
5: SQL NULL;
6: SQL NULL;
7: len 8; hex 8000000000000028; asc (;;
8: len 8; hex 8000000000000005; asc ;;
9: len 4; hex 62a6ae07; asc b ;;
10: len 4; hex 62a6ae07; asc b ;;
11: len 1; hex 80; asc ;;
12: len 8; hex 8000000000005f14; asc _ ;;

*** CONFLICTING WITH:
RECORD LOCKS space id 9 page no 3872 n bits 208 index PRIMARY of table
`akonadi`.`pimitemtable` trx id 78342 lock_mode X locks rec but not gap
Record lock, heap no 169 PHYSICAL RECORD: n_fields 13; compact format; info
bits 0
0: len 8; hex 800000000004cb8d; asc ;;
1: len 6; hex 000000013205; asc 2 ;;
2: len 7; hex 730000080d03f1; asc s ;;
3: len 4; hex 80000001; asc ;;
4: len 5; hex 3834383038; asc 84808;;
5: SQL NULL;
6: SQL NULL;
7: len 8; hex 8000000000000028; asc (;;
8: len 8; hex 8000000000000005; asc ;;
9: len 4; hex 62a6ae07; asc b ;;
10: len 4; hex 62a6ae07; asc b ;;
11: len 1; hex 80; asc ;;
12: len 8; hex 8000000000005f14; asc _ ;;

*** WE ROLL BACK TRANSACTION (0)
------------
TRANSACTIONS
------------
Trx id counter 78442
Purge done for trx's n:o < 78439 undo n:o < 0 state: running but idle
History list length 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 78441, ACTIVE 2344 sec inserting
mysql tables in use 1, locked 1
8 lock struct(s), heap size 1128, 4 row lock(s), undo log entries 427
MariaDB thread id 47, OS thread handle 140231558207040, query id 233232
localhost user Update
INSERT INTO PimItemTable (rev, remoteId, remoteRevision, gid, collectionId,
mimeTypeId, datetime, atime, dirty, size) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?,
?)
---TRANSACTION (0x7f8a422bcd80), not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION (0x7f8a422a4c80), not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION (0x7f8a422a4180), not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION (0x7f8a422a3680), not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION (0x7f8a422a2b80), not started
0 lock struct(s), heap size 1128, 0 row lock(s)
--------



And:
MariaDB [(none)]> show full processlist;
+----+------+-----------+---------+---------+------+----------
+-------------------------------------------------------------------------------------------------------------------------------------------------------------
+----------+
| Id | User | Host | db | Command | Time | State | Info
| Progress |
+----+------+-----------+---------+---------+------+----------
+-------------------------------------------------------------------------------------------------------------------------------------------------------------
+----------+
| 5 | user | localhost | akonadi | Sleep | 3145 | | NULL
| 0.000 |
| 6 | user | localhost | akonadi | Sleep | 142 | | NULL
| 0.000 |
| 7 | user | localhost | akonadi | Sleep | 145 | | NULL
| 0.000 |
| 8 | user | localhost | akonadi | Sleep | 3133 | | NULL
| 0.000 |
| 43 | user | localhost | akonadi | Sleep | 1949 | | NULL
| 0.000 |
| 47 | user | localhost | akonadi | Execute | 2023 | Update | INSERT INTO
PimItemTable (rev, remoteId, remoteRevision, gid, collectionId, mimeTypeId,
datetime, atime, dirty, size) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) | 0.000
|
| 53 | user | localhost | NULL | Query | 0 | starting | show full
processlist
| 0.000 |
+----+------+-----------+---------+---------+------+----------
+-------------------------------------------------------------------------------------------------------------------------------------------------------------
+----------+
7 rows in set (0.000 sec)

MariaDB [(none)]> show open tables where In_Use > 0 ;
+----------+--------------+--------+-------------+
| Database | Table | In_use | Name_locked |
+----------+--------------+--------+-------------+
| akonadi | pimitemtable | 1 | 0 |
+----------+--------------+--------+-------------+
1 row in set (0.001 sec)


So does anyone have an idea why the insert statement does not finish?

Stefan Fritsch

unread,
Jun 16, 2022, 6:00:05 AM6/16/22
to

Hi,

I have the problem that after suspend/resume, if I shut down the system,
systemd complains that mysql does not die. I have wondered, why akonadi
does not kill mysql and it is because of akonadi's apparmor rules:


Jun 16 11:24:45 k kernel: [ 4096.077336] audit: type=1400
audit(1655371485.959:102): apparmor="DENIED" operation="signal"
profile="/usr/bin/akonadiserver" pid=16671 comm="akonadiserver"
requested_mask="send" denied_mask="send" signal=term peer="unconfined"
Jun 16 11:24:48 k kernel: [ 4099.080389] audit: type=1400
audit(1655371488.963:103): apparmor="DENIED" operation="signal"
profile="/usr/bin/akonadiserver" pid=16671 comm="akonadiserver"
requested_mask="send" denied_mask="send" signal=kill peer="unconfined"

If I set akonadi's profile to complain instead of enforce, akonadi can
kill mysql ok:

sudo aa-complain /etc/apparmor.d/usr.bin.akonadiserver
sudo systemctl reload apparmor.service


Somehow mysql should be running in the mysqld_akonadi profile but it is
running in fact unconstrained and therefore akonadiserver is not allowed
to send a signal to it. Don't know how to fix that, though.

I suspect the fact that mysql hangs after suspend/resume is a different
bug in mysql.

Cheers,
Stefan

Hefee

unread,
Jun 20, 2022, 4:00:03 PM6/20/22
to
Hi,

the fix is already in master, it is actually just a typo in the profile name:
https://invent.kde.org/pim/akonadi/-/commit/
a6fb4c7de13eed9d90237388113425413bf4d733

that may be worth to backport.

> If I set akonadi's profile to complain instead of enforce, akonadi can
> kill mysql ok:
>
> sudo aa-complain /etc/apparmor.d/usr.bin.akonadiserver
> sudo systemctl reload apparmor.service

you don't need to restart apparmor after set akonadiserver to complain mode.


> Somehow mysql should be running in the mysqld_akonadi profile but it is
> running in fact unconstrained and therefore akonadiserver is not allowed
> to send a signal to it. Don't know how to fix that, though.

I see the same apparmor issue, but Akonadi is still not able to kill mariadb
process.


> I suspect the fact that mysql hangs after suspend/resume is a different
> bug in mysql.

yepp - But I have no idea how to debug this.

regards,

hefee
signature.asc

gi...@leonde.de

unread,
Aug 22, 2022, 12:30:03 PM8/22/22
to
I don't know what fixed it, but it works for me again:

akonadi-backend-mysql 4:22.04.3-1
akonadi-server 4:22.04.3-1
kontact 4:22.04.3-1
libkf5libkdepim5:amd64 4:22.04.3-1
libqt5sql5-mysql:amd64 5.15.4+dfsg-5
mariadb-server 1:10.6.9-1

Thanks a lot to whoever fixed it! <3

Patrick Franz

unread,
Aug 22, 2022, 2:30:03 PM8/22/22
to
Hi,

On Mon, 22 Aug 2022 18:10:59 +0200 gi...@leonde.de wrote:
> I don't know what fixed it, but it works for me again:

Then please be so kind and close the bug.


--
Med vänliga hälsningar

Patrick Franz
0 new messages