Description:
After enabling InnoDB Encryption on a CentOS 6.7 setup using 5.7.13 64-bit Linux tarball glibc2.5, FusionIO, and innodb_flush_method=O_DIRECT, we are seeing crashes upon table creation or altering existing tables to be encrypted. One table was able to be created (after disabling native_aio), but then a subsequent INSERT crashed it.
How to repeat:
Set up 5.7.13 64-bit instanceon Linux.
Use FusionIO disk.
Set innodb_flush_method=O_DIRECT
Enable InnoDB encryption (i.e., early-plugin-load=keyring_file.so, keyring_file_data=/path/to/keyring)
Then try to create an encrypted table, like:
CREATE TABLE `test`.`enc1` (`i` int(11) DEFAULT NULL) ENGINE=InnoDB DEFAULT CHARSET=utf8 ENCRYPTION='y';
Crash!
Stack Trace #1:
Version: '5.7.13-log' socket: '/tmp/mysqld.sock' port: 3306 MySQL Community Server (GPL)
2016-06-28T17:01:27.172072Z 0 [ERROR] [FATAL] InnoDB: Native Linux AIO interface. io_submit() call failed when resubmitting a partial I/O request on the file ./test1/#sql-af28_7.ibd.
2016-06-28 10:01:27 0x7f52551c5700 InnoDB: Assertion failure in thread 139991591966464 in file ut0ut.cc line 920
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
17:01:27 UTC - 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=83886080
read_buffer_size=131072
max_used_connections=3
max_threads=480
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 272641 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
/glide/mysql/5.7.13/bin/mysqld(my_print_stacktrace+0x35)[0xf1a055]
/glide/mysql/5.7.13/bin/mysqld(handle_fatal_signal+0x4a4)[0x79c1b4]
/lib64/libpthread.so.0(+0xf7e0)[0x7f532f18f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x7f532de3a625]
/lib64/libc.so.6(abort+0x175)[0x7f532de3be05]
/glide/mysql/5.7.13/bin/mysqld[0x10a6eb5]
/glide/mysql/5.7.13/bin/mysqld(_ZN2ib5fatalD1Ev+0xb3)[0x10aba03]
/glide/mysql/5.7.13/bin/mysqld(_ZN15LinuxAIOHandler4pollEPP10fil_node_tPPvP9IORequest+0x37c)[0xfb617c]
/glide/mysql/5.7.13/bin/mysqld(_Z14os_aio_handlermPP10fil_node_tPPvP9IORequest+0xb7)[0xfb62a7]
/glide/mysql/5.7.13/bin/mysqld(_Z12fil_aio_waitm+0x38)[0x114cec8]
/glide/mysql/5.7.13/bin/mysqld(io_handler_thread+0xc8)[0x105aca8]
/lib64/libpthread.so.0(+0x7aa1)[0x7f532f187aa1]
/lib64/libc.so.6(clone+0x6d)[0x7f532def093d]
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.
2016-06-28T17:01:27.289511Z mysqld_safe Number of processes running now: 0
2016-06-28T17:01:27.292220Z mysqld_safe mysqld restarted
Stack Trace #2 (after disabling native_aio):
Disabling native_aio seems to allow it to work partially, but it still crashes (was able to insert a couple records into an empty table before it crashed this time, but it still crashed). The error with native_aio disabled is:
Version: '5.7.13-log' socket: '/tmp/mysqld.sock' port: 3306 MySQL Community Server (GPL)
2016-06-28T17:46:57.149264Z 0 [Warning] InnoDB: Retry attempts for writing partial data failed.
2016-06-28T17:46:57.149308Z 0 [ERROR] InnoDB: Write to file ./benchmarking1/enc1.ibdfailed at offset 49152, 16384 bytes should have been written, only 0 were written. Operating system error number 22. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
2016-06-28T17:46:57.149337Z 0 [ERROR] InnoDB: Error number 22 means 'Invalid argument'
2016-06-28T17:46:57.149347Z 0 [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html
2016-06-28 10:46:57 0x7f19e2076700 InnoDB: Assertion failure in thread 139749143045888 in file os0file.cc line 7702
InnoDB: Failing assertion: err == DB_SUCCESS || err == DB_IO_NO_PUNCH_HOLE
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
17:46:57 UTC - 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=83886080
read_buffer_size=131072
max_used_connections=1
max_threads=480
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 272641 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
/glide/mysql/5.7.13/bin/mysqld(my_print_stacktrace+0x35)[0xf1a055]
/glide/mysql/5.7.13/bin/mysqld(handle_fatal_signal+0x4a4)[0x79c1b4]
/lib64/libpthread.so.0(+0xf7e0)[0x7f1abb63f7e0]
/lib64/libc.so.6(gsignal+0x35)[0x7f1aba2ea625]
/lib64/libc.so.6(abort+0x175)[0x7f1aba2ebe05]
/glide/mysql/5.7.13/bin/mysqld[0x10a6eb5]
/glide/mysql/5.7.13/bin/mysqld(_Z14os_aio_handlermPP10fil_node_tPPvP9IORequest+0xc70)[0xfb6e60]
/glide/mysql/5.7.13/bin/mysqld(_Z12fil_aio_waitm+0x38)[0x114cec8]
/glide/mysql/5.7.13/bin/mysqld(io_handler_thread+0xc8)[0x105aca8]
/lib64/libpthread.so.0(+0x7aa1)[0x7f1abb637aa1]
/lib64/libc.so.6(clone+0x6d)[0x7f1aba3a093d]
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.
2016-06-28T17:46:57.262330Z mysqld_safe Number of processes running now: 0
2016-06-28T17:46:57.265238Z mysqld_safe mysqld restarted
#3:
Version: '5.7.13-log' socket: '/tmp/mysqld.sock' port: 3306 MySQL Community Server (GPL)
2016-06-29T18:44:14.147545Z 0 [Warning] InnoDB: Retry attempts for writing partial data failed.
2016-06-29T18:44:14.147603Z 0 [ERROR] InnoDB: Write to file ./test/enc1.ibdfailed at offset 16384, 16384 bytes should have been written, only 0 were written. Operating system error number 22. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
2016-06-29T18:44:14.147631Z 0 [ERROR] InnoDB: Error number 22 means 'Invalid argument'
2016-06-29T18:44:14.147640Z 0 [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html
2016-06-29 11:44:14 0x7f1b12bfd700 InnoDB: Assertion failure in thread 139754255406848 in file os0file.cc line 7702
InnoDB: Failing assertion: err == DB_SUCCESS || err == DB_IO_NO_PUNCH_HOLE
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
18:44:14 UTC - 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=83886080
read_buffer_size=131072
max_used_connections=2
max_threads=480
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 272641 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
/glide/mysql/5.7.13/bin/mysqld(my_print_stacktrace+0x35)[0xf1a055]
/glide/mysql/5.7.13/bin/mysqld(handle_fatal_signal+0x4a4)[0x79c1b4]
/lib64/libpthread.so.0(+0xf7e0)[0x7f1bf8be97e0]
/lib64/libc.so.6(gsignal+0x35)[0x7f1bf7894625]
/lib64/libc.so.6(abort+0x175)[0x7f1bf7895e05]
/glide/mysql/5.7.13/bin/mysqld[0x10a6eb5]
/glide/mysql/5.7.13/bin/mysqld(_Z14os_aio_handlermPP10fil_node_tPPvP9IORequest+0xc70)[0xfb6e60]
/glide/mysql/5.7.13/bin/mysqld(_Z12fil_aio_waitm+0x38)[0x114cec8]
/glide/mysql/5.7.13/bin/mysqld(io_handler_thread+0xc8)[0x105aca8]
/lib64/libpthread.so.0(+0x7aa1)[0x7f1bf8be1aa1]
/lib64/libc.so.6(clone+0x6d)[0x7f1bf794a93d]
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.
2016-06-29T18:44:14.261831Z mysqld_safe Number of processes running now: 0
2016-06-29T18:44:14.264709Z mysqld_safe mysqld restarted
#4:
Version: '5.7.13-log' socket: '/tmp/mysqld.sock' port: 3306 MySQL Community Server (GPL)
2016-06-29T18:44:16.821121Z 0 [Warning] InnoDB: Retry attempts for writing partial data failed.
2016-06-29T18:44:16.821167Z 0 [ERROR] InnoDB: Write to file ./test/enctest.ibdfailed at offset 16384, 16384 bytes should have been written, only 0 were written. Operating system error number 22. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
2016-06-29T18:44:16.821188Z 0 [ERROR] InnoDB: Error number 22 means 'Invalid argument'
2016-06-29T18:44:16.821197Z 0 [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html
2016-06-29 11:44:16 0x7f76adbf5700 InnoDB: Assertion failure in thread 140147697866496 in file os0file.cc line 7702
InnoDB: Failing assertion: err == DB_SUCCESS || err == DB_IO_NO_PUNCH_HOLE
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
18:44:16 UTC - 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=83886080
read_buffer_size=131072
max_used_connections=0
max_threads=480
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 272641 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
/glide/mysql/5.7.13/bin/mysqld(my_print_stacktrace+0x35)[0xf1a055]
/glide/mysql/5.7.13/bin/mysqld(handle_fatal_signal+0x4a4)[0x79c1b4]
/lib64/libpthread.so.0(+0xf7e0)[0x7f77871c07e0]
/lib64/libc.so.6(gsignal+0x35)[0x7f7785e6b625]
/lib64/libc.so.6(abort+0x175)[0x7f7785e6ce05]
/glide/mysql/5.7.13/bin/mysqld[0x10a6eb5]
/glide/mysql/5.7.13/bin/mysqld(_Z14os_aio_handlermPP10fil_node_tPPvP9IORequest+0xc70)[0xfb6e60]
/glide/mysql/5.7.13/bin/mysqld(_Z12fil_aio_waitm+0x38)[0x114cec8]
/glide/mysql/5.7.13/bin/mysqld(io_handler_thread+0xc8)[0x105aca8]
/lib64/libpthread.so.0(+0x7aa1)[0x7f77871b8aa1]
/lib64/libc.so.6(clone+0x6d)[0x7f7785f2193d]
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.
2016-06-29T18:44:16.934023Z mysqld_safe Number of processes running now: 0
2016-06-29T18:44:16.936893Z mysqld_safe mysqld restarted
#5:
Version: '5.7.13-log' socket: '/tmp/mysqld.sock' port: 3306 MySQL Community Server (GPL)
2016-06-29T18:44:19.493526Z 0 [Warning] InnoDB: Retry attempts for writing partial data failed.
2016-06-29T18:44:19.493578Z 0 [ERROR] InnoDB: Write to file ./test/enc1.ibdfailed at offset 32768, 16384 bytes should have been written, only 0 were written. Operating system error number 22. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
2016-06-29T18:44:19.493603Z 0 [ERROR] InnoDB: Error number 22 means 'Invalid argument'
2016-06-29T18:44:19.493612Z 0 [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html
2016-06-29 11:44:19 0x7fd68f5fe700 InnoDB: Assertion failure in thread 140559505155840 in file os0file.cc line 7702
InnoDB: Failing assertion: err == DB_SUCCESS || err == DB_IO_NO_PUNCH_HOLE
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
18:44:19 UTC - 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=83886080
read_buffer_size=131072
max_used_connections=0
max_threads=480
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 272641 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
/glide/mysql/5.7.13/bin/mysqld(my_print_stacktrace+0x35)[0xf1a055]
/glide/mysql/5.7.13/bin/mysqld(handle_fatal_signal+0x4a4)[0x79c1b4]
/lib64/libpthread.so.0(+0xf7e0)[0x7fd76cd517e0]
/lib64/libc.so.6(gsignal+0x35)[0x7fd76b9fc625]
/lib64/libc.so.6(abort+0x175)[0x7fd76b9fde05]
/glide/mysql/5.7.13/bin/mysqld[0x10a6eb5]
/glide/mysql/5.7.13/bin/mysqld(_Z14os_aio_handlermPP10fil_node_tPPvP9IORequest+0xc70)[0xfb6e60]
/glide/mysql/5.7.13/bin/mysqld(_Z12fil_aio_waitm+0x38)[0x114cec8]
/glide/mysql/5.7.13/bin/mysqld(io_handler_thread+0xc8)[0x105aca8]
/lib64/libpthread.so.0(+0x7aa1)[0x7fd76cd49aa1]
/lib64/libc.so.6(clone+0x6d)[0x7fd76bab293d]
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.
2016-06-29T18:44:19.604656Z mysqld_safe Number of processes running now: 0
2016-06-29T18:44:19.607496Z mysqld_safe mysqld restarted
#6:
Version: '5.7.13-log' socket: '/tmp/mysqld.sock' port: 3306 MySQL Community Server (GPL)
2016-06-29T18:44:22.156469Z 0 [Warning] InnoDB: Retry attempts for writing partial data failed.
2016-06-29T18:44:22.156534Z 0 [ERROR] InnoDB: Write to file ./test/enctest.ibdfailed at offset 32768, 16384 bytes should have been written, only 0 were written. Operating system error number 22. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
2016-06-29T18:44:22.156557Z 0 [ERROR] InnoDB: Error number 22 means 'Invalid argument'
2016-06-29T18:44:22.156567Z 0 [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html
2016-06-29 11:44:22 0x7f0b1e1fc700 InnoDB: Assertion failure in thread 139685726766848 in file os0file.cc line 7702
InnoDB: Failing assertion: err == DB_SUCCESS || err == DB_IO_NO_PUNCH_HOLE
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
18:44:22 UTC - 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=83886080
read_buffer_size=131072
max_used_connections=0
max_threads=480
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 272641 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
/glide/mysql/5.7.13/bin/mysqld(my_print_stacktrace+0x35)[0xf1a055]
/glide/mysql/5.7.13/bin/mysqld(handle_fatal_signal+0x4a4)[0x79c1b4]
/lib64/libpthread.so.0(+0xf7e0)[0x7f0bfca587e0]
/lib64/libc.so.6(gsignal+0x35)[0x7f0bfb703625]
/lib64/libc.so.6(abort+0x175)[0x7f0bfb704e05]
/glide/mysql/5.7.13/bin/mysqld[0x10a6eb5]
/glide/mysql/5.7.13/bin/mysqld(_Z14os_aio_handlermPP10fil_node_tPPvP9IORequest+0xc70)[0xfb6e60]
/glide/mysql/5.7.13/bin/mysqld(_Z12fil_aio_waitm+0x38)[0x114cec8]
/glide/mysql/5.7.13/bin/mysqld(io_handler_thread+0xc8)[0x105aca8]
/lib64/libpthread.so.0(+0x7aa1)[0x7f0bfca50aa1]
/lib64/libc.so.6(clone+0x6d)[0x7f0bfb7b993d]
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.
2016-06-29T18:44:22.268208Z mysqld_safe Number of processes running now: 0
2016-06-29T18:44:22.271117Z mysqld_safe mysqld restarted
...