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

Assertion `trx->mysql_thd == thd' failed in innobase_kill_query from process_timers/timer_handler and use-after-poison in innobase_kill_query

    XMLWordPrintable

    Details

      Description

      Sporadic. Usually reproduces every 1 in 200 to 5000. Possibly same as, or connected with, MDEV-26014. Also see MDEV-23536 and MDEV-17092.

      Single threaded SQL replay suffices. Readily reproduces at the CLI on debug builds of 10.5 to 10.11. No issues observed on optimized builds, even with longer runs.

      Engine=TokuDB can be ignored; it is just a testcase artifact (auto-swapped to InnoDB). Likely a few other artifacts remain (high sporadicity) like the table colums.

      # Repeat 200 to 5000 times for issue to trigger
      DROP DATABASE test;  # Only here to ensure clean state on each iteration
      CREATE DATABASE test;  # Idem
      USE test;  # Idem
      SET sql_mode='';
      CREATE TABLE ti (a INT NOT NULL, b INT UNSIGNED NOT NULL, c CHAR(45), d VARCHAR(57) NOT NULL, e VARBINARY(48), f VARCHAR(97) NOT NULL, g BLOB, h LONGBLOB NOT NULL, id BIGINT NOT NULL, KEY(b), KEY(e), PRIMARY KEY(id)) ENGINE=TokuDB;
      XA START 'a';
      XA END 'a';
      SET @@max_statement_time=0.0001;
      SET SESSION pseudo_slave_mode=1;
      XA PREPARE 'a';;
      XA COMMIT 'a';  # Only here to ensure the next round of SQL works correctly, not required in actual crash sequence.
      

      Leads to:

      10.11.0 bc563f1a4b0b38de3b41fd0f0d3d8b7f1aacbd8b (Debug)

      mysqld: /test/10.11_dbg/storage/innobase/handler/ha_innodb.cc:4969: void innobase_kill_query(handlerton*, THD*, thd_kill_levels): Assertion `trx->mysql_thd == thd' failed.
      

      10.11.0 bc563f1a4b0b38de3b41fd0f0d3d8b7f1aacbd8b (Debug)

      Core was generated by `/test/MD190822-mariadb-10.11.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 0x15366b7a3700 (LWP 2465524))]
      (gdb) bt
      #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      #1  0x000015366bb3d859 in __GI_abort () at abort.c:79
      #2  0x000015366bb3d729 in __assert_fail_base (fmt=0x15366bcd3588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55723d115a9b "trx->mysql_thd == thd", file=0x55723d1183a8 "/test/10.11_dbg/storage/innobase/handler/ha_innodb.cc", line=4969, function=<optimized out>) at assert.c:92
      #3  0x000015366bb4efd6 in __GI___assert_fail (assertion=assertion@entry=0x55723d115a9b "trx->mysql_thd == thd", file=file@entry=0x55723d1183a8 "/test/10.11_dbg/storage/innobase/handler/ha_innodb.cc", line=line@entry=4969, function=function@entry=0x55723d1193b0 "void innobase_kill_query(handlerton*, THD*, thd_kill_levels)") at assert.c:101
      #4  0x000055723c902759 in innobase_kill_query (thd=0x153610000db8) at /test/10.11_dbg/storage/innobase/handler/ha_innodb.cc:4969
      #5  0x000055723c5fd9ad in kill_handlerton (thd=thd@entry=0x153610000db8, plugin=<optimized out>, level=level@entry=0x15366b7a2c3c) at /test/10.11_dbg/sql/handler.cc:923
      #6  0x000055723c33723c in plugin_foreach_with_mask (thd=thd@entry=0x153610000db8, func=func@entry=0x55723c5fd953 <kill_handlerton(THD*, plugin_ref, void*)>, type=type@entry=1, state_mask=state_mask@entry=8, arg=arg@entry=0x15366b7a2c3c) at /test/10.11_dbg/sql/sql_plugin.cc:2511
      #7  0x000055723c6011d7 in ha_kill_query (thd=thd@entry=0x153610000db8, level=<optimized out>) at /test/10.11_dbg/sql/handler.cc:930
      #8  0x000055723c2ab7a1 in THD::awake_no_mutex (this=this@entry=0x153610000db8, state_to_set=state_to_set@entry=KILL_TIMEOUT) at /test/10.11_dbg/sql/sql_class.cc:1899
      #9  0x000055723c2ab9b9 in THD::awake (state_to_set=KILL_TIMEOUT, this=0x153610000db8) at /test/10.11_dbg/sql/sql_class.h:3769
      #10 thd_kill_timeout (thd=thd@entry=0x153610000db8) at /test/10.11_dbg/sql/sql_class.cc:628
      #11 0x000055723cd42d00 in process_timers (now=<synthetic pointer>) at /test/10.11_dbg/mysys/thr_timer.c:271
      #12 timer_handler (arg=<optimized out>) at /test/10.11_dbg/mysys/thr_timer.c:315
      #13 0x000015366c04e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #14 0x000015366bc3a133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Bug confirmed present in:
      MariaDB: 10.5.18 (dbg), 10.6.10 (dbg), 10.7.6 (dbg), 10.8.5 (dbg), 10.9.2 (dbg), 10.10.2 (dbg), 10.11.0 (dbg)

      Bug (or feature/syntax) confirmed not present in:
      MariaDB: 10.3.37 (dbg), 10.3.37 (opt), 10.4.27 (dbg), 10.4.27 (opt), 10.5.18 (opt), 10.6.10 (opt), 10.7.6 (opt), 10.8.5 (opt), 10.9.2 (opt), 10.10.2 (opt), 10.11.0 (opt)
      MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.38 (dbg), 5.7.38 (opt), 8.0.29 (dbg), 8.0.29 (opt)

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              serg Sergei Golubchik
              Reporter:
              Roel Roel Van de Paar
              Votes:
              0 Vote for this issue
              Watchers:
              5 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.