Bug 334420 - Different behavior when starting mysqld via command line and crash/do not start after doing same via akonadi
Summary: Different behavior when starting mysqld via command line and crash/do not sta...
Status: RESOLVED UNMAINTAINED
Alias: None
Product: Akonadi
Classification: Frameworks and Libraries
Component: server (show other bugs)
Version: 4.13
Platform: openSUSE Linux
: NOR critical
Target Milestone: ---
Assignee: kdepim bugs
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-05-06 14:58 UTC by Peter Fodrek
Modified: 2017-01-07 23:58 UTC (History)
1 user (show)

See Also:
Latest Commit:
Version Fixed In:
Sentry Crash Report:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Peter Fodrek 2014-05-06 14:58:19 UTC
When staring mysqld 
via
 /usr/sbin/mysqld --defaults-file=/home/peto/.local/share/akonadi/mysql.conf --datadir=/home/peto/.local/share/akonadi/db_data/ --socket=/tmp/akonadi-petoMOJ/mysql.socket 

is mysqld straed as single process and
I reached mysql.err as of

140506 14:34:49 InnoDB: The InnoDB memory heap is disabled
140506 14:34:49 InnoDB: Mutexes and rw_locks use GCC atomic builtins
140506 14:34:49 InnoDB: Compressed tables use zlib 1.2.8
140506 14:34:49 InnoDB: Using Linux native AIO
140506 14:34:49 InnoDB: Initializing buffer pool, size = 128.0M
140506 14:34:49 InnoDB: Completed initialization of buffer pool
140506 14:34:49 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 815629381135
140506 14:34:49  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 815629381247
140506 14:34:49  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 634, file name ./mysql-bin.000331
140506 14:34:50  InnoDB: Waiting for the background threads to start
140506 14:34:51 Percona XtraDB (http://www.percona.com) 5.5.33-MariaDB-31.1 started; log sequence number 815629381247
140506 14:34:51 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.33-MariaDB-log'  socket: '/tmp/akonadi-petoMOJ/mysql.socket'  port: 0  openSUSE package
140506 14:39:13 [Note] /usr/sbin/mysqld: Normal shutdown

140506 14:39:13  InnoDB: Starting shutdown...
140506 14:39:14  InnoDB: Shutdown completed; log sequence number 815629381247
140506 14:39:14 [Note] /usr/sbin/mysqld: Shutdown complete


or

140506 14:34:49 InnoDB: The InnoDB memory heap is disabled
140506 14:34:49 InnoDB: Mutexes and rw_locks use GCC atomic builtins
140506 14:34:49 InnoDB: Compresse
devtmpfs        1.9G  8.0K  1.9G   1% /dev
tmpfs           2.0G   88K  2.0G   1% /dev/shm
tmpfs           2.0G  3.7M  2.0G   1% /run                                                                                                                                                                                                   
tmpfs           2.0G     0  2.0G   0% /sys/fs/cgroup                                                                                                                                                                                         d tables use zlib 1.2.8
140506 14:34:49 InnoDB: Using Linux native AIO
140506 14:34:49 InnoDB: Initializing buffer pool, size = 128.0M
140506 14:34:49 InnoDB: Completed initialization of buffer pool
140506 14:34:49 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 815629381135
140506 14:34:49  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 815629381247
140506 14:34:49  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 634, file name ./mysql-bin.000331
140506 14:34:50  InnoDB: Waiting for the background threads to start
140506 14:34:51 Percona XtraDB (http://www.percona.com) 5.5.33-MariaDB-31.1 started; log sequence number 815629381247
140506 14:34:51 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.33-MariaDB-log'  socket: '/tmp/akonadi-petoMOJ/mysql.socket'  port: 0  openSUSE package
140506 14:39:13 [Note] /usr/sbin/mysqld: Normal shutdown

140506 14:39:13  InnoDB: Starting shutdown...
140506 14:39:14  InnoDB: Shutdown completed; log sequence number 815629381247
140506 14:39:14 [Note] /usr/sbin/mysqld: Shutdown complete

140506 14:40:27 InnoDB: The InnoDB memory heap is disabled
140506 14:40:27 InnoDB: Mutexes and rw_locks use GCC atomic builtins
140506 14:40:27 InnoDB: Compressed tables use zlib 1.2.8
140506 14:40:27 InnoDB: Using Linux native AIO
140506 14:40:27 InnoDB: Initializing buffer pool, size = 128.0M
140506 14:40:27 InnoDB: Completed initialization of buffer pool
140506 14:40:27 InnoDB: highest supported file format is Barracuda.
140506 14:40:27  InnoDB: Waiting for the background threads to start
140506 14:40:28 Percona XtraDB (http://www.percona.com) 5.5.33-MariaDB-31.1 started; log sequence number 815629381247
140506 14:40:28 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.33-MariaDB-log'  socket: '/tmp/akonadi-petoMOJ/mysql.socket'  port: 0  openSUSE package
140506 14:40:35 [Note] /usr/sbin/mysqld: Normal shutdown

140506 14:40:35  InnoDB: Starting shutdown...
140506 14:40:36  InnoDB: Shutdown completed; log sequence number 815629381247
140506 14:40:36 [Note] /usr/sbin/mysqld: Shutdown complete



But when started akonadi i got four mysqld processes and mysql.err as of


140506 14:43:46 InnoDB: The InnoDB memory heap is disabled
140506 14:43:46 InnoDB: Mutexes and rw_locks use GCC atomic builtins
140506 14:43:46 InnoDB: Compressed tables use zlib 1.2.8
140506 14:43:46 InnoDB: Using Linux native AIO
140506 14:43:46  InnoDB: Warning: io_setup() failed with EAGAIN. Will make 5 attempts before giving up.
InnoDB: Warning: io_setup() attempt 1 failed.
InnoDB: Warning: io_setup() attempt 2 failed.
InnoDB: Warning: io_setup() attempt 3 failed.
InnoDB: Warning: io_setup() attempt 4 failed.
InnoDB: Warning: io_setup() attempt 5 failed.
140506 14:43:48  InnoDB: Error: io_setup() failed with EAGAIN after 5 attempts.
InnoDB: You can disable Linux Native AIO by setting innodb_use_native_aio = 0 in my.cnf
  InnoDB: Warning: Linux Native AIO disabled because os_aio_linux_create_io_ctx() failed. To get rid of this warning you can try increasing system fs.aio-max-nr to 1048576 or larger or setting innodb_use_native_aio = 0 in my.cnf
140506 14:43:48 InnoDB: Initializing buffer pool, size = 128.0M
140506 14:43:48 InnoDB: Completed initialization of buffer pool
InnoDB: Unable to lock ./ibdata1, error: 11
InnoDB: Check that you do not already have another mysqld process
InnoDB: using the same InnoDB data or log files.
140506 14:43:48  InnoDB: Retrying to lock the first data file
InnoDB: Unable to lock ./ibdata1, error: 11
.................................
InnoDB: using the same InnoDB data or log files.
140506 14:45:28  InnoDB: Unable to open the first data file
InnoDB: Error in opening ./ibdata1
140506 14:45:28  InnoDB: Operating system error number 11 in a file operation.
InnoDB: Error number 11 means 'Resource temporarily unavailable'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.5/en/operating-system-error-codes.html
140506 14:45:28 InnoDB: Could not open or create data files.
140506 14:45:28 InnoDB: If you tried to add new data files, and it failed here,
140506 14:45:28 InnoDB: you should now edit innodb_data_file_path in my.cnf back
140506 14:45:28 InnoDB: to what it was, and remove the new ibdata files InnoDB created
140506 14:45:28 InnoDB: in this failed attempt. InnoDB only wrote those files full of
140506 14:45:28 InnoDB: zeros, but did not yet use them in any way. But be careful: do not
140506 14:45:28 InnoDB: remove old data files which contain your precious data!
140506 14:45:28 [ERROR] Plugin 'InnoDB' init function returned error.
140506 14:45:28 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
140506 14:45:28 [ERROR] mysqld: Can't lock aria control file '/home/peto/.local/share/akonadi/db_data/aria_log_control' for exclusive use, error: 11. Will retry for 30 seconds
140506 14:45:59 [ERROR] mysqld: Got error 'Could not get an exclusive lock; file is probably in use by another process' when trying to use aria control file '/home/peto/.local/share/akonadi/db_data/aria_log_control'
140506 14:45:59 [ERROR] Plugin 'Aria' init function returned error.
140506 14:45:59 [ERROR] Plugin 'Aria' registration as a STORAGE ENGINE failed.
140506 14:45:59 [ERROR] Unknown/unsupported storage engine: InnoDB
140506 14:45:59 [ERROR] Aborting

140506 14:45:59 [Note] /usr/sbin/mysqld: Shutdown complete

It seems to be coincidence between mysqld/mariadb instances

And i see unstandard output of
>pwd
/home/peto/.local/share/akonadi/db_data

and
> ls -lah
258M May  6 16:06 ibdata1
113G May  6 16:06 mysql.full

for personal email database as well
and 
>df -h

/dev/sda6        39G   26G   12G  69% /
/dev/sda9       494M  310M  149M  68% /boot
/dev/sda7        18G   17G  1.3G  93% /usr/src
/dev/sda10      136G  128G  1.2G 100% /home
/dev/sda8       3.9G  2.4G  1.6G  61% /var
/dev/sda1        29G  5.5G   24G  20% /tmp
Comment 1 Peter Fodrek 2014-05-09 11:45:49 UTC
I am to provide additiona informtaion when starting akonadi . It starts migration assistant and it returned

Adding new foreign key constraints 
"ALTER TABLE CollectionTable ADD FOREIGN KEY (parentId) REFERENCES CollectionTable(id) ON UPDATE CASCADE ON DELETE CASCADE" 
Updating index failed:  
Sql error: Cannot add or update a child row: a foreign key constraint fails (`akonadi`.`#sql-ea8_18`, CONSTRAINT `#sql-ea8_18_ibfk_1` FOREIGN KEY (`parentId`) REFERENCES `collectiontable` (`id`) ON DELETE CASCADE ON UPDATE CASCADE) QMYSQL: Unable to execute query
Query: ALTER TABLE CollectionTable ADD FOREIGN KEY (parentId) REFERENCES CollectionTable(id) ON UPDATE CASCADE ON DELETE CASCADE 
""
Unable to initialize database.
"[
0: akonadiserver(_Z11akBacktracev+0x37) [0x468267]
1: akonadiserver() [0x4684c2]
2: /lib64/libc.so.6(+0x358d0) [0x7f53c1e518d0]
3: /lib64/libc.so.6(gsignal+0x39) [0x7f53c1e51849]
4: /lib64/libc.so.6(abort+0x148) [0x7f53c1e52cd8]
5: /usr/lib64/libQtCore.so.4(_Z17qt_message_output9QtMsgTypePKc+0x64) [0x7f53c3656204]
6: akonadiserver(_ZN15FileDebugStream9writeDataEPKcx+0x9d) [0x46a67d]
7: /usr/lib64/libQtCore.so.4(_ZN9QIODevice5writeEPKcx+0xb0) [0x7f53c36f0830]
8: /usr/lib64/libQtCore.so.4(+0x11ec2d) [0x7f53c36fdc2d]
9: /usr/lib64/libQtCore.so.4(_ZN11QTextStreamD1Ev+0x33) [0x7f53c3706813]
10: akonadiserver(_ZN7Akonadi6Server13AkonadiServer4initEv+0x5fa) [0x46e09a]
11: /usr/lib64/libQtCore.so.4(_ZN7QObject5eventEP6QEvent+0x24e) [0x7f53c377811e]
12: /usr/lib64/libQtCore.so.4(_ZN16QCoreApplication14notifyInternalEP7QObjectP6QEvent+0x6d) [0x7f53c37600ad]
13: /usr/lib64/libQtCore.so.4(_ZN23QCoreApplicationPrivate16sendPostedEventsEP7QObjectiP11QThreadData+0x1ef) [0x7f53c37630ff]
14: /usr/lib64/libQtCore.so.4(+0x1ae493) [0x7f53c378d493]
15: /usr/lib64/libglib-2.0.so.0(g_main_context_dispatch+0x146) [0x7f53c152c316]
16: /usr/lib64/libglib-2.0.so.0(+0x4b668) [0x7f53c152c668]
17: /usr/lib64/libglib-2.0.so.0(g_main_context_iteration+0x2c) [0x7f53c152c70c]
18: /usr/lib64/libQtCore.so.4(_ZN20QEventDispatcherGlib13processEventsE6QFlagsIN10QEventLoop17ProcessEventsFlagEE+0x65) [0x7f53c378cd55]
19: /usr/lib64/libQtCore.so.4(_ZN10QEventLoop13processEventsE6QFlagsINS_17ProcessEventsFlagEE+0x2f) [0x7f53c375ed0f]
20: /usr/lib64/libQtCore.so.4(_ZN10QEventLoop4execE6QFlagsINS_17ProcessEventsFlagEE+0x175) [0x7f53c375f005]
21: /usr/lib64/libQtCore.so.4(_ZN16QCoreApplication4execEv+0x8b) [0x7f53c376413b]
22: akonadiserver(main+0x1bf) [0x461c6f]
23: /lib64/libc.so.6(__libc_start_main+0xf5) [0x7f53c1e3dbe5]
24: akonadiserver() [0x4623a9]
]
"
ProcessControl: Application 'akonadiserver' returned with exit code 255 (Unknown error)
"akonadiserver" crashed too often and will not be restarted! 

It may be solved via database update with akonadi related  command, but I am no so familiar with SQL to determine which one is correct
Comment 2 Peter Fodrek 2014-05-09 12:12:43 UTC
 /usr/bin/mysqlcheck --defaults-file=/home/peto/.local/share/akonadi/mysql.conf --socket=/tmp/akonadi-petoMOJ/mysql.socket -vc -A
Processing databases
information_schema
akonadi
akonadi.collectionattributetable                   OK
akonadi.collectionmimetyperelation                 OK
akonadi.collectionpimitemrelation                  OK
akonadi.collectiontable                            OK
akonadi.flagtable                                  OK
akonadi.mimetypetable                              OK
akonadi.parttable                                  OK
akonadi.parttypetable                              OK
akonadi.pimitemflagrelation                        OK
akonadi.pimitemtable                               OK
akonadi.pimitemtagrelation                         OK
akonadi.resourcetable                              OK
akonadi.schemaversiontable                         OK
akonadi.tagattributetable                          OK
akonadi.tagremoteidresourcerelationtable           OK
akonadi.tagtable                                   OK
mysql
mysql.columns_priv                                 OK
mysql.db                                           OK
mysql.event                                        OK
mysql.func                                         OK
mysql.help_category                                OK
mysql.help_keyword                                 OK
mysql.help_relation                                OK
mysql.help_topic                                   OK
mysql.host                                         OK
mysql.ndb_binlog_index                             OK
mysql.plugin                                       OK
mysql.proc                                         OK
mysql.procs_priv                                   OK
mysql.proxies_priv                                 OK
mysql.servers                                      OK
mysql.tables_priv                                  OK
mysql.time_zone                                    OK
mysql.time_zone_leap_second                        OK
mysql.time_zone_name                               OK
mysql.time_zone_transition                         OK
mysql.time_zone_transition_type                    OK
mysql.user                                         OK
performance_schema
test


but 

usr/bin/mysqlcheck --defaults-file=/home/peto/.local/share/akonadi/mysql.conf --socket=/tmp/akonadi-petoMOJ/mysql.socket -vr -A
Processing databases
information_schema
akonadi
akonadi.collectionattributetable
note     : The storage engine for the table doesn't support repair
akonadi.collectionmimetyperelation
note     : The storage engine for the table doesn't support repair
akonadi.collectionpimitemrelation
note     : The storage engine for the table doesn't support repair
akonadi.collectiontable
note     : The storage engine for the table doesn't support repair
akonadi.flagtable
note     : The storage engine for the table doesn't support repair
akonadi.mimetypetable
note     : The storage engine for the table doesn't support repair
akonadi.parttable
note     : The storage engine for the table doesn't support repair
akonadi.parttypetable
note     : The storage engine for the table doesn't support repair
akonadi.pimitemflagrelation
note     : The storage engine for the table doesn't support repair
akonadi.pimitemtable
note     : The storage engine for the table doesn't support repair
akonadi.pimitemtagrelation
note     : The storage engine for the table doesn't support repair
akonadi.resourcetable
note     : The storage engine for the table doesn't support repair
akonadi.schemaversiontable
note     : The storage engine for the table doesn't support repair
akonadi.tagattributetable
note     : The storage engine for the table doesn't support repair
akonadi.tagremoteidresourcerelationtable
note     : The storage engine for the table doesn't support repair
akonadi.tagtable
note     : The storage engine for the table doesn't support repair
mysql
mysql.columns_priv                                 OK
Comment 3 Denis Kurz 2016-09-24 20:34:30 UTC
This bug has only been reported for versions older than KDEPIM 4.14 (at most akonadi-1.3). Can anyone tell if this bug still present?

If noone confirms this bug for a recent version of akonadi (part of KDE Applications 15.08 or later), it gets closed in about three months.
Comment 4 Denis Kurz 2017-01-07 23:58:27 UTC
Just as announced in my last comment, I close this bug. If you encounter it again in a recent version (at least 5.0 aka 15.08), please open a new one unless it already exists. Thank you for all your input.