[MDEV-25562] Assertion `pause_seqno_.is_undefined() == false' failed in void wsrep::server_state::resume() Created: 2021-04-29  Updated: 2021-05-26  Resolved: 2021-05-26

Status: Closed
Project: MariaDB Server
Component/s: Galera
Affects Version/s: 10.4, 10.5, 10.6
Fix Version/s: 10.6.2, 10.4.20, 10.5.11

Type: Bug Priority: Major
Reporter: Ramesh Sivaraman Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: not-10.2, not-10.3

Attachments: File mdev-25562.test    

 Description   

SET GLOBAL wsrep_ignore_apply_errors=1;
CREATE TABLE t1 (a CHAR(1));
CREATE TABLE t1 (a CHAR(1));
SHOW PROCEDURE STATUS WHERE db = 'test';
SET GLOBAL read_only=1;

Leads to:

10.6.0 8751aa7397b2e698fa0b46ec3e60abb9e2fd7e1b (Debug)

mysqld: /test/10.6_dbg/wsrep-lib/src/server_state.cpp:580: void wsrep::server_state::resume(): Assertion `pause_seqno_.is_undefined() == false' failed.

10.6.0 8751aa7397b2e698fa0b46ec3e60abb9e2fd7e1b (Debug)

Core was generated by `/test/GAL_MD200421-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --defaults-file=/'.
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 0x1540b8ca7700 (LWP 2549921))]
(gdb) bt
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
#1  0x000055edfd62b70f in my_write_core (sig=sig@entry=6) at /test/10.6_dbg/mysys/stacktrace.c:424
#2  0x000055edfcdc0c86 in handle_fatal_signal (sig=6) at /test/10.6_dbg/sql/signal_handler.cc:343
#3  <signal handler called>
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#5  0x00001540caf91859 in __GI_abort () at abort.c:79
#6  0x00001540caf91729 in __assert_fail_base (fmt=0x1540cb127588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55edfdd22b28 "pause_seqno_.is_undefined() == false", file=0x55edfdd226a0 "/test/10.6_dbg/wsrep-lib/src/server_state.cpp", line=580, function=<optimized out>) at assert.c:92
#7  0x00001540cafa2f36 in __GI___assert_fail (assertion=assertion@entry=0x55edfdd22b28 "pause_seqno_.is_undefined() == false", file=file@entry=0x55edfdd226a0 "/test/10.6_dbg/wsrep-lib/src/server_state.cpp", line=line@entry=580, function=function@entry=0x55edfdd22b00 "void wsrep::server_state::resume()") at assert.c:101
#8  0x000055edfd74b2af in wsrep::server_state::resume (this=this@entry=0x55edff5f79d0) at /test/10.6_dbg/wsrep-lib/src/server_state.cpp:582
#9  0x000055edfcf3bf41 in Global_read_lock::unlock_global_read_lock (this=this@entry=0x154058004710, thd=thd@entry=0x154058000db8) at /test/10.6_dbg/sql/lock.cc:1136
#10 0x000055edfcc71773 in fix_read_only (self=<optimized out>, thd=0x154058000db8, type=<optimized out>) at /test/10.6_dbg/sql/sys_vars.cc:2881
#11 0x000055edfca00638 in sys_var::update (this=0x55edfe0fb540 <Sys_readonly>, thd=0x154058000db8, var=0x154058013cf8) at /test/10.6_dbg/sql/set_var.cc:207
#12 0x000055edfca00b4f in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/10.6_dbg/sql/set_var.cc:859
#13 0x000055edfca01ec0 in sql_set_variables (thd=thd@entry=0x154058000db8, var_list=var_list@entry=0x154058005ec0, free=free@entry=true) at /test/10.6_dbg/sql/set_var.cc:746
#14 0x000055edfcb0123c in mysql_execute_command (thd=thd@entry=0x154058000db8) at /test/10.6_dbg/sql/sql_parse.cc:5030
#15 0x000055edfcaea3b8 in mysql_parse (thd=thd@entry=0x154058000db8, rawbuf=rawbuf@entry=0x154058013bb0 "SET GLOBAL read_only=1", length=length@entry=22, parser_state=parser_state@entry=0x1540b8ca6410) at /test/10.6_dbg/sql/sql_parse.cc:8017
#16 0x000055edfcae9d51 in wsrep_mysql_parse (thd=thd@entry=0x154058000db8, rawbuf=0x154058013bb0 "SET GLOBAL read_only=1", length=22, parser_state=parser_state@entry=0x1540b8ca6410) at /test/10.6_dbg/sql/sql_parse.cc:7831
#17 0x000055edfcaf926b in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x154058000db8, packet=packet@entry=0x15405800b369 "SET GLOBAL read_only=1", packet_length=packet_length@entry=22, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1331
#18 0x000055edfcafc653 in do_command (thd=0x154058000db8, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1406
#19 0x000055edfcc5726d in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55edffbee238, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
#20 0x000055edfcc57875 in handle_one_connection (arg=arg@entry=0x55edffbee238) at /test/10.6_dbg/sql/sql_connect.cc:1312
#21 0x000055edfd1082f7 in pfs_spawn_thread (arg=0x55edffc535d8) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
#22 0x00001540cb49f609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#23 0x00001540cb08e293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.5.10 (dbg), 10.6.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.38 (dbg), 10.3.29 (dbg), 10.4.19 (dbg)



 Comments   
Comment by Ramesh Sivaraman [ 2021-05-19 ]

Found similar assertion with slightly different stack. The testcase crashes 10.4, 10.5 and 10.6

SET SESSION WSREP_ON=0;
FLUSH TABLES WITH READ LOCK AND DISABLE CHECKPOINT;
SET SESSION wsrep_on=1;
UNLOCK TABLES;

10.6.1 370b310b1d67ad42df96b75c3876fdcf67a8694f (Debug)

mysqld: /test/10.6_dbg/wsrep-lib/src/server_state.cpp:580: void wsrep::server_state::resume(): Assertion `pause_seqno_.is_undefined() == false' failed.

10.6.1 370b310b1d67ad42df96b75c3876fdcf67a8694f (Debug)

Core was generated by `/test/GAL_MD120521-mariadb-10.6.1-linux-x86_64-dbg/bin/mysqld --defaults-file=/'.
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 0x147fdcd5a700 (LWP 2543732))]
(gdb) bt
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
#1  0x000055c8a532e1f1 in my_write_core (sig=sig@entry=6) at /test/10.6_dbg/mysys/stacktrace.c:424
#2  0x000055c8a4ac6d3e in handle_fatal_signal (sig=6) at /test/10.6_dbg/sql/signal_handler.cc:343
#3  <signal handler called>
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#5  0x0000147ffef52859 in __GI_abort () at abort.c:79
#6  0x0000147ffef52729 in __assert_fail_base (fmt=0x147fff0e8588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55c8a5a2cae8 "pause_seqno_.is_undefined() == false", file=0x55c8a5a2c660 "/test/10.6_dbg/wsrep-lib/src/server_state.cpp", line=580, function=<optimized out>) at assert.c:92
#7  0x0000147ffef63f36 in __GI___assert_fail (assertion=assertion@entry=0x55c8a5a2cae8 "pause_seqno_.is_undefined() == false", file=file@entry=0x55c8a5a2c660 "/test/10.6_dbg/wsrep-lib/src/server_state.cpp", line=line@entry=580, function=function@entry=0x55c8a5a2cac0 "void wsrep::server_state::resume()") at assert.c:101
#8  0x000055c8a544dba1 in wsrep::server_state::resume (this=this@entry=0x55c8a76c9a10) at /test/10.6_dbg/wsrep-lib/src/server_state.cpp:582
#9  0x000055c8a544eb35 in wsrep::server_state::resume_and_resync (this=this@entry=0x55c8a76c9a10) at /test/10.6_dbg/wsrep-lib/src/server_state.cpp:638
#10 0x000055c8a4c417c8 in Global_read_lock::unlock_global_read_lock (this=this@entry=0x147f7c0048a0, thd=thd@entry=0x147f7c000db8) at /test/10.6_dbg/sql/lock.cc:1141
#11 0x000055c8a4800a14 in mysql_execute_command (thd=thd@entry=0x147f7c000db8) at /test/10.6_dbg/sql/sql_parse.cc:5068
#12 0x000055c8a47e9a81 in mysql_parse (thd=thd@entry=0x147f7c000db8, rawbuf=rawbuf@entry=0x147f7c013fe0 "UNLOCK TABLES", length=length@entry=13, parser_state=parser_state@entry=0x147fdcd59410) at /test/10.6_dbg/sql/sql_parse.cc:8018
#13 0x000055c8a47e941a in wsrep_mysql_parse (thd=thd@entry=0x147f7c000db8, rawbuf=0x147f7c013fe0 "UNLOCK TABLES", length=13, parser_state=parser_state@entry=0x147fdcd59410) at /test/10.6_dbg/sql/sql_parse.cc:7832
#14 0x000055c8a47f8994 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x147f7c000db8, packet=packet@entry=0x147f7c00b799 "UNLOCK TABLES", packet_length=packet_length@entry=13, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_class.h:1333
#15 0x000055c8a47fbd79 in do_command (thd=0x147f7c000db8, blocking=blocking@entry=true) at /test/10.6_dbg/sql/sql_parse.cc:1406
#16 0x000055c8a4957de7 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55c8a7cb5d58, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
#17 0x000055c8a49583ef in handle_one_connection (arg=arg@entry=0x55c8a7cb5d58) at /test/10.6_dbg/sql/sql_connect.cc:1312
#18 0x000055c8a4e0dbc1 in pfs_spawn_thread (arg=0x55c8a7d321d8) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
#19 0x0000147fff460609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#20 0x0000147fff04f293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment by Marko Mäkelä [ 2021-05-26 ]

The added test case fails in 10.5:

CURRENT_TEST: galera.MDEV-25562
mysqltest: At line 17: query 'SHOW PROCEDURE STATUS WHERE db = 'test'' failed: 1205: Lock wait timeout exceeded; try restarting transaction

If I adjust for that, it will still fail:

mysqltest: At line 23: query 'DROP TABLE t1' failed: 1047: WSREP has not yet prepared node for application use

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