Description:
The test innodb.log_file can occasionally crash due to an error in the startup error handling.
One of the failures I analyzed in test step 12:
--echo # 12. With ibdata*, without ib_logfile2
--remove_file $bugdir/ib_logfile2
--list_files $bugdir
--error 1
--exec $MYSQLD $args
let SEARCH_PATTERN=Resizing redo log from \d+\*\d+ to \d+\*\d+ pages, LSN=\d+;
--source include/search_pattern_in_file.inc
The exec line would return 139, also known as 128+SIGABRT, due to an assertion failure somewhere when GNU libc tried to complain about memory corruption deep down the stack in:
#16 0x0000000001b2141d in SyncDebug::~SyncDebug (this=0x2bc6b00 <syncDebug>,
__in_chrg=<optimized out>)
at storage/innobase/sync/sync0debug.cc:230
#17 0x00007f321e299bc9 in __run_exit_handlers (status=1,
listp=0x7f321e6055a8 <__exit_funcs>,
run_list_atexit=run_list_atexit@entry=true) at exit.c:82
#18 0x00007f321e299c15 in __GI_exit (status=<optimized out>) at exit.c:104
#19 0x0000000000f52d00 in mysqld_main (argc=13, argv=0x3cc2360)
at sql/mysqld.cc:4923
#20 0x0000000000f4a976 in main (argc=8, argv=0x7ffc100cf378)
At this point, all the InnoDB threads were active.
InnoDB should have been shut down before calling exit().
See also Bug#19442959 which is caused by unacceptable exit() calls from InnoDB itself.
The root cause for this abort seems to be ER_NO_SUCH_TABLE for some table, observed in the file my_restart.err that was created by the test step:
2015-03-30T12:45:56.767495Z 0 [Note] InnoDB: 5.8.0 started; log sequence number 62671
2015-03-30T12:45:56.768336Z 0 [Note] Plugin 'FEDERATED' is disabled.
mysqld: Unknown error 1146
2015-03-30T12:45:56.768668Z 0 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it.
and then
2015-03-30T12:45:56.771466Z 0 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/t/mysql-test/var/2/tmp/log_file/ib_buffer_pool
2015-03-30T12:45:56.771511Z 0 [ERROR] Fatal error: Can't open and lock privilege tables: Unknown error 1146
12:45:56 UTC - mysqld got signal 6 ;
How to repeat:
./mtr --parallel=auto --repeat=10 innodb.log_file{,,,}
Depending on luck, you will see some messages like this:
innodb.log_file w3 [ pass ] 16921
*** Error in `/dev/shm/t/sql/mysqld': double free or corruption (fasttop): 0x00007f34c0000b70 ***
innodb.log_file w4 [ pass ] 16747
Or you will see an actual crash like this:
CURRENT_TEST: innodb.log_file
mysqltest: At line 236: command "$MYSQLD $args" failed with wrong error: 134
The compilation options
cmake -DWITH_{DEBUG,ASAN}:BOOL=ON
and gcc 4.9.2
did not seem to improve the chances of failure.
It might be better to use
cmake -DWITH_{DEBUG,ASAN}:BOOL=OFF
Suggested fix:
Try to shut down plugins before calling exit(), because plugins may invoke atexit() to install handlers that assume that plugin shutdown has been invoked.
Description: The test innodb.log_file can occasionally crash due to an error in the startup error handling. One of the failures I analyzed in test step 12: --echo # 12. With ibdata*, without ib_logfile2 --remove_file $bugdir/ib_logfile2 --list_files $bugdir --error 1 --exec $MYSQLD $args let SEARCH_PATTERN=Resizing redo log from \d+\*\d+ to \d+\*\d+ pages, LSN=\d+; --source include/search_pattern_in_file.inc The exec line would return 139, also known as 128+SIGABRT, due to an assertion failure somewhere when GNU libc tried to complain about memory corruption deep down the stack in: #16 0x0000000001b2141d in SyncDebug::~SyncDebug (this=0x2bc6b00 <syncDebug>, __in_chrg=<optimized out>) at storage/innobase/sync/sync0debug.cc:230 #17 0x00007f321e299bc9 in __run_exit_handlers (status=1, listp=0x7f321e6055a8 <__exit_funcs>, run_list_atexit=run_list_atexit@entry=true) at exit.c:82 #18 0x00007f321e299c15 in __GI_exit (status=<optimized out>) at exit.c:104 #19 0x0000000000f52d00 in mysqld_main (argc=13, argv=0x3cc2360) at sql/mysqld.cc:4923 #20 0x0000000000f4a976 in main (argc=8, argv=0x7ffc100cf378) At this point, all the InnoDB threads were active. InnoDB should have been shut down before calling exit(). See also Bug#19442959 which is caused by unacceptable exit() calls from InnoDB itself. The root cause for this abort seems to be ER_NO_SUCH_TABLE for some table, observed in the file my_restart.err that was created by the test step: 2015-03-30T12:45:56.767495Z 0 [Note] InnoDB: 5.8.0 started; log sequence number 62671 2015-03-30T12:45:56.768336Z 0 [Note] Plugin 'FEDERATED' is disabled. mysqld: Unknown error 1146 2015-03-30T12:45:56.768668Z 0 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it. and then 2015-03-30T12:45:56.771466Z 0 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/t/mysql-test/var/2/tmp/log_file/ib_buffer_pool 2015-03-30T12:45:56.771511Z 0 [ERROR] Fatal error: Can't open and lock privilege tables: Unknown error 1146 12:45:56 UTC - mysqld got signal 6 ; How to repeat: ./mtr --parallel=auto --repeat=10 innodb.log_file{,,,} Depending on luck, you will see some messages like this: innodb.log_file w3 [ pass ] 16921 *** Error in `/dev/shm/t/sql/mysqld': double free or corruption (fasttop): 0x00007f34c0000b70 *** innodb.log_file w4 [ pass ] 16747 Or you will see an actual crash like this: CURRENT_TEST: innodb.log_file mysqltest: At line 236: command "$MYSQLD $args" failed with wrong error: 134 The compilation options cmake -DWITH_{DEBUG,ASAN}:BOOL=ON and gcc 4.9.2 did not seem to improve the chances of failure. It might be better to use cmake -DWITH_{DEBUG,ASAN}:BOOL=OFF Suggested fix: Try to shut down plugins before calling exit(), because plugins may invoke atexit() to install handlers that assume that plugin shutdown has been invoked.