[MDEV-25516] Assertion `m_thd == _current_thd()' failed in virtual int Wsrep_client_service::bf_rollback() Created: 2021-02-23  Updated: 2023-02-13  Resolved: 2023-02-13

Status: Closed
Project: MariaDB Server
Component/s: Galera, XA
Affects Version/s: 10.6
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Ramesh Sivaraman Assignee: Daniele Sciascia
Resolution: Duplicate Votes: 0
Labels: not-10.2, not-10.3, not-10.4, not-10.5, regression

Issue Links:
Duplicate
duplicates MDEV-24981 LOAD INDEX may cause rollback of prep... Open

 Description    

XA START 'a';
 
XA END 'a';
 
XA PREPARE 'a';
 
LOAD INDEX INTO cache t1 KEY(PRIMARY);

10.6.0 219925919cd7b63b4a177755c55c13929bf6dfa8 (Debug)

 
mysqld: /test/10.6_dbg/sql/wsrep_client_service.cc:439: virtual int Wsrep_client_service::bf_rollback(): Assertion `m_thd == _current_thd()' failed.

10.6.0 219925919cd7b63b4a177755c55c13929bf6dfa8 (Debug)

 
Core was generated by `/test/GAL_EMD230221-mariadb-10.6.0-0-linux-x86_64-dbg/bin/mysqld --defaults-fil'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
[Current thread is 1 (Thread 0x14569482d700 (LWP 421596))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
#1  0x0000555cffa44b95 in my_write_core (sig=sig@entry=6) at /test/10.6_dbg/mysys/stacktrace.c:424
 
#2  0x0000555cff18ff57 in handle_fatal_signal (sig=6) at /test/10.6_dbg/sql/signal_handler.cc:330
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#5  0x00001456abbc7859 in __GI_abort () at abort.c:79
 
#6  0x00001456abbc7729 in __assert_fail_base (fmt=0x1456abd5d588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x555cffddac9b "m_thd == _current_thd()", file=0x555cffddad40 "/test/10.6_dbg/sql/wsrep_client_service.cc", line=439, function=<optimized out>) at assert.c:92
 
#7  0x00001456abbd8f36 in __GI___assert_fail (assertion=assertion@entry=0x555cffddac9b "m_thd == _current_thd()", file=file@entry=0x555cffddad40 "/test/10.6_dbg/sql/wsrep_client_service.cc", line=line@entry=439, function=function@entry=0x555cffddb088 "virtual int Wsrep_client_service::bf_rollback()") at assert.c:101
 
#8  0x0000555cff545401 in Wsrep_client_service::bf_rollback (this=0x14561c041c78) at /test/10.6_dbg/sql/wsrep_client_service.cc:439
 
#9  0x0000555cffb58ce7 in wsrep::client_state::close (this=0x14561c041c90) at /test/10.6_dbg/wsrep-lib/src/client_state.cpp:59
 
#10 0x0000555cff548c27 in Wsrep_applier_service::~Wsrep_applier_service (this=0x555d01c81050, __in_chrg=<optimized out>) at /test/10.6_dbg/sql/sql_class.h:5089
 
#11 0x0000555cff573af8 in Wsrep_prepared_applier_service::~Wsrep_prepared_applier_service (this=0x555d01c81050, __in_chrg=<optimized out>) at /test/10.6_dbg/sql/wsrep_high_priority_service.h:103
 
#12 Wsrep_prepared_applier_service::~Wsrep_prepared_applier_service (this=0x555d01c81050, __in_chrg=<optimized out>) at /test/10.6_dbg/sql/wsrep_high_priority_service.h:103
 
#13 0x0000555cff571bfa in Wsrep_server_service::release_high_priority_service (this=<optimized out>, high_priority_service=<optimized out>) at /test/10.6_dbg/sql/wsrep_server_service.cc:169
 
#14 0x0000555cffb63fda in wsrep::server_state::convert_streaming_client_to_applier (this=0x555d010eee50, client_state=0x14561c007240) at /test/10.6_dbg/wsrep-lib/src/server_state.cpp:1195
 
#15 0x0000555cffb67e5b in wsrep::transaction::streaming_rollback (this=this@entry=0x14561c0072a8, lock=@0x14569482b330: {_M_device = 0x14561c007208, _M_owns = false}) at /test/10.6_dbg/wsrep-lib/src/transaction.cpp:1859
 
#16 0x0000555cffb694ef in wsrep::transaction::before_rollback (this=this@entry=0x14561c0072a8) at /test/10.6_dbg/wsrep-lib/src/transaction.cpp:687
 
#17 0x0000555cff19587f in wsrep::client_state::before_rollback (this=0x14561c007240) at /test/10.6_dbg/wsrep-lib/include/wsrep/client_state.hpp:527
 
#18 wsrep_before_rollback (all=true, thd=0x14561c000db8) at /test/10.6_dbg/sql/wsrep_trans_observer.h:469
 
#19 ha_rollback_trans (thd=thd@entry=0x14561c000db8, all=all@entry=true) at /test/10.6_dbg/sql/handler.cc:2081
 
#20 0x0000555cff036ace in trans_rollback_implicit (thd=thd@entry=0x14561c000db8) at /test/10.6_dbg/sql/transaction.cc:421
 
#21 0x0000555cff034bbe in mysql_admin_table (thd=thd@entry=0x14561c000db8, tables=tables@entry=0x14561c0127c8, check_opt=check_opt@entry=0x0, operator_name=<optimized out>, operator_name@entry=0x555cffd938a3 "preload_keys", lock_type=lock_type@entry=TL_READ_NO_INSERT, org_open_for_modify=org_open_for_modify@entry=false, repair_table_use_frm=false, extra_open_options=0, prepare_func=0x0, operator_func=&virtual table offset 768, view_operator_func=0x0) at /test/10.6_dbg/sql/sql_admin.cc:1195
 
#22 0x0000555cff0359ae in mysql_preload_keys (thd=thd@entry=0x14561c000db8, tables=tables@entry=0x14561c0127c8) at /test/10.6_dbg/sql/sql_admin.cc:1339
 
#23 0x0000555cfeec68eb in mysql_execute_command (thd=thd@entry=0x14561c000db8) at /test/10.6_dbg/sql/sql_parse.cc:3976
 
#24 0x0000555cfeeb2282 in mysql_parse (thd=thd@entry=0x14561c000db8, rawbuf=rawbuf@entry=0x14561c0126d0 "LOAD INDEX INTO cache t1", length=length@entry=24, parser_state=parser_state@entry=0x14569482c3d0) at /test/10.6_dbg/sql/sql_parse.cc:7918
 
#25 0x0000555cfeeb1b34 in wsrep_mysql_parse (thd=thd@entry=0x14561c000db8, rawbuf=0x14561c0126d0 "LOAD INDEX INTO cache t1", length=24, parser_state=parser_state@entry=0x14569482c3d0) at /test/10.6_dbg/sql/sql_parse.cc:7732
 
#26 0x0000555cfeec0499 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14561c000db8, packet=packet@entry=0x14561c008d49 "", packet_length=packet_length@entry=24) at /test/10.6_dbg/sql/sql_class.h:1254
 
#27 0x0000555cfeec3a8b in do_command (thd=0x14561c000db8) at /test/10.6_dbg/sql/sql_parse.cc:1355
 
#28 0x0000555cff0205aa in do_handle_one_connection (connect=<optimized out>, connect@entry=0x555d01d3cb88, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
 
#29 0x0000555cff020cb1 in handle_one_connection (arg=arg@entry=0x555d01d3cb88) at /test/10.6_dbg/sql/sql_connect.cc:1312
 
#30 0x0000555cff4ddc5f in pfs_spawn_thread (arg=0x555d01d3e3a8) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
 
#31 0x00001456ac0d3609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#32 0x00001456abcc4293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.6.0 (dbg)

Bug confirmed not present in:
MariaDB: 10.2.37 (dbg), 10.3.28 (dbg), 10.4.18 (dbg), 10.5.9 (dbg)

 Comments   
Comment by Daniele Sciascia [ 2021-02-25 ]

There is a bug here that does not seem to depend on WSREP. Once a transaction is PREPARED, the server should not attempt to roll it back. Details in the linked MENT-1120 ticket

Comment by Ramesh Sivaraman [ 2021-03-22 ]

sciascid Found similar assertion but with different test case. Note the different frames after a few matching initial frames, please let me know if I should lodge new bug. 

XA START 'a';
 
SET debug_dbug='+d,ib_create_table_fail_too_many_trx';
 
XA END 'a';
 
XA PREPARE 'a';

Leads to:

10.6.0-0 3402184ce3d235788455c30a2d2dae3c32d15af9 (Debug)

 
mysqld: /test/10.6_dbg/sql/wsrep_client_service.cc:439: virtual int Wsrep_client_service::bf_rollback(): Assertion `m_thd == _current_thd()' failed.

10.6.0-0 3402184ce3d235788455c30a2d2dae3c32d15af9 (Debug)

 
Core was generated by `/test/GAL_EMD150321-mariadb-10.6.0-0-linux-x86_64-dbg/bin/mysqld --defaults-fil'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
[Current thread is 1 (Thread 0x152098cb6700 (LWP 1340752))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
 
#1  0x00005625a47a7c45 in my_write_core (sig=sig@entry=6) at /test/10.6_dbg/mysys/stacktrace.c:424
 
#2  0x00005625a3ef3033 in handle_fatal_signal (sig=6) at /test/10.6_dbg/sql/signal_handler.cc:330
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#5  0x00001520b19f2859 in __GI_abort () at abort.c:79
 
#6  0x00001520b19f2729 in __assert_fail_base (fmt=0x1520b1b88588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5625a4b3dc9b "m_thd == _current_thd()", file=0x5625a4b3dd40 "/test/10.6_dbg/sql/wsrep_client_service.cc", line=439, function=<optimized out>) at assert.c:92
 
#7  0x00001520b1a03f36 in __GI___assert_fail (assertion=assertion@entry=0x5625a4b3dc9b "m_thd == _current_thd()", file=file@entry=0x5625a4b3dd40 "/test/10.6_dbg/sql/wsrep_client_service.cc", line=line@entry=439, function=function@entry=0x5625a4b3e088 "virtual int Wsrep_client_service::bf_rollback()") at assert.c:101
 
#8  0x00005625a42a84dd in Wsrep_client_service::bf_rollback (this=0x1520440375f8) at /test/10.6_dbg/sql/wsrep_client_service.cc:439
 
#9  0x00005625a48bbd97 in wsrep::client_state::close (this=this@entry=0x152044037610) at /test/10.6_dbg/wsrep-lib/src/client_state.cpp:59
 
#10 0x00005625a42d85c5 in wsrep_close (thd=0x152044031188) at /test/10.6_dbg/sql/sql_class.h:5089
 
#11 Wsrep_storage_service::~Wsrep_storage_service (this=0x15204401bd50, __in_chrg=<optimized out>) at /test/10.6_dbg/sql/wsrep_storage_service.cc:75
 
#12 0x00005625a42d8669 in Wsrep_storage_service::~Wsrep_storage_service (this=0x15204401bd50, __in_chrg=<optimized out>) at /test/10.6_dbg/sql/wsrep_storage_service.cc:72
 
#13 0x00005625a42d4c7b in Wsrep_server_service::release_storage_service (this=<optimized out>, storage_service=0x15204401bd50) at /test/10.6_dbg/sql/wsrep_server_service.cc:86
 
#14 0x00005625a48cf4e3 in (anonymous namespace)::storage_service_deleter::operator() (storage_service=0x15204401bd50, this=<synthetic pointer>) at /test/10.6_dbg/wsrep-lib/src/transaction.cpp:1499
 
#15 (anonymous namespace)::scoped_storage_service<(anonymous namespace)::storage_service_deleter>::~scoped_storage_service (this=<synthetic pointer>, __in_chrg=<optimized out>) at /test/10.6_dbg/wsrep-lib/src/transaction.cpp:74
 
#16 wsrep::transaction::certify_fragment (this=this@entry=0x1520440072a8, lock=@0x152098cb4a20: {_M_device = 0x152044007208, _M_owns = false}) at /test/10.6_dbg/wsrep-lib/src/transaction.cpp:1477
 
#17 0x00005625a48cff29 in wsrep::transaction::streaming_step (this=this@entry=0x1520440072a8, lock=@0x152098cb4a20: {_M_device = 0x152044007208, _M_owns = false}, force=force@entry=true) at /test/10.6_dbg/wsrep-lib/src/transaction.cpp:1391
 
#18 0x00005625a48d0274 in wsrep::transaction::before_prepare (this=this@entry=0x1520440072a8, lock=@0x152098cb4a20: {_M_device = 0x152044007208, _M_owns = false}) at /test/10.6_dbg/wsrep-lib/src/transaction.cpp:332
 
#19 0x00005625a3f0e786 in wsrep::client_state::before_prepare (this=0x152044007240) at /test/10.6_dbg/wsrep-lib/include/wsrep/client_state.hpp:488
 
#20 wsrep_before_prepare (all=true, thd=0x152044000db8) at /test/10.6_dbg/sql/wsrep_trans_observer.h:304
 
#21 ha_prepare (thd=thd@entry=0x152044000db8) at /test/10.6_dbg/sql/handler.cc:1423
 
#22 0x00005625a3e58779 in trans_xa_prepare (thd=thd@entry=0x152044000db8) at /test/10.6_dbg/include/mysql/psi/mysql_transaction.h:206
 
#23 0x00005625a3c2e3b7 in mysql_execute_command (thd=thd@entry=0x152044000db8) at /test/10.6_dbg/sql/sql_parse.cc:5726
 
#24 0x00005625a3c15282 in mysql_parse (thd=thd@entry=0x152044000db8, rawbuf=rawbuf@entry=0x1520440126d0 "XA PREPARE 'a'", length=length@entry=14, parser_state=parser_state@entry=0x152098cb53d0) at /test/10.6_dbg/sql/sql_parse.cc:7918
 
#25 0x00005625a3c14b34 in wsrep_mysql_parse (thd=thd@entry=0x152044000db8, rawbuf=0x1520440126d0 "XA PREPARE 'a'", length=14, parser_state=parser_state@entry=0x152098cb53d0) at /test/10.6_dbg/sql/sql_parse.cc:7732
 
#26 0x00005625a3c23499 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x152044000db8, packet=packet@entry=0x152044008d49 "XA PREPARE 'a'", packet_length=packet_length@entry=14) at /test/10.6_dbg/sql/sql_class.h:1254
 
#27 0x00005625a3c26a8b in do_command (thd=0x152044000db8) at /test/10.6_dbg/sql/sql_parse.cc:1355
 
#28 0x00005625a3d835aa in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5625a7218718, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
 
#29 0x00005625a3d83cb1 in handle_one_connection (arg=arg@entry=0x5625a7218718) at /test/10.6_dbg/sql/sql_connect.cc:1312
 
#30 0x00005625a4240d3b in pfs_spawn_thread (arg=0x5625a728b238) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
 
#31 0x00001520b1efe609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#32 0x00001520b1aef293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.6.0-0 (dbg)

Generated at Thu Feb 08 09:38:17 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.