[MDEV-18156] Assertion `0' failed or `btr_validate_index(index, 0, false)' in row_upd_sec_index_entry or error code 126: Index is corrupted upon DELETE with PAD_CHAR_TO_FULL_LENGTH Created: 2019-01-06  Updated: 2022-11-15  Resolved: 2019-09-03

Status: Closed
Project: MariaDB Server
Component/s: Data types, Virtual Columns
Affects Version/s: 10.2, 10.3, 10.4
Fix Version/s: 10.2.27, 10.3.18, 10.4.8, 10.5.0

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

Issue Links:
Relates
relates to MDEV-17890 Server crash on DELETE with YEAR fiel... Closed
relates to MDEV-20423 Assertion `0' failed or `btr_validate... Closed
relates to MDEV-20472 Document MDEV-18156 - sql_mode depend... Closed
relates to MDEV-18153 Assertion `0' or Assertion `btr_valid... 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
relates to MDEV-28190 sql_mode makes MDEV-371 virtual colum... Closed
relates to MDEV-29777 Unable to create stored generated col... Closed

 Description   

Note: It might well be a duplicate of MDEV-18153, the results are exactly the same, but it's a different SQL_MODE (and thus different affected versions), and different table structures, so I'm filing it separately just in case.

CREATE TABLE t1 (c CHAR(8), v BINARY(8) AS (c), KEY(v));
 
INSERT INTO t1 (c) VALUES ('foo') ;
 
 
 
SET SQL_MODE= 'PAD_CHAR_TO_FULL_LENGTH';
 
DELETE FROM t1 WHERE c <> 'bar';
 
 
 
# Cleanup
 
DROP TABLE t1;

10.2 0c20b247de with MyISAM

 
mysqltest: At line 5: query 'DELETE FROM t1 WHERE c <> 'bar'' failed: 126: Index for table './test/t1.MYI' is corrupt; try to repair it

10.2 debug 0c20b247de with InnoDB

 
2019-01-06 22:02:13 140655082366720 [ERROR] InnoDB: Record in index `v` of table `test`.`t1` was not found on update: TUPLE (info_bits=0, 2 fields): {[8]foo     (0x666F6F2020202020),[6]      (0x000000000200)} at: COMPACT RECORD(info_bits=0, 2 fields): {[8]foo     (0x666F6F0000000000),[6]      (0x000000000200)}
 
mysqld: /data/src/10.2/storage/innobase/row/row0upd.cc:2436: dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*): Assertion `0' failed.
 
190106 22:02:13 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007fecd7f19ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
 
#8  0x000055bf73ba59bb in row_upd_sec_index_entry (node=0x7fec88136de0, thr=0x7fec880848a8) at /data/src/10.2/storage/innobase/row/row0upd.cc:2436
 
#9  0x000055bf73ba6031 in row_upd_sec_step (node=0x7fec88136de0, thr=0x7fec880848a8) at /data/src/10.2/storage/innobase/row/row0upd.cc:2549
 
#10 0x000055bf73ba82b2 in row_upd (node=0x7fec88136de0, thr=0x7fec880848a8) at /data/src/10.2/storage/innobase/row/row0upd.cc:3308
 
#11 0x000055bf73ba8603 in row_upd_step (thr=0x7fec880848a8) at /data/src/10.2/storage/innobase/row/row0upd.cc:3425
 
#12 0x000055bf73b4ec37 in row_update_for_mysql (prebuilt=0x7fec881362d8) at /data/src/10.2/storage/innobase/row/row0mysql.cc:1830
 
#13 0x000055bf73a1536b in ha_innobase::delete_row (this=0x7fec88135498, record=0x7fec880311d0 "\371foo     foo     ", '\245' <repeats 31 times>, "\030\022\003\210\354\177") at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:9098
 
#14 0x000055bf73709360 in handler::ha_delete_row (this=0x7fec88135498, buf=0x7fec880311d0 "\371foo     foo     ", '\245' <repeats 31 times>, "\030\022\003\210\354\177") at /data/src/10.2/sql/handler.cc:6021
 
#15 0x000055bf73898cb4 in mysql_delete (thd=0x7fec88000b00, table_list=0x7fec88012530, conds=0x7fec88012ce8, order_list=0x7fec88005078, limit=18446744073709551615, options=0, result=0x0) at /data/src/10.2/sql/sql_delete.cc:583
 
#16 0x000055bf73484616 in mysql_execute_command (thd=0x7fec88000b00) at /data/src/10.2/sql/sql_parse.cc:4636
 
#17 0x000055bf7348ef51 in mysql_parse (thd=0x7fec88000b00, rawbuf=0x7fec88012448 "DELETE FROM t1 WHERE c <> 'bar'", length=31, parser_state=0x7fecd0385200, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:8015
 
#18 0x000055bf7347c88b in dispatch_command (command=COM_QUERY, thd=0x7fec88000b00, packet=0x7fec88096261 "DELETE FROM t1 WHERE c <> 'bar'", packet_length=31, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1826
 
#19 0x000055bf7347b1e2 in do_command (thd=0x7fec88000b00) at /data/src/10.2/sql/sql_parse.cc:1379
 
#20 0x000055bf735cdccd in do_handle_one_connection (connect=0x55bf772692d0) at /data/src/10.2/sql/sql_connect.cc:1335
 
#21 0x000055bf735cda5a in handle_one_connection (arg=0x55bf772692d0) at /data/src/10.2/sql/sql_connect.cc:1241
 
#22 0x000055bf739f397c in pfs_spawn_thread (arg=0x55bf771af6d0) at /data/src/10.2/storage/perfschema/pfs.cc:1862
 
#23 0x00007fecd9bf0494 in start_thread (arg=0x7fecd0386700) at pthread_create.c:333
 
#24 0x00007fecd7fd693f in clone () from /lib/x86_64-linux-gnu/libc.so.6

10.2 non-debug 0c20b247de with InnoDB

 
2019-01-06 22:03:36 140321956206336 [ERROR] InnoDB: Record in index `v` of table `test`.`t1` was not found on update: TUPLE (info_bits=0, 2 fields): {[8]foo     (0x666F6F2020202020),[6]      (0x000000000200)} at: COMPACT RECORD(info_bits=0, 2 fields): {[8]foo     (0x666F6F0000000000),[6]      (0x000000000200)}



 Comments   
Comment by Alexander Barkov [ 2019-02-18 ]

The problem happens because after changing sql_mode, the value of the column 'v' changes from CONCAT('bar',0x0000000000) to CONCAT('bar', 0x2020202020).
The engine then notices that the index value does not match to the column value and reports an index corruption.

This script demonstrates the difference:

SET SQL_MODE='';
 
CREATE OR REPLACE TABLE t1 (c CHAR(8), v BINARY(8) AS (c), KEY(v));
 
INSERT INTO t1 (c) VALUES ('foo');
 
SELECT HEX(CAST(c AS BINARY(8))) AS nopad FROM t1;
 
SET SQL_MODE= 'PAD_CHAR_TO_FULL_LENGTH';
 
SELECT HEX(CAST(c AS BINARY(8))) AS pad FROM t1;


+------------------+
 
| nopad            |
 
+------------------+
 
| 666F6F0000000000 |
 
+------------------+


+------------------+
 
| pad              |
 
+------------------+
 
| 666F6F2020202020 |
 
+------------------+

A possible solution would be to disallow CHAR columns inside virtual column expressions.

Comment by Elena Stepanova [ 2019-05-25 ]

This one now also causes btr_validate_index assertion (with InnoDB):

10.3 592dc59d

 
2019-05-26  2:01:41 9 [ERROR] InnoDB: Record in index `v` of table `test`.`t1` was not found on update: TUPLE (info_bits=0, 2 fields): {[8]foo     (0x666F6F2020202020),[6]      (0x000000000200)} at: COMPACT RECORD(info_bits=0, 2 fields): {[8]foo     (0x666F6F0000000000),[6]      (0x000000000200)}
 
mysqld: /data/src/10.3/storage/innobase/row/row0upd.cc:2449: dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*): Assertion `btr_validate_index(index, 0, false)' failed.
 
190526  2:01:41 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007fc65ff3ef12 in __GI___assert_fail (assertion=0x55cb3b1e7aa0 "btr_validate_index(index, 0, false)", file=0x55cb3b1e7498 "/data/src/10.3/storage/innobase/row/row0upd.cc", line=2449, function=0x55cb3b1ea3a0 <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  0x000055cb3aaf5244 in row_upd_sec_index_entry (node=0x7fc6080a75e0, thr=0x7fc608181458) at /data/src/10.3/storage/innobase/row/row0upd.cc:2449
 
#9  0x000055cb3aaf5956 in row_upd_sec_step (node=0x7fc6080a75e0, thr=0x7fc608181458) at /data/src/10.3/storage/innobase/row/row0upd.cc:2563
 
#10 0x000055cb3aaf8127 in row_upd (node=0x7fc6080a75e0, thr=0x7fc608181458) at /data/src/10.3/storage/innobase/row/row0upd.cc:3328
 
#11 0x000055cb3aaf8495 in row_upd_step (thr=0x7fc608181458) at /data/src/10.3/storage/innobase/row/row0upd.cc:3443
 
#12 0x000055cb3aa9cbc4 in row_update_for_mysql (prebuilt=0x7fc6080a6af8) at /data/src/10.3/storage/innobase/row/row0mysql.cc:1887
 
#13 0x000055cb3a942e29 in ha_innobase::delete_row (this=0x7fc6080a5c68, record=0x7fc608008290 "\371foo     foo     ", '\245' <repeats 31 times>, "\330\202") at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:8999
 
#14 0x000055cb3a73b6ac in handler::ha_delete_row (this=0x7fc6080a5c68, buf=0x7fc608008290 "\371foo     foo     ", '\245' <repeats 31 times>, "\330\202") at /data/src/10.3/sql/handler.cc:6508
 
#15 0x000055cb3a8cea89 in TABLE::delete_row (this=0x7fc60800a5e0) at /data/src/10.3/sql/sql_delete.cc:253
 
#16 0x000055cb3a8cbdec in mysql_delete (thd=0x7fc608000b00, table_list=0x7fc6080128f0, conds=0x7fc6080130f8, order_list=0x7fc6080053b8, limit=18446744073709551615, options=0, result=0x0) at /data/src/10.3/sql/sql_delete.cc:747
 
#17 0x000055cb3a43558d in mysql_execute_command (thd=0x7fc608000b00) at /data/src/10.3/sql/sql_parse.cc:4931
 
#18 0x000055cb3a43f8d8 in mysql_parse (thd=0x7fc608000b00, rawbuf=0x7fc608012808 "DELETE FROM t1 WHERE c <> 'bar'", length=31, parser_state=0x7fc6592dc5f0, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:8098
 
#19 0x000055cb3a42c91a in dispatch_command (command=COM_QUERY, thd=0x7fc608000b00, packet=0x7fc60815fe71 "DELETE FROM t1 WHERE c <> 'bar'", packet_length=31, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1858
 
#20 0x000055cb3a42b33d in do_command (thd=0x7fc608000b00) at /data/src/10.3/sql/sql_parse.cc:1403
 
#21 0x000055cb3a59356b in do_handle_one_connection (connect=0x55cb3c9bd450) at /data/src/10.3/sql/sql_connect.cc:1402
 
#22 0x000055cb3a5932e2 in handle_one_connection (arg=0x55cb3c9bd450) at /data/src/10.3/sql/sql_connect.cc:1308
 
#23 0x000055cb3ae6aa8c in pfs_spawn_thread (arg=0x55cb3c900ab0) at /data/src/10.3/storage/perfschema/pfs.cc:1862
 
#24 0x00007fc661ab34a4 in start_thread (arg=0x7fc6592dd700) at pthread_create.c:456
 
#25 0x00007fc65fffbd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Comment by Alexander Barkov [ 2019-08-23 ]

A similar crash happens with the NO_UNSIGNED_SUBTRACTION flag change:

SET sql_mode=NO_UNSIGNED_SUBTRACTION;
 
CREATE OR REPLACE TABLE t1 (
 
  a INT UNSIGNED,
 
  b INT UNSIGNED,
 
  c INT GENERATED ALWAYS AS (a-b) VIRTUAL,
 
  KEY (c)
 
);
 
INSERT IGNORE INTO t1 (a,b) VALUES (1,2);
 
SELECT * FROM t1;
 
SET sql_mode='';
 
FLUSH TABLES;
 
SELECT * FROM t1;
 
UPDATE t1 SET a=3;

Comment by Alexander Barkov [ 2019-08-23 ]

A similar crash happens with TIME_ROUND_FRACTIONAL. See MDEV-20423.

Comment by Alexander Barkov [ 2019-08-26 ]

Please review a patch:
https://github.com/MariaDB/server/commit/5f1cd8fe7a5bb3bba7e00791943c3ebf8e3c341b

Comment by Alexander Barkov [ 2019-08-28 ]

serg, please review a new version:
https://github.com/MariaDB/server/commit/e4415549e5374f6fcb5d317a7078ead610adfa6c

Comment by Sergei Golubchik [ 2019-08-28 ]

This patch is good, basically ok to push. But it makes old tables unreadable (an error when a table is opened).

We need some reasonable user-friendly behavior on upgrades. In a separate patch, yes. But both have to be pushed together, otherwise we risk that the first patch will be released alone and the second patch won't make it.

Comment by Alexander Barkov [ 2019-08-29 ]

serg, please find an additional patch here:
https://github.com/MariaDB/server/commit/899c0b3ec6e609e34b217e1f35e3c07a901e4a92

It allows to open old tables for most purposes, only creation of "bad" virtual fields is now disallowed.

Note, automatic fixing, like adding RTRIM()/RPAD(), is not implemented yet.

Thanks.

Comment by Sergei Golubchik [ 2019-08-30 ]

ok to push

Comment by Elena Stepanova [ 2020-08-11 ]

For the record, despite having a long history, I think it ended up only fixed in 10.5, as the fix wasn't acceptable for post-GA versions. But there were several commits in all branches, so I'm not sure what is the correct value for fixVersion.

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