[MDEV-21779] Assertion `!memcmp(insert_buf, rec - extra_size, rec_size)' failed in page_cur_insert_rec_low Created: 2020-02-19  Updated: 2020-03-26  Resolved: 2020-03-26

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

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

Issue Links:
Problem/Incident
is caused by MDEV-12353 Efficient InnoDB redo log record format Closed
Relates
relates to MDEV-21850 ASAN use-after-poison in page_cur_ins... Closed

 Description   

--source include/have_innodb.inc
 
CREATE TABLE t1 (
    pk int,
    a int unsigned,
    b int unsigned,
    unique (a),
    unique (b),
    primary key (pk)
) ENGINE=InnoDB;
 
INSERT IGNORE INTO t1 VALUES (1,1,NULL),(2,9,6),(3,2,6),(4,NULL,0),(5,0,NULL);
 
# Cleanup
DROP TABLE t1;

10.5 9fd30949

mysqld: /data/src/10.5/storage/innobase/page/page0cur.cc:1324: rec_t* page_cur_insert_rec_low(const page_cur_t*, dict_index_t*, const rec_t*, offset_t*, mtr_t*): Assertion `!memcmp(insert_buf, rec - extra_size, rec_size)' failed.
200219 19:30:59 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f7359fe4f12 in __GI___assert_fail (assertion=0x55d34b7bc260 "!memcmp(insert_buf, rec - extra_size, rec_size)", file=0x55d34b7bbc70 "/data/src/10.5/storage/innobase/page/page0cur.cc", line=1324, function=0x55d34b7be2e0 <page_cur_insert_rec_low(page_cur_t const*, dict_index_t*, unsigned char const*, unsigned short*, mtr_t*)::__PRETTY_FUNCTION__> "rec_t* page_cur_insert_rec_low(const page_cur_t*, dict_index_t*, const rec_t*, offset_t*, mtr_t*)") at assert.c:101
#8  0x000055d34b00fffc in page_cur_insert_rec_low (cur=0x7f7354378598, index=0x7f732019fa60, rec=0x7f73200688e6 "", offsets=0x7f7354378630, mtr=0x7f7354378890) at /data/src/10.5/storage/innobase/page/page0cur.cc:1324
#9  0x000055d34b1c0572 in page_cur_tuple_insert (cursor=0x7f7354378598, tuple=0x7f7320067eb0, index=0x7f732019fa60, offsets=0x7f7354378538, heap=0x7f7354378510, n_ext=0, mtr=0x7f7354378890) at /data/src/10.5/storage/innobase/include/page0cur.ic:285
#10 0x000055d34b1ce7b9 in btr_cur_optimistic_insert (flags=0, cursor=0x7f7354378590, offsets=0x7f7354378538, heap=0x7f7354378510, entry=0x7f7320067eb0, rec=0x7f7354378540, big_rec=0x7f7354378548, n_ext=0, thr=0x7f732009bc80, mtr=0x7f7354378890) at /data/src/10.5/storage/innobase/btr/btr0cur.cc:3537
#11 0x000055d34b08647b in row_ins_sec_index_entry_low (flags=0, mode=2, index=0x7f732019fa60, offsets_heap=0x7f7320068860, heap=0x7f7320068cf0, entry=0x7f7320067eb0, trx_id=0, thr=0x7f732009bc80) at /data/src/10.5/storage/innobase/row/row0ins.cc:3115
#12 0x000055d34b086d52 in row_ins_sec_index_entry (index=0x7f732019fa60, entry=0x7f7320067eb0, thr=0x7f732009bc80, check_foreign=true) at /data/src/10.5/storage/innobase/row/row0ins.cc:3316
#13 0x000055d34b086f48 in row_ins_index_entry (index=0x7f732019fa60, entry=0x7f7320067eb0, thr=0x7f732009bc80) at /data/src/10.5/storage/innobase/row/row0ins.cc:3361
#14 0x000055d34b0877a5 in row_ins_index_entry_step (node=0x7f732009b9f8, thr=0x7f732009bc80) at /data/src/10.5/storage/innobase/row/row0ins.cc:3528
#15 0x000055d34b087bc9 in row_ins (node=0x7f732009b9f8, thr=0x7f732009bc80) at /data/src/10.5/storage/innobase/row/row0ins.cc:3664
#16 0x000055d34b088374 in row_ins_step (thr=0x7f732009bc80) at /data/src/10.5/storage/innobase/row/row0ins.cc:3807
#17 0x000055d34b0acac5 in row_insert_for_mysql (mysql_rec=0x7f732000b430 "\375\005", prebuilt=0x7f732009b470, ins_mode=ROW_INS_NORMAL) at /data/src/10.5/storage/innobase/row/row0mysql.cc:1463
#18 0x000055d34af0516c in ha_innobase::write_row (this=0x7f732009a828, record=0x7f732000b430 "\375\005") at /data/src/10.5/storage/innobase/handler/ha_innodb.cc:7774
#19 0x000055d34aafbf26 in handler::ha_write_row (this=0x7f732009a828, buf=0x7f732000b430 "\375\005") at /data/src/10.5/sql/handler.cc:6657
#20 0x000055d34a75748c in write_record (thd=0x7f7320000b00, table=0x7f732000a5b0, info=0x7f7354379c60, sink=0x0) at /data/src/10.5/sql/sql_insert.cc:2056
#21 0x000055d34a754402 in mysql_insert (thd=0x7f7320000b00, table_list=0x7f73200135f0, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=true, result=0x0) at /data/src/10.5/sql/sql_insert.cc:1081
#22 0x000055d34a7a5543 in mysql_execute_command (thd=0x7f7320000b00) at /data/src/10.5/sql/sql_parse.cc:4505
#23 0x000055d34a7b145c in mysql_parse (thd=0x7f7320000b00, rawbuf=0x7f73200134a8 "INSERT IGNORE INTO t1 VALUES (1,1,NULL),(2,9,6),(3,2,6),(4,NULL,0),(5,0,NULL)", length=77, parser_state=0x7f735437a570, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7918
#24 0x000055d34a79d105 in dispatch_command (command=COM_QUERY, thd=0x7f7320000b00, packet=0x7f73201580f1 "INSERT IGNORE INTO t1 VALUES (1,1,NULL),(2,9,6),(3,2,6),(4,NULL,0),(5,0,NULL)", packet_length=77, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1845
#25 0x000055d34a79b84c in do_command (thd=0x7f7320000b00) at /data/src/10.5/sql/sql_parse.cc:1364
#26 0x000055d34a93b9a9 in do_handle_one_connection (connect=0x55d34db22380, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1422
#27 0x000055d34a93b6d8 in handle_one_connection (arg=0x55d34db22380) at /data/src/10.5/sql/sql_connect.cc:1319
#28 0x000055d34ae98183 in pfs_spawn_thread (arg=0x55d34daa3c00) at /data/src/10.5/storage/perfschema/pfs.cc:1869
#29 0x00007f735bf6d4a4 in start_thread (arg=0x7f735437b700) at pthread_create.c:456
#30 0x00007f735a0a1d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

The failure appeared in 10.5 recently, I didn't bisect for the exact revision.
No obvious problem on a non-debug build.



 Comments   
Comment by Elena Stepanova [ 2020-03-01 ]

The failure stopped being reproducible after this patch:

commit 572d20757be38157fa2309c35efdec19e68087f1
Author: Marko Mäkelä
Date:   Sat Feb 22 17:32:45 2020 +0200
 
    MDEV-12353: Reduce log volume of page_cur_delete_rec()

I'll leave it to marko to decide whether it is a real fix or the change just masked the problem (and whether the test case is worth adding to the MTR suite).

Comment by Marko Mäkelä [ 2020-03-26 ]

The assertion fails when inserting the value (a,pk)=(0,5) to the UNIQUE INDEX(a). That corresponds to the very last value in the INSERT statement.
The assertion fails, because we failed to copy the correct bytes 80 00 00 05 for the inserted signed int value 5.

That the failure disappeared with 572d20757be38157fa2309c35efdec19e68087f1 could be a coincidence. Later, the code was rewritten in MDEV-21724 and a somewhat similar bug fixed in MDEV-21850. I think that we are fine now.

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