Assertion `pending == log_requests.start.load(std::memory_order_relaxed)' failed in log_flush_notify_and_unlock or crash in MYSQL_BIN_LOG::mark_xid_done

--source include/have_innodb.inc

--source include/have_log_bin.inc

--connect (con1,localhost,root,,)

--let $conid= `select connection_id()`

--delimiter $

--send

LOOP

  FLUSH LOGS;

END LOOP $

--delimiter ;

--connection default

--let $run= 10000

--disable_query_log

while ($run)

{

  CREATE OR REPLACE TABLE t ENGINE=InnoDB AS SELECT 1 AS a;

  --dec $run

  if (!`SELECT MOD($run,1000)`)

  {

    --echo # $run loops left

  }

}

# Cleanup

--enable_query_log

--eval KILL $conid

DROP TABLE IF EXISTS t;

mariadbd: /data/src/10.5/storage/innobase/handler/ha_innodb.cc:4467: void log_flush_notify_and_unlock(log_flush_request*, lsn_t): Assertion `pending == log_requests.start.load(std::memory_order_relaxed)' failed.

210401  1:31:00 [ERROR] mysqld got signal 6 ;

#7  0x00007ff62bccaf36 in __GI___assert_fail (assertion=0x55d10e406a78 "pending == log_requests.start.load(std::memory_order_relaxed)", file=0x55d10e403708 "/data/src/10.5/storage/innobase/handler/ha_innodb.cc", line=4467, function=0x55d10e4069b8 "void log_flush_notify_and_unlock(log_flush_request*, lsn_t)") at assert.c:101

#8  0x000055d10db14833 in log_flush_notify_and_unlock (pending=0x7ff5f4025d48, lsn=3465869) at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:4467

#9  0x000055d10db14969 in log_flush_notify (flush_lsn=3465869) at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:4509

#10 0x000055d10dbf07ba in log_write_up_to (lsn=3465869, flush_to_disk=true, rotate_key=false) at /data/src/10.5/storage/innobase/log/log0log.cc:832

#11 0x000055d10debccc4 in fil_delete_tablespace (id=1921, if_exists=false, detached_handles=0x7ff625024310) at /data/src/10.5/storage/innobase/fil/fil0fil.cc:1827

#12 0x000055d10dcdff0a in row_drop_table_for_mysql (name=0x7ff625024990 "test/t", trx=0x7ff62631f360, sqlcom=SQLCOM_CREATE_TABLE, create_failed=false, nonatomic=true) at /data/src/10.5/storage/innobase/row/row0mysql.cc:3767

#13 0x000055d10db4274f in ha_innobase::delete_table (this=0x7ff5f00174b8, name=0x7ff625025c50 "./test/t", sqlcom=SQLCOM_CREATE_TABLE) at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:13304

#14 0x000055d10db29990 in ha_innobase::delete_table (this=0x7ff5f00174b8, name=0x7ff625025c50 "./test/t") at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:13431

#15 0x000055d10d698509 in hton_drop_table (hton=0x55d10fc84488, path=0x7ff625025c50 "./test/t") at /data/src/10.5/sql/handler.cc:564

#16 0x000055d10d69dcdd in ha_delete_table (thd=0x7ff5f0000db8, hton=0x55d10fc84488, path=0x7ff625025c50 "./test/t", db=0x7ff625025ad0, alias=0x7ff625025ae0, generate_warning=false) at /data/src/10.5/sql/handler.cc:2770

#17 0x000055d10d41e899 in mysql_rm_table_no_locks (thd=0x7ff5f0000db8, tables=0x7ff625026190, if_exists=false, drop_temporary=false, drop_view=false, drop_sequence=false, dont_log_query=true, dont_free_locks=true) at /data/src/10.5/sql/sql_table.cc:2508

#18 0x000055d10d426fcb in create_table_impl (thd=0x7ff5f0000db8, orig_db=..., orig_table_name=..., db=..., table_name=..., path=0x7ff625026940 "./test/t", options=..., create_info=0x7ff625027b80, alter_info=0x7ff625027ab0, create_table_mode=1, is_trans=0x0, key_info=0x7ff625026920, key_count=0x7ff625026914, frm=0x7ff625026930) at /data/src/10.5/sql/sql_table.cc:5260

#19 0x000055d10d4279bd in mysql_create_table_no_lock (thd=0x7ff5f0000db8, db=0x7ff5f0015558, table_name=0x7ff5f0015568, create_info=0x7ff625027b80, alter_info=0x7ff625027ab0, is_trans=0x0, create_table_mode=1, table_list=0x7ff5f0015540) at /data/src/10.5/sql/sql_table.cc:5460

#20 0x000055d10d2e62aa in select_create::create_table_from_items (this=0x7ff5f0016b70, thd=0x7ff5f0000db8, items=0x7ff625027640, lock=0x7ff625027630, hooks=0x7ff625027680) at /data/src/10.5/sql/sql_insert.cc:4462

#21 0x000055d10d2e6b03 in select_create::prepare (this=0x7ff5f0016b70, _values=..., u=0x7ff5f0004f68) at /data/src/10.5/sql/sql_insert.cc:4659

#22 0x000055d10d3786d3 in JOIN::prepare (this=0x7ff5f0016c70, tables_init=0x0, conds_init=0x0, og_num=0, order_init=0x0, skip_order_by=false, group_init=0x0, having_init=0x0, proc_param_init=0x0, select_lex_arg=0x7ff5f0015c20, unit_arg=0x7ff5f0004f68) at /data/src/10.5/sql/sql_select.cc:1506

#23 0x000055d10d3841cc in mysql_select (thd=0x7ff5f0000db8, tables=0x0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2201171004160, result=0x7ff5f0016b70, unit=0x7ff5f0004f68, select_lex=0x7ff5f0015c20) at /data/src/10.5/sql/sql_select.cc:4701

#24 0x000055d10d373d0b in handle_select (thd=0x7ff5f0000db8, lex=0x7ff5f0004ea0, result=0x7ff5f0016b70, setup_tables_done_option=0) at /data/src/10.5/sql/sql_select.cc:419

#25 0x000055d10d43b8f8 in Sql_cmd_create_table_like::execute (this=0x7ff5f00154e0, thd=0x7ff5f0000db8) at /data/src/10.5/sql/sql_table.cc:12100

#26 0x000055d10d335270 in mysql_execute_command (thd=0x7ff5f0000db8) at /data/src/10.5/sql/sql_parse.cc:6049

#27 0x000055d10d33b494 in mysql_parse (thd=0x7ff5f0000db8, rawbuf=0x7ff5f0015410 "CREATE OR REPLACE TABLE t ENGINE=InnoDB AS SELECT 1 AS a", length=56, parser_state=0x7ff625028510, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:8093

#28 0x000055d10d32735f in dispatch_command (command=COM_QUERY, thd=0x7ff5f0000db8, packet=0x7ff5f000b6c9 "CREATE OR REPLACE TABLE t ENGINE=InnoDB AS SELECT 1 AS a", packet_length=56, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1889

#29 0x000055d10d325b53 in do_command (thd=0x7ff5f0000db8) at /data/src/10.5/sql/sql_parse.cc:1370

#30 0x000055d10d4d43b7 in do_handle_one_connection (connect=0x55d1102a1638, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1410

#31 0x000055d10d4d411a in handle_one_connection (arg=0x55d1102637d8) at /data/src/10.5/sql/sql_connect.cc:1312

#32 0x000055d10da36217 in pfs_spawn_thread (arg=0x55d1101e55c8) at /data/src/10.5/storage/perfschema/pfs.cc:2201

#33 0x00007ff62c1e2609 in start_thread (arg=<optimized out>) at pthread_create.c:477

#34 0x00007ff62bdb6293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

commit 8c2e3259c13d1d0a494fb3f9c1e5fb780a193ab1

Author: Marko Mäkelä

Date:   Tue Mar 30 09:58:24 2021 +0300

    MDEV-24302 follow-up: RESET MASTER hangs

#3  <signal handler called>

#4  0x0000558c9c457070 in MYSQL_BIN_LOG::mark_xid_done (this=0x558c9d2bcca0 <mysql_bin_log>, binlog_id=2661, write_checkpoint=<optimized out>) at /data/src/10.5/include/mysql/psi/mysql_thread.h:759

#5  0x0000558c9c4576f5 in binlog_background_thread (arg=arg@entry=0x0) at /data/src/10.5/sql/log.cc:10381

#6  0x0000558c9c5d2ca6 in pfs_spawn_thread (arg=0x558c9e87a698) at /data/src/10.5/storage/perfschema/pfs.cc:2201

#7  0x00007fa37023e609 in start_thread (arg=<optimized out>) at pthread_create.c:477

#8  0x00007fa36fe2d293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 26 (Thread 0x7fa369085700 (LWP 742707)):

#0  __lll_lock_wait (futex=futex@entry=0x558c9d2bccb0 <mysql_bin_log+16>, private=0) at lowlevellock.c:52

#1  0x00007fa3702410a3 in __GI___pthread_mutex_lock (mutex=mutex@entry=0x558c9d2bccb0 <mysql_bin_log+16>) at ../nptl/pthread_mutex_lock.c:80

#2  0x0000558c9c447e33 in inline_mysql_mutex_lock (that=that@entry=0x558c9d2bccb0 <mysql_bin_log+16>, src_line=src_line@entry=6608, src_file=0x558c9cbd825c "/data/src/10.5/sql/log.cc") at /data/src/10.5/include/mysql/psi/mysql_thread.h:752

#3  0x0000558c9c4609b1 in MYSQL_BIN_LOG::write (this=0x558c9d2bcca0 <mysql_bin_log>, event_info=event_info@entry=0x7fa3690837f0, with_annotate=with_annotate@entry=0x0) at /data/src/10.5/sql/log.cc:6608

#4  0x0000558c9c0f1d68 in THD::binlog_query (this=0x7fa32c000c58, qtype=qtype@entry=THD::ROW_QUERY_TYPE, query_arg=0x7fa32c010580 "CREATE OR REPLACE TABLE t ENGINE=InnoDB AS SELECT 1 AS a", query_len=56, is_trans=<optimized out>, is_trans@entry=true, direct=<optimized out>, direct@entry=false, suppress_use=false, errcode=0) at /data/src/10.5/sql/sql_class.cc:7475

#5  0x0000558c9c109717 in select_insert::prepare_eof (this=this@entry=0x7fa32c011ce0) at /data/src/10.5/sql/sql_class.h:1270

#6  0x0000558c9c109b36 in select_create::send_eof (this=0x7fa32c011ce0) at /data/src/10.5/sql/sql_insert.cc:4897

#7  0x0000558c9c1acbf2 in JOIN::exec_inner (this=0x7fa32c011de0) at /data/src/10.5/sql/sql_select.cc:4348

#8  0x0000558c9c1ad209 in JOIN::exec (this=this@entry=0x7fa32c011de0) at /data/src/10.5/sql/sql_select.cc:4249

#9  0x0000558c9c1ab19a in mysql_select (thd=0x7fa32c000c58, tables=0x0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=<optimized out>, result=0x7fa32c011ce0, unit=0x7fa32c004c48, select_lex=0x7fa32c010d90) at /data/src/10.5/sql/sql_select.cc:4725

#10 0x0000558c9c1abb77 in handle_select (thd=thd@entry=0x7fa32c000c58, lex=lex@entry=0x7fa32c004b80, result=result@entry=0x7fa32c011ce0, setup_tables_done_option=setup_tables_done_option@entry=0) at /data/src/10.5/sql/sql_select.cc:419

#11 0x0000558c9c1e988a in Sql_cmd_create_table_like::execute (this=<optimized out>, thd=0x7fa32c000c58) at /data/src/10.5/sql/sql_table.cc:12100

#12 0x0000558c9c1456f6 in mysql_execute_command (thd=0x7fa32c000c58) at /data/src/10.5/sql/sql_parse.cc:6049

#13 0x0000558c9c1350ef in mysql_parse (thd=0x7fa32c000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.5/sql/sql_parse.cc:8093

#14 0x0000558c9c14194f in dispatch_command (command=COM_QUERY, thd=0x7fa32c000c58, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.5/sql/sql_class.h:1270

#15 0x0000558c9c143d27 in do_command (thd=0x7fa32c000c58) at /data/src/10.5/sql/sql_parse.cc:1370

#16 0x0000558c9c248f01 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x558c9eb9cf48, put_in_cache=put_in_cache@entry=true) at /data/src/10.5/sql/sql_connect.cc:1410

#17 0x0000558c9c24937d in handle_one_connection (arg=arg@entry=0x558c9eb9cf48) at /data/src/10.5/sql/sql_connect.cc:1312

#18 0x0000558c9c5d2ca6 in pfs_spawn_thread (arg=0x558c9eb33ba8) at /data/src/10.5/storage/perfschema/pfs.cc:2201

#19 0x00007fa37023e609 in start_thread (arg=<optimized out>) at pthread_create.c:477

#20 0x00007fa36fe2d293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 9 (Thread 0x7fa36903a700 (LWP 742710)):

#0  __lll_lock_wait (futex=futex@entry=0x558c9d2bd150 <mysql_bin_log+1200>, private=0) at lowlevellock.c:52

#1  0x00007fa370241235 in __GI___pthread_mutex_lock (mutex=mutex@entry=0x558c9d2bd150 <mysql_bin_log+1200>) at ../nptl/pthread_mutex_lock.c:135

#2  0x0000558c9c456ec3 in inline_mysql_mutex_lock (src_file=0x558c9cbd825c "/data/src/10.5/sql/log.cc", src_line=10058, that=0x558c9d2bd150 <mysql_bin_log+1200>) at /data/src/10.5/include/mysql/psi/mysql_thread.h:752

#3  MYSQL_BIN_LOG::mark_xids_active (this=this@entry=0x558c9d2bcca0 <mysql_bin_log>, binlog_id=binlog_id@entry=2662, xid_count=xid_count@entry=1) at /data/src/10.5/sql/log.cc:10058

#4  0x0000558c9c45ad98 in MYSQL_BIN_LOG::rotate (force_rotate=<optimized out>, check_purge=0x7fa369037b4f, this=0x558c9d2bcca0 <mysql_bin_log>) at /data/src/10.5/sql/log.cc:6998

#5  MYSQL_BIN_LOG::rotate (this=0x558c9d2bcca0 <mysql_bin_log>, force_rotate=<optimized out>, check_purge=0x7fa369037b4f) at /data/src/10.5/sql/log.cc:6961

#6  0x0000558c9c45f590 in MYSQL_BIN_LOG::rotate_and_purge (this=this@entry=0x558c9d2bcca0 <mysql_bin_log>, force_rotate=force_rotate@entry=true, domain_drop_lex=0x0) at /data/src/10.5/sql/log.cc:7196

#7  0x0000558c9c266b20 in reload_acl_and_cache (thd=thd@entry=0x7fa330000c58, options=16130, tables=tables@entry=0x0, write_to_binlog=write_to_binlog@entry=0x7fa369037dc0) at /data/src/10.5/sql/sql_reload.cc:154

#8  0x0000558c9c146293 in mysql_execute_command (thd=0x7fa330000c58) at /data/src/10.5/sql/sql_parse.cc:5515

#9  0x0000558c9c09a209 in sp_instr_stmt::exec_core (this=0x7fa330018120, thd=<optimized out>, nextp=0x7fa3690385c4) at /data/src/10.5/sql/sp_head.cc:3768

#10 0x0000558c9c0a3135 in sp_lex_keeper::reset_lex_and_exec_core (this=0x7fa330018168, thd=0x7fa330000c58, nextp=0x7fa3690385c4, open_tables=<optimized out>, instr=0x7fa330018120) at /data/src/10.5/sql/sp_head.cc:3495

#11 0x0000558c9c0a3b51 in sp_instr_stmt::execute (this=0x7fa330018120, thd=0x7fa330000c58, nextp=0x7fa3690385c4) at /data/src/10.5/sql/sp_head.cc:3674

#12 0x0000558c9c09da9c in sp_head::execute (this=0x7fa3300175a0, thd=0x7fa330000c58, merge_da_on_success=true) at /data/src/10.5/sql/sp_head.cc:1437

#13 0x0000558c9c09f16a in sp_head::execute_procedure (this=0x7fa3300175a0, thd=thd@entry=0x7fa330000c58, args=0x7fa330005b28) at /data/src/10.5/sql/sp_head.cc:2449

#14 0x0000558c9c13a4c7 in do_execute_sp (thd=thd@entry=0x7fa330000c58, sp=<optimized out>) at /data/src/10.5/sql/sql_parse.cc:3088

#15 0x0000558c9c146c6d in mysql_execute_command (thd=0x7fa330000c58) at /data/src/10.5/sql/sql_parse.cc:5774

#16 0x0000558c9c1350ef in mysql_parse (thd=0x7fa330000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.5/sql/sql_parse.cc:8093

#17 0x0000558c9c14194f in dispatch_command (command=COM_QUERY, thd=0x7fa330000c58, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.5/sql/sql_class.h:1270

#18 0x0000558c9c143d27 in do_command (thd=0x7fa330000c58) at /data/src/10.5/sql/sql_parse.cc:1370

#19 0x0000558c9c248f01 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x558c9eba4ff8, put_in_cache=put_in_cache@entry=true) at /data/src/10.5/sql/sql_connect.cc:1410

#20 0x0000558c9c24937d in handle_one_connection (arg=arg@entry=0x558c9eba4ff8) at /data/src/10.5/sql/sql_connect.cc:1312

#21 0x0000558c9c5d2ca6 in pfs_spawn_thread (arg=0x558c9eb33ef8) at /data/src/10.5/storage/perfschema/pfs.cc:2201

#22 0x00007fa37023e609 in start_thread (arg=<optimized out>) at pthread_create.c:477

#23 0x00007fa36fe2d293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95