RENAME/DROP crashes with innodb_track_changed_pages
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Percona Server moved to https://jira.percona.com/projects/PS |
Fix Released
|
Critical
|
Laurynas Biveinis | ||
5.1 |
Fix Released
|
Critical
|
Laurynas Biveinis | ||
5.5 |
Fix Released
|
Critical
|
Laurynas Biveinis | ||
5.6 |
Fix Released
|
Critical
|
Laurynas Biveinis |
Bug Description
The redo log reading code has been chaned in 5.5.30 with
http://
Part of the change is that on MLOG_FILE_RENAME events the
recv_parse_
also applys the rename operation.
This can lead to InnoDB assertion failures if:
* innodb_
* a table is renamed
* and is dropped shortly after
The assertion messages are:
InnoDB: Error: cannot find space id ### in the tablespace memory cache
InnoDB: though the table '(name not specified)' in a rename operation should have that id
InnoDB: Assertion failure in thread ### in file fil0fil.c line 2248
The related backtrace looks like this:
??:0(
??:0(
??:0(
??:0(
??:0(
??:0(
??:0(
??:0(
??:0(
??:0(
??:0(
??:0(
The important part of the InnoDB change is:
+ case MLOG_FILE_RENAME:
+ ptr = fil_op_
+ space_id, 0);
+ break;
case MLOG_FILE_CREATE:
- case MLOG_FILE_RENAME:
case MLOG_FILE_DELETE:
case MLOG_FILE_CREATE2:
ptr = fil_op_
which causes MLOG_FILE_RENAME events to be replayed when
the page change cache parses the logs. Now what can happen is
that a table gets renamed and then dropped shortly afterwards.
As the page change tracking thread reads the redo log with a
slight delay it may only end up reaching the RENAME event at
about the time when the DROP happens.
Now if this happens at just the "right" time then
fil_op_
fil_tablespace_
exists, then check for fil_get_
right after it has been dropped, and comes to the wrong
conclusion that the rename has not happened yet and
needs to be recovered/redone. Then next it tries
fil_rename_
table no longer exists and eventually the
cannot find space id ### in the tablespace memory cache
assertion is raised.
So actually a bug introduced by Oracle, but I'm reporting it
here only for now as it only affects the Percona page change
feature but has probably no negative effect on upstream
MySQL itself as the log parsing code is only used for crash
recovery or ibbackup postprocessing and never has to deal
with other DB activity going on in parallel ...
Related branches
- Alexey Kopytov (community): Approve
-
Diff: 308 lines (+173/-7)9 files modifiedPercona-Server/mysql-test/r/percona_server_variables_debug.result (+2/-0)
Percona-Server/mysql-test/suite/innodb_plugin/r/percona_changed_page_bmp_debug.result (+14/-0)
Percona-Server/mysql-test/suite/innodb_plugin/t/percona_changed_page_bmp_debug-master.opt (+1/-1)
Percona-Server/mysql-test/suite/innodb_plugin/t/percona_changed_page_bmp_debug.test (+46/-0)
Percona-Server/storage/innodb_plugin/fil/fil0fil.c (+5/-0)
Percona-Server/storage/innodb_plugin/handler/ha_innodb.cc (+80/-3)
Percona-Server/storage/innodb_plugin/log/log0recv.c (+2/-1)
Percona-Server/storage/innodb_plugin/row/row0merge.c (+17/-2)
Percona-Server/storage/innodb_plugin/srv/srv0srv.c (+6/-0)
- Alexey Kopytov (community): Approve
-
Diff: 547 lines (+381/-7)14 files modifiedPercona-Server/mysql-test/r/percona_server_variables_debug.result (+2/-0)
Percona-Server/mysql-test/suite/innodb/r/percona_changed_page_bmp_debug.result (+14/-0)
Percona-Server/mysql-test/suite/innodb/t/percona_changed_page_bmp_debug-master.opt (+1/-1)
Percona-Server/mysql-test/suite/innodb/t/percona_changed_page_bmp_debug.test (+46/-0)
Percona-Server/mysql-test/suite/sys_vars/r/innodb_log_checkpoint_now_basic.result (+79/-0)
Percona-Server/mysql-test/suite/sys_vars/r/innodb_track_redo_log_now_basic.result (+28/-0)
Percona-Server/mysql-test/suite/sys_vars/t/innodb_log_checkpoint_now_basic.test (+68/-0)
Percona-Server/mysql-test/suite/sys_vars/t/innodb_track_changed_pages_basic.test (+1/-0)
Percona-Server/mysql-test/suite/sys_vars/t/innodb_track_redo_log_now_basic.test (+27/-0)
Percona-Server/storage/innobase/fil/fil0fil.c (+5/-0)
Percona-Server/storage/innobase/handler/ha_innodb.cc (+85/-3)
Percona-Server/storage/innobase/log/log0recv.c (+2/-1)
Percona-Server/storage/innobase/row/row0merge.c (+17/-2)
Percona-Server/storage/innobase/srv/srv0srv.c (+6/-0)
- Alexey Kopytov (community): Approve
-
Diff: 322 lines (+178/-6)11 files modifiedPercona-Server/mysql-test/suite/innodb/r/percona_changed_page_bmp_debug.result (+14/-0)
Percona-Server/mysql-test/suite/innodb/t/percona_changed_page_bmp_debug-master.opt (+1/-1)
Percona-Server/mysql-test/suite/innodb/t/percona_changed_page_bmp_debug.test (+50/-0)
Percona-Server/mysql-test/suite/sys_vars/r/innodb_track_redo_log_now_basic.result (+28/-0)
Percona-Server/mysql-test/suite/sys_vars/t/innodb_track_changed_pages_basic.test (+1/-0)
Percona-Server/mysql-test/suite/sys_vars/t/innodb_track_redo_log_now_basic.test (+27/-0)
Percona-Server/storage/innobase/fil/fil0fil.cc (+5/-0)
Percona-Server/storage/innobase/handler/ha_innodb.cc (+42/-4)
Percona-Server/storage/innobase/handler/handler0alter.cc (+2/-0)
Percona-Server/storage/innobase/log/log0recv.cc (+2/-1)
Percona-Server/storage/innobase/srv/srv0srv.cc (+6/-0)
summary: |
- RENAME/DROP crashes 5.5.30+ with innodb_track_changed_pages + RENAME/DROP crashes with innodb_track_changed_pages |
Hartmut -
Thank you for the bug report and the detailed analysis. Indeed we did not take into account this upstream change. But I'm not sure if there's a serious upstream bug to be found, the only thing I can think of is that recv_parse_ or_apply_ log_rec_ body() header comment "File ops are parsed, but not applied in this function." is not true anymore.