Combination of log archiving, log tracking, and small logs hangs the server on the bootstrap shutdown

[Laurynas Biveinis]

$ rm -rf tmp && mkdir tmp
$ ./bin/mysqld --no-defaults --bootstrap --basedir=. --datadir=./tmp --tmpdir=. --lc-messages-dir=./share --character-sets-dir=./share/charsets --innodb_log_archive=1 --innodb_log_block_size=4096 --innodb_log_file_size=1048576 --innodb_track_changed_pages=1 < /dev/null

results in the last log message printed

2014-06-04 16:25:07 3852 [Note] InnoDB: Starting shutdown...

and infinite loop in logs_empty_and_mark_files_at_shutdown:

(gdb) bt
#0 0x00007f1e7e104c33 in select () at ../sysdeps/unix/syscall-template.S:81
#1 0x00000000009630ef in os_thread_sleep (tm=tm@entry=100000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/storage/innobase/os/os0thread.cc:282
#2 0x0000000000947c9e in logs_empty_and_mark_files_at_shutdown ()
    at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/storage/innobase/log/log0log.cc:3408
#3 0x00000000009cddcf in innobase_shutdown_for_mysql () at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/storage/innobase/srv/srv0start.cc:2974
#4 0x00000000008fb806 in innobase_end (hton=<optimized out>, type=<optimized out>)
    at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/storage/innobase/handler/ha_innodb.cc:3795
#5 0x00000000005bb48c in ha_finalize_handlerton (plugin=0x21982d0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/sql/handler.cc:641
#6 0x0000000000706e87 in plugin_deinitialize (ref_check=true, plugin=0x21982d0)
    at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/sql/sql_plugin.cc:937
#7 reap_plugins () at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/sql/sql_plugin.cc:1015
#8 0x00000000007083d0 in plugin_shutdown () at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/sql/sql_plugin.cc:1700
#9 0x00000000005ae9d8 in clean_up (print_message=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/sql/mysqld.cc:1917
#10 0x00000000005b0266 in clean_up (print_message=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/sql/mysqld.cc:1803
#11 unireg_abort (exit_code=0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/sql/mysqld.cc:1803
#12 0x00000000005b6bab in mysqld_main (argc=12, argv=0x213edd8) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos5-64/percona-server-5.6.17-66.0/sql/mysqld.cc:5778
#13 0x00007f1e7e033ec5 in __libc_start_main (main=0x591ff0 <main(int, char**)>, argc=12, argv=0x7fffdaf9ed38, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>,
    stack_end=0x7fffdaf9ed28) at libc-start.c:287
#14 0x00000000005a7f8d in _start ()

[Laurynas Biveinis (laurynas-biveinis)]

A very unlikely combination for end users, but a boundary condition hit by RQG tests.

[Laurynas Biveinis (laurynas-biveinis)]

MTR version of the testcase

let $MYSQLD_DATADIR= `select @@datadir`;

mkdir $MYSQLTEST_VARDIR/tmpdatadir;

--write_file $MYSQLTEST_VARDIR/tmp/bootstrap_test.sql
EOF

--echo Running mysqld --bootstrap --innodb-log-archive=1 --innodb-log-block-size=4096 --innodb-log-file-size=1048576 --innodb-track-changed-pages=1
--exec $MYSQLD_BOOTSTRAP_CMD --innodb-log-group-home-dir=$MYSQLTEST_VARDIR/tmpdatadir --innodb-log-archive=1 --innodb-log-block-size=4096 --innodb-log-file-size=1048576 --innodb-track-changed-pages=1 < $MYSQLTEST_VARDIR/tmp/bootstrap_test.sql
remove_file $MYSQLTEST_VARDIR/tmp/bootstrap_test.sql;
remove_files_wildcard $MYSQLTEST_VARDIR/tmpdatadir;
rmdir $MYSQLTEST_VARDIR/tmpdatadir;

[Laurynas Biveinis (laurynas-biveinis)]

Happens with the default log block size too, although less frequently.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-1510