[MDEV-28457] Crash in page_dir_find_owner_slot() Created: 2022-05-02  Updated: 2023-02-02  Resolved: 2022-06-09

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.5.13
Fix Version/s: 10.6.9, 10.7.5, 10.8.4, 10.9.2

Type: Bug Priority: Major
Reporter: Daniel T Assignee: Marko Mäkelä
Resolution: Fixed Votes: 1
Labels: corruption

Issue Links:
Blocks
blocks MDEV-28349 Provide "crash safe" options for CHEC... Open
is blocked by MDEV-13542 Crashing on a corrupted page is unhel... Closed
Problem/Incident
causes MDEV-28797 Assertion `page_rec_is_user_rec(rec)'... Closed

 Description   

On a 64bit , os Rocky Linux 8.5 (Green Obsidian), using 10.5.13 MariaDB, while checking some records inside a innodb 16M records table (SELECT * FROM... ORDER BY Id DESC LIMIT 100) - I suddenly got a total crash for MariaDB and the service keeps trying to fix and fails, then starts over... Reboot did not help either.
The os uses glibc-2.28-164.el8_5.3.x86_64 and bellow is the log line that was right before the loop crash failure:

2022-05-02 18:20:14 1691406 [ERROR] InnoDB: Probable data corruption on page 519096. Original record on that page;
(compact record)2022-05-02 18:20:14 1691406 [ERROR] InnoDB: Cannot find the dir slot for this record on that page;
(compact record)2022-05-02 18:20:14 0x7f908931c700  InnoDB: Assertion failure in file /builddir/build/BUILD/mariadb-10.5.9/storage/innobase/page/page0page.cc line 138
 
The loop failure log is bellow:
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
InnoDB: about forcing recovery.
220502 18:20:14 [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.9-MariaDB
key_buffer_size=402653184
read_buffer_size=2097152
max_used_connections=77
max_threads=302
thread_count=14
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 5967331 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f8f88071c48
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 = 0x7f908931bbd8 thread_stack 0x49000
??:0(my_print_stacktrace)[0x55b67cf70171]
??:0(handle_fatal_signal)[0x55b67ca18115]
sigaction.c:0(__restore_rt)[0x7f91b4904c20]
:0(__GI_raise)[0x7f91b269f37f]
:0(__GI_abort)[0x7f91b2689db5]
??:0(wsrep_write_dummy_event_low(THD*, char const*))[0x55b67c70990a]
??:0(wsrep_write_dummy_event_low(THD*, char const*))[0x55b67c6f0b34]
??:0(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > __gnu_cxx::__to_xstring<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, char>(int (*)(c
har*, unsigned long, char const*, __va_list_tag*), unsigned long, char const*, ...))[0x55b67cd53df8]
??:0(wsrep_notify_status(wsrep::server_state::state, wsrep::view const*))[0x55b67cd2187a]
??:0(wsrep_notify_status(wsrep::server_state::state, wsrep::view const*))[0x55b67cd2610c]
??: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>*))[0x55b67ce53609]
??: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>*))[0x55b67ce5369e]
??: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>*))[0x55b67ce33107]
??:0(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > __gnu_cxx::__to_xstring<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, char>(int (*)(c
har*, unsigned long, char const*, __va_list_tag*), unsigned long, char const*, ...))[0x55b67cdb7992]
??:0(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > __gnu_cxx::__to_xstring<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, char>(int (*)(c
har*, unsigned long, char const*, __va_list_tag*), unsigned long, char const*, ...))[0x55b67cdb7a7e]
??:0(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > __gnu_cxx::__to_xstring<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, char>(int (*)(c
har*, unsigned long, char const*, __va_list_tag*), unsigned long, char const*, ...))[0x55b67cdc81e3]
??:0(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > __gnu_cxx::__to_xstring<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, char>(int (*)(c
har*, unsigned long, char const*, __va_list_tag*), unsigned long, char const*, ...))[0x55b67cdc8e57]
??:0(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > __gnu_cxx::__to_xstring<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, char>(int (*)(c
har*, unsigned long, char const*, __va_list_tag*), unsigned long, char const*, ...))[0x55b67cda3304]
??:0(wsrep_notify_status(wsrep::server_state::state, wsrep::view const*))[0x55b67ccebd16]
??:0(handler::ha_update_row(unsigned char const*, unsigned char const*))[0x55b67ca25d82]
??:0(mysql_update(THD*, TABLE_LIST*, List<Item>&, List<Item>&, Item*, unsigned int, st_order*, unsigned long long, bool, unsigned long long*, unsigned long long*))[0x55b67c8d42f5]
??:0(mysql_execute_command(THD*))[0x55b67c82961f]
??:0(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x55b67c81b5ba]
??:0(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x55b67c826755]
??:0(do_command(THD*))[0x55b67c827734]
??:0(do_handle_one_connection(CONNECT*, bool))[0x55b67c916268]
??:0(handle_one_connection)[0x55b67c91666d]
??:0(MyCTX_nopad::finish(unsigned char*, unsigned int*))[0x55b67cc3bb6f]
pthread_create.c:0(start_thread)[0x7f91b48fa17a]
:0(__GI___clone)[0x7f91b2764dc3]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7f8f8801e1e0): update feed308_buffer set Id = Id+15500070
 
Connection ID (thread ID): 1691406
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,deriv
ed_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,exi
sts_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.
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             63030                63030                processes
Max open files            8531                 8531                 files
Max locked memory         65536                65536                bytes
Max address space         unlimited            unlimited            bytes
Max file locks            unlimited            unlimited            locks
Max pending signals       63030                63030                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: |/usr/lib/systemd/systemd-coredump %P %u %g %s %t %c %h %e

Then it says the recovery was done BUT NO, it keeps crashing...



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

Stack trace has similarities to MDEV-27765. Are you sure about 10.5.13? The error log lists 10.5.9. Did you update after the crash?

The stack trace info shows the triggering query was update feed308_buffer set Id = Id+15500070.

Can you install the MariaDB-server-debuginfo corresponding to your server version. Then coredumpctl debug followed by thread apply all bt -frame-arguments all full.

From MDEV-27734, recommending changing to innodb_change_buffering=none.

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

The stack trace output above handler::ha_update_row() is incorrect. That is a bug in the MariaDB crash handler.
Based on the number of stack frames, the crash might occur during a merge of the change buffer. The message is output by the function page_dir_find_owner_slot(), which has many other callers as well.

Disabling the change buffer alone would not fix such corruption. Rebuilding the table (ALTER TABLE feed308_buffer FORCE;) should.

Comment by Daniel T [ 2022-05-03 ]

Hi Marko,
Yes, you are right - at the failure moment the mariadb version was 10.5.9 and AFTER the crash i update it, hoping for that to help some way, but it did not.
The only way I managed to make mariadb work again was to delete the innodb file for the table i was working on (luckily had separate file per each innodb table) and restore it from latest sql backup dump. For any other config change, the innodb auto repair simply kept staying in repair + false success loop, over and over again.
Thank you.

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

I do not have enough information to guess the cause of the corruption. Among other things, it could be something in Galera snapshot transfer (MDEV-24845) or something in recovery (say, MDEV-28043).

In MDEV-13542, many sources of crash on corrupted data were removed, but not this one.

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