[MDEV-27596] MariaDB service startup error in debian stretch Created: 2022-01-24  Updated: 2022-01-25

Status: Open
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.5.13
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Jose Hernández Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: crash
Environment:

Debian Stretch


 Description   

We can't start mariadb service in debian stretch, we only have this output:

2022-01-24 11:33:53 0 [Warning] 'debug' is disabled in this build
 
2022-01-24 11:33:53 0 [Note] mariadbd (mysqld 10.5.13-MariaDB-1:10.5.13+maria~stretch) starting as process 58180 ...
 
2022-01-24 11:33:53 0 [Note] InnoDB: Uses event mutexes
 
2022-01-24 11:33:53 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
2022-01-24 11:33:53 0 [Note] InnoDB: Number of pools: 1
 
2022-01-24 11:33:53 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
 
2022-01-24 11:33:53 0 [Note] InnoDB: Using Linux native AIO
 
2022-01-24 11:33:53 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
 
2022-01-24 11:33:53 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-01-24 11:33:53 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=211998879789,211998879789
 
2022-01-24 11:33:53 0 [Note] InnoDB: Starting final batch to recover 387 pages from redo log.
 
2022-01-24 11:33:54 0 [Note] InnoDB: 128 rollback segments are active.
 
2022-01-24 11:33:54 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
 
2022-01-24 11:33:54 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2022-01-24 11:33:54 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2022-01-24 11:33:54 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2022-01-24 11:33:54 0 [Note] InnoDB: 10.5.13 started; log sequence number 212029548059; transaction id 89176170
 
2022-01-24 11:33:54 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-01-24 11:33:54 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
 
2022-01-24 11:33:54 0 [Note] Server socket created on IP: '127.0.0.1'.
 
2022-01-24 11:33:54 0 [ERROR] [FATAL] InnoDB: Rec offset 99, cur1 offset 188, cur2 offset 172
 
220124 11:33:54 [ERROR] mysqld got signal 6 ;
 
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.5.13-MariaDB-1:10.5.13+maria~stretch
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=0
 
max_threads=153
 
thread_count=0
 
It is possible that mysqld could use up to
 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467872 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x563c41305558
 
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 = 0x7fe121df7b58 thread_stack 0x49000
 
addr2line: 2022-01-24 11:33:54 0 [Note] InnoDB: Buffer pool(s) load completed at 220124 11:33:54
 
'mariadbd': No hay tal fichero
 
mariadbd(my_print_stacktrace+0x2e)[0x563c3f7dba0e]
 
Printing to addr2line failed
 
mariadbd(handle_fatal_signal+0x38f)[0x563c3f1f531f]
 
??:0(__restore_rt)[0x7fe149a060e0]
 
2022-01-24 11:33:54 0 [Note] Reading of all Master_info entries succeeded
 
2022-01-24 11:33:54 0 [Note] Added new Master_info '' to hash table
 
2022-01-24 11:33:54 0 [Note] mariadbd: ready for connections.
 
Version: '10.5.13-MariaDB-1:10.5.13+maria~stretch'  socket: '/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
 
linux/raise.c:51(__GI_raise)[0x7fe148dfefff]
 
stdlib/abort.c:91(__GI_abort)[0x7fe148e0042a]
 
addr2line: 'mariadbd': No hay tal fichero
 
mariadbd(+0xd6ef91)[0x563c3f642f91]
 
mariadbd(+0xc8f6fc)[0x563c3f5636fc]
 
mariadbd(+0xc9f764)[0x563c3f573764]
 
mariadbd(+0xc88bb7)[0x563c3f55cbb7]
 
mariadbd(+0xc4c515)[0x563c3f520515]
 
mariadbd(+0xc524f0)[0x563c3f5264f0]
 
mariadbd(+0xdadbc1)[0x563c3f681bc1]
 
mariadbd(+0xdadd82)[0x563c3f681d82]
 
mariadbd(+0xd7c9a7)[0x563c3f6509a7]
 
mariadbd(+0xd8935a)[0x563c3f65d35a]
 
mariadbd(+0xd8dc98)[0x563c3f661c98]
 
mariadbd(+0xcfb072)[0x563c3f5cf072]
 
mariadbd(+0xcfb1ff)[0x563c3f5cf1ff]
 
mariadbd(+0xcf6489)[0x563c3f5ca489]
 
mariadbd(+0xcf763a)[0x563c3f5cb63a]
 
mariadbd(+0xcf7ad4)[0x563c3f5cbad4]
 
mariadbd(+0xcaa1be)[0x563c3f57e1be]
 
mariadbd(+0xd19726)[0x563c3f5ed726]
 
mariadbd(_ZN5tpool10task_group7executeEPNS_4taskE+0x72)[0x563c3f763e92]
 
mariadbd(_ZN5tpool19thread_pool_generic11worker_mainEPNS_11worker_dataE+0x4f)[0x563c3f762d4f]
 
??:0(std::error_code::default_error_condition() const)[0x7fe149528e6f]
 
nptl/pthread_create.c:456(start_thread)[0x7fe1499fc4a4]
 
x86_64/clone.S:99(clone)[0x7fe148eb4d0f]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x0): (null)
 
Connection ID (thread ID): 0
 
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,not_null_range_scan=off
 
 
 
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.
 
 
 
We think the query pointer is invalid, but we will try to print it anyway.
 
Query:
 
 
 
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             15060                15060                processes
 
Max open files            32184                32184                files
 
Max locked memory         65536                65536                bytes
 
Max address space         unlimited            unlimited            bytes
 
Max file locks            unlimited            unlimited            locks
 
Max pending signals       15060                15060                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

What could we do?

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

Can you tell what happened before this startup?

  • Did the previous version crash?
  • Do you have the journalctl log from the previous shutdown?
  • What operations where going on in the server when it was last being used?

Are you able to installed the debug symbols, for mariadb https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/#installing-debug-info-packages-from-mariadb-debian-or-ubuntu / https://wiki.debian.org/AutomaticDebugPackages ? ..

and then obtain a full backtrace on all threads - https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/#analyzing-a-core-file-with-gdb-on-linux ?

Comment by Jose Hernández [ 2022-01-25 ]

Hello Daniel, is the first time that we get a corrupted table. In our research we have discovered:

  • We haven't update the server rencently so we are using the same version.
  • This is the complete journal of the crash

Jan 25 18:31:15 webserver mariadbd[24396]: 2022-01-25 18:31:15 1061 [ERROR] [FATAL] InnoDB: Rec offset 99, cur1 offset 188, cur2 offset 172
 
Jan 25 18:31:15 webserver mariadbd[24396]: 220125 18:31:15 [ERROR] mysqld got signal 6 ;
 
Jan 25 18:31:15 webserver mariadbd[24396]: This could be because you hit a bug. It is also possible that this binary
 
Jan 25 18:31:15 webserver mariadbd[24396]: or one of the libraries it was linked against is corrupt, improperly built,
 
Jan 25 18:31:15 webserver mariadbd[24396]: or misconfigured. This error can also be caused by malfunctioning hardware.
 
Jan 25 18:31:15 webserver mariadbd[24396]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
Jan 25 18:31:15 webserver mariadbd[24396]: We will try our best to scrape up some info that will hopefully help
 
Jan 25 18:31:15 webserver mariadbd[24396]: diagnose the problem, but since we have already crashed,
 
Jan 25 18:31:15 webserver mariadbd[24396]: something is definitely wrong and this may fail.
 
Jan 25 18:31:15 webserver mariadbd[24396]: Server version: 10.5.13-MariaDB-1:10.5.13+maria~stretch
 
Jan 25 18:31:15 webserver mariadbd[24396]: key_buffer_size=134217728
 
Jan 25 18:31:15 webserver mariadbd[24396]: read_buffer_size=131072
 
Jan 25 18:31:15 webserver mariadbd[24396]: max_used_connections=5
 
Jan 25 18:31:15 webserver mariadbd[24396]: max_threads=153
 
Jan 25 18:31:15 webserver mariadbd[24396]: thread_count=5
 
Jan 25 18:31:15 webserver mariadbd[24396]: It is possible that mysqld could use up to
 
Jan 25 18:31:15 webserver mariadbd[24396]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467872 K  bytes of memory
 
Jan 25 18:31:15 webserver mariadbd[24396]: Hope that's ok; if not, decrease some variables in the equation.
 
Jan 25 18:31:15 webserver mariadbd[24396]: Thread pointer: 0x7f166c0009b8
 
Jan 25 18:31:15 webserver mariadbd[24396]: Attempting backtrace. You can use the following information to find out
 
Jan 25 18:31:15 webserver mariadbd[24396]: where mysqld died. If you see no messages after this, something went
 
Jan 25 18:31:15 webserver mariadbd[24396]: terribly wrong...
 
Jan 25 18:31:15 webserver mariadbd[24396]: stack_bottom = 0x7f16b0ef5c78 thread_stack 0x49000
 
Jan 25 18:31:16 webserver mariadbd[24396]: /usr/sbin/mariadbd(my_print_stacktrace+0x2e)[0x55f38411ea0e]
 
Jan 25 18:31:16 webserver mariadbd[24396]: /usr/sbin/mariadbd(handle_fatal_signal+0x38f)[0x55f383b3831f]
 
Jan 25 18:31:17 webserver mariadbd[24396]: ??:0(__restore_rt)[0x7f16cabbf0e0]
 
Jan 25 18:31:17 webserver mariadbd[24396]: linux/raise.c:51(__GI_raise)[0x7f16c9fb7fff]
 
Jan 25 18:31:17 webserver mariadbd[24396]: stdlib/abort.c:91(__GI_abort)[0x7f16c9fb942a]
 
Jan 25 18:31:18 webserver mariadbd[24396]: /usr/sbin/mariadbd(+0xd6ef91)[0x55f383f85f91]
 
Jan 25 18:31:18 webserver mariadbd[24396]: /usr/sbin/mariadbd(+0xc8f6fc)[0x55f383ea66fc]
 
Jan 25 18:31:19 webserver mariadbd[24396]: /usr/sbin/mariadbd(+0xc9f764)[0x55f383eb6764]
 
Jan 25 18:31:19 webserver mariadbd[24396]: ??:0(std::_Rb_tree<unsigned int, unsigned int, std::_Identity<unsigned int>, std::less<unsigned int>, std::allocator<unsigned int> >::_M_erase(std::_Rb_tree_node<unsigned int>*))[0x55f383e9fbb7]
 
Jan 25 18:31:19 webserver mariadbd[24396]: page/page0page.cc:499(page_copy_rec_list_end_no_locks(buf_block_t*, buf_block_t*, unsigned char*, dict_index_t*, mtr_t*))[0x55f383e63515]
 
Jan 25 18:31:19 webserver mariadbd[24396]: include/assume_aligned.h:34(my_assume_aligned<8ul, void const*>)[0x55f383e694f0]
 
Jan 25 18:31:19 webserver mariadbd[24396]: page/page0cur.cc:1780(page_cur_insert_rec_zip(page_cur_t*, dict_index_t*, unsigned char const*, unsigned short*, mtr_t*))[0x55f383fc4bc1]
 
Jan 25 18:31:19 webserver mariadbd[24396]: include/page0cur.ic:283(page_cur_tuple_insert)[0x55f383fc4d82]
 
Jan 25 18:31:19 webserver mariadbd[24396]: ibuf/ibuf0ibuf.cc:3883(ibuf_insert_to_index_page)[0x55f383f939a7]
 
Jan 25 18:31:19 webserver mariadbd[24396]: buf/buf0buf.cc:3383(buf_page_get_low(page_id_t, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned int, mtr_t*, dberr_t*, bool))[0x55f383f8fa24]
 
Jan 25 18:31:19 webserver mariadbd[24396]: buf/buf0buf.cc:3464(buf_page_get_gen(page_id_t, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned int, mtr_t*, dberr_t*, bool))[0x55f383e33e33]
 
Jan 25 18:31:19 webserver mariadbd[24396]: include/btr0btr.h:237(btr_block_get_func(dict_index_t const&, unsigned int, unsigned long, bool, char const*, unsigned int, mtr_t*))[0x55f383b40b2d]
 
Jan 25 18:31:19 webserver mariadbd[24396]: btr/btr0btr.cc:4780(btr_validate_level)[0x55f383a36c93]
 
Jan 25 18:31:19 webserver mariadbd[24396]: handler/ha_innodb.cc:14822(ha_innobase::check(THD*, st_ha_check_opt*))[0x55f383a37c18]
 
Jan 25 18:31:19 webserver mariadbd[24396]: sql/handler.cc:4605(handler::ha_check(THD*, st_ha_check_opt*))[0x55f383931799]
 
Jan 25 18:31:19 webserver mariadbd[24396]: sql/sql_admin.cc:885(mysql_admin_table)[0x55f38393825c]
 
Jan 25 18:31:19 webserver mariadbd[24396]: sql/sql_admin.cc:1479(Sql_cmd_check_table::execute(THD*))[0x55f38392dfb9]
 
Jan 25 18:31:19 webserver mariadbd[24396]: sql/sql_parse.cc:6056(mysql_execute_command(THD*))[0x55f38392c38b]
 
Jan 25 18:31:19 webserver mariadbd[24396]: sql/sql_parse.cc:8117(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x55f383a29100]
 
Jan 25 18:31:19 webserver mariadbd[24396]: sql/sql_parse.cc:1951(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x55f383a297c4]
 
Jan 25 18:31:19 webserver mariadbd[24396]: sql/sql_parse.cc:1371(do_command(THD*))[0x55f383d76591]
 
Jan 25 18:31:19 webserver mariadbd[24396]: nptl/pthread_create.c:456(start_thread)[0x7f16cabb54a4]
 
Jan 25 18:31:19 webserver mariadbd[24396]: x86_64/clone.S:99(clone)[0x7f16ca06dd0f]
 
Jan 25 18:31:19 webserver mariadbd[24396]: Trying to get some variables.
 
Jan 25 18:31:19 webserver mariadbd[24396]: Some pointers may be invalid and cause the dump to abort.
 
Jan 25 18:31:19 webserver mariadbd[24396]: Query (0x7f166c010490): CHECK TABLE `oc_filecache`
 
Jan 25 18:31:19 webserver mariadbd[24396]: Connection ID (thread ID): 1061
 
Jan 25 18:31:19 webserver mariadbd[24396]: Status: NOT_KILLED
 
Jan 25 18:31:19 webserver mariadbd[24396]: 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,not_null_range_scan=off
 
Jan 25 18:31:19 webserver mariadbd[24396]: The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
 
Jan 25 18:31:19 webserver mariadbd[24396]: information that should help you find out what is causing the crash.
 
Jan 25 18:31:19 webserver mariadbd[24396]: Writing a core file...
 
Jan 25 18:31:19 webserver mariadbd[24396]: Working directory at /var/lib/mysql
 
Jan 25 18:31:19 webserver mariadbd[24396]: Resource Limits:
 
Jan 25 18:31:19 webserver mariadbd[24396]: Limit                     Soft Limit           Hard Limit           Units
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max cpu time              unlimited            unlimited            seconds
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max file size             unlimited            unlimited            bytes
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max data size             unlimited            unlimited            bytes
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max stack size            8388608              unlimited            bytes
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max core file size        0                    unlimited            bytes
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max resident set          unlimited            unlimited            bytes
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max processes             15060                15060                processes
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max open files            32768                32768                files
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max locked memory         65536                65536                bytes
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max address space         unlimited            unlimited            bytes
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max file locks            unlimited            unlimited            locks
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max pending signals       15060                15060                signals
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max msgqueue size         819200               819200               bytes
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max nice priority         0                    0
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max realtime priority     0                    0
 
Jan 25 18:31:19 webserver mariadbd[24396]: Max realtime timeout      unlimited            unlimited            us
 
Jan 25 18:31:19 webserver mariadbd[24396]: Core pattern: core
 
Jan 25 18:31:19 webserver systemd[1]: mariadb.service: Main process exited, code=killed, status=6/ABRT
 
Jan 25 18:31:19 webserver systemd[1]: mariadb.service: Unit entered failed state.
 
Jan 25 18:31:19 webserver systemd[1]: mariadb.service: Failed with result 'signal'.
 
Jan 25 18:31:24 webserver systemd[1]: mariadb.service: Service hold-off time over, scheduling restart.
 
Jan 25 18:31:24 webserver systemd[1]: Stopped MariaDB 10.5.13 database server.

  • Since the corrupted table is oc_filestore we think that this corruption can be a bug in nextcloud behaviour, but there is nothing before the crash in logs that looks relevant so we don't know exactly what happened.

We have fixed the database following this steps: [ https://www.digitalocean.com/community/tutorials/how-to-fix-corrupted-tables-in-mysql|https://www.digitalocean.com/community/tutorials/how-to-fix-corrupted-tables-in-mysql] making a backup of the table, drop in it and realoading from the backup and everything look ok now.

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