Drop Table对MySQL的性能影响分析 (2)

为了进一步验证，我们在测试环境下模拟测试了drop table对高并发MySQL性能的影响。
1、 使用sysbench工具做压测，首先在测试环境下创建了8张2亿条记录的表，单表容量48G
2、 开启innodb_adaptive_hash_index，用olap模板压测1个小时，填充目标8张表所对应的AHI内存
3、 再次开启压测线程只对sbtest1表做访问，观察MySQL的访问情况
4、 新建会话运行drop table test.sbtest2，看到drop一张48G的表消耗了64.84秒

5、用自定义脚本检测每秒Innodb_buffer_pool_pages_misc和Innodb_buffer_pool_pages_free指标的变化情况，看到在drop table期间Innodb_buffer_pool_pages_misc大量释放，Innodb_buffer_pool_pages_free值同时增长，释放和增加的内容总量基本一致，如下图所示

6、drop table期间，MySQL处于hang死状态，QPS长时间跌0

7、errorlog中也重现了page_cleaner的日志信息

至此复现了问题现象。

【为什么MySQL会短暂hang死】

1、 压测期间，抓取了pstack，show engine innodb status，以及performance_schema下events_waits_summary_global_by_event_name表中相关mutex等现场信息
2、 在SEMAPHORES相关信息中，可以看到hang死期间大量Thread请求S-lock，被同一个线程140037411514112持有的锁所阻塞，时间持续了64秒

--Thread 140037475792640 has waited at row0purge.cc line 862 for 64.00 seconds the semaphore:
S-lock on RW-latch at 0x966f6e38 created in file dict0dict.cc line 1183
a writer (thread id 140037411514112) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0purge.cc line 862
Last time write locked in file /mysql-5.7.23/storage/innobase/row/row0mysql.cc line 4253
--Thread 140037563102976 has waited at srv0srv.cc line 1982 for 57.00 seconds the semaphore:
X-lock on RW-latch at 0x966f6e38 created in file dict0dict.cc line 1183
a writer (thread id 140037411514112) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0purge.cc line 862
Last time write locked in file /mysql-5.7.23/storage/innobase/row/row0mysql.cc line 4253

3、通过ROW OPERATIONS相关信息，可以看到MySQL的Main Thread也被同一个线程140037411514112阻塞，状态处于enforcing dict cache limit状态

3 queries inside InnoDB, 0 queries in queue
17 read views open inside InnoDB
Process ID=39257, Main thread ID=140037563102976, state: enforcing dict cache limit
Number of rows inserted 1870023456, updated 44052478, deleted 22022445, read 9301843315
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s

4、可以看到线程140037411514112执行的SQL就是drop table test.sbtest2语句，说明drop table期间持有的锁，阻塞了Main Thread及其他线程

---TRANSACTION 44734025, ACTIVE 64 sec dropping table——
10 lock struct(s), heap size 1136, 7 row lock(s), undo log entries 1
MySQL thread id 440836, OS thread handle 140037411514112, query id 475074428 localhost root checking permissions
drop table test.sbtest2

5、下面是抓到的drop table 的简化后的调用栈信息，对比可以看出，64秒的时间，drop table 都在执行函数btr_search_drop_page_hash_index，清空对应的AHI记录信息

Thread 32 (Thread 0x7f5d002b2700 (LWP 8156)):
#0 ha_remove_all_nodes_to_page
#1 btr_search_drop_page_hash_index
#2 btr_search_drop_page_hash_when_freed
#3 fseg_free_extent
#4 fseg_free_step
#5 btr_free_but_not_root
#6 btr_free_if_exists
#7 dict_drop_index_tree
#8 row_upd_clust_step
#9 row_upd
#10 row_upd_step
#11 que_thr_step
#12 que_run_threads_low
#13 que_run_threads
#14 que_eval_sql
#15 row_drop_table_for_mysql
#16 ha_innobase::delete_table
#17 ha_delete_table
#18 mysql_rm_table_no_locks
#19 mysql_rm_table
#20 mysql_execute_command
#21 mysql_parse
#22 dispatch_command
#23 do_command
#24 handle_connection
#25 pfs_spawn_thread
#26 start_thread ()
#27 clone ()