[MDEV-21339] rpl.rpl_sync test failed, assertion page_offset(rec) <= page_header_get_field failed Created: 2019-12-17  Updated: 2023-12-19  Resolved: 2023-12-19

Status: Closed
Project: MariaDB Server
Component/s: N/A
Affects Version/s: 10.2, 10.3, 10.4
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Alice Sherepa Assignee: Alice Sherepa
Resolution: Cannot Reproduce Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-19241 InnoDB fails to write MLOG_INDEX_LOAD... Closed
relates to MDEV-22371 Crash on recovery, assert "page_offse... Open
relates to MDEV-22942 InnoDB: Failing assertion: page_offse... Closed

 Description   

./mtr rpl.rpl_sync,innodb,mix  --repeat=2

10.2 8129ff14407826d54745346c552f

2019-12-17 15:57:40 0x7f2ad34228c0  InnoDB: Assertion failure in file /10.2/storage/innobase/include/page0page.ic line 546
InnoDB: Failing assertion: page_offset(rec) <= page_header_get_field(page, PAGE_HEAP_TOP)
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
InnoDB: about forcing recovery.
191217 15:57:40 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
Server version: 10.2.31-MariaDB-debug-log
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=0
max_threads=153
thread_count=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63104 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x0 thread_stack 0x49000
mysys/stacktrace.c:267(my_print_stacktrace)[0x5590f5b6e324]
sql/signal_handler.cc:209(handle_fatal_signal)[0x5590f5411050]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7f2ad1b6f390]
linux/raise.c:54(__GI_raise)[0x7f2ad0f28428]
stdlib/abort.c:91(__GI_abort)[0x7f2ad0f2a02a]
ut/ut0new.cc:97(ut_new_boot())[0x5590f5964b08]
include/page0page.ic:547(page_rec_check(unsigned char const*))[0x5590f57b99e0]
include/page0page.ic:300(page_rec_is_supremum(unsigned char const*))[0x5590f57c76fb]
page/page0cur.cc:1215(page_cur_insert_rec_low(unsigned char*, dict_index_t*, unsigned char const*, unsigned short*, mtr_t*))[0x5590f5821cc2]
include/page0cur.ic:328(page_cur_rec_insert(page_cur_t*, unsigned char const*, dict_index_t*, unsigned short*, mtr_t*))[0x5590f581f01c]
page/page0cur.cc:1159(page_cur_parse_insert_rec(unsigned long, unsigned char const*, unsigned char const*, buf_block_t*, dict_index_t*, mtr_t*))[0x5590f5821a53]
log/log0recv.cc:1654(recv_parse_or_apply_log_rec_body(mlog_id_t, unsigned char*, unsigned char*, unsigned long, unsigned long, bool, buf_block_t*, mtr_t*))[0x5590f57f4a9a]
log/log0recv.cc:2155(recv_recover_page(buf_block_t*, mtr_t&, recv_addr_t*, unsigned long))[0x5590f57f69a1]
log/log0recv.cc:2484(recv_apply_hashed_log_recs(bool))[0x5590f57f7c22]
srv/srv0start.cc:2248(innobase_start_or_create_for_mysql())[0x5590f590a025]
handler/ha_innodb.cc:4370(innobase_init(void*))[0x5590f5752ee5]
sql/handler.cc:555(ha_initialize_handlerton(st_plugin_int*))[0x5590f541318c]
sql/sql_plugin.cc:1417(plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool))[0x5590f51a8a4a]
sql/sql_plugin.cc:1698(plugin_init(int*, char**, int))[0x5590f51a9677]
sql/mysqld.cc:5333(init_server_components())[0x5590f50b0a62]
sql/mysqld.cc:5929(mysqld_main(int, char**))[0x5590f50b1b3f]
sql/main.cc:26(main)[0x5590f50a6660]
csu/libc-start.c:325(__libc_start_main)[0x7f2ad0f13830]
/10.2/sql/mysqld(_start+0x29)[0x5590f50a6539]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file...
Working directory at /dev/shm/var_auto_rm3J/mysqld.2/data
Resource Limits:
Limit                     Soft Limit           Hard Limit           Units     
Max cpu time              unlimited            unlimited            seconds   
Max file size             unlimited            unlimited            bytes     
Max data size             unlimited            unlimited            bytes     
Max stack size            8388608              unlimited            bytes     
Max core file size        0                    0                    bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             127667               127667               processes 
Max open files            1024                 1024                 files     
Max locked memory         65536                65536                bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       127667               127667               signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us        
Core pattern: |/usr/share/apport/apport %p %s %c %d %P
 
----------SERVER LOG END-------------
mysqltest failed but provided no output
The result from queries just before the failure was:
< snip >
flush tables;
CREATE TABLE t1(a INT, PRIMARY KEY(a)) engine=innodb;
insert into t1(a) values(1);
insert into t1(a) values(2);
insert into t1(a) values(3);
=====Inserting data on the master but without the SQL Thread being running=======;
connection slave;
connection slave;
include/stop_slave_sql.inc
connection master;
insert into t1(a) values(4);
insert into t1(a) values(5);
insert into t1(a) values(6);
=====Removing relay log files and crashing/recoverying the slave=======;
connection slave;
include/stop_slave_io.inc
SET SESSION debug_dbug="d,crash_before_rotate_relaylog";
FLUSH LOGS;
ERROR HY000: Lost connection to MySQL server during query
include/rpl_reconnect.inc



 Comments   
Comment by Marko Mäkelä [ 2023-12-10 ]

10.4 5775df012701144a76eb96501336d53c61fb28a5

rpl.rpl_sync 'innodb,mix'                [ pass ]   4599
rpl.rpl_sync 'innodb,mix'                [ 2 pass ]   3581

Can you still reproduce this? I can’t.

I suspect that the cause of the original failure should be one of the following:

  • A bug in crash recovery
  • A bug that allowed multiple instances of MariaDB Server to start up on the same set of data files.
Comment by Alice Sherepa [ 2023-12-19 ]

not reproducible on current 10.4 87a5d16911bb94 -11.4

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