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

Assert in trx_purge_add_update_undo_to_history during shutdown

Details

    Description

      ML13.test
      ----------------
      --source include/have_innodb.inc
       
      --disable_abort_on_error
      CREATE TABLE t1 (col3 INT, col4 VARCHAR(10)) ENGINE = InnoDB ;
      ALTER TABLE t1 ADD FULLTEXT KEY ftidx ( col4 ) ;
      INSERT INTO t1 (col3,col4) VALUES (1,'1'), (1,'1')  ;
      ALTER TABLE t1 DROP KEY ftidx ;
      # Get the assert on shutdown
      --error ER_DUP_ENTRY
      ALTER TABLE t1 ADD UNIQUE KEY uidx ( col3 ), ADD FULLTEXT KEY ftidx ( col4 ) ;
       
      ./mtr --mem ML13
      Logging: /home/mleich/Server/10.2/mysql-test/mysql-test-run.pl  --mem ML13
      ...
      MariaDB Version 10.2.31-MariaDB-debug
      ...
      ==============================================================================
       
      TEST                                      RESULT   TIME (ms) or COMMENT
      --------------------------------------------------------------------------
       
      worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
      CREATE TABLE t1 (col3 INT, col4 VARCHAR(10)) ENGINE = InnoDB ;
      ALTER TABLE t1 ADD FULLTEXT KEY ftidx ( col4 ) ;
      Warnings:
      Warning 124     InnoDB rebuilding table to add column FTS_DOC_ID
      INSERT INTO t1 (col3,col4) VALUES (1,'1'), (1,'1')  ;
      ALTER TABLE t1 DROP KEY ftidx ;
      ALTER TABLE t1 ADD UNIQUE KEY uidx ( col3 ), ADD FULLTEXT KEY ftidx ( col4 ) ;
      ERROR 23000: Duplicate entry '1' for key 'uidx'
      ***Warnings generated in error logs during shutdown after running tests: main.ML13
       
      mysqld: storage/innobase/trx/trx0purge.cc:292: void trx_purge_add_update_undo_to_history(trx_t*, ib_page_t*, mtr_t*): Assertion `srv_undo_sources || trx->undo_no == 0 || ((srv_is_being_started || trx_rollback_or_clean_is_active) && purge_sys->state == PURGE_STATE_INIT) || (srv_force_recovery >= SRV_FORCE_NO_BACKGROUND && purge_sys->state == PURGE_STATE_DISABLED) || ((trx->in_mysql_trx_list || trx->internal) && srv_fast_shutdown)' failed.
      Attempting backtrace. You can use the following information to find out
       
      mysql-test-run: *** ERROR: Test suite aborted
       
      Content of var/log/mysqld.1.err (shortened)
      -------------------------------------------
      CURRENT_TEST: main.ML13
      2020-01-24 19:07:44 140468614063936 [Note] /home/mleich/Server/10.2/bld_debug/sql/mysqld (mysqld 10.2.31-MariaDB-debug-log) starting as process 2290 ...
      ...
      2020-01-24 19:07:44 140468614063936 [Note] /home/mleich/Server/10.2/bld_debug/sql/mysqld: ready for connections.
      Version: '10.2.31-MariaDB-debug-log'  socket: '/home/mleich/Server/10.2/bld_debug/mysql-test/var/tmp/mysqld.1.sock'  port: 16000  Source distribution
      2020-01-24 19:07:45 140468479891200 [Note] /home/mleich/Server/10.2/bld_debug/sql/mysqld (initiated by: root[root] @ localhost [127.0.0.1]): Normal shutdown
      2020-01-24 19:07:45 140468096587520 [Note] InnoDB: FTS optimize thread exiting.
      2020-01-24 19:07:45 140468479891200 [Note] Event Scheduler: Purging the queue. 0 events
      mysqld: /home/mleich/Server/10.2/storage/innobase/trx/trx0purge.cc:292: void trx_purge_add_update_undo_to_history(trx_t*, ib_page_t*, mtr_t*): Assertion `srv_undo_sources || trx->undo_no == 0 || ((srv_is_being_started || trx_rollback_or_clean_is_active) && purge_sys->state == PURGE_STATE_INIT) || (srv_force_recovery >= SRV_FORCE_NO_BACKGROUND && purge_sys->state == PURGE_STATE_DISABLED) || ((trx->in_mysql_trx_list || trx->internal) && srv_fast_shutdown)' failed.
      200124 19:07:45 [ERROR] mysqld got signal 6 ;
      ...
      Server version: 10.2.31-MariaDB-debug-log
      key_buffer_size=1048576
      read_buffer_size=131072
      max_used_connections=1
      max_threads=153
      thread_count=0
      ....
      Thread pointer: 0x0
      Attempting backtrace. You can use the following information to find out
      where mysqld died. If you see no messages after this, something went
      terribly wrong...
      stack_bottom = 0x0 thread_stack 0x49000
      /home/mleich/Server/10.2/bld_debug/sql/mysqld(my_print_stacktrace+0x38)[0x560a4482fabe]
      mysys/stacktrace.c:267(my_print_stacktrace)[0x560a44084a7c]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x13150)[0x7fc164438150]
      linux/raise.c:51(__GI_raise)[0x7fc1637890bb]
      stdlib/abort.c:92(__GI_abort)[0x7fc16378af5d]
      assert/assert.c:92(__assert_fail_base)[0x7fc163780f17]
      /lib/x86_64-linux-gnu/libc.so.6(+0x2efc2)[0x7fc163780fc2]
      trx/trx0purge.cc:303(trx_purge_add_update_undo_to_history(trx_t*, unsigned char*, mtr_t*))[0x560a44469f53]
      trx/trx0undo.cc:1750(trx_undo_update_cleanup(trx_t*, unsigned char*, mtr_t*))[0x560a444a1281]
      trx/trx0trx.cc:1421(trx_write_serialisation_history(trx_t*, mtr_t*))[0x560a4449099a]
      trx/trx0trx.cc:1881(trx_commit_low(trx_t*, mtr_t*))[0x560a44492242]
      trx/trx0trx.cc:1939(trx_commit(trx_t*))[0x560a444923d4]
      trx/trx0trx.cc:2163(trx_commit_for_mysql(trx_t*))[0x560a44492c81]
      dict/dict0dict.cc:445(dict_table_try_drop_aborted(dict_table_t*, unsigned long, int))[0x560a44544b51]
      dict/dict0dict.cc:535(dict_table_close(dict_table_t*, unsigned long, unsigned long))[0x560a44544ea2]
      row/row0mysql.cc:1039(row_prebuilt_free(row_prebuilt_t*, unsigned long))[0x560a443d61bd]
      handler/ha_innodb.cc:6663(ha_innobase::close())[0x560a442953e8]
      sql/handler.cc:2650(handler::ha_close())[0x560a4408b9a7]
      sql/table.cc:3490(closefrm(TABLE*))[0x560a43f0e4b6]
      sql/table_cache.cc:223(intern_close_table(TABLE*))[0x560a43ffcb1b]
      sql/table_cache.cc:334(tc_purge(bool))[0x560a43ffcf3f]
      sql/sql_base.cc:376(close_cached_tables(THD*, TABLE_LIST*, bool, unsigned long))[0x560a43d8f746]
      sql/table_cache.cc:648(tdc_start_shutdown())[0x560a43ffdfbc]
      sql/mysqld.cc:2225(clean_up(bool))[0x560a43d204df]
      sql/mysqld.cc:2100(unireg_end())[0x560a43d1ffdf]
      sql/mysqld.cc:2026(kill_server(void*))[0x560a43d1fed9]
      sql/mysqld.cc:2051(kill_server_thread)[0x560a43d1ff1b]
      perfschema/pfs.cc:1864(pfs_spawn_thread)[0x560a447830ab]
      nptl/pthread_create.c:465(start_thread)[0x7fc16442c7fc]
      x86_64/clone.S:97(clone)[0x7fc163866b5f]
      <snip>
      

      Attachments

        Activity

          Replay on (all binaries compiled with debug)
          - 10.2.31 commit 7d313214641241e8ce839d9de01529c2335c620f
          - 10.3.19 commit bef843b97f2e91859f2a08845822d619e769f89f
          - 10.4.12 commit 983163209d026bfd979b4298053fcbdb373efa9d
          - 10.5.1 commit 6af00b2cc620a96372541447cca7134f2d051b19
          

          mleich Matthias Leich added a comment - Replay on (all binaries compiled with debug) - 10.2.31 commit 7d313214641241e8ce839d9de01529c2335c620f - 10.3.19 commit bef843b97f2e91859f2a08845822d619e769f89f - 10.4.12 commit 983163209d026bfd979b4298053fcbdb373efa9d - 10.5.1 commit 6af00b2cc620a96372541447cca7134f2d051b19

          A variation of the stack trace that I've been getting in my tests (adding it here for the record and further searches, as I'm removing it from my notes):

          10.4 f5390eea

          mysqld: /home/vsts/src/storage/innobase/trx/trx0purge.cc:268: void trx_purge_add_undo_to_history(const trx_t*, trx_undo_t*&, mtr_t*): Assertion `srv_undo_sources || trx->undo_no == 0 || (!purge_sys.enabled() && (srv_is_being_started || trx_rollback_is_active || srv_force_recovery >= SRV_FORCE_NO_BACKGROUND)) || ((trx->mysql_thd || trx->internal) && srv_fast_shutdown)' failed.
          190718  2:48:46 [ERROR] mysqld got signal 6 ;
          This could be because you hit a bug. It is also possible that this binary
          or one of the libraries it was linked against is corrupt, improperly built,
          or misconfigured. This error can also be caused by malfunctioning hardware.
          To report this bug, see https://mariadb.com/kb/en/reporting-bugs
          We will try our best to scrape up some info that will hopefully help
          diagnose the problem, but since we have already crashed, 
          something is definitely wrong and this may fail.
          Server version: 10.4.7-MariaDB-debug-log
          key_buffer_size=134217728
          read_buffer_size=131072
          max_used_connections=7
          max_threads=153
          thread_count=10
          It is possible that mysqld could use up to 
          key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467838 K  bytes of memory
          Hope that's ok; if not, decrease some variables in the equation.
          Thread pointer: 0x7f7558001f20
          Attempting backtrace. You can use the following information to find out
          where mysqld died. If you see no messages after this, something went
          terribly wrong...
          stack_bottom = 0x7f755d213ec0 thread_stack 0x49000
          /home/vsts/server/bin/mysqld(my_print_stacktrace+0x40)[0x5582815082f5]
          /home/vsts/server/bin/mysqld(handle_fatal_signal+0x3ae)[0x558280d320ad]
          /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f757d86c390]
          linux/raise.c:54(__GI_raise)[0x7f757c9be428]
          stdlib/abort.c:91(__GI_abort)[0x7f757c9c002a]
          assert/assert.c:92(__assert_fail_base)[0x7f757c9b6bd7]
          /lib/x86_64-linux-gnu/libc.so.6(+0x2dc82)[0x7f757c9b6c82]
          /home/vsts/server/bin/mysqld(+0xf50434)[0x55828115f434]
          trx/trx0purge.cc:278(trx_purge_add_undo_to_history(trx_t const*, trx_undo_t*&, mtr_t*))[0x55828118560f]
          trx/trx0trx.cc:1100(trx_write_serialisation_history(trx_t*, mtr_t*))[0x558281187147]
          trx/trx0trx.cc:1528(trx_commit_low(trx_t*, mtr_t*))[0x5582811872a7]
          trx/trx0trx.cc:1582(trx_commit(trx_t*))[0x5582811876e8]
          trx/trx0trx.cc:1724(trx_commit_for_mysql(trx_t*))[0x5582812e6e73]
          fts/fts0sql.cc:276(fts_sql_commit(trx_t*))[0x5582812d946c]
          fts/fts0opt.cc:1806(fts_optimize_words(fts_optimize_t*, dict_index_t*, fts_string_t*))[0x5582812d9bc5]
          fts/fts0opt.cc:1995(fts_optimize_index(fts_optimize_t*, dict_index_t*))[0x5582812da52d]
          fts/fts0opt.cc:2292(fts_optimize_indexes(fts_optimize_t*))[0x5582812da8e1]
          fts/fts0opt.cc:2469(fts_optimize_table(dict_table_t*))[0x558280f7aa9e]
          handler/ha_innodb.cc:14455(ha_innobase::optimize(THD*, st_ha_check_opt*))[0x558280d407d7]
          sql/handler.cc:4460(handler::ha_optimize(THD*, st_ha_check_opt*))[0x558280b80360]
          sql/sql_admin.cc:806(mysql_admin_table(THD*, TABLE_LIST*, st_ha_check_opt*, char const*, thr_lock_type, bool, bool, unsigned int, int (*)(THD*, TABLE_LIST*, st_ha_check_opt*), int (handler::*)(THD*, st_ha_check_opt*), int (*)(THD*, TABLE_LIST*, st_ha_check_opt*)))[0x558280b8278a]
          sql/sql_parse.cc:6098(mysql_execute_command(THD*))[0x558280a01917]
          sql/sql_parse.cc:7908(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x558280a06bce]
          sql/sql_parse.cc:1845(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x5582809f2e3c]
          sql/sql_parse.cc:1360(do_command(THD*))[0x5582809f1556]
          sql/sql_connect.cc:1404(do_handle_one_connection(CONNECT*))[0x558280b6b880]
          sql/sql_connect.cc:1307(handle_one_connection)[0x558280b6b5a9]
          /lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7f757d8626ba]
          x86_64/clone.S:111(clone)[0x7f757ca9041d]
          Trying to get some variables.
          Some pointers may be invalid and cause the dump to abort.
          Query (0x7f75580130f8): OPTIMIZE TABLE fti_t5 /* QNO 782 CON_ID 16 */
          Connection ID (thread ID): 16
          Status: KILL_SERVER
          Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on
          

          elenst Elena Stepanova added a comment - A variation of the stack trace that I've been getting in my tests (adding it here for the record and further searches, as I'm removing it from my notes): 10.4 f5390eea mysqld: /home/vsts/src/storage/innobase/trx/trx0purge.cc:268: void trx_purge_add_undo_to_history(const trx_t*, trx_undo_t*&, mtr_t*): Assertion `srv_undo_sources || trx->undo_no == 0 || (!purge_sys.enabled() && (srv_is_being_started || trx_rollback_is_active || srv_force_recovery >= SRV_FORCE_NO_BACKGROUND)) || ((trx->mysql_thd || trx->internal) && srv_fast_shutdown)' failed. 190718 2:48:46 [ERROR] mysqld got signal 6 ; This could be because you hit a bug. It is also possible that this binary or one of the libraries it was linked against is corrupt, improperly built, or misconfigured. This error can also be caused by malfunctioning hardware. To report this bug, see https://mariadb.com/kb/en/reporting-bugs We will try our best to scrape up some info that will hopefully help diagnose the problem, but since we have already crashed, something is definitely wrong and this may fail. Server version: 10.4.7-MariaDB-debug-log key_buffer_size=134217728 read_buffer_size=131072 max_used_connections=7 max_threads=153 thread_count=10 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467838 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x7f7558001f20 Attempting backtrace. You can use the following information to find out where mysqld died. If you see no messages after this, something went terribly wrong... stack_bottom = 0x7f755d213ec0 thread_stack 0x49000 /home/vsts/server/bin/mysqld(my_print_stacktrace+0x40)[0x5582815082f5] /home/vsts/server/bin/mysqld(handle_fatal_signal+0x3ae)[0x558280d320ad] /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f757d86c390] linux/raise.c:54(__GI_raise)[0x7f757c9be428] stdlib/abort.c:91(__GI_abort)[0x7f757c9c002a] assert/assert.c:92(__assert_fail_base)[0x7f757c9b6bd7] /lib/x86_64-linux-gnu/libc.so.6(+0x2dc82)[0x7f757c9b6c82] /home/vsts/server/bin/mysqld(+0xf50434)[0x55828115f434] trx/trx0purge.cc:278(trx_purge_add_undo_to_history(trx_t const*, trx_undo_t*&, mtr_t*))[0x55828118560f] trx/trx0trx.cc:1100(trx_write_serialisation_history(trx_t*, mtr_t*))[0x558281187147] trx/trx0trx.cc:1528(trx_commit_low(trx_t*, mtr_t*))[0x5582811872a7] trx/trx0trx.cc:1582(trx_commit(trx_t*))[0x5582811876e8] trx/trx0trx.cc:1724(trx_commit_for_mysql(trx_t*))[0x5582812e6e73] fts/fts0sql.cc:276(fts_sql_commit(trx_t*))[0x5582812d946c] fts/fts0opt.cc:1806(fts_optimize_words(fts_optimize_t*, dict_index_t*, fts_string_t*))[0x5582812d9bc5] fts/fts0opt.cc:1995(fts_optimize_index(fts_optimize_t*, dict_index_t*))[0x5582812da52d] fts/fts0opt.cc:2292(fts_optimize_indexes(fts_optimize_t*))[0x5582812da8e1] fts/fts0opt.cc:2469(fts_optimize_table(dict_table_t*))[0x558280f7aa9e] handler/ha_innodb.cc:14455(ha_innobase::optimize(THD*, st_ha_check_opt*))[0x558280d407d7] sql/handler.cc:4460(handler::ha_optimize(THD*, st_ha_check_opt*))[0x558280b80360] sql/sql_admin.cc:806(mysql_admin_table(THD*, TABLE_LIST*, st_ha_check_opt*, char const*, thr_lock_type, bool, bool, unsigned int, int (*)(THD*, TABLE_LIST*, st_ha_check_opt*), int (handler::*)(THD*, st_ha_check_opt*), int (*)(THD*, TABLE_LIST*, st_ha_check_opt*)))[0x558280b8278a] sql/sql_parse.cc:6098(mysql_execute_command(THD*))[0x558280a01917] sql/sql_parse.cc:7908(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x558280a06bce] sql/sql_parse.cc:1845(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x5582809f2e3c] sql/sql_parse.cc:1360(do_command(THD*))[0x5582809f1556] sql/sql_connect.cc:1404(do_handle_one_connection(CONNECT*))[0x558280b6b880] sql/sql_connect.cc:1307(handle_one_connection)[0x558280b6b5a9] /lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7f757d8626ba] x86_64/clone.S:111(clone)[0x7f757ca9041d] Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (0x7f75580130f8): OPTIMIZE TABLE fti_t5 /* QNO 782 CON_ID 16 */ Connection ID (thread ID): 16 Status: KILL_SERVER Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on

          People

            thiru Thirunarayanan Balathandayuthapani
            mleich Matthias Leich
            Votes:
            0 Vote for this issue
            Watchers:
            2 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.