[MDEV-24781] Assertion `mode == 16 || mode == 12 || fix_block->page.status != buf_page_t::FREED' failed in buf_page_get_low Created: 2021-02-03  Updated: 2021-02-05  Resolved: 2021-02-05

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

Type: Bug Priority: Major
Reporter: Matthias Leich Assignee: Thirunarayanan Balathandayuthapani
Resolution: Fixed Votes: 0
Labels: rr-profile

Issue Links:
Problem/Incident
is caused by MDEV-515 innodb bulk insert Closed

 Description   

Problem found during RQG testing
mysqld: /Server/bb-10.6-MDEV-24731/storage/innobase/buf/buf0buf.cc:3230: buf_block_t* buf_page_get_low(page_id_t, ulint, ulint, buf_block_t*, ulint, mtr_t*, dberr_t*, bool): Assertion `mode == 16 || mode == 12 || fix_block->page.status != buf_page_t::FREED' failed.
...
Query (0x62b000111238): ALTER TABLE t1 ADD PRIMARY KEY ( col4(10), col1 )
Status: KILL_TIMEOUT
 
#0  0x0000559ccfa3e27e in buf_page_free (space=0x613000122158, page=6, mtr=0x2d4943f35140)
    at /Server/bb-10.6-MDEV-24731/storage/innobase/buf/buf0buf.cc:2510
#1  0x0000559ccfb9d7dd in fseg_free_step (header=0x538310f5304a "", mtr=0x2d4943f35140, ahi=false)
    at /Server/bb-10.6-MDEV-24731/storage/innobase/fsp/fsp0fsp.cc:2751
#2  0x0000559ccf98ecdf in btr_free_but_not_root (block=0x538310ba77a0, log_mode=MTR_LOG_ALL, ahi=false)
    at /Server/bb-10.6-MDEV-24731/storage/innobase/btr/btr0btr.cc:1153
#3  0x0000559ccf98f284 in dict_index_t::clear (this=0x616000bf8c20, thr=0x6170001715d8)
    at /Server/bb-10.6-MDEV-24731/storage/innobase/btr/btr0btr.cc:1206
#4  0x0000559ccf82f73a in dict_table_t::clear (this=0x618000093d20, thr=0x6170001715d8)
    at /Server/bb-10.6-MDEV-24731/storage/innobase/row/row0log.cc:4108
#5  0x0000559ccfc76a9b in row_undo_ins (node=0x61b00004ed20, thr=0x6170001715d8)
    at /Server/bb-10.6-MDEV-24731/storage/innobase/row/row0uins.cc:607
#6  0x0000559ccfa00225 in btr_copy_blob_prefix (
    buf=0x621000352288 '\276' <repeats 200 times>..., len=2049, id=..., 
    offset=38)
    at /Server/bb-10.6-MDEV-24731/storage/innobase/btr/btr0cur.cc:7867
#10 0x0000559ccf81836a in row_log_table_apply_convert_mrec (
    mrec=0x334a4fcb5005 "", index=0x616000bf8c20, offsets=0x60600007e758, 
    log=0x7fc12f71d818, heap=0x621000352118, error=0x26202e839990)
    at /Server/bb-10.6-MDEV-24731/storage/innobase/row/row0log.cc:1620
 
Per short analysis of Marko:
This is a online table rebuild and its claimed that the BLOB is already purged.
It looks like a MDEV-515 related problem.
watch -l *(unsigned*)0x538310ba8fb4
reverse-continue
helps a lot.
 
sdp:/home/mleich/RQG_O/storage/1612370745/TBR-776/dev/shm/vardir/1612370745/50/1/rr
_RR_TRACE_DIR="." rr replay --mark-stdio



 Comments   
Comment by Marko Mäkelä [ 2021-02-03 ]

It seems to me that after dict_table_t::clear() freed all BLOBs of a table when rolling back a MDEV-515 bulk insert, an online table rebuild tried to read a BLOB page while applying older log. I believe that whenever we append ROW_T_EMPTY to the online_log, we must immediately clear online_log->blobs. (In fact, I think that whenever we append that record, we could truncate the entire online_log, but that might be harder to get right.)

Comment by Matthias Leich [ 2021-02-04 ]

origin/bb-10.6-MDEV-24781 8017c3a5801c2ef85cc0a166d2463882eeceb388 2021-02-04T14:23:01+05:30 behaved well in RQG testing.
With some specialized test MDEV-24781 replays quite fast on bb-10.6-MDEV-24731.
On bb-10.6-MDEV-24781 I gave up after 2000 attempts.

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