[MDEV-16539] Server crashes in THD::mark_tmp_table_as_free_for_reuse Created: 2018-06-20  Updated: 2022-10-03

Status: Open
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.2, 10.3
Fix Version/s: 10.3

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Elena Stepanova
Resolution: Unresolved Votes: 0
Labels: None

Attachments: File mysql.log    
Issue Links:
Relates
relates to MDEV-10356 rpl.rpl_parallel_temptable failure du... Closed

 Description   

_Note: until now, it was assumed that these failures might be the same as MDEV-11071. However, MDEV-11071 is fixed and closed now, but the crash still occurs (the revision under test contains the fix for MDEV-11071).

http://buildbot.askmonty.org/buildbot/builders/qa-win-rel/builds/5151/steps/result_summary/logs/stdio

10.2 d79bf0009a17f0020203003a97ce7e83449aeb3a

180620  4:48:47 [ERROR] mysqld got exception 0xc0000005 ;
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.2.16-MariaDB-log
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=7
max_threads=65537
thread_count=14
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 136060 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x652d502f28
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...
mysqld.exe!handler::ha_reset()[handler.cc:5933]
mysqld.exe!THD::mark_tmp_table_as_free_for_reuse()[temporary_tables.cc:768]
mysqld.exe!THD::mark_tmp_tables_as_free_for_reuse()[temporary_tables.cc:727]
mysqld.exe!close_thread_tables()[sql_base.cc:795]
mysqld.exe!Locked_tables_list::unlock_locked_tables()[sql_base.cc:2176]
mysqld.exe!Locked_tables_list::unlink_all_closed_tables()[sql_base.cc:2343]
mysqld.exe!Locked_tables_list::reopen_tables()[sql_base.cc:2389]
mysqld.exe!mysql_inplace_alter_table()[sql_table.cc:7492]
mysqld.exe!mysql_alter_table()[sql_table.cc:9390]
mysqld.exe!Sql_cmd_alter_table::execute()[sql_alter.cc:329]
mysqld.exe!mysql_execute_command()[sql_parse.cc:6223]
mysqld.exe!mysql_parse()[sql_parse.cc:8004]
mysqld.exe!dispatch_command()[sql_parse.cc:1823]
mysqld.exe!do_command()[sql_parse.cc:1374]
mysqld.exe!threadpool_process_request()[threadpool_common.cc:366]
mysqld.exe!tp_callback()[threadpool_common.cc:192]
ntdll.dll!RtlFreeUnicodeString()
ntdll.dll!RtlFreeUnicodeString()
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x652d95fd00): ALTER TABLE `t4` /* 100301 WAIT 5 */ FORCE, ALGORITHM=INPLACE /* QNO 1349 CON_ID 19 */
Connection ID (thread ID): 19
Status: KILL_TIMEOUT
 
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

windows 59febe381aafeca45419bb73b4a1144ca8a5fb20

perl E:\buildbot\rqg/runall-new.pl --grammar=conf/mariadb/optimizer.yy --gendata-advanced --skip-gendata --no-mask --queries=100M --duration=350 --threads=6 --seed=1529469830 --views --vcols --reporters=Backtrace,ErrorLog --validators=TransformerNoComparator --transformers=ExecuteAsCTE,ExecuteAsDeleteReturning,ExecuteAsExecuteImmediate,ExecuteAsInsertSelect,ExecuteAsUnion,ExecuteAsUpdateDelete,ExecuteAsView,ExecuteAsPreparedTwice,ExecuteAsSPTwice --redefine=conf/mariadb/general-workarounds.yy --redefine=conf/mariadb/alter_table.yy --redefine=conf/mariadb/bulk_insert.yy --mysqld=--log_output=FILE --mysqld=--log_bin_trust_function_creators=1 --mysqld=--log-bin --mysqld=--loose-max-statement-time=30 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --engine=InnoDB --mysqld=--innodb-buffer-pool-size=256M --mtr-build-thread=140 --basedir1=D:\qa-win-rel\install --vardir1=E:\buildbot\vardirs\qa-win-rel\10.2-5151\optim-combo/current1_1

Not reproducible right away (not surprisingly, given that it happens on KILL_TIMEOUT).



 Comments   
Comment by Elena Stepanova [ 2018-09-20 ]

New occurrence on 10.2: http://buildbot.askmonty.org/buildbot/builders/qa-win-rel/builds/5324/steps/result_summary/logs/stdio

Comment by Elena Stepanova [ 2018-12-21 ]

Still happens: http://buildbot.askmonty.org/buildbot/builders/qa-win-rel/builds/5635/steps/result_summary/logs/stdio

Comment by Elena Stepanova [ 2019-01-23 ]

New occurrence on 10.3: https://travis-ci.org/elenst/travis-tests/jobs/483082474 [2561 71 3]

Comment by Elena Stepanova [ 2019-05-02 ]

On 10.2: http://buildbot.askmonty.org/buildbot/builders/qa-win-rel/builds/6067/steps/result_summary/logs/stdio

10.2 2370eeb0

190502 12:42:21 [ERROR] mysqld got exception 0xc0000005 ;
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.2.24-MariaDB-log
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=8
max_threads=65537
thread_count=14
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 136063 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x30a28357b8
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...
mysqld.exe!handler::ha_reset()[handler.cc:6030]
mysqld.exe!THD::mark_tmp_table_as_free_for_reuse()[temporary_tables.cc:768]
mysqld.exe!THD::mark_tmp_tables_as_free_for_reuse()[temporary_tables.cc:727]
mysqld.exe!close_thread_tables()[sql_base.cc:797]
mysqld.exe!Locked_tables_list::unlock_locked_tables()[sql_base.cc:2222]
mysqld.exe!Locked_tables_list::unlink_all_closed_tables()[sql_base.cc:2389]
mysqld.exe!Locked_tables_list::reopen_tables()[sql_base.cc:2435]
mysqld.exe!mysql_inplace_alter_table()[sql_table.cc:7493]
mysqld.exe!mysql_alter_table()[sql_table.cc:9445]
mysqld.exe!mysql_recreate_table()[sql_table.cc:10275]
mysqld.exe!admin_recreate_table()[sql_admin.cc:57]
mysqld.exe!mysql_admin_table()[sql_admin.cc:1023]
mysqld.exe!Sql_cmd_optimize_table::execute()[sql_admin.cc:1366]
mysqld.exe!mysql_execute_command()[sql_parse.cc:6236]
mysqld.exe!mysql_parse()[sql_parse.cc:8018]
mysqld.exe!dispatch_command()[sql_parse.cc:1835]
mysqld.exe!do_command()[sql_parse.cc:1386]
mysqld.exe!threadpool_process_request()[threadpool_common.cc:366]
mysqld.exe!tp_callback()[threadpool_common.cc:192]
ntdll.dll!RtlFreeUnicodeString()
ntdll.dll!RtlFreeUnicodeString()
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x30a234fb70): OPTIMIZE TABLE t7 /* QNO 2527 CON_ID 20 */
Connection ID (thread ID): 20
Status: KILL_TIMEOUT
 
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

perl E:\buildbot\rqg/runall-new.pl --grammar=conf/partitioning/partitions.yy --gendata-advanced --skip-gendata --store-binaries --no-mask --queries=100M --duration=350 --threads=6 --seed=1556800658 --views --vcols --reporters=Backtrace,ErrorLog,Deadlock --validators=TransformerNoComparator --transformers=ExecuteAsCTE,ExecuteAsDeleteReturning,ExecuteAsExecuteImmediate,ExecuteAsInsertSelect,ExecuteAsUnion,ExecuteAsUpdateDelete,ExecuteAsView,ExecuteAsPreparedTwice,ExecuteAsSPTwice --redefine=conf/mariadb/general-workarounds.yy --redefine=conf/mariadb/alter_table.yy --redefine=conf/mariadb/bulk_insert.yy --mysqld=--log_output=FILE --mysqld=--log_bin_trust_function_creators=1 --mysqld=--log-bin --mysqld=--loose-max-statement-time=30 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --engine=InnoDB --mysqld=--innodb-buffer-pool-size=256M --mtr-build-thread=140 --basedir1=D:\qa-win-rel\install --vardir1=E:\buildbot\vardirs\qa-win-rel\10.2-6067\optim-combo/current1_1

Comment by Marko Mäkelä [ 2020-08-26 ]

http://buildbot.askmonty.org/buildbot/builders/kvm-bintar-centos6-amd64-debug/builds/3023/steps/mtr/logs/stdio

10.2 21a96581fd1dd11c5605dd89e3adbaabdf6de5eb

CURRENT_TEST: rpl.rpl_parallel_temptable
mysqltest: At line 132: failed in 'select master_pos_wait('master-bin.000002', 585, 300, '')': 2013: Lost connection to MySQL server during query
200826  5:04:57 [ERROR] mysqld got signal 11 ;
/usr/local/mariadb-10.2.34-linux-x86_64/bin/mysqld(handle_fatal_signal+0x30c)[0x7f0351b16ea5]
sigaction.c:0(__restore_rt)[0x7f0350fb94a0]
sql/sql_plist.h:181(THD::mark_tmp_tables_as_free_for_reuse())[0x7f0351ab8c8c]
sql/sql_base.cc:805(close_thread_tables(THD*))[0x7f03518ead44]
sql/sql_parse.cc:6046(mysql_execute_command(THD*))[0x7f035194b0d0]
sql/sql_parse.cc:7733(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x7f035194c1a8]
sql/log_event.cc:5361(Query_log_event::do_apply_event(rpl_group_info*, char const*, unsigned int))[0x7f0351c29fd7]
sql/log_event.cc:5040(Query_log_event::do_apply_event(rpl_group_info*))[0x7f0351c2a90a]
sql/log_event.h:1452(apply_event_and_update_pos_apply(Log_event*, THD*, rpl_group_info*, int))[0x7f03518ab56e]
sql/slave.cc:3764(apply_event_and_update_pos_for_parallel(Log_event*, THD*, rpl_group_info*))[0x7f03518b1af2]
sql/mysqld.h:759(rpt_handle_event(rpl_parallel_thread::queued_event*, rpl_parallel_thread*))[0x7f0351a8e59c]
sql/rpl_parallel.cc:1335(handle_rpl_parallel_thread)[0x7f0351a92943]
perfschema/pfs.cc:1872(pfs_spawn_thread)[0x7f03521257f6]
pthread_create.c:0(start_thread)[0x7f0350fb17f1]
/lib64/libc.so.6(clone+0x6d)[0x7f034ff31ccd]

Comment by Vladislav Vaintroub [ 2022-07-07 ]

tried to reproduced as described, with randgen, for 30 minutes, on current 10.3 , 66c06735a2aeff32d69e5d2a4378563ad474691f

Could not reproduce. "not reproducible right away" in the description may suggest I did not try too hard, but I need either clarification and simpler "how to repeat" method. Or maybe elenst could confirm that it does not happen anymore in her settings, too., and we could close it.

Generated at Thu Feb 08 08:29:40 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.