[MDEV-12144] Signal 6 crash corrupts ibd files - Jira

Edward Hicks created issue - 2017-02-27 15:58

Elena Stepanova made changes - 2017-02-27 16:12

Field	Original Value	New Value
Fix Version/s		10.0 [ 16000 ]
Assignee		Marko Mäkelä [ marko ]

Edward Hicks made changes - 2017-02-27 16:28

Description

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29.

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

Edward Hicks made changes - 2017-02-27 16:28

Description

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

{{2017-02-27 01:25:07 7f50466df700 InnoDB: Assertion failure in thread 139982755723008 in file buf0lru.cc line 2245
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/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb924ab]
/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x739136]
/lib64/libpthread.so.0[0x323120f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x3230e325e5]
/lib64/libc.so.6(abort+0x175)[0x3230e33dc5]
/usr/sbin/mysqld[0x9c86c9]
/usr/sbin/mysqld[0x8db7d5]
/usr/sbin/mysqld[0x9280e8]
/usr/sbin/mysqld[0x8835ff]
/usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x3a)[0x67c43a]
/usr/sbin/mysqld(_Z18intern_close_tableP5TABLE+0x59)[0x59a609]
/usr/sbin/mysqld(_Z8tc_purgeb+0x285)[0x6e88f5]
/usr/sbin/mysqld(_Z19close_cached_tablesP3THDP10TABLE_LISTbm+0x8f)[0x5a317f]
/usr/sbin/mysqld(_Z20reload_acl_and_cacheP3THDyP10TABLE_LISTPi+0x3ce)[0x6c023e]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4889)[0x5e3899]
/usr/sbin/mysqld[0x5e5a97]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6c)[0x5e7e6c]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6a6f13]
/usr/sbin/mysqld(handle_one_connection+0x42)[0x6a6fe2]
/lib64/libpthread.so.0[0x3231207aa1]
/lib64/libc.so.6(clone+0x6d)[0x3230ee8aad]
170227 01:25:09 mysqld_safe Number of processes running now: 0
170227 01:25:09 mysqld_safe mysqld restarted
170227 1:25:09 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB) starting as process 23465 ...
170227 1:25:09 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170227 1:25:09 [Note] InnoDB: The InnoDB memory heap is disabled
170227 1:25:09 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170227 1:25:09 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
170227 1:25:09 [Note] InnoDB: Compressed tables use zlib 1.2.3
170227 1:25:09 [Note] InnoDB: Using Linux native AIO
170227 1:25:10 [Note] InnoDB: Using CPU crc32 instructions
170227 1:25:10 [Note] InnoDB: Initializing buffer pool, size = 7.0G
170227 1:25:10 [Note] InnoDB: Completed initialization of buffer pool
170227 1:25:10 [Note] InnoDB: Highest supported file format is Barracuda.
170227 1:25:10 [Note] InnoDB: Log scan progressed past the checkpoint lsn 6877178025086
170227 1:25:10 [Note] InnoDB: Database was not shutdown normally!
170227 1:25:10 [Note] InnoDB: Starting crash recovery.
170227 1:25:10 [Note] InnoDB: Reading tablespace information from the .ibd files...
170227 1:28:01 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535
170227 1:28:01 [ERROR] InnoDB: innodb-page-size mismatch in tablespace ./optometrydb/page_manager_handlers.ibd (table optometrydb/page_manager_handlers)
170227 1:28:01 [Note] InnoDB: Page size:1024 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 1024, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:2048 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 2048, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:4096 Pages to analyze:32
170227 1:28:01 [Note] InnoDB: Page size: 4096, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:8192 Pages to analyze:16
170227 1:28:01 [Note] InnoDB: Page size: 8192, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:16384 Pages to analyze:8
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:1 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:2 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:3 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:4 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:5 page_size:16384
170227 1:28:01 [Note] InnoDB: Page size: 16384, Possible space_id count:1
170227 1:28:01 [Note] InnoDB: space_id:1859997, Number of pages matched: 5/5 (16384)
170227 1:28:01 [Note] InnoDB: Chosen space:1859997

170227 1:28:01 [Note] InnoDB: Restoring page 0 of tablespace 1859997
170227 1:28:01 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1859997
2017-02-27 01:28:01 7f7346996820 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
InnoDB: Error: could not open single-table tablespace file ./optometrydb/page_manager_handlers.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.
}}

Edward Hicks made changes - 2017-02-27 16:29

Description

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

{{2017-02-27 01:25:07 7f50466df700 InnoDB: Assertion failure in thread 139982755723008 in file buf0lru.cc line 2245
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/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb924ab]
/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x739136]
/lib64/libpthread.so.0[0x323120f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x3230e325e5]
/lib64/libc.so.6(abort+0x175)[0x3230e33dc5]
/usr/sbin/mysqld[0x9c86c9]
/usr/sbin/mysqld[0x8db7d5]
/usr/sbin/mysqld[0x9280e8]
/usr/sbin/mysqld[0x8835ff]
/usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x3a)[0x67c43a]
/usr/sbin/mysqld(_Z18intern_close_tableP5TABLE+0x59)[0x59a609]
/usr/sbin/mysqld(_Z8tc_purgeb+0x285)[0x6e88f5]
/usr/sbin/mysqld(_Z19close_cached_tablesP3THDP10TABLE_LISTbm+0x8f)[0x5a317f]
/usr/sbin/mysqld(_Z20reload_acl_and_cacheP3THDyP10TABLE_LISTPi+0x3ce)[0x6c023e]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4889)[0x5e3899]
/usr/sbin/mysqld[0x5e5a97]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6c)[0x5e7e6c]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6a6f13]
/usr/sbin/mysqld(handle_one_connection+0x42)[0x6a6fe2]
/lib64/libpthread.so.0[0x3231207aa1]
/lib64/libc.so.6(clone+0x6d)[0x3230ee8aad]
170227 01:25:09 mysqld_safe Number of processes running now: 0
170227 01:25:09 mysqld_safe mysqld restarted
170227 1:25:09 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB) starting as process 23465 ...
170227 1:25:09 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170227 1:25:09 [Note] InnoDB: The InnoDB memory heap is disabled
170227 1:25:09 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170227 1:25:09 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
170227 1:25:09 [Note] InnoDB: Compressed tables use zlib 1.2.3
170227 1:25:09 [Note] InnoDB: Using Linux native AIO
170227 1:25:10 [Note] InnoDB: Using CPU crc32 instructions
170227 1:25:10 [Note] InnoDB: Initializing buffer pool, size = 7.0G
170227 1:25:10 [Note] InnoDB: Completed initialization of buffer pool
170227 1:25:10 [Note] InnoDB: Highest supported file format is Barracuda.
170227 1:25:10 [Note] InnoDB: Log scan progressed past the checkpoint lsn 6877178025086
170227 1:25:10 [Note] InnoDB: Database was not shutdown normally!
170227 1:25:10 [Note] InnoDB: Starting crash recovery.
170227 1:25:10 [Note] InnoDB: Reading tablespace information from the .ibd files...
170227 1:28:01 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535
170227 1:28:01 [ERROR] InnoDB: innodb-page-size mismatch in tablespace ./optometrydb/page_manager_handlers.ibd (table optometrydb/page_manager_handlers)
170227 1:28:01 [Note] InnoDB: Page size:1024 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 1024, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:2048 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 2048, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:4096 Pages to analyze:32
170227 1:28:01 [Note] InnoDB: Page size: 4096, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:8192 Pages to analyze:16
170227 1:28:01 [Note] InnoDB: Page size: 8192, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:16384 Pages to analyze:8
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:1 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:2 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:3 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:4 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:5 page_size:16384
170227 1:28:01 [Note] InnoDB: Page size: 16384, Possible space_id count:1
170227 1:28:01 [Note] InnoDB: space_id:1859997, Number of pages matched: 5/5 (16384)
170227 1:28:01 [Note] InnoDB: Chosen space:1859997

170227 1:28:01 [Note] InnoDB: Restoring page 0 of tablespace 1859997
170227 1:28:01 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1859997
2017-02-27 01:28:01 7f7346996820 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
InnoDB: Error: could not open single-table tablespace file ./optometrydb/page_manager_handlers.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.
}}

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

{{
2017-02-27 01:25:07 7f50466df700 InnoDB: Assertion failure in thread 139982755723008 in file buf0lru.cc line 2245
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/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb924ab]
/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x739136]
/lib64/libpthread.so.0[0x323120f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x3230e325e5]
/lib64/libc.so.6(abort+0x175)[0x3230e33dc5]
/usr/sbin/mysqld[0x9c86c9]
/usr/sbin/mysqld[0x8db7d5]
/usr/sbin/mysqld[0x9280e8]
/usr/sbin/mysqld[0x8835ff]
/usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x3a)[0x67c43a]
/usr/sbin/mysqld(_Z18intern_close_tableP5TABLE+0x59)[0x59a609]
/usr/sbin/mysqld(_Z8tc_purgeb+0x285)[0x6e88f5]
/usr/sbin/mysqld(_Z19close_cached_tablesP3THDP10TABLE_LISTbm+0x8f)[0x5a317f]
/usr/sbin/mysqld(_Z20reload_acl_and_cacheP3THDyP10TABLE_LISTPi+0x3ce)[0x6c023e]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4889)[0x5e3899]
/usr/sbin/mysqld[0x5e5a97]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6c)[0x5e7e6c]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6a6f13]
/usr/sbin/mysqld(handle_one_connection+0x42)[0x6a6fe2]
/lib64/libpthread.so.0[0x3231207aa1]
/lib64/libc.so.6(clone+0x6d)[0x3230ee8aad]
170227 01:25:09 mysqld_safe Number of processes running now: 0
170227 01:25:09 mysqld_safe mysqld restarted
170227 1:25:09 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB) starting as process 23465 ...
170227 1:25:09 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170227 1:25:09 [Note] InnoDB: The InnoDB memory heap is disabled
170227 1:25:09 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170227 1:25:09 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
170227 1:25:09 [Note] InnoDB: Compressed tables use zlib 1.2.3
170227 1:25:09 [Note] InnoDB: Using Linux native AIO
170227 1:25:10 [Note] InnoDB: Using CPU crc32 instructions
170227 1:25:10 [Note] InnoDB: Initializing buffer pool, size = 7.0G
170227 1:25:10 [Note] InnoDB: Completed initialization of buffer pool
170227 1:25:10 [Note] InnoDB: Highest supported file format is Barracuda.
170227 1:25:10 [Note] InnoDB: Log scan progressed past the checkpoint lsn 6877178025086
170227 1:25:10 [Note] InnoDB: Database was not shutdown normally!
170227 1:25:10 [Note] InnoDB: Starting crash recovery.
170227 1:25:10 [Note] InnoDB: Reading tablespace information from the .ibd files...
170227 1:28:01 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535
170227 1:28:01 [ERROR] InnoDB: innodb-page-size mismatch in tablespace ./optometrydb/page_manager_handlers.ibd (table optometrydb/page_manager_handlers)
170227 1:28:01 [Note] InnoDB: Page size:1024 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 1024, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:2048 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 2048, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:4096 Pages to analyze:32
170227 1:28:01 [Note] InnoDB: Page size: 4096, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:8192 Pages to analyze:16
170227 1:28:01 [Note] InnoDB: Page size: 8192, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:16384 Pages to analyze:8
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:1 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:2 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:3 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:4 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:5 page_size:16384
170227 1:28:01 [Note] InnoDB: Page size: 16384, Possible space_id count:1
170227 1:28:01 [Note] InnoDB: space_id:1859997, Number of pages matched: 5/5 (16384)
170227 1:28:01 [Note] InnoDB: Chosen space:1859997

170227 1:28:01 [Note] InnoDB: Restoring page 0 of tablespace 1859997
170227 1:28:01 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1859997
2017-02-27 01:28:01 7f7346996820 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
InnoDB: Error: could not open single-table tablespace file ./optometrydb/page_manager_handlers.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.
}}

Edward Hicks made changes - 2017-02-27 16:29

Description

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

{{
2017-02-27 01:25:07 7f50466df700 InnoDB: Assertion failure in thread 139982755723008 in file buf0lru.cc line 2245
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/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb924ab]
/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x739136]
/lib64/libpthread.so.0[0x323120f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x3230e325e5]
/lib64/libc.so.6(abort+0x175)[0x3230e33dc5]
/usr/sbin/mysqld[0x9c86c9]
/usr/sbin/mysqld[0x8db7d5]
/usr/sbin/mysqld[0x9280e8]
/usr/sbin/mysqld[0x8835ff]
/usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x3a)[0x67c43a]
/usr/sbin/mysqld(_Z18intern_close_tableP5TABLE+0x59)[0x59a609]
/usr/sbin/mysqld(_Z8tc_purgeb+0x285)[0x6e88f5]
/usr/sbin/mysqld(_Z19close_cached_tablesP3THDP10TABLE_LISTbm+0x8f)[0x5a317f]
/usr/sbin/mysqld(_Z20reload_acl_and_cacheP3THDyP10TABLE_LISTPi+0x3ce)[0x6c023e]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4889)[0x5e3899]
/usr/sbin/mysqld[0x5e5a97]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6c)[0x5e7e6c]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6a6f13]
/usr/sbin/mysqld(handle_one_connection+0x42)[0x6a6fe2]
/lib64/libpthread.so.0[0x3231207aa1]
/lib64/libc.so.6(clone+0x6d)[0x3230ee8aad]
170227 01:25:09 mysqld_safe Number of processes running now: 0
170227 01:25:09 mysqld_safe mysqld restarted
170227 1:25:09 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB) starting as process 23465 ...
170227 1:25:09 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170227 1:25:09 [Note] InnoDB: The InnoDB memory heap is disabled
170227 1:25:09 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170227 1:25:09 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
170227 1:25:09 [Note] InnoDB: Compressed tables use zlib 1.2.3
170227 1:25:09 [Note] InnoDB: Using Linux native AIO
170227 1:25:10 [Note] InnoDB: Using CPU crc32 instructions
170227 1:25:10 [Note] InnoDB: Initializing buffer pool, size = 7.0G
170227 1:25:10 [Note] InnoDB: Completed initialization of buffer pool
170227 1:25:10 [Note] InnoDB: Highest supported file format is Barracuda.
170227 1:25:10 [Note] InnoDB: Log scan progressed past the checkpoint lsn 6877178025086
170227 1:25:10 [Note] InnoDB: Database was not shutdown normally!
170227 1:25:10 [Note] InnoDB: Starting crash recovery.
170227 1:25:10 [Note] InnoDB: Reading tablespace information from the .ibd files...
170227 1:28:01 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535
170227 1:28:01 [ERROR] InnoDB: innodb-page-size mismatch in tablespace ./optometrydb/page_manager_handlers.ibd (table optometrydb/page_manager_handlers)
170227 1:28:01 [Note] InnoDB: Page size:1024 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 1024, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:2048 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 2048, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:4096 Pages to analyze:32
170227 1:28:01 [Note] InnoDB: Page size: 4096, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:8192 Pages to analyze:16
170227 1:28:01 [Note] InnoDB: Page size: 8192, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:16384 Pages to analyze:8
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:1 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:2 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:3 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:4 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:5 page_size:16384
170227 1:28:01 [Note] InnoDB: Page size: 16384, Possible space_id count:1
170227 1:28:01 [Note] InnoDB: space_id:1859997, Number of pages matched: 5/5 (16384)
170227 1:28:01 [Note] InnoDB: Chosen space:1859997

170227 1:28:01 [Note] InnoDB: Restoring page 0 of tablespace 1859997
170227 1:28:01 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1859997
2017-02-27 01:28:01 7f7346996820 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
InnoDB: Error: could not open single-table tablespace file ./optometrydb/page_manager_handlers.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.
}}

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

2017-02-27 01:25:07 7f50466df700 InnoDB: Assertion failure in thread 139982755723008 in file buf0lru.cc line 2245
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/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb924ab]
/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x739136]
/lib64/libpthread.so.0[0x323120f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x3230e325e5]
/lib64/libc.so.6(abort+0x175)[0x3230e33dc5]
/usr/sbin/mysqld[0x9c86c9]
/usr/sbin/mysqld[0x8db7d5]
/usr/sbin/mysqld[0x9280e8]
/usr/sbin/mysqld[0x8835ff]
/usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x3a)[0x67c43a]
/usr/sbin/mysqld(_Z18intern_close_tableP5TABLE+0x59)[0x59a609]
/usr/sbin/mysqld(_Z8tc_purgeb+0x285)[0x6e88f5]
/usr/sbin/mysqld(_Z19close_cached_tablesP3THDP10TABLE_LISTbm+0x8f)[0x5a317f]
/usr/sbin/mysqld(_Z20reload_acl_and_cacheP3THDyP10TABLE_LISTPi+0x3ce)[0x6c023e]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4889)[0x5e3899]
/usr/sbin/mysqld[0x5e5a97]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6c)[0x5e7e6c]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6a6f13]
/usr/sbin/mysqld(handle_one_connection+0x42)[0x6a6fe2]
/lib64/libpthread.so.0[0x3231207aa1]
/lib64/libc.so.6(clone+0x6d)[0x3230ee8aad]
170227 01:25:09 mysqld_safe Number of processes running now: 0
170227 01:25:09 mysqld_safe mysqld restarted
170227 1:25:09 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB) starting as process 23465 ...
170227 1:25:09 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170227 1:25:09 [Note] InnoDB: The InnoDB memory heap is disabled
170227 1:25:09 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170227 1:25:09 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
170227 1:25:09 [Note] InnoDB: Compressed tables use zlib 1.2.3
170227 1:25:09 [Note] InnoDB: Using Linux native AIO
170227 1:25:10 [Note] InnoDB: Using CPU crc32 instructions
170227 1:25:10 [Note] InnoDB: Initializing buffer pool, size = 7.0G
170227 1:25:10 [Note] InnoDB: Completed initialization of buffer pool
170227 1:25:10 [Note] InnoDB: Highest supported file format is Barracuda.
170227 1:25:10 [Note] InnoDB: Log scan progressed past the checkpoint lsn 6877178025086
170227 1:25:10 [Note] InnoDB: Database was not shutdown normally!
170227 1:25:10 [Note] InnoDB: Starting crash recovery.
170227 1:25:10 [Note] InnoDB: Reading tablespace information from the .ibd files...
170227 1:28:01 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535
170227 1:28:01 [ERROR] InnoDB: innodb-page-size mismatch in tablespace ./optometrydb/page_manager_handlers.ibd (table optometrydb/page_manager_handlers)
170227 1:28:01 [Note] InnoDB: Page size:1024 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 1024, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:2048 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 2048, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:4096 Pages to analyze:32
170227 1:28:01 [Note] InnoDB: Page size: 4096, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:8192 Pages to analyze:16
170227 1:28:01 [Note] InnoDB: Page size: 8192, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:16384 Pages to analyze:8
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:1 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:2 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:3 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:4 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:5 page_size:16384
170227 1:28:01 [Note] InnoDB: Page size: 16384, Possible space_id count:1
170227 1:28:01 [Note] InnoDB: space_id:1859997, Number of pages matched: 5/5 (16384)
170227 1:28:01 [Note] InnoDB: Chosen space:1859997

170227 1:28:01 [Note] InnoDB: Restoring page 0 of tablespace 1859997
170227 1:28:01 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1859997
2017-02-27 01:28:01 7f7346996820 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
InnoDB: Error: could not open single-table tablespace file ./optometrydb/page_manager_handlers.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.

Edward Hicks made changes - 2017-02-27 16:31

Description

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

2017-02-27 01:25:07 7f50466df700 InnoDB: Assertion failure in thread 139982755723008 in file buf0lru.cc line 2245
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/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb924ab]
/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x739136]
/lib64/libpthread.so.0[0x323120f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x3230e325e5]
/lib64/libc.so.6(abort+0x175)[0x3230e33dc5]
/usr/sbin/mysqld[0x9c86c9]
/usr/sbin/mysqld[0x8db7d5]
/usr/sbin/mysqld[0x9280e8]
/usr/sbin/mysqld[0x8835ff]
/usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x3a)[0x67c43a]
/usr/sbin/mysqld(_Z18intern_close_tableP5TABLE+0x59)[0x59a609]
/usr/sbin/mysqld(_Z8tc_purgeb+0x285)[0x6e88f5]
/usr/sbin/mysqld(_Z19close_cached_tablesP3THDP10TABLE_LISTbm+0x8f)[0x5a317f]
/usr/sbin/mysqld(_Z20reload_acl_and_cacheP3THDyP10TABLE_LISTPi+0x3ce)[0x6c023e]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4889)[0x5e3899]
/usr/sbin/mysqld[0x5e5a97]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6c)[0x5e7e6c]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6a6f13]
/usr/sbin/mysqld(handle_one_connection+0x42)[0x6a6fe2]
/lib64/libpthread.so.0[0x3231207aa1]
/lib64/libc.so.6(clone+0x6d)[0x3230ee8aad]
170227 01:25:09 mysqld_safe Number of processes running now: 0
170227 01:25:09 mysqld_safe mysqld restarted
170227 1:25:09 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB) starting as process 23465 ...
170227 1:25:09 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170227 1:25:09 [Note] InnoDB: The InnoDB memory heap is disabled
170227 1:25:09 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170227 1:25:09 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
170227 1:25:09 [Note] InnoDB: Compressed tables use zlib 1.2.3
170227 1:25:09 [Note] InnoDB: Using Linux native AIO
170227 1:25:10 [Note] InnoDB: Using CPU crc32 instructions
170227 1:25:10 [Note] InnoDB: Initializing buffer pool, size = 7.0G
170227 1:25:10 [Note] InnoDB: Completed initialization of buffer pool
170227 1:25:10 [Note] InnoDB: Highest supported file format is Barracuda.
170227 1:25:10 [Note] InnoDB: Log scan progressed past the checkpoint lsn 6877178025086
170227 1:25:10 [Note] InnoDB: Database was not shutdown normally!
170227 1:25:10 [Note] InnoDB: Starting crash recovery.
170227 1:25:10 [Note] InnoDB: Reading tablespace information from the .ibd files...
170227 1:28:01 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535
170227 1:28:01 [ERROR] InnoDB: innodb-page-size mismatch in tablespace ./optometrydb/page_manager_handlers.ibd (table optometrydb/page_manager_handlers)
170227 1:28:01 [Note] InnoDB: Page size:1024 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 1024, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:2048 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 2048, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:4096 Pages to analyze:32
170227 1:28:01 [Note] InnoDB: Page size: 4096, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:8192 Pages to analyze:16
170227 1:28:01 [Note] InnoDB: Page size: 8192, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:16384 Pages to analyze:8
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:1 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:2 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:3 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:4 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:5 page_size:16384
170227 1:28:01 [Note] InnoDB: Page size: 16384, Possible space_id count:1
170227 1:28:01 [Note] InnoDB: space_id:1859997, Number of pages matched: 5/5 (16384)
170227 1:28:01 [Note] InnoDB: Chosen space:1859997

170227 1:28:01 [Note] InnoDB: Restoring page 0 of tablespace 1859997
170227 1:28:01 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1859997
2017-02-27 01:28:01 7f7346996820 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
InnoDB: Error: could not open single-table tablespace file ./optometrydb/page_manager_handlers.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

2017-02-27 01:25:07 7f50466df700 InnoDB: Assertion failure in thread 139982755723008 in file buf0lru.cc line 2245
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/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb924ab]
/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x739136]
/lib64/libpthread.so.0[0x323120f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x3230e325e5]
/lib64/libc.so.6(abort+0x175)[0x3230e33dc5]
/usr/sbin/mysqld[0x9c86c9]
/usr/sbin/mysqld[0x8db7d5]
/usr/sbin/mysqld[0x9280e8]
/usr/sbin/mysqld[0x8835ff]
/usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x3a)[0x67c43a]
/usr/sbin/mysqld(_Z18intern_close_tableP5TABLE+0x59)[0x59a609]
/usr/sbin/mysqld(_Z8tc_purgeb+0x285)[0x6e88f5]
/usr/sbin/mysqld(_Z19close_cached_tablesP3THDP10TABLE_LISTbm+0x8f)[0x5a317f]
/usr/sbin/mysqld(_Z20reload_acl_and_cacheP3THDyP10TABLE_LISTPi+0x3ce)[0x6c023e]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4889)[0x5e3899]
/usr/sbin/mysqld[0x5e5a97]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6c)[0x5e7e6c]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6a6f13]
/usr/sbin/mysqld(handle_one_connection+0x42)[0x6a6fe2]
/lib64/libpthread.so.0[0x3231207aa1]
/lib64/libc.so.6(clone+0x6d)[0x3230ee8aad]
170227 01:25:09 mysqld_safe Number of processes running now: 0
170227 01:25:09 mysqld_safe mysqld restarted
170227 1:25:09 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB) starting as process 23465 ...
170227 1:25:09 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170227 1:25:09 [Note] InnoDB: The InnoDB memory heap is disabled
170227 1:25:09 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170227 1:25:09 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
170227 1:25:09 [Note] InnoDB: Compressed tables use zlib 1.2.3
170227 1:25:09 [Note] InnoDB: Using Linux native AIO
170227 1:25:10 [Note] InnoDB: Using CPU crc32 instructions
170227 1:25:10 [Note] InnoDB: Initializing buffer pool, size = 7.0G
170227 1:25:10 [Note] InnoDB: Completed initialization of buffer pool
170227 1:25:10 [Note] InnoDB: Highest supported file format is Barracuda.
170227 1:25:10 [Note] InnoDB: Log scan progressed past the checkpoint lsn 6877178025086
170227 1:25:10 [Note] InnoDB: Database was not shutdown normally!
170227 1:25:10 [Note] InnoDB: Starting crash recovery.
170227 1:25:10 [Note] InnoDB: Reading tablespace information from the .ibd files...
170227 1:28:01 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535
170227 1:28:01 [ERROR] InnoDB: innodb-page-size mismatch in tablespace ./optometrydb/page_manager_handlers.ibd (table optometrydb/page_manager_handlers)
170227 1:28:01 [Note] InnoDB: Page size:1024 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 1024, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:2048 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 2048, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:4096 Pages to analyze:32
170227 1:28:01 [Note] InnoDB: Page size: 4096, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:8192 Pages to analyze:16
170227 1:28:01 [Note] InnoDB: Page size: 8192, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:16384 Pages to analyze:8
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:1 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:2 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:3 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:4 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:5 page_size:16384
170227 1:28:01 [Note] InnoDB: Page size: 16384, Possible space_id count:1
170227 1:28:01 [Note] InnoDB: space_id:1859997, Number of pages matched: 5/5 (16384)
170227 1:28:01 [Note] InnoDB: Chosen space:1859997

170227 1:28:01 [Note] InnoDB: Restoring page 0 of tablespace 1859997
170227 1:28:01 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1859997
2017-02-27 01:28:01 7f7346996820 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
InnoDB: Error: could not open single-table tablespace file ./optometrydb/page_manager_handlers.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.
170227 01:28:01 mysqld_safe mysqld from pid file /var/lib/mysqldata/mysql/DATABASES/whsqlprd05.pid ended

Edward Hicks made changes - 2017-02-27 16:33

Description

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

2017-02-27 01:25:07 7f50466df700 InnoDB: Assertion failure in thread 139982755723008 in file buf0lru.cc line 2245
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/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb924ab]
/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x739136]
/lib64/libpthread.so.0[0x323120f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x3230e325e5]
/lib64/libc.so.6(abort+0x175)[0x3230e33dc5]
/usr/sbin/mysqld[0x9c86c9]
/usr/sbin/mysqld[0x8db7d5]
/usr/sbin/mysqld[0x9280e8]
/usr/sbin/mysqld[0x8835ff]
/usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x3a)[0x67c43a]
/usr/sbin/mysqld(_Z18intern_close_tableP5TABLE+0x59)[0x59a609]
/usr/sbin/mysqld(_Z8tc_purgeb+0x285)[0x6e88f5]
/usr/sbin/mysqld(_Z19close_cached_tablesP3THDP10TABLE_LISTbm+0x8f)[0x5a317f]
/usr/sbin/mysqld(_Z20reload_acl_and_cacheP3THDyP10TABLE_LISTPi+0x3ce)[0x6c023e]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4889)[0x5e3899]
/usr/sbin/mysqld[0x5e5a97]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6c)[0x5e7e6c]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6a6f13]
/usr/sbin/mysqld(handle_one_connection+0x42)[0x6a6fe2]
/lib64/libpthread.so.0[0x3231207aa1]
/lib64/libc.so.6(clone+0x6d)[0x3230ee8aad]
170227 01:25:09 mysqld_safe Number of processes running now: 0
170227 01:25:09 mysqld_safe mysqld restarted
170227 1:25:09 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB) starting as process 23465 ...
170227 1:25:09 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170227 1:25:09 [Note] InnoDB: The InnoDB memory heap is disabled
170227 1:25:09 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170227 1:25:09 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
170227 1:25:09 [Note] InnoDB: Compressed tables use zlib 1.2.3
170227 1:25:09 [Note] InnoDB: Using Linux native AIO
170227 1:25:10 [Note] InnoDB: Using CPU crc32 instructions
170227 1:25:10 [Note] InnoDB: Initializing buffer pool, size = 7.0G
170227 1:25:10 [Note] InnoDB: Completed initialization of buffer pool
170227 1:25:10 [Note] InnoDB: Highest supported file format is Barracuda.
170227 1:25:10 [Note] InnoDB: Log scan progressed past the checkpoint lsn 6877178025086
170227 1:25:10 [Note] InnoDB: Database was not shutdown normally!
170227 1:25:10 [Note] InnoDB: Starting crash recovery.
170227 1:25:10 [Note] InnoDB: Reading tablespace information from the .ibd files...
170227 1:28:01 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535
170227 1:28:01 [ERROR] InnoDB: innodb-page-size mismatch in tablespace ./optometrydb/page_manager_handlers.ibd (table optometrydb/page_manager_handlers)
170227 1:28:01 [Note] InnoDB: Page size:1024 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 1024, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:2048 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 2048, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:4096 Pages to analyze:32
170227 1:28:01 [Note] InnoDB: Page size: 4096, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:8192 Pages to analyze:16
170227 1:28:01 [Note] InnoDB: Page size: 8192, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:16384 Pages to analyze:8
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:1 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:2 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:3 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:4 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:5 page_size:16384
170227 1:28:01 [Note] InnoDB: Page size: 16384, Possible space_id count:1
170227 1:28:01 [Note] InnoDB: space_id:1859997, Number of pages matched: 5/5 (16384)
170227 1:28:01 [Note] InnoDB: Chosen space:1859997

170227 1:28:01 [Note] InnoDB: Restoring page 0 of tablespace 1859997
170227 1:28:01 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1859997
2017-02-27 01:28:01 7f7346996820 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
InnoDB: Error: could not open single-table tablespace file ./optometrydb/page_manager_handlers.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.
170227 01:28:01 mysqld_safe mysqld from pid file /var/lib/mysqldata/mysql/DATABASES/whsqlprd05.pid ended

3 times now in the last 6 months or so we've had a random signal 6 crash corrupt a single ibd file by actually overwriting the top it with the error message. (which I assume was meant for the log file instead)

I've attached the corrupted file as an example. I've confirmed this occurs in 10.0.28 and 10.0.29. Here's the error data from the correct log file:

{noformat}
2017-02-27 01:25:07 7f50466df700 InnoDB: Assertion failure in thread 139982755723008 in file buf0lru.cc line 2245
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/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb924ab]
/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x739136]
/lib64/libpthread.so.0[0x323120f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x3230e325e5]
/lib64/libc.so.6(abort+0x175)[0x3230e33dc5]
/usr/sbin/mysqld[0x9c86c9]
/usr/sbin/mysqld[0x8db7d5]
/usr/sbin/mysqld[0x9280e8]
/usr/sbin/mysqld[0x8835ff]
/usr/sbin/mysqld(_Z8closefrmP5TABLEb+0x3a)[0x67c43a]
/usr/sbin/mysqld(_Z18intern_close_tableP5TABLE+0x59)[0x59a609]
/usr/sbin/mysqld(_Z8tc_purgeb+0x285)[0x6e88f5]
/usr/sbin/mysqld(_Z19close_cached_tablesP3THDP10TABLE_LISTbm+0x8f)[0x5a317f]
/usr/sbin/mysqld(_Z20reload_acl_and_cacheP3THDyP10TABLE_LISTPi+0x3ce)[0x6c023e]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4889)[0x5e3899]
/usr/sbin/mysqld[0x5e5a97]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6c)[0x5e7e6c]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6a6f13]
/usr/sbin/mysqld(handle_one_connection+0x42)[0x6a6fe2]
/lib64/libpthread.so.0[0x3231207aa1]
/lib64/libc.so.6(clone+0x6d)[0x3230ee8aad]
170227 01:25:09 mysqld_safe Number of processes running now: 0
170227 01:25:09 mysqld_safe mysqld restarted
170227 1:25:09 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB) starting as process 23465 ...
170227 1:25:09 [Note] InnoDB: Using mutexes to ref count buffer pool pages
170227 1:25:09 [Note] InnoDB: The InnoDB memory heap is disabled
170227 1:25:09 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
170227 1:25:09 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
170227 1:25:09 [Note] InnoDB: Compressed tables use zlib 1.2.3
170227 1:25:09 [Note] InnoDB: Using Linux native AIO
170227 1:25:10 [Note] InnoDB: Using CPU crc32 instructions
170227 1:25:10 [Note] InnoDB: Initializing buffer pool, size = 7.0G
170227 1:25:10 [Note] InnoDB: Completed initialization of buffer pool
170227 1:25:10 [Note] InnoDB: Highest supported file format is Barracuda.
170227 1:25:10 [Note] InnoDB: Log scan progressed past the checkpoint lsn 6877178025086
170227 1:25:10 [Note] InnoDB: Database was not shutdown normally!
170227 1:25:10 [Note] InnoDB: Starting crash recovery.
170227 1:25:10 [Note] InnoDB: Reading tablespace information from the .ibd files...
170227 1:28:01 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535
170227 1:28:01 [ERROR] InnoDB: innodb-page-size mismatch in tablespace ./optometrydb/page_manager_handlers.ibd (table optometrydb/page_manager_handlers)
170227 1:28:01 [Note] InnoDB: Page size:1024 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 1024, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:2048 Pages to analyze:64
170227 1:28:01 [Note] InnoDB: Page size: 2048, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:4096 Pages to analyze:32
170227 1:28:01 [Note] InnoDB: Page size: 4096, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:8192 Pages to analyze:16
170227 1:28:01 [Note] InnoDB: Page size: 8192, Possible space_id count:0
170227 1:28:01 [Note] InnoDB: Page size:16384 Pages to analyze:8
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:1 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:2 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:3 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:4 page_size:16384
170227 1:28:01 [Note] InnoDB: VALID: space:1859997 page_no:5 page_size:16384
170227 1:28:01 [Note] InnoDB: Page size: 16384, Possible space_id count:1
170227 1:28:01 [Note] InnoDB: space_id:1859997, Number of pages matched: 5/5 (16384)
170227 1:28:01 [Note] InnoDB: Chosen space:1859997

170227 1:28:01 [Note] InnoDB: Restoring page 0 of tablespace 1859997
170227 1:28:01 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1859997
2017-02-27 01:28:01 7f7346996820 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
InnoDB: Error: could not open single-table tablespace file ./optometrydb/page_manager_handlers.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.
170227 01:28:01 mysqld_safe mysqld from pid file /var/lib/mysqldata/mysql/DATABASES/whsqlprd05.pid ended
{noformat}

Marko Mäkelä added a comment - 2017-02-28 07:15

It looks like the file optometrydb/page_manager_handlers.ibd must have been overwritten with some ASCII text:
544434535 == 0x20736967 == " sig"
1851878432 == 0x6e616c20 == "nal "
Can you please share what was written to the start of the file? Anything like "mysqld got signal", by any chance?

In the past (while I worked as a MySQL developer) I have suspected that maybe if the mysqld process is started without file descriptor 2 (stderr) being assigned, it is possible that a data file gets opened as file descriptor 2. Then, when some code attempts to report something to stderr, it would overwrite the data file that happens to be associated with file descriptor 2.

This hypothesis should be fairly easy to test by an invocation similar to the following:

mysqld 2>&-

Marko Mäkelä added a comment - 2017-02-28 07:15 It looks like the file optometrydb/page_manager_handlers.ibd must have been overwritten with some ASCII text: 544434535 == 0x20736967 == " sig" 1851878432 == 0x6e616c20 == "nal " Can you please share what was written to the start of the file? Anything like "mysqld got signal", by any chance? In the past (while I worked as a MySQL developer) I have suspected that maybe if the mysqld process is started without file descriptor 2 (stderr) being assigned, it is possible that a data file gets opened as file descriptor 2. Then, when some code attempts to report something to stderr, it would overwrite the data file that happens to be associated with file descriptor 2. This hypothesis should be fairly easy to test by an invocation similar to the following: mysqld 2>&-

Daniel Black added a comment - 2017-02-28 10:07 - edited

flush [error] log, will reopen the file descriptor but not necessary the same one will come back. Maybe. Another thread could open a file which becomes FD 2.

LOCK_error_log isn't held in reopen_fstreams for stderr.

Daniel Black added a comment - 2017-02-28 10:07 - edited flush [error] log, will reopen the file descriptor but not necessary the same one will come back. Maybe. Another thread could open a file which becomes FD 2. LOCK_error_log isn't held in reopen_fstreams for stderr.

Edward Hicks added a comment - 2017-02-28 15:13

I'm not sure what you mean by "the start of the file" - what is attached is the entire file as copied from the data directory before I started on recovery. Just run it through less and you see this at the top:

170227  1:25:07 [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.0.29-MariaDB

key_buffer_size=134217728

read_buffer_size=131072

max_used_connections=211

max_threads=5002

thread_count=12

It is possible that mysqld could use up to

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 11114545 K  bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f50b8c25008

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 = 0x7f50466ded30 thread_stack 0x48000

Trying to get some variables.

Some pointers may be invalid and cause the dump to abort.

Query (0x7f507e2be020): is an invalid pointer

Connection ID (thread ID): 12720053

Status: NOT_KILLED

Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on

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.

We think the query pointer is invalid, but we will try to print it anyway.

Query: FLUSH /*!40101 LOCAL */ TABLES

And then the rest is binary through the EOF.

Edward Hicks added a comment - 2017-02-28 15:13 I'm not sure what you mean by "the start of the file" - what is attached is the entire file as copied from the data directory before I started on recovery. Just run it through less and you see this at the top: 170227 1:25:07 [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.0.29-MariaDB key_buffer_size=134217728 read_buffer_size=131072 max_used_connections=211 max_threads=5002 thread_count=12 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 11114545 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x7f50b8c25008 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 = 0x7f50466ded30 thread_stack 0x48000 Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (0x7f507e2be020): is an invalid pointer Connection ID (thread ID): 12720053 Status: NOT_KILLED Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on 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. We think the query pointer is invalid, but we will try to print it anyway. Query: FLUSH /*!40101 LOCAL */ TABLES And then the rest is binary through the EOF.

Marko Mäkelä added a comment - 2017-03-18 20:05

eshicks4, sorry that I overlooked the file attachment. Can you share more details? Do you have a server error log from immediately before the crash?
What was the last message timestamp in the server error log? Do you have an idea if any other maintenance commands were issued close to the statement FLUSH LOCAL TABLES that was mentioned at the end of the MySQL crash output (FLUSH LOCAL TABLES)?

How many InnoDB files do you have, and have you configured innodb_open_files or table_cache (or table_open_cache)? These parameters affect the fil_system->max_n_open and the fil_system->LRU (closing of rarely accessed data files) in InnoDB.

danblack has a promising-looking hypothesis. Maybe fil_node_open_file() in InnoDB opened a data file at a very unfortunate moment as file descriptor 2 (STDERR_FILENO) which happened to be available at that point of time.

Side note: All of the output that corrupted the .ibd file was written by the server core, not InnoDB.

Marko Mäkelä added a comment - 2017-03-18 20:05 eshicks4 , sorry that I overlooked the file attachment. Can you share more details? Do you have a server error log from immediately before the crash? What was the last message timestamp in the server error log? Do you have an idea if any other maintenance commands were issued close to the statement FLUSH LOCAL TABLES that was mentioned at the end of the MySQL crash output (FLUSH LOCAL TABLES)? How many InnoDB files do you have, and have you configured innodb_open_files or table_cache (or table_open_cache)? These parameters affect the fil_system->max_n_open and the fil_system->LRU (closing of rarely accessed data files) in InnoDB. danblack has a promising-looking hypothesis. Maybe fil_node_open_file() in InnoDB opened a data file at a very unfortunate moment as file descriptor 2 (STDERR_FILENO) which happened to be available at that point of time. Side note: All of the output that corrupted the .ibd file was written by the server core, not InnoDB.

Daniel Black made changes - 2017-03-19 04:51

Attachment

fdmain.c [ 43458 ]

Daniel Black added a comment - 2017-03-19 04:54 - edited

fdmain.c - an approach using dup2 to ensure that stdout(or another fd) isn't closed - generating a race condition but still redirecting it to another object.

open("/tmp/xx.txt", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3

dup2(3, 1)                              = 1

close(3)                                = 0

fcntl(1, F_GETFL)                       = 0x8001 (flags O_WRONLY|O_LARGEFILE)

fstat(1, {st_mode=S_IFREG|0664, st_size=0, ...}) = 0

write(1, "hi\n", 3)                     = 3

exit_group(0)                           = ?

$ more /tmp/xx.txt

hi

Note 1: during testing I fclose(stdout) after dup2 and the fprintf(stdout..) generated a segfault which seems closer like this bug report.

looking at freopen is seems the syscalls are quite similar anyway.

open("/tmp/xx.txt", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3

dup3(3, 1, 0)                           = 1

close(3)                                = 0

fstat(1, {st_mode=S_IFREG|0664, st_size=0, ...}) = 0

Daniel Black added a comment - 2017-03-19 04:54 - edited fdmain.c - an approach using dup2 to ensure that stdout(or another fd) isn't closed - generating a race condition but still redirecting it to another object. open("/tmp/xx.txt", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3 dup2(3, 1) = 1 close(3) = 0 fcntl(1, F_GETFL) = 0x8001 (flags O_WRONLY|O_LARGEFILE) fstat(1, {st_mode=S_IFREG|0664, st_size=0, ...}) = 0 write(1, "hi\n", 3) = 3 exit_group(0) = ? $ more /tmp/xx.txt hi Note 1: during testing I fclose(stdout) after dup2 and the fprintf(stdout..) generated a segfault which seems closer like this bug report. looking at freopen is seems the syscalls are quite similar anyway. open("/tmp/xx.txt", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3 dup3(3, 1, 0) = 1 close(3) = 0 fstat(1, {st_mode=S_IFREG|0664, st_size=0, ...}) = 0

Marko Mäkelä added a comment - 2017-03-20 08:32

There indeed are a few calls to freopen(), mostly during the server initialization. I tested starting mysqld with all of stdin, stdout, stderr closed, and my_freopen() is being called by reopen_fstreams() and init_server_components() before the InnoDB storage engine is initialized:

break my_freopen

break innobase_start_or_create_for_mysql

run <&- >&- 2>&-

continue

continue

break open

continue

At this startup, we have fileno(srv_monitor_file)==1 (STDOUT_FILENO) and fileno(srv_dict_tmpfile)==2 (STDERR_FILENO).

A possible solution for this startup problem could be to allocate a dummy file to the STDERR_FILENO before starting up storage engines, or refuse startup outright if STDERR_FILENO is not open.

I will for now assume that the standard error stream was properly open during the startup.

Like danblack pointed out, flush_error_log() is calling redirect_std_streams(), which calls freopen() via my_freopen(). Assuming that the main() function of storage/mroonga/vendor/groonga/src/groonga.c is not compiled in, flush_error_log() seems to be the only caller of freopen() while the server is running.

The only caller of flush_error_log() is reload_acl_and_cache(), when REFRESH_LOG or REFRESH_ERROR_LOG are set. The callers that use one of those flags are:

The SIGHUP handler (after calling mysql_print_status())
FLUSH LOGS
FLUSH ERROR LOGS

The calls to fdopen() seem to be OK.

The function mysqld_main() is calling close(stdin), which seems OK. On a normal startup (without all of stdin, stdout, stderr being open), there is no call to close() with the argument STDOUT_FILENO or STDERR_FILENO.

Marko Mäkelä added a comment - 2017-03-20 08:32 There indeed are a few calls to freopen(), mostly during the server initialization. I tested starting mysqld with all of stdin, stdout, stderr closed, and my_freopen() is being called by reopen_fstreams() and init_server_components() before the InnoDB storage engine is initialized: break my_freopen break innobase_start_or_create_for_mysql run <&- >&- 2>&- continue continue break open continue At this startup, we have fileno(srv_monitor_file)==1 (STDOUT_FILENO) and fileno(srv_dict_tmpfile)==2 (STDERR_FILENO). A possible solution for this startup problem could be to allocate a dummy file to the STDERR_FILENO before starting up storage engines, or refuse startup outright if STDERR_FILENO is not open. I will for now assume that the standard error stream was properly open during the startup. Like danblack pointed out, flush_error_log() is calling redirect_std_streams(), which calls freopen() via my_freopen(). Assuming that the main() function of storage/mroonga/vendor/groonga/src/groonga.c is not compiled in, flush_error_log() seems to be the only caller of freopen() while the server is running. The only caller of flush_error_log() is reload_acl_and_cache(), when REFRESH_LOG or REFRESH_ERROR_LOG are set. The callers that use one of those flags are: The SIGHUP handler (after calling mysql_print_status()) FLUSH LOGS FLUSH ERROR LOGS The calls to fdopen() seem to be OK. The function mysqld_main() is calling close(stdin), which seems OK. On a normal startup (without all of stdin, stdout, stderr being open), there is no call to close() with the argument STDOUT_FILENO or STDERR_FILENO.

Edward Hicks added a comment - 2017-03-21 18:36 - edited

There is nothing in the error logs for days leading up to the crash. I am now noticing that 1:25AM is when we kick off the nightly backup of the primary database. (around 570 databases) Having crashed only 7 seconds after the script was kicked off it looks like a pretty good candidate for the triggering event.

The first thing the backup script does is build a config file (not sure why - not my script) and then executes 'show databases' to get a list:

mysql --defaults-file=$TMPFILE.cnf --disable-pager --batch --disable-tee \

  --execute='show databases' --host=$DATASERVER --user=$OPERUSER --database=mysql

The generated config file only includes is a [client] section with password, port, and optional socket.

It then creates a directory for each database (excluding binlog, relay, innodb, and information_schema) and places into it 2 SQL files:

echo "SET FOREIGN_KEY_CHECKS=0;" >$BACKUPDIR/$DATABASE/$DATABASE.ddl.$DATE.sql

mysqldump --defaults-file=$TMPFILE.cnf --host=$DATASERVER --user=$OPERUSER \

	--skip-lock-tables --single-transaction --hex-blob --master-data=2 --allow-keywords \

	--add-drop-table --quick --add-locks --create-options --complete-insert --extended-insert \

	--force --databases --no-data $DATABASE \

	2>$TMPFILE >>$BACKUPDIR/$DATABASE/$DATABASE.ddl.$DATE.sql

echo "SET FOREIGN_KEY_CHECKS=0;" >$BACKUPDIR/$DATABASE/$DATABASE.full.$DATE.sql

mysqldump --defaults-file=$TMPFILE.cnf --host=$DATASERVER --user=$OPERUSER \

	--skip-lock-tables --single-transaction --hex-blob --master-data=2 --allow-keywords \

	--add-drop-table --quick --add-locks --create-options --complete-insert --extended-insert \

	--force --database --no-create-info --master-data=2 --flush-logs $DATABASE \

	2>$TMPFILE >>$BACKUPDIR/$DATABASE/$DATABASE.full.$DATE.sql

Afterward it tars everything up.

I don't have innodb_open_files but I do have a fair amount of customizations to make it production-level responsive and as VM-friendly as is possible for a DBMS:

max_connections=5000

max_connect_errors=4294967295

table_cache=1000

max_heap_table_size=268435456

tmp_table_size=268435456

open_files_limit=9076

symbolic-links=0

query_cache_type=1

query_cache_size=32M

max_allowed_packet=32M

slow-query-log=ON

default_storage_engine=InnoDB

transaction-isolation=READ-COMMITTED

thread_cache_size=4

query_cache_limit=10485760

table_open_cache=16384

table_definition_cache=16384

join_buffer_size=512K

wait_timeout=900

interactive_timeout=900

net_read_timeout=300

net_write_timeout=600

innodb_buffer_pool_size=7G

innodb_log_file_size=1G

innodb_flush_neighbors=0

innodb_autoinc_lock_mode=2

innodb_data_file_path=ibdata1:256M;ibdata2:256M;ibdata3:256M:autoextend

innodb_large_prefix=1

innodb_file_per_table=1

innodb_file_format=Barracuda

innodb_file_format_max=Barracuda

innodb_random_read_ahead=1

innodb_stats_auto_recalc=1

If you need anything else then let me know. Thanks

Edward Hicks added a comment - 2017-03-21 18:36 - edited There is nothing in the error logs for days leading up to the crash. I am now noticing that 1:25AM is when we kick off the nightly backup of the primary database. (around 570 databases) Having crashed only 7 seconds after the script was kicked off it looks like a pretty good candidate for the triggering event. The first thing the backup script does is build a config file (not sure why - not my script) and then executes 'show databases' to get a list: mysql --defaults-file=$TMPFILE.cnf --disable-pager --batch --disable-tee \ --execute='show databases' --host=$DATASERVER --user=$OPERUSER --database=mysql The generated config file only includes is a [client] section with password, port, and optional socket. It then creates a directory for each database (excluding binlog, relay, innodb, and information_schema) and places into it 2 SQL files: echo "SET FOREIGN_KEY_CHECKS=0;" >$BACKUPDIR/$DATABASE/$DATABASE.ddl.$DATE.sql mysqldump --defaults-file=$TMPFILE.cnf --host=$DATASERVER --user=$OPERUSER \ --skip-lock-tables --single-transaction --hex-blob --master-data=2 --allow-keywords \ --add-drop-table --quick --add-locks --create-options --complete-insert --extended-insert \ --force --databases --no-data $DATABASE \ 2>$TMPFILE >>$BACKUPDIR/$DATABASE/$DATABASE.ddl.$DATE.sql echo "SET FOREIGN_KEY_CHECKS=0;" >$BACKUPDIR/$DATABASE/$DATABASE.full.$DATE.sql mysqldump --defaults-file=$TMPFILE.cnf --host=$DATASERVER --user=$OPERUSER \ --skip-lock-tables --single-transaction --hex-blob --master-data=2 --allow-keywords \ --add-drop-table --quick --add-locks --create-options --complete-insert --extended-insert \ --force --database --no-create-info --master-data=2 --flush-logs $DATABASE \ 2>$TMPFILE >>$BACKUPDIR/$DATABASE/$DATABASE.full.$DATE.sql Afterward it tars everything up. I don't have innodb_open_files but I do have a fair amount of customizations to make it production-level responsive and as VM-friendly as is possible for a DBMS: max_connections=5000 max_connect_errors=4294967295 table_cache=1000 max_heap_table_size=268435456 tmp_table_size=268435456 open_files_limit=9076 symbolic-links=0 query_cache_type=1 query_cache_size=32M max_allowed_packet=32M slow-query-log=ON default_storage_engine=InnoDB transaction-isolation=READ-COMMITTED thread_cache_size=4 query_cache_limit=10485760 table_open_cache=16384 table_definition_cache=16384 join_buffer_size=512K wait_timeout=900 interactive_timeout=900 net_read_timeout=300 net_write_timeout=600 innodb_buffer_pool_size=7G innodb_log_file_size=1G innodb_flush_neighbors=0 innodb_autoinc_lock_mode=2 innodb_data_file_path=ibdata1:256M;ibdata2:256M;ibdata3:256M:autoextend innodb_large_prefix=1 innodb_file_per_table=1 innodb_file_format=Barracuda innodb_file_format_max=Barracuda innodb_random_read_ahead=1 innodb_stats_auto_recalc=1 If you need anything else then let me know. Thanks

Sergey Vojtovich made changes - 2017-03-23 11:55

Labels

corruption crash innodb

contribution corruption crash foundation innodb

Sergey Vojtovich made changes - 2017-03-23 11:55

Fix Version/s

5.5 [ 15800 ]

Jean Weisbuch added a comment - 2017-03-28 02:31 - edited

The same just happened to me on 10.0.29 using Debian Wheezy packages from MariaDB.

Here is what i have on my error log :

/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb9f46b]

/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x7461f6]

/lib/x86_64-linux-gnu/libpthread.so.0(+0xf0a0)[0x7fb8deced0a0]

/usr/sbin/mysqld(_ZN4JOIN14optimize_innerEv+0x1640)[0x63b310]

/usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x9e)[0x63cade]

/usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x28d)[0x64038d]

/usr/sbin/mysqld[0x5e5886]

/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x503d)[0x5f0e9d]

/usr/sbin/mysqld[0x5f28f7]

/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6e)[0x5f4cce]

/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6b3fa3]

/usr/sbin/mysqld(handle_one_connection+0x42)[0x6b4072]

/lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7fb8dece4b50]

/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fb8dd3eefbd]

170328 03:55:04 mysqld_safe Number of processes running now: 0

170328 03:55:04 mysqld_safe mysqld restarted

170328  3:55:04 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB-1~wheezy) starting as process 8742 ...

/usr/sbin/mysqld: Query cache is disabled (resize or similar command in progress); repeat this command later

170328  3:55:05 [Note] InnoDB: Using mutexes to ref count buffer pool pages

170328  3:55:05 [Note] InnoDB: The InnoDB memory heap is disabled

170328  3:55:05 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins

170328  3:55:05 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier

170328  3:55:05 [Note] InnoDB: Compressed tables use zlib 1.2.7

170328  3:55:05 [Note] InnoDB: Using Linux native AIO

170328  3:55:05 [Note] InnoDB: Using CPU crc32 instructions

170328  3:55:05 [Note] InnoDB: Initializing buffer pool, size = 8.0G

170328  3:55:05 [Note] InnoDB: Completed initialization of buffer pool

170328  3:55:05 [Note] InnoDB: Highest supported file format is Barracuda.

170328  3:55:05 [Note] InnoDB: Log scan progressed past the checkpoint lsn 39835474231511

170328  3:55:05 [Note] InnoDB: Database was not shutdown normally!

170328  3:55:05 [Note] InnoDB: Starting crash recovery.

170328  3:55:05 [Note] InnoDB: Reading tablespace information from the .ibd files...

170328  3:55:06 [ERROR] InnoDB: space header page consists of zero bytes in tablespace ./otherdb/#sql-ib7991104-2285190905.ibd (table otherdb/#sql-ib7991104-2285190905)

170328  3:55:06 [Note] InnoDB: Page size:1024 Pages to analyze:64

170328  3:55:06 [Note] InnoDB: Page size: 1024, Possible space_id count:0

170328  3:55:06 [Note] InnoDB: Page size:2048 Pages to analyze:32

170328  3:55:06 [Note] InnoDB: Page size: 2048, Possible space_id count:0

170328  3:55:06 [Note] InnoDB: Page size:4096 Pages to analyze:16

170328  3:55:06 [Note] InnoDB: Page size: 4096, Possible space_id count:0

170328  3:55:06 [Note] InnoDB: Page size:8192 Pages to analyze:8

170328  3:55:06 [Note] InnoDB: Page size: 8192, Possible space_id count:0

170328  3:55:06 [Note] InnoDB: Page size:16384 Pages to analyze:4

170328  3:55:06 [Note] InnoDB: Page size: 16384, Possible space_id count:0

2017-03-28 03:55:06 7f1fb88bc760  InnoDB: Operating system error number 2 in a file operation.

InnoDB: The error means the system cannot find the path specified.

InnoDB: If you are installing InnoDB, remember that you must create

InnoDB: directories yourself, InnoDB does not create them.

InnoDB: Error: could not open single-table tablespace file ./otherdb/#sql-ib7991104-2285190905.ibd

170328  3:55:07 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535

170328  3:55:07 [ERROR] InnoDB: checksum mismatch in tablespace ./database/wp_term_relationships.ibd (table database/wp_term_relationships)

170328  3:55:07 [Note] InnoDB: Page size:1024 Pages to analyze:64

170328  3:55:07 [Note] InnoDB: Page size: 1024, Possible space_id count:0

170328  3:55:07 [Note] InnoDB: Page size:2048 Pages to analyze:56

170328  3:55:07 [Note] InnoDB: Page size: 2048, Possible space_id count:0

170328  3:55:07 [Note] InnoDB: Page size:4096 Pages to analyze:28

170328  3:55:07 [Note] InnoDB: Page size: 4096, Possible space_id count:0

170328  3:55:07 [Note] InnoDB: Page size:8192 Pages to analyze:14

170328  3:55:07 [Note] InnoDB: Page size: 8192, Possible space_id count:0

170328  3:55:07 [Note] InnoDB: Page size:16384 Pages to analyze:7

170328  3:55:07 [Note] InnoDB: VALID: space:8763257 page_no:1 page_size:16384

170328  3:55:07 [Note] InnoDB: VALID: space:8763257 page_no:2 page_size:16384

170328  3:55:07 [Note] InnoDB: VALID: space:8763257 page_no:3 page_size:16384

170328  3:55:07 [Note] InnoDB: VALID: space:8763257 page_no:4 page_size:16384

170328  3:55:07 [Note] InnoDB: Page size: 16384, Possible space_id count:1

170328  3:55:07 [Note] InnoDB: space_id:8763257, Number of pages matched: 4/4 (16384)

170328  3:55:07 [Note] InnoDB: Chosen space:8763257

170328  3:55:07 [Note] InnoDB: Restoring page 0 of tablespace 8763257

170328  3:55:07 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 8763257

2017-03-28 03:55:07 7f1fb88bc760  InnoDB: Operating system error number 2 in a file operation.

InnoDB: The error means the system cannot find the path specified.

InnoDB: If you are installing InnoDB, remember that you must create

InnoDB: directories yourself, InnoDB does not create them.

InnoDB: Error: could not open single-table tablespace file ./database/wp_term_relationships.ibd

InnoDB: We do not continue the crash recovery, because the table may become

InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.

InnoDB: To fix the problem and start mysqld:

InnoDB: 1) If there is a permission problem in the file and mysqld cannot

InnoDB: open the file, you should modify the permissions.

InnoDB: 2) If the table is not needed, or you can restore it from a backup,

InnoDB: then you can remove the .ibd file, and InnoDB will do a normal

InnoDB: crash recovery and ignore that table.

InnoDB: 3) If the file system or the disk is broken, and you cannot remove

InnoDB: and force InnoDB to continue crash recovery here.

170328 03:55:07 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

170328 03:58:47 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql

170328  3:58:47 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB-1~wheezy) starting as process 9173 ...

/usr/sbin/mysqld: Query cache is disabled (resize or similar command in progress); repeat this command later

/usr/sbin/mysqld: Query cache is disabled (resize or similar command in progress); repeat this command later

170328  3:58:48 [Note] InnoDB: Using mutexes to ref count buffer pool pages

170328  3:58:48 [Note] InnoDB: The InnoDB memory heap is disabled

170328  3:58:48 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins

170328  3:58:48 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier

170328  3:58:48 [Note] InnoDB: Compressed tables use zlib 1.2.7

170328  3:58:48 [Note] InnoDB: Using Linux native AIO

170328  3:58:48 [Note] InnoDB: Using CPU crc32 instructions

170328  3:58:48 [Note] InnoDB: Initializing buffer pool, size = 8.0G

170328  3:58:48 [Note] InnoDB: Completed initialization of buffer pool

170328  3:58:48 [Note] InnoDB: Highest supported file format is Barracuda.

170328  3:58:48 [Note] InnoDB: Log scan progressed past the checkpoint lsn 39835474231511

170328  3:58:48 [Note] InnoDB: Database was not shutdown normally!

170328  3:58:48 [Note] InnoDB: Starting crash recovery.

170328  3:58:48 [Note] InnoDB: Reading tablespace information from the .ibd files...

170328  3:58:49 [ERROR] InnoDB: space header page consists of zero bytes in tablespace ./otherdb/#sql-ib7991104-2285190905.ibd (table otherdb/#sql-ib7991104-2285190905)

170328  3:58:49 [Note] InnoDB: Page size:1024 Pages to analyze:64

170328  3:58:49 [Note] InnoDB: Page size: 1024, Possible space_id count:0

170328  3:58:49 [Note] InnoDB: Page size:2048 Pages to analyze:32

170328  3:58:49 [Note] InnoDB: Page size: 2048, Possible space_id count:0

170328  3:58:49 [Note] InnoDB: Page size:4096 Pages to analyze:16

170328  3:58:49 [Note] InnoDB: Page size: 4096, Possible space_id count:0

170328  3:58:49 [Note] InnoDB: Page size:8192 Pages to analyze:8

170328  3:58:49 [Note] InnoDB: Page size: 8192, Possible space_id count:0

170328  3:58:49 [Note] InnoDB: Page size:16384 Pages to analyze:4

170328  3:58:49 [Note] InnoDB: Page size: 16384, Possible space_id count:0

2017-03-28 03:58:49 7f4edc6dd760  InnoDB: Operating system error number 2 in a file operation.

InnoDB: The error means the system cannot find the path specified.

InnoDB: If you are installing InnoDB, remember that you must create

InnoDB: directories yourself, InnoDB does not create them.

InnoDB: Error: could not open single-table tablespace file ./otherdb/#sql-ib7991104-2285190905.ibd

170328  3:58:49 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535

170328  3:58:49 [ERROR] InnoDB: checksum mismatch in tablespace ./database/wp_term_relationships.ibd (table database/wp_term_relationships)

[...]

And at the beginning of the idb file :

170328  3:55:01 [ERROR] 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.

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.0.29-MariaDB-1~wheezy

key_buffer_size=4294967292

read_buffer_size=131072

max_used_connections=64

max_threads=311

thread_count=8

It is possible that mysqld could use up to

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4877184 K  bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7fb2d2e51008

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 = 0x7fb5877b5e20 thread_stack 0x48000

Trying to get some variables.

Some pointers may be invalid and cause the dump to abort.

Query (0x7fb42ed1b020): is an invalid pointer

Connection ID (thread ID): 24769909

Status: NOT_KILLED

Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on

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.

We think the query pointer is invalid, but we will try to print it anyway.

Query: SELECT m.name, COUNT(DISTINCT p.id_product) nbr, m.id_manufacturer , m.name, psi.price_min, psi.price_max

                                        FROM `ps_category_product` cp

                                        INNER JOIN  `ps_category` c ON (c.id_category = cp.id_category)

                                        INNER JOIN ps_product p ON (p.id_product = cp.id_product)

                                        INNER JOIN ps_manufacturer m ON (m.id_manufacturer = p.id_manufacturer)  INNER JOIN ps_product_shop product_shop

                ON (product_shop.id_product = p.id_product AND product_shop.id_shop = 1)

                        INNER JOIN `ps_layered_price_index` psi

                        ON (psi.id_product = p.id_product AND psi.id_currency = 1)

WHERE

                                        c.nleft >= 4

                                        AND c.nright <= 5

                                        AND c.active = 1

                                        AND product_shop.active = 1 AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 15 OR fp.`id_feature_value` = 18 OR fp.`id_feature_value` = 23)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 68)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 62)

                AND p.id_product IN (SELECT pa.`id_product`

                FROM `ps_product_attribute_combination` pac

                LEFT JOIN `ps_product_attribute` pa ON (pa.`id_product_attribute` = pac.`id_product_attribute`)

                WHERE pac.`id_attribute` = 34)

                AND p.id_product IN (SELECT pa.`id_product`

                FROM `ps_product_attribute_combination` pac

                LEFT JOIN `ps_product_attribute` pa ON (pa.`id_product_attribute` = pac.`id_product_attribute`)

                WHERE pac.`id_attribute` = 39 OR pac.`id_attribute` = 41 OR pac.`id_attribute` = 53 OR pac.`id_attribute` = 98)

 GROUP BY p.id_manufacturer

Jean Weisbuch added a comment - 2017-03-28 02:31 - edited The same just happened to me on 10.0.29 using Debian Wheezy packages from MariaDB. Here is what i have on my error log : /usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb9f46b] /usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x7461f6] /lib/x86_64-linux-gnu/libpthread.so.0(+0xf0a0)[0x7fb8deced0a0] /usr/sbin/mysqld(_ZN4JOIN14optimize_innerEv+0x1640)[0x63b310] /usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x9e)[0x63cade] /usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x28d)[0x64038d] /usr/sbin/mysqld[0x5e5886] /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x503d)[0x5f0e9d] /usr/sbin/mysqld[0x5f28f7] /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6e)[0x5f4cce] /usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6b3fa3] /usr/sbin/mysqld(handle_one_connection+0x42)[0x6b4072] /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7fb8dece4b50] /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fb8dd3eefbd] 170328 03:55:04 mysqld_safe Number of processes running now: 0 170328 03:55:04 mysqld_safe mysqld restarted 170328 3:55:04 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB-1~wheezy) starting as process 8742 ... /usr/sbin/mysqld: Query cache is disabled (resize or similar command in progress); repeat this command later 170328 3:55:05 [Note] InnoDB: Using mutexes to ref count buffer pool pages 170328 3:55:05 [Note] InnoDB: The InnoDB memory heap is disabled 170328 3:55:05 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 170328 3:55:05 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 170328 3:55:05 [Note] InnoDB: Compressed tables use zlib 1.2.7 170328 3:55:05 [Note] InnoDB: Using Linux native AIO 170328 3:55:05 [Note] InnoDB: Using CPU crc32 instructions 170328 3:55:05 [Note] InnoDB: Initializing buffer pool, size = 8.0G 170328 3:55:05 [Note] InnoDB: Completed initialization of buffer pool 170328 3:55:05 [Note] InnoDB: Highest supported file format is Barracuda. 170328 3:55:05 [Note] InnoDB: Log scan progressed past the checkpoint lsn 39835474231511 170328 3:55:05 [Note] InnoDB: Database was not shutdown normally! 170328 3:55:05 [Note] InnoDB: Starting crash recovery. 170328 3:55:05 [Note] InnoDB: Reading tablespace information from the .ibd files... 170328 3:55:06 [ERROR] InnoDB: space header page consists of zero bytes in tablespace ./otherdb/#sql-ib7991104-2285190905.ibd (table otherdb/#sql-ib7991104-2285190905) 170328 3:55:06 [Note] InnoDB: Page size:1024 Pages to analyze:64 170328 3:55:06 [Note] InnoDB: Page size: 1024, Possible space_id count:0 170328 3:55:06 [Note] InnoDB: Page size:2048 Pages to analyze:32 170328 3:55:06 [Note] InnoDB: Page size: 2048, Possible space_id count:0 170328 3:55:06 [Note] InnoDB: Page size:4096 Pages to analyze:16 170328 3:55:06 [Note] InnoDB: Page size: 4096, Possible space_id count:0 170328 3:55:06 [Note] InnoDB: Page size:8192 Pages to analyze:8 170328 3:55:06 [Note] InnoDB: Page size: 8192, Possible space_id count:0 170328 3:55:06 [Note] InnoDB: Page size:16384 Pages to analyze:4 170328 3:55:06 [Note] InnoDB: Page size: 16384, Possible space_id count:0 2017-03-28 03:55:06 7f1fb88bc760 InnoDB: Operating system error number 2 in a file operation. InnoDB: The error means the system cannot find the path specified. InnoDB: If you are installing InnoDB, remember that you must create InnoDB: directories yourself, InnoDB does not create them. InnoDB: Error: could not open single-table tablespace file ./otherdb/#sql-ib7991104-2285190905.ibd 170328 3:55:07 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535 170328 3:55:07 [ERROR] InnoDB: checksum mismatch in tablespace ./database/wp_term_relationships.ibd (table database/wp_term_relationships) 170328 3:55:07 [Note] InnoDB: Page size:1024 Pages to analyze:64 170328 3:55:07 [Note] InnoDB: Page size: 1024, Possible space_id count:0 170328 3:55:07 [Note] InnoDB: Page size:2048 Pages to analyze:56 170328 3:55:07 [Note] InnoDB: Page size: 2048, Possible space_id count:0 170328 3:55:07 [Note] InnoDB: Page size:4096 Pages to analyze:28 170328 3:55:07 [Note] InnoDB: Page size: 4096, Possible space_id count:0 170328 3:55:07 [Note] InnoDB: Page size:8192 Pages to analyze:14 170328 3:55:07 [Note] InnoDB: Page size: 8192, Possible space_id count:0 170328 3:55:07 [Note] InnoDB: Page size:16384 Pages to analyze:7 170328 3:55:07 [Note] InnoDB: VALID: space:8763257 page_no:1 page_size:16384 170328 3:55:07 [Note] InnoDB: VALID: space:8763257 page_no:2 page_size:16384 170328 3:55:07 [Note] InnoDB: VALID: space:8763257 page_no:3 page_size:16384 170328 3:55:07 [Note] InnoDB: VALID: space:8763257 page_no:4 page_size:16384 170328 3:55:07 [Note] InnoDB: Page size: 16384, Possible space_id count:1 170328 3:55:07 [Note] InnoDB: space_id:8763257, Number of pages matched: 4/4 (16384) 170328 3:55:07 [Note] InnoDB: Chosen space:8763257 170328 3:55:07 [Note] InnoDB: Restoring page 0 of tablespace 8763257 170328 3:55:07 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 8763257 2017-03-28 03:55:07 7f1fb88bc760 InnoDB: Operating system error number 2 in a file operation. InnoDB: The error means the system cannot find the path specified. InnoDB: If you are installing InnoDB, remember that you must create InnoDB: directories yourself, InnoDB does not create them. InnoDB: Error: could not open single-table tablespace file ./database/wp_term_relationships.ibd InnoDB: We do not continue the crash recovery, because the table may become InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it. InnoDB: To fix the problem and start mysqld: InnoDB: 1) If there is a permission problem in the file and mysqld cannot InnoDB: open the file, you should modify the permissions. InnoDB: 2) If the table is not needed, or you can restore it from a backup, InnoDB: then you can remove the .ibd file, and InnoDB will do a normal InnoDB: crash recovery and ignore that table. InnoDB: 3) If the file system or the disk is broken, and you cannot remove InnoDB: and force InnoDB to continue crash recovery here. 170328 03:55:07 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended 170328 03:58:47 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql 170328 3:58:47 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB-1~wheezy) starting as process 9173 ... /usr/sbin/mysqld: Query cache is disabled (resize or similar command in progress); repeat this command later /usr/sbin/mysqld: Query cache is disabled (resize or similar command in progress); repeat this command later 170328 3:58:48 [Note] InnoDB: Using mutexes to ref count buffer pool pages 170328 3:58:48 [Note] InnoDB: The InnoDB memory heap is disabled 170328 3:58:48 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 170328 3:58:48 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 170328 3:58:48 [Note] InnoDB: Compressed tables use zlib 1.2.7 170328 3:58:48 [Note] InnoDB: Using Linux native AIO 170328 3:58:48 [Note] InnoDB: Using CPU crc32 instructions 170328 3:58:48 [Note] InnoDB: Initializing buffer pool, size = 8.0G 170328 3:58:48 [Note] InnoDB: Completed initialization of buffer pool 170328 3:58:48 [Note] InnoDB: Highest supported file format is Barracuda. 170328 3:58:48 [Note] InnoDB: Log scan progressed past the checkpoint lsn 39835474231511 170328 3:58:48 [Note] InnoDB: Database was not shutdown normally! 170328 3:58:48 [Note] InnoDB: Starting crash recovery. 170328 3:58:48 [Note] InnoDB: Reading tablespace information from the .ibd files... 170328 3:58:49 [ERROR] InnoDB: space header page consists of zero bytes in tablespace ./otherdb/#sql-ib7991104-2285190905.ibd (table otherdb/#sql-ib7991104-2285190905) 170328 3:58:49 [Note] InnoDB: Page size:1024 Pages to analyze:64 170328 3:58:49 [Note] InnoDB: Page size: 1024, Possible space_id count:0 170328 3:58:49 [Note] InnoDB: Page size:2048 Pages to analyze:32 170328 3:58:49 [Note] InnoDB: Page size: 2048, Possible space_id count:0 170328 3:58:49 [Note] InnoDB: Page size:4096 Pages to analyze:16 170328 3:58:49 [Note] InnoDB: Page size: 4096, Possible space_id count:0 170328 3:58:49 [Note] InnoDB: Page size:8192 Pages to analyze:8 170328 3:58:49 [Note] InnoDB: Page size: 8192, Possible space_id count:0 170328 3:58:49 [Note] InnoDB: Page size:16384 Pages to analyze:4 170328 3:58:49 [Note] InnoDB: Page size: 16384, Possible space_id count:0 2017-03-28 03:58:49 7f4edc6dd760 InnoDB: Operating system error number 2 in a file operation. InnoDB: The error means the system cannot find the path specified. InnoDB: If you are installing InnoDB, remember that you must create InnoDB: directories yourself, InnoDB does not create them. InnoDB: Error: could not open single-table tablespace file ./otherdb/#sql-ib7991104-2285190905.ibd 170328 3:58:49 [ERROR] InnoDB: Space id in fsp header 1851878432,but in the page header 544434535 170328 3:58:49 [ERROR] InnoDB: checksum mismatch in tablespace ./database/wp_term_relationships.ibd (table database/wp_term_relationships) [...] And at the beginning of the idb file : 170328 3:55:01 [ERROR] 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. 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.0.29-MariaDB-1~wheezy key_buffer_size=4294967292 read_buffer_size=131072 max_used_connections=64 max_threads=311 thread_count=8 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4877184 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x7fb2d2e51008 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 = 0x7fb5877b5e20 thread_stack 0x48000 Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (0x7fb42ed1b020): is an invalid pointer Connection ID (thread ID): 24769909 Status: NOT_KILLED Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on 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. We think the query pointer is invalid, but we will try to print it anyway. Query: SELECT m.name, COUNT(DISTINCT p.id_product) nbr, m.id_manufacturer , m.name, psi.price_min, psi.price_max FROM `ps_category_product` cp INNER JOIN `ps_category` c ON (c.id_category = cp.id_category) INNER JOIN ps_product p ON (p.id_product = cp.id_product) INNER JOIN ps_manufacturer m ON (m.id_manufacturer = p.id_manufacturer) INNER JOIN ps_product_shop product_shop ON (product_shop.id_product = p.id_product AND product_shop.id_shop = 1) INNER JOIN `ps_layered_price_index` psi ON (psi.id_product = p.id_product AND psi.id_currency = 1) WHERE c.nleft >= 4 AND c.nright <= 5 AND c.active = 1 AND product_shop.active = 1 AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 15 OR fp.`id_feature_value` = 18 OR fp.`id_feature_value` = 23) AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 68) AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 62) AND p.id_product IN (SELECT pa.`id_product` FROM `ps_product_attribute_combination` pac LEFT JOIN `ps_product_attribute` pa ON (pa.`id_product_attribute` = pac.`id_product_attribute`) WHERE pac.`id_attribute` = 34) AND p.id_product IN (SELECT pa.`id_product` FROM `ps_product_attribute_combination` pac LEFT JOIN `ps_product_attribute` pa ON (pa.`id_product_attribute` = pac.`id_product_attribute`) WHERE pac.`id_attribute` = 39 OR pac.`id_attribute` = 41 OR pac.`id_attribute` = 53 OR pac.`id_attribute` = 98) GROUP BY p.id_manufacturer

Daniel Black made changes - 2017-03-28 05:22

Remote Link

This issue links to "mysql 78067 - tablespace containing assuming error message(?) (Web Link)" [ 27944 ]

Michael Widenius added a comment - 2017-03-28 06:37 - edited

What is intersting in Jean's log is that the ibfile contains half of the crash, but the stack trace continues
in the error log file. Another interesting thing is that the ibfile contains the first stderr print after a failure.
Wonder if it's the crash that triggers stderr to be using the wrong file.

I noticed that on windows, we call reopen_fstreams after innodb is opened, which could in theory cause some issues if innodb crashed in a background thread during this reopen.
We should at least move this reopen_fstreams before init_server_components

Unfortunately this doesn't explain this crash as Jean's crash is not on windows.

How atomic is writing to stderr if freopen() is called ?
What I don't understand is how it's possible that stderr could, possible as part of freopen(), use the file descriptor to the innodb file?

One FreeBSD we did have a bug like this a long time ago when freopen was not thread safe and another thread could get the same file descriptor as used by stderr:
https://bugs.mysql.com/bug.php?id=51023

This bug happens apparently on wheezy. Wonder on which other OS this problem has appeared?

Regards,
Monty

Michael Widenius added a comment - 2017-03-28 06:37 - edited What is intersting in Jean's log is that the ibfile contains half of the crash, but the stack trace continues in the error log file. Another interesting thing is that the ibfile contains the first stderr print after a failure. Wonder if it's the crash that triggers stderr to be using the wrong file. I noticed that on windows, we call reopen_fstreams after innodb is opened, which could in theory cause some issues if innodb crashed in a background thread during this reopen. We should at least move this reopen_fstreams before init_server_components Unfortunately this doesn't explain this crash as Jean's crash is not on windows. How atomic is writing to stderr if freopen() is called ? What I don't understand is how it's possible that stderr could, possible as part of freopen(), use the file descriptor to the innodb file? One FreeBSD we did have a bug like this a long time ago when freopen was not thread safe and another thread could get the same file descriptor as used by stderr: https://bugs.mysql.com/bug.php?id=51023 This bug happens apparently on wheezy. Wonder on which other OS this problem has appeared? Regards, Monty

Michael Widenius made changes - 2017-03-28 06:49

Environment

RHEL6, x86_64, VMWare

RHEL6, x86_64, VMWare, wheezy

Jean Weisbuch added a comment - 2017-03-28 09:09

Some additional notes on my crash : The server is on an OpenVZ container running kernel 2.6.32-openvz-042stab116.2-amd64 (Jun 24 2016), the server was up since the 17/02 and there are 4 OpenVZ container containing each a MariaDB server on this server.

On the error log backlog there is a similar crash that happened on the 17/02 on the same query but with all the log on the error log :

170216 16:58:16 [ERROR] 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.

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.0.29-MariaDB-1~wheezy

key_buffer_size=4294967292

read_buffer_size=131072

max_used_connections=47

max_threads=311

thread_count=3

It is possible that mysqld could use up to

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4877184 K  bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f574ca5c008

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 = 0x7f57bd0d9e20 thread_stack 0x48000

/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb9f46b]

/usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x7461f6]

/lib/x86_64-linux-gnu/libpthread.so.0(+0xf0a0)[0x7f5b065880a0]

/usr/sbin/mysqld(_Z30setup_sj_materialization_part2P13st_join_table+0x57)[0x6e10c7]

/usr/sbin/mysqld(_ZN4JOIN14optimize_innerEv+0x1710)[0x63b3e0]

/usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x9e)[0x63cade]

/usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x28d)[0x64038d]

/usr/sbin/mysqld[0x5e5886]

/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x503d)[0x5f0e9d]

/usr/sbin/mysqld[0x5f28f7]

/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6e)[0x5f4cce]

/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6b3fa3]

/usr/sbin/mysqld(handle_one_connection+0x42)[0x6b4072]

/lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7f5b0657fb50]

/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f5b04c89fbd]

Trying to get some variables.

Some pointers may be invalid and cause the dump to abort.

Query (0x7f5644414020): is an invalid pointer

Connection ID (thread ID): 519012

Status: NOT_KILLED

Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on

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.

We think the query pointer is invalid, but we will try to print it anyway.

Query: SELECT m.name, COUNT(DISTINCT p.id_product) nbr, m.id_manufacturer , m.name, psi.price_min, psi.price_max

					FROM `ps_category_product` cp

					INNER JOIN  `ps_category` c ON (c.id_category = cp.id_category)

					INNER JOIN ps_product p ON (p.id_product = cp.id_product)

					INNER JOIN ps_manufacturer m ON (m.id_manufacturer = p.id_manufacturer)  INNER JOIN ps_product_shop product_shop

		ON (product_shop.id_product = p.id_product AND product_shop.id_shop = 1)

			INNER JOIN `ps_layered_price_index` psi

			ON (psi.id_product = p.id_product AND psi.id_currency = 1)

WHERE

					c.nleft >= 4

					AND c.nright <= 5

					AND c.active = 1

					AND product_shop.active = 1 AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 23)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 68)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 62)

		AND p.id_product IN (SELECT pa.`id_product`

		FROM `ps_product_attribute_combination` pac

		LEFT JOIN `ps_product_attribute` pa ON (pa.`id_product_attribute` = pac.`id_product_attribute`)

		WHERE pac.`id_attribute` = 35 OR pac.`id_attribute` = 36)

		AND p.id_product IN (SELECT pa.`id_product`

		FROM `ps_product_attribute_combination` pac

		LEFT JOIN `ps_product_attribute` pa ON (pa.`id_product_attribute` = pac.`id_product_attribute`)

		WHERE pac.`id_attribute` = 14)

 GROUP BY p.id_manufacturer

170216 16:58:19 mysqld_safe Number of processes running now: 0

170216 16:58:19 mysqld_safe mysqld restarted

170216 16:58:19 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB-1~wheezy) starting as process 12920 ...

/usr/sbin/mysqld: Query cache is disabled (resize or similar command in progress); repeat this command later

170216 16:58:20 [Note] InnoDB: Using mutexes to ref count buffer pool pages

170216 16:58:20 [Note] InnoDB: The InnoDB memory heap is disabled

170216 16:58:20 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins

170216 16:58:20 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier

170216 16:58:20 [Note] InnoDB: Compressed tables use zlib 1.2.7

170216 16:58:20 [Note] InnoDB: Using Linux native AIO

170216 16:58:20 [Note] InnoDB: Using CPU crc32 instructions

170216 16:58:20 [Note] InnoDB: Initializing buffer pool, size = 8.0G

170216 16:58:20 [Note] InnoDB: Completed initialization of buffer pool

170216 16:58:20 [Note] InnoDB: Highest supported file format is Barracuda.

170216 16:58:20 [Note] InnoDB: Log scan progressed past the checkpoint lsn 39776728170240

170216 16:58:20 [Note] InnoDB: Database was not shutdown normally!

170216 16:58:20 [Note] InnoDB: Starting crash recovery.

170216 16:58:20 [Note] InnoDB: Reading tablespace information from the .ibd files...

170216 16:58:20 [ERROR] InnoDB: space header page consists of zero bytes in tablespace ./otherdb/#sql-ib7991104-2285190905.ibd (table otherdb/#sql-ib7991104-2285190905)

170216 16:58:20 [Note] InnoDB: Page size:1024 Pages to analyze:64

170216 16:58:20 [Note] InnoDB: Page size: 1024, Possible space_id count:0

170216 16:58:20 [Note] InnoDB: Page size:2048 Pages to analyze:32

170216 16:58:20 [Note] InnoDB: Page size: 2048, Possible space_id count:0

170216 16:58:20 [Note] InnoDB: Page size:4096 Pages to analyze:16

170216 16:58:20 [Note] InnoDB: Page size: 4096, Possible space_id count:0

170216 16:58:20 [Note] InnoDB: Page size:8192 Pages to analyze:8

170216 16:58:20 [Note] InnoDB: Page size: 8192, Possible space_id count:0

170216 16:58:20 [Note] InnoDB: Page size:16384 Pages to analyze:4

170216 16:58:20 [Note] InnoDB: Page size: 16384, Possible space_id count:0

2017-02-16 16:58:20 7fb8df10b760  InnoDB: Operating system error number 2 in a file operation.

InnoDB: The error means the system cannot find the path specified.

InnoDB: If you are installing InnoDB, remember that you must create

InnoDB: directories yourself, InnoDB does not create them.

InnoDB: Error: could not open single-table tablespace file ./otherdb/#sql-ib7991104-2285190905.ibd

170216 16:58:24 [Note] InnoDB: Restoring possible half-written data pages

170216 16:58:24 [Note] InnoDB: from the doublewrite buffer...

InnoDB: Doing recovery: scanned up to log sequence number 39776728204895

170216 16:58:25 [Note] InnoDB: Starting an apply batch of log records to the database...

InnoDB: Progress in percent: 2 3 4 5 6 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 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99

InnoDB: Apply batch completed

170216 16:58:27 [Note] InnoDB: 128 rollback segment(s) are active.

170216 16:58:27 [Note] InnoDB: Waiting for purge to start

170216 16:58:27 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.34-79.1 started; log sequence number 39776728204895

170216 16:58:27 [Note] Plugin 'FEEDBACK' is disabled.

170216 16:58:27 [Note] Server socket created on IP: '::'.

170216 16:58:27 [Note] Server socket created on IP: '::'.

170216 16:58:27 [ERROR] mysqld: Table './mysql/user' is marked as crashed and should be repaired

170216 16:58:27 [Warning] Checking table:   './mysql/user'

170216 16:58:27 [ERROR] mysql.user: 1 client is using or hasn't closed the table properly

170216 16:58:27 [Note] /usr/sbin/mysqld: ready for connections.

Version: '10.0.29-MariaDB-1~wheezy'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution

Configuration :

[client]

port		= 3306

socket		= /var/run/mysqld/mysqld.sock

[mysqld_safe]

socket		= /var/run/mysqld/mysqld.sock

nice		= 0

[mysqld]

user		= mysql

pid-file	= /var/run/mysqld/mysqld.pid

socket		= /var/run/mysqld/mysqld.sock

port		= 3306

basedir		= /usr

datadir		= /var/lib/mysql

tmpdir		= /tmpfs

skip-external-locking

key_buffer_size		= 4G

max_allowed_packet	= 64M

thread_cache_size	= 24

myisam-recover-options		= BACKUP

max_connections		= 300

table_open_cache	= 10000

table_definition_cache	= 10000

query_cache_limit       = 1M

query_cache_size        = 64M

query_cache_min_res_unit        = 2048

query_cache_type        = OFF

local-infile		= 0

open_files_limit	= 65535

skip-name-resolve

max_delayed_threads	= 1

wait_timeout		= 60

interactive_timeout	= 60

join_buffer_size	= 2M

read_rnd_buffer_size	= 1M

tmp_table_size		= 64M

max_heap_table_size	= 64M

max_connect_errors	= 1000

bulk_insert_buffer_size	= 32M

myisam_sort_buffer_size = 32M

default_storage_engine  = InnoDB

innodb_file_format	= Barracuda

innodb_buffer_pool_size	= 8G

innodb_log_file_size	= 128M

innodb_flush_log_at_trx_commit	= 2

innodb_log_buffer_size	= 8M

innodb_file_per_table	= 1

innodb_open_files	= 400

innodb_io_capacity	= 400

innodb_flush_method	= O_DIRECT

join_cache_level	= 6

key_cache_segments	= 6

innodb_old_blocks_time	= 1000

extra_port		= 3307

extra-max-connections	= 10

log_error		= /var/log/mysql/error.log

slow_query_log_file	= /var/log/mysql/mysql-slow.log

slow_query_log		= 1

long_query_time		= 4

[mysqldump]

quick

quote-names

max_allowed_packet	= 64M

[mysql]

[isamchk]

key_buffer		= 64M

!includedir /etc/mysql/conf.d/

# egrep -v "^$|^#" /etc/mysql/conf.d/*

/etc/mysql/conf.d/mariadb.cnf:[client]

/etc/mysql/conf.d/mariadb.cnf:[mysqld]

/etc/mysql/conf.d/mysqld_safe_syslog.cnf.dpkg-dist:[mysqld_safe]

/etc/mysql/conf.d/mysqld_safe_syslog.cnf.dpkg-dist:skip_log_error

/etc/mysql/conf.d/mysqld_safe_syslog.cnf.dpkg-dist:syslog

/etc/mysql/conf.d/tokudb.cnf:[mariadb]

MariaDB [information_schema]> SELECT COUNT(*) FROM tables;

+----------+

| COUNT(*) |

+----------+

|    88955 |

+----------+

1 row in set (0.88 sec)

MariaDB [information_schema]> SELECT COUNT(DISTINCT table_schema) FROM tables;

+------------------------------+

| COUNT(DISTINCT table_schema) |

+------------------------------+

|                          967 |

+------------------------------+

1 row in set (0.94 sec)

Jean Weisbuch added a comment - 2017-03-28 09:09 Some additional notes on my crash : The server is on an OpenVZ container running kernel 2.6.32-openvz-042stab116.2-amd64 (Jun 24 2016), the server was up since the 17/02 and there are 4 OpenVZ container containing each a MariaDB server on this server. On the error log backlog there is a similar crash that happened on the 17/02 on the same query but with all the log on the error log : 170216 16:58:16 [ERROR] 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. 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.0.29-MariaDB-1~wheezy key_buffer_size=4294967292 read_buffer_size=131072 max_used_connections=47 max_threads=311 thread_count=3 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4877184 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x7f574ca5c008 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 = 0x7f57bd0d9e20 thread_stack 0x48000 /usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xb9f46b] /usr/sbin/mysqld(handle_fatal_signal+0x3b6)[0x7461f6] /lib/x86_64-linux-gnu/libpthread.so.0(+0xf0a0)[0x7f5b065880a0] /usr/sbin/mysqld(_Z30setup_sj_materialization_part2P13st_join_table+0x57)[0x6e10c7] /usr/sbin/mysqld(_ZN4JOIN14optimize_innerEv+0x1710)[0x63b3e0] /usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x9e)[0x63cade] /usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x28d)[0x64038d] /usr/sbin/mysqld[0x5e5886] /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x503d)[0x5f0e9d] /usr/sbin/mysqld[0x5f28f7] /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1c6e)[0x5f4cce] /usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x453)[0x6b3fa3] /usr/sbin/mysqld(handle_one_connection+0x42)[0x6b4072] /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7f5b0657fb50] /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f5b04c89fbd] Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (0x7f5644414020): is an invalid pointer Connection ID (thread ID): 519012 Status: NOT_KILLED Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on 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. We think the query pointer is invalid, but we will try to print it anyway. Query: SELECT m.name, COUNT(DISTINCT p.id_product) nbr, m.id_manufacturer , m.name, psi.price_min, psi.price_max FROM `ps_category_product` cp INNER JOIN `ps_category` c ON (c.id_category = cp.id_category) INNER JOIN ps_product p ON (p.id_product = cp.id_product) INNER JOIN ps_manufacturer m ON (m.id_manufacturer = p.id_manufacturer) INNER JOIN ps_product_shop product_shop ON (product_shop.id_product = p.id_product AND product_shop.id_shop = 1) INNER JOIN `ps_layered_price_index` psi ON (psi.id_product = p.id_product AND psi.id_currency = 1) WHERE c.nleft >= 4 AND c.nright <= 5 AND c.active = 1 AND product_shop.active = 1 AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 23) AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 68) AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 62) AND p.id_product IN (SELECT pa.`id_product` FROM `ps_product_attribute_combination` pac LEFT JOIN `ps_product_attribute` pa ON (pa.`id_product_attribute` = pac.`id_product_attribute`) WHERE pac.`id_attribute` = 35 OR pac.`id_attribute` = 36) AND p.id_product IN (SELECT pa.`id_product` FROM `ps_product_attribute_combination` pac LEFT JOIN `ps_product_attribute` pa ON (pa.`id_product_attribute` = pac.`id_product_attribute`) WHERE pac.`id_attribute` = 14) GROUP BY p.id_manufacturer 170216 16:58:19 mysqld_safe Number of processes running now: 0 170216 16:58:19 mysqld_safe mysqld restarted 170216 16:58:19 [Note] /usr/sbin/mysqld (mysqld 10.0.29-MariaDB-1~wheezy) starting as process 12920 ... /usr/sbin/mysqld: Query cache is disabled (resize or similar command in progress); repeat this command later 170216 16:58:20 [Note] InnoDB: Using mutexes to ref count buffer pool pages 170216 16:58:20 [Note] InnoDB: The InnoDB memory heap is disabled 170216 16:58:20 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 170216 16:58:20 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 170216 16:58:20 [Note] InnoDB: Compressed tables use zlib 1.2.7 170216 16:58:20 [Note] InnoDB: Using Linux native AIO 170216 16:58:20 [Note] InnoDB: Using CPU crc32 instructions 170216 16:58:20 [Note] InnoDB: Initializing buffer pool, size = 8.0G 170216 16:58:20 [Note] InnoDB: Completed initialization of buffer pool 170216 16:58:20 [Note] InnoDB: Highest supported file format is Barracuda. 170216 16:58:20 [Note] InnoDB: Log scan progressed past the checkpoint lsn 39776728170240 170216 16:58:20 [Note] InnoDB: Database was not shutdown normally! 170216 16:58:20 [Note] InnoDB: Starting crash recovery. 170216 16:58:20 [Note] InnoDB: Reading tablespace information from the .ibd files... 170216 16:58:20 [ERROR] InnoDB: space header page consists of zero bytes in tablespace ./otherdb/#sql-ib7991104-2285190905.ibd (table otherdb/#sql-ib7991104-2285190905) 170216 16:58:20 [Note] InnoDB: Page size:1024 Pages to analyze:64 170216 16:58:20 [Note] InnoDB: Page size: 1024, Possible space_id count:0 170216 16:58:20 [Note] InnoDB: Page size:2048 Pages to analyze:32 170216 16:58:20 [Note] InnoDB: Page size: 2048, Possible space_id count:0 170216 16:58:20 [Note] InnoDB: Page size:4096 Pages to analyze:16 170216 16:58:20 [Note] InnoDB: Page size: 4096, Possible space_id count:0 170216 16:58:20 [Note] InnoDB: Page size:8192 Pages to analyze:8 170216 16:58:20 [Note] InnoDB: Page size: 8192, Possible space_id count:0 170216 16:58:20 [Note] InnoDB: Page size:16384 Pages to analyze:4 170216 16:58:20 [Note] InnoDB: Page size: 16384, Possible space_id count:0 2017-02-16 16:58:20 7fb8df10b760 InnoDB: Operating system error number 2 in a file operation. InnoDB: The error means the system cannot find the path specified. InnoDB: If you are installing InnoDB, remember that you must create InnoDB: directories yourself, InnoDB does not create them. InnoDB: Error: could not open single-table tablespace file ./otherdb/#sql-ib7991104-2285190905.ibd 170216 16:58:24 [Note] InnoDB: Restoring possible half-written data pages 170216 16:58:24 [Note] InnoDB: from the doublewrite buffer... InnoDB: Doing recovery: scanned up to log sequence number 39776728204895 170216 16:58:25 [Note] InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percent: 2 3 4 5 6 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 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Apply batch completed 170216 16:58:27 [Note] InnoDB: 128 rollback segment(s) are active. 170216 16:58:27 [Note] InnoDB: Waiting for purge to start 170216 16:58:27 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.34-79.1 started; log sequence number 39776728204895 170216 16:58:27 [Note] Plugin 'FEEDBACK' is disabled. 170216 16:58:27 [Note] Server socket created on IP: '::'. 170216 16:58:27 [Note] Server socket created on IP: '::'. 170216 16:58:27 [ERROR] mysqld: Table './mysql/user' is marked as crashed and should be repaired 170216 16:58:27 [Warning] Checking table: './mysql/user' 170216 16:58:27 [ERROR] mysql.user: 1 client is using or hasn't closed the table properly 170216 16:58:27 [Note] /usr/sbin/mysqld: ready for connections. Version: '10.0.29-MariaDB-1~wheezy' socket: '/var/run/mysqld/mysqld.sock' port: 3306 mariadb.org binary distribution Configuration : [client] port = 3306 socket = /var/run/mysqld/mysqld.sock [mysqld_safe] socket = /var/run/mysqld/mysqld.sock nice = 0 [mysqld] user = mysql pid-file = /var/run/mysqld/mysqld.pid socket = /var/run/mysqld/mysqld.sock port = 3306 basedir = /usr datadir = /var/lib/mysql tmpdir = /tmpfs skip-external-locking key_buffer_size = 4G max_allowed_packet = 64M thread_cache_size = 24 myisam-recover-options = BACKUP max_connections = 300 table_open_cache = 10000 table_definition_cache = 10000 query_cache_limit = 1M query_cache_size = 64M query_cache_min_res_unit = 2048 query_cache_type = OFF local-infile = 0 open_files_limit = 65535 skip-name-resolve max_delayed_threads = 1 wait_timeout = 60 interactive_timeout = 60 join_buffer_size = 2M read_rnd_buffer_size = 1M tmp_table_size = 64M max_heap_table_size = 64M max_connect_errors = 1000 bulk_insert_buffer_size = 32M myisam_sort_buffer_size = 32M default_storage_engine = InnoDB innodb_file_format = Barracuda innodb_buffer_pool_size = 8G innodb_log_file_size = 128M innodb_flush_log_at_trx_commit = 2 innodb_log_buffer_size = 8M innodb_file_per_table = 1 innodb_open_files = 400 innodb_io_capacity = 400 innodb_flush_method = O_DIRECT join_cache_level = 6 key_cache_segments = 6 innodb_old_blocks_time = 1000 extra_port = 3307 extra-max-connections = 10 log_error = /var/log/mysql/error.log slow_query_log_file = /var/log/mysql/mysql-slow.log slow_query_log = 1 long_query_time = 4 [mysqldump] quick quote-names max_allowed_packet = 64M [mysql] [isamchk] key_buffer = 64M !includedir /etc/mysql/conf.d/ # egrep -v "^$|^#" /etc/mysql/conf.d/* /etc/mysql/conf.d/mariadb.cnf:[client] /etc/mysql/conf.d/mariadb.cnf:[mysqld] /etc/mysql/conf.d/mysqld_safe_syslog.cnf.dpkg-dist:[mysqld_safe] /etc/mysql/conf.d/mysqld_safe_syslog.cnf.dpkg-dist:skip_log_error /etc/mysql/conf.d/mysqld_safe_syslog.cnf.dpkg-dist:syslog /etc/mysql/conf.d/tokudb.cnf:[mariadb] MariaDB [information_schema]> SELECT COUNT(*) FROM tables; +----------+ | COUNT(*) | +----------+ | 88955 | +----------+ 1 row in set (0.88 sec) MariaDB [information_schema]> SELECT COUNT(DISTINCT table_schema) FROM tables; +------------------------------+ | COUNT(DISTINCT table_schema) | +------------------------------+ | 967 | +------------------------------+ 1 row in set (0.94 sec)

Edward Hicks added a comment - 2017-03-28 14:29 - edited

Ours is:

$ uname -a

Linux dbserver 2.6.32-642.13.1.el6.x86_64 #1 SMP Wed Nov 23 16:03:01 EST 2016 x86_64 x86_64 x86_64 GNU/Linux

$ cat /etc/redhat-release

Red Hat Enterprise Linux Server release 6.8 (Santiago)

Edward Hicks added a comment - 2017-03-28 14:29 - edited Ours is: $ uname -a Linux dbserver 2.6.32-642.13.1.el6.x86_64 #1 SMP Wed Nov 23 16:03:01 EST 2016 x86_64 x86_64 x86_64 GNU/Linux $ cat /etc/redhat-release Red Hat Enterprise Linux Server release 6.8 (Santiago)

Edward Hicks made changes - 2017-03-29 15:48

Attachment

osumed_1571_posts.ibd [ 43516 ]

Edward Hicks made changes - 2017-03-29 15:54

Attachment

osumed_1571_posts.ibd [ 43516 ]

Edward Hicks added a comment - 2017-03-29 16:01 - edited

We had another event last night which was triggered by the disk running out of free space. The crash was therefore not a surprise; however, in the process another ibd file was corrupted. You can add 10.0.30 to the list of affected versions.

Unfortunately I cannot attach it this time as it holds potentially sensitive info; however, this time the top of the overwritten file only contained the string "pure virtual method called".

2017-03-29 08:14:05 7f05ac913700 InnoDB: Error: Write to file ./database/table.ibd failed at offset 131072.

InnoDB: 32768 bytes should have been written, only 0 were written.

InnoDB: Operating system error number 28.

InnoDB: Check that your OS and file system support files of this size.

InnoDB: Check also that the disk is not full or a disk quota exceeded.

InnoDB: Error number 28 means 'No space left on device'.

InnoDB: Some operating system error numbers are described at

InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html

FAIL170329  8:14:05 [ERROR] mysqld: The table 'table' is full

FAIL170329  8:14:05 [ERROR] mysqld: The table 'table' is full

FAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAIL170329  8:14:07 [ERROR] mysqld: The table 'table' is full

FAIL170329  8:14:07 [ERROR] mysqld: The table 'table' is full

FAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILInnoDB: Fatal error (Out of disk space) in rollback.

InnoDB: Out of tablespace.

InnoDB: Consider increasing your tablespace.

FAILFAILFAILFAIL170329 08:14:12 mysqld_safe Number of processes running now: 0

170329 08:14:12 mysqld_safe mysqld restarted

170329  8:14:12 [Note] /usr/sbin/mysqld (mysqld 10.0.30-MariaDB) starting as process 9407 ...

170329  8:14:13 [Note] InnoDB: Using mutexes to ref count buffer pool pages

170329  8:14:13 [Note] InnoDB: The InnoDB memory heap is disabled

170329  8:14:13 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins

170329  8:14:13 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier

170329  8:14:13 [Note] InnoDB: Compressed tables use zlib 1.2.3

170329  8:14:13 [Note] InnoDB: Using Linux native AIO

170329  8:14:13 [Note] InnoDB: Using CPU crc32 instructions

170329  8:14:13 [Note] InnoDB: Initializing buffer pool, size = 7.0G

170329  8:14:13 [Note] InnoDB: Completed initialization of buffer pool

170329  8:14:13 [Note] InnoDB: Highest supported file format is Barracuda.

170329  8:14:13 [Note] InnoDB: Log scan progressed past the checkpoint lsn 7020651191165

170329  8:14:13 [Note] InnoDB: Database was not shutdown normally!

170329  8:14:13 [Note] InnoDB: Starting crash recovery.

170329  8:14:13 [Note] InnoDB: Reading tablespace information from the .ibd files...

170329  8:16:28 [ERROR] InnoDB: Space id in fsp header 876228913,but in the page header 540555825

170329  8:16:28 [ERROR] InnoDB: checksum mismatch in tablespace ./meddb/anothertable.ibd (table meddb/anothertable)

170329  8:16:28 [Note] InnoDB: Page size:1024 Pages to analyze:64

170329  8:16:28 [Note] InnoDB: Page size: 1024, Possible space_id count:0

170329  8:16:28 [Note] InnoDB: Page size:2048 Pages to analyze:64

170329  8:16:28 [Note] InnoDB: Page size: 2048, Possible space_id count:0

170329  8:16:28 [Note] InnoDB: Page size:4096 Pages to analyze:56

170329  8:16:28 [Note] InnoDB: Page size: 4096, Possible space_id count:0

170329  8:16:28 [Note] InnoDB: Page size:8192 Pages to analyze:28

170329  8:16:28 [Note] InnoDB: Page size: 8192, Possible space_id count:0

170329  8:16:28 [Note] InnoDB: Page size:16384 Pages to analyze:14

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:1 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:2 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:3 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:4 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:5 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:6 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:7 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:8 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:9 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:10 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:11 page_size:16384

170329  8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:12 page_size:16384

170329  8:16:28 [Note] InnoDB: Page size: 16384, Possible space_id count:1

170329  8:16:28 [Note] InnoDB: space_id:1894080, Number of pages matched: 12/12 (16384)

170329  8:16:28 [Note] InnoDB: Chosen space:1894080

170329  8:16:28 [Note] InnoDB: Restoring page 0 of tablespace 1894080

170329  8:16:28 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1894080

2017-03-29 08:16:28 7f1ca3eec820  InnoDB: Operating system error number 2 in a file operation.

InnoDB: The error means the system cannot find the path specified.

InnoDB: If you are installing InnoDB, remember that you must create

InnoDB: directories yourself, InnoDB does not create them.

InnoDB: Error: could not open single-table tablespace file ./meddb/anothertable.ibd

InnoDB: We do not continue the crash recovery, because the table may become

InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.

InnoDB: To fix the problem and start mysqld:

InnoDB: 1) If there is a permission problem in the file and mysqld cannot

InnoDB: open the file, you should modify the permissions.

InnoDB: 2) If the table is not needed, or you can restore it from a backup,

InnoDB: then you can remove the .ibd file, and InnoDB will do a normal

InnoDB: crash recovery and ignore that table.

InnoDB: 3) If the file system or the disk is broken, and you cannot remove

InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf

InnoDB: and force InnoDB to continue crash recovery here.

170329 08:16:28 mysqld_safe mysqld from pid file /var/lib/mysqldata/mysql/DATABASES/whsqlprd05.pid ended

Edward Hicks added a comment - 2017-03-29 16:01 - edited We had another event last night which was triggered by the disk running out of free space. The crash was therefore not a surprise; however, in the process another ibd file was corrupted. You can add 10.0.30 to the list of affected versions. Unfortunately I cannot attach it this time as it holds potentially sensitive info; however, this time the top of the overwritten file only contained the string "pure virtual method called". 2017-03-29 08:14:05 7f05ac913700 InnoDB: Error: Write to file ./database/table.ibd failed at offset 131072. InnoDB: 32768 bytes should have been written, only 0 were written. InnoDB: Operating system error number 28. InnoDB: Check that your OS and file system support files of this size. InnoDB: Check also that the disk is not full or a disk quota exceeded. InnoDB: Error number 28 means 'No space left on device'. InnoDB: Some operating system error numbers are described at InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html FAIL170329 8:14:05 [ERROR] mysqld: The table 'table' is full FAIL170329 8:14:05 [ERROR] mysqld: The table 'table' is full FAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAIL170329 8:14:07 [ERROR] mysqld: The table 'table' is full FAIL170329 8:14:07 [ERROR] mysqld: The table 'table' is full FAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILFAILInnoDB: Fatal error (Out of disk space) in rollback. InnoDB: Out of tablespace. InnoDB: Consider increasing your tablespace. FAILFAILFAILFAIL170329 08:14:12 mysqld_safe Number of processes running now: 0 170329 08:14:12 mysqld_safe mysqld restarted 170329 8:14:12 [Note] /usr/sbin/mysqld (mysqld 10.0.30-MariaDB) starting as process 9407 ... 170329 8:14:13 [Note] InnoDB: Using mutexes to ref count buffer pool pages 170329 8:14:13 [Note] InnoDB: The InnoDB memory heap is disabled 170329 8:14:13 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 170329 8:14:13 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 170329 8:14:13 [Note] InnoDB: Compressed tables use zlib 1.2.3 170329 8:14:13 [Note] InnoDB: Using Linux native AIO 170329 8:14:13 [Note] InnoDB: Using CPU crc32 instructions 170329 8:14:13 [Note] InnoDB: Initializing buffer pool, size = 7.0G 170329 8:14:13 [Note] InnoDB: Completed initialization of buffer pool 170329 8:14:13 [Note] InnoDB: Highest supported file format is Barracuda. 170329 8:14:13 [Note] InnoDB: Log scan progressed past the checkpoint lsn 7020651191165 170329 8:14:13 [Note] InnoDB: Database was not shutdown normally! 170329 8:14:13 [Note] InnoDB: Starting crash recovery. 170329 8:14:13 [Note] InnoDB: Reading tablespace information from the .ibd files... 170329 8:16:28 [ERROR] InnoDB: Space id in fsp header 876228913,but in the page header 540555825 170329 8:16:28 [ERROR] InnoDB: checksum mismatch in tablespace ./meddb/anothertable.ibd (table meddb/anothertable) 170329 8:16:28 [Note] InnoDB: Page size:1024 Pages to analyze:64 170329 8:16:28 [Note] InnoDB: Page size: 1024, Possible space_id count:0 170329 8:16:28 [Note] InnoDB: Page size:2048 Pages to analyze:64 170329 8:16:28 [Note] InnoDB: Page size: 2048, Possible space_id count:0 170329 8:16:28 [Note] InnoDB: Page size:4096 Pages to analyze:56 170329 8:16:28 [Note] InnoDB: Page size: 4096, Possible space_id count:0 170329 8:16:28 [Note] InnoDB: Page size:8192 Pages to analyze:28 170329 8:16:28 [Note] InnoDB: Page size: 8192, Possible space_id count:0 170329 8:16:28 [Note] InnoDB: Page size:16384 Pages to analyze:14 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:1 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:2 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:3 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:4 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:5 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:6 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:7 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:8 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:9 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:10 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:11 page_size:16384 170329 8:16:28 [Note] InnoDB: VALID: space:1894080 page_no:12 page_size:16384 170329 8:16:28 [Note] InnoDB: Page size: 16384, Possible space_id count:1 170329 8:16:28 [Note] InnoDB: space_id:1894080, Number of pages matched: 12/12 (16384) 170329 8:16:28 [Note] InnoDB: Chosen space:1894080 170329 8:16:28 [Note] InnoDB: Restoring page 0 of tablespace 1894080 170329 8:16:28 [Warning] InnoDB: Doublewrite does not have page_no=0 of space: 1894080 2017-03-29 08:16:28 7f1ca3eec820 InnoDB: Operating system error number 2 in a file operation. InnoDB: The error means the system cannot find the path specified. InnoDB: If you are installing InnoDB, remember that you must create InnoDB: directories yourself, InnoDB does not create them. InnoDB: Error: could not open single-table tablespace file ./meddb/anothertable.ibd InnoDB: We do not continue the crash recovery, because the table may become InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it. InnoDB: To fix the problem and start mysqld: InnoDB: 1) If there is a permission problem in the file and mysqld cannot InnoDB: open the file, you should modify the permissions. InnoDB: 2) If the table is not needed, or you can restore it from a backup, InnoDB: then you can remove the .ibd file, and InnoDB will do a normal InnoDB: crash recovery and ignore that table. InnoDB: 3) If the file system or the disk is broken, and you cannot remove InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf InnoDB: and force InnoDB to continue crash recovery here. 170329 08:16:28 mysqld_safe mysqld from pid file /var/lib/mysqldata/mysql/DATABASES/whsqlprd05.pid ended

Edward Hicks made changes - 2017-03-29 16:01

Affects Version/s

10.0.30 [ 22313 ]

Jean Weisbuch added a comment - 2017-07-06 16:25

Any news on this, is it still not possible to upgrade to 10.0.31?

Jean Weisbuch added a comment - 2017-07-06 16:25 Any news on this, is it still not possible to upgrade to 10.0.31?

Sergey Vojtovich added a comment - 2017-07-14 11:24

mysqld_safe starts mysqld with with "1" and "2" file descriptors closed. This was introduced in https://github.com/MariaDB/server/commit/7497ebf8a49bfe30bb4110f2ac20a30f804b7946

This means that descriptors "1" and "2" are free for use for any file.

But then signal handler writes it's messages to a hardcoded file descriptor STDERR_FILENO (which is "2").

In both reports InnoDB data file header was overrider exactly with signal handler messages.

I'm reassigning to serg and raising priority to critical, since it causes data loss.

Sergey Vojtovich added a comment - 2017-07-14 11:24 mysqld_safe starts mysqld with with "1" and "2" file descriptors closed. This was introduced in https://github.com/MariaDB/server/commit/7497ebf8a49bfe30bb4110f2ac20a30f804b7946 This means that descriptors "1" and "2" are free for use for any file. But then signal handler writes it's messages to a hardcoded file descriptor STDERR_FILENO (which is "2"). In both reports InnoDB data file header was overrider exactly with signal handler messages. I'm reassigning to serg and raising priority to critical, since it causes data loss.

Sergey Vojtovich made changes - 2017-07-14 11:25

Priority

Major [ 3 ]

Critical [ 2 ]

Sergey Vojtovich made changes - 2017-07-14 11:25

Assignee

Marko Mäkelä [ marko ]

Sergei Golubchik [ serg ]

Sergey Vojtovich added a comment - 2017-07-14 11:29

Please also note that early server error messages (before freopen(stderr)) may also go to undesired location.
Same for setups where log_error is not defined.

Sergey Vojtovich added a comment - 2017-07-14 11:29 Please also note that early server error messages (before freopen(stderr)) may also go to undesired location. Same for setups where log_error is not defined.

Sergei Golubchik made changes - 2017-07-14 12:02

Status

Open [ 1 ]

In Progress [ 3 ]

Sergei Golubchik made changes - 2017-07-14 13:31

Status

In Progress [ 3 ]

Stalled [ 10000 ]

Sergei Golubchik made changes - 2017-07-15 06:43

Fix Version/s		5.5.57 [ 22539 ]
Fix Version/s		10.0.32 [ 22504 ]
Fix Version/s		10.1.26 [ 22553 ]
Fix Version/s		10.2.8 [ 22544 ]
Fix Version/s	5.5 [ 15800 ]
Fix Version/s	10.0 [ 16000 ]
Resolution		Fixed [ 1 ]
Status	Stalled [ 10000 ]	Closed [ 6 ]

Sergei Golubchik made changes - 2021-12-06 21:44

Workflow

MariaDB v3 [ 79770 ]

MariaDB v4 [ 151758 ]

MariaDB Server

Signal 6 crash corrupts ibd files

Details

Description

Attachments

Attachments

Issue Links

Activity

People

Dates

Git Integration