Bug #69000 Assert when innodb_log_group_home_dir does not exist
Submitted: 18 Apr 2013 19:46 Modified: 16 Aug 2013 12:52
Reporter: Roel Van de Paar (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:5.6.11 OS:Any
Assigned to: CPU Architecture:Any
Triage: Needs Triage: D2 (Serious)

[18 Apr 2013 19:46] Roel Van de Paar
Description:
========== Debug output
2013-04-18 12:37:45 5826 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created!
2013-04-18 12:37:45 5826 [Note] InnoDB: Setting file ./ibdata1 size to 12 MB
2013-04-18 12:37:45 5826 [Note] InnoDB: Database physically writes the file full: wait...
2013-04-18 12:37:45 7fdde4e69720  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.
2013-04-18 12:37:45 7fdde4e69720  InnoDB: File name /tmp/vardir2/master-data/ib_logfile101
2013-04-18 12:37:45 7fdde4e69720  InnoDB: File operation call: 'create' returned OS error 71.
2013-04-18 12:37:45 7fdde4e69720  InnoDB: Cannot continue operation.
2013-04-18 12:37:45 7fdde4e69720  InnoDB: Assertion failure in thread 140591004817184 in file os0file.cc line 662
InnoDB: Failing assertion: 0

========== Optimized output
2013-04-18 11:13:57 7febed77e720  InnoDB: File name /tmp/vardir2/master-data/ib_logfile101
2013-04-18 11:13:57 7febed77e720  InnoDB: File operation call: 'create' returned OS error 71.
2013-04-18 11:13:57 7febed77e720  InnoDB: Cannot continue operation.

========== GDB
(gdb) bt
#0  0x00007fdde4a4b69c in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000a8a8df in my_write_core (sig=6) at /ssd/mysql-5.6.11/mysys/stacktrace.c:422
#2  0x0000000000722e7f in handle_fatal_signal (sig=6) at /ssd/mysql-5.6.11/sql/signal_handler.cc:248
#3  <signal handler called>
#4  0x00007fdde36fa8a5 in raise () from /lib64/libc.so.6
#5  0x00007fdde36fc085 in abort () from /lib64/libc.so.6
#6  0x0000000000b7cee2 in os_file_handle_error_cond_exit (name=0x7fff57679780 "/tmp/vardir2/master-data/ib_logfile101", operation=0xff2542 "create", should_exit=1, on_error_silent=0) at /ssd/mysql-5.6.11/storage/innobase/os/os0file.cc:662
#7  0x0000000000b7cf17 in os_file_handle_error (name=0x7fff57679780 "/tmp/vardir2/master-data/ib_logfile101", operation=0xff2542 "create") at /ssd/mysql-5.6.11/storage/innobase/os/os0file.cc:681
#8  0x0000000000b7dccb in os_file_create_func (name=0x7fff57679780 "/tmp/vardir2/master-data/ib_logfile101", create_mode=52, purpose=62, type=101, success=0x7fff576796e8) at /ssd/mysql-5.6.11/storage/innobase/os/os0file.cc:1741
#9  0x0000000000c469f7 in pfs_os_file_create_func (key=45, name=0x7fff57679780 "/tmp/vardir2/master-data/ib_logfile101", create_mode=52, purpose=62, type=101, success=0x7fff576796e8, src_file=0x101c898 "/ssd/mysql-5.6.11/storage/innobase/srv/srv0start.cc", src_line=525) at /ssd/mysql-5.6.11/storage/innobase/include/os0file.ic:151
#10 0x0000000000c47f35 in create_log_file (file=0x17ed9e0, name=0x7fff57679780 "/tmp/vardir2/master-data/ib_logfile101") at /ssd/mysql-5.6.11/storage/innobase/srv/srv0start.cc:525
#11 0x0000000000c48209 in create_log_files (logfilename=0x7fff57679780 "/tmp/vardir2/master-data/ib_logfile101", dirnamelen=25, lsn=8204, logfile0=@0x7fff5767d338) at /ssd/mysql-5.6.11/storage/innobase/srv/srv0start.cc:607
#12 0x0000000000c4ab39 in innobase_start_or_create_for_mysql () at /ssd/mysql-5.6.11/storage/innobase/srv/srv0start.cc:2008
#13 0x0000000000b024c1 in innobase_init (p=0x1cfaac0) at /ssd/mysql-5.6.11/storage/innobase/handler/ha_innodb.cc:3235
#14 0x000000000063288c in ha_initialize_handlerton (plugin=0x1cf77b8) at /ssd/mysql-5.6.11/sql/handler.cc:659
#15 0x00000000007dd6b1 in plugin_initialize (plugin=0x1cf77b8) at /ssd/mysql-5.6.11/sql/sql_plugin.cc:1126
#16 0x00000000007de101 in plugin_init (argc=0x17b1808, argv=0x1b89a40, flags=0) at /ssd/mysql-5.6.11/sql/sql_plugin.cc:1417
#17 0x000000000061ed63 in init_server_components () at /ssd/mysql-5.6.11/sql/mysqld.cc:4804
#18 0x000000000061fbec in mysqld_main (argc=6, argv=0x1b89a40) at /ssd/mysql-5.6.11/sql/mysqld.cc:5385
#19 0x0000000000615474 in main (argc=6, argv=0x7fff5767dd18) at /ssd/mysql-5.6.11/sql/main.cc:25

How to repeat:
rm -Rf /tmp/vardir2
mkdir /tmp/vardir2
./mysqld --no-defaults --basedir=/mysql-5.6.11/ --datadir
=/tmp/vardir2 --innodb_log_group_home_dir=/tmp/vardir2/master-data --core

Suggested fix:
Provide better output (the problem is that the directory does not exist), and don't assert on '0'.
[18 Apr 2013 19:46] Roel Van de Paar
Error log

Attachment: 18-4-13_err.txt (text/plain), 4.78 KiB.

[18 Apr 2013 19:47] Roel Van de Paar
thread apply all bt on core

Attachment: 18-4-13_gdb.txt (text/plain), 10.59 KiB.

[18 Apr 2013 19:47] Roel Van de Paar
thread apply all bt FULL on core

Attachment: 18-4-13_gdb-full.txt (text/plain), 33.44 KiB.

[19 Apr 2013 8:07] Umesh Shastry
Hello Roel,

Thank you for the report.
Verified as described.

Thanks,
Umesh
[19 Apr 2013 8:08] Umesh Shastry
(gdb) bt
#0  0x000000328280c69c in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000a8a6e3 in my_write_core (sig=6) at /home/ushastry/mybuilds/mysql-5.6.11-release/mysys/stacktrace.c:422
#2  0x0000000000722d29 in handle_fatal_signal (sig=6) at /home/ushastry/mybuilds/mysql-5.6.11-release/sql/signal_handler.cc:248
#3  <signal handler called>
#4  0x0000003281c329a5 in raise () from /lib64/libc.so.6
#5  0x0000003281c34185 in abort () from /lib64/libc.so.6
#6  0x0000000000b83ef8 in os_file_handle_error_cond_exit (name=0x7fffd28b1780 "/tmp/5611/master-data/ib_logfile101", operation=0xff96f2 "create", should_exit=1, 
    on_error_silent=0) at /home/ushastry/mybuilds/mysql-5.6.11-release/storage/innobase/os/os0file.cc:662
#7  0x0000000000b83f2d in os_file_handle_error (name=0x7fffd28b1780 "/tmp/5611/master-data/ib_logfile101", operation=0xff96f2 "create")
    at /home/ushastry/mybuilds/mysql-5.6.11-release/storage/innobase/os/os0file.cc:681
#8  0x0000000000b84ce1 in os_file_create_func (name=0x7fffd28b1780 "/tmp/5611/master-data/ib_logfile101", create_mode=52, purpose=62, type=101, success=0x7fffd28b16e8)
    at /home/ushastry/mybuilds/mysql-5.6.11-release/storage/innobase/os/os0file.cc:1741
#9  0x0000000000c4c973 in pfs_os_file_create_func (key=45, name=0x7fffd28b1780 "/tmp/5611/master-data/ib_logfile101", create_mode=52, purpose=62, type=101, 
    success=0x7fffd28b16e8, src_file=0x1025d68 "/home/ushastry/mybuilds/mysql-5.6.11-release/storage/innobase/srv/srv0start.cc", src_line=525)
    at /home/ushastry/mybuilds/mysql-5.6.11-release/storage/innobase/include/os0file.ic:151
#10 0x0000000000c4deb1 in create_log_file (file=0x17fa620, name=0x7fffd28b1780 "/tmp/5611/master-data/ib_logfile101")
    at /home/ushastry/mybuilds/mysql-5.6.11-release/storage/innobase/srv/srv0start.cc:525
#11 0x0000000000c4e185 in create_log_files (logfilename=0x7fffd28b1780 "/tmp/5611/master-data/ib_logfile101", dirnamelen=22, lsn=1625987, logfile0=@0x7fffd28b5338)
    at /home/ushastry/mybuilds/mysql-5.6.11-release/storage/innobase/srv/srv0start.cc:607
#12 0x0000000000c50b8a in innobase_start_or_create_for_mysql () at /home/ushastry/mybuilds/mysql-5.6.11-release/storage/innobase/srv/srv0start.cc:2053
#13 0x0000000000b0961d in innobase_init (p=0x3597e10) at /home/ushastry/mybuilds/mysql-5.6.11-release/storage/innobase/handler/ha_innodb.cc:3235
#14 0x0000000000632750 in ha_initialize_handlerton (plugin=0x358ce20) at /home/ushastry/mybuilds/mysql-5.6.11-release/sql/handler.cc:659
#15 0x00000000007dd500 in plugin_initialize (plugin=0x358ce20) at /home/ushastry/mybuilds/mysql-5.6.11-release/sql/sql_plugin.cc:1126
#16 0x00000000007ddf54 in plugin_init (argc=0x17be348, argv=0x3410f28, flags=0) at /home/ushastry/mybuilds/mysql-5.6.11-release/sql/sql_plugin.cc:1417
#17 0x000000000061ec23 in init_server_components () at /home/ushastry/mybuilds/mysql-5.6.11-release/sql/mysqld.cc:4804
#18 0x000000000061faac in mysqld_main (argc=21, argv=0x3410f28) at /home/ushastry/mybuilds/mysql-5.6.11-release/sql/mysqld.cc:5385
#19 0x0000000000615334 in main (argc=10, argv=0x7fffd28b5d18) at /home/ushastry/mybuilds/mysql-5.6.11-release/sql/main.cc:2
[19 Apr 2013 8:10] Umesh Shastry
thread apply all bt on core

Attachment: 69000.txt (text/plain), 17.27 KiB.

[22 Apr 2013 18:08] Roel Van de Paar
Hi Umesh, D4 for a crash?
[16 Aug 2013 12:52] Bugs System
Noted in 5.6.14, 5.7.2 changelogs:

"In debug builds, an assertion failure would occur if
"innodb_log_group_home_dir" does not exist. Instead of an assertion,
"InnoDB" now aborts with an error message if "innodb_log_group_home_dir"
does not exist."

Thank you for the bug report.