[MDEV-13101] Assertion `0 || offs == 0 + (38U + 36 + 2 * 10) + 0 ... 38U + 0 + 6' failed in recv_parse_or_apply_log_rec_body Created: 2017-06-15  Updated: 2018-01-08  Resolved: 2018-01-08

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2
Fix Version/s: 10.3.4, 10.2.13

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

Sprint: 10.2.12

 Description   

10.2 227bfe446686

2017-06-15 16:39:11 139734300143680 [Note] InnoDB: Highest supported file format is Barracuda.
2017-06-15 16:39:11 139734300143680 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3627999
2017-06-15 16:39:12 139734300143680 [Note] InnoDB: Starting final batch to recover 413 pages from redo log.
mysqld: /data/src/10.2/storage/innobase/log/log0recv.cc:1243: byte* recv_parse_or_apply_log_rec_body(mlog_id_t, byte*, byte*, ulint, ulint, bool, buf_block_t*, mtr_t*): Assertion `0 || offs == 0 + (38U + 36 + 2 * 10) + 0 || offs == 0 + (38U + 36 + 2 * 10) + 4 || offs == 36 + 38U || offs == 36 + 38U + 0 || offs == 36 + 38U + 0 + 6 || offs == 36 + 38U + 4 || offs == 36 + 38U + 0 || offs == (36 + 10) + 38U + 4 || offs == (36 + 10) + 38U + 0 || offs == 36 + 38U + 0 + 0 || offs == 36 + 38U + 0 + 6' failed.
170615 16:39:12 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f166b1ccee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8  0x000055d31f73b94f in recv_parse_or_apply_log_rec_body (type=MLOG_4BYTES, ptr=0x7f1648514898 "", end_ptr=0x7f164851489b "", space_id=0, page_no=20, apply=true, block=0x7f1647479c50, mtr=0x7f164533d590) at /data/src/10.2/storage/innobase/log/log0recv.cc:1218
#9  0x000055d31f73d7e4 in recv_recover_page (just_read_in=true, block=0x7f1647479c50) at /data/src/10.2/storage/innobase/log/log0recv.cc:1851
#10 0x000055d31f91c09a in buf_page_io_complete (bpage=0x7f1647479c50, evict=false) at /data/src/10.2/storage/innobase/buf/buf0buf.cc:6022
#11 0x000055d31f9a9799 in fil_aio_wait (segment=2) at /data/src/10.2/storage/innobase/fil/fil0fil.cc:5507
#12 0x000055d31f85256b in io_handler_thread (arg=0x55d320ed9950 <n+16>) at /data/src/10.2/storage/innobase/srv/srv0start.cc:339
#13 0x00007f166d111494 in start_thread (arg=0x7f164533e700) at pthread_create.c:333
#14 0x00007f166b28993f in clone () from /lib/x86_64-linux-gnu/libc.so.6

To reproduce (set your basedir instead of <basedir>)

git clone https://github.com/elenst/rqg --branch mdev13101 rqg-mdev13101
cd rqg-mdev13101
BASEDIR=<basedir> . ./mdev13101.cmd

The test starts the server from basedir with options

--file-key-management \
--plugin-load-add=file_key_management.so \
--innodb-encrypt-tables \
--innodb-encryption-threads=1 \
--file-key-management-filename=<key file> \

(also listed in mdev13101.cmd with --mysqld prefix), creates one table and runs one SELECT as shown in mdev13101.yy. After a couple of seconds it SIGKILLs the server and restarts it with the same options.



 Comments   
Comment by Marko Mäkelä [ 2018-01-08 ]

This was a bogus debug assertion. In MariaDB, the function fil_crypt_rotate_page() writes dummy MLOG_4BYTES records for (not) updating FIL_SPACE_PAGE_ID, because any page write needs some (dummy) redo log record write.

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