[MDEV-28662] [ERROR] mysqld got signal 11 after updating from 10.4.8 to 10.4.24 Created: 2022-05-25  Updated: 2022-07-27  Resolved: 2022-07-27

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.3.31, 10.4.21, 10.5.12, 10.6.4, 10.4.24
Fix Version/s: 10.3.36, 10.4.26, 10.5.17, 10.6.9, 10.7.5, 10.8.4, 10.9.2, 10.10.1

Type: Bug Priority: Critical
Reporter: Francisco Javier Rubio Campos Assignee: Marko Mäkelä
Resolution: Duplicate Votes: 0
Labels: regression
Environment:

Debian Stretch - 4.19.0-0.bpo.19-amd64

Issue Links:
Duplicate
duplicates MDEV-28495 Corruption due to attempting to start... Closed
is duplicated by MDEV-28697 One Node crashed and did not recover Closed
Problem/Incident
is caused by MDEV-24393 table_open_cache creates same number ... Closed
Relates
relates to MDEV-28976 InnoDB: Missing FILE_CHECKPOINT Closed

 Description   

MariaDB server crashes after updating from 10.4.8 to 10.4.24. It seems that mysqld daemon is initiated twice and after that, there is a segmentation fault.

Sun May  1 14:24:15 2022 PerconaFT file system space is really low and access is restricted
 
Mon May  2 11:48:42 2022 PerconaFT file system space is really low and access is restricted
 
Tue May  3 06:17:58 2022 PerconaFT file system space is really low and access is restricted
 
Tue May  3 06:21:38 2022 PerconaFT file system space is really low and access is restricted
 
Tue May  3 07:01:54 2022 PerconaFT file system space is really low and access is restricted
 
Tue May  3 07:03:09 2022 PerconaFT file system space is really low and access is restricted
 
Wed May  4 23:04:40 2022 PerconaFT No space when writing 2292 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:09:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:10:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:11:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:12:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:13:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:14:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:15:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:16:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:17:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:18:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:19:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:20:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:21:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:22:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:23:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:24:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:25:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:26:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:27:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:28:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:29:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:30:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:31:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:32:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:33:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:34:41 2022 PerconaFT No space when writing 4711 bytes to /var/lib/mysql/log000000154028.tokulog29 retry in 1 second
 
Wed May  4 23:35:41 2022 PerconaFTMon May  9 22:14:16 2022 PerconaFT file system space is low
 
Tue May 10 20:22:13 2022 PerconaFT file system space is low
 
Wed May 11 00:38:43 2022 PerconaFT file system space is low
 
2022-05-11 10:42:50 0 [Note] /usr/sbin/mysqld (initiated by: debian-sys-maint[debian-sys-maint] @ localhost []): Normal shutdown
 
2022-05-11 10:42:50 0 [Note] Event Scheduler: Killing the scheduler thread, thread id 6
 
2022-05-11 10:42:50 0 [Note] Event Scheduler: Waiting for the scheduler thread to reply
 
2022-05-11 10:42:50 0 [Note] Event Scheduler: Stopped
 
2022-05-11 10:42:50 0 [Note] Event Scheduler: Purging the queue. 0 events
 
2022-05-11 10:42:50 0 [Note] InnoDB: FTS optimize thread exiting.
 
2022-05-11 10:42:53 0 [Note] InnoDB: Starting shutdown...
 
2022-05-11 10:42:53 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
 
2022-05-11 10:42:53 0 [Note] InnoDB: Instance 0, restricted to 20030 pages due to innodb_buf_pool_dump_pct=25
 
2022-05-11 10:42:53 0 [Note] InnoDB: Instance 1, restricted to 20030 pages due to innodb_buf_pool_dump_pct=25
 
2022-05-11 10:42:53 0 [Note] InnoDB: Instance 2, restricted to 20030 pages due to innodb_buf_pool_dump_pct=25
 
2022-05-11 10:42:53 0 [Note] InnoDB: Instance 3, restricted to 20030 pages due to innodb_buf_pool_dump_pct=25
 
2022-05-11 10:42:53 0 [Note] InnoDB: Instance 4, restricted to 20030 pages due to innodb_buf_pool_dump_pct=25
 
2022-05-11 10:42:53 0 [Note] InnoDB: Instance 5, restricted to 20030 pages due to innodb_buf_pool_dump_pct=25
 
2022-05-11 10:42:53 0 [Note] InnoDB: Instance 6, restricted to 20030 pages due to innodb_buf_pool_dump_pct=25
 
2022-05-11 10:42:53 0 [Note] InnoDB: Instance 7, restricted to 20030 pages due to innodb_buf_pool_dump_pct=25
 
2022-05-11 10:42:53 0 [Note] InnoDB: Buffer pool(s) dump completed at 220511 10:42:53
 
2022-05-11 10:43:34 0 [Note] InnoDB: Shutdown completed; log sequence number 3840809316650; transaction id 269179863
 
2022-05-11 10:43:34 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./datawarehouse/report_data 0x7f730effb008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/idm_data 0x7f79c5bca008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./datawarehouse/incidents_ssi 0x7f7a3bda1008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/acid_event 0x7f799b201008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/extra_data 0x7f79a67fc008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault/event 0x7f79a3631008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/reputation_data 0x7f7998dbe008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/otx_data 0x7f7897d3b008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault/extra_data 0x7f79a55a0008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/po_acid_event 0x7f79a6260008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault/otx_data 0x7f793bf83008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault/sem_stats_events 0x7f79c3fc3008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault/idm_data 0x7f793bf61008
 
9784 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./datawarehouse/ssi 0x7f7a3bd58008
 
2022-05-11 10:43:55 0 [Note] /usr/sbin/mysqld: Shutdown complete
 
 
 
2022-05-11 10:47:40 0 [Note] InnoDB: Using Linux native AIO
 
2022-05-11 10:47:40 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2022-05-11 10:47:40 0 [Note] InnoDB: Uses event mutexes
 
2022-05-11 10:47:40 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
2022-05-11 10:47:40 0 [Note] InnoDB: Number of pools: 1
 
2022-05-11 10:47:40 0 [Note] InnoDB: Using SSE2 crc32 instructions
 
2022-05-11 10:47:40 0 [Note] mysqld: O_TMPFILE is not supported on /var/tmp (disabling future attempts)
 
2022-05-11 10:47:40 0 [Note] InnoDB: Initializing buffer pool, total size = 10G, instances = 8, chunk size = 128M
 
2022-05-11 10:47:41 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-05-11 10:47:41 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2022-05-11 10:47:41 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2022-05-11 10:47:41 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2022-05-11 10:47:41 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2022-05-11 10:47:41 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2022-05-11 10:47:41 0 [Note] InnoDB: Waiting for purge to start
 
2022-05-11 10:47:41 0 [Note] InnoDB: 10.4.8 started; log sequence number 3840809316650; transaction id 269179863
 
2022-05-11 10:47:41 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
 
2022-05-11 10:47:41 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-05-11 10:47:42 0 [Note] Server socket created on IP: '0.0.0.0'.
 
2022-05-11 10:47:42 0 [Warning] 'user' entry '@xpyusm' ignored in --skip-name-resolve mode.
 
2022-05-11 10:47:42 0 [Warning] 'user' entry 'root@xpyusm' ignored in --skip-name-resolve mode.
 
2022-05-11 10:47:43 6 [Note] Event Scheduler: scheduler thread started with id 6
 
2022-05-11 10:47:43 0 [Note] /usr/sbin/mysqld: ready for connections.
 
Version: '10.4.8-MariaDB-1:10.4.8+maria~stretch'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
 
2022-05-11 10:47:55 16 [Warning] 'user' entry '@xpyusm' ignored in --skip-name-resolve mode.
 
2022-05-11 10:47:55 16 [Warning] 'user' entry 'root@xpyusm' ignored in --skip-name-resolve mode.
 
2022-05-11 10:48:45 0 [Note] InnoDB: Buffer pool(s) load completed at 220511 10:48:45
 
2022-05-11 13:21:04 0 [Note] /usr/sbin/mysqld (initiated by: debian-sys-maint[debian-sys-maint] @ localhost []): Normal shutdown
 
2022-05-11 13:21:04 0 [Note] Event Scheduler: Killing the scheduler thread, thread id 6
 
2022-05-11 13:21:04 0 [Note] Event Scheduler: Waiting for the scheduler thread to reply
 
2022-05-11 13:21:04 0 [Note] Event Scheduler: Stopped
 
2022-05-11 13:21:04 0 [Note] Event Scheduler: Purging the queue. 0 events
 
2022-05-11 13:21:04 0 [Note] InnoDB: FTS optimize thread exiting.
 
2022-05-11 13:21:08 0 [Note] InnoDB: Starting shutdown...
 
2022-05-11 13:21:08 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
 
2022-05-11 13:21:08 0 [Note] InnoDB: Buffer pool(s) dump completed at 220511 13:21:08
 
2022-05-11 13:21:10 0 [Note] InnoDB: Shutdown completed; log sequence number 3840843556758; transaction id 269213247
 
2022-05-11 13:21:10 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/extra_data 0x7f692c040008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault/sem_stats_events 0x7f69e7daf008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault/idm_data 0x7f69943e3008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault/extra_data 0x7f699527a008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault/event 0x7f6994250008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/otx_data 0x7f697d5b4008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/reputation_data 0x7f69456f4008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault/otx_data 0x7f698c39c008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/po_acid_event 0x7f698d934008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/acid_event 0x7f697d7e5008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./datawarehouse/report_data 0x7f69d9112008
 
10942 /home/buildbot/buildbot/build/mariadb-10.4.8/storage/tokudb/ha_tokudb.cc:161 static_destroy _open_tables ./alienvault_siem/idm_data 0x7f6945705008
 
2022-05-11 13:21:12 0 [Note] /usr/sbin/mysqld: Shutdown complete
 
 
 
220516 20:08:51 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
 
2022-05-16 20:08:52 0 [Note] Using unique option prefix 'log_warning' is error-prone and can break in the future. Please use the full name 'log_warnings' instead.
 
2022-05-16 20:08:52 0 [Warning] option 'server_id': unsigned value 0 adjusted to 1
 
2022-05-16 20:08:52 0 [Warning] option 'join_buffer_size': unsigned value 0 adjusted to 128
 
2022-05-16 20:08:52 0 [Warning] 'THREAD_CONCURRENCY' is deprecated and will be removed in a future release.
 
2022-05-16 20:08:52 0 [Note] /usr/sbin/mysqld (mysqld 10.4.24-MariaDB-1:10.4.24+maria~stretch) starting as process 3830 ...
 
2022-05-16 20:08:53 0 [Note] InnoDB: Using Linux native AIO
 
2022-05-16 20:08:53 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2022-05-16 20:08:53 0 [Note] InnoDB: Uses event mutexes
 
2022-05-16 20:08:53 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
2022-05-16 20:08:53 0 [Note] InnoDB: Number of pools: 1
 
2022-05-16 20:08:53 0 [Note] InnoDB: Using SSE2 crc32 instructions
 
2022-05-16 20:08:53 0 [Note] InnoDB: Initializing buffer pool, total size = 36G, instances = 8, chunk size = 128M
 
2022-05-16 20:08:54 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-05-16 20:08:54 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2022-05-16 20:08:54 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 536870912 bytes
 
2022-05-16 20:08:56 0 [Note] InnoDB: Setting log file ./ib_logfile1 size to 536870912 bytes
 
2022-05-16 20:08:57 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
 
2022-05-16 20:08:57 0 [Note] InnoDB: New log files created, LSN=3850943478927
 
220516 20:09:00 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
 
2022-05-16 20:09:00 0 [Note] Using unique option prefix 'log_warning' is error-prone and can break in the future. Please use the full name 'log_warnings' instead.
 
2022-05-16 20:09:00 0 [Warning] option 'server_id': unsigned value 0 adjusted to 1
 
2022-05-16 20:09:00 0 [Warning] option 'join_buffer_size': unsigned value 0 adjusted to 128
 
2022-05-16 20:09:00 0 [Warning] 'THREAD_CONCURRENCY' is deprecated and will be removed in a future release.
 
2022-05-16 20:09:00 0 [Note] /usr/sbin/mysqld (mysqld 10.4.24-MariaDB-1:10.4.24+maria~stretch) starting as process 4235 ...
 
2022-05-16 20:09:00 0 [ERROR] mysqld: Can't lock aria control file '/var/lib/mysql/aria_log_control' for exclusive use, error: 11. Will retry for 30 seconds
 
2022-05-16 20:09:04 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2022-05-16 20:09:04 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2022-05-16 20:09:04 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2022-05-16 20:09:04 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2022-05-16 20:09:04 0 [Note] InnoDB: Waiting for purge to start
 
2022-05-16 20:09:04 0 [Note] InnoDB: 10.4.24 started; log sequence number 3850943479308; transaction id 270611988
 
2022-05-16 20:09:04 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
 
2022-05-16 20:09:04 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-05-16 20:09:08 0 [Note] Server socket created on IP: '0.0.0.0'.
 
2022-05-16 20:09:08 0 [Warning] 'user' entry '@xpyusm' ignored in --skip-name-resolve mode.
 
2022-05-16 20:09:08 0 [Warning] 'user' entry 'root@xpyusm' ignored in --skip-name-resolve mode.
 
2022-05-16 20:09:09 6 [Note] Event Scheduler: scheduler thread started with id 6
 
2022-05-16 20:09:10 0 [Note] /usr/sbin/mysqld: ready for connections.
 
Version: '10.4.24-MariaDB-1:10.4.24+maria~stretch'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
 
2022-05-16 20:09:31 0 [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 '/var/lib/mysql/aria_log_control'
 
2022-05-16 20:09:31 0 [ERROR] Plugin 'Aria' init function returned error.
 
2022-05-16 20:09:31 0 [ERROR] Plugin 'Aria' registration as a STORAGE ENGINE failed.
 
2022-05-16 20:09:31 0 [Note] InnoDB: Using Linux native AIO
 
2022-05-16 20:09:31 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2022-05-16 20:09:31 0 [Note] InnoDB: Uses event mutexes
 
2022-05-16 20:09:31 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
2022-05-16 20:09:31 0 [Note] InnoDB: Number of pools: 1
 
2022-05-16 20:09:31 0 [Note] InnoDB: Using SSE2 crc32 instructions
 
2022-05-16 20:09:31 0 [Note] InnoDB: Initializing buffer pool, total size = 36G, instances = 8, chunk size = 128M
 
2022-05-16 20:09:33 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-05-16 20:09:33 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2022-05-16 20:09:33 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3850943482440
 
2022-05-16 20:09:33 0 [Note] InnoDB: Last binlog file '/var/log/mysql/mariadb-bin.000884', position 43685163
 
2022-05-16 20:09:33 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2022-05-16 20:09:33 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
 
2022-05-16 20:09:33 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2022-05-16 20:09:33 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2022-05-16 20:09:33 0 [Note] InnoDB: Buffer pool(s) load completed at 220516 20:09:33
 
2022-05-16 20:09:33 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2022-05-16 20:09:33 0 [Note] InnoDB: Waiting for purge to start
 
2022-05-16 20:09:33 0 [Note] InnoDB: 10.4.24 started; log sequence number 3850943482449; transaction id 270612014
 
2022-05-16 20:09:33 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
 
2022-05-16 20:09:33 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-05-16 20:09:33 0 [ERROR] Could not open mysql.plugin table. Some plugins may be not loaded
 
2022-05-16 20:09:33 0 [ERROR] Failed to initialize plugins.
 
2022-05-16 20:09:33 0 [ERROR] Aborting
 
220516 20:09:39 mysqld_safe Number of processes running now: 1
 
220516 20:09:39 mysqld_safe mysqld process hanging, pid 3830 - killed
 
220516 20:09:39 mysqld_safe mysqld restarted
 
2022-05-16 20:09:39 0 [Note] Using unique option prefix 'log_warning' is error-prone and can break in the future. Please use the full name 'log_warnings' instead.
 
2022-05-16 20:09:39 0 [Warning] option 'server_id': unsigned value 0 adjusted to 1
 
2022-05-16 20:09:39 0 [Warning] option 'join_buffer_size': unsigned value 0 adjusted to 128
 
2022-05-16 20:09:39 0 [Warning] 'THREAD_CONCURRENCY' is deprecated and will be removed in a future release.
 
2022-05-16 20:09:39 0 [Note] /usr/sbin/mysqld (mysqld 10.4.24-MariaDB-1:10.4.24+maria~stretch) starting as process 4863 ...
 
2022-05-16 20:09:39 0 [ERROR] mysqld: Can't lock aria control file '/var/lib/mysql/aria_log_control' for exclusive use, error: 11. Will retry for 30 seconds
 
220516 20:09:39 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended
 
220516 20:09:40 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
 
2022-05-16 20:09:40 0 [Note] Using unique option prefix 'log_warning' is error-prone and can break in the future. Please use the full name 'log_warnings' instead.
 
2022-05-16 20:09:40 0 [Warning] option 'server_id': unsigned value 0 adjusted to 1
 
2022-05-16 20:09:40 0 [Warning] option 'join_buffer_size': unsigned value 0 adjusted to 128
 
2022-05-16 20:09:40 0 [Warning] 'THREAD_CONCURRENCY' is deprecated and will be removed in a future release.
 
2022-05-16 20:09:40 0 [Note] /usr/sbin/mysqld (mysqld 10.4.24-MariaDB-1:10.4.24+maria~stretch) starting as process 5205 ...
 
2022-05-16 20:09:40 0 [Note] mysqld: Aria engine: starting recovery
 
recovered pages: 0% 90% 100% (0.0 seconds);
 
2022-05-16 20:09:41 0 [Note] mysqld: Aria engine: recovery done
 
2022-05-16 20:09:41 0 [Note] InnoDB: Using Linux native AIO
 
2022-05-16 20:09:41 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2022-05-16 20:09:41 0 [Note] InnoDB: Uses event mutexes
 
2022-05-16 20:09:41 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
2022-05-16 20:09:41 0 [Note] InnoDB: Number of pools: 1
 
2022-05-16 20:09:41 0 [Note] InnoDB: Using SSE2 crc32 instructions
 
2022-05-16 20:09:41 0 [Note] InnoDB: Initializing buffer pool, total size = 12G, instances = 8, chunk size = 128M
 
2022-05-16 20:09:41 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-05-16 20:09:41 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2022-05-16 20:09:42 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2022-05-16 20:09:42 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2022-05-16 20:09:42 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2022-05-16 20:09:42 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2022-05-16 20:09:42 0 [Note] InnoDB: Waiting for purge to start
 
2022-05-16 20:09:42 0 [Note] InnoDB: 10.4.24 started; log sequence number 3850943484127; transaction id 270612014
 
2022-05-16 20:09:42 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
 
2022-05-16 20:09:42 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-05-16 20:09:42 0 [Note] InnoDB: Buffer pool(s) load completed at 220516 20:09:42
 
Mon May 16 20:09:42 2022 PerconaFT recovery starting in env /var/lib/mysql/
 
Mon May 16 20:09:42 2022 PerconaFT recovery scanning backward from 100531923382
 
Mon May 16 20:09:43 2022 PerconaFT recovery bw_end_checkpoint at 100531898122 timestamp 1652728147089863 xid 100531898118 (bw_newer)
 
Mon May 16 20:09:43 2022 PerconaFT recovery bw_begin_checkpoint at 100531898118 timestamp 1652728147089858 (bw_between)
 
Mon May 16 20:09:43 2022 PerconaFT recovery turning around at begin checkpoint 100531898118 time 5
 
Mon May 16 20:09:43 2022 PerconaFT recovery starts scanning forward to 100531923382 from 100531898118 left 25264 (fw_between)
 
Mon May 16 20:09:52 2022 PerconaFT recovery closing 11 dictionaries
 
Mon May 16 20:09:54 2022 PerconaFT recovery making a checkpoint
 
Mon May 16 20:09:54 2022 PerconaFT recovery done
 
2022-05-16 20:09:54 0 [Note] Recovering after a crash using tc.log
 
2022-05-16 20:09:54 0 [Note] Starting crash recovery...
 
2022-05-16 20:09:54 0 [Note] Crash recovery finished.
 
2022-05-16 20:09:55 0 [Note] Server socket created on IP: '0.0.0.0'.
 
2022-05-16 20:09:55 0 [Warning] 'user' entry '@xpyusm' ignored in --skip-name-resolve mode.
 
2022-05-16 20:09:55 0 [Warning] 'user' entry 'root@xpyusm' ignored in --skip-name-resolve mode.
 
2022-05-16 20:09:55 6 [Note] Event Scheduler: scheduler thread started with id 6
 
2022-05-16 20:09:55 0 [Note] /usr/sbin/mysqld: ready for connections.
 
Version: '10.4.24-MariaDB-1:10.4.24+maria~stretch'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
 
2022-05-16 20:10:10 0 [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 '/var/lib/mysql/aria_log_control'
 
2022-05-16 20:10:10 0 [ERROR] Plugin 'Aria' init function returned error.
 
2022-05-16 20:10:10 0 [ERROR] Plugin 'Aria' registration as a STORAGE ENGINE failed.
 
2022-05-16 20:10:10 0 [Note] InnoDB: Using Linux native AIO
 
2022-05-16 20:10:10 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2022-05-16 20:10:10 0 [Note] InnoDB: Uses event mutexes
 
2022-05-16 20:10:10 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
2022-05-16 20:10:10 0 [Note] InnoDB: Number of pools: 1
 
2022-05-16 20:10:10 0 [Note] InnoDB: Using SSE2 crc32 instructions
 
2022-05-16 20:10:10 0 [Note] InnoDB: Initializing buffer pool, total size = 12G, instances = 8, chunk size = 128M
 
2022-05-16 20:10:11 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-05-16 20:10:11 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2022-05-16 20:10:11 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3850943486895
 
2022-05-16 20:10:11 0 [Note] InnoDB: Last binlog file '/var/log/mysql/mariadb-bin.000884', position 53918303
 
2022-05-16 20:10:11 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2022-05-16 20:10:11 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
 
2022-05-16 20:10:11 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2022-05-16 20:10:11 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2022-05-16 20:10:11 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2022-05-16 20:10:11 0 [Note] InnoDB: Waiting for purge to start
 
2022-05-16 20:10:11 0 [Note] InnoDB: 10.4.24 started; log sequence number 3850943486904; transaction id 270612058
 
2022-05-16 20:10:11 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
 
2022-05-16 20:10:11 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-05-16 20:10:11 0 [ERROR] Could not open mysql.plugin table. Some plugins may be not loaded
 
2022-05-16 20:10:11 0 [ERROR] Failed to initialize plugins.
 
2022-05-16 20:10:11 0 [ERROR] Aborting
 
220516 20:10:14 mysqld_safe Number of processes running now: 1
 
220516 20:10:14 mysqld_safe mysqld process hanging, pid 5205 - killed
 
220516 20:10:14 mysqld_safe mysqld restarted
 
2022-05-16 20:10:14 0 [Note] Using unique option prefix 'log_warning' is error-prone and can break in the future. Please use the full name 'log_warnings' instead.
 
2022-05-16 20:10:14 0 [Warning] option 'server_id': unsigned value 0 adjusted to 1
 
2022-05-16 20:10:14 0 [Warning] option 'join_buffer_size': unsigned value 0 adjusted to 128
 
2022-05-16 20:10:14 0 [Warning] 'THREAD_CONCURRENCY' is deprecated and will be removed in a future release.
 
2022-05-16 20:10:14 0 [Note] /usr/sbin/mysqld (mysqld 10.4.24-MariaDB-1:10.4.24+maria~stretch) starting as process 6450 ...
 
2022-05-16 20:10:14 0 [ERROR] mysqld: Can't lock aria control file '/var/lib/mysql/aria_log_control' for exclusive use, error: 11. Will retry for 30 seconds
 
220516 20:10:14 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended
 
2022-05-16 20:10:15 0 [Note] InnoDB: Using Linux native AIO
 
2022-05-16 20:10:15 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2022-05-16 20:10:15 0 [Note] InnoDB: Uses event mutexes
 
2022-05-16 20:10:15 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
2022-05-16 20:10:15 0 [Note] InnoDB: Number of pools: 1
 
2022-05-16 20:10:15 0 [Note] InnoDB: Using SSE2 crc32 instructions
 
2022-05-16 20:10:15 0 [Note] InnoDB: Initializing buffer pool, total size = 12G, instances = 8, chunk size = 128M
 
2022-05-16 20:10:15 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-05-16 20:10:15 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2022-05-16 20:10:15 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2022-05-16 20:10:15 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2022-05-16 20:10:15 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2022-05-16 20:10:15 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2022-05-16 20:10:15 0 [Note] InnoDB: Waiting for purge to start
 
2022-05-16 20:10:15 0 [Note] InnoDB: 10.4.24 started; log sequence number 3850943487193; transaction id 270612058
 
2022-05-16 20:10:15 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
 
2022-05-16 20:10:15 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-05-16 20:10:15 0 [Note] InnoDB: Buffer pool(s) load completed at 220516 20:10:15
 
Mon May 16 20:10:15 2022 PerconaFT recovery starting in env /var/lib/mysql/
 
Mon May 16 20:10:15 2022 PerconaFT recovery scanning backward from 100531930137
 
Mon May 16 20:10:15 2022 PerconaFT recovery bw_end_checkpoint at 100531923393 timestamp 1652728194938633 xid 100531923389 (bw_newer)
 
Mon May 16 20:10:15 2022 PerconaFT recovery bw_begin_checkpoint at 100531923389 timestamp 1652728194938622 (bw_between)
 
Mon May 16 20:10:15 2022 PerconaFT recovery turning around at begin checkpoint 100531923389 time 11
 
Mon May 16 20:10:15 2022 PerconaFT recovery starts scanning forward to 100531930137 from 100531923389 left 6748 (fw_between)
 
Mon May 16 20:10:16 2022 PerconaFT recovery closing 11 dictionaries
 
Mon May 16 20:10:17 2022 PerconaFT recovery making a checkpoint
 
Mon May 16 20:10:17 2022 PerconaFT recovery done
 
2022-05-16 20:10:17 0 [Note] Recovering after a crash using tc.log
 
2022-05-16 20:10:17 0 [Note] Starting crash recovery...
 
2022-05-16 20:10:17 0 [Note] Crash recovery finished.
 
2022-05-16 20:10:17 0 [Note] Server socket created on IP: '0.0.0.0'.
 
2022-05-16 20:10:17 0 [Warning] 'user' entry '@xpyusm' ignored in --skip-name-resolve mode.
 
2022-05-16 20:10:17 0 [Warning] 'user' entry 'root@xpyusm' ignored in --skip-name-resolve mode.
 
2022-05-16 20:10:17 6 [Note] Event Scheduler: scheduler thread started with id 6
 
2022-05-16 20:10:17 0 [Note] /usr/sbin/mysqld: ready for connections.
 
Version: '10.4.24-MariaDB-1:10.4.24+maria~stretch'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
 
220516 20:12:03 [ERROR] mysqld got signal 11 ;
 
This could be because you hit a bug. It is also possible that this binary
 
or one of the libraries it was linked against is corrupt, improperly built,
 
or misconfigured. This error can also be caused by malfunctioning hardware.
 
 
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
 
 
We will try our best to scrape up some info that will hopefully help
 
diagnose the problem, but since we have already crashed,
 
something is definitely wrong and this may fail.
 
 
 
Server version: 10.4.24-MariaDB-1:10.4.24+maria~stretch
 
key_buffer_size=536870912
 
read_buffer_size=131072
 
max_used_connections=18
 
max_threads=122
 
thread_count=24
 
It is possible that mysqld could use up to
 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 6789304 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x7f3e7b812008
 
Attempting backtrace. You can use the following information to find out
 
where mysqld died. If you see no messages after this, something went
 
terribly wrong...
 
stack_bottom = 0x7f3ece2eccb8 thread_stack 0x80000
 
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x558f0529e63e]
 
/usr/sbin/mysqld(handle_fatal_signal+0x3af)[0x558f04ce416f]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x110e0)[0x7f424736a0e0]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x7f3e7b844020): UPDATE host_scan SET status = 2 WHERE host_id = unhex('98B9CD4E1FA0AE33DFDECDFB0BE71609') AND plugin_id = 2007 AND plugin_sid = 0
 
 
 
Connection ID (thread ID): 749
 
Status: NOT_KILLED
 
 
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on
 
 
 
The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
 
information that should help you find out what is causing the crash.
 
Writing a core file...
 
Working directory at /var/lib/mysql
 
Resource Limits:
 
Limit                     Soft Limit           Hard Limit           Units
 
Max cpu time              unlimited            unlimited            seconds
 
Max file size             unlimited            unlimited            bytes
 
Max data size             unlimited            unlimited            bytes
 
Max stack size            8388608              unlimited            bytes
 
Max core file size        0                    unlimited            bytes
 
Max resident set          unlimited            unlimited            bytes
 
Max processes             289765               289765               processes
 
Max open files            1000000              1000000              files
 
Max locked memory         65536                65536                bytes
 
Max address space         unlimited            unlimited            bytes
 
Max file locks            unlimited            unlimited            locks
 
Max pending signals       289765               289765               signals
 
Max msgqueue size         819200               819200               bytes
 
Max nice priority         0                    0
 
Max realtime priority     0                    0
 
Max realtime timeout      unlimited            unlimited            us
 
Core pattern: core
 
 
 
220516 20:12:03 mysqld_safe Number of processes running now: 0
 
220516 20:12:03 mysqld_safe mysqld restarted
 
2022-05-16 20:12:03 0 [Note] Using unique option prefix 'log_warning' is error-prone and can break in the future. Please use the full name 'log_warnings' instead.
 
2022-05-16 20:12:03 0 [Warning] option 'server_id': unsigned value 0 adjusted to 1
 
2022-05-16 20:12:03 0 [Warning] option 'join_buffer_size': unsigned value 0 adjusted to 128
 
2022-05-16 20:12:03 0 [Warning] 'THREAD_CONCURRENCY' is deprecated and will be removed in a future release.
 
2022-05-16 20:12:03 0 [Note] /usr/sbin/mysqld (mysqld 10.4.24-MariaDB-1:10.4.24+maria~stretch) starting as process 19054 ...
 
2022-05-16 20:12:04 0 [Note] InnoDB: Using Linux native AIO
 
2022-05-16 20:12:04 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2022-05-16 20:12:04 0 [Note] InnoDB: Uses event mutexes
 
2022-05-16 20:12:04 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
2022-05-16 20:12:04 0 [Note] InnoDB: Number of pools: 1
 
2022-05-16 20:12:04 0 [Note] InnoDB: Using SSE2 crc32 instructions
 
2022-05-16 20:12:04 0 [Note] InnoDB: Initializing buffer pool, total size = 12G, instances = 8, chunk size = 128M
 
2022-05-16 20:12:04 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-05-16 20:12:04 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2022-05-16 20:12:04 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3850943715499
 
2022-05-16 20:12:05 0 [Note] InnoDB: Starting final batch to recover 1 pages from redo log.
 
2022-05-16 20:12:05 0 [Note] InnoDB: Last binlog file '/var/log/mysql/mariadb-bin.000884', position 53921890
 
2022-05-16 20:12:05 0 [Note] InnoDB: 128 out of 128 rollback segments are active.



 Comments   
Comment by Daniel Black [ 2022-05-25 ]

This looks like a clear out of server storage space issue.

'Could not get an exclusive lock' looks like you shutdown the server but another instance start up before it had finished. Its quite possible the shutdown was wanting more space too.

I see it eventually crashed on UPDATE host_scan. Is this a TokuDB table? With space issues I don't suppose a core file was saved anywhere?

Comment by Francisco Javier Rubio Campos [ 2022-05-25 ]

Hey Daniel,

It's so strange because there was enough disk space ...

XPYUSM:~# df -h
 
Filesystem     Type      Size  Used Avail Use% Mounted on
 
udev           devtmpfs   36G     0   36G   0% /dev
 
tmpfs          tmpfs     7.1G  4.8M  7.1G   1% /run
 
/dev/sda1      ext4      993G  618G  325G  66% /
 
tmpfs          tmpfs     5.0M     0  5.0M   0% /run/lock
 
tmpfs          tmpfs      18G  356K   18G   1% /run/shm

It is very curious that the space issue with Percona was reported on May 4th but the crash was on May 16th, 13 days later.

And host_scan is not a TokuDB table ...

MariaDB [alienvault]> show create table host_scan;
 
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
 
| Table     | Create Table                                                                                                                                                                                                                                                |
 
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
 
| host_scan | CREATE TABLE `host_scan` (
 
  `host_id` binary(16) NOT NULL,
 
  `plugin_id` int(11) NOT NULL,
 
  `plugin_sid` int(11) NOT NULL,
 
  `status` int(11) NOT NULL DEFAULT 0,
 
  PRIMARY KEY (`host_id`,`plugin_id`,`plugin_sid`)
 
) ENGINE=InnoDB DEFAULT CHARSET=utf8 |
 
+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
 
1 row in set (0.000 sec)
 
 
 
MariaDB [alienvault]>

Anyway, the most strange thing is why two processes are initialized in only 8 seconds, it seems that this situation is the origin of the issue. And it's not an isolated case because I have seen this behavior in more than 30 different systems that are running in 10.4.21 and 10.4.24. However, no problems with 10.4.8.

Comment by Daniel Black [ 2022-05-26 ]

I was scrolled too far right to notice the dates.

marko, serg, monty, this appears to be a regression caused by MDEV-24393.

The logs show a Can't lock aria control file '/var/lib/mysql/aria_log_control' however innodb continues and I assume is corrupting something.

As marko highlights in MDEV-24393, the advisory locks where successful in preventing multiple instances on the same data directory. Aria has this protection in aria_log_control independent on --external-locking. The failure of Aria to start up doesn't prevent InnoDB from continuing.

Could InnoDB advisory lock the ibdata1, ib_logfile0 and maybe more generally even ddl_recovery.log?

Comment by Daniel Black [ 2022-05-28 ]

note the availability of locks doesn't appear universal, but I'm unsure if its our problem to solve.

Comment by Marko Mäkelä [ 2022-05-31 ]

Based on comments in MDEV-24393, it was indeed serg’s intention that the InnoDB advisory locking be disabled by default.

To reduce the chance of corruption, I would suggest that we change the server startup as follows:

If an advisory lock on the Aria log file cannot be acquired (an advisory lock on that file will always be acquired), then we will refuse to start up the entire server.

Currently, only the Aria storage engine will fail to start up, and InnoDB will be able to corrupt its data and log files.

This suggested refinement would still not protect users who are starting multiple servers with different configurations, such that the innodb_data_home_dir or innodb_log_group_home_dir (or any manually created symbolic links in datadir) point to the same files, but it would help the common case of attempting to start multiple servers with the exact same configuration.

Comment by Marko Mäkelä [ 2022-05-31 ]

I believe that MDEV-28697 is essentially a duplicate of this report.

Comment by Francisco Javier Rubio Campos [ 2022-06-08 ]

Sergei, do you know if this ticket is going to be fixed on 10.4.26 for Debian 9? It seems that 10.4.25 is the last version compatible with Debian 9.

Comment by Daniel Black [ 2022-06-08 ]

Debian 9 had its last release announced, is EOL on our depreciation policy, and is EOL in June 2022 from Debian.

Comment by Francisco Javier Rubio Campos [ 2022-06-09 ]

Thank you Daniel for your clarification. One more question, since this bug is not going to be released in 10.4.26 for Debian 9, do you know if there is any way to mitigate this? For instance, by changing something in the configuration files?
Or do you know if it would be possible to compile manually another 10.4.X version of MariaDB (that includes the fix) for Debian 9?

Comment by Marko Mäkelä [ 2022-06-09 ]

Fran, the mitigation --external-locking was already mentioned.

Comment by Francisco Javier Rubio Campos [ 2022-06-09 ]

Sorry Marko but I'm a little bit confused ...

I thought that --external-locking was only for MyISAM tables. Then enabling this option could help to prevent corruption in InnoDB tables?

Comment by Sergei Golubchik [ 2022-06-21 ]

after MDEV-24393 it also applies to InnoDB

Comment by Francisco Javier Rubio Campos [ 2022-06-21 ]

Thank you, Sergey.

Generated at Thu Feb 08 10:02:30 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.