Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-22708

Assertion `!mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()' failed in Delayed_insert::handle_inserts and in Diagnostics_area::set_eof_status

Details

    Description

      # mysqld options required for replay: --log-bin 
      USE test;
      SET GLOBAL wsrep_forced_binlog_format=1;
      CREATE TABLE t1(c INT PRIMARY KEY) ENGINE=MEMORY;
      INSERT DELAYED INTO t1 VALUES(),(),();
      SELECT SLEEP(1);
      

      Leads to:

      10.5.4 8569dac1ec9f6853a0b2f3ea9bcbda67644ead24

      mysqld: /test/10.5_dbg/sql/sql_insert.cc:3490: bool Delayed_insert::handle_inserts(): Assertion `!mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()' failed.
      

      10.5.4 8569dac1ec9f6853a0b2f3ea9bcbda67644ead24

      Core was generated by `/test/MD260520-mariadb-10.5.4-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 0x145b29e62700 (LWP 3548649))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
      #1  0x000055988acdfd7a in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
      #2  0x000055988a485385 in handle_fatal_signal (sig=6) at /test/10.5_dbg/sql/signal_handler.cc:330
      #3  <signal handler called>
      #4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
      #5  0x0000145b2863c801 in __GI_abort () at abort.c:79
      #6  0x0000145b2862c39a in __assert_fail_base (fmt=0x145b287b37d8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x55988ae56c98 "!mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()", file=file@entry=0x55988ae56988 "/test/10.5_dbg/sql/sql_insert.cc", line=line@entry=3490, function=function@entry=0x55988ae577a0 <Delayed_insert::handle_inserts()::__PRETTY_FUNCTION__> "bool Delayed_insert::handle_inserts()") at assert.c:92
      #7  0x0000145b2862c412 in __GI___assert_fail (assertion=assertion@entry=0x55988ae56c98 "!mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()", file=file@entry=0x55988ae56988 "/test/10.5_dbg/sql/sql_insert.cc", line=line@entry=3490, function=function@entry=0x55988ae577a0 <Delayed_insert::handle_inserts()::__PRETTY_FUNCTION__> "bool Delayed_insert::handle_inserts()") at assert.c:101
      #8  0x000055988a19d508 in Delayed_insert::handle_inserts (this=this@entry=0x145b074a6088) at /test/10.5_dbg/sql/sql_insert.cc:3489
      #9  0x000055988a19f1a2 in handle_delayed_insert (arg=arg@entry=0x145b074a6088) at /test/10.5_dbg/sql/sql_insert.cc:3282
      #10 0x000055988a78d14e in pfs_spawn_thread (arg=0x145b07428388) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
      #11 0x0000145b2931f6db in start_thread (arg=0x145b29e62700) at pthread_create.c:463
      #12 0x0000145b2871d88f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Bug confirmed present in:
      MariaDB: 10.2.33 (dbg), 10.3.24 (dbg), 10.4.14 (dbg), 10.5.4 (dbg)

      Bug confirmed not present in:
      MariaDB: 10.1.46 (dbg), 10.1.46 (opt), 10.2.33 (opt), 10.3.24 (opt), 10.4.14 (opt), 10.5.4 (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)

      Attachments

        Issue Links

          Activity

            Secondary testcase

            # mysqld options required for replay: --log-bin 
            USE test;
            CREATE TABLE t1 (str VARCHAR(255)) ENGINE=MyISAM;
            SET @@GLOBAL.wsrep_forced_binlog_format=STATEMENT;
            INSERT DELAYED INTO t1 VALUES('a');
            SELECT SLEEP(2);
            INSERT DELAYED INTO t1 VALUES('a');  # Server will likely crash here
            SELECT SLEEP(2);
            INSERT DELAYED INTO t1 VALUES('a');
            

            Roel Roel Van de Paar added a comment - Secondary testcase # mysqld options required for replay: --log-bin USE test; CREATE TABLE t1 (str VARCHAR(255)) ENGINE=MyISAM; SET @@GLOBAL.wsrep_forced_binlog_format=STATEMENT; INSERT DELAYED INTO t1 VALUES('a'); SELECT SLEEP(2); INSERT DELAYED INTO t1 VALUES('a'); # Server will likely crash here SELECT SLEEP(2); INSERT DELAYED INTO t1 VALUES('a');
            Roel Roel Van de Paar added a comment - - edited

            In close connection with MDEV-22422, the following testcase produces the same assertion provided the server is started with --log-bin, otherwise it produces the crash of MDEV-22422. Both on the same statement.

            # mysqld options required for replay: --log-bin
            SET SQL_MODE='';
            SET GLOBAL wsrep_forced_binlog_format='STATEMENT';
            HELP '%a';
            CREATE TABLE t (c CHAR(8) NOT NULL) ENGINE=MEMORY;
            SET max_session_mem_used = 50000;
            REPLACE DELAYED t VALUES (5);
            HELP 'a%';
            

            Leads to:

            10.6.0 5d4599f9750140f92cfdbbe4d292ae1b8dd456f8 (Debug)

            mysqld: /test/10.6_dbg/sql/sql_insert.cc:3491: bool Delayed_insert::handle_inserts(): Assertion `!mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()' failed.
            

            10.6.0 5d4599f9750140f92cfdbbe4d292ae1b8dd456f8 (Debug)

            Core was generated by `/test/MD211020-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
            Program terminated with signal SIGABRT, Aborted.
            #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
            [Current thread is 1 (Thread 0x1480dc0ff700 (LWP 2385962))]
            (gdb) bt
            #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
            #1  0x00001480f2de0859 in __GI_abort () at abort.c:79
            #2  0x00001480f2de0729 in __assert_fail_base (fmt=0x1480f2f76588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x564086252b69 "! is_set()", file=0x564086252638 "/test/10.6_dbg/sql/sql_error.cc", line=374, function=<optimized out>) at assert.c:92
            #3  0x00001480f2df1f36 in __GI___assert_fail (assertion=assertion@entry=0x564086252b69 "! is_set()", file=file@entry=0x564086252638 "/test/10.6_dbg/sql/sql_error.cc", line=line@entry=374, function=function@entry=0x5640862527d8 "void Diagnostics_area::set_eof_status(THD*)") at assert.c:101
            #4  0x000056408551bce1 in Diagnostics_area::set_eof_status (this=0x1480a0006a30, thd=thd@entry=0x1480a0000db8) at /test/10.6_dbg/sql/sql_error.h:1005
            #5  0x0000564085a39cb1 in my_eof (thd=0x1480a0000db8) at /test/10.6_dbg/sql/sql_class.h:5238
            #6  mysqld_help_internal (thd=thd@entry=0x1480a0000db8, mask=<optimized out>) at /test/10.6_dbg/sql/sql_help.cc:845
            #7  0x0000564085a3aac1 in mysqld_help (thd=thd@entry=0x1480a0000db8, mask=<optimized out>) at /test/10.6_dbg/sql/sql_help.cc:863
            #8  0x0000564085576c29 in mysql_execute_command (thd=thd@entry=0x1480a0000db8) at /test/10.6_dbg/sql/sql_parse.cc:3821
            #9  0x0000564085562fd2 in mysql_parse (thd=thd@entry=0x1480a0000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1480dc0fe3d0) at /test/10.6_dbg/sql/sql_parse.cc:7833
            #10 0x00005640855710c7 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1480a0000db8, packet=packet@entry=0x1480a0008e09 "", packet_length=packet_length@entry=9) at /test/10.6_dbg/sql/sql_class.h:1253
            #11 0x00005640855743d2 in do_command (thd=0x1480a0000db8) at /test/10.6_dbg/sql/sql_parse.cc:1343
            #12 0x00005640856ce994 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5640896b2d38, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
            #13 0x00005640856cf09b in handle_one_connection (arg=arg@entry=0x5640896b2d38) at /test/10.6_dbg/sql/sql_connect.cc:1312
            #14 0x0000564085b82abb in pfs_spawn_thread (arg=0x564089617768) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
            #15 0x00001480f32ee609 in start_thread (arg=<optimized out>) at pthread_create.c:477
            #16 0x00001480f2edd293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
            

            Bug confirmed present in:
            MariaDB: 10.1.48 (dbg), 10.2.35 (dbg), 10.3.26 (dbg), 10.4.16 (dbg), 10.5.7 (dbg), 10.6.0 (dbg)

            Bug confirmed not present in:
            MariaDB: 10.1.48 (opt), 10.2.35 (opt), 10.3.26 (opt), 10.4.16 (opt), 10.5.7 (opt), 10.6.0 (opt)
            MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.50 (dbg), 5.6.50 (opt), 5.7.32 (dbg), 5.7.32 (opt), 8.0.22 (dbg), 8.0.22 (opt)

            The stack is slightly different. Unique ID's seen thus far:

            !mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()|SIGABRT|Delayed_insert::handle_inserts|handle_delayed_insert|pfs_spawn_thread|start_thread
            !mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()|SIGABRT|Diagnostics_area::set_eof_status|my_eof|mysqld_help_internal|mysqld_help
            !mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()|SIGABRT|trx_rseg_update_wsrep_checkpoint|trx_rseg_update_wsrep_checkpoint|trx_rseg_update_wsrep_checkpoint|innobase_wsrep_set_checkpoint
            

            Roel Roel Van de Paar added a comment - - edited In close connection with MDEV-22422 , the following testcase produces the same assertion provided the server is started with --log-bin, otherwise it produces the crash of MDEV-22422 . Both on the same statement. # mysqld options required for replay: --log-bin SET SQL_MODE=''; SET GLOBAL wsrep_forced_binlog_format='STATEMENT'; HELP '%a'; CREATE TABLE t (c CHAR(8) NOT NULL) ENGINE=MEMORY; SET max_session_mem_used = 50000; REPLACE DELAYED t VALUES (5); HELP 'a%'; Leads to: 10.6.0 5d4599f9750140f92cfdbbe4d292ae1b8dd456f8 (Debug) mysqld: /test/10.6_dbg/sql/sql_insert.cc:3491: bool Delayed_insert::handle_inserts(): Assertion `!mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()' failed. 10.6.0 5d4599f9750140f92cfdbbe4d292ae1b8dd456f8 (Debug) Core was generated by `/test/MD211020-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'. Program terminated with signal SIGABRT, Aborted. #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 [Current thread is 1 (Thread 0x1480dc0ff700 (LWP 2385962))] (gdb) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 #1 0x00001480f2de0859 in __GI_abort () at abort.c:79 #2 0x00001480f2de0729 in __assert_fail_base (fmt=0x1480f2f76588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x564086252b69 "! is_set()", file=0x564086252638 "/test/10.6_dbg/sql/sql_error.cc", line=374, function=<optimized out>) at assert.c:92 #3 0x00001480f2df1f36 in __GI___assert_fail (assertion=assertion@entry=0x564086252b69 "! is_set()", file=file@entry=0x564086252638 "/test/10.6_dbg/sql/sql_error.cc", line=line@entry=374, function=function@entry=0x5640862527d8 "void Diagnostics_area::set_eof_status(THD*)") at assert.c:101 #4 0x000056408551bce1 in Diagnostics_area::set_eof_status (this=0x1480a0006a30, thd=thd@entry=0x1480a0000db8) at /test/10.6_dbg/sql/sql_error.h:1005 #5 0x0000564085a39cb1 in my_eof (thd=0x1480a0000db8) at /test/10.6_dbg/sql/sql_class.h:5238 #6 mysqld_help_internal (thd=thd@entry=0x1480a0000db8, mask=<optimized out>) at /test/10.6_dbg/sql/sql_help.cc:845 #7 0x0000564085a3aac1 in mysqld_help (thd=thd@entry=0x1480a0000db8, mask=<optimized out>) at /test/10.6_dbg/sql/sql_help.cc:863 #8 0x0000564085576c29 in mysql_execute_command (thd=thd@entry=0x1480a0000db8) at /test/10.6_dbg/sql/sql_parse.cc:3821 #9 0x0000564085562fd2 in mysql_parse (thd=thd@entry=0x1480a0000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1480dc0fe3d0) at /test/10.6_dbg/sql/sql_parse.cc:7833 #10 0x00005640855710c7 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1480a0000db8, packet=packet@entry=0x1480a0008e09 "", packet_length=packet_length@entry=9) at /test/10.6_dbg/sql/sql_class.h:1253 #11 0x00005640855743d2 in do_command (thd=0x1480a0000db8) at /test/10.6_dbg/sql/sql_parse.cc:1343 #12 0x00005640856ce994 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5640896b2d38, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410 #13 0x00005640856cf09b in handle_one_connection (arg=arg@entry=0x5640896b2d38) at /test/10.6_dbg/sql/sql_connect.cc:1312 #14 0x0000564085b82abb in pfs_spawn_thread (arg=0x564089617768) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201 #15 0x00001480f32ee609 in start_thread (arg=<optimized out>) at pthread_create.c:477 #16 0x00001480f2edd293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 Bug confirmed present in: MariaDB: 10.1.48 (dbg), 10.2.35 (dbg), 10.3.26 (dbg), 10.4.16 (dbg), 10.5.7 (dbg), 10.6.0 (dbg) Bug confirmed not present in: MariaDB: 10.1.48 (opt), 10.2.35 (opt), 10.3.26 (opt), 10.4.16 (opt), 10.5.7 (opt), 10.6.0 (opt) MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.50 (dbg), 5.6.50 (opt), 5.7.32 (dbg), 5.7.32 (opt), 8.0.22 (dbg), 8.0.22 (opt) The stack is slightly different. Unique ID's seen thus far: !mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()|SIGABRT|Delayed_insert::handle_inserts|handle_delayed_insert|pfs_spawn_thread|start_thread !mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()|SIGABRT|Diagnostics_area::set_eof_status|my_eof|mysqld_help_internal|mysqld_help !mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()|SIGABRT|trx_rseg_update_wsrep_checkpoint|trx_rseg_update_wsrep_checkpoint|trx_rseg_update_wsrep_checkpoint|innobase_wsrep_set_checkpoint
            Roel Roel Van de Paar added a comment - - edited

            Another such occurrence. In connection with MDEV-22285 this time, the following testcase produces the same assertion, provided the server is started with --log-bin, otherwise it produces the crash of MDEV-22285. Both on the same statement.

            # mysqld options required for replay: --log-bin 
            SET SQL_MODE='';
            CREATE TABLE t (c INT) ENGINE=MEMORY;
            SET GLOBAL wsrep_forced_binlog_format='STATEMENT';
            INSERT DELAYED INTO t VALUES(1);
            SET GLOBAL wsrep_start_position='00000000-0000-0000-0000-000000000000:-2';
            

            Leads to:

            10.6.0 5d4599f9750140f92cfdbbe4d292ae1b8dd456f8 (Debug)

            mysqld: /test/10.6_dbg/sql/sql_insert.cc:3491: bool Delayed_insert::handle_inserts(): Assertion `!mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()' failed.
            

            10.6.0 5d4599f9750140f92cfdbbe4d292ae1b8dd456f8 (Debug)

            Core was generated by `/test/MD211020-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
            Program terminated with signal SIGABRT, Aborted.
            #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
            [Current thread is 1 (Thread 0x1513b45f8700 (LWP 1271953))]
            (gdb) bt
            #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
            #1  0x00001513b7205859 in __GI_abort () at abort.c:79
            #2  0x00001513b7205729 in __assert_fail_base (fmt=0x1513b739b588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55e434be0898 "xid_seqno > wsrep_seqno", file=0x55e434be0a40 "/test/10.6_dbg/storage/innobase/trx/trx0rseg.cc", line=108, function=<optimized out>) at assert.c:92
            #3  0x00001513b7216f36 in __GI___assert_fail (assertion=assertion@entry=0x55e434be0898 "xid_seqno > wsrep_seqno", file=file@entry=0x55e434be0a40 "/test/10.6_dbg/storage/innobase/trx/trx0rseg.cc", line=line@entry=108, function=function@entry=0x55e434be0d80 "void trx_rseg_update_wsrep_checkpoint(buf_block_t*, const XID*, mtr_t*)") at assert.c:101
            #4  0x000055e43456f85d in trx_rseg_update_wsrep_checkpoint (rseg_header=rseg_header@entry=0x151394000a10, xid=xid@entry=0x1513b45f6680, mtr=mtr@entry=0x1513b45f5ff0) at /test/10.6_dbg/storage/innobase/trx/trx0rseg.cc:108
            #5  0x000055e4345706ed in trx_rseg_update_wsrep_checkpoint (xid=xid@entry=0x1513b45f6680, mtr=mtr@entry=0x1513b45f5ff0) at /test/10.6_dbg/storage/innobase/trx/trx0rseg.cc:146
            #6  0x000055e4345719ad in trx_rseg_update_wsrep_checkpoint (xid=xid@entry=0x1513b45f6680) at /test/10.6_dbg/storage/innobase/trx/trx0rseg.cc:176
            #7  0x000055e434308295 in innobase_wsrep_set_checkpoint (hton=0x55e436645958, xid=0x1513b45f6680) at /test/10.6_dbg/storage/innobase/handler/ha_innodb.cc:18526
            #8  0x000055e4342d1b54 in set_SE_checkpoint (unused=unused@entry=0x0, plugin=<optimized out>, arg=arg@entry=0x1513b45f6680) at /test/10.6_dbg/sql/wsrep_xid.cc:127
            #9  0x000055e433c651d7 in plugin_foreach_with_mask (thd=thd@entry=0x0, func=func@entry=0x55e4342d1ac5 <set_SE_checkpoint(THD*, plugin_ref, void*)>, type=type@entry=1, state_mask=state_mask@entry=8, arg=arg@entry=0x1513b45f6680) at /test/10.6_dbg/sql/sql_plugin.cc:2505
            #10 0x000055e4342d1c9d in wsrep_set_SE_checkpoint (xid=@0x1513b45f6680: {formatID = 1, gtrid_length = 48, bqual_length = 0, data = "WSREPXif", '\000' <repeats 16 times>, "\376\377\377\377\377\377\377\377", '\000' <repeats 95 times>}) at /test/10.6_dbg/sql/wsrep_xid.cc:134
            #11 0x000055e4342d1cdd in wsrep_set_SE_checkpoint (wsgtid=@0x1513b45f6750: {static undefined_ = {static undefined_ = <same as static member of an already seen type>, id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = '\000' <repeats 15 times>}}, seqno_ = {seqno_ = -1}}, id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = '\000' <repeats 15 times>}}, seqno_ = {seqno_ = -2}}, gtid=@0x1513b45f6740: {domain_id = 0, server_id = 0, seqno = 0}) at /test/10.6_dbg/sql/wsrep_xid.cc:142
            #12 0x000055e4342e14e4 in wsrep_sst_received (thd=thd@entry=0x151360000db8, uuid=@0x1513b45f67c0: {data = '\000' <repeats 15 times>, alignment = 0}, seqno=seqno@entry=-2, state=state@entry=0x0, state_len=state_len@entry=0) at /test/10.6_dbg/sql/wsrep_mysqld.h:421
            #13 0x000055e4342e4b47 in wsrep_set_local_position (thd=thd@entry=0x151360000db8, value=<optimized out>, length=<optimized out>, sst=sst@entry=true) at /test/10.6_dbg/sql/wsrep_var.cc:257
            #14 0x000055e4342e5043 in wsrep_start_position_check (self=<optimized out>, thd=0x151360000db8, var=0x151360012990) at /test/10.6_dbg/sql/wsrep_var.cc:285
            #15 0x000055e433b5777c in sys_var::check (this=0x55e435289ac0 <Sys_wsrep_start_position>, thd=thd@entry=0x151360000db8, var=var@entry=0x151360012990) at /test/10.6_dbg/sql/set_var.cc:246
            #16 0x000055e433b587e7 in set_var::check (this=0x151360012990, thd=0x151360000db8) at /test/10.6_dbg/sql/set_var.cc:811
            #17 0x000055e433b58f2b in sql_set_variables (thd=thd@entry=0x151360000db8, var_list=var_list@entry=0x151360005e50, free=free@entry=true) at /test/10.6_dbg/sql/set_var.cc:739
            #18 0x000055e433c5ba96 in mysql_execute_command (thd=thd@entry=0x151360000db8) at /test/10.6_dbg/sql/sql_parse.cc:4861
            #19 0x000055e433c44fd2 in mysql_parse (thd=thd@entry=0x151360000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1513b45f73d0) at /test/10.6_dbg/sql/sql_parse.cc:7833
            #20 0x000055e433c530c7 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x151360000db8, packet=packet@entry=0x151360008e09 "SET GLOBAL wsrep_start_position='00000000-0000-0000-0000-", '0' <repeats 12 times>, ":-2'", packet_length=packet_length@entry=73) at /test/10.6_dbg/sql/sql_class.h:1253
            #21 0x000055e433c563d2 in do_command (thd=0x151360000db8) at /test/10.6_dbg/sql/sql_parse.cc:1343
            #22 0x000055e433db0994 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55e43711a2b8, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410
            #23 0x000055e433db109b in handle_one_connection (arg=arg@entry=0x55e43711a2b8) at /test/10.6_dbg/sql/sql_connect.cc:1312
            #24 0x000055e434264abb in pfs_spawn_thread (arg=0x55e437095e78) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201
            #25 0x00001513b7713609 in start_thread (arg=<optimized out>) at pthread_create.c:477
            #26 0x00001513b7302293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
            

            Bug confirmed present in:
            MariaDB: 10.1.48 (dbg), 10.2.35 (dbg), 10.3.26 (dbg), 10.4.16 (dbg), 10.5.7 (dbg), 10.6.0 (dbg)

            Bug confirmed not present in:
            MariaDB: 10.1.48 (opt), 10.2.35 (opt), 10.3.26 (opt), 10.4.16 (opt), 10.5.7 (opt), 10.6.0 (opt)
            MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.50 (dbg), 5.6.50 (opt), 5.7.32 (dbg), 5.7.32 (opt), 8.0.22 (dbg), 8.0.22 (opt)

            Raised to critical as this is now cross-affecting bugs and testing.

            Roel Roel Van de Paar added a comment - - edited Another such occurrence. In connection with MDEV-22285 this time, the following testcase produces the same assertion, provided the server is started with --log-bin, otherwise it produces the crash of MDEV-22285 . Both on the same statement. # mysqld options required for replay: --log-bin SET SQL_MODE=''; CREATE TABLE t (c INT) ENGINE=MEMORY; SET GLOBAL wsrep_forced_binlog_format='STATEMENT'; INSERT DELAYED INTO t VALUES(1); SET GLOBAL wsrep_start_position='00000000-0000-0000-0000-000000000000:-2'; Leads to: 10.6.0 5d4599f9750140f92cfdbbe4d292ae1b8dd456f8 (Debug) mysqld: /test/10.6_dbg/sql/sql_insert.cc:3491: bool Delayed_insert::handle_inserts(): Assertion `!mysql_bin_log.is_open() || thd.is_current_stmt_binlog_format_row()' failed. 10.6.0 5d4599f9750140f92cfdbbe4d292ae1b8dd456f8 (Debug) Core was generated by `/test/MD211020-mariadb-10.6.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'. Program terminated with signal SIGABRT, Aborted. #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 [Current thread is 1 (Thread 0x1513b45f8700 (LWP 1271953))] (gdb) bt #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50 #1 0x00001513b7205859 in __GI_abort () at abort.c:79 #2 0x00001513b7205729 in __assert_fail_base (fmt=0x1513b739b588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55e434be0898 "xid_seqno > wsrep_seqno", file=0x55e434be0a40 "/test/10.6_dbg/storage/innobase/trx/trx0rseg.cc", line=108, function=<optimized out>) at assert.c:92 #3 0x00001513b7216f36 in __GI___assert_fail (assertion=assertion@entry=0x55e434be0898 "xid_seqno > wsrep_seqno", file=file@entry=0x55e434be0a40 "/test/10.6_dbg/storage/innobase/trx/trx0rseg.cc", line=line@entry=108, function=function@entry=0x55e434be0d80 "void trx_rseg_update_wsrep_checkpoint(buf_block_t*, const XID*, mtr_t*)") at assert.c:101 #4 0x000055e43456f85d in trx_rseg_update_wsrep_checkpoint (rseg_header=rseg_header@entry=0x151394000a10, xid=xid@entry=0x1513b45f6680, mtr=mtr@entry=0x1513b45f5ff0) at /test/10.6_dbg/storage/innobase/trx/trx0rseg.cc:108 #5 0x000055e4345706ed in trx_rseg_update_wsrep_checkpoint (xid=xid@entry=0x1513b45f6680, mtr=mtr@entry=0x1513b45f5ff0) at /test/10.6_dbg/storage/innobase/trx/trx0rseg.cc:146 #6 0x000055e4345719ad in trx_rseg_update_wsrep_checkpoint (xid=xid@entry=0x1513b45f6680) at /test/10.6_dbg/storage/innobase/trx/trx0rseg.cc:176 #7 0x000055e434308295 in innobase_wsrep_set_checkpoint (hton=0x55e436645958, xid=0x1513b45f6680) at /test/10.6_dbg/storage/innobase/handler/ha_innodb.cc:18526 #8 0x000055e4342d1b54 in set_SE_checkpoint (unused=unused@entry=0x0, plugin=<optimized out>, arg=arg@entry=0x1513b45f6680) at /test/10.6_dbg/sql/wsrep_xid.cc:127 #9 0x000055e433c651d7 in plugin_foreach_with_mask (thd=thd@entry=0x0, func=func@entry=0x55e4342d1ac5 <set_SE_checkpoint(THD*, plugin_ref, void*)>, type=type@entry=1, state_mask=state_mask@entry=8, arg=arg@entry=0x1513b45f6680) at /test/10.6_dbg/sql/sql_plugin.cc:2505 #10 0x000055e4342d1c9d in wsrep_set_SE_checkpoint (xid=@0x1513b45f6680: {formatID = 1, gtrid_length = 48, bqual_length = 0, data = "WSREPXif", '\000' <repeats 16 times>, "\376\377\377\377\377\377\377\377", '\000' <repeats 95 times>}) at /test/10.6_dbg/sql/wsrep_xid.cc:134 #11 0x000055e4342d1cdd in wsrep_set_SE_checkpoint (wsgtid=@0x1513b45f6750: {static undefined_ = {static undefined_ = <same as static member of an already seen type>, id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = '\000' <repeats 15 times>}}, seqno_ = {seqno_ = -1}}, id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = '\000' <repeats 15 times>}}, seqno_ = {seqno_ = -2}}, gtid=@0x1513b45f6740: {domain_id = 0, server_id = 0, seqno = 0}) at /test/10.6_dbg/sql/wsrep_xid.cc:142 #12 0x000055e4342e14e4 in wsrep_sst_received (thd=thd@entry=0x151360000db8, uuid=@0x1513b45f67c0: {data = '\000' <repeats 15 times>, alignment = 0}, seqno=seqno@entry=-2, state=state@entry=0x0, state_len=state_len@entry=0) at /test/10.6_dbg/sql/wsrep_mysqld.h:421 #13 0x000055e4342e4b47 in wsrep_set_local_position (thd=thd@entry=0x151360000db8, value=<optimized out>, length=<optimized out>, sst=sst@entry=true) at /test/10.6_dbg/sql/wsrep_var.cc:257 #14 0x000055e4342e5043 in wsrep_start_position_check (self=<optimized out>, thd=0x151360000db8, var=0x151360012990) at /test/10.6_dbg/sql/wsrep_var.cc:285 #15 0x000055e433b5777c in sys_var::check (this=0x55e435289ac0 <Sys_wsrep_start_position>, thd=thd@entry=0x151360000db8, var=var@entry=0x151360012990) at /test/10.6_dbg/sql/set_var.cc:246 #16 0x000055e433b587e7 in set_var::check (this=0x151360012990, thd=0x151360000db8) at /test/10.6_dbg/sql/set_var.cc:811 #17 0x000055e433b58f2b in sql_set_variables (thd=thd@entry=0x151360000db8, var_list=var_list@entry=0x151360005e50, free=free@entry=true) at /test/10.6_dbg/sql/set_var.cc:739 #18 0x000055e433c5ba96 in mysql_execute_command (thd=thd@entry=0x151360000db8) at /test/10.6_dbg/sql/sql_parse.cc:4861 #19 0x000055e433c44fd2 in mysql_parse (thd=thd@entry=0x151360000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1513b45f73d0) at /test/10.6_dbg/sql/sql_parse.cc:7833 #20 0x000055e433c530c7 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x151360000db8, packet=packet@entry=0x151360008e09 "SET GLOBAL wsrep_start_position='00000000-0000-0000-0000-", '0' <repeats 12 times>, ":-2'", packet_length=packet_length@entry=73) at /test/10.6_dbg/sql/sql_class.h:1253 #21 0x000055e433c563d2 in do_command (thd=0x151360000db8) at /test/10.6_dbg/sql/sql_parse.cc:1343 #22 0x000055e433db0994 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55e43711a2b8, put_in_cache=put_in_cache@entry=true) at /test/10.6_dbg/sql/sql_connect.cc:1410 #23 0x000055e433db109b in handle_one_connection (arg=arg@entry=0x55e43711a2b8) at /test/10.6_dbg/sql/sql_connect.cc:1312 #24 0x000055e434264abb in pfs_spawn_thread (arg=0x55e437095e78) at /test/10.6_dbg/storage/perfschema/pfs.cc:2201 #25 0x00001513b7713609 in start_thread (arg=<optimized out>) at pthread_create.c:477 #26 0x00001513b7302293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 Bug confirmed present in: MariaDB: 10.1.48 (dbg), 10.2.35 (dbg), 10.3.26 (dbg), 10.4.16 (dbg), 10.5.7 (dbg), 10.6.0 (dbg) Bug confirmed not present in: MariaDB: 10.1.48 (opt), 10.2.35 (opt), 10.3.26 (opt), 10.4.16 (opt), 10.5.7 (opt), 10.6.0 (opt) MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.50 (dbg), 5.6.50 (opt), 5.7.32 (dbg), 5.7.32 (opt), 8.0.22 (dbg), 8.0.22 (opt) Raised to critical as this is now cross-affecting bugs and testing.

            mkaruza, this seems to have broken the test binlog.binlog_unsafe. Here is an excerpt from a debug builder:

            10.4 86a2e2ba9051888d457b6a5d0b4fb2879e24beb5

            binlog.binlog_unsafe 'stmt'              w1 [ fail ]
                    Test ended at 2021-10-04 06:31:07
             
            CURRENT_TEST: binlog.binlog_unsafe
            mysqltest: At line 351: Wrong events in binlog.
            

            marko Marko Mäkelä added a comment - mkaruza , this seems to have broken the test binlog.binlog_unsafe . Here is an excerpt from a debug builder : 10.4 86a2e2ba9051888d457b6a5d0b4fb2879e24beb5 binlog.binlog_unsafe 'stmt' w1 [ fail ] Test ended at 2021-10-04 06:31:07   CURRENT_TEST: binlog.binlog_unsafe mysqltest: At line 351: Wrong events in binlog.

            People

              jplindst Jan Lindström (Inactive)
              Roel Roel Van de Paar
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

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