Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
5.5.37, 10.0.11, 10.1.0, 10.2.0, 10.3.0, 10.4.0
Description
Note: Possibly it is related to the numerous existing bugs known as "MDEV-9663 family" or MDEV-14643 family". But there have been false relations before, I don't want to pollute the bug reports any further, so I'm filing this one separately. If you find a true relation, feel free to close this one as a duplicate.
--source include/have_innodb.inc
|
|
|
CREATE TABLE t1 ( |
pk INT, |
a INT, |
b INT, |
PRIMARY KEY (pk), |
KEY (b) |
) ENGINE=InnoDB;
|
|
|
INSERT INTO t1 VALUES |
(1,9,4),(2,0,0),(3,0,0),(4,5,0),(5,0,0),(6,0,3),(7,0,4),(8,3,9),(9,0,0),
|
(10,0,0),(11,9,0),(12,0,9),(13,9,0),(14,4,5),(15,0,0),(16,0,0);
|
|
|
ALTER TABLE t1 ADD CONSTRAINT FOREIGN KEY (a) REFERENCES t1 (b) ON DELETE CASCADE; |
DELETE IGNORE FROM t1 WHERE b = 4; |
|
|
INSERT IGNORE INTO t1 VALUES |
(1,9,4),(2,0,0),(3,0,0),(4,5,0),(5,0,0),(6,0,3),(7,0,4),(8,3,9),(9,0,0),
|
(10,0,0),(11,9,0),(12,0,9),(13,9,0),(14,4,5),(15,0,0),(16,0,0);
|
|
|
# Cleanup
|
DROP TABLE t1; |
On 10.2-10.4 RelWithDebInfo builds it produces numerous errors and eventually the very same assertion failure:
|
10.2 non-debug a8a27e65a8d2 |
2019-01-16 20:34:23 139880853542656 [ERROR] InnoDB: Cannot delete/update rows with cascading foreign key constraints that exceed max depth of 15. Please drop excessive foreign constraints and try again
|
2019-01-16 20:34:23 139880633984768 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000010)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000010)}
|
2019-01-16 20:34:23 139880617199360 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x8000000C)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x8000000C)}
|
2019-01-16 20:34:23 139880625592064 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x8000000F)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x8000000F)}
|
2019-01-16 20:34:23 139880617199360 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000009),[4] (0x8000000B)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000009),[4] (0x8000000B)}
|
2019-01-16 20:34:23 139880625592064 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000009)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000009)}
|
2019-01-16 20:34:23 139880617199360 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000003)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000003)}
|
2019-01-16 20:34:23 139880633984768 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x8000000A)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x8000000A)}
|
2019-01-16 20:34:23 139880608806656 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000009),[4] (0x8000000D)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000009),[4] (0x8000000D)}
|
2019-01-16 20:34:23 139880633984768 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000003),[4] (0x80000008)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000003),[4] (0x80000008)}
|
2019-01-16 20:34:23 139880633984768 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000002)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000002)}
|
2019-01-16 20:34:23 139880608806656 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000005)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000005)}
|
2019-01-16 20:34:23 139880625592064 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000006)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000006)}
|
2019-01-16 20:34:23 139880608806656 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000004),[4] (0x8000000E)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000004),[4] (0x8000000E)}
|
2019-01-16 20:34:23 139880625592064 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000005),[4] (0x80000004)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000005),[4] (0x80000004)}
|
2019-01-16 20:34:23 0x7f388c961700 InnoDB: Assertion failure in file /data/src/10.2/storage/innobase/row/row0ins.cc line 262
|
InnoDB: Failing assertion: !cursor->index->is_committed()
|
InnoDB: We intentionally generate a memory trap.
|
|
|
#5 0x0000561975aa9993 in ut_dbg_assertion_failed (expr=expr@entry=0x5619762f6670 "!cursor->index->is_committed()", file=file@entry=0x5619762f6520 "/data/src/10.2/storage/innobase/row/row0ins.cc", line=line@entry=262) at /data/src/10.2/storage/innobase/ut/ut0dbg.cc:60
|
#6 0x0000561975fb0ccd in row_ins_sec_index_entry_by_modify (mtr=0x7f388c95d890, thr=0x7f38400b7938, entry=0x7f38400943a8, heap=0x7f38400a2220, offsets_heap=0x7f38400bb900, offsets=0x7f388c95c980, cursor=0x7f388c95ca00, mode=2, flags=0) at /data/src/10.2/storage/innobase/row/row0ins.cc:262
|
#7 row_ins_sec_index_entry_low (flags=flags@entry=0, mode=<optimized out>, mode@entry=2, index=index@entry=0x7f3840095bb0, offsets_heap=offsets_heap@entry=0x7f38400bb900, heap=heap@entry=0x7f38400a2220, entry=entry@entry=0x7f38400943a8, trx_id=0, thr=0x7f38400b7938, dup_chk_only=false) at /data/src/10.2/storage/innobase/row/row0ins.cc:3054
|
#8 0x0000561975fb3a2c in row_ins_sec_index_entry (index=0x7f3840095bb0, entry=0x7f38400943a8, thr=0x7f38400b7938, dup_chk_only=<optimized out>) at /data/src/10.2/storage/innobase/row/row0ins.cc:3248
|
#9 0x0000561975fb5ddf in row_ins_index_entry (thr=0x7f38400b7938, entry=<optimized out>, index=0x7f3840095bb0) at /data/src/10.2/storage/innobase/row/row0ins.cc:3294
|
#10 row_ins_index_entry_step (thr=0x7f38400b7938, node=<optimized out>) at /data/src/10.2/storage/innobase/row/row0ins.cc:3442
|
#11 row_ins (thr=<optimized out>, node=<optimized out>) at /data/src/10.2/storage/innobase/row/row0ins.cc:3585
|
#12 row_ins_step (thr=thr@entry=0x7f38400b7938) at /data/src/10.2/storage/innobase/row/row0ins.cc:3811
|
#13 0x0000561975fc5098 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x7f3840093cf8 "\371\002", prebuilt=0x7f38400b6af0) at /data/src/10.2/storage/innobase/row/row0mysql.cc:1413
|
#14 0x0000561975f14d41 in ha_innobase::write_row (this=0x7f3840091cf0, record=0x7f3840093cf8 "\371\002") at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:8234
|
#15 0x0000561975cf44ea in handler::ha_write_row (this=0x7f3840091cf0, buf=0x7f3840093cf8 "\371\002") at /data/src/10.2/sql/handler.cc:5961
|
#16 0x0000561975b39ecb in write_record (thd=thd@entry=0x7f38400009a8, table=table@entry=0x7f38400b5b18, info=info@entry=0x7f388c95e8f0) at /data/src/10.2/sql/sql_insert.cc:1930
|
#17 0x0000561975b4027a in mysql_insert (thd=0x7f38400009a8, table_list=<optimized out>, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=true) at /data/src/10.2/sql/sql_insert.cc:1057
|
#18 0x0000561975b56691 in mysql_execute_command (thd=0x7f38400009a8) at /data/src/10.2/sql/sql_parse.cc:4438
|
#19 0x0000561975b5cbfa in mysql_parse (thd=0x7f38400009a8, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.2/sql/sql_parse.cc:8015
|
#20 0x0000561975b60774 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f38400009a8, packet=packet@entry=0x7f3840006ce9 "INSERT IGNORE INTO t1 VALUES \n(1,9,4),(2,0,0),(3,0,0),(4,5,0),(5,0,0),(6,0,3),(7,0,4),(8,3,9),(9,0,0),\n(10,0,0),(11,9,0),(12,0,9),(13,9,0),(14,4,5),(15,0,0),(16,0,0)", packet_length=packet_length@entry=166, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.2/sql/sql_parse.cc:1826
|
#21 0x0000561975b611a9 in do_command (thd=0x7f38400009a8) at /data/src/10.2/sql/sql_parse.cc:1379
|
#22 0x0000561975c2a604 in do_handle_one_connection (connect=connect@entry=0x561977d66b28) at /data/src/10.2/sql/sql_connect.cc:1335
|
#23 0x0000561975c2a7a4 in handle_one_connection (arg=arg@entry=0x561977d66b28) at /data/src/10.2/sql/sql_connect.cc:1241
|
#24 0x0000561975eef254 in pfs_spawn_thread (arg=0x561977d28ba8) at /data/src/10.2/storage/perfschema/pfs.cc:1862
|
#25 0x00007f389aef4494 in start_thread (arg=0x7f388c961700) at pthread_create.c:333
|
#26 0x00007f38992da93f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
Reproducible on older 10.2, at least 10.2.15 (I didn't check earlier versions).
On a debug build, it fails earlier:
|
10.2 debug a8a27e65a8 |
2019-01-16 20:46:15 140694608205568 [ERROR] InnoDB: Cannot delete/update rows with cascading foreign key constraints that exceed max depth of 15. Please drop excessive foreign constraints and try again
|
2019-01-16 20:46:15 140694312175360 [ERROR] InnoDB: tried to purge non-delete-marked record in index `a` of table `test`.`t1`: tuple: TUPLE (info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000010)}, record: COMPACT RECORD(info_bits=0, 2 fields): {[4] (0x80000000),[4] (0x80000010)}
|
mysqld: /data/src/10.2/storage/innobase/row/row0purge.cc:621: bool row_purge_remove_sec_if_poss_leaf(purge_node_t*, dict_index_t*, const dtuple_t*): Assertion `0' failed.
|
190116 20:46:15 [ERROR] mysqld got signal 6 ;
|
|
|
#7 0x00007ff60c5e1ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
|
#8 0x000055f464b8ac87 in row_purge_remove_sec_if_poss_leaf (node=0x55f468938fb0, index=0x7ff5b8091638, entry=0x7ff5e8016a38) at /data/src/10.2/storage/innobase/row/row0purge.cc:621
|
#9 0x000055f464b8aff2 in row_purge_remove_sec_if_poss (node=0x55f468938fb0, index=0x7ff5b8091638, entry=0x7ff5e8016a38) at /data/src/10.2/storage/innobase/row/row0purge.cc:717
|
#10 0x000055f464b8b1ff in row_purge_del_mark (node=0x55f468938fb0) at /data/src/10.2/storage/innobase/row/row0purge.cc:791
|
#11 0x000055f464b8be4a in row_purge_record_func (node=0x55f468938fb0, undo_rec=0x7ff5e8014ab8 "", thr=0x55f468938ef8, updated_extern=false) at /data/src/10.2/storage/innobase/row/row0purge.cc:1102
|
#12 0x000055f464b8c0c1 in row_purge (node=0x55f468938fb0, undo_rec=0x7ff5e8014ab8 "", thr=0x55f468938ef8) at /data/src/10.2/storage/innobase/row/row0purge.cc:1163
|
#13 0x000055f464b8c400 in row_purge_step (thr=0x55f468938ef8) at /data/src/10.2/storage/innobase/row/row0purge.cc:1249
|
#14 0x000055f464b1c65b in que_thr_step (thr=0x55f468938ef8) at /data/src/10.2/storage/innobase/que/que0que.cc:1045
|
#15 0x000055f464b1c859 in que_run_threads_low (thr=0x55f468938ef8) at /data/src/10.2/storage/innobase/que/que0que.cc:1107
|
#16 0x000055f464b1ca02 in que_run_threads (thr=0x55f468938ef8) at /data/src/10.2/storage/innobase/que/que0que.cc:1147
|
#17 0x000055f464c06747 in trx_purge (n_purge_threads=4, batch_size=300, truncate=false) at /data/src/10.2/storage/innobase/trx/trx0purge.cc:1733
|
#18 0x000055f464bd8222 in srv_do_purge (n_total_purged=0x7ff5f27fbed0) at /data/src/10.2/storage/innobase/srv/srv0srv.cc:2688
|
#19 0x000055f464bd878b in srv_purge_coordinator_thread (arg=0x0) at /data/src/10.2/storage/innobase/srv/srv0srv.cc:2830
|
#20 0x00007ff60e2b8494 in start_thread (arg=0x7ff5f27fc700) at pthread_create.c:333
|
#21 0x00007ff60c69e93f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
No failure on 10.1.
Attachments
Issue Links
- relates to
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Open
-
- links to
(1 relates to, 1 links to)
Activity
Here is an even simpler test case:
--source include/have_innodb.inc
|
SET @saved_frequency = @@GLOBAL.innodb_purge_rseg_truncate_frequency; |
SET GLOBAL innodb_purge_rseg_truncate_frequency = 1; |
|
|
--echo #
|
--echo # MDEV-18272 InnoDB index corruption after failed DELETE CASCADE
|
--echo #
|
CREATE TABLE t1 (a INT, b INT, KEY(b), |
CONSTRAINT FOREIGN KEY (a) REFERENCES t1 (b) ON DELETE CASCADE) |
ENGINE=InnoDB;
|
|
|
SET foreign_key_checks=OFF; |
INSERT INTO t1 VALUES |
(9,4),(0,0),(0,0),(5,0),(0,0),(0,3),(0,4),(3,9),(0,0),
|
(0,0),(9,0),(0,9),(9,0),(4,5),(0,0),(0,0);
|
SET foreign_key_checks=ON; |
|
|
DELETE IGNORE FROM t1 WHERE b = 4; |
CHECK TABLE t1; |
--source include/wait_all_purged.inc
|
DROP TABLE t1; |
SET GLOBAL innodb_purge_rseg_truncate_frequency = @saved_frequency; |
It crashes for me already during the CHECK TABLE. The trouble clearly is due to the DELETE IGNORE, which reports the following warnings:
|
10.2 c155946c90307ba448af8b4b5161f35b8af9d31d |
Warnings:
|
Warning 152 InnoDB: Cannot delete/update rows with cascading foreign key constraints that exceed max depth of 20. Please drop extra constraints and try again
|
Warning 1296 Got error 193 '`test`.`t1`, CONSTRAINT `t1_ibfk_1` FOREIGN KEY (`a`) REFERENCES `t1` (`b`) ON DELETE CASCADE' from InnoDB
|
Ever since the MDEV-15199/MDEV-14222 fix reverted to the procedural recursion for FOREIGN KEY processing in MariaDB 10.2.13, the logic should be similar to earlier versions.
The purge control is not available in 10.1, and the DELETE IGNORE would emit a different warning:
|
10.1 485dcb07d12db2309e21b06d46b3156a765495cb |
Warning 1451 Cannot delete or update a parent row: a foreign key constraint fails (`test`.`t1`, CONSTRAINT `t1_ibfk_1` FOREIGN KEY (`a`) REFERENCES `t1` (`b`) ON DELETE CASCADE)
|
Warning 1451 Cannot delete or update a parent row: a foreign key constraint fails (`test`.`t1`, CONSTRAINT `t1_ibfk_1` FOREIGN KEY (`a`) REFERENCES `t1` (`b`) ON DELETE CASCADE)
|
I tried to hard-wire the equivalent of innodb_purge_rseg_truncate_frequency = 1 with the following, but it did not have any effect; the history list length would remain 13 or 14.
diff --git a/storage/xtradb/srv/srv0srv.cc b/storage/xtradb/srv/srv0srv.cc
|
index c05b667dcf4..79a542adf9b 100644
|
--- a/storage/xtradb/srv/srv0srv.cc
|
+++ b/storage/xtradb/srv/srv0srv.cc
|
@@ -3389,7 +3389,6 @@ srv_do_purge(
|
{
|
ulint n_pages_purged;
|
|
- static ulint count = 0;
|
static ulint n_use_threads = 0;
|
static ulint rseg_history_len = 0;
|
ulint old_activity_count = srv_get_activity_count();
|
@@ -3445,7 +3444,7 @@ srv_do_purge(
|
|
n_pages_purged = trx_purge(
|
n_use_threads, srv_purge_batch_size,
|
- (++count % TRX_SYS_N_RSEGS) == 0);
|
+ true);
|
|
*n_total_purged += n_pages_purged;
|
} while (!srv_purge_should_exit(n_pages_purged) |
I also tried to create extra transactions to ensure a purge of the DELETE IGNORE transaction in 10.1, but that did not work for me:
--source include/have_innodb.inc
|
--echo #
|
--echo # MDEV-18272 InnoDB index corruption after failed DELETE CASCADE
|
--echo #
|
CREATE TABLE t1 (a INT, b INT, KEY(b), |
CONSTRAINT FOREIGN KEY (a) REFERENCES t1 (b) ON DELETE CASCADE) |
ENGINE=InnoDB;
|
CREATE TABLE t2 (a INT PRIMARY KEY) ENGINE=InnoDB; |
|
|
SET foreign_key_checks=OFF; |
INSERT INTO t1 VALUES |
(9,4),(0,0),(0,0),(5,0),(0,0),(0,3),(0,4),(3,9),(0,0),
|
(0,0),(9,0),(0,9),(9,0),(4,5),(0,0),(0,0);
|
SET foreign_key_checks=ON; |
|
|
DELETE IGNORE FROM t1 WHERE b = 4; |
INSERT INTO t2 SET a=1; |
let $n=200;
|
--disable_query_log
|
while ($n)
|
{
|
UPDATE t2 SET a=a+1; |
dec $n; |
}
|
--enable_query_log
|
CHECK TABLE t1; |
CHECK TABLE t1; |
CHECK TABLE t1; |
CHECK TABLE t1; |
CHECK TABLE t1; |
DROP TABLE t1,t2; |
So, this bug needs to be analyzed further in 10.2 and then fixed in the earliest applicable version, whatever it turns out to be.
Close to minimal test case for 10.2:
--source include/have_innodb.inc
|
SET @saved_frequency = @@GLOBAL.innodb_purge_rseg_truncate_frequency; |
SET GLOBAL innodb_purge_rseg_truncate_frequency = 1; |
CREATE TABLE t1 (pk SERIAL, a INT, b INT, KEY(b), |
CONSTRAINT FOREIGN KEY (a) REFERENCES t1 (b) ON DELETE CASCADE) |
ENGINE=InnoDB;
|
INSERT INTO t1 (a,b) VALUES |
(0,0),(0,0),(0,0),(0,0),(0,0),(0,0),(0,0),(0,0),(0,0),(0,0),(0,0),(0,0),
|
(0,1),(0,1),(1,0);
|
DELETE IGNORE FROM t1 WHERE b = 1; |
CHECK TABLE t1; |
--source include/wait_all_purged.inc
|
DROP TABLE t1; |
SET GLOBAL innodb_purge_rseg_truncate_frequency = @saved_frequency; |
The pk SERIAL is only there to ease debugging (to have an internal primary key whose sequence numbering starts from 1 instead of some bigger value that would be used for DB_ROW_ID). This fails for me every time already during the CHECK TABLE.
Long debugging session short, we return the error code DB_FOREIGN_EXCEED_MAX_CASCADE all the way up to row_update_for_mysql(), which then invokes row_mysql_handle_errors(), which fails to rollback to the start of the row operation. The following patch fixes the problem:
diff --git a/storage/innobase/row/row0mysql.cc b/storage/innobase/row/row0mysql.cc
|
index 4d1a05d516a..6d0ee7bdfd0 100644
|
--- a/storage/innobase/row/row0mysql.cc
|
+++ b/storage/innobase/row/row0mysql.cc
|
@@ -726,6 +726,7 @@ row_mysql_handle_errors(
|
case DB_TABLE_NOT_FOUND:
|
case DB_DECRYPTION_FAILED:
|
case DB_COMPUTE_VALUE_FAILED:
|
+ rollback_to_savept:
|
DBUG_EXECUTE_IF("row_mysql_crash_if_error", {
|
log_buffer_flush_to_disk();
|
DBUG_SUICIDE(); });
|
@@ -773,13 +774,13 @@ row_mysql_handle_errors(
|
" tablespace. If the mysqld server crashes after"
|
" the startup or when you dump the tables. "
|
<< FORCE_RECOVERY_MSG;
|
- break;
|
+ goto rollback_to_savept;
|
case DB_FOREIGN_EXCEED_MAX_CASCADE:
|
ib::error() << "Cannot delete/update rows with cascading"
|
" foreign key constraints that exceed max depth of "
|
<< FK_MAX_CASCADE_DEL << ". Please drop excessive"
|
" foreign constraints and try again";
|
- break;
|
+ goto rollback_to_savept;
|
default:
|
ib::fatal() << "Unknown error code " << err << ": "
|
<< ut_strerr(err); |
The problem was introduced in MySQL 5.5.37 and propagated to MariaDB 5.5.37, 10.0.11, 10.1.0 and later, in a fix of MySQL Bug#54582.
Some more details from my debugging session:
- There was a very high recursion stack from ha_innobase::delete_row(), 7 or 8 stack frames per CASCADE operation.
- According to --debug=d,ib_cur we delete-marked all entries in the clustered index and in index b, but none on index a.
- By the time purge crashed, no records had been removed from the clustered index, and 4 had been removed from index b.
The following rules were violated or about to be violated due to the transaction commit after the missing partial rollback:
- A secondary index record must always point to a clustered index record.
- A non-delete-marked secondary index record may only point to a delete-marked clustered index record if that record is implicitly locked by an active transaction. (If the transaction is committed such that the clustered index record remains delete-marked, then the secondary index record must be delete-marked as well.)
For our test case, the following change in MySQL 5.7.2 (and MariaDB 10.2.2) is relevant:
diff --git a/storage/innobase/row/row0ins.cc b/storage/innobase/row/row0ins.cc
|
index a0c72f7f348..8e990648924 100644
|
--- a/storage/innobase/row/row0ins.cc
|
+++ b/storage/innobase/row/row0ins.cc
|
@@ -1061,8 +1055,8 @@ row_ins_foreign_check_on_constraint(
|
goto nonstandard_exit_func;
|
}
|
|
- if (row_ins_cascade_n_ancestors(cascade) >= 15) {
|
- err = DB_ROW_IS_REFERENCED;
|
+ if (row_ins_cascade_n_ancestors(cascade) >= FK_MAX_CASCADE_DEL) {
|
+ err = DB_FOREIGN_EXCEED_MAX_CASCADE;
|
|
row_ins_foreign_report_err(
|
"Trying a too deep cascaded delete or update\n", |
With the above change of the error code, the wrong error handling that was introduced in MySQL 5.5.37 started to be more prominent. The error DB_ROW_IS_REFERENCED was always handled correctly, by rolling back the current row operation.
This explains why we were not able to reproduce a problem with this test case in earlier versions. There could be some other test case that repeats the problem in earlier versions.
In MariaDB 10.3.4 and 10.4.0, similar wrong handling was introduced for the error code DB_UNSUPPORTED, which is issued when foreign key constraints conflict with operations on system-versioned tables (MDEV-12894).
I can repeat the failure. For me, the failure occurs on index a. The record (a,pk)=(0,16) is not delete-marked in the secondary index, while the record is delete-marked in the clustered index root page: (pk,DB_TRX_ID,DB_ROLL_PTR,a,b)=(16,0x515,(not insert),0,0).
The transaction 0x515 is not active any more, so the clustered index record definitely is purgeable. Only a single transaction, with id=0x517 is active. It looks like 0x515 must have committed right before 0x517 started, because we are assigning the "commit identifier" from the same global sequence, trx_sys->max_trx_id.
It looks like the transaction 0x515 can only be the DELETE IGNORE statement.
The active transaction 0x517 is waiting for block->lock on page 5:5, which is the root page of the secondary index a, that is, the very page that the purge thread (where the assertion fails) is holding in exclusive mode.
On page 5:4 (the root page of the secondary index b), there had been a record (b,pk)=(0,16), but it has been delete-marked and purged. It is the very last element in the PAGE_FREE list, so it could have been the very first record that was deleted from the page since the table was rebuilt by the ALTER TABLE.
This looks like a bug outside purge. Something appears to be leaving an apparently orphan non-delete-marked record in the secondary index.
I suspect some foul play in ON DELETE CASCADE when DELETE IGNORE is being executed. I am not even sure about the expected semantics for that, and I did not know that DELETE IGNORE even exists. Anyway, the bug must be inside InnoDB.
Here is the stack trace for transaction 0x517 that is rolling back the insert of the current row (pk,DB_TRX_ID,DB_ROLL_PTR,a,b)=(1,0x517,(insert),9,4) in INSERT IGNORE. The error that triggered the row rollback was DB_NO_REFERENCED_ROW for index a. The row rollback is searching for the record (a,pk)=(9,1) while the purge thread is exclusively locking that index page:
10.2 c155946c90307ba448af8b4b5161f35b8af9d31d
#12 0x0000559cfdf95d5a in btr_pcur_open_low (index=0x7f850008cfa8, level=0,tuple=0x7f85000349c8, mode=PAGE_CUR_LE, latch_mode=2,cursor=0x7f856497c210,file=0x559cfe5b9195 "/mariadb/10.2/storage/innobase/row/row0row.cc",line=1070, autoinc=0, mtr=0x7f856497c9b0)at /mariadb/10.2/storage/innobase/include/btr0pcur.ic:483#13 0x0000559cfdf964cc in row_search_index_entry (index=0x7f850008cfa8,entry=0x7f85000349c8, mode=2, pcur=0x7f856497c210, mtr=0x7f856497c9b0)at /mariadb/10.2/storage/innobase/row/row0row.cc:1070#14 0x0000559cfe216720 in row_undo_mod_del_mark_or_remove_sec_low (node=0x7f8500098898, thr=0x7f8500036600, index=0x7f850008cfa8,entry=0x7f85000349c8, mode=2)at /mariadb/10.2/storage/innobase/row/row0umod.cc:469#15 0x0000559cfe2152c3 in row_undo_mod_del_mark_or_remove_sec (node=0x7f8500098898, thr=0x7f8500036600, index=0x7f850008cfa8,entry=0x7f85000349c8)at /mariadb/10.2/storage/innobase/row/row0umod.cc:580#16 0x0000559cfe21436e in row_undo_mod_upd_del_sec (node=0x7f8500098898,thr=0x7f8500036600) at /mariadb/10.2/storage/innobase/row/row0umod.cc:885#17 0x0000559cfe2132dc in row_undo_mod (node=0x7f8500098898,thr=0x7f8500036600) at /mariadb/10.2/storage/innobase/row/row0umod.cc:1265#18 0x0000559cfdfc6ddf in row_undo (node=0x7f8500098898, thr=0x7f8500036600)at /mariadb/10.2/storage/innobase/row/row0undo.cc:302#19 0x0000559cfdfc6a15 in row_undo_step (thr=0x7f8500036600)at /mariadb/10.2/storage/innobase/row/row0undo.cc:350#20 0x0000559cfdf05fac in que_thr_step (thr=0x7f8500036600)at /mariadb/10.2/storage/innobase/que/que0que.cc:1043#21 0x0000559cfdf052d3 in que_run_threads_low (thr=0x7f8500036600)at /mariadb/10.2/storage/innobase/que/que0que.cc:1107#22 0x0000559cfdf050a4 in que_run_threads (thr=0x7f8500036600)at /mariadb/10.2/storage/innobase/que/que0que.cc:1147#23 0x0000559cfe03c80b in trx_rollback_to_savepoint_low (trx=0x7f856554f148,savept=0x7f856497e000)at /mariadb/10.2/storage/innobase/trx/trx0roll.cc:108#24 0x0000559cfe03c36c in trx_rollback_to_savepoint (trx=0x7f856554f148,savept=0x7f856497e000)at /mariadb/10.2/storage/innobase/trx/trx0roll.cc:149#25 0x0000559cfdf61749 in row_mysql_handle_errors (new_err=0x7f856497dff4,trx=0x7f856554f148, thr=0x7f850000a118, savept=0x7f856497e000)at /mariadb/10.2/storage/innobase/row/row0mysql.cc:736#26 0x0000559cfdf63c59 in row_insert_for_mysql (mysql_rec=0x7f850007b8a8 "\371\001", prebuilt=0x7f8500009288)at /mariadb/10.2/storage/innobase/row/row0mysql.cc:1426#27 0x0000559cfdde087a in ha_innobase::write_row (this=0x7f850007bc90,record=0x7f850007b8a8 "\371\001")at /mariadb/10.2/storage/innobase/handler/ha_innodb.cc:8253So, it is the very first record that the INSERT IGNORE was trying to insert.
Here is a slightly simplified test case:
--source include/have_innodb.inc(1,9,4),(2,0,0),(3,0,0),(4,5,0),(5,0,0),(6,0,3),(7,0,4),(8,3,9),(9,0,0),(10,0,0),(11,9,0),(12,0,9),(13,9,0),(14,4,5),(15,0,0),(16,0,0);--source include/wait_all_purged.inc