[MDEV-23217] 0x7fc561ffb700 InnoDB: Assertion failure Created: 2020-07-19  Updated: 2020-12-28  Resolved: 2020-12-28

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

Type: Bug Priority: Major
Reporter: Bill Platt Assignee: Marko Mäkelä
Resolution: Incomplete Votes: 0
Labels: need_feedback
Environment:

CentOS Linux release 8.2.2004 (Core)
Physical Server 32GB 6c/12t Xeon


 Description   

This popped up every time restarting after an error occurred importing databases. At first I was getting Mysql server went away messages piping one DB to another.

This error prevents MariaDB from starting up

Increase timeouts and buffer sizes while using a dump and then a separate command to import worked on databases that were created.

I then tried to import into a database that did not exist and the issue came back.

Deleting ib_logfile* ibtmp1 and tc.log while setting

innodb_force_recovery = 2
innodb_purge_threads=0

restarting, deleting the newly created files and restarting again got me back online

relevant section of the log file is below
-----------------------

2020-07-19 07:42:27 0x7fc561ffb700 InnoDB: Assertion failure in file /builddir/build/BUILD/mariadb-10.3.17/storage/innobase/btr/btr0sea.cc line 1415
InnoDB: Failing assertion: index->id == btr_page_get_index_id(page)
InnoDB: We intentionally generate a memory trap.

Server version: 10.3.17-MariaDB-log
key_buffer_size=268435456
read_buffer_size=1048576
max_used_connections=0
max_threads=153
thread_count=4

Thread pointer: 0x7fc538000c48
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 = 0x7fc561ffabd0 thread_stack 0x49000
/usr/libexec/mysqld(my_print_stacktrace+0x41)[0x562e97297c31]
/usr/libexec/mysqld(handle_fatal_signal+0x4e5)[0x562e96dc8c85]
sigaction.c:0(__restore_rt)[0x7fc5d08f6dd0]
:0(__GI_raise)[0x7fc5ce6b870f]
:0(__GI_abort)[0x7fc5ce6a2b25]
/usr/libexec/mysqld(+0x4c9a25)[0x562e96afea25]
/usr/libexec/mysqld(+0x4cd9ba)[0x562e96b029ba]
/usr/libexec/mysqld(+0xa6ddae)[0x562e970a2dae]
/usr/libexec/mysqld(+0xa63d7c)[0x562e97098d7c]
/usr/libexec/mysqld(+0x9e3ab2)[0x562e97018ab2]
/usr/libexec/mysqld(+0x9e59b5)[0x562e9701a9b5]
/usr/libexec/mysqld(+0x9e04a1)[0x562e970154a1]
/usr/libexec/mysqld(+0x9e096d)[0x562e9701596d]
/usr/libexec/mysqld(+0x9e2a06)[0x562e97017a06]
/usr/libexec/mysqld(+0x9e3579)[0x562e97018579]
/usr/libexec/mysqld(+0x9a8848)[0x562e96fdd848]
/usr/libexec/mysqld(+0xa08540)[0x562e9703d540]
pthread_create.c:0(start_thread)[0x7fc5d08ec2de]
:0(_GI__clone)[0x7fc5ce77ce83]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x0):
Connection ID (thread ID): 2
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=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html 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 unlimited unlimited bytes
Max resident set unlimited unlimited bytes
Max processes 127168 127168 processes
Max open files 1024 262144 files
Max locked memory 65536 65536 bytes
Max address space unlimited unlimited bytes
Max file locks unlimited unlimited locks
Max pending signals 127168 127168 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

 Comments   
Comment by Bill Platt [ 2020-07-19 ]

Log file after a successful start

2020-07-19 8:20:52 0 [Note] InnoDB: Using Linux native AIO
2020-07-19 8:20:52 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-07-19 8:20:52 0 [Note] InnoDB: Uses event mutexes
2020-07-19 8:20:52 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-07-19 8:20:52 0 [Note] InnoDB: Number of pools: 1
2020-07-19 8:20:52 0 [Note] InnoDB: Using SSE2 crc32 instructions
2020-07-19 8:20:52 0 [Note] InnoDB: Initializing buffer pool, total size = 1G, instances = 8, chunk size = 128M
2020-07-19 8:20:52 0 [Note] InnoDB: Completed initialization of buffer pool
2020-07-19 8:20:52 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-07-19 8:20:52 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2020-07-19 8:20:52 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-07-19 8:20:52 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-07-19 8:20:52 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-07-19 8:20:52 0 [Note] InnoDB: Waiting for purge to start
2020-07-19 8:20:52 0 [Note] InnoDB: 10.3.17 started; log sequence number 5667136747; transaction id 19097291
2020-07-19 8:20:52 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2020-07-19 8:20:52 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-07-19 8:20:52 0 [Note] InnoDB: Buffer pool(s) load completed at 200719 8:20:52
2020-07-19 8:20:52 0 [Note] Server socket created on IP: '::'.
2020-07-19 8:20:52 0 [Warning] 'proxies_priv' entry '@% root@web-02.goodguyssigns.com' ignored in --skip-name-resolve mode.
2020-07-19 8:20:52 6 [Warning] InnoDB: Table mysql/innodb_table_stats has length mismatch in the column name table_name. Please run mysql_upgrade
2020-07-19 8:20:52 6 [Warning] InnoDB: Table mysql/innodb_index_stats has length mismatch in the column name table_name. Please run mysql_upgrade
2020-07-19 8:20:52 0 [Note] Reading of all Master_info entries succeeded
2020-07-19 8:20:52 0 [Note] Added new Master_info '' to hash table
2020-07-19 8:20:52 0 [Note] /usr/libexec/mysqld: ready for connections.
Version: '10.3.17-MariaDB-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server

Comment by Elena Stepanova [ 2020-08-05 ]

Could be related to the recently fixed cluster of failures in btr_search_drop_page_hash_index (MDEV-23233 and siblings)?

Comment by Marko Mäkelä [ 2020-10-23 ]

I think that anything can happen if you kill the server, delete log files, and restart. You should never ever do that!

I cannot imagine that any bug in the adaptive hash index would cause index ID mismatch. The main reason for the index ID to be written to the B-tree pages is that it is used to validate the guesses in the adaptive hash index.

Does this corruption occur if you do not delete log files and do not prevent crash recovery by setting innodb_force_recovery=6?

Comment by Marko Mäkelä [ 2020-11-24 ]

elenst, sorry, I misread the description.

JazzBlueRT, did you get this kind of errors after upgrading to a later version? We fixed several bugs in the adaptive hash index lately, including some race conditions between buffer pool resizing and the adaptive hash index.

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