-
Type:
Bug
-
Status: Open (View Workflow)
-
Priority:
Critical
-
Resolution: Unresolved
-
Affects Version/s: 10.5.6
-
Fix Version/s: 10.5
-
Component/s: Platform RedHat, Storage Engine - InnoDB
-
Environment:Centos 7.8.2003, 32 vCore, 256GB RAM
See below error dump & attached core dump, happens sporadically 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. System is not under excessive load at the time the problems manifests. Problem also was manifest in 10.5.5
2020-12-01 11:11:36 0x7f474137d700 InnoDB: Assertion failure in file /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX/mariadb-10.5.6/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.
201201 11:11:36 [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.6-MariaDB-log
key_buffer_size=67108864
read_buffer_size=1048576
max_used_connections=624
max_threads=1252
thread_count=462
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: 0x7f44840b6ef8
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 = 0x7f474137cc90 thread_stack 0x49000
Can't start addr2line
/usr/sbin/mariadbd(my_print_stacktrace+0x2e)[0x5581d45b00ae]
/usr/sbin/mariadbd(handle_fatal_signal+0x307)[0x5581d3fb15d7]
/lib64/libpthread.so.0(+0xf630)[0x7f7f13604630]
/lib64/libc.so.6(gsignal+0x37)[0x7f7f1165e387]
/lib64/libc.so.6(abort+0x148)[0x7f7f1165fa78]
/usr/sbin/mariadbd(+0x64c5b7)[0x5581d3c8f5b7]
/usr/sbin/mariadbd(+0xdaa307)[0x5581d43ed307]
/usr/sbin/mariadbd(+0xdaa433)[0x5581d43ed433]
/usr/sbin/mariadbd(+0xdaa714)[0x5581d43ed714]
/usr/sbin/mariadbd(+0xc4c83c)[0x5581d428f83c]
/usr/sbin/mariadbd(+0xc57893)[0x5581d429a893]
/usr/sbin/mariadbd(_ZN7handler16ha_external_lockEP3THDi+0x261)[0x5581d3fbd651]
/usr/sbin/mariadbd(+0xa6ae4a)[0x5581d40ade4a]
/usr/sbin/mariadbd(_Z24mysql_unlock_read_tablesP3THDP13st_mysql_lock+0x72)[0x5581d40ae6d2]
/usr/sbin/mariadbd(_ZN4JOIN9join_freeEv+0x169)[0x5581d3debc89]
/usr/sbin/mariadbd(_ZN4JOIN10exec_innerEv+0xc6c)[0x5581d3e1052c]
/usr/sbin/mariadbd(_ZN4JOIN4execEv+0x33)[0x5581d3e107e3]
/usr/sbin/mariadbd(_Z12mysql_selectP3THDP10TABLE_LISTR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x186)[0x5581d3e0e9a6]
/usr/sbin/mariadbd(_Z13handle_selectP3THDP3LEXP13select_resultm+0x1cc)[0x5581d3e0f50c]
/usr/sbin/mariadbd(+0x63340a)[0x5581d3c7640a]
/usr/sbin/mariadbd(_Z21mysql_execute_commandP3THD+0x37f5)[0x5581d3db55d5]
/usr/sbin/mariadbd(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x36a)[0x5581d3db84da]
/usr/sbin/mariadbd(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x1bbd)[0x5581d3dba84d]
/usr/sbin/mariadbd(_Z10do_commandP3THD+0x10b)[0x5581d3dbbfeb]
/usr/sbin/mariadbd(_Z24do_handle_one_connectionP7CONNECTb+0x1b2)[0x5581d3ea4b02]
/usr/sbin/mariadbd(handle_one_connection+0x34)[0x5581d3ea4db4]
/usr/sbin/mariadbd(+0xbb627d)[0x5581d41f927d]
/lib64/libpthread.so.0(+0x7ea5)[0x7f7f135fcea5]
/lib64/libc.so.6(clone+0x6d)[0x7f7f117268dd]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7f44840e5d90): SELECT * FROM `lookup_permissions_grid` WHERE `application` IN ('guest')
Connection ID (thread ID): 8019424
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 unlimited 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-12-01 11:12:06 0 [Note] mariadbd: Aria engine: starting recovery
recovered pages: 0% 16% 37% 59% 81% 94% 100% (0.0 seconds); tables to flush: 2 1 0
(2.5 seconds);
2020-12-01 11:12:08 0 [Note] mariadbd: Aria engine: recovery done
2020-12-01 11:12:08 0 [Warning] The parameter innodb_buffer_pool_instances is deprecated and has no effect.
2020-12-01 11:12:08 0 [Note] InnoDB: Using Linux native AIO
2020-12-01 11:12:08 0 [Note] InnoDB: Uses event mutexes
2020-12-01 11:12:08 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2020-12-01 11:12:08 0 [Note] InnoDB: Number of pools: 1
2020-12-01 11:12:08 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
2020-12-01 11:12:08 0 [Note] InnoDB: Initializing buffer pool, total size = 235149459456, chunk size = 134217728
2020-12-01 11:12:15 0 [Note] InnoDB: Completed initialization of buffer pool
2020-12-01 11:12:15 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-12-01 11:12:15 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=41701133623035
2020-12-01 11:12:16 0 [Note] InnoDB: 13 transaction(s) which must be rolled back or cleaned up in total 1710 row operations to undo
2020-12-01 11:12:16 0 [Note] InnoDB: Trx id counter is 128600878351
2020-12-01 11:12:16 0 [Note] InnoDB: Starting final batch to recover 6393 pages from redo log.
2020-12-01 11:12:17 0 [Note] InnoDB: Last binlog file '/mnt/db/mysqllogs/bin-log.016476', position 903131623
2020-12-01 11:12:17 0 [Note] InnoDB: 128 rollback segments are active.
2020-12-01 11:12:17 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
2020-12-01 11:12:17 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2020-12-01 11:12:17 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-12-01 11:12:17 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-12-01 11:12:17 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-12-01 11:12:17 0 [Note] InnoDB: 10.5.6 started; log sequence number 41701133722664; transaction id 128600878353
2020-12-01 11:12:17 0 [Note] InnoDB: Loading buffer pool(s) from /mnt/db/mysql/ib_buffer_pool
2020-12-01 11:12:17 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-12-01 11:12:17 0 [Note] Recovering after a crash using /mnt/db/mysqllogs/bin-log
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878319
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600873770
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878248
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878283
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878247
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600874989
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600876172
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600863931
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878174
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878294
2020-12-01 11:12:17 0 [Note] InnoDB: Rolled back recovered transaction 128600878322
2020-12-01 11:12:18 0 [Note] InnoDB: Rolled back recovered transaction 128600877747
2020-12-01 11:12:18 0 [Note] InnoDB: Rolled back recovered transaction 128600878337
2020-12-01 11:12:18 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2020-12-01 11:12:20 0 [Note] Starting crash recovery...
2020-12-01 11:12:20 0 [Note] Crash recovery finished.
2020-12-01 11:12:20 0 [Note] Server socket created on IP: '::'.
2020-12-01 11:12:20 0 [Note] Reading of all Master_info entries succeeded
2020-12-01 11:12:20 0 [Note] Added new Master_info '' to hash table
2020-12-01 11:12:20 0 [Note] /usr/sbin/mariadbd: ready for connections.
Version: '10.5.6-MariaDB-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
2020-12-01 11:12:20 131 [Warning] IP address '10.0.1.58' could not be resolved: Name or service not known
2020-12-01 11:12:22 715 [Warning] IP address '10.0.1.56' could not be resolved: Name or service not known
2020-12-01 11:13:00 23979 [Note] Start binlog_dump to slave_server(2), pos(bin-log.016476, 903133807), using_gtid(1), gtid('1-1-15145546826')
2020-12-01 11:13:00 23982 [Note] Start binlog_dump to slave_server(11), pos(bin-log.016476, 903133807), using_gtid(1), gtid('1-1-15145546826,2-1-3532097557')
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 --core_file --innodb_io_capacity=2000 --innodb_thread_concurrency=0
- is duplicated by
-
MDEV-24035 Failing assertion: UT_LIST_GET_LEN(lock.trx_locks) == 0 causing disruption and replication failure
-
- Closed
-