Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.5.5, 10.5.6, 10.6.12, 10.11.3, 10.6.16, 10.11.6
-
Centos 7.8.2003
Description
See below error dump, happens sporadically (every 2 to 3 weeks) resulting in dropping of all connections and evacuation of cache taking around 20 seconds to recover. In each case it is a random simple select that causes the issue. All tables are innodb and have been mysqlcheck'd with no issue found. Issue did not occur under 10.4 but coincided with move to 10.5.5. System is not under excessive load at the time the problems manifests. Recent upgrade to 10.5.6 has not resolved the issue
IMPORTANT : Knock on effect for replication slaves is duplicate records causing replication to fail - so this effectively looks like two bugs (duplicate updates can be skipped). I believe the assertion failure handling may be causing this secondary serious issue :
1) assertion failure on master host
2) replication failure on slave host
2020-10-21 14:47:03 0x7f45b0c42700 InnoDB: Assertion failure in file /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX/mariadb-10.5.5/storage/innobase/trx/trx0trx.cc line 1329
|
InnoDB: Failing assertion: UT_LIST_GET_LEN(lock.trx_locks) == 0
|
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.
|
201021 14:47:03 [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.5-MariaDB-log
|
key_buffer_size=67108864
|
read_buffer_size=1048576
|
max_used_connections=1137
|
max_threads=1252
|
thread_count=486
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2660907 K bytes of memory
|
Hope that's ok; if not, decrease some variables in the equation.
|
|
|
Thread pointer: 0x7f43a0064958
|
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 = 0x7f45b0c41c90 thread_stack 0x49000
|
Can't start addr2line
|
/usr/sbin/mariadbd(my_print_stacktrace+0x2e)[0x556585139f3e]
|
/usr/sbin/mariadbd(handle_fatal_signal+0x307)[0x556584b3c607]
|
/lib64/libpthread.so.0(+0xf630)[0x7f7d8a62e630]
|
/lib64/libc.so.6(gsignal+0x37)[0x7f7d88688387]
|
/lib64/libc.so.6(abort+0x148)[0x7f7d88689a78]
|
/usr/sbin/mariadbd(+0x64c5e7)[0x55658481a5e7]
|
/usr/sbin/mariadbd(+0xda9197)[0x556584f77197]
|
/usr/sbin/mariadbd(+0xda92c3)[0x556584f772c3]
|
/usr/sbin/mariadbd(+0xda95a4)[0x556584f775a4]
|
/usr/sbin/mariadbd(+0xc4b6cc)[0x556584e196cc]
|
/usr/sbin/mariadbd(+0xc56723)[0x556584e24723]
|
/usr/sbin/mariadbd(_ZN7handler16ha_external_lockEP3THDi+0x261)[0x556584b48681]
|
/usr/sbin/mariadbd(+0xa6ae7a)[0x556584c38e7a]
|
/usr/sbin/mariadbd(_Z24mysql_unlock_read_tablesP3THDP13st_mysql_lock+0x72)[0x556584c39702]
|
/usr/sbin/mariadbd(_ZN4JOIN9join_freeEv+0x169)[0x556584976cb9]
|
/usr/sbin/mariadbd(_ZN4JOIN10exec_innerEv+0xc6c)[0x55658499b55c]
|
/usr/sbin/mariadbd(_ZN4JOIN4execEv+0x33)[0x55658499b813]
|
/usr/sbin/mariadbd(_Z12mysql_selectP3THDP10TABLE_LISTR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x186)[0x5565849999d6]
|
/usr/sbin/mariadbd(_Z13handle_selectP3THDP3LEXP13select_resultm+0x1cc)[0x55658499a53c]
|
/usr/sbin/mariadbd(+0x63343a)[0x55658480143a]
|
/usr/sbin/mariadbd(_Z21mysql_execute_commandP3THD+0x37f5)[0x556584940605]
|
/usr/sbin/mariadbd(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x36a)[0x55658494350a]
|
/usr/sbin/mariadbd(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x1bbd)[0x55658494587d]
|
/usr/sbin/mariadbd(_Z10do_commandP3THD+0x10b)[0x55658494701b]
|
/usr/sbin/mariadbd(_Z24do_handle_one_connectionP7CONNECTb+0x1b2)[0x556584a2fb32]
|
/usr/sbin/mariadbd(handle_one_connection+0x34)[0x556584a2fde4]
|
/usr/sbin/mariadbd(+0xbb62ad)[0x556584d842ad]
|
/lib64/libpthread.so.0(+0x7ea5)[0x7f7d8a626ea5]
|
/lib64/libc.so.6(clone+0x6d)[0x7f7d887508dd]
|
|
|
Trying to get some variables.
|
Some pointers may be invalid and cause the dump to abort.
|
Query (0x7f43a0074710): SELECT * FROM `lookup_permissions_grid` WHERE `application` IN ('guest')
|
Connection ID (thread ID): 187768692
|
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.
|
Writing a core file...
|
Working directory at /mnt/db/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 1030944 1030944 processes
|
Max open files 16384 16384 files
|
Max locked memory 65536 65536 bytes
|
Max address space unlimited unlimited bytes
|
Max file locks unlimited unlimited locks
|
Max pending signals 1030944 1030944 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
|
|
|
2020-10-21 14:47:27 0 [Note] mariadbd: Aria engine: starting recovery
|
tables to flush: 2 1 0
|
(0.0 seconds);
|
2020-10-21 14:47:27 0 [Note] mariadbd: Aria engine: recovery done
|
mysqld --print-defaults
mysqld would have been started with the following arguments:
--datadir=/mnt/db/mysql --tmpdir=/var/lib/mysqltmp --sql-mode=STRICT_TRANS_TABLES,NO_ENGINE_SUBSTITUTION --userstat=1 --log_warnings=2 --thread_handling=one-thread-per-connection --thread-cache-size=16 --table-open-cache=4096 --table-definition-cache=2048 --query-cache-type=0 --sort-buffer-size=1M --read-buffer-size=1M --read-rnd-buffer-size=1M --join-buffer-size=1M --tmp-table-size=128M --max-heap-table-size=128M --back-log=100 --max-connections=1250 --max-connect-errors=10000 --max-allowed-packet=16M --interactive-timeout=28800 --wait-timeout=28800 --default-storage-engine=InnoDB --innodb=FORCE --key-buffer-size=64M --myisam-sort-buffer-size=128M --innodb-buffer-pool-size=224256M --innodb-log-file-size=100M --innodb-file-per-table=1 --innodb-open-files=4096 --innodb_flush_log_at_trx_commit=0 --innodb_buffer_pool_instances=16 --innodb_flush_method=O_DIRECT --log-output=FILE --slow-query-log=1 --slow-query-log-file=/mnt/db/mysql_slow.log --long-query-time=1 --character-set-server=utf8 --group_concat_max_len=40960 --log-error=/mnt/db/mysqld.log --open-files-limit=65535 --server-id=1 --gtid-domain-id=1 --log-bin=/mnt/db/mysqllogs/bin-log --relay-log-space-limit=16G --expire-logs-days=2 --sync-binlog=0 --innodb_io_capacity=2000 --innodb_thread_concurrency=0
|
Attachments
Issue Links
- causes
-
-
- Closed
-
-
-
- Confirmed
-
- duplicates
-
-
- Closed
-
- is blocked by
-
-
- Closed
-
- is duplicated by
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
MDEV-31259 mariadb server crash dump
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
- relates to
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Confirmed
-
-
-
- Confirmed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Needs Feedback
-
- mentioned in
-
Page Loading...
Activity
mleich, thank you. This crash must be due to the non-default setting innodb_adaptive_hash_index=ON. It is something that we might have a fix for in MDEV-35049.
I would suggest to test this patch with the default setting (the adaptive hash index was disabled by default in MDEV-20487), to hopefully find some misuse of transactions. It is also theoretically possible that the simplified logic around transaction savepoints, commit and rollback are making the problems go away. But then again, the original reported failure was never reproduced by us internally.
origin/10.6-MDEV-24035 840d19e4a60edec79c6ab6e7275c8bfedabfc985 2024-12-11T16:31:57+02:00
performed well in RQG testing. No new problems
The code looks good to me. I hope the fix will solve the described issue.
MDEV-35944 demonstrates that the function mysql_delete() (executing SQL DELETE statements) can ignore transaction abort and keep going, implicitly starting a new transaction in the storage engine. This could a likely explanation of why the reported crash occurred in the first place. In the test scenario that I checked, the initial locking read of DELETE (determining which records should be deleted) resulted in a transaction abort due to a deadlock (it could also be a lock wait timeout or an ACID violation due to innodb_snapshot_isolation), but mysql_delete() kept going.
Preliminary results of RQG testing on origin/10.6-
MDEV-2403515abe5a8eba370f9d53419d44c219ec9ae679326 2024-12-05T18:34:49+02:00pluto:/data/results/1733417653/TBR-2113$ gdb -c ./1/data/core.1841043 /data/Server_bin/10.6-MDEV-24035_debug_Og/bin/mariadbd(gdb) bt#0 __pthread_kill_implementation (no_tid=0, signo=11, threadid=140329635636800) at ./nptl/pthread_kill.c:44#1 __pthread_kill_internal (signo=11, threadid=140329635636800) at ./nptl/pthread_kill.c:78#2 __GI___pthread_kill (threadid=140329635636800, signo=11) at ./nptl/pthread_kill.c:89#3 0x0000562d139e066c in my_write_core (sig=11) at /data/Server/10.6-MDEV-24035/mysys/stacktrace.c:424#4 0x0000562d1318b756 in handle_fatal_signal (sig=11) at /data/Server/10.6-MDEV-24035/sql/signal_handler.cc:366#5 <signal handler called>#6 dict_index_t::get_n_nullable (this=0x7fa0b8075a50, n_prefix=12, n_prefix@entry=11) at /data/Server/10.6-MDEV-24035/storage/innobase/include/dict0mem.h:588#7 0x0000562d13692eed in rec_init_offsets_comp_ordinary<>(const rec_t *, const dict_index_t *, rec_offs *, ulint, const dict_col_t::def_t *, rec_leaf_format) (rec=<optimized out>, index=<optimized out>,offsets=offsets@entry=0x7fa0d404ca70, n_core=n_core@entry=8, def_val=def_val@entry=0x0, format=format@entry=REC_LEAF_INSTANT) at /data/Server/10.6-MDEV-24035/storage/innobase/rem/rem0rec.cc:344#8 0x0000562d136939c1 in rec_init_offsets (rec=<optimized out>, index=<optimized out>, n_core=n_core@entry=8, offsets=offsets@entry=0x7fa0d404ca70) at /data/Server/10.6-MDEV-24035/storage/innobase/rem/rem0rec.cc:651#9 0x0000562d136981b8 in rec_get_offsets_func (rec=<optimized out>, rec@entry=0x7fa10c656851 "\200", index=<optimized out>, index@entry=0x7fa0b8075a50, offsets=offsets@entry=0x7fa0d404ca70, n_core=8, n_fields=<optimized out>,file=file@entry=0x562d13e81a10 "/data/Server/10.6-MDEV-24035/storage/innobase/btr/btr0sea.cc", line=1319, heap=0x7fa10a155a98) at /data/Server/10.6-MDEV-24035/storage/innobase/rem/rem0rec.cc:938#10 0x0000562d138181ef in btr_search_drop_page_hash_index (block=block@entry=0x7fa10c360580, garbage_collect=garbage_collect@entry=false) at /data/Server/10.6-MDEV-24035/storage/innobase/btr/btr0sea.cc:1319#11 0x0000562d1385a656 in buf_LRU_free_page (bpage=bpage@entry=0x7fa10c360580, zip=zip@entry=true) at /data/Server/10.6-MDEV-24035/storage/innobase/buf/buf0lru.cc:952#12 0x0000562d138524d2 in buf_flush_LRU_list_batch (max=max@entry=2000, n=n@entry=0x7fa10a155c00) at /data/Server/10.6-MDEV-24035/storage/innobase/buf/buf0flu.cc:1294#13 0x0000562d13852f8d in buf_do_LRU_batch (max=max@entry=2000, n=n@entry=0x7fa10a155c00) at /data/Server/10.6-MDEV-24035/storage/innobase/buf/buf0flu.cc:1411#14 0x0000562d138530a1 in buf_flush_LRU (max_n=max_n@entry=2000) at /data/Server/10.6-MDEV-24035/storage/innobase/buf/buf0flu.cc:1757#15 0x0000562d13853e9b in buf_flush_page_cleaner () at /data/Server/10.6-MDEV-24035/storage/innobase/buf/buf0flu.cc:2427#16 0x0000562d1385496f in std::__invoke_impl<void, void (*)()> (__f=<optimized out>) at /usr/include/c++/11/bits/invoke.h:60#17 std::__invoke<void (*)()> (__fn=<optimized out>) at /usr/include/c++/11/bits/invoke.h:96#18 std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul> (this=<optimized out>) at /usr/include/c++/11/bits/std_thread.h:259#19 std::thread::_Invoker<std::tuple<void (*)()> >::operator() (this=<optimized out>) at /usr/include/c++/11/bits/std_thread.h:266#20 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)()> > >::_M_run (this=<optimized out>) at /usr/include/c++/11/bits/std_thread.h:211#21 0x00007fa119f19253 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6#22 0x00007fa119b9fac3 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442#23 0x00007fa119c31850 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81(gdb)