[MDEV-21744] Assertion `!rec_offs_nth_sql_null(offsets, n)' failed in btr_cur_upd_rec_in_place Created: 2020-02-17  Updated: 2020-02-17  Resolved: 2020-02-17

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.5
Fix Version/s: 10.5.2

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: regression

Issue Links:
Problem/Incident
is caused by MDEV-12353 Efficient InnoDB redo log record format Closed

 Description   

--source include/have_innodb.inc
 
CREATE TABLE t1 (pk INT, a DATE DEFAULT '0000-00-00', PRIMARY KEY (pk), UNIQUE(a)) ENGINE=InnoDB;
INSERT INTO t1 (pk) VALUES (1);
ALTER TABLE t1 ADD COLUMN b INT;
REPLACE INTO t1 (pk) VALUES (2),(3),(2);
 
# Cleanup
DROP TABLE t1;

10.5 5874aac7

mysqld: /data/src/10.5/storage/innobase/btr/btr0cur.cc:4139: void btr_cur_upd_rec_in_place(rec_t*, const dict_index_t*, const offset_t*, const upd_t*, buf_block_t*, mtr_t*): Assertion `!rec_offs_nth_sql_null(offsets, n)' failed.
200217  4:12:30 [ERROR] mysqld got signal 6 ;
 
#7  0x00007fe11c1d2f12 in __GI___assert_fail (assertion=0x559445daa018 "!rec_offs_nth_sql_null(offsets, n)", file=0x559445da82b0 "/data/src/10.5/storage/innobase/btr/btr0cur.cc", line=4139, function=0x559445daf3a0 <btr_cur_upd_rec_in_place(unsigned char*, dict_index_t const*, unsigned short const*, upd_t const*, buf_block_t*, mtr_t*)::__PRETTY_FUNCTION__> "void btr_cur_upd_rec_in_place(rec_t*, const dict_index_t*, const offset_t*, const upd_t*, buf_block_t*, mtr_t*)") at assert.c:101
#8  0x000055944571b007 in btr_cur_upd_rec_in_place (rec=0x7fe115d200b0 "\200", index=0x7fe0dc19f7f0, offsets=0x7fe115565390, update=0x7fe0dc09a740, block=0x7fe11582cde0, mtr=0x7fe1155655f0) at /data/src/10.5/storage/innobase/btr/btr0cur.cc:4139
#9  0x000055944571c276 in btr_cur_update_in_place (flags=0, cursor=0x7fe115565290, offsets=0x7fe115565390, update=0x7fe0dc09a740, cmpl_info=0, thr=0x7fe0dc068518, trx_id=36, mtr=0x7fe1155655f0) at /data/src/10.5/storage/innobase/btr/btr0cur.cc:4315
#10 0x000055944571dd47 in btr_cur_optimistic_update (flags=0, cursor=0x7fe115565290, offsets=0x7fe115565228, heap=0x7fe115565220, update=0x7fe0dc09a740, cmpl_info=0, thr=0x7fe0dc068518, trx_id=36, mtr=0x7fe1155655f0) at /data/src/10.5/storage/innobase/btr/btr0cur.cc:4559
#11 0x00005594455c94c9 in row_ins_clust_index_entry_by_modify (pcur=0x7fe115565290, flags=0, mode=2, offsets=0x7fe115565228, offsets_heap=0x7fe115565220, heap=0x7fe0dc09a6c0, entry=0x7fe0dc09a2d0, thr=0x7fe0dc068518, mtr=0x7fe1155655f0) at /data/src/10.5/storage/innobase/row/row0ins.cc:365
#12 0x00005594455cff33 in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x7fe0dc19f7f0, n_uniq=1, entry=0x7fe0dc09a2d0, n_ext=0, thr=0x7fe0dc068518) at /data/src/10.5/storage/innobase/row/row0ins.cc:2743
#13 0x00005594455d1955 in row_ins_clust_index_entry (index=0x7fe0dc19f7f0, entry=0x7fe0dc09a2d0, thr=0x7fe0dc068518, n_ext=0) at /data/src/10.5/storage/innobase/row/row0ins.cc:3236
#14 0x0000559445656da8 in row_upd_clust_rec_by_insert (node=0x7fe0dc0681e0, index=0x7fe0dc19f7f0, thr=0x7fe0dc068518, referenced=0, foreign=false, mtr=0x7fe1155662b0) at /data/src/10.5/storage/innobase/row/row0upd.cc:2510
#15 0x00005594456584f7 in row_upd_clust_step (node=0x7fe0dc0681e0, thr=0x7fe0dc068518) at /data/src/10.5/storage/innobase/row/row0upd.cc:2928
#16 0x00005594456588dd in row_upd (node=0x7fe0dc0681e0, thr=0x7fe0dc068518) at /data/src/10.5/storage/innobase/row/row0upd.cc:3002
#17 0x0000559445658ea3 in row_upd_step (thr=0x7fe0dc068518) at /data/src/10.5/storage/innobase/row/row0upd.cc:3146
#18 0x00005594455f8eb3 in row_update_for_mysql (prebuilt=0x7fe0dc0676b0) at /data/src/10.5/storage/innobase/row/row0mysql.cc:1889
#19 0x000055944545224e in ha_innobase::update_row (this=0x7fe0dc00a658, old_row=0x7fe0dc19ee30 "\245\003", new_row=0x7fe0dc19ee20 "\375\002") at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:8569
#20 0x000055944504747b in handler::ha_update_row (this=0x7fe0dc00a658, old_data=0x7fe0dc19ee30 "\245\003", new_data=0x7fe0dc19ee20 "\375\002") at /data/src/10.5/sql/handler.cc:6702
#21 0x0000559444ca2079 in write_record (thd=0x7fe0dc000b00, table=0x7fe0dc06a2a0, info=0x7fe115566c60, sink=0x0) at /data/src/10.5/sql/sql_insert.cc:1976
#22 0x0000559444c9f402 in mysql_insert (thd=0x7fe0dc000b00, table_list=0x7fe0dc0135a0, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_REPLACE, ignore=false, result=0x0) at /data/src/10.5/sql/sql_insert.cc:1081
#23 0x0000559444cf0543 in mysql_execute_command (thd=0x7fe0dc000b00) at /data/src/10.5/sql/sql_parse.cc:4505
#24 0x0000559444cfc45c in mysql_parse (thd=0x7fe0dc000b00, rawbuf=0x7fe0dc0134a8 "REPLACE INTO t1 (pk) VALUES (2),(3),(2)", length=39, parser_state=0x7fe115567570, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7918
#25 0x0000559444ce8105 in dispatch_command (command=COM_QUERY, thd=0x7fe0dc000b00, packet=0x7fe0dc158111 "REPLACE INTO t1 (pk) VALUES (2),(3),(2)", packet_length=39, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1845
#26 0x0000559444ce684c in do_command (thd=0x7fe0dc000b00) at /data/src/10.5/sql/sql_parse.cc:1364
#27 0x0000559444e869a9 in do_handle_one_connection (connect=0x559449149c30, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1422
#28 0x0000559444e866d8 in handle_one_connection (arg=0x559449149c30) at /data/src/10.5/sql/sql_connect.cc:1319
#29 0x00005594453e3183 in pfs_spawn_thread (arg=0x5594490cb650) at /data/src/10.5/storage/perfschema/pfs.cc:1869
#30 0x00007fe11e15b4a4 in start_thread (arg=0x7fe115568700) at pthread_create.c:456
#31 0x00007fe11c28fd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Appeared recently, I didn't bisect for the exact revision.



 Comments   
Comment by Marko Mäkelä [ 2020-02-17 ]

The test does not fail immediately before MDEV-12353. So, MariaDB 10.5.1 is unaffected by this.

Comment by Marko Mäkelä [ 2020-02-17 ]

The failing assertion was introduced along with the physical logging of INSERT operations. Some code changes are needed, because the assertion is documenting an assumption that turns out to be invalid.
Here is a simpler test case:

--source include/have_innodb.inc
CREATE TABLE t1 (pk INT PRIMARY KEY) ENGINE=InnoDB;
INSERT INTO t1 (pk) VALUES (1);
ALTER TABLE t1 ADD COLUMN b INT;
BEGIN;
UPDATE t1 SET pk=2;
UPDATE t1 SET pk=1;
COMMIT;
connect (con1,localhost,root);
SELECT * FROM t1;
disconnect con1;
connection default;
DROP TABLE t1;

The wrong assumption (and assertion) is duplicated in two places: updating the record, and reconstructing an earlier version of the record:

diff --git a/storage/innobase/btr/btr0cur.cc b/storage/innobase/btr/btr0cur.cc
index 186f75dd792..cc7640de010 100644
--- a/storage/innobase/btr/btr0cur.cc
+++ b/storage/innobase/btr/btr0cur.cc
@@ -4405,7 +4405,12 @@ void btr_cur_upd_rec_in_place(rec_t *rec, const dict_index_t *index,
 		ut_ad(!rec_offs_nth_default(offsets, n));
 
 		if (UNIV_UNLIKELY(dfield_is_null(&uf->new_val))) {
-			ut_ad(!rec_offs_nth_sql_null(offsets, n));
+			if (rec_offs_nth_sql_null(offsets, n)) {
+				ut_ad(index->table->is_instant());
+				ut_ad(n >= index->n_core_fields);
+				continue;
+			}
+
 			ut_ad(!index->table->not_redundant());
 			mtr->memset(block,
 				    page_offset(rec + rec_get_field_start_offs(
diff --git a/storage/innobase/trx/trx0rec.cc b/storage/innobase/trx/trx0rec.cc
index d215b07e3a3..16ebe174a4c 100644
--- a/storage/innobase/trx/trx0rec.cc
+++ b/storage/innobase/trx/trx0rec.cc
@@ -2455,7 +2455,11 @@ trx_undo_prev_version_build(
 			ut_ad(!rec_offs_nth_default(offsets, n));
 
 			if (UNIV_UNLIKELY(dfield_is_null(&uf->new_val))) {
-				ut_ad(!rec_offs_nth_sql_null(offsets, n));
+				if (rec_offs_nth_sql_null(offsets, n)) {
+					ut_ad(index->table->is_instant());
+					ut_ad(n >= index->n_core_fields);
+					continue;
+				}
 				ut_ad(!index->table->not_redundant());
 				ulint l = rec_get_1byte_offs_flag(*old_vers)
 					? (n + 1) : (n + 1) * 2;

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