mysqld crash on ALL_O_DIRECT

[Jay Janssen]

I was resizing the log files, but it turned out that was unrelated. I can reliably crash mysqld on startup if I set innodb_flush_method=ALL_O_DIRECT. I was able to get the server started with just O_DIRECT.

120823 12:46:25 InnoDB: Log file ./ib_logfile0 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile0 size to 2048 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000 1100 1200 1300 1400 1500 1600 1700 1800 1900 2000
120823 12:46:28 InnoDB: Log file ./ib_logfile1 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile1 size to 2048 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000 1100 1200 1300 1400 1500 1600 1700 1800 1900 2000
120823 12:46:30 InnoDB: Error: Write to file ./ib_logfile0 failed at offset 0 0.
InnoDB: 512 bytes should have been written, only 0 were written.
InnoDB: Operating system error number 22.
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 22 means 'Invalid argument'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.5/en/operating-system-error-codes.html
120823 12:46:30 InnoDB: Assertion failure in thread 47989575833504 in file fil0fil.c line 5424
InnoDB: Failing assertion: ret
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.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
17:46:30 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.
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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

key_buffer_size=67108864
read_buffer_size=1048576
max_used_connections=0
max_threads=3000
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 = 6246309 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
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x7d6755]
/usr/sbin/mysqld(handle_fatal_signal+0x3e1)[0x693621]
/lib64/libpthread.so.0[0x3fb840eb10]
/lib64/libc.so.6(gsignal+0x35)[0x3fb7830265]
/lib64/libc.so.6(abort+0x110)[0x3fb7831d10]
/usr/sbin/mysqld[0x8abad4]
/usr/sbin/mysqld[0x8e0099]
/usr/sbin/mysqld[0x8e23ea]
/usr/sbin/mysqld[0x8e288e]
/usr/sbin/mysqld[0x8e2da4]
/usr/sbin/mysqld[0x8e5ad6]
/usr/sbin/mysqld[0x824a42]
/usr/sbin/mysqld[0x7e64e3]
/usr/sbin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x46)[0x6955c6]
/usr/sbin/mysqld[0x58828c]
/usr/sbin/mysqld(_Z11plugin_initPiPPci+0xc8d)[0x58aded]
/usr/sbin/mysqld[0x5068f8]
/usr/sbin/mysqld(_Z11mysqld_mainiPPc+0xa25)[0x509665]
/lib64/libc.so.6(__libc_start_main+0xf4)[0x3fb781d994]
/usr/sbin/mysqld[0x500299]

The filesystem was not full, and I did not see any obvious errors in dmesg.

File system is:

/dev/mapper/storage-mysql on /mnt/mysql-lvm type xfs (rw,noatime,nobarrier,nouuid)

This is PS 5.5.25a-27.1-log

# uname -a
Linux xxxxxxxxx 2.6.18-238.40.1.el5 #1 SMP Thu Jun 28 07:33:25 EDT 2012 x86_64 x86_64 x86_64 GNU/Linux

[Raghavendra D Prabhu (raghavendra-prabhu)]

I tested with latest XFS (on 3.x kernel), didn't see the crash. I think on older kernels (or on unsupported fs) unaligned AIO DIO (AIO is used to init the logs) returned EINVAL when it wasn't supported, may be because unaligned DIO can cause data corruption (unless handled by fs correctly). Hence on latter kernels, a 'fix' was introduced which serializes all the unaligned writes -- https://bugzilla.redhat.com/show_bug.cgi?id=669272 and http://lists.openwall.net/linux-ext4/2011/01/14/7 which introduced certain performance penalties.

Related discussion here http://nginx.2469901.n2.nabble.com/nginx-0-8-11-td3534858.html in context of nginx and how it is handled there.

As far as Percona Server is concerned, as commented here https://bugs.launchpad.net/percona-server/+bug/1033051/comments/1 one can workaround this by setting innodb-log-block-size to 4096 (which is the default fs block size but can be rechecked on fusion-io etc.)

Also, related MPB post http://www.mysqlperformanceblog.com/2011/01/03/effect-from-innodb-log-block-size-4096-bytes/ about innodb-log-block-size 4096 and SSDs.

[Raghavendra D Prabhu (raghavendra-prabhu)]

Marking this as a duplicate of 1033051 wherein documentation may need to added with ALL_O_DIRECT and block sizes. (and innodb-log-block-size).