Bug #30687 Next record offset is nonsensical
Submitted: 29 Aug 2007 10:22 Modified: 30 Sep 2007 10:41
Reporter: Manas Garg Email Updates:
Status: No Feedback Impact on me:
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.0.17 OS:Linux (FC4)
Assigned to: CPU Architecture:Any
Tags: replication, slave

[29 Aug 2007 10:22] Manas Garg

We encountered an error recently during replication where mysql kept restarting itself. We don't know how to reproduce the problem, however, we had taken a backup of the mysql data directory before we re-created the data dir. Whenever, we try to start mysql with the backed up data directory, we get the same error.

Setup & other background information:

There are two nodes A and B. A was setup as the master node which replicated data to B to begin with. Then A node failed for some reason and B took over. Now, B started replicating data to A. At some point of time, the replication process stopped. We do not have the logs to find out why that happened. Now, A had relatively old data and B had new and more data.

Because of another change in the setup, both the nodes (A & B) were re-started and A again became the master mysql node replicating to B. After this B started printing the error "Next record is nonsensical" in the slave.err. This problem couldn't be rectified by just restarting mysql. We went in for a fresh setup of mysql on node B.

Here is the error log from node B [I have not included the page dump as it seemed pretty big for the report. Please let me know if I can send it as an attachment to some id. Also, I have not resolved the stack, please let me know if it's required for this bug report.]

070829 01:49:16  mysqld started
070829  1:49:17  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
070829  1:49:17  InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 0 1404272412.
InnoDB: Doing recovery: scanned up to log sequence number 0 1404352085
070829  1:49:17  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39
 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 8
1 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Next record offset is nonsensical 58798 in record at offset 5
InnoDB: rec address 0x7809c200, first buffer frame 0x77f74000
InnoDB: buffer pool high end 0xb7f74000, buf fix count 1
070829  1:49:17  InnoDB: Page dump in ascii and hex (16384 bytes):
 len 16384; hex 

<lots of data follows/>

;InnoDB: End of page dump
070829  1:49:17  InnoDB: Page checksum 1441612516, prior-to-4.0.14-form checksum 730090228
InnoDB: stored checksum 2283764820, prior-to-4.0.14-form stored checksum 730090228
InnoDB: Page lsn 0 1404268315, low 4 bytes of lsn at page end 1404268315
InnoDB: Page number (if stored to page already) 24728,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 0
InnoDB: Page may be an update undo log page
InnoDB: Page may be an index page where index id is 0 4320
070829  1:49:17InnoDB: Assertion failure in thread 2002197424 in file ../include/page0page.ic line 583
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
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: http://dev.mysql.com/doc/mysql/en/Forcing_recovery.html
InnoDB: about forcing recovery.
mysqld got signal 11;
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.
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.

It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 2302998 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

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...
Cannot determine thread, fp=0x77570498, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/mysql/en/Using_stack_trace.html and follow instructions on how to resolve the stack trac
e. Resolved
stack trace is much more helpful in diagnosing the problem, so please do
resolve it
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.
070829 01:49:17  mysqld ended

How to repeat:
We do not know how it can be reproduced. We just seemed to have run into this situation by chance.
[29 Aug 2007 10:27] Manas Garg
Page dump from slave.err

Attachment: page_dump.txt (text/plain), 51.63 KiB.

[29 Aug 2007 19:59] Valeriy Kravchuk
Thank you for a problem report. Please, specify the exact version, 5.0.x, you had used on slave. Are you sure that memory fault/corruption on disk is impossible?
[30 Aug 2007 7:31] Manas Garg
The setup on which the problem occurred was running mysql-pro-4.1.16. Later on, I took the data directory from there and tried running mysql-pro-5.1.17 against that data directory. The page dump that I have attached came from 5.1.17 version.
[30 Aug 2007 7:32] Manas Garg
Sorry, I meant to say version 5.0.17 in my previous comment.
[30 Aug 2007 10:41] Sveta Smirnova
Thank you for the feedback.

But version 5.0.17 is old and many bugs were fixed since. Please upgrade to current version 5.0.45, try with it and say us result.
[30 Sep 2007 23:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".