Assertion during shutdown if lru restore is in progress

[Bill Karwin]

Reported against Percona Server 5.5.16-rel22.0 revision 189.

Percona Server gets an assertion if you try to do a shutdown while it's restoring the buffer pool from a saved lru dump.

Here are the steps to reproduce the issue.

----------------
Step 1: Enable automatic lru dump/restore in my.cnf:

innodb_buffer_pool_restore_at_startup = 1

----------------
Step 2: Start mysqld, to get lru dump going.

----------------
Step 3: Restart mysqld, so it begins restoring the buffer pool. See the notice in the error log:

120223 15:56:37 InnoDB: Restoring buffer pool pages from ib_lru_dump

----------------
Step 4: Stop mysqld again while the restore is working. See the assertion about pending I/O in the error log, and an intentional memory trap in the error log:

120223 15:59:06 InnoDB: Starting shutdown...
120223 15:59:21 InnoDB: Assertion failure in thread 1248631104 in file fil0fil.c line 867
InnoDB: Failing assertion: node->n_pending == 0 || node->space->is_being_deleted
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.
120223 15:59:21 - 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.
key_buffer_size=15032385536
read_buffer_size=131072
max_used_connections=2
max_threads=200
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 = 15117656 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 = (nil) thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x39)[0x7ce749]
/usr/sbin/mysqld(handle_segfault+0x379)[0x500de9]
/lib64/libpthread.so.0[0x3bd760eb10]
/lib64/libc.so.6(gsignal+0x35)[0x3bd6e30265]
/lib64/libc.so.6(abort+0x110)[0x3bd6e31d10]
/usr/sbin/mysqld[0x8e844b]
/usr/sbin/mysqld[0x8ec051]
/usr/sbin/mysqld[0x929564]
/usr/sbin/mysqld[0x86a108]
/usr/sbin/mysqld[0x830714]
/usr/sbin/mysqld(_Z22ha_finalize_handlertonP13st_plugin_int+0x2c)[0x68dacc]
/usr/sbin/mysqld[0x581f4b]
/usr/sbin/mysqld[0x5849fe]
/usr/sbin/mysqld(_Z15plugin_shutdownv+0xd3)[0x586533]
/usr/sbin/mysqld[0x504b7f]
/usr/sbin/mysqld(_Z10unireg_endv+0xe)[0x508ece]
/usr/sbin/mysqld(kill_server_thread+0x873)[0x509753]
/lib64/libpthread.so.0[0x3bd760673d]
/lib64/libc.so.6(clone+0x6d)[0x3bd6ed3f6d]
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.

This causes mysqld_safe to restart the server.

----------------
Step 5: Wait until the lru restore is finished. See report in error log:

120223 18:28:49 InnoDB: Completed reading buffer pool pages (requested: 3840295, read: 3839769)

----------------
Step 6: Now stop mysqld. See it terminate cleanly:

120223 18:30:11 [Note] /usr/sbin/mysqld: Normal shutdown
120223 18:30:11 [Note] Event Scheduler: Purging the queue. 0 events
120223 18:30:11 InnoDB: Starting shutdown...
120223 18:30:43 InnoDB: Shutdown completed; log sequence number 574342454727
120223 18:30:43 [Note] /usr/sbin/mysqld: Shutdown complete
120223 18:30:44 mysqld_safe mysqld from pid file /mysqldb/data/mysql.pid ended

If innodb_buffer_pool_restore_at_startup=0 or is commented out, the notice about restoring ib_lru_dump does not appear in the error log, and if we stop mysqld, the assertion does not occur.

[Shahriyar Rzayev (rzayev-sehriyar)]

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