Description:
Our database server is running FreeBSD 5.0.4 with Mysql version 5.0.11, and is a replication master. Our slave machine is running the same configuration. The database master comes under heavy load, as it hosts the databases for our web store, which runs a modified version of a shopping cart called Storefront, which creates several DB records for every visitor. The crash occurs when the code attempts to delete serveral thousand records from one InnoDB table. Once the DB server comes back from the crash, the table is reported as corrupt by CHECK TABLE, and needs to be restored from backup (if subsequent selects are performed on the table and it is not restored, the DB server just keeps crashing after every query). The reason I mentioned the slave machine being part of the configuration is that the slave's database also becomes corrupt when the master's does. We have been operating with the exact same schema on version 4.1 of Mysql for some time now without any problems. The following is what appears in the error log after the crash:
050831 15:38:18 mysqld ended
050831 15:55:31 mysqld started
050831 15:55:32 InnoDB: Started; log sequence number 0 2216346649
050831 15:55:32 [Note] /usr/local/libexec/mysqld: ready for connections.
Version: '5.0.11-beta-log' socket: '/tmp/mysql.sock' port: 3306 FreeBSD port: mysql-server-5.0.11
050902 6:27:07 InnoDB: Page dump in ascii and hex (16384 bytes):
len 16384; hex
{several pages of HEX, including pieces of ASCII data from affected tables}
InnoDB: End of page dump
050902 6:27:07 InnoDB: Page checksum 2604776410, prior-to-4.0.14-form checksum 3335900197
InnoDB: stored checksum 2297191503, prior-to-4.0.14-form stored checksum 3624587645
InnoDB: Page lsn 0 2276057858, low 4 bytes of lsn at page end 2276057858
InnoDB: Page number (if stored to page already) 18784,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 0
InnoDB: Page may be an index page where index id is 0 609
InnoDB: (index PRIMARY of table storefront/customer)
050902 6:27:07 InnoDB: Page dump in ascii and hex (16384 bytes):
len 16384; hex
InnoDB: End of page dump
050902 10:20:33 InnoDB: Page checksum 1497439258, prior-to-4.0.14-form checksum 4060562682
InnoDB: stored checksum 2976445453, prior-to-4.0.14-form stored checksum 4060562682
InnoDB: Page lsn 0 2282474463, low 4 bytes of lsn at page end 2282474463
InnoDB: Page number (if stored to page already) 18814,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 0
InnoDB: Page may be an index page where index id is 0 609
InnoDB: (index PRIMARY of table storefront/customer)
InnoDB: Error: page old data size 14003 new data size 14203
InnoDB: Error: page old max ins size 2195 new max ins size 1995
InnoDB: Submit a detailed bug report to http://bugs.mysql.com
InnoDB: Error: trying to access page number 2147322239 in space 0,
InnoDB: space name /var/db/mysql/ibdata1,
InnoDB: which is outside the tablespace bounds.
InnoDB: Byte offset 0, len 16384, i/o type 10
050902 10:31:12InnoDB: Assertion failure in thread 793017344 in file fil0fil.c line 3869
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.
key_buffer_size=402653184
read_buffer_size=2093056
max_used_connections=25
max_connections=100
threads_connected=8
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 802415 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
050902 10:31:12 mysqld restarted
050902 10:31:13 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...
050902 10:31:13 InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 0 2283021918.
InnoDB: Doing recovery: scanned up to log sequence number 0 2283022910
050902 10:31:13 InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 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 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 35483901, file name ./mysql-bin.001745
050902 10:31:14 InnoDB: Started; log sequence number 0 2283022910
050902 10:31:14 [Note] Recovering after a crash using mysql-bin
050902 10:31:15 [Note] Starting crash recovery...
050902 10:31:15 [Note] Crash recovery finished.
050902 10:31:15 [Warning] 'user' entry 'root@db10.primetimesolutions.net' ignored in --skip-name-resolve mode.
050902 10:31:15 [Note] /usr/local/libexec/mysqld: ready for connections.
Version: '5.0.11-beta-log' socket: '/tmp/mysql.sock' port: 3306 FreeBSD port: mysql-server-5.0.11
InnoDB: Error: trying to access page number 2147322239 in space 0,
InnoDB: space name /var/db/mysql/ibdata1,
InnoDB: which is outside the tablespace bounds.
InnoDB: Byte offset 0, len 16384, i/o type 10
050902 10:31:15InnoDB: Assertion failure in thread 791524352 in file fil0fil.c line 3869
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.
InnoDB: Thread 791526400 stopped in file row0mysql.c line 142
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.
key_buffer_size=402653184
read_buffer_size=2093056
max_used_connections=4
max_connections=100
threads_connected=4
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 802415 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
050902 10:31:15 mysqld restarted
I cut out the page dumps simply because they are so large, but if a developer from MySQL would like to see them I'd be happy to provide the entire file.
How to repeat:
There is no set amount of steps involved in repeating this bug, the server crash seems to occur intermittently (sometimes hours, sometimes several days apart).
Description: Our database server is running FreeBSD 5.0.4 with Mysql version 5.0.11, and is a replication master. Our slave machine is running the same configuration. The database master comes under heavy load, as it hosts the databases for our web store, which runs a modified version of a shopping cart called Storefront, which creates several DB records for every visitor. The crash occurs when the code attempts to delete serveral thousand records from one InnoDB table. Once the DB server comes back from the crash, the table is reported as corrupt by CHECK TABLE, and needs to be restored from backup (if subsequent selects are performed on the table and it is not restored, the DB server just keeps crashing after every query). The reason I mentioned the slave machine being part of the configuration is that the slave's database also becomes corrupt when the master's does. We have been operating with the exact same schema on version 4.1 of Mysql for some time now without any problems. The following is what appears in the error log after the crash: 050831 15:38:18 mysqld ended 050831 15:55:31 mysqld started 050831 15:55:32 InnoDB: Started; log sequence number 0 2216346649 050831 15:55:32 [Note] /usr/local/libexec/mysqld: ready for connections. Version: '5.0.11-beta-log' socket: '/tmp/mysql.sock' port: 3306 FreeBSD port: mysql-server-5.0.11 050902 6:27:07 InnoDB: Page dump in ascii and hex (16384 bytes): len 16384; hex {several pages of HEX, including pieces of ASCII data from affected tables} InnoDB: End of page dump 050902 6:27:07 InnoDB: Page checksum 2604776410, prior-to-4.0.14-form checksum 3335900197 InnoDB: stored checksum 2297191503, prior-to-4.0.14-form stored checksum 3624587645 InnoDB: Page lsn 0 2276057858, low 4 bytes of lsn at page end 2276057858 InnoDB: Page number (if stored to page already) 18784, InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 0 InnoDB: Page may be an index page where index id is 0 609 InnoDB: (index PRIMARY of table storefront/customer) 050902 6:27:07 InnoDB: Page dump in ascii and hex (16384 bytes): len 16384; hex InnoDB: End of page dump 050902 10:20:33 InnoDB: Page checksum 1497439258, prior-to-4.0.14-form checksum 4060562682 InnoDB: stored checksum 2976445453, prior-to-4.0.14-form stored checksum 4060562682 InnoDB: Page lsn 0 2282474463, low 4 bytes of lsn at page end 2282474463 InnoDB: Page number (if stored to page already) 18814, InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 0 InnoDB: Page may be an index page where index id is 0 609 InnoDB: (index PRIMARY of table storefront/customer) InnoDB: Error: page old data size 14003 new data size 14203 InnoDB: Error: page old max ins size 2195 new max ins size 1995 InnoDB: Submit a detailed bug report to http://bugs.mysql.com InnoDB: Error: trying to access page number 2147322239 in space 0, InnoDB: space name /var/db/mysql/ibdata1, InnoDB: which is outside the tablespace bounds. InnoDB: Byte offset 0, len 16384, i/o type 10 050902 10:31:12InnoDB: Assertion failure in thread 793017344 in file fil0fil.c line 3869 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. key_buffer_size=402653184 read_buffer_size=2093056 max_used_connections=25 max_connections=100 threads_connected=8 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 802415 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. 050902 10:31:12 mysqld restarted 050902 10:31:13 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... 050902 10:31:13 InnoDB: Starting log scan based on checkpoint at InnoDB: log sequence number 0 2283021918. InnoDB: Doing recovery: scanned up to log sequence number 0 2283022910 050902 10:31:13 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 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 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Apply batch completed InnoDB: Last MySQL binlog file position 0 35483901, file name ./mysql-bin.001745 050902 10:31:14 InnoDB: Started; log sequence number 0 2283022910 050902 10:31:14 [Note] Recovering after a crash using mysql-bin 050902 10:31:15 [Note] Starting crash recovery... 050902 10:31:15 [Note] Crash recovery finished. 050902 10:31:15 [Warning] 'user' entry 'root@db10.primetimesolutions.net' ignored in --skip-name-resolve mode. 050902 10:31:15 [Note] /usr/local/libexec/mysqld: ready for connections. Version: '5.0.11-beta-log' socket: '/tmp/mysql.sock' port: 3306 FreeBSD port: mysql-server-5.0.11 InnoDB: Error: trying to access page number 2147322239 in space 0, InnoDB: space name /var/db/mysql/ibdata1, InnoDB: which is outside the tablespace bounds. InnoDB: Byte offset 0, len 16384, i/o type 10 050902 10:31:15InnoDB: Assertion failure in thread 791524352 in file fil0fil.c line 3869 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. InnoDB: Thread 791526400 stopped in file row0mysql.c line 142 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. key_buffer_size=402653184 read_buffer_size=2093056 max_used_connections=4 max_connections=100 threads_connected=4 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 802415 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. 050902 10:31:15 mysqld restarted I cut out the page dumps simply because they are so large, but if a developer from MySQL would like to see them I'd be happy to provide the entire file. How to repeat: There is no set amount of steps involved in repeating this bug, the server crash seems to occur intermittently (sometimes hours, sometimes several days apart).