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

InnoDB: Assertion of missing row in sec index row_start upon REPLACE on a system-versioned table

    XMLWordPrintable

    Details

      Description

      Notes:

      • Given the history of false-positives in attempts to reproduce MDEV-14643 / MDEV-9663, I file this one separately. If we are lucky this time and turns out to be the problem that we have been chasing for within MDEV-14643, feel free to close as a duplicate.
      • Due to system versioning in the scenario, the test case is not applicable to 10.2. I suspect that system versioning as such may be unrelated and only creates the right index structure under the hood, but I couldn't get rid of it. I expect if it is possible, it will become obvious during the development analysis.
      • Please note that !cursor->index->is_committed() only happens on non-debug builds. Debug builds fail with a different assertion. Both are quoted below.

      --source include/have_innodb.inc
       
      CREATE TABLE t1 (
        a int,
        b int,
        row_start bigint(20) unsigned GENERATED ALWAYS AS ROW START,
        row_end bigint(20) unsigned GENERATED ALWAYS AS ROW END,
        UNIQUE KEY (b,row_end),
        KEY (row_start),
        PERIOD FOR SYSTEM_TIME (row_start,row_end)
      ) ENGINE=InnoDB WITH SYSTEM VERSIONING;
       
      INSERT INTO t1 (a,b) VALUES (1,2);
      REPLACE INTO t1 (a,b) VALUES (3,2),(3,2);
       
      # Cleanup
      DROP TABLE t1;
      

      10.3 non-debug 0fb84216

      2020-03-27 15:11:04 9 [ERROR] InnoDB: Record in index `row_start` of table `test`.`t1` was not found on update: TUPLE (info_bits=0, 2 fields): {[8]       '(0x0000000000000027),[6]      (0x000000000200)} at: COMPACT RECORD(info_bits=0, 2 fields): {[8]       $(0x0000000000000024),[6]      (0x000000000202)}
      2020-03-27 15:11:04 0x7f3ea039a700  InnoDB: Assertion failure in file /data/src/10.3/storage/innobase/row/row0ins.cc line 266
      InnoDB: Failing assertion: !cursor->index->is_committed()
       
      #5  0x00007f3ea6fd642a in __GI_abort () at abort.c:89
      #6  0x0000556e50e1f885 in ut_dbg_assertion_failed (expr=expr@entry=0x556e5170f038 "!cursor->index->is_committed()", file=file@entry=0x556e5170eb50 "/data/src/10.3/storage/innobase/row/row0ins.cc", line=line@entry=266) at /data/src/10.3/storage/innobase/ut/ut0dbg.cc:60
      #7  0x0000556e512bfa7b in row_ins_sec_index_entry_by_modify (mtr=0x7f3ea0396760, thr=0x7f3e58066ba8, entry=0x7f3e580a94f8, heap=0x7f3e580a9e20, offsets_heap=<optimized out>, offsets=0x7f3ea0395880, cursor=0x7f3ea0395950, mode=2, flags=0) at /data/src/10.3/storage/innobase/row/row0ins.cc:266
      #8  row_ins_sec_index_entry_low (flags=flags@entry=0, mode=mode@entry=2, index=index@entry=0x7f3e58064258, offsets_heap=<optimized out>, offsets_heap@entry=0x7f3e580a99b0, heap=heap@entry=0x7f3e580a9e20, entry=entry@entry=0x7f3e580a94f8, trx_id=<optimized out>, thr=<optimized out>) at /data/src/10.3/storage/innobase/row/row0ins.cc:3118
      #9  0x0000556e512bff59 in row_ins_sec_index_entry (index=index@entry=0x7f3e58064258, entry=0x7f3e580a94f8, thr=thr@entry=0x7f3e58066ba8, check_foreign=<optimized out>) at /data/src/10.3/storage/innobase/row/row0ins.cc:3315
      #10 0x0000556e512f5df0 in row_upd_sec_index_entry (node=node@entry=0x7f3e58066850, thr=thr@entry=0x7f3e58066ba8) at /data/src/10.3/storage/innobase/row/row0upd.cc:2539
      #11 0x0000556e512fb586 in row_upd_sec_step (thr=0x7f3e58066ba8, node=0x7f3e58066850) at /data/src/10.3/storage/innobase/row/row0upd.cc:2566
      #12 row_upd (thr=0x7f3e58066ba8, node=0x7f3e58066850) at /data/src/10.3/storage/innobase/row/row0upd.cc:3336
      #13 row_upd_step (thr=thr@entry=0x7f3e58066ba8) at /data/src/10.3/storage/innobase/row/row0upd.cc:3451
      #14 0x0000556e512d052c in row_update_for_mysql (prebuilt=0x7f3e58065cf8) at /data/src/10.3/storage/innobase/row/row0mysql.cc:1888
      #15 0x0000556e51224c00 in ha_innobase::update_row (this=0x7f3e58070ed0, old_row=0x7f3e580648d8 "", new_row=0x7f3e580648b8 "\371\003") at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:8838
      #16 0x0000556e510bbc0b in handler::ha_update_row (this=0x7f3e58070ed0, old_data=0x7f3e580648d8 "", new_data=0x7f3e580648b8 "\371\003") at /data/src/10.3/sql/handler.cc:6479
      #17 0x0000556e50ebcc84 in write_record (thd=thd@entry=0x7f3e580009a8, table=table@entry=0x7f3e580702f8, info=info@entry=0x7f3ea0397c60) at /data/src/10.3/sql/sql_insert.cc:1953
      #18 0x0000556e50ec61c1 in mysql_insert (thd=thd@entry=0x7f3e580009a8, table_list=<optimized out>, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_REPLACE, ignore=false) at /data/src/10.3/sql/sql_insert.cc:1072
      #19 0x0000556e50eebcb5 in mysql_execute_command (thd=thd@entry=0x7f3e580009a8) at /data/src/10.3/sql/sql_parse.cc:4454
      #20 0x0000556e50ef04f9 in mysql_parse (thd=thd@entry=0x7f3e580009a8, rawbuf=<optimized out>, length=40, parser_state=parser_state@entry=0x7f3ea0399620, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.3/sql/sql_parse.cc:7817
      #21 0x0000556e50ef2d0d in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f3e580009a8, packet=packet@entry=0x7f3e580070c9 "REPLACE INTO t1 (a,b) VALUES (3,2),(3,2)", packet_length=packet_length@entry=40, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.3/sql/sql_parse.cc:1856
      #22 0x0000556e50ef3986 in do_command (thd=0x7f3e580009a8) at /data/src/10.3/sql/sql_parse.cc:1401
      #23 0x0000556e50fbadb4 in do_handle_one_connection (connect=connect@entry=0x556e530e95d8) at /data/src/10.3/sql/sql_connect.cc:1403
      #24 0x0000556e50fbae64 in handle_one_connection (arg=arg@entry=0x556e530e95d8) at /data/src/10.3/sql/sql_connect.cc:1308
      #25 0x0000556e51524744 in pfs_spawn_thread (arg=0x556e53085d98) at /data/src/10.3/storage/perfschema/pfs.cc:1869
      #26 0x00007f3ea8f564a4 in start_thread (arg=0x7f3ea039a700) at pthread_create.c:456
      #27 0x00007f3ea708ad0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
      

      10.3 debug 0fb84216

      2020-03-27 15:14:22 9 [ERROR] InnoDB: Record in index `row_start` of table `test`.`t1` was not found on update: TUPLE (info_bits=0, 2 fields): {[8]       '(0x0000000000000027),[6]      (0x000000000200)} at: COMPACT RECORD(info_bits=0, 2 fields): {[8]       $(0x0000000000000024),[6]      (0x000000000202)}
      mysqld: /data/src/10.3/storage/innobase/row/row0upd.cc:2442: dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*): Assertion `btr_validate_index(index, 0, false)' failed.
      200327 15:14:22 [ERROR] mysqld got signal 6 ;
       
      #6  0x00007f3739274e67 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x55a2928756d8 "btr_validate_index(index, 0, false)", file=file@entry=0x55a292875080 "/data/src/10.3/storage/innobase/row/row0upd.cc", line=line@entry=2442, function=function@entry=0x55a292877f40 <row_upd_sec_index_entry(upd_node_t*, que_thr_t*)::__PRETTY_FUNCTION__> "dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*)") at assert.c:92
      #7  0x00007f3739274f12 in __GI___assert_fail (assertion=0x55a2928756d8 "btr_validate_index(index, 0, false)", file=0x55a292875080 "/data/src/10.3/storage/innobase/row/row0upd.cc", line=2442, function=0x55a292877f40 <row_upd_sec_index_entry(upd_node_t*, que_thr_t*)::__PRETTY_FUNCTION__> "dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*)") at assert.c:101
      #8  0x000055a2920f9273 in row_upd_sec_index_entry (node=0x7f36e00a4bd0, thr=0x7f36e00a4f38) at /data/src/10.3/storage/innobase/row/row0upd.cc:2442
      #9  0x000055a2920f9c30 in row_upd_sec_step (node=0x7f36e00a4bd0, thr=0x7f36e00a4f38) at /data/src/10.3/storage/innobase/row/row0upd.cc:2566
      #10 0x000055a2920fc9f2 in row_upd (node=0x7f36e00a4bd0, thr=0x7f36e00a4f38) at /data/src/10.3/storage/innobase/row/row0upd.cc:3336
      #11 0x000055a2920fce3f in row_upd_step (thr=0x7f36e00a4f38) at /data/src/10.3/storage/innobase/row/row0upd.cc:3451
      #12 0x000055a29208e158 in row_update_for_mysql (prebuilt=0x7f36e00a4030) at /data/src/10.3/storage/innobase/row/row0mysql.cc:1888
      #13 0x000055a291ef7945 in ha_innobase::update_row (this=0x7f36e000a608, old_row=0x7f36e00a5d20 "\241\003", new_row=0x7f36e00a5d00 "\371\003") at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:8838
      #14 0x000055a291cd5660 in handler::ha_update_row (this=0x7f36e000a608, old_data=0x7f36e00a5d20 "\241\003", new_data=0x7f36e00a5d00 "\371\003") at /data/src/10.3/sql/handler.cc:6479
      #15 0x000055a29196c5b6 in write_record (thd=0x7f36e0000af0, table=0x7f36e00a33f0, info=0x7f372e5fbbb0) at /data/src/10.3/sql/sql_insert.cc:1953
      #16 0x000055a291969ade in mysql_insert (thd=0x7f36e0000af0, table_list=0x7f36e0012918, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_REPLACE, ignore=false) at /data/src/10.3/sql/sql_insert.cc:1072
      #17 0x000055a2919ad79f in mysql_execute_command (thd=0x7f36e0000af0) at /data/src/10.3/sql/sql_parse.cc:4454
      #18 0x000055a2919b907b in mysql_parse (thd=0x7f36e0000af0, rawbuf=0x7f36e0012818 "REPLACE INTO t1 (a,b) VALUES (3,2),(3,2)", length=40, parser_state=0x7f372e5fc5e0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7817
      #19 0x000055a2919a5c07 in dispatch_command (command=COM_QUERY, thd=0x7f36e0000af0, packet=0x7f36e0165511 "REPLACE INTO t1 (a,b) VALUES (3,2),(3,2)", packet_length=40, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1856
      #20 0x000055a2919a454f in do_command (thd=0x7f36e0000af0) at /data/src/10.3/sql/sql_parse.cc:1401
      #21 0x000055a291b1c0c8 in do_handle_one_connection (connect=0x55a29417adc0) at /data/src/10.3/sql/sql_connect.cc:1403
      #22 0x000055a291b1be2a in handle_one_connection (arg=0x55a29417adc0) at /data/src/10.3/sql/sql_connect.cc:1308
      #23 0x000055a2924cc36a in pfs_spawn_thread (arg=0x55a294195e70) at /data/src/10.3/storage/perfschema/pfs.cc:1869
      #24 0x00007f373b1fd4a4 in start_thread (arg=0x7f372e5fd700) at pthread_create.c:456
      #25 0x00007f3739331d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
      

      The debug version is slightly different on 10.4+:

      10.4 debug ba679ae5

       2 fields): {[8]       '(0x0000000000000027),[6]      (0x000000000200)} at: COMPACT RECORD(info_bits=0, 2 fields): {[8]       $(0x0000000000000024),[6]      (0x000000000202)}
      mysqld: /data/src/10.4/storage/innobase/row/row0upd.cc:2422: dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*): Assertion `btr_validate_index(index, 0)' failed.
      200327 15:20:17 [ERROR] mysqld got signal 6 ;
       
      #6  0x00007fcac1999e67 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x55d8078e3a0d "btr_validate_index(index, 0)", file=file@entry=0x55d8078e3270 "/data/src/10.4/storage/innobase/row/row0upd.cc", line=line@entry=2422, function=function@entry=0x55d8078e60e0 <row_upd_sec_index_entry(upd_node_t*, que_thr_t*)::__PRETTY_FUNCTION__> "dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*)") at assert.c:92
      #7  0x00007fcac1999f12 in __GI___assert_fail (assertion=0x55d8078e3a0d "btr_validate_index(index, 0)", file=0x55d8078e3270 "/data/src/10.4/storage/innobase/row/row0upd.cc", line=2422, function=0x55d8078e60e0 <row_upd_sec_index_entry(upd_node_t*, que_thr_t*)::__PRETTY_FUNCTION__> "dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*)") at assert.c:101
      #8  0x000055d8070e9719 in row_upd_sec_index_entry (node=0x7fca6818a648, thr=0x7fca6818a9b0) at /data/src/10.4/storage/innobase/row/row0upd.cc:2422
      #9  0x000055d8070ea0c1 in row_upd_sec_step (node=0x7fca6818a648, thr=0x7fca6818a9b0) at /data/src/10.4/storage/innobase/row/row0upd.cc:2546
      #10 0x000055d8070ed0e2 in row_upd (node=0x7fca6818a648, thr=0x7fca6818a9b0) at /data/src/10.4/storage/innobase/row/row0upd.cc:3327
      #11 0x000055d8070ed528 in row_upd_step (thr=0x7fca6818a9b0) at /data/src/10.4/storage/innobase/row/row0upd.cc:3442
      #12 0x000055d807088e63 in row_update_for_mysql (prebuilt=0x7fca68189aa0) at /data/src/10.4/storage/innobase/row/row0mysql.cc:1889
      #13 0x000055d806ee4464 in ha_innobase::update_row (this=0x7fca681892a8, old_row=0x7fca6800b430 "\241\003", new_row=0x7fca6800b410 "\371\003") at /data/src/10.4/storage/innobase/handler/ha_innodb.cc:8830
      #14 0x000055d806ca461a in handler::ha_update_row (this=0x7fca681892a8, old_data=0x7fca6800b430 "\241\003", new_data=0x7fca6800b410 "\371\003") at /data/src/10.4/sql/handler.cc:6722
      #15 0x000055d8068e8b83 in write_record (thd=0x7fca68000af0, table=0x7fca6800a5a0, info=0x7fcabc143490) at /data/src/10.4/sql/sql_insert.cc:1976
      #16 0x000055d8068e5f01 in mysql_insert (thd=0x7fca68000af0, table_list=0x7fca68013298, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_REPLACE, ignore=false) at /data/src/10.4/sql/sql_insert.cc:1078
      #17 0x000055d806934467 in mysql_execute_command (thd=0x7fca68000af0) at /data/src/10.4/sql/sql_parse.cc:4528
      #18 0x000055d806940bf1 in mysql_parse (thd=0x7fca68000af0, rawbuf=0x7fca68013198 "REPLACE INTO t1 (a,b) VALUES (3,2),(3,2)", length=40, parser_state=0x7fcabc144160, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7900
      #19 0x000055d80692bdc0 in dispatch_command (command=COM_QUERY, thd=0x7fca68000af0, packet=0x7fca68137141 "REPLACE INTO t1 (a,b) VALUES (3,2),(3,2)", packet_length=40, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1842
      #20 0x000055d80692a44d in do_command (thd=0x7fca68000af0) at /data/src/10.4/sql/sql_parse.cc:1360
      #21 0x000055d806ab39b3 in do_handle_one_connection (connect=0x55d80a24f170) at /data/src/10.4/sql/sql_connect.cc:1412
      #22 0x000055d806ab3702 in handle_one_connection (arg=0x55d80a24f170) at /data/src/10.4/sql/sql_connect.cc:1316
      #23 0x000055d8074bc0a1 in pfs_spawn_thread (arg=0x55d80a5ab770) at /data/src/10.4/storage/perfschema/pfs.cc:1869
      #24 0x00007fcac39224a4 in start_thread (arg=0x7fcabc145700) at pthread_create.c:456
      #25 0x00007fcac1a56d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
      

      Reproducible on 10.3-10.5.
      The test case is not applicable to previous versions.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              midenok Aleksey Midenkov
              Reporter:
              elenst Elena Stepanova
              Votes:
              1 Vote for this issue
              Watchers:
              6 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: