[MDEV-26264] server wont start after clean shutdown Created: 2021-07-28  Updated: 2022-03-12

Status: Open
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.3.27
Fix Version/s: 10.3

Type: Bug Priority: Major
Reporter: Gili Buzaglo Assignee: Thirunarayanan Balathandayuthapani
Resolution: Unresolved Votes: 0
Labels: hang
Environment:

centos 8.3
kernel:
4.18.0-240.22.1.el8_3.x86_64


Attachments: File mariadb.rar    
Issue Links:
Relates
relates to MDEV-14486 InnoDB hang on shutdown Confirmed

 Description   

We have service webapp application which uses mariadb as it's backend database.
Normally the application starts after poweroff/on.
On this occasion it didn't start due to mariadb crash loop.
We can see in log prior to crash that innodb shutdown was completed ok.



 Comments   
Comment by Gili Buzaglo [ 2021-07-28 ]

crash dump from /var/log/messages:

systemd-coredump[2186]: Process 1863 (mysqld) of user 27 dumped core.
 
Stack trace of thread 1946:
#0  0x00007f58e3fc87ff raise (libc.so.6)
#1  0x00007f58e3fb2cfe abort (libc.so.6)
#2  0x000055705c1c8c41 _ZN2ib5fatalD2Ev.cold.29 (mysqld)
#3  0x000055705c1ce8f6 _Z16buf_page_get_low9page_id_tRK11page_size_tmP11buf_block_tmPKcjP5mtr_tP7dberr_t.cold.191 (mysqld)
#4  0x000055705c65708b _ZL29ibuf_bitmap_get_map_page_func9page_id_tRK11page_size_tPKcjP5mtr_t (mysqld)
#5  0x000055705c65f380 _Z29ibuf_merge_or_delete_for_pageP11buf_block_t9page_id_tPK11page_size_tm (mysqld)
#6  0x000055705c780f1c _Z20buf_page_io_completeP10buf_page_tbb (mysqld)
#7  0x000055705c79b58b _ZL17buf_read_page_lowP7dberr_tbmm9page_id_tRK11page_size_tbb.constprop.48 (mysqld)
#8  0x000055705c79b6cd _Z24buf_read_page_background9page_id_tRK11page_size_tb (mysqld)
#9  0x000055705c78b11a _ZL8buf_loadv (mysqld)
#10 0x000055705c78b70b buf_dump_thread (mysqld)
#11 0x00007f58e620714a start_thread (libpthread.so.0)
#12 0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1913:
#0  0x00007f58e408878d syscall (libc.so.6)
#1  0x00007f58e5ddfb7e __io_getevents_0_4 (libaio.so.1)
#2  0x000055705c68b103 _ZN15LinuxAIOHandler7collectEv (mysqld)
#3  0x000055705c68ead0 _ZN15LinuxAIOHandler4pollEPP10fil_node_tPPvP9IORequest (mysqld)
#4  0x000055705c68ff0a _Z14os_aio_handlermPP10fil_node_tPPvP9IORequest (mysqld)
#5  0x000055705c7d5f67 _Z12fil_aio_waitm (mysqld)
#6  0x000055705c70d0f8 io_handler_thread (mysqld)
#7  0x00007f58e620714a start_thread (libpthread.so.0)
#8  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1919:
#0  0x00007f58e408878d syscall (libc.so.6)
#1  0x00007f58e5ddfb7e __io_getevents_0_4 (libaio.so.1)
#2  0x000055705c68b103_ZN15LinuxAIOHandler7collectEv (mysqld)
#3  0x000055705c68ead0 _ZN15LinuxAIOHandler4pollEPP10fil_node_tPPvP9IORequest (mysqld)
#4  0x000055705c68ff0a _Z14os_aio_handlermPP10fil_node_tPPvP9IORequest (mysqld)
#5  0x000055705c7d5f67 _Z12fil_aio_waitm (mysqld)
#6  0x000055705c70d0f8 io_handler_thread (mysqld)
#7  0x00007f58e620714a start_thread (libpthread.so.0)
#8  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1899:
#0  0x00007f58e620d64a pthread_cond_timedwait@@GLIBC_2.3.2 (libpthread.so.0)
#1  0x000055705c967be3 timer_handler (mysqld)
#2  0x00007f58e620714a start_thread (libpthread.so.0)
#3  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1917:
#0  0x00007f58e408878d syscall (libc.so.6)
#1  0x00007f58e5ddfb7e __io_getevents_0_4 (libaio.so.1)
#2  0x000055705c68b103 _ZN15LinuxAIOHandler7collectEv (mysqld)
#3  0x000055705c68ead0 _ZN15LinuxAIOHandler4pollEPP10fil_node_tPPvP9IORequest (mysqld)
#4  0x000055705c68ff0a _Z14os_aio_handlermPP10fil_node_tPPvP9IORequest (mysqld)
#5  0x000055705c7d5f67 _Z12fil_aio_waitm (mysqld)
#6  0x000055705c70d0f8 io_handler_thread(mysqld)
#7  0x00007f58e620714a start_thread (libpthread.so.0)
#8  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1916:
#0  0x00007f58e408878d syscall (libc.so.6)
#1  0x00007f58e5ddfb7e __io_getevents_0_4 (libaio.so.1)
#2  0x000055705c68b103 _ZN15LinuxAIOHandler7collectEv (mysqld)
#3  0x000055705c68ead0 _ZN15LinuxAIOHandler4pollEPP10fil_node_tPPvP9IORequest (mysqld)
#4  0x000055705c68ff0a _Z14os_aio_handlermPP10fil_node_tPPvP9IORequest (mysqld)
#5  0x000055705c7d5f67 _Z12fil_aio_waitm (mysqld)
#6  0x000055705c70d0f8 io_handler_thread (mysqld)
#7  0x00007f58e620714a start_thread (libpthread.so.0)
#8  0x00007f58e408df23 __clone (libc.so.6)
 
 
Stack trace of thread 1915:
#0  0x00007f58e408878d syscall (libc.so.6)
#1  0x00007f58e5ddfb7e __io_getevents_0_4 (libaio.so.1)
#2  0x000055705c68b103 _ZN15LinuxAIOHandler7collectEv (mysqld)
#3  0x000055705c68ead0_ZN15LinuxAIOHandler4pollEPP10fil_node_tPPvP9IORequest (mysqld)
#4  0x000055705c68ff0a _Z14os_aio_handlermPP10fil_node_tPPvP9IORequest (mysqld)
#5  0x000055705c7d5f67 _Z12fil_aio_waitm (mysqld)
#6  0x000055705c70d0f8 io_handler_thread (mysqld)
#7  0x00007f58e620714a start_thread (libpthread.so.0)
#8  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1979:
#0  0x00007f58e3fc95cc __sigtimedwait (libc.so.6)
#1  0x00007f58e62116ac sigwait (libpthread.so.0)
#2  0x000055705c1fc263 signal_hand (mysqld)
#3  0x00007f58e620714a start_thread (libpthread.so.0)
#4  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1941:
#0  0x00007f58e620d2fc pthread_cond_wait@@GLIBC_2.3.2 (libpthread.so.0)
#1  0x000055705c6910f9 _ZN8os_event8wait_lowEl (mysqld)
#2  0x000055705c7060fd _ZL17srv_resume_threadP10srv_slot_tlbm (mysqld)
#3  0x000055705c70ba60 srv_worker_thread (mysqld)
#4  0x00007f58e620714a start_thread (libpthread.so.0)
#5  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1949:
#0  0x00007f58e620d2fc pthread_cond_wait@@GLIBC_2.3.2 (libpthread.so.0)
#1  0x000055705c619afb thd_destructor_proxy (mysqld)
#2  0x00007f58e620714a start_thread (libpthread.so.0)
#3  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1914:
#0  0x00007f58e408878d syscall (libc.so.6)
 
#1  0x00007f58e5ddfb7e __io_getevents_0_4 (libaio.so.1)
#2  0x000055705c68b103 _ZN15LinuxAIOHandler7collectEv (mysqld)
#3  0x000055705c68ead0 _ZN15LinuxAIOHandler4pollEPP10fil_node_tPPvP9IORequest (mysqld)
#4  0x000055705c68ff0a _Z14os_aio_handlermPP10fil_node_tPPvP9IORequest (mysqld)
#5  0x000055705c7d5f67 _Z12fil_aio_waitm (mysqld)
#6  0x000055705c70d0f8 io_handler_thread (mysqld)
#7  0x00007f58e620714a start_thread (libpthread.so.0)
#8  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 2018:
#0  0x00007f58e620d2fc pthread_cond_wait@@GLIBC_2.3.2 (libpthread.so.0)
#1  0x000055705c21b7e3 handle_slave_background (mysqld)
#2  0x00007f58e620714astart_thread (libpthread.so.0)
#3  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1923:
#0  0x00007f58e620d64a pthread_cond_timedwait@@GLIBC_2.3.2 (libpthread.so.0)
#1  0x000055705c691026 _ZN8os_event10timed_waitEPK8timespec (mysqld)
#2  0x000055705c6911a9 _ZN8os_event13wait_time_lowEml (mysqld)
#3  0x000055705c1d1e22 buf_flush_page_cleaner_coordinator.cold.128 (mysqld)
#4  0x00007f58e620714a start_thread (libpthread.so.0)#012#5  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1934:
#0  0x00007f58e620d64a pthread_cond_timedwait@@GLIBC_2.3.2 (libpthread.so.0)
#1  0x000055705c691026 _ZN8os_event10timed_waitEPK8timespec (mysqld)#012#2  0x000055705c6911a9 _ZN8os_event13wait_time_lowEml (mysqld)
#3  0x000055705c70996f srv_error_monitor_thread (mysqld)
#4  0x00007f58e620714a start_thread (libpthread.so.0)
#5  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1960:
#0  0x00007f58e620d64a pthread_cond_timedwait@@GLIBC_2.3.2 (libpthread.so.0)
#1  0x000055705c869251 my_service_thread_sleep (mysqld)
#2  0x000055705c861fb1 ma_checkpoint_background (mysqld)
#3  0x00007f58e620714a start_thread (libpthread.so.0)
#4  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1920:
#0  0x00007f58e408878d syscall (libc.so.6)
#1  0x00007f58e5ddfb7e __io_getevents_0_4 (libaio.so.1)
#2  0x000055705c68b103 _ZN15LinuxAIOHandler7collectEv (mysqld)
#3  0x000055705c68ead0 _ZN15LinuxAIOHandler4pollEPP10fil_node_tPPvP9IORequest (mysqld)
#4  0x000055705c68ff0a _Z14os_aio_handlermPP10fil_node_tPPvP9IORequest (mysqld)
#5  0x000055705c7d5f67 _Z12fil_aio_waitm (mysqld)
#6  0x000055705c70d0f8 io_handler_thread (mysqld)
#7  0x00007f58e620714a start_thread (libpthread.so.0)
#8  0x00007f58e408df23 __clone (libc.so.6)
 
Stack trace of thread 1922:
#0  0x00007f58e408878d syscall (libc.so.6)
#1  0x00007f58e5ddfb7e __io_getevents_0_4 (libaio.so.1)
#2  0x000055705c68b103 _ZN15LinuxAIOHandler7collectEv (mysqld)
#3  0x000055705c68ead0 _ZN15LinuxAI

Comment by Gili Buzaglo [ 2021-07-28 ]

To recover I've performed the followings (guided by: https://mariadb.com/kb/en/innodb-recovery-modes/)
1) Edited /etc/my.cnf :
Added :
under: [mysqld]
innodb_force_recovery=1

2) service mariadb restart
3) Backup the database :
mysqldump nvmf > nvmf.sql
4) Restore from backup:
mysql nvmf < nvmf.sql
5) removed the line added in 1)

Is there a way to ensure that corruption will never occur ? performance degradation is not an issue

Comment by Gili Buzaglo [ 2021-09-12 ]

why is this still unassigned ?

Comment by Marko Mäkelä [ 2022-02-11 ]

This looks like a duplicate of MDEV-14486. Among the stack traces, I see only one srv_worker_thread and no purge coordinator thread.

Generated at Thu Feb 08 09:43:59 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.