[MDEV-34122] Assertion `entry' failed in Active_tranx::assert_thd_is_waiter - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.5, 10.6, 10.11, 11.1(EOL), 11.2(EOL), 11.4, 11.6(EOL), 11.7(EOL)
Fix Version/s: 10.6.20, 10.11.10, 11.2.6, 11.4.4
Component/s: Replication
Labels:
- affects-tests
- corruption

Description

--source include/have_log_bin.inc

call mtr.add_suppression("Timeout waiting for reply of binlog");

set @semisync.save= @@rpl_semi_sync_master_enabled;

CREATE TABLE t (a INT);

START TRANSACTION;

SET GLOBAL RPL_SEMI_SYNC_MASTER_ENABLED= 1;

INSERT INTO t VALUES (NULL);

SET GLOBAL RPL_SEMI_SYNC_MASTER_ENABLED= 0;

SET GLOBAL RPL_SEMI_SYNC_MASTER_ENABLED= 1;

COMMIT;

# Cleanup

DROP TABLE t;

SET GLOBAL RPL_SEMI_SYNC_MASTER_ENABLED= @semisync.save;

10.6 6daccd4e48943fc578e99eef5a01334e7970363e
mariadbd: /data/bld/10.6-asan/sql/semisync_master.cc:382: void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t): Assertion `entry' failed.
240508 23:22:46 [ERROR] mysqld got signal 6 ;
Sorry, we probably made a mistake, and this is a bug.

#9 0x00007faee3a53e32 in __GI___assert_fail (assertion=0x55949d484900 "entry", file=0x55949d484220 "/data/bld/10.6-asan/sql/semisync_master.cc", line=382, function=0x55949d484880 "void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t)") at ./assert/assert.c:101
#10 0x000055949b63849c in Active_tranx::assert_thd_is_waiter (this=0x60800000ada0, thd_to_check=0x62b00008c218, log_file_name=0x6160006a98a0 "master-bin.000001", log_file_pos=1002) at /data/bld/10.6-asan/sql/semisync_master.cc:382
#11 0x000055949b63b753 in Repl_semi_sync_master::commit_trx (this=0x55949f687d60 <repl_semisync_master>, trx_wait_binlog_name=0x6160006a98a0 "master-bin.000001", trx_wait_binlog_pos=1002) at /data/bld/10.6-asan/sql/semisync_master.cc:969
#12 0x000055949b63a880 in Repl_semi_sync_master::wait_after_commit (this=0x55949f687d60 <repl_semisync_master>, thd=0x62b00008c218, all=true) at /data/bld/10.6-asan/sql/semisync_master.cc:770
#13 0x000055949b8c6288 in ha_commit_trans (thd=0x62b00008c218, all=true) at /data/bld/10.6-asan/sql/handler.cc:1988
#14 0x000055949b4e6c0c in trans_commit (thd=0x62b00008c218) at /data/bld/10.6-asan/sql/transaction.cc:270
#15 0x000055949b044187 in mysql_execute_command (thd=0x62b00008c218, is_called_from_prepared_stmt=false) at /data/bld/10.6-asan/sql/sql_parse.cc:5746
#16 0x000055949b053f04 in mysql_parse (thd=0x62b00008c218, rawbuf=0x62b000093238 "COMMIT", length=6, parser_state=0x7faed99fe9f0) at /data/bld/10.6-asan/sql/sql_parse.cc:8146
#17 0x000055949b0292ba in dispatch_command (command=COM_QUERY, thd=0x62b00008c218, packet=0x62900023f219 "COMMIT", packet_length=6, blocking=true) at /data/bld/10.6-asan/sql/sql_parse.cc:1896
#18 0x000055949b025fee in do_command (thd=0x62b00008c218, blocking=true) at /data/bld/10.6-asan/sql/sql_parse.cc:1409
#19 0x000055949b4a05b6 in do_handle_one_connection (connect=0x608000002eb8, put_in_cache=true) at /data/bld/10.6-asan/sql/sql_connect.cc:1415
#20 0x000055949b49ff77 in handle_one_connection (arg=0x608000002e38) at /data/bld/10.6-asan/sql/sql_connect.cc:1317
#21 0x000055949c10f856 in pfs_spawn_thread (arg=0x617000006298) at /data/bld/10.6-asan/storage/perfschema/pfs.cc:2201
#22 0x00007faee3aa8044 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#23 0x00007faee3b2861c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

The failure (along with the assertion and the surrounding code) was introduced by this commit in 10.6:

commit 75c7c6dc39a1b622b876199aca8242bd23720844

Commit:     Brandon Nesterenko

CommitDate: Thu Mar 21 08:42:18 2024 -0600

    MDEV-33551: Semi-sync Wait Point AFTER_COMMIT Slow on Workloads with Heavy Concurrency

I don't see any immediate problem on a non-debug build.

Attachments

Issue Links

is caused by

MDEV-33551 Semi-sync Wait Point AFTER_COMMIT Slow on Workloads with Heavy Concurrency

Closed

Activity

Ascending order - Click to sort in descending order

Brandon Nesterenko added a comment - 2024-05-08 21:37

Looks like the underlying behavior is present before 75c7c6dc39a, and my commit just added an assertion showing that the event can't receive an ACK if semi-sync is disabled mid-transaction. I.e., SET GLOBAL RPL_SEMI_SYNC_MASTER_ENABLED=0 calls clear_active_tranx_nodes(), which means there won't be any nodes to compare against when the ACK comes, and the transaction will wait until rpl_semi_sync_master_timeout.

Brandon Nesterenko added a comment - 2024-05-08 21:37 Looks like the underlying behavior is present before 75c7c6dc39a, and my commit just added an assertion showing that the event can't receive an ACK if semi-sync is disabled mid-transaction. I.e., SET GLOBAL RPL_SEMI_SYNC_MASTER_ENABLED=0 calls clear_active_tranx_nodes(), which means there won't be any nodes to compare against when the ACK comes, and the transaction will wait until rpl_semi_sync_master_timeout.

Roel Van de Paar added a comment - 2024-05-13 02:39 - edited

Ran into the same with:

--source include/have_log_bin.inc

XA START 'a';

SET GLOBAL rpl_semi_sync_master_enabled=1;

INSERT INTO mysql.columns_priv SET HOST='a';

SET GLOBAL rpl_semi_sync_master_enabled=0;

SET GLOBAL rpl_semi_sync_master_enabled=1;

SELECT foo(bar);

10.11.8 64314d3094ef5eb52223c613632292be96bd7732 (Debug)
mariadbd: /test/10.11_dbg/sql/semisync_master.cc:382: void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t): Assertion `entry' failed.

10.11.8 64314d3094ef5eb52223c613632292be96bd7732 (Debug)
Core was generated by `/test/MD070524-mariadb-10.11.8-linux-x86_64-dbg/bin/mariadbd --no-defaults --ma'.
Program terminated with signal SIGABRT, Aborted.
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44
Download failed: Invalid argument. Continuing without source file ./nptl/./nptl/pthread_kill.c.
[Current thread is 1 (LWP 3275333)]
(gdb) bt
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44
#1 __pthread_kill_internal (signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:78
#2 __GI___pthread_kill (threadid=<optimized out>, signo=signo@entry=6)at ./nptl/pthread_kill.c:89
#3 0x000006abb3442866 in __GI_raise (sig=sig@entry=6)at ../sysdeps/posix/raise.c:26
#4 0x000006abb34268b7 in __GI_abort () at ./stdlib/abort.c:79
#5 0x000006abb34267db in __assert_fail_base (fmt=0x6abb35c5168 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x61397964b109 "entry", file=file@entry=0x6139794e4778 "/test/10.11_dbg/sql/semisync_master.cc", line=line@entry=382, function=function@entry=0x6139794e4848 "void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t)") at ./assert/assert.c:92
#6 0x000006abb3439186 in __assert_fail (assertion=0x61397964b109 "entry", file=0x6139794e4778 "/test/10.11_dbg/sql/semisync_master.cc", line=382, function=0x6139794e4848 "void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t)") at ./assert/assert.c:101
#7 0x000061397897a139 in Active_tranx::assert_thd_is_waiter (this=<optimized out>, thd_to_check=thd_to_check@entry=0x6ab60000d58, log_file_name=log_file_name@entry=0x6ab600a4810 "qa-roel-2-bin.000002", log_file_pos=log_file_pos@entry=571)at /test/10.11_dbg/sql/semisync_master.cc:382
#8 0x000061397897ab5e in Repl_semi_sync_master::commit_trx (this=this@entry=0x613979f986e0 <repl_semisync_master>, trx_wait_binlog_name=trx_wait_binlog_name@entry=0x6ab600a4810 "qa-roel-2-bin.000002", trx_wait_binlog_pos=trx_wait_binlog_pos@entry=571)at /test/10.11_dbg/sql/semisync_master.cc:969
#9 0x000061397897af94 in Repl_semi_sync_master::wait_after_commit (this=0x613979f986e0 <repl_semisync_master>, thd=thd@entry=0x6ab60000d58, all=all@entry=true) at /test/10.11_dbg/sql/semisync_master.cc:770
#10 0x0000613978a65921 in ha_commit_trans (thd=thd@entry=0x6ab60000d58, all=all@entry=true) at /test/10.11_dbg/sql/handler.cc:1987
#11 0x000061397871a8b4 in THD::commit_whole_transaction_and_close_tables (this=this@entry=0x6ab60000d58) at /test/10.11_dbg/sql/sql_class.cc:6205
#12 0x0000613978bfb9e7 in Sp_handler::db_find_routine (this=this@entry=0x613979e94028 <sp_handler_function>, thd=thd@entry=0x6ab60000d58, name=name@entry=0x6aba80f4520, sphp=sphp@entry=0x6aba80f4780) at /test/10.11_dbg/sql/sp.cc:776
#13 0x0000613978bfba5d in Sp_handler::db_find_and_cache_routine (this=this@entry=0x613979e94028 <sp_handler_function>, thd=thd@entry=0x6ab60000d58, name=name@entry=0x6aba80f4520, sp=sp@entry=0x6aba80f4780) at /test/10.11_dbg/sql/sp.cc:788
#14 0x0000613978bfbb06 in Sp_handler::sp_cache_routine (this=0x613979e94028 <sp_handler_function>, thd=0x6ab60000d58, name=0x6aba80f4520, sp=0x6aba80f4780) at /test/10.11_dbg/sql/sp.cc:2830
#15 0x0000613978bffb5d in Sroutine_hash_entry::sp_cache_routine (this=this@entry=0x6ab60013cc0, thd=thd@entry=0x6ab60000d58, sp=sp@entry=0x6aba80f4780) at /test/10.11_dbg/sql/sp.cc:2790
#16 0x00006139786fe6a8 in open_and_process_routine (routine_modifies_data=<synthetic pointer>, need_prelocking=0x6aba80f477f, ot_ctx=0x6aba80f47a0, has_prelocking_list=false, prelocking_strategy=0x6aba80f4890, rt=0x6ab60013cc0, prelocking_ctx=0x6ab60005128, thd=0x6ab60000d58)at /test/10.11_dbg/sql/sql_base.cc:3783
#17 open_tables (thd=thd@entry=0x6ab60000d58, options=@0x6ab60006780: {m_options = DDL_options_st::OPT_NONE}, start=start@entry=0x6aba80f4828, counter=counter@entry=0x6aba80f483c, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x6aba80f4890)at /test/10.11_dbg/sql/sql_base.cc:4706
#18 0x00006139786ff1e1 in open_and_lock_tables (thd=thd@entry=0x6ab60000d58, options=<optimized out>, tables=<optimized out>, tables@entry=0x0, derived=derived@entry=true, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x6aba80f4890)at /test/10.11_dbg/sql/sql_base.cc:5607
#19 0x000061397877104a in open_and_lock_tables (flags=0, derived=true, tables=0x0, thd=0x6ab60000d58) at /test/10.11_dbg/sql/sql_base.h:514
#20 execute_sqlcom_select (thd=thd@entry=0x6ab60000d58, all_tables=0x0)at /test/10.11_dbg/sql/sql_parse.cc:6305
#21 0x000061397877caf1 in mysql_execute_command (thd=thd@entry=0x6ab60000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false)at /test/10.11_dbg/sql/sql_parse.cc:3987
#22 0x0000613978784257 in mysql_parse (thd=thd@entry=0x6ab60000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x6aba80f52b0)at /test/10.11_dbg/sql/sql_parse.cc:8126
#23 0x0000613978786732 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x6ab60000d58, packet=packet@entry=0x6ab6000b2c9 "SELECT foo(bar)", packet_length=packet_length@entry=15, blocking=blocking@entry=true)at /test/10.11_dbg/sql/sql_class.h:244
#24 0x00006139787889df in do_command (thd=0x6ab60000d58, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407
#25 0x00006139788e5e81 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x61397cb14b68, put_in_cache=put_in_cache@entry=true)at /test/10.11_dbg/sql/sql_connect.cc:1415
#26 0x00006139788e6180 in handle_one_connection (arg=arg@entry=0x61397cb14b68)at /test/10.11_dbg/sql/sql_connect.cc:1317
#27 0x0000613978d13c08 in pfs_spawn_thread (arg=0x61397ca94d38)at /test/10.11_dbg/storage/perfschema/pfs.cc:2201
#28 0x000006abb3497ada in start_thread (arg=<optimized out>)at ./nptl/pthread_create.c:444
#29 0x000006abb352847c in clone3 ()at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78

Bug confirmed present in:
MariaDB: 10.6.18 (dbg), 10.11.8 (dbg), 11.1.5 (dbg), 11.2.4 (dbg)

Roel Van de Paar added a comment - 2024-05-13 02:39 - edited Ran into the same with: --source include/have_log_bin.inc XA START 'a' ; SET GLOBAL rpl_semi_sync_master_enabled=1; INSERT INTO mysql.columns_priv SET HOST= 'a' ; SET GLOBAL rpl_semi_sync_master_enabled=0; SET GLOBAL rpl_semi_sync_master_enabled=1; SELECT foo(bar); 10.11.8 64314d3094ef5eb52223c613632292be96bd7732 (Debug) mariadbd: /test/10.11_dbg/sql/semisync_master.cc:382: void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t): Assertion `entry' failed. 10.11.8 64314d3094ef5eb52223c613632292be96bd7732 (Debug) Core was generated by `/test/MD070524-mariadb-10.11.8-linux-x86_64-dbg/bin/mariadbd --no-defaults --ma'. Program terminated with signal SIGABRT, Aborted. #0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44 Download failed: Invalid argument. Continuing without source file ./nptl/./nptl/pthread_kill.c. [Current thread is 1 (LWP 3275333)] (gdb) bt #0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44 #1 __pthread_kill_internal (signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:78 #2 __GI___pthread_kill (threadid=<optimized out>, signo=signo@entry=6)at ./nptl/pthread_kill.c:89 #3 0x000006abb3442866 in __GI_raise (sig=sig@entry=6)at ../sysdeps/posix/raise.c:26 #4 0x000006abb34268b7 in __GI_abort () at ./stdlib/abort.c:79 #5 0x000006abb34267db in __assert_fail_base (fmt=0x6abb35c5168 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x61397964b109 "entry", file=file@entry=0x6139794e4778 "/test/10.11_dbg/sql/semisync_master.cc", line=line@entry=382, function=function@entry=0x6139794e4848 "void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t)") at ./assert/assert.c:92 #6 0x000006abb3439186 in __assert_fail (assertion=0x61397964b109 "entry", file=0x6139794e4778 "/test/10.11_dbg/sql/semisync_master.cc", line=382, function=0x6139794e4848 "void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t)") at ./assert/assert.c:101 #7 0x000061397897a139 in Active_tranx::assert_thd_is_waiter (this=<optimized out>, thd_to_check=thd_to_check@entry=0x6ab60000d58, log_file_name=log_file_name@entry=0x6ab600a4810 "qa-roel-2-bin.000002", log_file_pos=log_file_pos@entry=571)at /test/10.11_dbg/sql/semisync_master.cc:382 #8 0x000061397897ab5e in Repl_semi_sync_master::commit_trx (this=this@entry=0x613979f986e0 <repl_semisync_master>, trx_wait_binlog_name=trx_wait_binlog_name@entry=0x6ab600a4810 "qa-roel-2-bin.000002", trx_wait_binlog_pos=trx_wait_binlog_pos@entry=571)at /test/10.11_dbg/sql/semisync_master.cc:969 #9 0x000061397897af94 in Repl_semi_sync_master::wait_after_commit (this=0x613979f986e0 <repl_semisync_master>, thd=thd@entry=0x6ab60000d58, all=all@entry=true) at /test/10.11_dbg/sql/semisync_master.cc:770 #10 0x0000613978a65921 in ha_commit_trans (thd=thd@entry=0x6ab60000d58, all=all@entry=true) at /test/10.11_dbg/sql/handler.cc:1987 #11 0x000061397871a8b4 in THD::commit_whole_transaction_and_close_tables (this=this@entry=0x6ab60000d58) at /test/10.11_dbg/sql/sql_class.cc:6205 #12 0x0000613978bfb9e7 in Sp_handler::db_find_routine (this=this@entry=0x613979e94028 <sp_handler_function>, thd=thd@entry=0x6ab60000d58, name=name@entry=0x6aba80f4520, sphp=sphp@entry=0x6aba80f4780) at /test/10.11_dbg/sql/sp.cc:776 #13 0x0000613978bfba5d in Sp_handler::db_find_and_cache_routine (this=this@entry=0x613979e94028 <sp_handler_function>, thd=thd@entry=0x6ab60000d58, name=name@entry=0x6aba80f4520, sp=sp@entry=0x6aba80f4780) at /test/10.11_dbg/sql/sp.cc:788 #14 0x0000613978bfbb06 in Sp_handler::sp_cache_routine (this=0x613979e94028 <sp_handler_function>, thd=0x6ab60000d58, name=0x6aba80f4520, sp=0x6aba80f4780) at /test/10.11_dbg/sql/sp.cc:2830 #15 0x0000613978bffb5d in Sroutine_hash_entry::sp_cache_routine (this=this@entry=0x6ab60013cc0, thd=thd@entry=0x6ab60000d58, sp=sp@entry=0x6aba80f4780) at /test/10.11_dbg/sql/sp.cc:2790 #16 0x00006139786fe6a8 in open_and_process_routine (routine_modifies_data=<synthetic pointer>, need_prelocking=0x6aba80f477f, ot_ctx=0x6aba80f47a0, has_prelocking_list=false, prelocking_strategy=0x6aba80f4890, rt=0x6ab60013cc0, prelocking_ctx=0x6ab60005128, thd=0x6ab60000d58)at /test/10.11_dbg/sql/sql_base.cc:3783 #17 open_tables (thd=thd@entry=0x6ab60000d58, options=@0x6ab60006780: {m_options = DDL_options_st::OPT_NONE}, start=start@entry=0x6aba80f4828, counter=counter@entry=0x6aba80f483c, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x6aba80f4890)at /test/10.11_dbg/sql/sql_base.cc:4706 #18 0x00006139786ff1e1 in open_and_lock_tables (thd=thd@entry=0x6ab60000d58, options=<optimized out>, tables=<optimized out>, tables@entry=0x0, derived=derived@entry=true, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x6aba80f4890)at /test/10.11_dbg/sql/sql_base.cc:5607 #19 0x000061397877104a in open_and_lock_tables (flags=0, derived=true, tables=0x0, thd=0x6ab60000d58) at /test/10.11_dbg/sql/sql_base.h:514 #20 execute_sqlcom_select (thd=thd@entry=0x6ab60000d58, all_tables=0x0)at /test/10.11_dbg/sql/sql_parse.cc:6305 #21 0x000061397877caf1 in mysql_execute_command (thd=thd@entry=0x6ab60000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false)at /test/10.11_dbg/sql/sql_parse.cc:3987 #22 0x0000613978784257 in mysql_parse (thd=thd@entry=0x6ab60000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x6aba80f52b0)at /test/10.11_dbg/sql/sql_parse.cc:8126 #23 0x0000613978786732 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x6ab60000d58, packet=packet@entry=0x6ab6000b2c9 "SELECT foo(bar)", packet_length=packet_length@entry=15, blocking=blocking@entry=true)at /test/10.11_dbg/sql/sql_class.h:244 #24 0x00006139787889df in do_command (thd=0x6ab60000d58, blocking=blocking@entry=true) at /test/10.11_dbg/sql/sql_parse.cc:1407 #25 0x00006139788e5e81 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x61397cb14b68, put_in_cache=put_in_cache@entry=true)at /test/10.11_dbg/sql/sql_connect.cc:1415 #26 0x00006139788e6180 in handle_one_connection (arg=arg@entry=0x61397cb14b68)at /test/10.11_dbg/sql/sql_connect.cc:1317 #27 0x0000613978d13c08 in pfs_spawn_thread (arg=0x61397ca94d38)at /test/10.11_dbg/storage/perfschema/pfs.cc:2201 #28 0x000006abb3497ada in start_thread (arg=<optimized out>)at ./nptl/pthread_create.c:444 #29 0x000006abb352847c in clone3 ()at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78 Bug confirmed present in: MariaDB: 10.6.18 (dbg), 10.11.8 (dbg), 11.1.5 (dbg), 11.2.4 (dbg)

Roel Van de Paar added a comment - 2024-09-16 22:45 - edited

An additional interesting testcase

--source include/have_log_bin.inc

CREATE TABLE t (c1 INT) ENGINE=Aria;

XA START 'a';

SET GLOBAL rpl_semi_sync_master_enabled=1;

INSERT INTO t SELECT 1;

SET GLOBAL rpl_semi_sync_master_enabled=0;

XA END 'a';

LOAD INDEX INTO CACHE t KEY(PRIMARY,inx_b);

SET GLOBAL rpl_semi_sync_master_enabled=ON;

Leads to:

CS 11.2.6 e91a79945822def1452787f825e6047c6a64dbd9 (Debug)
11.2.6-dbg>XA END 'a';
Query OK, 0 rows affected (0.000 sec)

11.2.6-dbg>LOAD INDEX INTO CACHE t KEY(PRIMARY,inx_b);
+--------+--------------+----------+-------------------------------------------------------------------------------------------+
\| Table \| Op \| Msg_type \| Msg_text \|
+--------+--------------+----------+-------------------------------------------------------------------------------------------+
\| test.t \| preload_keys \| Error \| XAER_RMFAIL: The command cannot be executed when global transaction is in the IDLE state \|
\| test.t \| preload_keys \| Error \| XAER_RMFAIL: The command cannot be executed when global transaction is in the IDLE state \|
\| test.t \| preload_keys \| error \| Corrupt \|
+--------+--------------+----------+-------------------------------------------------------------------------------------------+
3 rows in set, 1 warning (0.000 sec)

11.2.6-dbg>SET GLOBAL rpl_semi_sync_master_enabled=ON;
ERROR 2013 (HY000): Lost connection to server during query

CS 11.2.6 e91a79945822def1452787f825e6047c6a64dbd9 (Debug)
mariadbd: /test/11.2_dbg/sql/semisync_master.cc:382: void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t): Assertion `entry' failed.

CS 11.2.6 e91a79945822def1452787f825e6047c6a64dbd9 (Debug)
Core was generated by `/test/MD090924-mariadb-11.2.6-linux-x86_64-dbg/bin/mariadbd --defaults-group-su'.
Program terminated with signal SIGABRT, Aborted.
Download failed: Invalid argument. Continuing without source file ./nptl/./nptl/pthread_kill.c.
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44

[Current thread is 1 (LWP 3567868)]
(gdb) bt
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44
#1 __pthread_kill_internal (signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:78
#2 __GI___pthread_kill (threadid=<optimized out>, signo=signo@entry=6)at ./nptl/pthread_kill.c:89
#3 0x0000148ece04526e in __GI_raise (sig=sig@entry=6)at ../sysdeps/posix/raise.c:26
#4 0x0000148ece0288ff in __GI_abort () at ./stdlib/abort.c:79
#5 0x0000148ece02881b in __assert_fail_base (fmt=0x148ece1d01e8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x562774a6d11f "entry", file=file@entry=0x5627748d2ff8 "/test/11.2_dbg/sql/semisync_master.cc", line=line@entry=382, function=function@entry=0x5627748d30c8 "void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t)") at ./assert/assert.c:94
#6 0x0000148ece03b507 in __assert_fail (assertion=0x562774a6d11f "entry", file=0x5627748d2ff8 "/test/11.2_dbg/sql/semisync_master.cc", line=382, function=0x5627748d30c8 "void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t)") at ./assert/assert.c:103
#7 0x0000562773d9e5bf in Active_tranx::assert_thd_is_waiter (this=<optimized out>, thd_to_check=thd_to_check@entry=0x148ea4000d58, log_file_name=log_file_name@entry=0x148ea4060ef0 "master-bin.000001", log_file_pos=log_file_pos@entry=724)at /test/11.2_dbg/sql/semisync_master.cc:382
#8 0x0000562773d9f028 in Repl_semi_sync_master::commit_trx (this=this@entry=0x5627753bae00 <repl_semisync_master>, trx_wait_binlog_name=trx_wait_binlog_name@entry=0x148ea4060ef0 "master-bin.000001", trx_wait_binlog_pos=trx_wait_binlog_pos@entry=724)at /test/11.2_dbg/sql/semisync_master.cc:972
#9 0x0000562773d9f42a in Repl_semi_sync_master::wait_after_commit (this=0x5627753bae00 <repl_semisync_master>, thd=thd@entry=0x148ea4000d58, all=all@entry=false) at /test/11.2_dbg/sql/semisync_master.cc:772
#10 0x0000562773d113ed in trans_commit_stmt (thd=thd@entry=0x148ea4000d58)at /test/11.2_dbg/sql/transaction.cc:524
#11 0x0000562773b89da3 in mysql_execute_command (thd=thd@entry=0x148ea4000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false)at /test/11.2_dbg/sql/sql_parse.cc:5967
#12 0x0000562773b8ad26 in mysql_parse (thd=thd@entry=0x148ea4000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x148ec95fe2a0)at /test/11.2_dbg/sql/sql_parse.cc:7929
#13 0x0000562773b8d1bd in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x148ea4000d58, packet=packet@entry=0x148ea400b449 "SET GLOBAL rpl_semi_sync_master_enabled=ON", packet_length=packet_length@entry=42, blocking=blocking@entry=true)at /test/11.2_dbg/sql/sql_class.h:248
#14 0x0000562773b8f3e3 in do_command (thd=0x148ea4000d58, blocking=blocking@entry=true) at /test/11.2_dbg/sql/sql_parse.cc:1407
#15 0x0000562773cfb35c in do_handle_one_connection (connect=<optimized out>, connect@entry=0x56277827f3e8, put_in_cache=put_in_cache@entry=true)at /test/11.2_dbg/sql/sql_connect.cc:1439
#16 0x0000562773cfb65c in handle_one_connection (arg=arg@entry=0x56277827f3e8)at /test/11.2_dbg/sql/sql_connect.cc:1341
#17 0x000056277414262c in pfs_spawn_thread (arg=0x5627781ff328)at /test/11.2_dbg/storage/perfschema/pfs.cc:2201
#18 0x0000148ece09ca94 in start_thread (arg=<optimized out>)at ./nptl/pthread_create.c:447
#19 0x0000148ece129c3c in clone3 ()at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78

Bug confirmed present in:
MariaDB: 10.6.20 (dbg), 10.11.10 (dbg), 11.1.7 (dbg), 11.2.6 (dbg), 11.4.4 (dbg), 11.6.2 (dbg), 11.7.0 (dbg)

Roel Van de Paar added a comment - 2024-09-16 22:45 - edited An additional interesting testcase --source include/have_log_bin.inc CREATE TABLE t (c1 INT ) ENGINE=Aria; XA START 'a' ; SET GLOBAL rpl_semi_sync_master_enabled=1; INSERT INTO t SELECT 1; SET GLOBAL rpl_semi_sync_master_enabled=0; XA END 'a' ; LOAD INDEX INTO CACHE t KEY ( PRIMARY ,inx_b); SET GLOBAL rpl_semi_sync_master_enabled= ON ; Leads to: CS 11.2.6 e91a79945822def1452787f825e6047c6a64dbd9 (Debug) 11.2.6-dbg>XA END 'a'; Query OK, 0 rows affected (0.000 sec) 11.2.6-dbg>LOAD INDEX INTO CACHE t KEY(PRIMARY,inx_b); +--------+--------------+----------+-------------------------------------------------------------------------------------------+ | Table | Op | Msg_type | Msg_text | +--------+--------------+----------+-------------------------------------------------------------------------------------------+ | test.t | preload_keys | Error | XAER_RMFAIL: The command cannot be executed when global transaction is in the IDLE state | | test.t | preload_keys | Error | XAER_RMFAIL: The command cannot be executed when global transaction is in the IDLE state | | test.t | preload_keys | error | Corrupt | +--------+--------------+----------+-------------------------------------------------------------------------------------------+ 3 rows in set, 1 warning (0.000 sec) 11.2.6-dbg>SET GLOBAL rpl_semi_sync_master_enabled=ON; ERROR 2013 (HY000): Lost connection to server during query CS 11.2.6 e91a79945822def1452787f825e6047c6a64dbd9 (Debug) mariadbd: /test/11.2_dbg/sql/semisync_master.cc:382: void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t): Assertion `entry' failed. CS 11.2.6 e91a79945822def1452787f825e6047c6a64dbd9 (Debug) Core was generated by `/test/MD090924-mariadb-11.2.6-linux-x86_64-dbg/bin/mariadbd --defaults-group-su'. Program terminated with signal SIGABRT, Aborted. Download failed: Invalid argument. Continuing without source file ./nptl/./nptl/pthread_kill.c. #0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44 [Current thread is 1 (LWP 3567868)] (gdb) bt #0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44 #1 __pthread_kill_internal (signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:78 #2 __GI___pthread_kill (threadid=<optimized out>, signo=signo@entry=6)at ./nptl/pthread_kill.c:89 #3 0x0000148ece04526e in __GI_raise (sig=sig@entry=6)at ../sysdeps/posix/raise.c:26 #4 0x0000148ece0288ff in __GI_abort () at ./stdlib/abort.c:79 #5 0x0000148ece02881b in __assert_fail_base (fmt=0x148ece1d01e8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x562774a6d11f "entry", file=file@entry=0x5627748d2ff8 "/test/11.2_dbg/sql/semisync_master.cc", line=line@entry=382, function=function@entry=0x5627748d30c8 "void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t)") at ./assert/assert.c:94 #6 0x0000148ece03b507 in __assert_fail (assertion=0x562774a6d11f "entry", file=0x5627748d2ff8 "/test/11.2_dbg/sql/semisync_master.cc", line=382, function=0x5627748d30c8 "void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t)") at ./assert/assert.c:103 #7 0x0000562773d9e5bf in Active_tranx::assert_thd_is_waiter (this=<optimized out>, thd_to_check=thd_to_check@entry=0x148ea4000d58, log_file_name=log_file_name@entry=0x148ea4060ef0 "master-bin.000001", log_file_pos=log_file_pos@entry=724)at /test/11.2_dbg/sql/semisync_master.cc:382 #8 0x0000562773d9f028 in Repl_semi_sync_master::commit_trx (this=this@entry=0x5627753bae00 <repl_semisync_master>, trx_wait_binlog_name=trx_wait_binlog_name@entry=0x148ea4060ef0 "master-bin.000001", trx_wait_binlog_pos=trx_wait_binlog_pos@entry=724)at /test/11.2_dbg/sql/semisync_master.cc:972 #9 0x0000562773d9f42a in Repl_semi_sync_master::wait_after_commit (this=0x5627753bae00 <repl_semisync_master>, thd=thd@entry=0x148ea4000d58, all=all@entry=false) at /test/11.2_dbg/sql/semisync_master.cc:772 #10 0x0000562773d113ed in trans_commit_stmt (thd=thd@entry=0x148ea4000d58)at /test/11.2_dbg/sql/transaction.cc:524 #11 0x0000562773b89da3 in mysql_execute_command (thd=thd@entry=0x148ea4000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false)at /test/11.2_dbg/sql/sql_parse.cc:5967 #12 0x0000562773b8ad26 in mysql_parse (thd=thd@entry=0x148ea4000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x148ec95fe2a0)at /test/11.2_dbg/sql/sql_parse.cc:7929 #13 0x0000562773b8d1bd in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x148ea4000d58, packet=packet@entry=0x148ea400b449 "SET GLOBAL rpl_semi_sync_master_enabled=ON", packet_length=packet_length@entry=42, blocking=blocking@entry=true)at /test/11.2_dbg/sql/sql_class.h:248 #14 0x0000562773b8f3e3 in do_command (thd=0x148ea4000d58, blocking=blocking@entry=true) at /test/11.2_dbg/sql/sql_parse.cc:1407 #15 0x0000562773cfb35c in do_handle_one_connection (connect=<optimized out>, connect@entry=0x56277827f3e8, put_in_cache=put_in_cache@entry=true)at /test/11.2_dbg/sql/sql_connect.cc:1439 #16 0x0000562773cfb65c in handle_one_connection (arg=arg@entry=0x56277827f3e8)at /test/11.2_dbg/sql/sql_connect.cc:1341 #17 0x000056277414262c in pfs_spawn_thread (arg=0x5627781ff328)at /test/11.2_dbg/storage/perfschema/pfs.cc:2201 #18 0x0000148ece09ca94 in start_thread (arg=<optimized out>)at ./nptl/pthread_create.c:447 #19 0x0000148ece129c3c in clone3 ()at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78 Bug confirmed present in: MariaDB: 10.6.20 (dbg), 10.11.10 (dbg), 11.1.7 (dbg), 11.2.6 (dbg), 11.4.4 (dbg), 11.6.2 (dbg), 11.7.0 (dbg)

Roel Van de Paar added a comment - 2024-09-16 22:56 - edited

Another testcase leading to a slightly offset stack

--source include/have_log_bin.inc

SET GLOBAL gtid_strict_mode=1;

CREATE TEMPORARY TABLE t (i INT);

SET GLOBAL rpl_semi_sync_master_wait_point=AFTER_SYNC;

SET SESSION gtid_domain_id=2;

SET gtid_seq_no=1;

SET gtid_domain_id=0;

SET GLOBAL rpl_semi_sync_master_enabled=1;

Leads to:

CS 11.2.6 e91a79945822def1452787f825e6047c6a64dbd9 (Debug)
mariadbd: /test/11.2_dbg/sql/semisync_master.cc:382: void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t): Assertion `entry' failed.

CS 11.2.6 e91a79945822def1452787f825e6047c6a64dbd9 (Debug)
Core was generated by `/test/MD090924-mariadb-11.2.6-linux-x86_64-dbg/bin/mariadbd --defaults-group-su'.
Program terminated with signal SIGABRT, Aborted.
Download failed: Invalid argument. Continuing without source file ./nptl/./nptl/pthread_kill.c.
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44

[Current thread is 1 (LWP 2103668)]
(gdb) bt
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44
#1 __pthread_kill_internal (signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:78
#2 __GI___pthread_kill (threadid=<optimized out>, signo=signo@entry=6)at ./nptl/pthread_kill.c:89
#3 0x000015323584526e in __GI_raise (sig=sig@entry=6)at ../sysdeps/posix/raise.c:26
#4 0x00001532358288ff in __GI_abort () at ./stdlib/abort.c:79
#5 0x000015323582881b in __assert_fail_base (fmt=0x1532359d01e8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x55e71b2d211f "entry", file=file@entry=0x55e71b137ff8 "/test/11.2_dbg/sql/semisync_master.cc", line=line@entry=382, function=function@entry=0x55e71b1380c8 "void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t)") at ./assert/assert.c:94
#6 0x000015323583b507 in __assert_fail (assertion=0x55e71b2d211f "entry", file=0x55e71b137ff8 "/test/11.2_dbg/sql/semisync_master.cc", line=382, function=0x55e71b1380c8 "void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t)") at ./assert/assert.c:103
#7 0x000055e71a6035bf in Active_tranx::assert_thd_is_waiter (this=<optimized out>, thd_to_check=thd_to_check@entry=0x15320c000d58, log_file_name=log_file_name@entry=0x55e71bc2436a <mysql_bin_log+202> "master-bin.000001", log_file_pos=log_file_pos@entry=479)at /test/11.2_dbg/sql/semisync_master.cc:382
#8 0x000055e71a604028 in Repl_semi_sync_master::commit_trx (this=this@entry=0x55e71bc1fe00 <repl_semisync_master>, trx_wait_binlog_name=0x55e71bc2436a <mysql_bin_log+202> "master-bin.000001", trx_wait_binlog_pos=trx_wait_binlog_pos@entry=479)at /test/11.2_dbg/sql/semisync_master.cc:972
#9 0x000055e71a604313 in Repl_semi_sync_master::wait_after_sync (this=0x55e71bc1fe00 <repl_semisync_master>, log_file=log_file@entry=0x55e71bc24368 <mysql_bin_log+200> "./master-bin.000001", log_pos=479) at /test/11.2_dbg/sql/semisync_master.cc:743
#10 0x000055e71a85f99c in MYSQL_BIN_LOG::write (this=0x55e71bc242a0 <mysql_bin_log>, event_info=event_info@entry=0x153230d685c0, with_annotate=with_annotate@entry=0x0) at /test/11.2_dbg/sql/log.cc:6929
#11 0x000055e71a65e64f in THD::log_events_and_free_tmp_shares (this=this@entry=0x15320c000d58)at /test/11.2_dbg/sql/temporary_tables.cc:1427
#12 0x000055e71a65e94c in THD::close_temporary_tables (this=this@entry=0x15320c000d58)at /test/11.2_dbg/sql/temporary_tables.cc:540
#13 0x000055e71a380c67 in THD::cleanup (this=this@entry=0x15320c000d58)at /test/11.2_dbg/sql/sql_class.cc:1598
#14 0x000055e71a2b7728 in unlink_thd (thd=0x15320c000d58)at /test/11.2_dbg/sql/mysqld.cc:2868
#15 0x000055e71a5603bb in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55e71cc3a3e8, put_in_cache=put_in_cache@entry=true)at /test/11.2_dbg/sql/sql_connect.cc:1450
#16 0x000055e71a56065c in handle_one_connection (arg=arg@entry=0x55e71cc3a3e8)at /test/11.2_dbg/sql/sql_connect.cc:1341
#17 0x000055e71a9a762c in pfs_spawn_thread (arg=0x55e71cbba328)at /test/11.2_dbg/storage/perfschema/pfs.cc:2201
#18 0x000015323589ca94 in start_thread (arg=<optimized out>)at ./nptl/pthread_create.c:447
#19 0x0000153235929c3c in clone3 ()at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78

Alternative testcase for the same stack:

--source include/have_log_bin.inc

SET SESSION gtid_domain_id=1;

ANALYZE TABLE t PERSISTENT FOR ALL;

SET GLOBAL rpl_semi_sync_master_wait_point=AFTER_SYNC;

SET GLOBAL gtid_strict_mode=ON;

CREATE TABLE t (c INT);

DROP TABLE t;

CREATE TABLE t (c INT);

SET gtid_domain_id=11;

SET gtid_seq_no=4;

SET GLOBAL rpl_semi_sync_master_enabled=1;

SET gtid_domain_id=1;

FLUSH TABLES;

Roel Van de Paar added a comment - 2024-09-16 22:56 - edited Another testcase leading to a slightly offset stack --source include/have_log_bin.inc SET GLOBAL gtid_strict_mode=1; CREATE TEMPORARY TABLE t (i INT ); SET GLOBAL rpl_semi_sync_master_wait_point=AFTER_SYNC; SET SESSION gtid_domain_id=2; SET gtid_seq_no=1; SET gtid_domain_id=0; SET GLOBAL rpl_semi_sync_master_enabled=1; Leads to: CS 11.2.6 e91a79945822def1452787f825e6047c6a64dbd9 (Debug) mariadbd: /test/11.2_dbg/sql/semisync_master.cc:382: void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t): Assertion `entry' failed. CS 11.2.6 e91a79945822def1452787f825e6047c6a64dbd9 (Debug) Core was generated by `/test/MD090924-mariadb-11.2.6-linux-x86_64-dbg/bin/mariadbd --defaults-group-su'. Program terminated with signal SIGABRT, Aborted. Download failed: Invalid argument. Continuing without source file ./nptl/./nptl/pthread_kill.c. #0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44 [Current thread is 1 (LWP 2103668)] (gdb) bt #0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44 #1 __pthread_kill_internal (signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:78 #2 __GI___pthread_kill (threadid=<optimized out>, signo=signo@entry=6)at ./nptl/pthread_kill.c:89 #3 0x000015323584526e in __GI_raise (sig=sig@entry=6)at ../sysdeps/posix/raise.c:26 #4 0x00001532358288ff in __GI_abort () at ./stdlib/abort.c:79 #5 0x000015323582881b in __assert_fail_base (fmt=0x1532359d01e8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x55e71b2d211f "entry", file=file@entry=0x55e71b137ff8 "/test/11.2_dbg/sql/semisync_master.cc", line=line@entry=382, function=function@entry=0x55e71b1380c8 "void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t)") at ./assert/assert.c:94 #6 0x000015323583b507 in __assert_fail (assertion=0x55e71b2d211f "entry", file=0x55e71b137ff8 "/test/11.2_dbg/sql/semisync_master.cc", line=382, function=0x55e71b1380c8 "void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t)") at ./assert/assert.c:103 #7 0x000055e71a6035bf in Active_tranx::assert_thd_is_waiter (this=<optimized out>, thd_to_check=thd_to_check@entry=0x15320c000d58, log_file_name=log_file_name@entry=0x55e71bc2436a <mysql_bin_log+202> "master-bin.000001", log_file_pos=log_file_pos@entry=479)at /test/11.2_dbg/sql/semisync_master.cc:382 #8 0x000055e71a604028 in Repl_semi_sync_master::commit_trx (this=this@entry=0x55e71bc1fe00 <repl_semisync_master>, trx_wait_binlog_name=0x55e71bc2436a <mysql_bin_log+202> "master-bin.000001", trx_wait_binlog_pos=trx_wait_binlog_pos@entry=479)at /test/11.2_dbg/sql/semisync_master.cc:972 #9 0x000055e71a604313 in Repl_semi_sync_master::wait_after_sync (this=0x55e71bc1fe00 <repl_semisync_master>, log_file=log_file@entry=0x55e71bc24368 <mysql_bin_log+200> "./master-bin.000001", log_pos=479) at /test/11.2_dbg/sql/semisync_master.cc:743 #10 0x000055e71a85f99c in MYSQL_BIN_LOG::write (this=0x55e71bc242a0 <mysql_bin_log>, event_info=event_info@entry=0x153230d685c0, with_annotate=with_annotate@entry=0x0) at /test/11.2_dbg/sql/log.cc:6929 #11 0x000055e71a65e64f in THD::log_events_and_free_tmp_shares (this=this@entry=0x15320c000d58)at /test/11.2_dbg/sql/temporary_tables.cc:1427 #12 0x000055e71a65e94c in THD::close_temporary_tables (this=this@entry=0x15320c000d58)at /test/11.2_dbg/sql/temporary_tables.cc:540 #13 0x000055e71a380c67 in THD::cleanup (this=this@entry=0x15320c000d58)at /test/11.2_dbg/sql/sql_class.cc:1598 #14 0x000055e71a2b7728 in unlink_thd (thd=0x15320c000d58)at /test/11.2_dbg/sql/mysqld.cc:2868 #15 0x000055e71a5603bb in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55e71cc3a3e8, put_in_cache=put_in_cache@entry=true)at /test/11.2_dbg/sql/sql_connect.cc:1450 #16 0x000055e71a56065c in handle_one_connection (arg=arg@entry=0x55e71cc3a3e8)at /test/11.2_dbg/sql/sql_connect.cc:1341 #17 0x000055e71a9a762c in pfs_spawn_thread (arg=0x55e71cbba328)at /test/11.2_dbg/storage/perfschema/pfs.cc:2201 #18 0x000015323589ca94 in start_thread (arg=<optimized out>)at ./nptl/pthread_create.c:447 #19 0x0000153235929c3c in clone3 ()at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78 Alternative testcase for the same stack: --source include/have_log_bin.inc SET SESSION gtid_domain_id=1; ANALYZE TABLE t PERSISTENT FOR ALL ; SET GLOBAL rpl_semi_sync_master_wait_point=AFTER_SYNC; SET GLOBAL gtid_strict_mode= ON ; CREATE TABLE t (c INT ); DROP TABLE t; CREATE TABLE t (c INT ); SET gtid_domain_id=11; SET gtid_seq_no=4; SET GLOBAL rpl_semi_sync_master_enabled=1; SET gtid_domain_id=1; FLUSH TABLES;

Brandon Nesterenko added a comment - 2024-09-23 16:41

Hi knielsen!

This is ready for review: PR 3544

Brandon Nesterenko added a comment - 2024-09-23 16:41 Hi knielsen ! This is ready for review: PR 3544

Kristian Nielsen added a comment - 2024-09-24 13:25

Thanks, Brandon, approved with a few comments

Kristian Nielsen added a comment - 2024-09-24 13:25 Thanks, Brandon, approved with a few comments

Roel Van de Paar added a comment - 2024-10-21 01:52 - edited

Repeating the following often enough (CLI):

# mysqld options required for replay: --log_bin

DROP DATABASE test;

CREATE DATABASE test;

USE test;

SET @@max_statement_time=0.00001;

SET default_storage_engine=MEMORY;

CREATE TABLE foo;

XA START 'a';

SET GLOBAL rpl_semi_sync_master_enabled=1;

CREATE TEMPORARY TABLE tmp(a INT);

SET GLOBAL rpl_semi_sync_master_enabled=0;

DROP TABLE t;

SET GLOBAL rpl_semi_sync_master_enabled=1;

SELECT * FROM sys.memory_by_host_by_current_bytes;

Leads to this additional stack:

CS 11.2.6 12a91b57e27b979819924cf89614e6e51f24b37b (Debug)
mariadbd: /test/11.2_dbg/sql/semisync_master.cc:382: void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t): Assertion `entry' failed.

CS 11.2.6 12a91b57e27b979819924cf89614e6e51f24b37b (Debug)
Core was generated by `/test/MD141024-mariadb-11.2.6-linux-x86_64-dbg/bin/mariadbd --no-defaults --max'.
Program terminated with signal SIGABRT, Aborted.
Download failed: Invalid argument. Continuing without source file ./nptl/./nptl/pthread_kill.c.
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44

[Current thread is 1 (LWP 2746854)]
(gdb) bt
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44
#1 __pthread_kill_internal (signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:78
#2 __GI___pthread_kill (threadid=<optimized out>, signo=signo@entry=6)at ./nptl/pthread_kill.c:89
#3 0x00001480c424526e in __GI_raise (sig=sig@entry=6)at ../sysdeps/posix/raise.c:26
#4 0x00001480c42288ff in __GI_abort () at ./stdlib/abort.c:79
#5 0x00001480c422881b in __assert_fail_base (fmt=0x1480c43d01e8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x558e32950c63 "entry", file=file@entry=0x558e327b64f8 "/test/11.2_dbg/sql/semisync_master.cc", line=line@entry=382, function=function@entry=0x558e327b65c8 "void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t)") at ./assert/assert.c:94
#6 0x00001480c423b507 in __assert_fail (assertion=0x558e32950c63 "entry", file=0x558e327b64f8 "/test/11.2_dbg/sql/semisync_master.cc", line=382, function=0x558e327b65c8 "void Active_tranx::assert_thd_is_waiter(THD, const char, my_off_t)") at ./assert/assert.c:103
#7 0x0000558e31c7f2fd in Active_tranx::assert_thd_is_waiter (this=<optimized out>, thd_to_check=thd_to_check@entry=0x14805c000d58, log_file_name=log_file_name@entry=0x14805c063640 "qa-roel-2-bin.000002", log_file_pos=log_file_pos@entry=570)at /test/11.2_dbg/sql/semisync_master.cc:382
#8 0x0000558e31c7fd66 in Repl_semi_sync_master::commit_trx (this=this@entry=0x558e3329f080 <repl_semisync_master>, trx_wait_binlog_name=trx_wait_binlog_name@entry=0x14805c063640 "qa-roel-2-bin.000002", trx_wait_binlog_pos=trx_wait_binlog_pos@entry=570)at /test/11.2_dbg/sql/semisync_master.cc:972
#9 0x0000558e31c80168 in Repl_semi_sync_master::wait_after_commit (this=0x558e3329f080 <repl_semisync_master>, thd=thd@entry=0x14805c000d58, all=all@entry=false) at /test/11.2_dbg/sql/semisync_master.cc:772
#10 0x0000558e31c801a4 in Repl_semi_sync_master::wait_after_rollback (this=<optimized out>, thd=thd@entry=0x14805c000d58, all=all@entry=false)at /test/11.2_dbg/sql/semisync_master.cc:785
#11 0x0000558e31bf223e in trans_rollback_stmt (thd=thd@entry=0x14805c000d58)at /test/11.2_dbg/sql/transaction.cc:574
#12 0x0000558e319e4229 in open_and_lock_tables (thd=thd@entry=0x14805c000d58, options=<optimized out>, tables=<optimized out>, tables@entry=0x1480c1bb0800, derived=derived@entry=false, flags=133122, prelocking_strategy=prelocking_strategy@entry=0x1480c1bb06e8)at /test/11.2_dbg/sql/sql_base.cc:5669
#13 0x0000558e319e9dbc in open_and_lock_tables (flags=<optimized out>, derived=false, tables=0x1480c1bb0800, thd=0x14805c000d58)at /test/11.2_dbg/sql/sql_base.h:531
#14 open_system_tables_for_read (thd=thd@entry=0x14805c000d58, table_list=table_list@entry=0x1480c1bb0800)at /test/11.2_dbg/sql/sql_base.cc:9642
#15 0x0000558e31f0a4ad in open_proc_table_for_read (thd=thd@entry=0x14805c000d58) at /test/11.2_dbg/sql/sp.cc:495
#16 0x0000558e31f0aeed in Sp_handler::db_find_routine (this=this@entry=0x558e3319a3e8 <sp_handler_function>, thd=thd@entry=0x14805c000d58, name=name@entry=0x1480c1bb2510, sphp=sphp@entry=0x1480c1bb2770) at /test/11.2_dbg/sql/sp.cc:714
#17 0x0000558e31f0b209 in Sp_handler::db_find_and_cache_routine (this=this@entry=0x558e3319a3e8 <sp_handler_function>, thd=thd@entry=0x14805c000d58, name=name@entry=0x1480c1bb2510, sp=sp@entry=0x1480c1bb2770) at /test/11.2_dbg/sql/sp.cc:788
#18 0x0000558e31f0b2b2 in Sp_handler::sp_cache_routine (this=0x558e3319a3e8 <sp_handler_function>, thd=0x14805c000d58, name=0x1480c1bb2510, sp=0x1480c1bb2770) at /test/11.2_dbg/sql/sp.cc:2889
#19 0x0000558e31f0f435 in Sroutine_hash_entry::sp_cache_routine (this=this@entry=0x14805c072958, thd=thd@entry=0x14805c000d58, sp=sp@entry=0x1480c1bb2770) at /test/11.2_dbg/sql/sp.cc:2849
#20 0x0000558e319e3757 in open_and_process_routine (routine_modifies_data=<synthetic pointer>, need_prelocking=0x1480c1bb276f, ot_ctx=0x1480c1bb2790, has_prelocking_list=false, prelocking_strategy=0x1480c1bb2880, rt=0x14805c072958, prelocking_ctx=0x14805c0051d8, thd=0x14805c000d58)at /test/11.2_dbg/sql/sql_base.cc:3817
#21 open_tables (thd=thd@entry=0x14805c000d58, options=@0x14805c006840: {m_options = DDL_options_st::OPT_NONE}, start=start@entry=0x1480c1bb2818, counter=counter@entry=0x1480c1bb282c, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x1480c1bb2880)at /test/11.2_dbg/sql/sql_base.cc:4739
#22 0x0000558e319e4130 in open_and_lock_tables (thd=thd@entry=0x14805c000d58, options=<optimized out>, tables=<optimized out>, tables@entry=0x14805c013e18, derived=derived@entry=true, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x1480c1bb2880)at /test/11.2_dbg/sql/sql_base.cc:5640
#23 0x0000558e31a5725f in open_and_lock_tables (flags=0, derived=true, tables=0x14805c013e18, thd=0x14805c000d58)at /test/11.2_dbg/sql/sql_base.h:531
#24 execute_sqlcom_select (thd=thd@entry=0x14805c000d58, all_tables=0x14805c013e18) at /test/11.2_dbg/sql/sql_parse.cc:6098
#25 0x0000558e31a635bc in mysql_execute_command (thd=thd@entry=0x14805c000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false)at /test/11.2_dbg/sql/sql_parse.cc:3984
#26 0x0000558e31a6a2ce in mysql_parse (thd=thd@entry=0x14805c000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1480c1bb32a0)at /test/11.2_dbg/sql/sql_parse.cc:7938
#27 0x0000558e31a6c786 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14805c000d58, packet=packet@entry=0x14805c00b3b9 "SELECT * FROM sys.memory_by_host_by_current_bytes", packet_length=packet_length@entry=49, blocking=blocking@entry=true)at /test/11.2_dbg/sql/sql_class.h:248
#28 0x0000558e31a6e9c2 in do_command (thd=0x14805c000d58, blocking=blocking@entry=true) at /test/11.2_dbg/sql/sql_parse.cc:1407
#29 0x0000558e31bdbfe7 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x558e34d95698, put_in_cache=put_in_cache@entry=true)at /test/11.2_dbg/sql/sql_connect.cc:1439
#30 0x0000558e31bdc2ef in handle_one_connection (arg=arg@entry=0x558e34d95698)at /test/11.2_dbg/sql/sql_connect.cc:1341
#31 0x0000558e32023f14 in pfs_spawn_thread (arg=0x558e34cf4af8)at /test/11.2_dbg/storage/perfschema/pfs.cc:2201
#32 0x00001480c429ca94 in start_thread (arg=<optimized out>)at ./nptl/pthread_create.c:447
#33 0x00001480c4329c3c in clone3 ()at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78

If needed, I can create an MTR testcase.

Roel Van de Paar added a comment - 2024-10-21 01:52 - edited Repeating the following often enough (CLI): # mysqld options required for replay: --log_bin DROP DATABASE test; CREATE DATABASE test; USE test; SET @@max_statement_time=0.00001; SET default_storage_engine=MEMORY; CREATE TABLE foo; XA START 'a' ; SET GLOBAL rpl_semi_sync_master_enabled=1; CREATE TEMPORARY TABLE tmp(a INT ); SET GLOBAL rpl_semi_sync_master_enabled=0; DROP TABLE t; SET GLOBAL rpl_semi_sync_master_enabled=1; SELECT * FROM sys.memory_by_host_by_current_bytes; Leads to this additional stack: CS 11.2.6 12a91b57e27b979819924cf89614e6e51f24b37b (Debug) mariadbd: /test/11.2_dbg/sql/semisync_master.cc:382: void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t): Assertion `entry' failed. CS 11.2.6 12a91b57e27b979819924cf89614e6e51f24b37b (Debug) Core was generated by `/test/MD141024-mariadb-11.2.6-linux-x86_64-dbg/bin/mariadbd --no-defaults --max'. Program terminated with signal SIGABRT, Aborted. Download failed: Invalid argument. Continuing without source file ./nptl/./nptl/pthread_kill.c. #0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44 [Current thread is 1 (LWP 2746854)] (gdb) bt #0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:44 #1 __pthread_kill_internal (signo=6, threadid=<optimized out>)at ./nptl/pthread_kill.c:78 #2 __GI___pthread_kill (threadid=<optimized out>, signo=signo@entry=6)at ./nptl/pthread_kill.c:89 #3 0x00001480c424526e in __GI_raise (sig=sig@entry=6)at ../sysdeps/posix/raise.c:26 #4 0x00001480c42288ff in __GI_abort () at ./stdlib/abort.c:79 #5 0x00001480c422881b in __assert_fail_base (fmt=0x1480c43d01e8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x558e32950c63 "entry", file=file@entry=0x558e327b64f8 "/test/11.2_dbg/sql/semisync_master.cc", line=line@entry=382, function=function@entry=0x558e327b65c8 "void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t)") at ./assert/assert.c:94 #6 0x00001480c423b507 in __assert_fail (assertion=0x558e32950c63 "entry", file=0x558e327b64f8 "/test/11.2_dbg/sql/semisync_master.cc", line=382, function=0x558e327b65c8 "void Active_tranx::assert_thd_is_waiter(THD*, const char*, my_off_t)") at ./assert/assert.c:103 #7 0x0000558e31c7f2fd in Active_tranx::assert_thd_is_waiter (this=<optimized out>, thd_to_check=thd_to_check@entry=0x14805c000d58, log_file_name=log_file_name@entry=0x14805c063640 "qa-roel-2-bin.000002", log_file_pos=log_file_pos@entry=570)at /test/11.2_dbg/sql/semisync_master.cc:382 #8 0x0000558e31c7fd66 in Repl_semi_sync_master::commit_trx (this=this@entry=0x558e3329f080 <repl_semisync_master>, trx_wait_binlog_name=trx_wait_binlog_name@entry=0x14805c063640 "qa-roel-2-bin.000002", trx_wait_binlog_pos=trx_wait_binlog_pos@entry=570)at /test/11.2_dbg/sql/semisync_master.cc:972 #9 0x0000558e31c80168 in Repl_semi_sync_master::wait_after_commit (this=0x558e3329f080 <repl_semisync_master>, thd=thd@entry=0x14805c000d58, all=all@entry=false) at /test/11.2_dbg/sql/semisync_master.cc:772 #10 0x0000558e31c801a4 in Repl_semi_sync_master::wait_after_rollback (this=<optimized out>, thd=thd@entry=0x14805c000d58, all=all@entry=false)at /test/11.2_dbg/sql/semisync_master.cc:785 #11 0x0000558e31bf223e in trans_rollback_stmt (thd=thd@entry=0x14805c000d58)at /test/11.2_dbg/sql/transaction.cc:574 #12 0x0000558e319e4229 in open_and_lock_tables (thd=thd@entry=0x14805c000d58, options=<optimized out>, tables=<optimized out>, tables@entry=0x1480c1bb0800, derived=derived@entry=false, flags=133122, prelocking_strategy=prelocking_strategy@entry=0x1480c1bb06e8)at /test/11.2_dbg/sql/sql_base.cc:5669 #13 0x0000558e319e9dbc in open_and_lock_tables (flags=<optimized out>, derived=false, tables=0x1480c1bb0800, thd=0x14805c000d58)at /test/11.2_dbg/sql/sql_base.h:531 #14 open_system_tables_for_read (thd=thd@entry=0x14805c000d58, table_list=table_list@entry=0x1480c1bb0800)at /test/11.2_dbg/sql/sql_base.cc:9642 #15 0x0000558e31f0a4ad in open_proc_table_for_read (thd=thd@entry=0x14805c000d58) at /test/11.2_dbg/sql/sp.cc:495 #16 0x0000558e31f0aeed in Sp_handler::db_find_routine (this=this@entry=0x558e3319a3e8 <sp_handler_function>, thd=thd@entry=0x14805c000d58, name=name@entry=0x1480c1bb2510, sphp=sphp@entry=0x1480c1bb2770) at /test/11.2_dbg/sql/sp.cc:714 #17 0x0000558e31f0b209 in Sp_handler::db_find_and_cache_routine (this=this@entry=0x558e3319a3e8 <sp_handler_function>, thd=thd@entry=0x14805c000d58, name=name@entry=0x1480c1bb2510, sp=sp@entry=0x1480c1bb2770) at /test/11.2_dbg/sql/sp.cc:788 #18 0x0000558e31f0b2b2 in Sp_handler::sp_cache_routine (this=0x558e3319a3e8 <sp_handler_function>, thd=0x14805c000d58, name=0x1480c1bb2510, sp=0x1480c1bb2770) at /test/11.2_dbg/sql/sp.cc:2889 #19 0x0000558e31f0f435 in Sroutine_hash_entry::sp_cache_routine (this=this@entry=0x14805c072958, thd=thd@entry=0x14805c000d58, sp=sp@entry=0x1480c1bb2770) at /test/11.2_dbg/sql/sp.cc:2849 #20 0x0000558e319e3757 in open_and_process_routine (routine_modifies_data=<synthetic pointer>, need_prelocking=0x1480c1bb276f, ot_ctx=0x1480c1bb2790, has_prelocking_list=false, prelocking_strategy=0x1480c1bb2880, rt=0x14805c072958, prelocking_ctx=0x14805c0051d8, thd=0x14805c000d58)at /test/11.2_dbg/sql/sql_base.cc:3817 #21 open_tables (thd=thd@entry=0x14805c000d58, options=@0x14805c006840: {m_options = DDL_options_st::OPT_NONE}, start=start@entry=0x1480c1bb2818, counter=counter@entry=0x1480c1bb282c, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x1480c1bb2880)at /test/11.2_dbg/sql/sql_base.cc:4739 #22 0x0000558e319e4130 in open_and_lock_tables (thd=thd@entry=0x14805c000d58, options=<optimized out>, tables=<optimized out>, tables@entry=0x14805c013e18, derived=derived@entry=true, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x1480c1bb2880)at /test/11.2_dbg/sql/sql_base.cc:5640 #23 0x0000558e31a5725f in open_and_lock_tables (flags=0, derived=true, tables=0x14805c013e18, thd=0x14805c000d58)at /test/11.2_dbg/sql/sql_base.h:531 #24 execute_sqlcom_select (thd=thd@entry=0x14805c000d58, all_tables=0x14805c013e18) at /test/11.2_dbg/sql/sql_parse.cc:6098 #25 0x0000558e31a635bc in mysql_execute_command (thd=thd@entry=0x14805c000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false)at /test/11.2_dbg/sql/sql_parse.cc:3984 #26 0x0000558e31a6a2ce in mysql_parse (thd=thd@entry=0x14805c000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1480c1bb32a0)at /test/11.2_dbg/sql/sql_parse.cc:7938 #27 0x0000558e31a6c786 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14805c000d58, packet=packet@entry=0x14805c00b3b9 "SELECT * FROM sys.memory_by_host_by_current_bytes", packet_length=packet_length@entry=49, blocking=blocking@entry=true)at /test/11.2_dbg/sql/sql_class.h:248 #28 0x0000558e31a6e9c2 in do_command (thd=0x14805c000d58, blocking=blocking@entry=true) at /test/11.2_dbg/sql/sql_parse.cc:1407 #29 0x0000558e31bdbfe7 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x558e34d95698, put_in_cache=put_in_cache@entry=true)at /test/11.2_dbg/sql/sql_connect.cc:1439 #30 0x0000558e31bdc2ef in handle_one_connection (arg=arg@entry=0x558e34d95698)at /test/11.2_dbg/sql/sql_connect.cc:1341 #31 0x0000558e32023f14 in pfs_spawn_thread (arg=0x558e34cf4af8)at /test/11.2_dbg/storage/perfschema/pfs.cc:2201 #32 0x00001480c429ca94 in start_thread (arg=<optimized out>)at ./nptl/pthread_create.c:447 #33 0x00001480c4329c3c in clone3 ()at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78 If needed, I can create an MTR testcase.

Brandon Nesterenko added a comment - 2024-10-21 22:32 - edited

Pushed into 10.6 as 1ed30e08af4.

There is a merge conflict in 11.4 with resolution in branch bb-11.4-MDEV-34122-mergefix

Brandon Nesterenko added a comment - 2024-10-21 22:32 - edited Pushed into 10.6 as 1ed30e08af4 . There is a merge conflict in 11.4 with resolution in branch bb-11.4-MDEV-34122-mergefix

People

Assignee:: Brandon Nesterenko

Reporter:: Elena Stepanova

Votes:: 0 Vote for this issue

Watchers:: 3 Start watching this issue

Dates

Created:: 2024-05-08 20:26

Updated:: 2024-10-31 11:58

Resolved:: 2024-10-21 22:32

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server