[MDEV-30111] InnoDB: Failing assertion: update->n_fields == 0 in row_ins_sec_index_entry_by_modify Created: 2022-11-28  Updated: 2023-11-28

Status: Open
Project: MariaDB Server
Component/s: Character Sets, Storage Engine - InnoDB
Affects Version/s: 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Alexander Barkov
Resolution: Unresolved Votes: 0
Labels: None


 Description   

--source include/have_innodb.inc
 
CREATE TABLE t (a INT, b VARCHAR(16), c CHAR(8), PRIMARY KEY (b,c), KEY(c)) ENGINE=InnoDB CHARACTER SET utf8mb3 COLLATE utf8mb3_general_nopad_ci;
INSERT INTO t VALUES (1,UNHEX('0001050001'),''),(2,UNHEX('0000'),'x');
UPDATE t SET a = 0;
INSERT INTO t VALUES (0,'','');
 
# Cleanup
DROP TABLE t;

10.3 4e920673

2022-11-28 15:01:25 0x7ff8a9a09300  InnoDB: Assertion failure in file /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/row/row0ins.cc line 220
InnoDB: Failing assertion: update->n_fields == 0
 
#6  0x000055a77f60d2a1 in ut_dbg_assertion_failed (expr=0x55a7805d2840 "update->n_fields == 0", file=0x55a7805d2500 "/home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/row/row0ins.cc", line=220) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/ut/ut0dbg.cc:60
#7  0x000055a77f3d7c41 in row_ins_sec_index_entry_by_modify (flags=0, mode=2, cursor=0x7ff8a9a03ac0, offsets=0x7ff8a9a03a00, offsets_heap=0x6190000d8e80, heap=0x6190000d9380, entry=0x6160000580c0, thr=0x6210000969d0, mtr=0x7ff8a9a03e80) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/row/row0ins.cc:220
#8  0x000055a77f3e7074 in row_ins_sec_index_entry_low (flags=0, mode=2, index=0x618000048508, offsets_heap=0x6190000d8e80, heap=0x6190000d9380, entry=0x6160000580c0, trx_id=0, thr=0x6210000969d0) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/row/row0ins.cc:3098
#9  0x000055a77f3e8265 in row_ins_sec_index_entry (index=0x618000048508, entry=0x6160000580c0, thr=0x6210000969d0, check_foreign=true) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/row/row0ins.cc:3292
#10 0x000055a77f3e863a in row_ins_index_entry (index=0x618000048508, entry=0x6160000580c0, thr=0x6210000969d0) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/row/row0ins.cc:3340
#11 0x000055a77f3e92cc in row_ins_index_entry_step (node=0x621000096710, thr=0x6210000969d0) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/row/row0ins.cc:3489
#12 0x000055a77f3e9d80 in row_ins (node=0x621000096710, thr=0x6210000969d0) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/row/row0ins.cc:3648
#13 0x000055a77f3eaff5 in row_ins_step (thr=0x6210000969d0) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/row/row0ins.cc:3798
#14 0x000055a77f435ccb in row_insert_for_mysql (mysql_rec=0x6190000d70b8 "\376", prebuilt=0x621000096188, ins_mode=ROW_INS_NORMAL) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/row/row0mysql.cc:1419
#15 0x000055a77f103c31 in ha_innobase::write_row (this=0x61c0000630a8, record=0x6190000d70b8 "\376") at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/innobase/handler/ha_innodb.cc:8201
#16 0x000055a77ebbc432 in handler::ha_write_row (this=0x61c0000630a8, buf=0x6190000d70b8 "\376") at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/sql/handler.cc:6495
#17 0x000055a77e39b885 in write_record (thd=0x62a0000ba208, table=0x61f000042888, info=0x7ff8a9a05cc0) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/sql/sql_insert.cc:2054
#18 0x000055a77e393d8a in mysql_insert (thd=0x62a0000ba208, table_list=0x62b000000338, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/sql/sql_insert.cc:1077
#19 0x000055a77e4391f7 in mysql_execute_command (thd=0x62a0000ba208) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/sql/sql_parse.cc:4505
#20 0x000055a77e450e9a in mysql_parse (thd=0x62a0000ba208, rawbuf=0x62b000000228 "INSERT INTO t VALUES (0,'','')", length=30, parser_state=0x7ff8a9a07950, is_com_multi=false, is_next_command=false) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/sql/sql_parse.cc:7855
#21 0x000055a77e4284e8 in dispatch_command (command=COM_QUERY, thd=0x62a0000ba208, packet=0x629000136209 "INSERT INTO t VALUES (0,'','')", packet_length=30, is_com_multi=false, is_next_command=false) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/sql/sql_parse.cc:1852
#22 0x000055a77e4250a0 in do_command (thd=0x62a0000ba208) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/sql/sql_parse.cc:1398
#23 0x000055a77e7e8b8c in do_handle_one_connection (connect=0x608000000ea8) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/sql/sql_connect.cc:1404
#24 0x000055a77e7e8488 in handle_one_connection (arg=0x608000000ea8) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/sql/sql_connect.cc:1309
#25 0x000055a77fd95929 in pfs_spawn_thread (arg=0x615000007608) at /home/jenkins/workspace/sandbox-elenst/Nightly-Build-CS/src/storage/perfschema/pfs.cc:1869
#26 0x00007ff8c03e4ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#27 0x00007ff8c0304aef in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Fails the same way on debug and release.



 Comments   
Comment by Marko Mäkelä [ 2022-11-28 ]

At the time of the assertion failure:

10.3 4e9206736c403206915c09db1c9d8e3cd0fd0c5b

2022-11-28 15:03:28 0x7fb80c05f6c0  InnoDB: Assertion failure in file /mariadb/10.3/storage/innobase/row/row0ins.cc line 220
InnoDB: Failing assertion: update->n_fields == 0

we have the following records in the buffer pool pages:
Secondary index (c,b)=('',0x0001050001),('x',0x0000)
Clustered index (b,c,DB_TRX_ID,DB_ROLL_PTR,a)=('','',39,(insert),0),(0x0000,'x',0,1<<55,0),(0x0001050001,'',0,1<<55,0).

The length of each field b or c is encoded explicitly; column c is 8 bytes, space-padded). No record is delete-marked.

Updating the PRIMARY KEY should delete-mark the old key (in all indexes) and then insert a new key into each index.

The crash occurs on the 2nd row that was processed by the UPDATE statement. At the start of that statement, the index entries are as follows:

Secondary index: (b,c)=('',0x000105001),('x',0x0000)
Clustered index: (c,b,DB_TRX_ID,DB_ROLL_PTR,a)=(0x0000,0,1<<55,2),(0x0001050001,'',0,1<<55,1)

That looks correct. DB_TRX_ID=0 means that all history has been purged (the record is visible in all read views). After the UPDATE…SET a=0 of the first row, we have the following:

Secondary index: (b,c)=('',0x000105001),('x',0x0000) (no change from previous)
Clustered index: (c,b,DB_TRX_ID,DB_ROLL_PTR,a)=(0x0000,'x',37,(update),0),(0x0001050001,'',0,1<<55,1)

After the UPDATE…SET a=0 of the second row, we have the following:

Secondary index: (b,c)=('',0x000105001),('x',0x0000) (no change from previous)
Clustered index: (c,b,DB_TRX_ID,DB_ROLL_PTR,a)=(0x0000,'x',37,(update),0),(0x0001050001,'',37,(update),0)

This is as I would expect.

The crash occurs on the INSERT by transaction ID 39. It had already successfully inserted a record into the clustered index (see the first dump) but not to the secondary index record. The comment before the failing assertion explains the problem:

		/* We should never insert in place of a record that
		has not been delete-marked. The only exception is when
		online CREATE INDEX copied the changes that we already
		made to the clustered index, and completed the
		secondary index creation before we got here. In this
		case, the change would already be there. The CREATE
		INDEX should be waiting for a MySQL meta-data lock
		upgrade at least until this INSERT or UPDATE
		returns. After that point, set_committed(true)
		would be invoked in commit_inplace_alter_table(). */
		ut_a(update->n_fields == 0);

It appears that we failed to notice a duplicate in the PRIMARY KEY during the INSERT, or the collation function is delivering inconsistent results. I see the following calls during the execution of the crashing INSERT statement:

(rr) finish
Run till exit from #0  my_strnncollsp_utf8_general_nopad_ci (
    cs=0x55bbf2b612c0 <my_charset_utf8_general_nopad_ci>, a=0x7fb8080a701e "", 
    a_length=0, b=0x7fb81dd4c0a6 "", b_length=2)
    at /mariadb/10.3/strings/strcoll.inl:221
0x000055bbf27517c3 in innobase_mysql_cmp (prtype=prtype@entry=69271823, a=a@entry=0x7fb8080a701e "", a_length=a_length@entry=0, b=b@entry=0x7fb81dd4c0a6 "", b_length=b_length@entry=2) at /mariadb/10.3/storage/innobase/rem/rem0cmp.cc:94
94	}
Value returned is $10 = 0

This claims that '' is equal to 0x0000, while inserting into the clustered index.

(rr) finish
Run till exit from #0  my_strnncollsp_utf8_general_nopad_ci (
    cs=0x55bbf2b612c0 <my_charset_utf8_general_nopad_ci>, 
    a=0x7fb8080a704e ' ' <repeats 24 times>, "\245\245\376\001", a_length=8, 
    b=0x7fb81dd4c0a8 "x       ", b_length=8)
    at /mariadb/10.3/strings/strcoll.inl:221
0x000055bbf27517c3 in innobase_mysql_cmp (prtype=prtype@entry=69272062, a=a@entry=0x7fb8080a704e ' ' <repeats 24 times>, "\245\245\376\001", a_length=a_length@entry=8, b=b@entry=0x7fb81dd4c0a8 "x       ", b_length=b_length@entry=8) at /mariadb/10.3/storage/innobase/rem/rem0cmp.cc:94
94	}
Value returned is $11 = -56

This claims that 'x' is less than ''. So, the record was inserted at the start of the clustered index.

There were 2 more calls for debug assertions for the clustered index. For the secondary index, the next call is:

(rr) finish
Run till exit from #0  my_strnncollsp_utf8_general_nopad_ci (
    cs=0x55bbf2b612c0 <my_charset_utf8_general_nopad_ci>, 
    a=0x7fb8080a704e ' ' <repeats 24 times>, "\245\245\376\001", a_length=8, 
    b=0x7fb81dd5007f "        ", b_length=8)
    at /mariadb/10.3/strings/strcoll.inl:221
0x000055bbf27517c3 in innobase_mysql_cmp (prtype=prtype@entry=69272062, a=a@entry=0x7fb8080a704e ' ' <repeats 24 times>, "\245\245\376\001", a_length=a_length@entry=8, b=b@entry=0x7fb81dd5007f "        ", b_length=b_length@entry=8) at /mariadb/10.3/storage/innobase/rem/rem0cmp.cc:94
94	}
Value returned is $14 = 0

According to this, the empty string (padded with 8 spaces) is equal to itself. I can agree with that.

(rr) finish
Run till exit from #0  my_strnncollsp_utf8_general_nopad_ci (
    cs=0x55bbf2b612c0 <my_charset_utf8_general_nopad_ci>, a=0x7fb8080a701e "", 
    a_length=0, b=0x7fb81dd50087 "", b_length=5)
    at /mariadb/10.3/strings/strcoll.inl:221
0x000055bbf27517c3 in innobase_mysql_cmp (prtype=prtype@entry=69271823, a=a@entry=0x7fb8080a701e "", a_length=a_length@entry=0, b=b@entry=0x7fb81dd50087 "", b_length=b_length@entry=5) at /mariadb/10.3/storage/innobase/rem/rem0cmp.cc:94
94	}
Value returned is $15 = 0

This claims that the empty string is equal to 0x0001050001. It looks wrong to me!
Finally, there is a comparison of ''<'x', which looks correct to me, and then the assertion failure.

Generated at Thu Feb 08 10:13:44 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.