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

Assertion `!rec_offs_any_null_extern(rec, offsets)' in row_merge_read_clustered_index

    XMLWordPrintable

    Details

      Description

      Scenario:
      1. Start the server and generate some initial data
      2. 9 sessions run their usual DDL/DML battle
      3. SIGKILL server during 2. is ongoing
      4. Restart attempt with success
      5. OPTIMIZE TABLE harvests a server crash
       
      # 2021-05-20T16:59:44 [3828706] | [rr 3918438 51362]mysqld: /data/Server/bb-10.6-marko/storage/innobase/row/row0merge.cc:2117: 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_offs_any_null_extern(rec, offsets)' failed.
      # 2021-05-20T16:59:44 [3828706] | Query (0x62b0000c4238): OPTIMIZE TABLE `test`.`t3`
      # 2021-05-20T16:59:44 [3828706] | [rr 3918438 66081]
      # 2021-05-20T16:59:44 [3828706] | Connection ID (thread ID): 5
      # 2021-05-20T16:59:44 [3828706] | [rr 3918438 66083]Status: NOT_KILLED
       
      (rr) bt
      #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      #1  0x00007aa72ec57859 in __GI_abort () at abort.c:79
      #2  0x00007aa72ec57729 in __assert_fail_base (fmt=0x7aa72eded588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55e902fb3f40 "!rec_offs_any_null_extern(rec, offsets)", file=0x55e902fb1300 "/data/Server/bb-10.6-marko/storage/innobase/row/row0merge.cc", 
          line=2117, function=<optimized out>) at assert.c:92
      #3  0x00007aa72ec68f36 in __GI___assert_fail (assertion=0x55e902fb3f40 "!rec_offs_any_null_extern(rec, offsets)", file=0x55e902fb1300 "/data/Server/bb-10.6-marko/storage/innobase/row/row0merge.cc", line=2117, 
          function=0x55e902fb3680 "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
      #4  0x000055e901bb3673 in row_merge_read_clustered_index (trx=0x42092aaa2a48, table=0x1fee1b033080, old_table=0x61800000e508, new_table=0x6180000dd508, online=true, index=0x61900028dee0, fts_sort_idx=0x0, psort_info=0x0, files=0x60300000b320, 
          key_numbers=0x61900028def0, n_index=1, defaults=0x0, add_v=0x0, col_map=0x61d000381970, add_autoinc=18446744073709551615, sequence=..., block=0x736f6d029000 "", skip_pk_sort=true, tmpfd=0x1fee1b0314e0, stage=0x602000060f50, pct_cost=50, crypt_block=0x0, 
          eval_table=0x1fee1b033080, allow_not_null=true) at /data/Server/bb-10.6-marko/storage/innobase/row/row0merge.cc:2117
      #5  0x000055e901bc38d2 in row_merge_build_indexes (trx=0x42092aaa2a48, old_table=0x61800000e508, new_table=0x6180000dd508, online=true, indexes=0x61900028dee0, key_numbers=0x61900028def0, n_indexes=1, table=0x1fee1b033080, defaults=0x0, col_map=0x61d000381970, 
          add_autoinc=18446744073709551615, sequence=..., skip_pk_sort=true, stage=0x602000060f50, add_v=0x0, eval_table=0x1fee1b033080, allow_not_null=true) at /data/Server/bb-10.6-marko/storage/innobase/row/row0merge.cc:4548
      #6  0x000055e90190b036 in ha_innobase::inplace_alter_table (this=0x61d0003778b8, altered_table=0x1fee1b033080, ha_alter_info=0x1fee1b032980) at /data/Server/bb-10.6-marko/storage/innobase/handler/handler0alter.cc:8452
      #7  0x000055e900a36752 in handler::ha_inplace_alter_table (this=0x61d0003778b8, altered_table=0x1fee1b033080, ha_alter_info=0x1fee1b032980) at /data/Server/bb-10.6-marko/sql/handler.h:4648
      #8  0x000055e900a15d7a in mysql_inplace_alter_table (thd=0x62b0000bd218, table_list=0x62b0000c4368, table=0x61900028a098, altered_table=0x1fee1b033080, ha_alter_info=0x1fee1b032980, target_mdl_request=0x1fee1b032a80, ddl_log_state=0x1fee1b0327a0, 
          trigger_param=0x1fee1b0334d0, alter_ctx=0x1fee1b033f50) at /data/Server/bb-10.6-marko/sql/sql_table.cc:7352
      #9  0x000055e900a297ab in mysql_alter_table (thd=0x62b0000bd218, new_db=0x55e902699a20 <null_clex_str>, new_name=0x55e902699a20 <null_clex_str>, create_info=0x1fee1b035370, table_list=0x62b0000c4368, alter_info=0x1fee1b035240, order_num=0, order=0x0, ignore=false, 
          if_exists=false) at /data/Server/bb-10.6-marko/sql/sql_table.cc:10176
      #10 0x000055e900a31bca in mysql_recreate_table (thd=0x62b0000bd218, table_list=0x62b0000c4368, table_copy=false) at /data/Server/bb-10.6-marko/sql/sql_table.cc:11235
      #11 0x000055e900bcabcc in admin_recreate_table (thd=0x62b0000bd218, table_list=0x62b0000c4368) at /data/Server/bb-10.6-marko/sql/sql_admin.cc:67
      #12 0x000055e900bd228c in mysql_admin_table (thd=0x62b0000bd218, tables=0x62b0000c4368, check_opt=0x62b0000c2618, operator_name=0x55e90370b0a0 <msg_optimize>, lock_type=TL_WRITE, org_open_for_modify=true, repair_table_use_frm=false, extra_open_options=0, 
          prepare_func=0x0, operator_func=(int (handler::*)(class handler * const, class THD *, HA_CHECK_OPT *)) 0x55e900f615f0 <handler::ha_optimize(THD*, st_ha_check_opt*)>, view_operator_func=0x0, is_cmd_replicated=true)
          at /data/Server/bb-10.6-marko/sql/sql_admin.cc:1144
      #13 0x000055e900bd4be1 in Sql_cmd_optimize_table::execute (this=0x62b0000c4a48, thd=0x62b0000bd218) at /data/Server/bb-10.6-marko/sql/sql_admin.cc:1521
      #14 0x000055e9007bea0c in mysql_execute_command (thd=0x62b0000bd218) at /data/Server/bb-10.6-marko/sql/sql_parse.cc:5986
      #15 0x000055e9007caf0f in mysql_parse (thd=0x62b0000bd218, rawbuf=0x62b0000c4238 "OPTIMIZE TABLE `test`.`t3`", length=26, parser_state=0x1fee1b037b20) at /data/Server/bb-10.6-marko/sql/sql_parse.cc:8019
      #16 0x000055e9007a31ac in dispatch_command (command=COM_QUERY, thd=0x62b0000bd218, packet=0x6290000dc219 "", packet_length=26, blocking=true) at /data/Server/bb-10.6-marko/sql/sql_parse.cc:1897
      #17 0x000055e9007a0581 in do_command (thd=0x62b0000bd218, blocking=true) at /data/Server/bb-10.6-marko/sql/sql_parse.cc:1406
      #18 0x000055e900b9bfda in do_handle_one_connection (connect=0x608000003f38, put_in_cache=true) at /data/Server/bb-10.6-marko/sql/sql_connect.cc:1410
      #19 0x000055e900b9b93c in handle_one_connection (arg=0x608000003f38) at /data/Server/bb-10.6-marko/sql/sql_connect.cc:1312
      #20 0x00001dc322277609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #21 0x00007aa72ed54293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      (rr)
      pluto:/data/Results/1621525973/TBR-795/dev/shm/vardir/1621525973/6/1/rr
      _RR_TRACE_DIR="." rr replay --mark-stdio mysqld-0  # Fate of DB server till SIGKILL
      _RR_TRACE_DIR="." rr replay --mark-stdio mysqld-1  # Fate of DB Server since restart
       
      GIT_SHOW: HEAD, origin/bb-10.6-marko 25d150d3fe193b5a41948a589c0ce30368c054e1 2021-05-20T18:36:07+03:00
       
      RQG
      ====
      git clone https://github.com/mleich1/rqg --branch experimental RQG
       
      perl rqg.pl \
      --grammar=conf/mariadb/table_stress_innodb.yy \
      --gendata=conf/mariadb/table_stress.zz \
      --gendata_sql=conf/mariadb/table_stress.sql \
      --reporters=CrashRecovery1 \
      --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \
      --mysqld=--loose-idle_write_transaction_timeout=0 \
      --mysqld=--loose-idle_transaction_timeout=0 \
      --mysqld=--loose-idle_readonly_transaction_timeout=0 \
      --mysqld=--connect_timeout=60 \
      --mysqld=--interactive_timeout=28800 \
      --mysqld=--slave_net_timeout=60 \
      --mysqld=--net_read_timeout=30 \
      --mysqld=--net_write_timeout=60 \
      --mysqld=--loose-table_lock_wait_timeout=50 \
      --mysqld=--wait_timeout=28800 \
      --mysqld=--lock-wait-timeout=86400 \
      --mysqld=--innodb-lock-wait-timeout=50 \
      --no-mask \
      --queries=10000000 \
      --seed=random \
      --reporters=Backtrace \
      --reporters=ErrorLog \
      --reporters=Deadlock1 \
      --validators=None \
      --mysqld=--log_output=none \
      --mysqld=--log-bin \
      --mysqld=--log_bin_trust_function_creators=1 \
      --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
      --engine=InnoDB \
      --restart_timeout=240 \
      --mysqld=--plugin-load-add=file_key_management.so \
      --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
      --duration=300 \
      --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
      --mysqld=--innodb_stats_persistent=off \
      --mysqld=--innodb_adaptive_hash_index=on \
      --mysqld=--loose-innodb_evict_tables_on_commit_debug=off \
      --mysqld=--loose-max-statement-time=30 \
      --threads=9 \
      --mysqld=--innodb-use-native-aio=0 \
      --rr=Extended \
      --rr_options="--chaos --wait" \
      --mysqld=--innodb_page_size=64K \
      --mysqld=--innodb-buffer-pool-size=256M \
      --no_mask \
      --workdir=<local settings> \
      --vardir=<local settings> \
      --mtr-build-thread=<local settings> \
      --basedir1=<local settings> \
      --script_debug=_nix
       
      RQG error pattern
      [ 'TBR-795-MDEV-25751', 'INFO: Reporter \'CrashRecovery1\': Attempting database recovery using the server.+ERROR: OPTIMIZE TABLE .{1,500} harvested 2013: Lost connection to MySQL server during query.+\[Note\] InnoDB: Starting crash recovery from checkpoint LSN.+\[Note\] .{1,200}mysqld: ready for connections.+mysqld: .{1,200}row0merge.cc:.{1,30} dberr_t row_merge_read_clustered_index.{1,500}: Assertion .\!rec_offs_any_null_extern\(rec, offsets\). failed..+RESULT: The RQG run ended with status STATUS_RECOVERY_FAILURE' ],
      
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              thiru Thirunarayanan Balathandayuthapani
              Reporter:
              mleich Matthias Leich
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Git Integration