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

Assertion failures upon reading InnoDB system table after normal upgrade from 10.2

    XMLWordPrintable

Details

    Description

      10.3 594aad7b, upon SELECT

      2020-09-02 16:40:13 9 [Warning] InnoDB: A transaction id in a record of table `mysql`.`innodb_index_stats` is newer than the system-wide maximum.
      mysqld: /data/src/10.3/storage/innobase/trx/trx0sys.cc:62: static void ReadView::check_trx_id_sanity(trx_id_t, const table_name_t&): Assertion `0' failed.
      200902 16:40:13 [ERROR] mysqld got signal 6 ;
       
      #7  0x00007f5ebc399f12 in __GI___assert_fail (assertion=0x5575e1c85435 "0", file=0x5575e1c85438 "/data/src/10.3/storage/innobase/trx/trx0sys.cc", line=62, function=0x5575e1c85ac0 <ReadView::check_trx_id_sanity(unsigned long, table_name_t const&)::__PRETTY_FUNCTION__> "static void ReadView::check_trx_id_sanity(trx_id_t, const table_name_t&)") at assert.c:101
      #8  0x00005575e15363f0 in ReadView::check_trx_id_sanity (id=20437, name=...) at /data/src/10.3/storage/innobase/trx/trx0sys.cc:62
      #9  0x00005575e1371442 in ReadView::changes_visible (this=0x7f5eb9025258, id=20437, name=...) at /data/src/10.3/storage/innobase/include/read0types.h:212
      #10 0x00005575e135826f in lock_clust_rec_cons_read_sees (rec=0x7f5e984e06d4 "testtc031PRIMARYn_diff_pfx01", index=0x7f5e4c01c9f0, offsets=0x7f5ea4c44660, view=0x7f5eb9025258) at /data/src/10.3/storage/innobase/lock/lock0lock.cc:399
      #11 0x00005575e14a9ba3 in row_search_mvcc (buf=0x7f5e50020378 "\001\004testl", mode=PAGE_CUR_G, prebuilt=0x7f5e500235e0, match_mode=0, direction=1) at /data/src/10.3/storage/innobase/row/row0sel.cc:5152
      #12 0x00005575e12c7bb8 in ha_innobase::general_fetch (this=0x7f5e5001fbc8, buf=0x7f5e50020378 "\001\004testl", direction=1, match_mode=0) at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:9502
      #13 0x00005575e12c813c in ha_innobase::rnd_next (this=0x7f5e5001fbc8, buf=0x7f5e50020378 "\001\004testl") at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:9711
      #14 0x00005575e10987b6 in handler::ha_rnd_next (this=0x7f5e5001fbc8, buf=0x7f5e50020378 "\001\004testl") at /data/src/10.3/sql/handler.cc:2847
      #15 0x00005575e122a56b in rr_sequential (info=0x7f5e50013c48) at /data/src/10.3/sql/records.cc:485
      #16 0x00005575e0cd58fd in READ_RECORD::read_record (this=0x7f5e50013c48) at /data/src/10.3/sql/records.h:70
      #17 0x00005575e0def8e8 in sub_select (join=0x7f5e50011e18, join_tab=0x7f5e50013b80, end_of_records=false) at /data/src/10.3/sql/sql_select.cc:19733
      #18 0x00005575e0deed03 in do_select (join=0x7f5e50011e18, procedure=0x0) at /data/src/10.3/sql/sql_select.cc:19254
      #19 0x00005575e0dc5c29 in JOIN::exec_inner (this=0x7f5e50011e18) at /data/src/10.3/sql/sql_select.cc:4116
      #20 0x00005575e0dc4ffc in JOIN::exec (this=0x7f5e50011e18) at /data/src/10.3/sql/sql_select.cc:3910
      #21 0x00005575e0dc630d in mysql_select (thd=0x7f5e50000af0, tables=0x7f5e500116c8, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7f5e50011df0, unit=0x7f5e500049b8, select_lex=0x7f5e50005140) at /data/src/10.3/sql/sql_select.cc:4315
      #22 0x00005575e0db78e2 in handle_select (thd=0x7f5e50000af0, lex=0x7f5e500048f8, result=0x7f5e50011df0, setup_tables_done_option=0) at /data/src/10.3/sql/sql_select.cc:370
      #23 0x00005575e0d7f1fc in execute_sqlcom_select (thd=0x7f5e50000af0, all_tables=0x7f5e500116c8) at /data/src/10.3/sql/sql_parse.cc:6286
      #24 0x00005575e0d7594f in mysql_execute_command (thd=0x7f5e50000af0) at /data/src/10.3/sql/sql_parse.cc:3812
      #25 0x00005575e0d83507 in mysql_parse (thd=0x7f5e50000af0, rawbuf=0x7f5e50011488 "select * from mysql.innodb_index_stats", length=38, parser_state=0x7f5ea4c46630, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7810
      #26 0x00005575e0d6fd4e in dispatch_command (command=COM_QUERY, thd=0x7f5e50000af0, packet=0x7f5e50019571 "\023\062\060\062\060-09-01 18:19:22\fn_diff_pfx01\003\066\064\067\001\064\032col_varchar_8_not_null_keyl", packet_length=38, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1848
      #27 0x00005575e0d6e666 in do_command (thd=0x7f5e50000af0) at /data/src/10.3/sql/sql_parse.cc:1393
      #28 0x00005575e0ee7f57 in do_handle_one_connection (connect=0x5575e4d05550) at /data/src/10.3/sql/sql_connect.cc:1403
      #29 0x00005575e0ee7cb9 in handle_one_connection (arg=0x5575e4d05550) at /data/src/10.3/sql/sql_connect.cc:1308
      #30 0x00007f5ebe3224a4 in start_thread (arg=0x7f5ea4c47700) at pthread_create.c:456
      #31 0x00007f5ebc456d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
      

      10.5 0af6e525, upon mysql_upgrade

      mysqld: /data/src/10.5/storage/innobase/row/row0merge.cc:2060: dberr_t row_merge_read_clustered_index(trx_t*, TABLE*, const dict_table_t*, dict_table_t*, bool, dict_index_t**, dict_index_t*, fts_psort_t*, merge_file_t*, const ulint*, ulint, const dtuple_t*, const dict_add_v_col_t*, const ulint*, ulint, ib_sequence_t&, row_merge_block_t*, bool, pfs_os_file_t*, ut_stage_alter_t*, double, row_merge_block_t*, TABLE*, bool): Assertion `rec_trx_id != trx->id' failed.
      200902 16:45:03 [ERROR] mysqld got signal 6 ;
       
      #7  0x00007f60f030cf12 in __GI___assert_fail (assertion=0x55874c72155e "rec_trx_id != trx->id", file=0x55874c720b80 "/data/src/10.5/storage/innobase/row/row0merge.cc", line=2060, function=0x55874c7249c0 <row_merge_read_clustered_index(trx_t*, TABLE*, dict_table_t const*, dict_table_t*, bool, dict_index_t**, dict_index_t*, fts_psort_t*, merge_file_t*, unsigned long const*, unsigned long, dtuple_t const*, dict_add_v_col_t const*, unsigned long const*, unsigned long, ib_sequence_t&, unsigned char*, bool, pfs_os_file_t*, ut_stage_alter_t*, double, unsigned char*, TABLE*, bool)::__PRETTY_FUNCTION__> "dberr_t row_merge_read_clustered_index(trx_t*, TABLE*, const dict_table_t*, dict_table_t*, bool, dict_index_t**, dict_index_t*, fts_psort_t*, merge_file_t*, const ulint*, ulint, const dtuple_t*, const"...) at assert.c:101
      #8  0x000055874bf52f70 in row_merge_read_clustered_index (trx=0x7f60db4003a0, table=0x7f60d8bac640, old_table=0x7f60b001c078, new_table=0x7f60b41b7138, online=true, index=0x7f60b41b6b58, fts_sort_idx=0x0, psort_info=0x0, files=0x7f60b4116bf8, key_numbers=0x7f60b41b6b60, n_index=1, defaults=0x0, add_v=0x0, col_map=0x7f60b41b7eb8, add_autoinc=18446744073709551615, sequence=..., block=0x7f60c82f6000 <error: Cannot access memory at address 0x7f60c82f6000>, skip_pk_sort=true, tmpfd=0x7f60d8bab640, stage=0x7f60b4173d78, pct_cost=50, crypt_block=0x0, eval_table=0x7f60d8bac640, allow_not_null=true) at /data/src/10.5/storage/innobase/row/row0merge.cc:2060
      #9  0x000055874bf5ba32 in row_merge_build_indexes (trx=0x7f60db4003a0, old_table=0x7f60b001c078, new_table=0x7f60b41b7138, online=true, indexes=0x7f60b41b6b58, key_numbers=0x7f60b41b6b60, n_indexes=1, table=0x7f60d8bac640, defaults=0x0, col_map=0x7f60b41b7eb8, add_autoinc=18446744073709551615, sequence=..., skip_pk_sort=true, stage=0x7f60b4173d78, add_v=0x0, eval_table=0x7f60d8bac640, allow_not_null=true) at /data/src/10.5/storage/innobase/row/row0merge.cc:4537
      #10 0x000055874be023bf in ha_innobase::inplace_alter_table (this=0x7f60b406ec90, altered_table=0x7f60d8bac640, ha_alter_info=0x7f60d8bac5a0) at /data/src/10.5/storage/innobase/handler/handler0alter.cc:8409
      #11 0x000055874b6fbd15 in handler::ha_inplace_alter_table (this=0x7f60b406ec90, altered_table=0x7f60d8bac640, ha_alter_info=0x7f60d8bac5a0) at /data/src/10.5/sql/handler.h:4526
      #12 0x000055874b6eec83 in mysql_inplace_alter_table (thd=0x7f60b4000b18, table_list=0x7f60b4183340, table=0x7f60b406bcf8, altered_table=0x7f60d8bac640, ha_alter_info=0x7f60d8bac5a0, target_mdl_request=0x7f60d8baca10, alter_ctx=0x7f60d8bad560) at /data/src/10.5/sql/sql_table.cc:7989
      #13 0x000055874b6f6707 in mysql_alter_table (thd=0x7f60b4000b18, new_db=0x7f60b414c700, new_name=0x7f60b414cb08, create_info=0x7f60d8bae160, table_list=0x7f60b4183340, alter_info=0x7f60d8bae090, order_num=0, order=0x0, ignore=false, if_exists=false) at /data/src/10.5/sql/sql_table.cc:10570
      #14 0x000055874b79bf74 in Sql_cmd_alter_table::execute (this=0x7f60b4183e40, thd=0x7f60b4000b18) at /data/src/10.5/sql/sql_alter.cc:540
      #15 0x000055874b5f9190 in mysql_execute_command (thd=0x7f60b4000b18) at /data/src/10.5/sql/sql_parse.cc:5952
      #16 0x000055874b4fb6f4 in sp_instr_stmt::exec_core (this=0x7f60b4183e58, thd=0x7f60b4000b18, nextp=0x7f60d8baf2ec) at /data/src/10.5/sql/sp_head.cc:3765
      #17 0x000055874b4faa93 in sp_lex_keeper::reset_lex_and_exec_core (this=0x7f60b4183ea0, thd=0x7f60b4000b18, nextp=0x7f60d8baf2ec, open_tables=false, instr=0x7f60b4183e58) at /data/src/10.5/sql/sp_head.cc:3492
      #18 0x000055874b4fb2b9 in sp_instr_stmt::execute (this=0x7f60b4183e58, thd=0x7f60b4000b18, nextp=0x7f60d8baf2ec) at /data/src/10.5/sql/sp_head.cc:3671
      #19 0x000055874b4f49c9 in sp_head::execute (this=0x7f60b4137c00, thd=0x7f60b4000b18, merge_da_on_success=true) at /data/src/10.5/sql/sp_head.cc:1435
      #20 0x000055874b4f77b6 in sp_head::execute_procedure (this=0x7f60b4137c00, thd=0x7f60b4000b18, args=0x7f60b4005b78) at /data/src/10.5/sql/sp_head.cc:2446
      #21 0x000055874b5eed82 in do_execute_sp (thd=0x7f60b4000b18, sp=0x7f60b4137c00) at /data/src/10.5/sql/sql_parse.cc:3043
      #22 0x000055874b5f8285 in mysql_execute_command (thd=0x7f60b4000b18) at /data/src/10.5/sql/sql_parse.cc:5683
      #23 0x000055874b5ff4d1 in mysql_parse (thd=0x7f60b4000b18, rawbuf=0x7f60b40124e0 "if @have_innodb then\n  \n  delete from innodb_index_stats where length(table_name) > 64;\n  delete from innodb_table_stats where length(table_name) > 64;\n  \n  alter table innodb_index_stats modify last_"..., length=564, parser_state=0x7f60d8bb0520, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7994
      #24 0x000055874b5eb7ca in dispatch_command (command=COM_QUERY, thd=0x7f60b4000b18, packet=0x7f60b4008699 "if @have_innodb then\n  \n  delete from innodb_index_stats where length(table_name) > 64;\n  delete from innodb_table_stats where length(table_name) > 64;\n  \n  alter table innodb_index_stats modify last_"..., packet_length=564, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1868
      #25 0x000055874b5e9ef8 in do_command (thd=0x7f60b4000b18) at /data/src/10.5/sql/sql_parse.cc:1349
      #26 0x000055874b7916d4 in do_handle_one_connection (connect=0x5587507058c8, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1410
      #27 0x000055874b79143c in handle_one_connection (arg=0x5587507058c8) at /data/src/10.5/sql/sql_connect.cc:1312
      #28 0x000055874bcd3862 in pfs_spawn_thread (arg=0x55875068fa88) at /data/src/10.5/storage/perfschema/pfs.cc:2201
      #29 0x00007f60f22954a4 in start_thread (arg=0x7f60d8bb1700) at pthread_create.c:456
      #30 0x00007f60f03c9d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x7f60b41a9dc0): alter table innodb_index_stats modify last_update timestamp not null default current_timestamp on update current_timestamp, modify table_name varchar(199)
       
      Connection ID (thread ID): 10
      Status: NOT_KILLED
      

      Notes:

      • The dataset was created on 10.2 3e617b8b, run with innodb-compression-algorithm=none innodb-page-size=8K, otherwise defaults;
      • there was no crash or intentional killing of the server, the session was seemingly uneventful and ended with normal server shutdown. The error log from that session is attached as mysql.err_orig, and the general log as mysql.log.gz;
      • the failure is not immediately reproducible by re-running the same test or by dumping/restoring the contents of innodb_index_stats table;
      • no obvious failures on non-debug builds;
      • 10.2 doesn't seem to have a problem opening this table after restart.

      Attachments

        Issue Links

          Activity

            People

              marko Marko Mäkelä
              elenst Elena Stepanova
              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.