Bug 425131 - After crashing, akonadi cannot start up and cannot recover itself
Summary: After crashing, akonadi cannot start up and cannot recover itself
Status: REPORTED
Alias: None
Product: Akonadi
Classification: Frameworks and Libraries
Component: general (show other bugs)
Version: 5.14.3
Platform: Neon Linux
: NOR crash
Target Milestone: ---
Assignee: kdepim bugs
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2020-08-08 07:54 UTC by Halla Rempt
Modified: 2022-10-15 11:31 UTC (History)
5 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Halla Rempt 2020-08-08 07:54:38 UTC
Kmail hung removing messages so I quit kmail and restart akonadi with "akonadictl restart" This failed. I rebooted and started kmail from a terminal. This failed: kmail gave me a button with the legend "details" but pressing that button didn't do a thing. The terminal output was:

org.kde.pim.akonadiserver: Starting up the Akonadi Server...
No text-to-speech plug-ins were found.
org.kde.pim.akonadiserver: database server stopped unexpectedly
org.kde.pim.akonadiserver: Database process exited unexpectedly during initial connection!
org.kde.pim.akonadiserver: executable: "/usr/sbin/mysqld-akonadi"
org.kde.pim.akonadiserver: arguments: ("--defaults-file=/home/boud/.local/share/akonadi/mysql.conf", "--datadir=/home/boud/.local/share/akonadi/db_data/", "--socket=/run/user/1000/akonadi/mysql.socket", "--pid-file=/run/user/1000/akonadi/mysql.pid")
org.kde.pim.akonadiserver: stdout: ""
org.kde.pim.akonadiserver: stderr: ""
org.kde.pim.akonadiserver: exit code: 1
org.kde.pim.akonadiserver: process error: "Unknown error"
org.kde.pim.akonadiserver: Shutting down AkonadiServer...
org.kde.pim.akonadicontrol: Application '/usr/bin/akonadiserver' exited normally...
org.kde.pim.akonadicore: Job error:  "" for collection: QVector()
org.kde.pim.akonadicore: Job error:  "" for collection: QVector()
org.kde.pim.messagelist: Failed to load tags  ""
org.kde.pim.kmail: ""
org.kde.pim.kmail: ""


System info:

Operating System: KDE neon 5.19
KDE Plasma Version: 5.19.4 
KDE Frameworks Version: 5.72.0
Qt Version: 5.14.2
Kernel Version: 5.3.0-28-generic
OS Type: 64-bit
Processors: 8 × Intel® Core™ i7-7700HQ CPU @ 2.80GHz
Memory: 31,1 GiB of RAM
Graphics Processor: Mesa DRI Intel® HD Graphics 630
Comment 1 Halla Rempt 2020-08-08 09:22:30 UTC
Note: this is not a duplicate of 416016 since it has nothing to do with apparmor and doesn't go away after a reboot.
Comment 2 Halla Rempt 2020-08-08 09:39:44 UTC
I also tried to get extra information like this:
boud@boud-ThinkPad-T470p:~$ /usr/sbin/mysqld-akonadi --log-error-verbosity 10 --defaults-file=/home/boud/.local/share/akonadi/mysql.conf --datadir=/home/boud/.local/share/akonadi/db_data/ --socket=/run/user/1000/akonadi/mysql.socket --pid-file=/run/user/1000/akonadi/mysql.pid 
2020-08-08T09:38:49.021049Z 0 [Warning] option 'log_error_verbosity': unsigned value 10 adjusted to 3
2020-08-08T09:38:49.021090Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2020-08-08T09:38:49.022108Z 0 [Warning] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2020-08-08T09:38:49.022124Z 0 [Note] /usr/sbin/mysqld-akonadi (mysqld 5.7.31-0ubuntu0.18.04.1) starting as process 2881 ...
2020-08-08T09:38:49.024269Z 0 [Note] InnoDB: PUNCH HOLE support available
2020-08-08T09:38:49.024281Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-08-08T09:38:49.024304Z 0 [Note] InnoDB: Uses event mutexes
2020-08-08T09:38:49.024307Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2020-08-08T09:38:49.024310Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-08-08T09:38:49.024335Z 0 [Note] InnoDB: Using Linux native AIO
2020-08-08T09:38:49.024522Z 0 [Note] InnoDB: Number of pools: 1
2020-08-08T09:38:49.024606Z 0 [Note] InnoDB: Using CPU crc32 instructions
2020-08-08T09:38:49.025798Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2020-08-08T09:38:49.031242Z 0 [Note] InnoDB: Completed initialization of buffer pool
2020-08-08T09:38:49.032823Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-08-08T09:38:49.044052Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2020-08-08T09:38:49.045151Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 31533912175
2020-08-08T09:38:49.045170Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 31533914677
2020-08-08T09:38:49.045219Z 0 [ERROR] InnoDB: Ignoring the redo log due to missing MLOG_CHECKPOINT between the checkpoint 31533912175 and the end 31533914677.
2020-08-08T09:38:49.045228Z 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
2020-08-08T09:38:49.646082Z 0 [ERROR] Plugin 'InnoDB' init function returned error.
2020-08-08T09:38:49.646122Z 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2020-08-08T09:38:49.646136Z 0 [ERROR] Failed to initialize builtin plugins.
2020-08-08T09:38:49.646144Z 0 [ERROR] Aborting

2020-08-08T09:38:49.646170Z 0 [Note] Binlog end
2020-08-08T09:38:49.646227Z 0 [Note] Shutting down plugin 'CSV'
2020-08-08T09:38:49.646677Z 0 [Note] /usr/sbin/mysqld-akonadi: Shutdown complete
Comment 3 Ahmad Samir 2020-08-13 10:04:58 UTC
Searching online for:
[ERROR] InnoDB: Ignoring the redo log due to missing MLOG_CHECKPOINT between the checkpoint 31533912175 and the end 31533914677.

seems to indicate it's an issue with the mysql database (mysqld didn't shutdown cleanly).
Comment 4 Halla Rempt 2020-08-13 10:06:46 UTC
That's possible; akonadi crashed when akonadictl tried to stop it.
Comment 5 Halla Rempt 2020-08-21 14:08:09 UTC
Okay, going to .local/share/akonadi/db_data and removing ib_logfile0 and ib_logfile1  got kmail started again. (Tip from http://mytechmembank.blogspot.com/2017/10/recovering-crashed-mysql-instance.html)

But that is not a solution, of course. It should never, ever be necessary do something like that just because a mail client has bug that causes a crash. Akonadi should be able to recover itself.
Comment 6 Grósz Dániel 2020-11-10 03:27:46 UTC
I have had a similar issue recently, after several system crashes (hard resets), and possibly a mariadb update.

I start KMail. It said it couldn't start the Akonadi service. Clicking the Start button again, it did nothing.

'akonadictl start' did nothing, no output at all.

'akonadictl start --verbose' indicated that it couldn't start the mysql server, similarly to the original description of this bug report.

Attempting to start the mysql (mariadb) server manually, with the same arguments that the Akonadi server uses, just said that it was starting the server, then quit with exit code 1. Same if I added the --verbose flag. Still no clue why.

Then it occurred to me to check the mysql log. It was this:

2020-11-06 23:28:28 0 [Note] InnoDB: Using Linux native AIO
2020-11-06 23:28:28 0 [Note] InnoDB: Uses event mutexes
2020-11-06 23:28:28 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-11-06 23:28:28 0 [Note] InnoDB: Number of pools: 1
2020-11-06 23:28:28 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
2020-11-06 23:28:28 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
2020-11-06 23:28:28 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
2020-11-06 23:28:28 0 [Note] InnoDB: Completed initialization of buffer pool
2020-11-06 23:28:28 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-11-06 23:28:28 0 [ERROR] InnoDB: Upgrade after a crash is not supported. The redo log was created with MariaDB 10.4.13.
2020-11-06 23:28:28 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
2020-11-06 23:28:28 0 [Note] InnoDB: Starting shutdown...
2020-11-06 23:28:28 0 [ERROR] Plugin 'InnoDB' init function returned error.
2020-11-06 23:28:28 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2020-11-06 23:28:28 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-11-06 23:28:28 0 [ERROR] Unknown/unsupported storage engine: innodb
2020-11-06 23:28:28 0 [ERROR] Aborting

After some further googling, I resolved it by removing ~/.local/share/akonadi/db_data/ib_logfile* . Akonadi works fine now. I still have no idea why this was needed, and why it works.

Akonadi should handle this scenario in a more user-friendly way.
Comment 7 Sébastien P. 2021-03-13 14:09:16 UTC
I had a similar issue:
* upgrade mariadb
* later, a crash
=> impossible to restart akonadi

~/.local/share/akonadi/db_data/mysql.err.old:
2021-03-13 14:51:11 0 [ERROR] InnoDB: Upgrade after a crash is not supported. The redo log was created with MariaDB 10.4.17.
2021-03-13 14:51:11 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error

Removing ib_logfile0 and ib_logfile1 solved that. Maybe akonadi should tell us to look at this file?
Comment 8 Jos van den Oever 2022-08-13 07:47:42 UTC
This bug has happened on a laptop I maintain as well. The file `~/.local/share/akonadi/db_data/mysql.err` reported that InnoDB missed MLOG_CHECKPOINT between another checkpoint and the end. The database would not start because of this. The user had no feedback. All they could see was a message in KMail that akonadi would not start.

Removing the files `~/.local/share/akonadi/db_data/ib_logfile*` solved the issue.

Perhaps a solution might be to let akonadictl make a backup of the db_data directory and then remove the ib_logfiles and retry starting up.
Comment 9 Jos van den Oever 2022-10-15 11:31:18 UTC
The issue happened again on two machines. Removing the files `~/.local/share/akonadi/db_data/ib_logfile*` solved the issue.