5.7.14 Node hangs while executing "Drop database"

Initial look at processlist suggest that drop table is in progress.
Other 2 threads are waiting as DROP/DDL action is serialized in Galera.
(This is classic Galera Blocking DDL issue).

----------------------------------------------------------------------

Server got killed as timeout for innodb exceeded the set threshold.

2016-12-07T09:37:16.688769Z 0 [ERROR] [FATAL] InnoDB: Semaphore wait has lasted > 600 seconds. We intentionally crash the server because it appears to be hung.

----------------------------------------------------------------------

Did this workload worked w/o any wait with PXC-5.6 ?

Server is not doing anything (it just awaits for mutex) - see https://launchpadlibrarian.net/296964684/pm05-single.png - there is no "actual work done" for 600s - just one peak and then mutex lock

on PXC-5.6 there is no delay - everything works perfectly.

I believe reproducing it will only help understand it better as there is no such flow that I can imagine that can lead to this issue.

Do you have (or can create) a short reproducible test-case that you can share.

Try creating a lot of databases (7000 with 230 tables each), and then drop them in parallel to speed up effect. I can provide SQL dump of example database.

What is more: After mysql killed itself I'm unable to start it again as it hangs after recovery (log in attachment)

The other node (the one I lost during production traffic) was also refusing to start in the same way

Maybe there's something wrong with page cleaner refactoring in mysql 5.7:

Log info:
2016-12-08T07:33:32.381816Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 875364ms. The settings might not be optimal. (flushed=0, during the time.)
2016-12-08T07:33:32.382092Z 0 [Note] InnoDB: Waiting for purge to start
<freezes here>

Also while dropping databases, there ale lot of dirty pages so maybe page cleaner is not tuned to scan this amount of databases/tables

Change in 5.7:
http://dev.mysql.com/worklog/task/?id=6642

Similar Problem:
https://bugs.mysql.com/bug.php?id=76661

setting innodb_buffer_pool_load_at_startup=0 allowed to restart mysql

Dropping databases after restart (empty buffer pool) works fine - no delays.

When I fill the buffer pool and then start dropping tables, mysql freezes after saveral drops.

Monitoring of buffer pool data during the process:

[[root@pm05 :: (none)]] > show global status like "%buffer_pool_bytes%";
+--------------------------------+-------------+
| Variable_name | Value |
+--------------------------------+-------------+
| Innodb_buffer_pool_bytes_data | 60038922240 |
| Innodb_buffer_pool_bytes_dirty | 372752384 |
+--------------------------------+-------------+
2 rows in set (0.00 sec)

[[root@pm05 :: (none)]] > show global status like "%buffer_pool_bytes%";
+--------------------------------+-------------+
| Variable_name | Value |
+--------------------------------+-------------+
| Innodb_buffer_pool_bytes_data | 60038922240 |
| Innodb_buffer_pool_bytes_dirty | 339984384 |
+--------------------------------+-------------+
2 rows in set (0.00 sec)

[[root@pm05 :: (none)]] > show global status like "%buffer_pool_bytes%";
+--------------------------------+-------------+
| Variable_name | Value |
+--------------------------------+-------------+
| Innodb_buffer_pool_bytes_data | 60038922240 |
| Innodb_buffer_pool_bytes_dirty | 325713920 |
+--------------------------------+-------------+
2 rows in set (0.00 sec)

[[root@pm05 :: (none)]] > show global status like "%buffer_pool_bytes%";
+--------------------------------+-------------+
| Variable_name | Value |
+--------------------------------+-------------+
| Innodb_buffer_pool_bytes_data | 60038922240 |
| Innodb_buffer_pool_bytes_dirty | 288768000 |
+--------------------------------+-------------+
2 rows in set (0.01 sec)

[[root@pm05 :: (none)]] > show global status like "%buffer_pool_bytes%";
+--------------------------------+-------------+
| Variable_name | Value |
+--------------------------------+-------------+
| Innodb_buffer_pool_bytes_data | 60038922240 |
| Innodb_buffer_pool_bytes_dirty | 288768000 |
+--------------------------------+-------------+
2 rows in set (0.00 sec)

Looks like it's not PXC issue, but mysql 5.7 bug

Hi Adrian,

I've been trying to repro this with PXC 5.7 (on a smaller scale though) on a 2-node cluster.

I've tried it with 180 databases (each with 140 tables).
I then startup two scripts (one for each node), each one deleting half of the databases.

Haven't been able to hang the cluster yet.

Is this similar to your scenario? If you can provide more info on your setup (OS info and example scripts, that would be great).

Thanks,
Kenn

You need to warm up the buffer pool first (select * from all the tables you created)
Start dropping tables when buffer pool is full. In my case it's about 56GB

"When I fill the buffer pool and then start dropping tables, mysql freezes"

I think there's something wrong with page cleaner refactoring in mysql 5.7

Dropping databases with empty buffer pool (just after mysql starts) works fine.

I will attach SQL scripts to recreate the databases (each one is exact clone)

Based on your analysis is sounds like the issue is with warmed up buffer pool which should then be presented even in Percona-Server. Can you try your test-case on PS and if reproduced there then PS team can look at it and fix it in PS code directly. PXC will inherit the fix.

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