[MDEV-22285] Assertion `xid_seqno > wsrep_seqno' failed in trx_rseg_update_wsrep_checkpoint on SET @@global.wsrep_start_position Created: 2020-04-18  Updated: 2022-07-12  Resolved: 2021-01-14

Status: Closed
Project: MariaDB Server
Component/s: wsrep
Affects Version/s: 10.4, 10.5
Fix Version/s: 10.4.18, 10.5.9, 10.6.0

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: affects-tests

Issue Links:
Duplicate
Relates
relates to MDEV-22708 Assertion `!mysql_bin_log.is_open() |... Closed
relates to MDEV-29086 Assertion `xid_seqno > wsrep_seqno' f... Open

 Description    

SET @@global.wsrep_start_position='00000000-0000-0000-0000-000000000000:-2';

Leads to:

10.5.3 364e7a9ae6b5fbf69494cec30733b5ad28738cbb

 
mysqld: /test/10.5_dbg/storage/innobase/trx/trx0rseg.cc:108: void trx_rseg_update_wsrep_checkpoint(buf_block_t*, const XID*, mtr_t*): Assertion `xid_seqno > wsrep_seqno' failed.

10.5.3 364e7a9ae6b5fbf69494cec30733b5ad28738cbb

 
Core was generated by `/test/MD110420-mariadb-10.5.3-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
 
    at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
[Current thread is 1 (Thread 0x7f2a3698c700 (LWP 11627))]
 
(gdb) bt
 
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
 
#1  0x0000556614ed721e in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
 
#2  0x000055661467d08f in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:329
 
#3  <signal handler called>
 
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
 
#5  0x00007f2a350d0801 in __GI_abort () at abort.c:79
 
#6  0x00007f2a350c039a in __assert_fail_base (fmt=0x7f2a352477d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x556615349216 "xid_seqno > wsrep_seqno", file=file@entry=0x556615348f18 "/test/10.5_dbg/storage/innobase/trx/trx0rseg.cc", line=line@entry=108, function=function@entry=0x55661534a600 <trx_rseg_update_wsrep_checkpoint(buf_block_t*, xid_t const*, mtr_t*)::__PRETTY_FUNCTION__> "void trx_rseg_update_wsrep_checkpoint(buf_block_t*, const XID*, mtr_t*)") at assert.c:92
 
#7  0x00007f2a350c0412 in __GI___assert_fail (assertion=assertion@entry=0x556615349216 "xid_seqno > wsrep_seqno", file=file@entry=0x556615348f18 "/test/10.5_dbg/storage/innobase/trx/trx0rseg.cc", line=line@entry=108, function=function@entry=0x55661534a600 <trx_rseg_update_wsrep_checkpoint(buf_block_t*, xid_t const*, mtr_t*)::__PRETTY_FUNCTION__> "void trx_rseg_update_wsrep_checkpoint(buf_block_t*, const XID*, mtr_t*)") at assert.c:101
 
#8  0x0000556614c703a2 in trx_rseg_update_wsrep_checkpoint (rseg_header=rseg_header@entry=0x7f2a1748ff88, xid=xid@entry=0x7f2a3698a4a0, mtr=mtr@entry=0x7f2a36989df0) at /test/10.5_dbg/storage/innobase/trx/trx0rseg.cc:108
 
#9  0x0000556614c7171d in trx_rseg_update_wsrep_checkpoint (xid=xid@entry=0x7f2a3698a4a0, mtr=mtr@entry=0x7f2a36989df0) at /test/10.5_dbg/storage/innobase/trx/trx0rseg.cc:146
 
#10 0x0000556614c71bec in trx_rseg_update_wsrep_checkpoint (xid=xid@entry=0x7f2a3698a4a0) at /test/10.5_dbg/storage/innobase/trx/trx0rseg.cc:176
 
#11 0x0000556614a2f028 in innobase_wsrep_set_checkpoint (hton=0x7f2a34443088, xid=0x7f2a3698a4a0) at /test/10.5_dbg/storage/innobase/handler/ha_innodb.cc:19089
 
#12 0x00005566149f5b63 in set_SE_checkpoint (unused=unused@entry=0x0, plugin=<optimized out>, arg=arg@entry=0x7f2a3698a4a0) at /test/10.5_dbg/sql/wsrep_xid.cc:127
 
#13 0x00005566143ec38f in plugin_foreach_with_mask (thd=thd@entry=0x0, func=func@entry=0x5566149f5adb <set_SE_checkpoint(THD*, plugin_ref, void*)>, type=type@entry=1, state_mask=state_mask@entry=8, arg=arg@entry=0x7f2a3698a4a0) at /test/10.5_dbg/sql/sql_plugin.cc:2470
 
#14 0x00005566149f5ca7 in wsrep_set_SE_checkpoint (xid=...) at /test/10.5_dbg/sql/wsrep_xid.cc:134
 
#15 0x00005566149f5ce1 in wsrep_set_SE_checkpoint (wsgtid=..., gtid=...) at /test/10.5_dbg/sql/wsrep_xid.cc:142
 
#16 0x0000556614a05e0c in wsrep_sst_received (thd=thd@entry=0x7f2a08815088, uuid=..., seqno=seqno@entry=-2, state=state@entry=0x0, state_len=state_len@entry=0) at /test/10.5_dbg/sql/wsrep_sst.cc:355
 
#17 0x0000556614a09b26 in wsrep_set_local_position (thd=thd@entry=0x7f2a08815088, value=<optimized out>, length=<optimized out>, sst=sst@entry=true) at /test/10.5_dbg/sql/wsrep_var.cc:266
 
#18 0x0000556614a0a01f in wsrep_start_position_check (self=<optimized out>, thd=0x7f2a08815088, var=0x7f2a08874408) at /test/10.5_dbg/sql/wsrep_var.cc:294
 
#19 0x00005566142ebabe in sys_var::check (this=0x556615c318a0 <Sys_wsrep_start_position>, thd=thd@entry=0x7f2a08815088, var=var@entry=0x7f2a08874408) at /test/10.5_dbg/sql/set_var.cc:246
 
#20 0x00005566142ecb58 in set_var::check (this=0x7f2a08874408, thd=0x7f2a08815088) at /test/10.5_dbg/sql/set_var.cc:811
 
#21 0x00005566142ed284 in sql_set_variables (thd=thd@entry=0x7f2a08815088, var_list=var_list@entry=0x7f2a08819fa0, free=free@entry=true) at /test/10.5_dbg/sql/set_var.cc:739
 
#22 0x00005566143d650c in mysql_execute_command (thd=thd@entry=0x7f2a08815088) at /test/10.5_dbg/sql/sql_parse.cc:4976
 
#23 0x00005566143e09d1 in mysql_parse (thd=thd@entry=0x7f2a08815088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f2a3698b450, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:7953
 
#24 0x00005566143cc719 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f2a08815088, packet=packet@entry=0x7f2a08867089 "SET @@global.wsrep_start_position='00000000-0000-0000-0000-", '0' <repeats 12 times>, ":-2'", packet_length=packet_length@entry=75, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:1839
 
#25 0x00005566143caf6f in do_command (thd=0x7f2a08815088) at /test/10.5_dbg/sql/sql_parse.cc:1358
 
#26 0x0000556614525a53 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x7f2a0d4433a8, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1422
 
#27 0x0000556614525d82 in handle_one_connection (arg=arg@entry=0x7f2a0d4433a8) at /test/10.5_dbg/sql/sql_connect.cc:1319
 
#28 0x0000556614986080 in pfs_spawn_thread (arg=0x7f2a34445888) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
 
#29 0x00007f2a35db36db in start_thread (arg=0x7f2a3698c700) at pthread_create.c:463
 
#30 0x00007f2a351b188f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.1.45 (dbg), 10.3.23 (dbg), 10.4.13 (dbg), 10.5.2 (dbg), 10.5.3 (dbg)

Bug confirmed not present in:
MariaDB: 10.1.45 (opt), 10.2.32 (dbg), 10.2.32 (opt), 10.3.23 (opt), 10.4.13 (opt), 10.5.2 (opt), 10.5.3 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.47 (dbg), 5.6.47 (opt), 5.7.29 (dbg), 5.7.29 (opt), 8.0.19 (dbg), 8.0.19 (opt)

 Comments   
Comment by Roel Van de Paar [ 2020-04-18 ]

Whilst both MDEV-22216 and MDEV-21026 show the same assert message, they have different stacks.

Comment by Jan Lindström (Inactive) [ 2020-04-27 ] 

MariaDB Version 10.3.23-MariaDB-debug
 
 - SSL connections supported
 
 - binaries are debug compiled
 
 - binaries built with wsrep patch
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
SET @@global.wsrep_start_position='00000000-0000-0000-0000-000000000000:-2';
 
galera.galera_wsrep_start_pos 'innodb'   [ fail ]
 
        Test ended at 2020-04-27 12:55:27
 
 
 
CURRENT_TEST: galera.galera_wsrep_start_pos
 
mysqltest: At line 3: query 'SET @@global.wsrep_start_position='00000000-0000-0000-0000-000000000000:-2'' failed: 1231: Variable 'wsrep_start_position' can't be set to the value of '00000000-0000-0000-0000-000000000000:-2'

Comment by Roel Van de Paar [ 2020-04-28 ]

Discussed on Slack. Jan is able to reproduce the same on 10.5, but not on 10.3.

Confirmed bug present in 10.3.23, debug, revision 811e4409ce587bc4b693cc0262bccccacc0238fb:

10.3.23 811e4409ce587bc4b693cc0262bccccacc0238fb

 
10.3.23>SET @@global.wsrep_start_position='00000000-0000-0000-0000-000000000000:-2';
 
ERROR 2013 (HY000): Lost connection to MySQL server during query

Comment by Roel Van de Paar [ 2020-11-03 ]

Also see MDEV-22708 in connection with this bug.

Comment by Jan Lindström (Inactive) [ 2021-01-14 ]
  • 10.2.37 and Galera 25.3.32 

    MariaDB Version 10.2.37-MariaDB-debug
    		 
     - SSL connections supported
    		 
     - binaries are debug compiled
    		 
     - binaries built with wsrep patch
    		 
    Collecting tests...
    		 
    Installing system database...
    		 
     
    		 
    ==============================================================================
    		 
     
    		 
    TEST                                      RESULT   TIME (ms) or COMMENT
    		 
    --------------------------------------------------------------------------
    		 
     
    		 
    worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
    		 
    SET @@global.wsrep_start_position='00000000-0000-0000-0000-000000000000:-2';
    		 
    galera.jan 'innodb'                      [ fail ]
    		 
            Test ended at 2021-01-14 09:38:25
    		 
     
    		 
    CURRENT_TEST: galera.jan
    		 
    mysqltest: At line 3: query 'SET @@global.wsrep_start_position='00000000-0000-0000-0000-000000000000:-2'' failed: 1231: Variable 'wsrep_start_position' can't be set to the value of '00000000-0000-0000-0000-000000000000:-2'

  • 10.3.28 and Galera 25.3.32 

    MariaDB Version 10.3.28-MariaDB-debug
    		 
     - SSL connections supported
    		 
     - binaries are debug compiled
    		 
     - binaries built with wsrep patch
    		 
    Collecting tests...
    		 
    Installing system database...
    		 
     
    		 
    ==============================================================================
    		 
     
    		 
    TEST                                      RESULT   TIME (ms) or COMMENT
    		 
    --------------------------------------------------------------------------
    		 
     
    		 
    worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
    		 
    SET @@global.wsrep_start_position='00000000-0000-0000-0000-000000000000:-2';
    		 
    galera.jan 'innodb'                      [ fail ]
    		 
            Test ended at 2021-01-14 09:44:41
    		 
     
    		 
    CURRENT_TEST: galera.jan
    		 
    mysqltest: At line 3: query 'SET @@global.wsrep_start_position='00000000-0000-0000-0000-000000000000:-2'' failed: 1231: Variable 'wsrep_start_position' can't be set to the value of '00000000-0000-0000-0000-000000000000:-2'

  • 10.4.18 and Galera 26.4.7 (crash) 

    MariaDB Version 10.4.18-MariaDB-debug
    		 
     - SSL connections supported
    		 
     - binaries are debug compiled
    		 
     - binaries built with wsrep patch
    		 
    Collecting tests...
    		 
    Installing system database...
    		 
     
    		 
    ==============================================================================
    		 
     
    		 
    TEST                                      RESULT   TIME (ms) or COMMENT
    		 
    --------------------------------------------------------------------------
    		 
     
    		 
    worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
    		 
    connection node_2;
    		 
    connection node_1;
    		 
    SET @@global.wsrep_start_position='00000000-0000-0000-0000-000000000000:-2';
    		 
    galera.jan 'innodb'                      [ fail ]
    		 
            Test ended at 2021-01-14 10:00:06
    		 
     
    		 
    CURRENT_TEST: galera.jan
    		 
    mysqltest: At line 3: query 'SET @@global.wsrep_start_position='00000000-0000-0000-0000-000000000000:-2'' failed: 2013: Lost connection to MySQL server during query

  • Stack trace 

    Thread 1 (Thread 0x7f05a3fff640 (LWP 1467049)):
    		 
    #0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:54
    		 
    #1  0x000056349c8c4be8 in my_write_core (sig=6) at /home/jan/mysql/10.4-bugs/mysys/stacktrace.c:386
    		 
    #2  0x000056349c00ece1 in handle_fatal_signal (sig=6) at /home/jan/mysql/10.4-bugs/sql/signal_handler.cc:343
    		 
    #3  <signal handler called>
    		 
    #4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:49
    		 
    #5  0x00007f05c6f7b864 in __GI_abort () at abort.c:79
    		 
    #6  0x00007f05c6f7b749 in __assert_fail_base (fmt=0x7f05c7107458 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x56349ce989e8 "state_ == s_joiner || state_ == s_initialized", file=0x56349ce98308 "/home/jan/mysql/10.4-bugs/wsrep-lib/src/server_state.cpp", line=702, function=<optimized out>) at assert.c:92
    		 
    #7  0x00007f05c6f8da96 in __GI___assert_fail (assertion=0x56349ce989e8 "state_ == s_joiner || state_ == s_initialized", file=0x56349ce98308 "/home/jan/mysql/10.4-bugs/wsrep-lib/src/server_state.cpp", line=702, function=0x56349ce989a0 "void wsrep::server_state::sst_received(wsrep::client_service&, int)") at assert.c:101
    		 
    #8  0x000056349c94509b in wsrep::server_state::sst_received (this=0x56349f481e40, cs=..., error=-2) at /home/jan/mysql/10.4-bugs/wsrep-lib/src/server_state.cpp:702
    		 
    #9  0x000056349bf20540 in wsrep_sst_complete (thd=0x7f0548000d90, rcode=-2) at /home/jan/mysql/10.4-bugs/sql/wsrep_sst.cc:315
    		 
    #10 0x000056349bf20680 in wsrep_sst_received (thd=0x7f0548000d90, uuid=..., seqno=-2, state=0x0, state_len=0) at /home/jan/mysql/10.4-bugs/sql/wsrep_sst.cc:374
    		 
    #11 0x000056349bf25ce6 in wsrep_set_local_position (thd=0x7f0548000d90, value=0x7f05480123c0 "00000000-0000-0000-0000-", '0' <repeats 12 times>, ":-2", length=39, sst=true) at /home/jan/mysql/10.4-bugs/sql/wsrep_var.cc:234
    		 
    #12 0x000056349bf25e07 in wsrep_start_position_check (self=0x56349d449c80 <Sys_wsrep_start_position>, thd=0x7f0548000d90, var=0x7f0548012370) at /home/jan/mysql/10.4-bugs/sql/wsrep_var.cc:262
    		 
    #13 0x000056349bb87298 in sys_var::check (this=0x56349d449c80 <Sys_wsrep_start_position>, thd=0x7f0548000d90, var=0x7f0548012370) at /home/jan/mysql/10.4-bugs/sql/set_var.cc:248
    		 
    #14 0x000056349bb88cf0 in set_var::check (this=0x7f0548012370, thd=0x7f0548000d90) at /home/jan/mysql/10.4-bugs/sql/set_var.cc:790
    		 
    #15 0x000056349bb88a0c in sql_set_variables (thd=0x7f0548000d90, var_list=0x7f0548005bd0, free=true) at /home/jan/mysql/10.4-bugs/sql/set_var.cc:733
    		 
    #16 0x000056349bcab419 in mysql_execute_command (thd=0x7f0548000d90) at /home/jan/mysql/10.4-bugs/sql/sql_parse.cc:4994
    		 
    #17 0x000056349bcb522b in mysql_parse (thd=0x7f0548000d90, rawbuf=0x7f0548012128 "SET @@global.wsrep_start_position='00000000-0000-0000-0000-", '0' <repeats 12 times>, ":-2'", length=75, parser_state=0x7f05a3ffe430, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4-bugs/sql/sql_parse.cc:7958
    		 
    #18 0x000056349bcb491d in wsrep_mysql_parse (thd=0x7f0548000d90, rawbuf=0x7f0548012128 "SET @@global.wsrep_start_position='00000000-0000-0000-0000-", '0' <repeats 12 times>, ":-2'", length=75, parser_state=0x7f05a3ffe430, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4-bugs/sql/sql_parse.cc:7762
    		 
    #19 0x000056349bca144e in dispatch_command (command=COM_QUERY, thd=0x7f0548000d90, packet=0x7f05480087b1 "SET @@global.wsrep_start_position='00000000-0000-0000-0000-", '0' <repeats 12 times>, ":-2'", packet_length=75, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4-bugs/sql/sql_parse.cc:1841
    		 
    #20 0x000056349bc9fdbb in do_command (thd=0x7f0548000d90) at /home/jan/mysql/10.4-bugs/sql/sql_parse.cc:1373
    		 
    #21 0x000056349be2f0ab in do_handle_one_connection (connect=0x56349f8ede20) at /home/jan/mysql/10.4-bugs/sql/sql_connect.cc:1412
    		 
    #22 0x000056349be2edf4 in handle_one_connection (arg=0x56349f8ede20) at /home/jan/mysql/10.4-bugs/sql/sql_connect.cc:1316
    		 
    #23 0x000056349c85080c in pfs_spawn_thread (arg=0x56349f985110) at /home/jan/mysql/10.4-bugs/storage/perfschema/pfs.cc:1869
    		 
    #24 0x00007f05c78c0590 in start_thread (arg=0x7f05a3fff640) at pthread_create.c:463
    		 
    #25 0x00007f05c706e223 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

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