[MDEV-30075] Assertion `slave_open_temp_tables || !temporary_tables' failed Created: 2022-11-23  Updated: 2023-11-28

Status: Open
Project: MariaDB Server
Component/s: Replication, Tests
Affects Version/s: 10.9, 10.11
Fix Version/s: 10.11

Type: Bug Priority: Major
Reporter: Angelique Sklavounos (Inactive) Assignee: Andrei Elkin
Resolution: Unresolved Votes: 0
Labels: None


 Description   

./mtr rpl.rpl_start_alter_7 --repeat 500

10.11 828394

CURRENT_TEST: rpl.rpl_start_alter_7
mysqltest: In included file "./include/wait_for_slave_param.inc":
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from /home/parallels/dev/build-10.11-828394/build1/mysql-test/suite/rpl/t/rpl_start_alter_7.test at line 79:
At line 75: query 'let $_slave_check_configured= query_get_value("SHOW SLAVE STATUS", Slave_IO_Running, 1)' failed: <Unknown> (2013): Lost connection to server during query
 
The result from queries just before the failure was:
< snip >
ERROR 23000: Duplicate entry '2' for key 'b'
ERROR 23000: Duplicate entry '2' for key 'b'
ERROR 23000: Duplicate entry '2' for key 'b'
ERROR 23000: Duplicate entry '2' for key 'b'
ERROR 23000: Duplicate entry '2' for key 'b'
ERROR 23000: Duplicate entry '2' for key 'b'
connection server_2;
drop database s2;
select @@gtid_binlog_pos;
@@gtid_binlog_pos
12-2-412
connection server_3;
start all slaves;
Warnings:
Note	1937	SLAVE 'm2' started
Note	1937	SLAVE 'm1' started
set default_master_connection = 'm1';
include/wait_for_slave_to_start.inc
set default_master_connection = 'm2';
include/wait_for_slave_to_start.inc
 
More results from queries before failure can be found in /home/parallels/dev/build-10.11-828394/build1/mysql-test/var/log/rpl_start_alter_7.log
 
 
Server [mysqld.3 - pid: 1435696, winpid: 1435696, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2022-11-22 21:33:35 622 [Note] Master connection name: 'm1'  Master_info_file: 'master-m1.info'  Relay_info_file: 'relay-log-m1.info'
2022-11-22 21:33:35 622 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16000', master_log_file='master-bin.000001', master_log_pos='72717'. New state master_host='127.0.0.1', master_port='16000', master_log_file='', master_log_pos='4'.
2022-11-22 21:33:35 622 [Note] Previous Using_Gtid=Slave_Pos. New Using_Gtid=Slave_Pos
2022-11-22 21:33:35 622 [Note] Master connection name: 'm2'  Master_info_file: 'master-m2.info'  Relay_info_file: 'relay-log-m2.info'
2022-11-22 21:33:35 622 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='', master_port='3306', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='16001', master_log_file='', master_log_pos='4'.
2022-11-22 21:33:35 622 [Note] Previous Using_Gtid=Slave_Pos. New Using_Gtid=Slave_Pos
2022-11-22 21:33:38 625 [Note] Master 'm2': Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16001' in log '' at position 4
2022-11-22 21:33:38 625 [Note] Master 'm2': Slave I/O thread: connected to master 'root@127.0.0.1:16001',replication starts at GTID position ''
2022-11-22 21:33:38 626 [Note] Master 'm2': Slave SQL thread initialized, starting replication in log 'FIRST' at position 4, relay log './mysqld-relay-bin-m2.000001' position: 4; GTID position ''
2022-11-22 21:33:38 635 [Note] Master 'm1': Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16000' in log '' at position 4
2022-11-22 21:33:38 636 [Note] Master 'm1': Slave SQL thread initialized, starting replication in log 'FIRST' at position 4, relay log './mysqld-relay-bin-m1.000001' position: 4; GTID position ''
2022-11-22 21:33:38 635 [Note] Master 'm1': Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication starts at GTID position ''
mariadbd: /home/parallels/dev/server/sql/temporary_tables.cc:1259: void THD::close_temporary_table(TABLE*): Assertion `slave_open_temp_tables || !temporary_tables' failed.
221122 21:33:38 [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.11.2-MariaDB-debug-log
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=2
max_threads=153
thread_count=14
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63934 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0xffff68001998
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 = 0xffff945006a8 thread_stack 0x49000
mysys/stacktrace.c:212(my_print_stacktrace)[0xaaaac4235d1c]
sql/signal_handler.cc:236(handle_fatal_signal)[0xaaaac38d5ae8]
addr2line: 'linux-vdso.so.1': No such file
linux-vdso.so.1(__kernel_rt_sigreturn+0x0)[0xffffac4f878c]
??:0(gsignal)[0xffffabba0cd8]
??:0(abort)[0xffffabb8da28]
??:0(uselocale)[0xffffabb9a3e4]
??:0(__assert_fail)[0xffffabb9a44c]
sql/temporary_tables.cc:1261(THD::close_temporary_table(TABLE*))[0xaaaac3809b58]
sql/temporary_tables.cc:1505(THD::free_temporary_table(TABLE*))[0xaaaac380a464]
sql/temporary_tables.cc:656(THD::drop_temporary_table(TABLE*, bool*, bool))[0xaaaac38082a0]
sql/sql_table.cc:11064(mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, Table_specification_st*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool, bool))[0xaaaac363e458]
sql/sql_alter.cc:557(Sql_cmd_alter_table::execute(THD*))[0xaaaac36f777c]
sql/sql_parse.cc:5999(mysql_execute_command(THD*, bool))[0xaaaac3527564]
sql/sql_parse.cc:7998(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0xaaaac352d254]
sql/log_event_server.cc:2170(Query_log_event::do_apply_event(rpl_group_info*, char const*, unsigned int))[0xaaaac3a7d358]
sql/log_event_server.cc:1617(Query_log_event::do_apply_event(rpl_group_info*))[0xaaaac3a7b83c]
sql/log_event.cc:4179(Log_event::apply_event(rpl_group_info*))[0xaaaac3a71054]
sql/slave.cc:3898(apply_event_and_update_pos_apply(Log_event*, THD*, rpl_group_info*, int))[0xaaaac33ff340]
sql/slave.cc:4095(apply_event_and_update_pos_for_parallel(Log_event*, THD*, rpl_group_info*))[0xaaaac33ffbd4]
sql/rpl_parallel.cc:62(rpt_handle_event(rpl_parallel_thread::queued_event*, rpl_parallel_thread*))[0xaaaac379a060]
sql/rpl_parallel.cc:1415(handle_rpl_parallel_thread)[0xaaaac379d6d0]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0xaaaac3c55028]
nptl/pthread_create.c:477(start_thread)[0xffffabfe451c]
??:0(clone)[0xffffabc3e22c]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0xffff6039fca1): alter table t1 add column c int
 
Connection ID (thread ID): 628
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 /home/parallels/dev/build-10.11-828394/build1/mysql-test/var/mysqld.3/data
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             15219                15219                processes
Max open files            1024                 1024                 files
Max locked memory         67108864             67108864             bytes
Max address space         unlimited            unlimited            bytes
Max file locks            unlimited            unlimited            locks
Max pending signals       15219                15219                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/share/apport/apport -p%p -s%s -c%c -d%d -P%P -u%u -g%g -- %E
 
Kernel version: Linux version 5.15.0-52-generic (buildd@bos02-arm64-010) (gcc (Ubuntu 9.4.0-1ubuntu1~20.04.1) 9.4.0, GNU ld (GNU Binutils for Ubuntu) 2.34) #58~20.04.1-Ubuntu SMP Thu Oct 13 13:10:09 UTC 2022

Don't think this is related to MDEV-27849.



 Comments   
Comment by Angelique Sklavounos (Inactive) [ 2022-11-25 ]

Andrei said he was aware of an issue related to this, so assigning to him for now.

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