[MDEV-18153] Assertion `0' or Assertion `btr_validate_index(index, 0)' failed in row_upd_sec_index_entry or error code 126: Index is corrupted upon UPDATE with TIME_ROUND_FRACTIONAL Created: 2019-01-06  Updated: 2019-10-06  Resolved: 2019-09-18

Status: Closed
Project: MariaDB Server
Component/s: Temporal Types, Virtual Columns
Affects Version/s: 10.4
Fix Version/s: 10.4.9

Type: Bug Priority: Critical
Reporter: Elena Stepanova Assignee: Alexander Barkov
Resolution: Fixed Votes: 0
Labels: affects-tests

Issue Links:
Blocks
is blocked by MDEV-20397 Support TIMESTAMP, DATETIME, TIME in ... Closed
Relates
relates to MDEV-18156 Assertion `0' failed or `btr_validate... Closed
relates to MDEV-20403 Assertion `0' or Assertion `btr_valid... Closed
relates to MDEV-17890 Server crash on DELETE with YEAR fiel... Closed
relates to MDEV-20610 Assertion failed or btr_validate_inde... Confirmed
relates to MDEV-20618 Assertion `btr_validate_index(index, ... Closed
relates to MDEV-20763 Table corruption or Assertion `btr_va... Closed

 Description   

See MDEV-18156 for very similar failures with different SQL_MODE on 10.2+.
The InnoDB part is also similar to MDEV-17890.

CREATE TABLE t1 ( 
  t TIMESTAMP(4),
 
  d DATETIME,
 
  v TIMESTAMP(3) AS (t) VIRTUAL,
 
  KEY(v,d)
 
);
 
 
 
INSERT IGNORE INTO t1 (t,d) VALUES ('2006-03-01 12:44:34.0496','2029-10-10 21:27:53');
 
 
 
SET SQL_MODE= 'TIME_ROUND_FRACTIONAL';
 
UPDATE IGNORE t1 SET d = NOW();
 
 
 
# Cleanup
 
DROP TABLE t1;

With MyISAM, the test case produces an error:

10.4 2465d3e00b2

 
query 'UPDATE IGNORE t1 SET d = NOW()' failed: 126: Index for table './test/t1.MYI' is corrupt; try to repair it

With InnoDB, there is a different error:

10.4 2465d3e00b2

 
2019-01-06 17:46:39 9 [ERROR] InnoDB: Record in index `v` of table `test`.`t1` was not found on update: TUPLE (info_bits=0, 3 fields): {[6]D {   (0x44057B1201F4),[5]   V (0x99C4D556F5),[6]      (0x000000000200)} at: COMPACT RECORD(info_bits=0, 3 fields): {[6]D {   (0x44057B1201EA),[5]   V (0x99C4D556F5),[6]      (0x000000000200)}

Which on a debug build is followed by an assertion failure:

mysqld: /data/src/10.4/storage/innobase/row/row0upd.cc:2426: dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*): Assertion `0' failed.
 
190106 17:46:39 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007f1c167b1ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
 
#8  0x00005625c5e2d1d3 in row_upd_sec_index_entry (node=0x7f1bb816d7b8, thr=0x7f1bb80723f8) at /data/src/10.4/storage/innobase/row/row0upd.cc:2426
 
#9  0x00005625c5e2d8a6 in row_upd_sec_step (node=0x7f1bb816d7b8, thr=0x7f1bb80723f8) at /data/src/10.4/storage/innobase/row/row0upd.cc:2539
 
#10 0x00005625c5e30271 in row_upd (node=0x7f1bb816d7b8, thr=0x7f1bb80723f8) at /data/src/10.4/storage/innobase/row/row0upd.cc:3317
 
#11 0x00005625c5e305d9 in row_upd_step (thr=0x7f1bb80723f8) at /data/src/10.4/storage/innobase/row/row0upd.cc:3432
 
#12 0x00005625c5dde726 in row_update_for_mysql (prebuilt=0x7f1bb816cc88) at /data/src/10.4/storage/innobase/row/row0mysql.cc:1889
 
#13 0x00005625c5c7b518 in ha_innobase::update_row (this=0x7f1bb8132d78, old_row=0x7f1bb800a9b8 "\371D\005{\022\001\360\231\304\325V\365D\005{\022\001\364\245\245\245\245\245\245\360\251", new_row=0x7f1bb800a9a0 "\371\\2\"\337\036\221\231\242\r\033\247D\005{\022\001\364\245\245\245\245\245\245\371D\005{\022\001\360\231\304\325V\365D\005{\022\001\364\245\245\245\245\245\245\360\251") at /data/src/10.4/storage/innobase/handler/ha_innodb.cc:8842
 
#14 0x00005625c5953deb in handler::ha_update_row (this=0x7f1bb8132d78, old_data=0x7f1bb800a9b8 "\371D\005{\022\001\360\231\304\325V\365D\005{\022\001\364\245\245\245\245\245\245\360\251", new_data=0x7f1bb800a9a0 "\371\\2\"\337\036\221\231\242\r\033\247D\005{\022\001\364\245\245\245\245\245\245\371D\005{\022\001\360\231\304\325V\365D\005{\022\001\364\245\245\245\245\245\245\360\251") at /data/src/10.4/sql/handler.cc:6305
 
#15 0x00005625c5730cb0 in mysql_update (thd=0x7f1bb8000b00, table_list=0x7f1bb8015080, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=18446744073709551615, handle_duplicates=DUP_ERROR, ignore=true, found_return=0x7f1c10341f20, updated_return=0x7f1c10341fe0) at /data/src/10.4/sql/sql_update.cc:947
 
#16 0x00005625c5635f08 in mysql_execute_command (thd=0x7f1bb8000b00) at /data/src/10.4/sql/sql_parse.cc:4584
 
#17 0x00005625c5641244 in mysql_parse (thd=0x7f1bb8000b00, rawbuf=0x7f1bb8014f98 "UPDATE IGNORE t1 SET d = NOW()", length=30, parser_state=0x7f1c10342600, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104
 
#18 0x00005625c562e46e in dispatch_command (command=COM_QUERY, thd=0x7f1bb8000b00, packet=0x7f1bb8137fd1 "UPDATE IGNORE t1 SET d = NOW()", packet_length=30, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851
 
#19 0x00005625c562ce92 in do_command (thd=0x7f1bb8000b00) at /data/src/10.4/sql/sql_parse.cc:1396
 
#20 0x00005625c57990ba in do_handle_one_connection (connect=0x5625c7f84be0) at /data/src/10.4/sql/sql_connect.cc:1402
 
#21 0x00005625c5798e3e in handle_one_connection (arg=0x5625c7f84be0) at /data/src/10.4/sql/sql_connect.cc:1308
 
#22 0x00005625c5c58164 in pfs_spawn_thread (arg=0x5625c7f7fb80) at /data/src/10.4/storage/perfschema/pfs.cc:1862
 
#23 0x00007f1c1826d494 in start_thread (arg=0x7f1c10343700) at pthread_create.c:333
 
#24 0x00007f1c1686e93f in clone () from /lib/x86_64-linux-gnu/libc.so.6



 Comments   
Comment by Elena Stepanova [ 2019-05-08 ]

On 10.4 fd386e39 the failing assertion is different:

10.4 fd386e39

 
2019-05-08 19:58:24 9 [ERROR] InnoDB: Record in index `v` of table `test`.`t1` was not found on update: TUPLE (info_bits=0, 3 fields): {[6]D {   (0x44057B1201F4),[5]   V (0x99C4D556F5),[6]      (0x000000000200)} at: COMPACT RECORD(info_bits=0, 3 fields): {[6]D {   (0x44057B1201EA),[5]   V (0x99C4D556F5),[6]      (0x000000000200)}
 
mysqld: /data/src/10.4/storage/innobase/row/row0upd.cc:2429: dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*): Assertion `btr_validate_index(index, 0)' failed.
 
 
 
#6  0x00007f8b80a7de67 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x55d3f05eac25 "btr_validate_index(index, 0)", file=file@entry=0x55d3f05ea4e0 "/data/src/10.4/storage/innobase/row/row0upd.cc", line=line@entry=2429, function=function@entry=0x55d3f05ed340 <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  0x00007f8b80a7df12 in __GI___assert_fail (assertion=0x55d3f05eac25 "btr_validate_index(index, 0)", file=0x55d3f05ea4e0 "/data/src/10.4/storage/innobase/row/row0upd.cc", line=2429, function=0x55d3f05ed340 <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  0x000055d3efe91b67 in row_upd_sec_index_entry (node=0x7f8b2c1507a0, thr=0x7f8b2c06b348) at /data/src/10.4/storage/innobase/row/row0upd.cc:2429
 
#9  0x000055d3efe9226b in row_upd_sec_step (node=0x7f8b2c1507a0, thr=0x7f8b2c06b348) at /data/src/10.4/storage/innobase/row/row0upd.cc:2543
 
#10 0x000055d3efe94c25 in row_upd (node=0x7f8b2c1507a0, thr=0x7f8b2c06b348) at /data/src/10.4/storage/innobase/row/row0upd.cc:3319
 
#11 0x000055d3efe94f8c in row_upd_step (thr=0x7f8b2c06b348) at /data/src/10.4/storage/innobase/row/row0upd.cc:3434
 
#12 0x000055d3efe44f02 in row_update_for_mysql (prebuilt=0x7f8b2c14fc68) at /data/src/10.4/storage/innobase/row/row0mysql.cc:1890
 
#13 0x000055d3efcdbffc in ha_innobase::update_row (this=0x7f8b2c00b368, old_row=0x7f8b2c1a2568 "\371D\005{\022\001\360\231\304\325V\365D\005{\022\001\364\245\245\245\245\245\245\240%\032,\213\177", new_row=0x7f8b2c1a2550 "\371\\\323\n\260\033\005\231\243\021>\230D\005{\022\001\364\245\245\245\245\245\245\371D\005{\022\001\360\231\304\325V\365D\005{\022\001\364\245\245\245\245\245\245\240%\032,\213\177") at /data/src/10.4/storage/innobase/handler/ha_innodb.cc:8882
 
#14 0x000055d3efabab85 in handler::ha_update_row (this=0x7f8b2c00b368, old_data=0x7f8b2c1a2568 "\371D\005{\022\001\360\231\304\325V\365D\005{\022\001\364\245\245\245\245\245\245\240%\032,\213\177", new_data=0x7f8b2c1a2550 "\371\\\323\n\260\033\005\231\243\021>\230D\005{\022\001\364\245\245\245\245\245\245\371D\005{\022\001\360\231\304\325V\365D\005{\022\001\364\245\245\245\245\245\245\240%\032,\213\177") at /data/src/10.4/sql/handler.cc:6610
 
#15 0x000055d3ef87892c in mysql_update (thd=0x7f8b2c000b00, table_list=0x7f8b2c0131e0, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=18446744073709551615, ignore=true, found_return=0x7f8b75e2d850, updated_return=0x7f8b75e2d910) at /data/src/10.4/sql/sql_update.cc:1040
 
#16 0x000055d3ef77596b in mysql_execute_command (thd=0x7f8b2c000b00) at /data/src/10.4/sql/sql_parse.cc:4644
 
#17 0x000055d3ef781f4b in mysql_parse (thd=0x7f8b2c000b00, rawbuf=0x7f8b2c0130f8 "UPDATE IGNORE t1 SET d = NOW()", length=30, parser_state=0x7f8b75e2e180, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8150
 
#18 0x000055d3ef76d637 in dispatch_command (command=COM_QUERY, thd=0x7f8b2c000b00, packet=0x7f8b2c137eb1 "UPDATE IGNORE t1 SET d = NOW()", packet_length=30, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1829
 
#19 0x000055d3ef76bdf7 in do_command (thd=0x7f8b2c000b00) at /data/src/10.4/sql/sql_parse.cc:1362
 
#20 0x000055d3ef8e38bf in do_handle_one_connection (connect=0x55d3f23d6140) at /data/src/10.4/sql/sql_connect.cc:1398
 
#21 0x000055d3ef8e3623 in handle_one_connection (arg=0x55d3f23d6140) at /data/src/10.4/sql/sql_connect.cc:1301
 
#22 0x000055d3f020b115 in pfs_spawn_thread (arg=0x55d3f2354ae0) at /data/src/10.4/storage/perfschema/pfs.cc:1862
 
#23 0x00007f8b825f24a4 in start_thread (arg=0x7f8b75e2f700) at pthread_create.c:456
 
#24 0x00007f8b80b3ad0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Comment by Elena Stepanova [ 2019-07-26 ]

Extension of the same test case also produces

10.4 e9c1701e

 
2019-07-27  0:40:38 4 [ERROR] mysqld: Table './test/t1' is marked as crashed and should be repaired


CREATE TABLE t1 ( 
  t TIMESTAMP(4),
 
  d DATETIME,
 
  v TIMESTAMP(3) AS (t) VIRTUAL,
 
  KEY(v,d)
 
);
 
 
INSERT IGNORE INTO t1 (t,d) VALUES ('2006-03-01 12:44:34.0496','2029-10-10 21:27:53');
 
 
SET SQL_MODE= 'TIME_ROUND_FRACTIONAL';
 
--error 126
 
UPDATE IGNORE t1 SET d = NOW();
 
FLUSH TABLES;
 
SELECT * FROM t1;
 
 
# Cleanup
 
DROP TABLE t1;

Comment by Alexander Barkov [ 2019-08-22 ]

It's also repeatable if the column 't' has a default clause rather than an automatically add ON UPDATE:

SET SQL_MODE= DEFAULT;
 
CREATE OR REPLACE TABLE t1 ( 
  t TIMESTAMP(4) DEFAULT '2001-01-01 00:00:00',
 
  d DATETIME,
 
  v TIMESTAMP(3) AS (t) VIRTUAL,
 
  KEY(v,d)
 
);
 
INSERT IGNORE INTO t1 (t,d) VALUES ('2006-03-01 12:44:34.0496','2029-10-10 21:27:53');
 
SET SQL_MODE= 'TIME_ROUND_FRACTIONAL';
 
UPDATE IGNORE t1 SET d = NOW();
 
DROP TABLE t1;

Note, if I change AS (t) to AS (TRUNCATE(t,3)), to get rid of the dependency on the TIME_ROUND_FRACTIONAL flag in sql_mode, the crash goes away:

SET SQL_MODE= DEFAULT;
 
CREATE OR REPLACE TABLE t1 ( 
  t TIMESTAMP(4) DEFAULT '2001-01-01 00:00:00',
 
  d DATETIME,
 
  v TIMESTAMP(3) AS (TRUNCATE(t,3)) VIRTUAL,
 
  KEY(v,d)
 
);
 
INSERT IGNORE INTO t1 (t,d) VALUES ('2006-03-01 12:44:34.0496','2029-10-10 21:27:53');
 
SET SQL_MODE= 'TIME_ROUND_FRACTIONAL';
 
UPDATE IGNORE t1 SET d = NOW();
 
DROP TABLE t1;

Comment by Alexander Barkov [ 2019-08-22 ]

The problem is also repeatable with MyISAM. It does not crash, but it reports a corrupted index:

SET SQL_MODE= DEFAULT;
 
CREATE OR REPLACE TABLE t1 ( 
  t TIMESTAMP(4) DEFAULT '2001-01-01 00:00:00',
 
  d DATETIME,
 
  v TIMESTAMP(3) AS (t) VIRTUAL,
 
  KEY(v,d)
 
) ENGINE=MyISAM;
 
INSERT IGNORE INTO t1 (t,d) VALUES ('2006-03-01 12:44:34.0496','2029-10-10 21:27:53');
 
SET SQL_MODE= 'TIME_ROUND_FRACTIONAL';
 
UPDATE IGNORE t1 SET d = NOW();


ERROR 126 (HY000): Index for table './test/t1.MYI' is corrupt; try to repair it

Again, like with InnoDB, changing the AS clause to TRUNCATE(t,3) fixes the problem: the error goes away:

SET SQL_MODE= DEFAULT;
 
CREATE OR REPLACE TABLE t1 ( 
  t TIMESTAMP(4) DEFAULT '2001-01-01 00:00:00',
 
  d DATETIME,
 
  v TIMESTAMP(3) AS (TRUNCATE(t,3)) VIRTUAL,
 
  KEY(v,d)
 
) ENGINE=MyISAM;
 
INSERT IGNORE INTO t1 (t,d) VALUES ('2006-03-01 12:44:34.0496','2029-10-10 21:27:53');
 
SET SQL_MODE= 'TIME_ROUND_FRACTIONAL';
 
UPDATE IGNORE t1 SET d = NOW();
 
DROP TABLE t1;

Comment by Alexander Barkov [ 2019-08-23 ]

The problem is also repeatable with TIME:

DROP TABLE IF EXISTS t1;
 
SET sql_mode=DEFAULT;
 
CREATE TABLE t1 ( 
  t TIME(4),
 
  d TIME,
 
  v TIME(3) AS (t) VIRTUAL,
 
  KEY(v,d)
 
);
 
INSERT IGNORE INTO t1 (t,d) VALUES ('12:44:34.0496','21:27:53');
 
SELECT * FROM t1;
 
SET SQL_MODE= 'TIME_ROUND_FRACTIONAL';
 
UPDATE IGNORE t1 SET d = CURRENT_TIME;
 
DROP TABLE t1;
 
SET sql_mode=DEFAULT;

Comment by Alexander Barkov [ 2019-08-23 ]

Please review the patch:
https://github.com/MariaDB/server/commit/af696410c4ea916e31328e8f86d8d0c9a4bf2ac7

Comment by Alexander Barkov [ 2019-08-23 ]

Will recommit the patch.

Comment by Alexander Barkov [ 2019-08-23 ]

Please review an improved version:

https://github.com/MariaDB/server/commit/39259d0bf55d1ff8b6bfd98a2a155a30ee7827d1

Comment by Alexander Barkov [ 2019-08-26 ]

The patch will possibly change after the fix for MDEV-18153 propagates to 10.4.
Cancelling the review request.

Generated at Thu Feb 08 08:41:53 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.