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

Assertion `thd->transaction->stmt.is_empty() || thd->in_sub_stmt' failed in mysql_execute_command (from mysql_parse) and in trans_check

    XMLWordPrintable

Details

    Description

      The following testcase, when repeated:

      # Repeat 3+ times
      CREATE OR REPLACE TABLE mysql.slow_log (a INT);
      DROP EVENT one_event;
      CREATE EVENT one_event ON SCHEDULE EVERY 10 SECOND DO SELECT 123;
      SET GLOBAL slow_query_log=ON;
      SET GLOBAL event_scheduler= 1;
      SET GLOBAL log_output=',TABLE';
      SET GLOBAL long_query_time=0.001;
      SELECT SLEEP (3);
      

      Leads to:

      10.6.0 3f871b339429441ad907ecf7dfabdc414797e664 (Debug)

      mysqld: /data/builds/10.6_dbg/sql/sql_parse.cc:3250: int mysql_execute_command(THD*): Assertion `thd->transaction->stmt.is_empty() || thd->in_sub_stmt' failed.
      

      10.6.0 3f871b339429441ad907ecf7dfabdc414797e664 (Debug)

      Core was generated by `/test/MD260121-mariadb-10.6.0-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:56
      [Current thread is 1 (Thread 0x1490e811c700 (LWP 4114450))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      #1  0x0000563c9a539210 in my_write_core (sig=sig@entry=6) at /data/builds/10.6_dbg/mysys/stacktrace.c:424
      #2  0x0000563c99cce2d0 in handle_fatal_signal (sig=6) at /data/builds/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  0x00001490ea4d7859 in __GI_abort () at abort.c:79
      #6  0x00001490ea4d7729 in __assert_fail_base (fmt=0x1490ea66d588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x563c9a6aab70 "thd->transaction->stmt.is_empty() || thd->in_sub_stmt", file=0x563c9a6a72b8 "/data/builds/10.6_dbg/sql/sql_parse.cc", line=3250, function=<optimized out>) at assert.c:92
      #7  0x00001490ea4e8f36 in __GI___assert_fail (assertion=assertion@entry=0x563c9a6aab70 "thd->transaction->stmt.is_empty() || thd->in_sub_stmt", file=file@entry=0x563c9a6a72b8 "/data/builds/10.6_dbg/sql/sql_parse.cc", line=line@entry=3250, function=function@entry=0x563c9a6aaaf8 "int mysql_execute_command(THD*)") at assert.c:101
      #8  0x0000563c99a08117 in mysql_execute_command (thd=thd@entry=0x149098000db8) at /data/builds/10.6_dbg/sql/handler.h:1844
      #9  0x0000563c999f615e in mysql_parse (thd=thd@entry=0x149098000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1490e811b3d0) at /data/builds/10.6_dbg/sql/sql_parse.cc:7901
      #10 0x0000563c99a0424f in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x149098000db8, packet=packet@entry=0x14909801aac9 "CREATE EVENT one_event ON SCHEDULE EVERY 10 SECOND DO SELECT 123", packet_length=packet_length@entry=64) at /data/builds/10.6_dbg/sql/sql_class.h:1294
      #11 0x0000563c99a07581 in do_command (thd=0x149098000db8) at /data/builds/10.6_dbg/sql/sql_parse.cc:1365
      #12 0x0000563c99b63079 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x563c9c7170d8, put_in_cache=put_in_cache@entry=true) at /data/builds/10.6_dbg/sql/sql_connect.cc:1410
      #13 0x0000563c99b6377d in handle_one_connection (arg=arg@entry=0x563c9c7170d8) at /data/builds/10.6_dbg/sql/sql_connect.cc:1312
      #14 0x0000563c9a01643f in pfs_spawn_thread (arg=0x563c9c64b2a8) at /data/builds/10.6_dbg/storage/perfschema/pfs.cc:2201
      #15 0x00001490ea9e5609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #16 0x00001490ea5d4293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      However, if you remove the second line (DROP EVENT), and repeat it a few times, you may see:

      10.6.0 3f871b339429441ad907ecf7dfabdc414797e664 (Debug)

      mysqld: /data/builds/10.6_dbg/sql/transaction.cc:79: bool trans_check(THD*): Assertion `thd->transaction->stmt.is_empty()' failed.
      

      10.6.0 3f871b339429441ad907ecf7dfabdc414797e664 (Debug)

      Core was generated by `/test/MD260121-mariadb-10.6.0-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:56
      [Current thread is 1 (Thread 0x1495740b4700 (LWP 9775))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      #1  0x000055cafdb0e210 in my_write_core (sig=sig@entry=6) at /data/builds/10.6_dbg/mysys/stacktrace.c:424
      #2  0x000055cafd2a32d0 in handle_fatal_signal (sig=6) at /data/builds/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  0x000014957e71a859 in __GI_abort () at abort.c:79
      #6  0x000014957e71a729 in __assert_fail_base (fmt=0x14957e8b0588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55cafdc6b998 "thd->transaction->stmt.is_empty()", file=0x55cafdcae148 "/data/builds/10.6_dbg/sql/transaction.cc", line=79, function=<optimized out>) at assert.c:92
      #7  0x000014957e72bf36 in __GI___assert_fail (assertion=assertion@entry=0x55cafdc6b998 "thd->transaction->stmt.is_empty()", file=file@entry=0x55cafdcae148 "/data/builds/10.6_dbg/sql/transaction.cc", line=line@entry=79, function=function@entry=0x55cafdcae69b "bool trans_check(THD*)") at assert.c:101
      #8  0x000055cafd14d29b in trans_check (thd=thd@entry=0x149528000db8) at /data/builds/10.6_dbg/sql/handler.h:1844
      #9  0x000055cafd14debc in trans_rollback (thd=thd@entry=0x149528000db8) at /data/builds/10.6_dbg/sql/transaction.cc:366
      #10 0x000055cafcf69c78 in THD::cleanup (this=this@entry=0x149528000db8, have_mutex=have_mutex@entry=false) at /data/builds/10.6_dbg/sql/sql_class.cc:1570
      #11 0x000055cafcec09a2 in unlink_thd (thd=0x149528000db8) at /data/builds/10.6_dbg/sql/mysqld.cc:2601
      #12 0x000055cafd1385a5 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55cb0004f118, put_in_cache=put_in_cache@entry=true) at /data/builds/10.6_dbg/sql/sql_connect.cc:1421
      #13 0x000055cafd13877d in handle_one_connection (arg=arg@entry=0x55cb0004f118) at /data/builds/10.6_dbg/sql/sql_connect.cc:1312
      #14 0x000055cafd5eb43f in pfs_spawn_thread (arg=0x55cafff83158) at /data/builds/10.6_dbg/storage/perfschema/pfs.cc:2201
      #15 0x000014957ec28609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #16 0x000014957e817293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Shutting down the server after a few testcases attempts where the server did not crash yet may also lead to the above result.

      {noformat:title=10.5.9 927a882341eb1087e71d64de4e8cd89ab520de89 (Debug)}
      mysqld: /data/builds/10.5_dbg/sql/sql_parse.cc:3398: int mysql_execute_command(THD*): Assertion `thd->transaction->stmt.is_empty() || thd->in_sub_stmt' failed.
      

      10.5.9 927a882341eb1087e71d64de4e8cd89ab520de89 (Debug)

      Core was generated by `/test/MD260121-mariadb-10.5.9-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:56
      [Current thread is 1 (Thread 0x147d18081700 (LWP 240587))]
      (gdb) bt
      #0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      #1  0x00005589d4a8f64e in my_write_core (sig=sig@entry=6) at /data/builds/10.5_dbg/mysys/stacktrace.c:424
      #2  0x00005589d41e41a8 in handle_fatal_signal (sig=6) at /data/builds/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:50
      #5  0x0000147d192e4859 in __GI_abort () at abort.c:79
      #6  0x0000147d192e4729 in __assert_fail_base (fmt=0x147d1947a588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5589d4c017d8 "thd->transaction->stmt.is_empty() || thd->in_sub_stmt", file=0x5589d4bfdef8 "/data/builds/10.5_dbg/sql/sql_parse.cc", line=3398, function=<optimized out>) at assert.c:92
      #7  0x0000147d192f5f36 in __GI___assert_fail (assertion=assertion@entry=0x5589d4c017d8 "thd->transaction->stmt.is_empty() || thd->in_sub_stmt", file=file@entry=0x5589d4bfdef8 "/data/builds/10.5_dbg/sql/sql_parse.cc", line=line@entry=3398, function=function@entry=0x5589d4c01760 "int mysql_execute_command(THD*)") at assert.c:101
      #8  0x00005589d3f1decc in mysql_execute_command (thd=thd@entry=0x147cc0000db8) at /data/builds/10.5_dbg/sql/handler.h:1844
      #9  0x00005589d3f0b8d8 in mysql_parse (thd=thd@entry=0x147cc0000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x147d180803d0, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/builds/10.5_dbg/sql/sql_parse.cc:8062
      #10 0x00005589d3f19be2 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x147cc0000db8, packet=packet@entry=0x147cc001ad29 "CREATE EVENT one_event ON SCHEDULE EVERY 10 SECOND DO SELECT 123", packet_length=packet_length@entry=64, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/builds/10.5_dbg/sql/sql_class.h:1256
      #11 0x00005589d3f1d32f in do_command (thd=0x147cc0000db8) at /data/builds/10.5_dbg/sql/sql_parse.cc:1370
      #12 0x00005589d4078c83 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5589d6aa0f38, put_in_cache=put_in_cache@entry=true) at /data/builds/10.5_dbg/sql/sql_connect.cc:1410
      #13 0x00005589d4079387 in handle_one_connection (arg=arg@entry=0x5589d6aa0f38) at /data/builds/10.5_dbg/sql/sql_connect.cc:1312
      #14 0x00005589d452d79d in pfs_spawn_thread (arg=0x5589d698d9e8) at /data/builds/10.5_dbg/storage/perfschema/pfs.cc:2201
      #15 0x0000147d197f2609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #16 0x0000147d193e1293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Except for an expected '2021-01-27 22:15:06 12 [ERROR] Failed to write to mysql.slow_log' error, optimized builds do not see to be affected.

      Attachments

        Issue Links

          Activity

            People

              sanja Oleksandr Byelkin
              Roel Roel Van de Paar
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:

                Git Integration

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