Marko Mäkelä added a comment - 2020-03-09 17:49 In the case that I analyzed, I observed 3 or 4 mini-transactions for the page: Create the B-tree page (root page of a secondary index, page 36 in the tablespace). Insert one record to the B-tree page, with the key 0x80000000 (looks like the PRIMARY KEY was an empty string). Update the PAGE_MAX_TRX_ID and delete-mark the record. Delete a non-existing record with the non-existing predecessor at byte offset 0x8a. We could detect the inconsistency earlier, by checking that the predecessor record is not beyond PAGE_HEAP_TOP . We could copy some further consistency checks from the INSERT function. Until we have a reasonably repeatable test case, it is not known what is causing this. It would seem that some log is missing. A bug in Mariabackup?

Marko Mäkelä added a comment - 2020-03-26 18:12 I think that I finally found the cause. It was rather challenging, so I am providing details for future reference, to aid in similar debugging. The patch is simple, and the cause is MDEV-21724 : diff --git a/storage/innobase/page/page0cur.cc b/storage/innobase/page/page0cur.cc index bce7231059a..ec79450995a 100644 --- a/storage/innobase/page/page0cur.cc +++ b/storage/innobase/page/page0cur.cc @@ -1551,7 +1551,6 @@ page_cur_insert_rec_low( /* Insert the record, possibly copying from the preceding record. */ ut_ad(mtr->get_log_mode() == MTR_LOG_ALL); - if (data_size) { const byte *r= rec; const byte *c= cur->rec; In a provided dataset, there were at least 2 pages for which the record failed to apply: pages 5:9 and 5:12. I concentrated on page 5:9. For that one, I instrumented the crash recovery with gdb as follows: break ib::error::~error break page_apply_delete_dynamic cond 2 block.page.id.m_id==0x500000009 break 'recv_recover_page(buf_block_t*, mtr_t&, std::_Rb_tree_iterator<std::pair<page_id_t const, page_recv_t> > const&, fil_space_t*, mlog_init_t::init*)' cond 3 block.page.id.m_id==0x500000009 command 3 set scheduler-locking on enable 4 continue break log_phys_t::apply disable 4 continue … display/x *begin()@len display *this command 4 continue end continue There were 2 page_apply_delete_dynamic() calls to this page. The second one failed, because it was pointing to an area in the page that was filled with zero bytes. That is, the next-record loop to find the record owner in the sparse page directory would exceed n_recs and the page would correctly be regarded as corrupted. Aimed with the knowledge on the LSN and the redo log record contents, I used the provided rr replay environment. First, I think that I let it run to the end (to the SIGKILL that was originally initiated by RQG), and did when to see how many steps there are in total. It was above 4 million. Then, I did roughly the following in the end (omitting lots of steps): run 4000000 break row_upd_sec_index_entry cond 1 log_sys.lsn._M_i>176623800 break mtr_buf_t::close cond 2 log_sys.lsn._M_i>176623800 define find_page_105 set $id=((unsigned long long)$arg0)<<32|$arg1 set $chunk=buf_pool->chunks set $i=buf_pool->n_chunks set $found=0 while ($i-- && !$found) set $j = $chunk->size set $b = $chunk->blocks while ($j--) if ($b->page.id.m_id==$id) print $b set $found=1 loop_break end set $b++ end set $chunk++ end end   document find_page_105 Buffer pool look-up: find_page_105 space_id page_no" end find_page_105 5 3 watch -l *(ulonglong*)$1.frame[0x38]@8 watch -l $1.frame[0x7a] display/x $1.frame[0x38]@8 display log_sys.lsn The first hardware watchpoint is for PAGE_MAX_TRX_ID on the page. The page turned out to be a secondary index page. The second watchpoint is for a byte that used to be a delete-mark flag that was set back and forth by the test. It was accidentally hit by the page_cur_insert_rec_low() . Thanks to the breakpoint on mtr_buf_t::close , which was not called for that insert, I knew that something is wrong. So, I went back in time by issuing when run (the reported number - a little bit) and single-stepped through the function page_cur_insert_rec_low() . The condition that my patch above removed is redundant and outright harmful. It is a rare corner case that a secondary index record has no data payload at all. It is possible when the PRIMARY KEY consists of variable-length string columns that are all empty, and all secondary index columns are either NULL or the empty string. We failed to write the INSERT_REUSE_DYNAMIC redo log record for the following statement: REPLACE INTO `table100_innodb_default` ( `col_text_latin1_unique_default_null` ) VALUES ( 5900288 ); This was on the secondary index col_char_latin1_unique , and the value is (NULL,'') , as expected.