[MDEV-29536] InnoDB: Assertion failure Created: 2022-09-14  Updated: 2023-08-17  Resolved: 2022-10-22

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.5.17
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Andreas Kugler Assignee: Marko Mäkelä
Resolution: Incomplete Votes: 0
Labels: None
Environment:

Ubuntu 20.04.5 LTS
Hardware is a rented VM (Hetzner Cloud)

Issue Links:
Duplicate
duplicates MDEV-24035 Failing assertion: UT_LIST_GET_LEN(lo... Open
duplicates MDEV-25163 Rowid filter does not process storage... Closed

 Description   

Hi,

We are trying to run a Pimcore X 10.5.5. Unfortunately, we are encountering issues on one instance that we believe are due to a bug in the DB server.

10.5.17+maria~ubu2004
Ubuntu 20.04.5 LTS
Hardware is a rented VM (Hetzner Cloud)

Sep 14 11:45:14 ghdev-pimcorex-db01 mariadbd[46013]: 2022-09-14 11:45:14 2832 [Warning] Sort aborted, host: 10.202.54.27, user: pimcore, thread: 2832, query: SELECT m.* FROM messenger_messages m WHERE (m.delivered_at is null OR m.delivered_at < '2022-09-14 10:45:14') AND (m.available_at <= '2022-09-14 11:45:14') AND (m.queue_name = 'pimcore_maintenance') ORDER BY available_at ASC LIMIT 1 FOR UPDATE
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: 2022-09-14 11:46:33 2832 [Warning] Sort aborted, host: 10.202.54.27, user: pimcore, thread: 2832, query: SELECT m.* FROM messenger_messages m WHERE (m.delivered_at is null OR m.delivered_at < '2022-09-14 10:46:33') AND (m.available_at <= '2022-09-14 11:46:33') AND (m.queue_name = 'pimcore_maintenance') ORDER BY available_at ASC LIMIT 1 FOR UPDATE
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: 2022-09-14 11:46:33 0x7f5568154700  InnoDB: Assertion failure in file /home/buildbot/buildbot/build/mariadb-10.5.17/storage/innobase/trx/trx0trx.cc line 1292
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: InnoDB: Failing assertion: UT_LIST_GET_LEN(lock.trx_locks) == 0
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: InnoDB: We intentionally generate a memory trap.
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: InnoDB: If you get repeated assertion failures or crashes, even
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: InnoDB: immediately after the mysqld startup, there may be
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: InnoDB: corruption in the InnoDB tablespace. Please refer to
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: InnoDB: about forcing recovery.
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: 220914 11:46:33 [ERROR] mysqld got signal 6 ;
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: This could be because you hit a bug. It is also possible that this binary
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: or one of the libraries it was linked against is corrupt, improperly built,
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: or misconfigured. This error can also be caused by malfunctioning hardware.
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: We will try our best to scrape up some info that will hopefully help
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: diagnose the problem, but since we have already crashed,
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: something is definitely wrong and this may fail.
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: Server version: 10.5.17-MariaDB-1:10.5.17+maria~ubu2004
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: key_buffer_size=134217728
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: read_buffer_size=131072
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: max_used_connections=14
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: max_threads=153
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: thread_count=14
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: It is possible that mysqld could use up to
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467873 K  bytes of memory
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: Hope that's ok; if not, decrease some variables in the equation.
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: Thread pointer: 0x7f523c000c58
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: Attempting backtrace. You can use the following information to find out
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: where mysqld died. If you see no messages after this, something went
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: terribly wrong...
 
Sep 14 11:46:33 ghdev-pimcorex-db01 mariadbd[46013]: stack_bottom = 0x7f5568153d58 thread_stack 0x49000
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(my_print_stacktrace)[0x5650366865e2]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(handle_fatal_signal)[0x5650360c9cd5]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(__restore_rt)[0x7f556f14e420]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(gsignal)[0x7f556ec5200b]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(abort)[0x7f556ec31859]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(Wsrep_server_service::log_dummy_write_set(wsrep::client_state&, wsrep::ws_meta const&))[0x565035d80be9]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??: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>*))[0x56503650617d]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??: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>*))[0x565036503309]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??: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>*))[0x5650365034e7]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(wsrep_notify_status(wsrep::server_state::state, wsrep::view const*))[0x5650363cf5fc]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(wsrep_notify_status(wsrep::server_state::state, wsrep::view const*))[0x5650363dbc89]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(handler::ha_external_lock(THD*, int))[0x5650360d7db4]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(mysql_unlock_tables(THD*, st_mysql_lock*, bool))[0x5650361dbbba]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(JOIN::optimize_stage2())[0x565035f18976]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(JOIN::optimize_inner())[0x565035f1c20f]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(JOIN::optimize())[0x565035f1e663]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(mysql_select(THD*, TABLE_LIST*, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*))[0x565035f1e737]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(handle_select(THD*, LEX*, select_result*, unsigned long))[0x565035f1f177]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(LEX::mark_first_table_as_inserting())[0x565035eab831]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(mysql_execute_command(THD*))[0x565035eba6ad]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x565035ea5f2f]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x565035eb2b65]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(do_command(THD*))[0x565035eb5573]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(do_handle_one_connection(CONNECT*, bool))[0x565035fbde21]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(handle_one_connection)[0x565035fbe29d]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(MyCTX_nopad::finish(unsigned char*, unsigned int*))[0x5650363282df]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(start_thread)[0x7f556f142609]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: ??:0(clone)[0x7f556ed2e133]
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Trying to get some variables.
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Some pointers may be invalid and cause the dump to abort.
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Query (0x7f523c0104d0): SELECT o_type,o_className,o_classId FROM objects WHERE o_id = '38563'
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Connection ID (thread ID): 2832
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Status: NOT_KILLED
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: 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
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: information that should help you find out what is causing the crash.
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Writing a core file...
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Working directory at /var/lib/mysql
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Resource Limits:
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Limit                     Soft Limit           Hard Limit           Units
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max cpu time              unlimited            unlimited            seconds
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max file size             unlimited            unlimited            bytes
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max data size             unlimited            unlimited            bytes
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max stack size            8388608              unlimited            bytes
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max core file size        0                    unlimited            bytes
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max resident set          unlimited            unlimited            bytes
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max processes             62369                62369                processes
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max open files            32768                32768                files
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max locked memory         65536                65536                bytes
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max address space         unlimited            unlimited            bytes
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max file locks            unlimited            unlimited            locks
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max pending signals       62369                62369                signals
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max msgqueue size         819200               819200               bytes
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max nice priority         0                    0
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max realtime priority     0                    0
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Max realtime timeout      unlimited            unlimited            us
 
Sep 14 11:46:34 ghdev-pimcorex-db01 mariadbd[46013]: Core pattern: |/usr/share/apport/apport -p%p -s%s -c%c -d%d -P%P -u%u -g%g -- %E



 Comments   
Comment by Marko Mäkelä [ 2022-09-14 ]

aKugler, unfortunately MariaDB Server often produces incorrectly resolved stack traces for InnoDB. Can you please install the mariadb-server-10.5-dbgsym package? For diagnosing this, I would need a stack trace of all threads from the debugger.

Have there been any server crashes earlier? Any restores of a backup? Please see also MDEV-25163. Because innodb_force_recovery was mentioned there (without any details, which could have been very helpful) and because we have so far been unable to reproduce this crash internally, I suspect that the transaction metadata could be corrupted in some way.

Comment by Thore Güntel [ 2022-09-15 ]

Hi Marko,

we installed the Package you mentioned, but we got the same error - no more information than Andreas posted before. Can you please tell us how to get the information you need?

We experienced no crashes before. The Database was migrated, so backup-up on one server an restored on the other server. I also tried to use innodb_force_recovery=1 but it didnt solved the problem, so I removed it after some tests.

Comment by Thore Güntel [ 2022-09-22 ]

Hi @Marko Mäkelä,

are there any other thought from you side?

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

tguentel, did you check the GDB instructions that I linked to? Unlike the built-in crash reporter in the server, GDB should produce valid stack traces and also include function parameter values in the output.

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