[MDEV-31385] Change buffer entries are left behind when freeing a page, causing secondary index corruption when the page is later reused Created: 2023-06-01  Updated: 2023-07-26  Resolved: 2023-06-02

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.6, 10.7, 10.8, 10.9, 10.10, 10.11, 11.0, 11.1
Fix Version/s: 10.6.15, 10.9.8, 10.10.6, 10.11.5, 11.0.3, 11.1.2

Type: Bug Priority: Major
Reporter: Thirunarayanan Balathandayuthapani Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: corruption

Issue Links:
Blocks
is blocked by MDEV-31088 Server freeze due to innodb_change_bu... Closed
Relates
relates to MDEV-31264 Purge trying to access freed secondar... Closed

 Description    

[rr 684056 158393]2023-05-25  3:12:42 15 [ERROR] InnoDB: Summed data size 221, returned by func 3502
 
[rr 684056 158397]2023-05-25  3:12:42 15 [ERROR] InnoDB: Apparent corruption in space 0 page 2002 of index `IBUF_DUMMY` of table `IBUF_DUMMY`
 
[rr 684056 158401]2023-05-25  3:12:42 15 [ERROR] InnoDB: Summed data size 221, returned by func 3502
 
[rr 684056 158405]2023-05-25  3:12:42 15 [ERROR] InnoDB: Apparent corruption in space 0 page 2002 of index `IBUF_DUMMY` of table `IBUF_DUMMY`
 
[rr 684056 158410]mysqld: /data/Server/bb-10.6-MDEV-31264/storage/innobase/ibuf/ibuf0ibuf.cc:4319: dberr_t ibuf_merge_or_delete_for_page(buf_block_t*, page_id_t, ulint): Assertion `page_validate(block->page.frame, dummy_index)' failed.
 
 
 
(rr) bt
 
 
 
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=77335817782848) at ./nptl/pthread_kill.c:44
 
#1  __pthread_kill_internal (signo=6, threadid=77335817782848) at ./nptl/pthread_kill.c:78
 
#2  __GI___pthread_kill (threadid=77335817782848, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
 
#3  0x000039e24514d476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
 
#4  0x000039e2451337f3 in __GI_abort () at ./stdlib/abort.c:79
 
#5  0x000039e24513371b in __assert_fail_base (fmt=0x39e2452e8150 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55be517327e0 "page_validate(block->page.frame, dummy_index)", 
    file=0x55be51725f20 "/data/Server/bb-10.6-MDEV-31264/storage/innobase/ibuf/ibuf0ibuf.cc", line=4319, function=<optimized out>) at ./assert/assert.c:92
 
#6  0x000039e245144e96 in __GI___assert_fail (assertion=0x55be517327e0 "page_validate(block->page.frame, dummy_index)", file=0x55be51725f20 "/data/Server/bb-10.6-MDEV-31264/storage/innobase/ibuf/ibuf0ibuf.cc", line=4319, 
    function=0x55be51732340 "dberr_t ibuf_merge_or_delete_for_page(buf_block_t*, page_id_t, ulint)") at ./assert/assert.c:101
 
#7  0x000055be505fe4f0 in ibuf_merge_or_delete_for_page (block=block@entry=0x4b461be028f0, page_id=..., zip_size=zip_size@entry=0) at /data/Server/bb-10.6-MDEV-31264/storage/innobase/ibuf/ibuf0ibuf.cc:4319
 
#8  0x000055be50af170a in buf_page_get_low (page_id=..., zip_size=zip_size@entry=0, rw_latch=rw_latch@entry=2, guess=<optimized out>, guess@entry=0x0, mode=mode@entry=16, mtr=mtr@entry=0x465625f224d0, err=<optimized out>, 
    allow_ibuf_merge=<optimized out>) at /data/Server/bb-10.6-MDEV-31264/storage/innobase/buf/buf0buf.cc:2827
 
#9  0x000055be50af2d9c in buf_page_get_gen (page_id=..., zip_size=zip_size@entry=0, rw_latch=rw_latch@entry=2, guess=guess@entry=0x0, mode=mode@entry=16, mtr=mtr@entry=0x465625f224d0, err=0x465625f22480, 
    allow_ibuf_merge=true) at /data/Server/bb-10.6-MDEV-31264/storage/innobase/buf/buf0buf.cc:2927
 
#10 0x000055be505f4657 in ibuf_read_merge_pages (space_ids=space_ids@entry=0x465625f22c60, page_nos=page_nos@entry=0x465625f22ca0, n_stored=<optimized out>)
 
    at /data/Server/bb-10.6-MDEV-31264/storage/innobase/ibuf/ibuf0ibuf.cc:2373
 
#11 0x000055be505f7ced in ibuf_insert_low (mode=mode@entry=BTR_MODIFY_PREV, op=op@entry=IBUF_OP_INSERT, no_counter=no_counter@entry=0, entry=entry@entry=0x616007250bd8, entry_size=entry_size@entry=13, 
    index=index@entry=0x6160029d6a08, page_id=..., zip_size=<optimized out>, thr=<optimized out>) at /data/Server/bb-10.6-MDEV-31264/storage/innobase/ibuf/ibuf0ibuf.cc:3269
 
#12 0x000055be505fab99 in ibuf_insert (op=op@entry=IBUF_OP_INSERT, entry=entry@entry=0x616007250bd8, index=0x6160029d6a08, page_id=..., zip_size=zip_size@entry=0, thr=<optimized out>)
 
    at /data/Server/bb-10.6-MDEV-31264/storage/innobase/ibuf/ibuf0ibuf.cc:3599
 
#13 0x000055be50a92241 in btr_cur_t::search_leaf (this=this@entry=0x465625f23f00, tuple=tuple@entry=0x616007250bd8, mode=mode@entry=PAGE_CUR_LE, latch_mode=latch_mode@entry=2114, mtr=mtr@entry=0x465625f24410)
 
    at /data/Server/bb-10.6-MDEV-31264/storage/innobase/btr/btr0cur.cc:1136
 
#14 0x000055be507fb9c1 in row_ins_sec_index_entry_low (flags=flags@entry=0, mode=mode@entry=BTR_MODIFY_LEAF, index=index@entry=0x6160029d6a08, offsets_heap=offsets_heap@entry=0x619000ae2480, 
    heap=heap@entry=0x619000ae2980, entry=entry@entry=0x616007250bd8, trx_id=<optimized out>, thr=<optimized out>) at /data/Server/bb-10.6-MDEV-31264/storage/innobase/row/row0ins.cc:3012
 
#15 0x000055be507fe0d6 in row_ins_sec_index_entry (index=index@entry=0x6160029d6a08, entry=entry@entry=0x616007250bd8, thr=thr@entry=0x62100413a250, check_foreign=check_foreign@entry=true)
 
    at /data/Server/bb-10.6-MDEV-31264/storage/innobase/row/row0ins.cc:3319
 
#16 0x000055be50803896 in row_ins_index_entry (index=0x6160029d6a08, entry=0x616007250bd8, thr=thr@entry=0x62100413a250) at /data/Server/bb-10.6-MDEV-31264/storage/innobase/row/row0ins.cc:3367
 
#17 0x000055be50803b93 in row_ins_index_entry_step (node=node@entry=0x621004139f18, thr=thr@entry=0x62100413a250) at /data/Server/bb-10.6-MDEV-31264/storage/innobase/row/row0ins.cc:3533
 
#18 0x000055be508054b9 in row_ins (node=node@entry=0x621004139f18, thr=thr@entry=0x62100413a250) at /data/Server/bb-10.6-MDEV-31264/storage/innobase/row/row0ins.cc:3658
 
#19 0x000055be50805eb2 in row_ins_step (thr=thr@entry=0x62100413a250) at /data/Server/bb-10.6-MDEV-31264/storage/innobase/row/row0ins.cc:3787
 
#20 0x000055be50857928 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x619000ae10c8 "\377\366\004", prebuilt=0x621004139988, ins_mode=<optimized out>)
 
    at /data/Server/bb-10.6-MDEV-31264/storage/innobase/row/row0mysql.cc:1314
 
#21 0x000055be504d4d61 in ha_innobase::write_row (this=0x61d000ce2cb8, record=<optimized out>) at /data/Server/bb-10.6-MDEV-31264/storage/innobase/handler/ha_innodb.cc:7913
 
#22 0x000055be4fa4df57 in handler::ha_write_row (this=0x61d000ce2cb8, buf=0x619000ae10c8 "\377\366\004") at /data/Server/bb-10.6-MDEV-31264/sql/handler.cc:7624
 
#23 0x000055be4f06ca60 in write_record (thd=thd@entry=0x62b00013b218, table=table@entry=0x619000adfc98, info=info@entry=0x465625f25770, sink=sink@entry=0x0) at /data/Server/bb-10.6-MDEV-31264/sql/sql_insert.cc:2157
 
#24 0x000055be4f0860ae in mysql_insert (thd=thd@entry=0x62b00013b218, table_list=<optimized out>, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>, 
    result=<optimized out>) at /data/Server/bb-10.6-MDEV-31264/sql/sql_insert.cc:1129
 
#25 0x000055be4f156e73 in mysql_execute_command (thd=thd@entry=0x62b00013b218, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /data/Server/bb-10.6-MDEV-31264/sql/sql_parse.cc:4570
 
#26 0x000055be4f16441a in mysql_parse (thd=thd@entry=0x62b00013b218, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x465625f26620) at /data/Server/bb-10.6-MDEV-31264/sql/sql_parse.cc:8036
 
#27 0x000055be4f16ac55 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62b00013b218, 
    packet=packet@entry=0x629001130219 "INSERT IGNORE INTO t1 ( id, k) VALUES ( NULL, 269418496 ) /* E_R Thread1 QNO 1566 CON_ID 15 */ ", packet_length=packet_length@entry=95, blocking=blocking@entry=true)
 
    at /data/Server/bb-10.6-MDEV-31264/sql/sql_parse.cc:1896
 
#28 0x000055be4f16fb5c in do_command (thd=0x62b00013b218, blocking=blocking@entry=true) at /data/Server/bb-10.6-MDEV-31264/sql/sql_parse.cc:1409
 
#29 0x000055be4f59b2d6 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x608000002d38, put_in_cache=put_in_cache@entry=true) at /data/Server/bb-10.6-MDEV-31264/sql/sql_connect.cc:1416
 
#30 0x000055be4f59b93c in handle_one_connection (arg=0x608000002d38) at /data/Server/bb-10.6-MDEV-31264/sql/sql_connect.cc:1318
 
#31 0x000039e24519fb43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
 
#32 0x000039e245230bb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100
 
 
 
(rr) 
 
 
 sdp:/data1/results/1685009505/TBR-1510$ _RR_TRACE_DIR=./1/rr rr replay --mark-stdio

Analysis:
========
buf_page_free() marks the state as FREED and reset the IBUF_EXIST state without
removing change buffer merge entries. This lead to stale entries in change buffer
and page_validation fails when page is being resued.

 Comments   
Comment by Thirunarayanan Balathandayuthapani [ 2023-06-01 ] 

@@ -2151,6 +2151,8 @@ void buf_page_free(fil_space_t *space, uint32_t page, mtr_t *mtr)
 
  }
 
 
 
  block->page.lock.x_lock();
 
  if (block->page.is_ibuf_exist())
 
    ibuf_merge_or_delete_for_page(nullptr, page_id, space->zip_size());
 
#ifdef BTR_CUR_HASH_ADAPT
 
  if (block->index)
 
    btr_search_drop_page_hash_index(block, false);

Above code can fix the issue.

Comment by Marko Mäkelä [ 2023-06-01 ]

Thank you. The change looks reasonable to me. It is conceptually similar to MDEV-24569.

However, the added call would trigger MDEV-31088 much more easily. I will try to fix MDEV-31088 and this bug in a single branch.

Comment by Matthias Leich [ 2023-06-02 ] 

origin/bb-10.6-MDEV-30986 d9d63d9ec180f7783d58fdc82607533493b8e306 2023-06-01T12:39:04+03:00
 
which also contains the fix for the current MDEV performed well in RQG testing.

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