Bug #66718 Assert from DROP TABLE concurrent with ibuf merges
Submitted: 6 Sep 2012 4:23 Modified: 18 Oct 2012 19:21
Reporter: Mark Callaghan Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB Plugin storage engine Severity:S3 (Non-critical)
Version:5.1, 5.5 OS:Any
Assigned to: CPU Architecture:Any

[6 Sep 2012 4:23] Mark Callaghan
Description:
I can reproduce this with 5.1 + Facebook patch and 5.5 latest (no facebook patch)

innodb_file_per_table must be used

The crash occurs when there is a pending read in fil_io that has called fil_node_prepare_for_io so that n_pending is > 0 for tablespace T. Before it decrements n_pending, a thread in fil_delete_tablespace must call fil_space_free which then calls fil_node_free which then fails on the assert "node->n_pending > 0".

How to repeat:
It isn't easy to get a server into the state above. I did it by accident with MySQL 5.1.63 + Facebook patch while testing the backport for the latest fix for bug 64284. I then reproduced it on purpose in unmodified 5.5 latest from launchpad. The Facebook patch was not applied but I had to add a lot of debugging code to reproduce the conditions above. 

There must be a thread in fil_io for the to-be-dropped tablespace. There must also be a thread in fil_delete_tablespace.  The sequence is:

1) fil_delete_tablespace thread runs the code that confirms n_pending == 0, then pauses
2) fil_io thread calls fil_node_prepare_for_io to increment n_pending from 0 to 1, then pauses
3) fil_delete_tablespace thread calls fil_space_free --> assert is raised

I think someone from the InnoDB team should review the code to confirm that this might be possible. My "patch" to InnoDB source to make it easier to reproduce this problem is very messy.

Suggested fix:
The protocol used by fil_delete_tablespace is obscure. It looks patched together. Now might be a good time to clean it up. 
* stop_new_ops is set, but only used by ibuf_merge_or_delete_for_page
* n_pending_ops and n_pending are used by different types of operations
* is_being_deleted is set and used

Why isn't one count of pending operations and one of (is_being_deleted, stop_new_ops) sufficient?
[6 Sep 2012 17:38] Mark Callaghan
My summary of the race.

reader thread:
calls fil_tablespace_deleted_or_being_deleted_in_mem in buf_page_init_for_read

dropper thread:
sets is_being_deleted and waits for n_pending==0 in fil_delete_tablespace

reader thread:
increments n_pending in fil_io

The work described above by the reader thread needs to be atomic. It isn't today.
[6 Sep 2012 17:43] Mark Callaghan
Is this fixed by adding a check for "space->is_being_deleted" to fil_io before the call to fil_node_prepare_for_io?
[6 Sep 2012 19:25] Mark Callaghan
It is safe to do that check and return DB_TABLESPACE_DELETED for async reads. It is not OK to do that for writes as many fil_io callers don't check return results and don't expect a failure, including buf_flush_buffered_writes
[12 Sep 2012 4:01] Inaam Rana
Mark,

I am in process of writing a patch for this. Do you have a test case to reproduce this on 5.5? You mentioned that your 'patch' to easily reproduce it messy but there doesn't seem to be an easy way to reproduce this.

When you saw the actual crash the reader thread was doing read io for what operation? It can't be a query thread because query threads should wait on MDL. I'd think it was a read request triggered by ibuf merge from master thread.
[12 Sep 2012 23:46] Mark Callaghan
I found it via the same testcase I provided for the SR associated with bugs.mysql.com/64284. I will attach what I think is the diff between 5.5 latest in trunk and my hacked version to make repro more likely.
[12 Sep 2012 23:46] Mark Callaghan
Diff for Mysql 5.5 latest from trunk to make repro more likely

Attachment: repro.66718 (application/octet-stream, text), 7.41 KiB.

[12 Sep 2012 23:47] Mark Callaghan
repro test

Attachment: innodb_drop_table_ibuf-master.opt (application/octet-stream, text), 150 bytes.

[12 Sep 2012 23:47] Mark Callaghan
repro test

Attachment: innodb_drop_table_ibuf.test (application/octet-stream, text), 2.45 KiB.

[12 Sep 2012 23:47] Mark Callaghan
repro test

Attachment: innodb_drop_table_ibuf.test (application/octet-stream, text), 2.45 KiB.

[18 Oct 2012 19:21] John Russell
Added to changelog for 5.5.29, 5.6.8, 5.7.0: 

With the innodb_file_per_table setting enabled, a DROP TABLE
operation could cause a crash, due to a race condition that depended
on the timing of pending I/O requests.