[MDEV-21658] Error on online ADD PRIMARY KEY after instant DROP/reorder - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.4(EOL)
Fix Version/s: 10.5.1, 10.4.13
Component/s: Data Definition - Alter Table, Data Manipulation - Update, Prepared Statements, Storage Engine - InnoDB
Labels:
None

Description

Notes:

There is a lot of "back and forth" in the test case with creating/dropping/renaming columns, but I can't get rid of the remaining part without having the outcome changed.
If I add ALGORITHM=COPY to any of the ALTER statements in the test case, the crash stops happening. Explicit ALGORITHM=INSTANT or ALGORITHM=INPLACE don't seem to change the outcome.
The test case is concurrent and hence should be non-deterministic. It fails every time for me, but if it doesn't for you, try to run with --repeat.

--source include/have_innodb.inc

--connect (con1,localhost,root,,test)

--connection default

CREATE  TABLE t1 (f GEOMETRY DEFAULT POINT(0,0), a INT, b INT, c INT, col INT) ENGINE=InnoDB;

ALTER TABLE t1 DROP COLUMN a;

ALTER TABLE t1 DROP COLUMN c;

ALTER TABLE t1 DROP COLUMN b;

ALTER TABLE t1 CHANGE COLUMN col b INT;

ALTER TABLE t1 ADD COLUMN col INT;

ALTER TABLE t1 DROP COLUMN b;

ALTER TABLE t1 CHANGE COLUMN col b INT;

ALTER TABLE t1 ADD COLUMN col INT;

ALTER TABLE t1 DROP COLUMN b  ;

ALTER TABLE t1 CHANGE COLUMN col b INT;

INSERT INTO t1 () VALUES ();

SET SQL_MODE= '';

--send

    ALTER TABLE t1 ADD PRIMARY KEY(b);

--connection con1

PREPARE stmt FROM 'UPDATE t1 SET b = 1';

EXECUTE stmt;

# Cleanup

DEALLOCATE PREPARE stmt;

--disconnect con1

--connection default

--reap

DROP TABLE t1;

10.4 574354a6
mysqld: /data/src/10.4/storage/innobase/row/row0log.cc:2121: dberr_t row_log_table_apply_update(que_thr_t, ulint, const mrec_t, const offset_t, mem_heap_t, mem_heap_t, row_merge_dup_t, const dtuple_t*): Assertion `log->blobs' failed.
200204 14:18:35 [ERROR] mysqld got signal 6 ;

#7 0x00007f0d897a5f12 in __GI___assert_fail (assertion=0x5562839cee4a "log->blobs", file=0x5562839ce248 "/data/src/10.4/storage/innobase/row/row0log.cc", line=2121, function=0x5562839d1f40 <row_log_table_apply_update(que_thr_t, unsigned long, unsigned char const, unsigned short const, mem_block_info_t, mem_block_info_t, row_merge_dup_t, dtuple_t const)::__PRETTY_FUNCTION__> "dberr_t row_log_table_apply_update(que_thr_t, ulint, const mrec_t, const offset_t, mem_heap_t, mem_heap_t, row_merge_dup_t, const dtuple_t)") at assert.c:101
#8 0x00005562831a3c54 in row_log_table_apply_update (thr=0x7f0d381ae4a8, new_trx_id_col=1, mrec=0x7f0d7e8fe016 "", offsets=0x7f0d381a24e0, offsets_heap=0x7f0d381d7460, heap=0x7f0d381d33d0, dup=0x7f0d8414bcf0, old_pk=0x7f0d381d3458) at /data/src/10.4/storage/innobase/row/row0log.cc:2121
#9 0x00005562831a5dcb in row_log_table_apply_op (thr=0x7f0d381ae4a8, new_trx_id_col=1, dup=0x7f0d8414bcf0, error=0x7f0d8414ba6c, offsets_heap=0x7f0d381d7460, heap=0x7f0d381d33d0, mrec=0x7f0d7e8fe016 "", mrec_end=0x7f0d7e8fe045 "", offsets=0x7f0d381a24e0) at /data/src/10.4/storage/innobase/row/row0log.cc:2664
#10 0x00005562831a7fe1 in row_log_table_apply_ops (thr=0x7f0d381ae4a8, dup=0x7f0d8414bcf0, stage=0x7f0d381b1340) at /data/src/10.4/storage/innobase/row/row0log.cc:3037
#11 0x00005562831a873d in row_log_table_apply (thr=0x7f0d381ae4a8, old_table=0x7f0d3800be58, table=0x7f0d8414c800, stage=0x7f0d381b1340, new_table=0x7f0d381aed98) at /data/src/10.4/storage/innobase/row/row0log.cc:3143
#12 0x000055628302ded0 in ha_innobase::inplace_alter_table (this=0x7f0d38066ed8, altered_table=0x7f0d8414c800, ha_alter_info=0x7f0d8414c770) at /data/src/10.4/storage/innobase/handler/handler0alter.cc:8379
#13 0x0000556282b2d9ff in handler::ha_inplace_alter_table (this=0x7f0d38066ed8, altered_table=0x7f0d8414c800, ha_alter_info=0x7f0d8414c770) at /data/src/10.4/sql/handler.h:4361
#14 0x0000556282b21a91 in mysql_inplace_alter_table (thd=0x7f0d38000af0, table_list=0x7f0d38013288, table=0x7f0d38066070, altered_table=0x7f0d8414c800, ha_alter_info=0x7f0d8414c770, inplace_supported=HA_ALTER_INPLACE_COPY_NO_LOCK, target_mdl_request=0x7f0d8414d5d0, alter_ctx=0x7f0d8414e100) at /data/src/10.4/sql/sql_table.cc:7725
#15 0x0000556282b28953 in mysql_alter_table (thd=0x7f0d38000af0, new_db=0x7f0d380052b0, new_name=0x7f0d380056b8, create_info=0x7f0d8414ecf0, table_list=0x7f0d38013288, alter_info=0x7f0d8414ec30, order_num=0, order=0x0, ignore=false) at /data/src/10.4/sql/sql_table.cc:10119
#16 0x0000556282bc0a47 in Sql_cmd_alter_table::execute (this=0x7f0d38013a18, thd=0x7f0d38000af0) at /data/src/10.4/sql/sql_alter.cc:508
#17 0x0000556282a3f221 in mysql_execute_command (thd=0x7f0d38000af0) at /data/src/10.4/sql/sql_parse.cc:6102
#18 0x0000556282a448e3 in mysql_parse (thd=0x7f0d38000af0, rawbuf=0x7f0d38013198 "ALTER TABLE t1 ADD PRIMARY KEY(b)", length=33, parser_state=0x7f0d84150160, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7901
#19 0x0000556282a2fab0 in dispatch_command (command=COM_QUERY, thd=0x7f0d38000af0, packet=0x7f0d381371b1 "ALTER TABLE t1 ADD PRIMARY KEY(b)", packet_length=33, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1842
#20 0x0000556282a2e13d in do_command (thd=0x7f0d38000af0) at /data/src/10.4/sql/sql_parse.cc:1360
#21 0x0000556282bb7357 in do_handle_one_connection (connect=0x556285d28b80) at /data/src/10.4/sql/sql_connect.cc:1412
#22 0x0000556282bb70a6 in handle_one_connection (arg=0x556285d28b80) at /data/src/10.4/sql/sql_connect.cc:1316
#23 0x00005562835bfb45 in pfs_spawn_thread (arg=0x556285c47b30) at /data/src/10.4/storage/perfschema/pfs.cc:1869
#24 0x00007f0d8b72e4a4 in start_thread (arg=0x7f0d84151700) at pthread_create.c:456
#25 0x00007f0d89862d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Reproducible on 10.4 and 10.5.
Not reproducible on 10.3 with the provided test case (although I do have a record of a similar failure on a 10.3 build).
Only reproducible with UPDATE executed as a prepared statement.

Non-debug build doesn't crash, but it produces an error which I wouldn't expect:

mysqltest: At line 31: query 'reap' failed: 1062: Duplicate entry '0' for key 'PRIMARY'

The table only has one row, so duplicate key error doesn't make sense to me.

Attachments

Issue Links

is caused by

MDEV-15562 Instant DROP COLUMN or changing the order of columns

Closed

is duplicated by

MDEV-21660 Unexpected ER_INVALID_USE_OF_NULL upon concurrent UPDATE and ALTER

Closed

Activity

Ascending order - Click to sort in descending order

Elena Stepanova added a comment - 2020-02-04 15:31

The test case below is almost identical to the one in the description, with the only difference being the datatype of the first column. It causes a different assertion failure.

--source include/have_innodb.inc

--connect (con1,localhost,root,,test)

--connection default

CREATE  TABLE t1 (f INT, a INT, b INT, c INT, col INT) ENGINE=InnoDB;

ALTER TABLE t1 DROP COLUMN a;

ALTER TABLE t1 DROP COLUMN c;

ALTER TABLE t1 DROP COLUMN b;

ALTER TABLE t1 CHANGE COLUMN col b INT;

ALTER TABLE t1 ADD COLUMN col INT;

ALTER TABLE t1 DROP COLUMN b;

ALTER TABLE t1 CHANGE COLUMN col b INT;

ALTER TABLE t1 ADD COLUMN col INT;

ALTER TABLE t1 DROP COLUMN b  ;

ALTER TABLE t1 CHANGE COLUMN col b INT;

INSERT INTO t1 () VALUES ();

SET SQL_MODE= '';

--send

    ALTER TABLE t1 ADD PRIMARY KEY(b);

--connection con1

PREPARE stmt FROM 'UPDATE t1 SET b = 1';

EXECUTE stmt;

# Cleanup

DEALLOCATE PREPARE stmt;

--disconnect con1

--connection default

--reap

DROP TABLE t1;

10.4 574354a6
mysqld: /data/src/10.4/storage/innobase/row/row0log.cc:2638: const mrec_t* row_log_table_apply_op(que_thr_t, ulint, row_merge_dup_t, dberr_t, mem_heap_t, mem_heap_t, const mrec_t, const mrec_t, offset_t): Assertion `extra_size \|\| !is_instant' failed.

#7 0x00007f6f39b0af12 in __GI___assert_fail (assertion=0x5562cc07a1c3 "extra_size \|\| !is_instant", file=0x5562cc079248 "/data/src/10.4/storage/innobase/row/row0log.cc", line=2638, function=0x5562cc07d060 <row_log_table_apply_op(que_thr_t, unsigned long, row_merge_dup_t, dberr_t, mem_block_info_t, mem_block_info_t, unsigned char const, unsigned char const, unsigned short)::__PRETTY_FUNCTION__> "const mrec_t* row_log_table_apply_op(que_thr_t, ulint, row_merge_dup_t, dberr_t, mem_heap_t, mem_heap_t, const mrec_t, const mrec_t, offset_t)") at assert.c:101
#8 0x00005562cb850c18 in row_log_table_apply_op (thr=0x7f6ee41b5fd8, new_trx_id_col=1, dup=0x7f6f340afcf0, error=0x7f6f340afa6c, offsets_heap=0x7f6ee41defc0, heap=0x7f6ee41daf30, mrec=0x7f6f2ecff015 "", mrec_end=0x7f6f2ecff02f "", offsets=0x7f6ee4068170) at /data/src/10.4/storage/innobase/row/row0log.cc:2638
#9 0x00005562cb852fe1 in row_log_table_apply_ops (thr=0x7f6ee41b5fd8, dup=0x7f6f340afcf0, stage=0x7f6ee41b8e00) at /data/src/10.4/storage/innobase/row/row0log.cc:3037
#10 0x00005562cb85373d in row_log_table_apply (thr=0x7f6ee41b5fd8, old_table=0x7f6ee400b598, table=0x7f6f340b0800, stage=0x7f6ee41b8e00, new_table=0x7f6ee41b6958) at /data/src/10.4/storage/innobase/row/row0log.cc:3143
#11 0x00005562cb6d8ed0 in ha_innobase::inplace_alter_table (this=0x7f6ee4064c28, altered_table=0x7f6f340b0800, ha_alter_info=0x7f6f340b0770) at /data/src/10.4/storage/innobase/handler/handler0alter.cc:8379
#12 0x00005562cb1d89ff in handler::ha_inplace_alter_table (this=0x7f6ee4064c28, altered_table=0x7f6f340b0800, ha_alter_info=0x7f6f340b0770) at /data/src/10.4/sql/handler.h:4361
#13 0x00005562cb1cca91 in mysql_inplace_alter_table (thd=0x7f6ee4000af0, table_list=0x7f6ee4013290, table=0x7f6ee4063dc0, altered_table=0x7f6f340b0800, ha_alter_info=0x7f6f340b0770, inplace_supported=HA_ALTER_INPLACE_COPY_NO_LOCK, target_mdl_request=0x7f6f340b15d0, alter_ctx=0x7f6f340b2100) at /data/src/10.4/sql/sql_table.cc:7725
#14 0x00005562cb1d3953 in mysql_alter_table (thd=0x7f6ee4000af0, new_db=0x7f6ee40052b0, new_name=0x7f6ee40056b8, create_info=0x7f6f340b2cf0, table_list=0x7f6ee4013290, alter_info=0x7f6f340b2c30, order_num=0, order=0x0, ignore=false) at /data/src/10.4/sql/sql_table.cc:10119
#15 0x00005562cb26ba47 in Sql_cmd_alter_table::execute (this=0x7f6ee4013a20, thd=0x7f6ee4000af0) at /data/src/10.4/sql/sql_alter.cc:508
#16 0x00005562cb0ea221 in mysql_execute_command (thd=0x7f6ee4000af0) at /data/src/10.4/sql/sql_parse.cc:6102
#17 0x00005562cb0ef8e3 in mysql_parse (thd=0x7f6ee4000af0, rawbuf=0x7f6ee4013198 "ALTER TABLE t1 ADD PRIMARY KEY ( col2 )", length=39, parser_state=0x7f6f340b4160, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7901
#18 0x00005562cb0daab0 in dispatch_command (command=COM_QUERY, thd=0x7f6ee4000af0, packet=0x7f6ee41371b1 "ALTER TABLE t1 ADD PRIMARY KEY ( col2 ) ", packet_length=40, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1842
#19 0x00005562cb0d913d in do_command (thd=0x7f6ee4000af0) at /data/src/10.4/sql/sql_parse.cc:1360
#20 0x00005562cb262357 in do_handle_one_connection (connect=0x5562ce2f9850) at /data/src/10.4/sql/sql_connect.cc:1412
#21 0x00005562cb2620a6 in handle_one_connection (arg=0x5562ce2f9850) at /data/src/10.4/sql/sql_connect.cc:1316
#22 0x00005562cbc6ab45 in pfs_spawn_thread (arg=0x5562ce218800) at /data/src/10.4/storage/perfschema/pfs.cc:1869
#23 0x00007f6f3ba934a4 in start_thread (arg=0x7f6f340b5700) at pthread_create.c:456
#24 0x00007f6f39bc7d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Elena Stepanova added a comment - 2020-02-04 15:31 The test case below is almost identical to the one in the description, with the only difference being the datatype of the first column. It causes a different assertion failure. --source include/have_innodb.inc --connect (con1,localhost,root,,test) --connection default CREATE TABLE t1 (f INT , a INT , b INT , c INT , col INT ) ENGINE=InnoDB; ALTER TABLE t1 DROP COLUMN a; ALTER TABLE t1 DROP COLUMN c; ALTER TABLE t1 DROP COLUMN b; ALTER TABLE t1 CHANGE COLUMN col b INT ; ALTER TABLE t1 ADD COLUMN col INT ; ALTER TABLE t1 DROP COLUMN b; ALTER TABLE t1 CHANGE COLUMN col b INT ; ALTER TABLE t1 ADD COLUMN col INT ; ALTER TABLE t1 DROP COLUMN b ; ALTER TABLE t1 CHANGE COLUMN col b INT ; INSERT INTO t1 () VALUES (); SET SQL_MODE= '' ; --send ALTER TABLE t1 ADD PRIMARY KEY (b); --connection con1 PREPARE stmt FROM 'UPDATE t1 SET b = 1' ; EXECUTE stmt; # Cleanup DEALLOCATE PREPARE stmt; --disconnect con1 --connection default --reap DROP TABLE t1; 10.4 574354a6 mysqld: /data/src/10.4/storage/innobase/row/row0log.cc:2638: const mrec_t* row_log_table_apply_op(que_thr_t*, ulint, row_merge_dup_t*, dberr_t*, mem_heap_t*, mem_heap_t*, const mrec_t*, const mrec_t*, offset_t*): Assertion `extra_size || !is_instant' failed. #7 0x00007f6f39b0af12 in __GI___assert_fail (assertion=0x5562cc07a1c3 "extra_size || !is_instant", file=0x5562cc079248 "/data/src/10.4/storage/innobase/row/row0log.cc", line=2638, function=0x5562cc07d060 <row_log_table_apply_op(que_thr_t*, unsigned long, row_merge_dup_t*, dberr_t*, mem_block_info_t*, mem_block_info_t*, unsigned char const*, unsigned char const*, unsigned short*)::__PRETTY_FUNCTION__> "const mrec_t* row_log_table_apply_op(que_thr_t*, ulint, row_merge_dup_t*, dberr_t*, mem_heap_t*, mem_heap_t*, const mrec_t*, const mrec_t*, offset_t*)") at assert.c:101 #8 0x00005562cb850c18 in row_log_table_apply_op (thr=0x7f6ee41b5fd8, new_trx_id_col=1, dup=0x7f6f340afcf0, error=0x7f6f340afa6c, offsets_heap=0x7f6ee41defc0, heap=0x7f6ee41daf30, mrec=0x7f6f2ecff015 "", mrec_end=0x7f6f2ecff02f "", offsets=0x7f6ee4068170) at /data/src/10.4/storage/innobase/row/row0log.cc:2638 #9 0x00005562cb852fe1 in row_log_table_apply_ops (thr=0x7f6ee41b5fd8, dup=0x7f6f340afcf0, stage=0x7f6ee41b8e00) at /data/src/10.4/storage/innobase/row/row0log.cc:3037 #10 0x00005562cb85373d in row_log_table_apply (thr=0x7f6ee41b5fd8, old_table=0x7f6ee400b598, table=0x7f6f340b0800, stage=0x7f6ee41b8e00, new_table=0x7f6ee41b6958) at /data/src/10.4/storage/innobase/row/row0log.cc:3143 #11 0x00005562cb6d8ed0 in ha_innobase::inplace_alter_table (this=0x7f6ee4064c28, altered_table=0x7f6f340b0800, ha_alter_info=0x7f6f340b0770) at /data/src/10.4/storage/innobase/handler/handler0alter.cc:8379 #12 0x00005562cb1d89ff in handler::ha_inplace_alter_table (this=0x7f6ee4064c28, altered_table=0x7f6f340b0800, ha_alter_info=0x7f6f340b0770) at /data/src/10.4/sql/handler.h:4361 #13 0x00005562cb1cca91 in mysql_inplace_alter_table (thd=0x7f6ee4000af0, table_list=0x7f6ee4013290, table=0x7f6ee4063dc0, altered_table=0x7f6f340b0800, ha_alter_info=0x7f6f340b0770, inplace_supported=HA_ALTER_INPLACE_COPY_NO_LOCK, target_mdl_request=0x7f6f340b15d0, alter_ctx=0x7f6f340b2100) at /data/src/10.4/sql/sql_table.cc:7725 #14 0x00005562cb1d3953 in mysql_alter_table (thd=0x7f6ee4000af0, new_db=0x7f6ee40052b0, new_name=0x7f6ee40056b8, create_info=0x7f6f340b2cf0, table_list=0x7f6ee4013290, alter_info=0x7f6f340b2c30, order_num=0, order=0x0, ignore=false) at /data/src/10.4/sql/sql_table.cc:10119 #15 0x00005562cb26ba47 in Sql_cmd_alter_table::execute (this=0x7f6ee4013a20, thd=0x7f6ee4000af0) at /data/src/10.4/sql/sql_alter.cc:508 #16 0x00005562cb0ea221 in mysql_execute_command (thd=0x7f6ee4000af0) at /data/src/10.4/sql/sql_parse.cc:6102 #17 0x00005562cb0ef8e3 in mysql_parse (thd=0x7f6ee4000af0, rawbuf=0x7f6ee4013198 "ALTER TABLE t1 ADD PRIMARY KEY ( col2 )", length=39, parser_state=0x7f6f340b4160, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7901 #18 0x00005562cb0daab0 in dispatch_command (command=COM_QUERY, thd=0x7f6ee4000af0, packet=0x7f6ee41371b1 "ALTER TABLE t1 ADD PRIMARY KEY ( col2 ) ", packet_length=40, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1842 #19 0x00005562cb0d913d in do_command (thd=0x7f6ee4000af0) at /data/src/10.4/sql/sql_parse.cc:1360 #20 0x00005562cb262357 in do_handle_one_connection (connect=0x5562ce2f9850) at /data/src/10.4/sql/sql_connect.cc:1412 #21 0x00005562cb2620a6 in handle_one_connection (arg=0x5562ce2f9850) at /data/src/10.4/sql/sql_connect.cc:1316 #22 0x00005562cbc6ab45 in pfs_spawn_thread (arg=0x5562ce218800) at /data/src/10.4/storage/perfschema/pfs.cc:1869 #23 0x00007f6f3ba934a4 in start_thread (arg=0x7f6f340b5700) at pthread_create.c:456 #24 0x00007f6f39bc7d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Marko Mäkelä added a comment - 2020-02-04 16:27

Here is a slightly cleaner version of the test:

--source include/have_innodb.inc

--connect (con1,localhost,root,,test)

--connection default

CREATE  TABLE t1 (f GEOMETRY DEFAULT POINT(0,0), a INT, b INT, c INT, col INT) ENGINE=InnoDB;

INSERT INTO t1 () VALUES ();

ALTER TABLE t1 DROP a, DROP b, DROP c, DROP col;

ALTER TABLE t1 ADD COLUMN col INT;

ALTER TABLE t1 DROP COLUMN col, ADD COLUMN b INT;

SET SQL_MODE= '';

send ALTER TABLE t1 ADD PRIMARY KEY(b);

--connection con1

PREPARE stmt FROM 'UPDATE t1 SET b = 1';

EXECUTE stmt;

DEALLOCATE PREPARE stmt;

--disconnect con1

--connection default

--reap

DROP TABLE t1;

It looks like the DB_TRX_ID,DB_ROLL_PTR values in the old_pk search tuple are off by 2 bytes (only 2 bytes of the 4-byte PRIMARY KEY are written).
Without the GEOMETRY column, I get a different assertion failure. This is a deterministic test:

--source include/have_innodb.inc

--source include/have_debug.inc

--source include/have_debug_sync.inc

--connect (con1,localhost,root,,test)

--connection default

CREATE  TABLE t1 (a INT, b INT, c INT, col INT) ENGINE=InnoDB;

INSERT INTO t1 () VALUES ();

ALTER TABLE t1 DROP b, DROP c, DROP col;

ALTER TABLE t1 ADD COLUMN col INT;

ALTER TABLE t1 DROP a, DROP col, ADD COLUMN b INT;

SET SQL_MODE= '';

SET DEBUG_SYNC = 'row_log_table_apply1_before SIGNAL scanned WAIT_FOR dml';

send ALTER TABLE t1 ADD PRIMARY KEY(b);

--connection con1

SET DEBUG_SYNC = 'now WAIT_FOR scanned';

UPDATE t1 SET b = 1;

SET DEBUG_SYNC = 'now SIGNAL dml';

--disconnect con1

--connection default

--reap

SET DEBUG_SYNC = 'RESET';

SELECT * FROM t1;

DROP TABLE t1;

10.4 46386661a2311cabd7bac914c44b1af0b4746e07

mysqld: storage/innobase/row/row0log.cc:2638: const mrec_t *row_log_table_apply_op(que_thr_t *, ulint, row_merge_dup_t *, dberr_t *, mem_heap_t *, mem_heap_t *, const mrec_t *, const mrec_t *, offset_t *): Assertion `extra_size || !is_instant' failed.

If I add ,FORCE to the penultimate ALTER TABLE, there will be no crash.

Marko Mäkelä added a comment - 2020-02-04 16:27 Here is a slightly cleaner version of the test: --source include/have_innodb.inc --connect (con1,localhost,root,,test) --connection default CREATE TABLE t1 (f GEOMETRY DEFAULT POINT(0,0), a INT , b INT , c INT , col INT ) ENGINE=InnoDB; INSERT INTO t1 () VALUES (); ALTER TABLE t1 DROP a, DROP b, DROP c, DROP col; ALTER TABLE t1 ADD COLUMN col INT ; ALTER TABLE t1 DROP COLUMN col, ADD COLUMN b INT ; SET SQL_MODE= '' ; send ALTER TABLE t1 ADD PRIMARY KEY (b); --connection con1 PREPARE stmt FROM 'UPDATE t1 SET b = 1' ; EXECUTE stmt; DEALLOCATE PREPARE stmt; --disconnect con1 --connection default --reap DROP TABLE t1; It looks like the DB_TRX_ID,DB_ROLL_PTR values in the old_pk search tuple are off by 2 bytes (only 2 bytes of the 4-byte PRIMARY KEY are written). Without the GEOMETRY column, I get a different assertion failure. This is a deterministic test: --source include/have_innodb.inc --source include/have_debug.inc --source include/have_debug_sync.inc --connect (con1,localhost,root,,test) --connection default CREATE TABLE t1 (a INT , b INT , c INT , col INT ) ENGINE=InnoDB; INSERT INTO t1 () VALUES (); ALTER TABLE t1 DROP b, DROP c, DROP col; ALTER TABLE t1 ADD COLUMN col INT ; ALTER TABLE t1 DROP a, DROP col, ADD COLUMN b INT ; SET SQL_MODE= '' ; SET DEBUG_SYNC = 'row_log_table_apply1_before SIGNAL scanned WAIT_FOR dml' ; send ALTER TABLE t1 ADD PRIMARY KEY (b); --connection con1 SET DEBUG_SYNC = 'now WAIT_FOR scanned' ; UPDATE t1 SET b = 1; SET DEBUG_SYNC = 'now SIGNAL dml' ; --disconnect con1 --connection default --reap SET DEBUG_SYNC = 'RESET' ; SELECT * FROM t1; DROP TABLE t1; 10.4 46386661a2311cabd7bac914c44b1af0b4746e07 mysqld: storage/innobase/row/row0log.cc:2638: const mrec_t *row_log_table_apply_op(que_thr_t *, ulint, row_merge_dup_t *, dberr_t *, mem_heap_t *, mem_heap_t *, const mrec_t *, const mrec_t *, offset_t *): Assertion `extra_size || !is_instant' failed. If I add ,FORCE to the penultimate ALTER TABLE , there will be no crash.

Marko Mäkelä added a comment - 2020-02-04 16:51

The problem seems to be in row_log_table_get_pk_col(), for translating the column b:

(gdb) p *log->defaults

$18 = {info_bits = 0, n_fields = 4, n_fields_cmp = 4,

  fields = 0x7fffa0080ac0, n_v_fields = 0, v_fields = 0x0, tuple_list = {

    prev = 0x4000, next = 0x7fffa00809b0}, magic_n = 65478679}

(gdb) p *log->defaults->fields@4

$19 = {{data = 0x7fffa0080b40, ext = 0, spatial_status = 0, len = 4, type = {

      prtype = 1283, mtype = 6, len = 4, mbminlen = 0, mbmaxlen = 0}}, {

    data = 0x0, ext = 0, spatial_status = 0, len = 4294967295, type = {

      prtype = 256, mtype = 8, len = 6, mbminlen = 0, mbmaxlen = 0}}, {

    data = 0x0, ext = 0, spatial_status = 0, len = 4294967295, type = {

      prtype = 257, mtype = 8, len = 6, mbminlen = 0, mbmaxlen = 0}}, {

    data = 0x0, ext = 0, spatial_status = 0, len = 4294967295, type = {

      prtype = 258, mtype = 8, len = 7, mbminlen = 0, mbmaxlen = 0}}}

(gdb) i lo

n_default_cols = 5

		ulint n_default_cols = i - DATA_N_SYS_COLS;

		field = static_cast<const byte*>(

			log->defaults->fields[n_default_cols].data);

The n_default_cols is out of the array bounds.

Marko Mäkelä added a comment - 2020-02-04 16:51 The problem seems to be in row_log_table_get_pk_col() , for translating the column b : (gdb) p *log->defaults $18 = {info_bits = 0, n_fields = 4, n_fields_cmp = 4, fields = 0x7fffa0080ac0, n_v_fields = 0, v_fields = 0x0, tuple_list = { prev = 0x4000, next = 0x7fffa00809b0}, magic_n = 65478679} (gdb) p *log->defaults->fields@4 $19 = {{data = 0x7fffa0080b40, ext = 0, spatial_status = 0, len = 4, type = { prtype = 1283, mtype = 6, len = 4, mbminlen = 0, mbmaxlen = 0}}, { data = 0x0, ext = 0, spatial_status = 0, len = 4294967295, type = { prtype = 256, mtype = 8, len = 6, mbminlen = 0, mbmaxlen = 0}}, { data = 0x0, ext = 0, spatial_status = 0, len = 4294967295, type = { prtype = 257, mtype = 8, len = 6, mbminlen = 0, mbmaxlen = 0}}, { data = 0x0, ext = 0, spatial_status = 0, len = 4294967295, type = { prtype = 258, mtype = 8, len = 7, mbminlen = 0, mbmaxlen = 0}}} (gdb) i lo n_default_cols = 5 ulint n_default_cols = i - DATA_N_SYS_COLS; field = static_cast < const byte*>( log ->defaults->fields[n_default_cols].data); The n_default_cols is out of the array bounds.

Marko Mäkelä added a comment - 2020-02-05 09:03

When row_log_table_get_pk_col() is replacing a NULL value for online ADD PRIMARY KEY, it would wrongly assume that columns had not been instantly reordered or dropped. We must pass the altered clustered index definition to the function, so that it can look up the default value of that PRIMARY KEY column in the altered table definition.

Marko Mäkelä added a comment - 2020-02-05 09:03 When row_log_table_get_pk_col() is replacing a NULL value for online ADD PRIMARY KEY , it would wrongly assume that columns had not been instantly reordered or dropped. We must pass the altered clustered index definition to the function, so that it can look up the default value of that PRIMARY KEY column in the altered table definition.

MariaDB Server

Error on online ADD PRIMARY KEY after instant DROP/reorder

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration