MySQL:kill和show global status命令hang住一列

本文涉及的产品
云数据库 RDS MySQL,集群系列 2核4GB
推荐场景:
搭建个人博客
RDS MySQL Serverless 基础系列,0.5-2RCU 50GB
云数据库 RDS MySQL,高可用系列 2核4GB
简介:

这个问题是一个朋友发给我的@mj环境如下:
MySQL 5.6.25
show processlist和pstack日志做了大量的删减,否则篇幅过大

一、问题描述

问题描述是这位朋友发给我的如下:

  • 问题描述
    收到从库xx.xx.xx.xx报警mysql宕机,实际上mysql没有宕机,而是因为下面这条SQL向表tmp_mds_cust_dealer_advisor_rela01插入的数据太多(这个表的数据文件高达184G,binlog文件binlog.001675高达138G).在binlog最终刷到磁盘的期间导致 SHOW GLOBAL STATUS 等命令阻塞。观察了当时的cpu,内存,磁盘情况,压力都不大。为什么刷binlog到磁盘会阻塞 SHOW GLOBAL STATUS 等命令 ?
  • show processlist如下:
dbadmin@(none) 08:49:50>show processlist;
+---------+-------------+-----------------+--------------------+---------+-------+----------------------------------+------------------------------------------------------------------------------------------------------+-----------+---------------+
| Id      | User        | Host            | db                 | Command | Time  | State                            | Info                                                                                                 | Rows_sent | Rows_examined |
+---------+-------------+-----------------+--------------------+---------+-------+----------------------------------+------------------------------------------------------------------------------------------------------+-----------+---------------+
|  862489 | dbadmin     | 127.0.0.1:41012 | NULL               | Killed  |   413 | executing                        | SHOW GLOBAL STATUS LIKE 'uptime'                                                                     |         0 |             0 |
|  862490 | dbadmin     | 127.0.0.1:41014 | information_schema | Killed  |   902 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
|  862491 | dbadmin     | 127.0.0.1:41015 | information_schema | Killed  |   902 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
|  862493 | dbadmin     | 127.0.0.1:41019 | information_schema | Killed  |   165 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
|  862495 | dbadmin     | 127.0.0.1:41022 | information_schema | Killed  |  1149 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
|  862508 | monitor     | 127.0.0.1:41041 | mysql              | Killed  |   411 | executing                        | show global status
            where Variable_name in
            (
                'Threads_connect |         0 |             0 |
| 1140925 | monitor     | 127.0.0.1:64924 | mysql              | Query   |   414 | executing                        | show global status 
    where Variable_name in 
    ('Com_select','Com_insert','Com_update','Com_del |         0 |             0 |
| 1153172 | system user |                 | NULL               | Connect | 82688 | Waiting for master to send event | NULL                                                                                                 |         0 |             0 |
| 1153173 | system user |                 | NULL               | Connect | 55564 | System lock                      | NULL                                                                                                 |         0 |             0 |
| 1168129 | dbadmin     | 127.0.0.1:9377  | information_schema | Killed  |   123 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181458 | dbadmin     | 127.0.0.1:11163 | NULL               | Killed  |   413 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181459 | dbadmin     | 127.0.0.1:11164 | NULL               | Killed  |   406 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181460 | dbadmin     | 127.0.0.1:11166 | NULL               | Killed  |   396 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181461 | dbadmin     | 127.0.0.1:11177 | NULL               | Killed  |   393 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181462 | dbmonitor   | 127.0.0.1:11226 | NULL               | Query   |   387 | executing                        | SHOW /*!50001 GLOBAL */ STATUS                                                                       |         0 |             0 |
| 1181463 | dbadmin     | 127.0.0.1:11242 | NULL               | Killed  |   386 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181464 | dbadmin     | 127.0.0.1:11328 | NULL               | Killed  |   376 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181465 | dbadmin     | 127.0.0.1:11408 | NULL               | Killed  |   366 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181466 | dbadmin     | 127.0.0.1:11436 | NULL               | Killed  |   363 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181467 | dbadmin     | 127.0.0.1:11465 | NULL               | Killed  |   356 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181468 | dbadmin     | 127.0.0.1:11467 | NULL               | Killed  |   346 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181469 | dbadmin     | 127.0.0.1:11469 | NULL               | Killed  |   336 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181470 | dbmonitor   | 127.0.0.1:11471 | NULL               | Query   |   327 | executing                        | SHOW /*!50001 GLOBAL */ STATUS                                                                       |         0 |             0 |
| 1181471 | dbadmin     | 127.0.0.1:11477 | NULL               | Killed  |   326 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181472 | dbadmin     | 127.0.0.1:11478 | NULL               | Killed  |   321 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181473 | dbadmin     | 127.0.0.1:11481 | NULL               | Killed  |   316 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181474 | dbadmin     | 127.0.0.1:11483 | NULL               | Killed  |   306 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181475 | dbadmin     | 127.0.0.1:11484 | NULL               | Killed  |   303 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181476 | dbadmin     | 127.0.0.1:11485 | NULL               | Killed  |   296 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181477 | dbadmin     | 127.0.0.1:11557 | NULL               | Killed  |   286 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181478 | dbadmin     | 127.0.0.1:11640 | NULL               | Killed  |   276 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181479 | dbmonitor   | 127.0.0.1:11711 | NULL               | Query   |   267 | executing                        | SHOW /*!50001 GLOBAL */ STATUS                                                                       |         0 |             0 |
| 1181480 | dbadmin     | 127.0.0.1:11730 | NULL               | Killed  |   266 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181481 | dbadmin     | 127.0.0.1:11783 | NULL               | Killed  |   256 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181482 | dbadmin     | 127.0.0.1:11784 | NULL               | Killed  |   249 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181483 | dbadmin     | 127.0.0.1:11785 | NULL               | Killed  |   246 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181484 | dbadmin     | 127.0.0.1:11786 | NULL               | Killed  |   243 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181485 | dbadmin     | 127.0.0.1:11788 | NULL               | Killed  |   236 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181486 | dbadmin     | 127.0.0.1:11792 | NULL               | Killed  |   226 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
| 1181487 | dbadmin     | localhost       | NULL               | Killed  |   218 | cleaning up                      | NULL                                                                                                 |         0 |             0 |
....
+---------+-------------+-----------------+--------------------+---------+-------+----------------------------------+------------------------------------------------------------------------------------------------------+-----------+---------------+
75 rows in set (0.01 sec)
  • pstack
    这位朋友给出了pstack 实际上是最有用的。
.....
Thread 112 (Thread 0x7f75ef237700 (LWP 82013)):
#0  0x00007f769d10425d in read () from /lib64/libpthread.so.0
#1  0x00000000008f12ba in read (__nbytes=5242880, __buf=0x7f5565800000, __fd=181) at /usr/include/bits/unistd.h:45
#2  my_read (Filedes=181, Buffer=0x7f5565800000 "\224\200錦224\234\215錦212℃\234\211閈231\220錦205\217竆b", Count=5242880, MyFlags=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/mysys/my_read.c:50
#3  0x00000000008dbd7d in my_b_fill (info=0x7f556546cb80) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/mysys/mf_iocache2.c:226
#4  0x000000000089cba9 in MYSQL_BIN_LOG::do_write_cache (this=this@entry=0x135e6c0 <mysql_bin_log>, thd=thd@entry=0x7f55764d6000, cache=cache@entry=0x7f556546cb80) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:6005
#5  0x00000000008a5f7b in MYSQL_BIN_LOG::write_cache (this=this@entry=0x135e6c0 <mysql_bin_log>, thd=thd@entry=0x7f55764d6000, cache_data=cache_data@entry=0x7f556546cb78) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:6144
#6  0x00000000008a6282 in binlog_cache_data::flush (this=0x7f556546cb78, thd=0x7f55764d6000, bytes_written=0x7f75ef2349e0, wrote_xid=0x7f75ef2349c0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:1261
#7  0x00000000008a6336 in flush (wrote_xid=0x7f75ef2349c0, bytes_written=<synthetic pointer>, thd=0x7f55764d6000, this=0x7f556546ca00) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:778
#8  MYSQL_BIN_LOG::flush_thread_caches (this=this@entry=0x135e6c0 <mysql_bin_log>, thd=thd@entry=0x7f55764d6000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:6779
#9  0x00000000008a6469 in MYSQL_BIN_LOG::process_flush_stage_queue (this=this@entry=0x135e6c0 <mysql_bin_log>, total_bytes_var=total_bytes_var@entry=0x7f75ef234ad0, rotate_var=rotate_var@entry=0x7f75ef234ab0, out_queue_var=out_queue_var@entry=0x7f75ef234ae0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:6835
#10 0x00000000008a674c in MYSQL_BIN_LOG::ordered_commit (this=this@entry=0x135e6c0 <mysql_bin_log>, thd=thd@entry=0x7f55764d6000, all=all@entry=true, skip_commit=skip_commit@entry=false) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:7265
#11 0x00000000008a7284 in MYSQL_BIN_LOG::commit (this=0x135e6c0 <mysql_bin_log>, thd=0x7f55764d6000, all=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:6738
#12 0x00000000005bfa07 in ha_commit_trans (thd=thd@entry=0x7f55764d6000, all=all@entry=true, ignore_global_read_lock=ignore_global_read_lock@entry=false) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/handler.cc:1513
#13 0x000000000078722e in trans_commit (thd=thd@entry=0x7f55764d6000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/transaction.cc:230
#14 0x0000000000888242 in Xid_log_event::do_commit (this=this@entry=0x7f557591d380, thd=0x7f55764d6000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/log_event.cc:7420
#15 0x0000000000888670 in Xid_log_event::do_apply_event (this=0x7f557591d380, rli=0x7f555da1a000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/log_event.cc:7632
#16 0x000000000088425a in Log_event::apply_event (this=this@entry=0x7f557591d380, rli=rli@entry=0x7f555da1a000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/log_event.cc:3057
#17 0x00000000008bb52e in apply_event_and_update_pos (ptr_ev=ptr_ev@entry=0x7f75ef236860, thd=thd@entry=0x7f55764d6000, rli=rli@entry=0x7f555da1a000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/rpl_slave.cc:3818
#18 0x00000000008befbb in exec_relay_log_event (rli=0x7f555da1a000, thd=0x7f55764d6000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/rpl_slave.cc:4315
#19 handle_slave_sql (arg=arg@entry=0x7f555da14000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/rpl_slave.cc:6206
#20 0x0000000000b050e3 in pfs_spawn_thread (arg=0x7f557009e0c0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/storage/perfschema/pfs.cc:1860
#21 0x00007f769d0fddf3 in start_thread () from /lib64/libpthread.so.0
#22 0x00007f769b7713dd in clone () from /lib64/libc.so.6
...
Thread 80 (Thread 0x7f553916a700 (LWP 1306)):
#0  0x00007f769d103f7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f769d0ffd41 in _L_lock_790 () from /lib64/libpthread.so.0
#2  0x00007f769d0ffc47 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000008a0014 in inline_mysql_mutex_lock (src_file=0xc31a00 "/mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc", src_line=7536, that=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/include/mysql/psi/mysql_thread.h:688
#4  MYSQL_BIN_LOG::set_status_variables (this=this@entry=0x135e6c0 <mysql_bin_log>, thd=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:7536
#5  0x00000000008a007b in show_binlog_vars (thd=<optimized out>, var=0x7f5539166c70, buff=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:9476
#6  0x00000000007375ff in show_status_array (thd=thd@entry=0x7f5573c2c000, wild=wild@entry=0x0, variables=0x7f75f43f9030, value_type=value_type@entry=OPT_GLOBAL, status_var=0x7f55391671b0, prefix=prefix@entry=0xc2ce39 "", table=0x7f556345d010, ucase_names=false, cond=cond@entry=0x7f55636380d0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:2635
#7  0x0000000000737f69 in fill_status (thd=thd@entry=0x7f5573c2c000, tables=tables@entry=0x7f5563638578, cond=0x7f55636380d0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:7321
#8  0x000000000073e692 in do_fill_table (join_table=0x7f5563636610, table_list=0x7f5563638578, thd=0x7f5573c2c000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:7986
#9  get_schema_tables_result (join=join@entry=0x7f5563638ed8, executed_place=executed_place@entry=PROCESSED_BY_JOIN_EXEC) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:8087
#10 0x000000000071f425 in JOIN::prepare_result (this=this@entry=0x7f5563638ed8, columns_list=columns_list@entry=0x7f5539167960) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:823
#11 0x00000000006d9e7c in JOIN::exec (this=0x7f5563638ed8) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_executor.cc:116
#12 0x0000000000723c05 in mysql_execute_select (free_join=true, select_lex=0x7f5573c2e880, thd=0x7f5573c2c000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:1100
#13 mysql_select (thd=thd@entry=0x7f5573c2c000, tables=0x7f5563638578, wild_num=0, fields=..., conds=0x7f55636380d0, order=order@entry=0x7f5573c2ea48, group=group@entry=0x7f5573c2e980, having=0x0, select_options=2684619520, result=result@entry=0x7f5563638eb0, unit=unit@entry=0x7f5573c2e238, select_lex=select_lex@entry=0x7f5573c2e880) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:1221
#14 0x0000000000724465 in handle_select (thd=thd@entry=0x7f5573c2c000, result=result@entry=0x7f5563638eb0, setup_tables_done_option=setup_tables_done_option@entry=0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:110
#15 0x0000000000581a38 in execute_sqlcom_select (thd=thd@entry=0x7f5573c2c000, all_tables=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:5665
#16 0x00000000006fd731 in mysql_execute_command (thd=thd@entry=0x7f5573c2c000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:2952
#17 0x0000000000702c98 in mysql_parse (thd=thd@entry=0x7f5573c2c000, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f5539169020) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:6950
#18 0x00000000007044ab in dispatch_command (command=<optimized out>, thd=thd@entry=0x7f5573c2c000, packet=<optimized out>, packet_length=739) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:1442
#19 0x0000000000706219 in do_command (thd=thd@entry=0x7f5573c2c000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:1054
#20 0x000000000078f368 in threadpool_process_request (thd=0x7f5573c2c000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_common.cc:311
#21 0x000000000079033d in handle_event (connection=0x7f5573b5b880) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1553
#22 worker_main (param=param@entry=0x1351e00 <all_groups+14848>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1606
#23 0x0000000000b050e3 in pfs_spawn_thread (arg=0x7f555d6f7ce0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/storage/perfschema/pfs.cc:1860
#24 0x00007f769d0fddf3 in start_thread () from /lib64/libpthread.so.0
#25 0x00007f769b7713dd in clone () from /lib64/libc.so.6
.....
Thread 55 (Thread 0x7f55318b2700 (LWP 2821)):
#0  0x00007f769d103f7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f769d0ffd77 in _L_lock_974 () from /lib64/libpthread.so.0
#2  0x00007f769d0ffd20 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000006cde10 in inline_mysql_mutex_lock (src_file=0xbc9938 "/mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_class.cc", src_line=1760, that=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/include/mysql/psi/mysql_thread.h:688
#4  THD::release_resources (this=this@entry=0x7f557629d000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_class.cc:1760
#5  0x000000000078f1e7 in threadpool_remove_connection (thd=0x7f557629d000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_common.cc:257
#6  0x00000000007902b6 in connection_abort (connection=0x7f556fea9610) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1363
#7  handle_event (connection=0x7f556fea9610) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1564
#8  worker_main (param=param@entry=0x134f400 <all_groups+4096>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1606
#9  0x0000000000b050e3 in pfs_spawn_thread (arg=0x7f555d6f7600) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/storage/perfschema/pfs.cc:1860
#10 0x00007f769d0fddf3 in start_thread () from /lib64/libpthread.so.0
#11 0x00007f769b7713dd in clone () from /lib64/libc.so.6
Thread 54 (Thread 0x7f553898b700 (LWP 2962)):
#0  0x00007f769d103f7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f769d0ffd77 in _L_lock_974 () from /lib64/libpthread.so.0
#2  0x00007f769d0ffd20 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000006cde10 in inline_mysql_mutex_lock (src_file=0xbc9938 "/mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_class.cc", src_line=1760, that=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/include/mysql/psi/mysql_thread.h:688
#4  THD::release_resources (this=this@entry=0x7f557469c000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_class.cc:1760
#5  0x000000000078f1e7 in threadpool_remove_connection (thd=0x7f557469c000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_common.cc:257
#6  0x00000000007902b6 in connection_abort (connection=0x7f556fea9760) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1363
#7  handle_event (connection=0x7f556fea9760) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1564
#8  worker_main (param=param@entry=0x134f600 <all_groups+4608>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1606
#9  0x0000000000b050e3 in pfs_spawn_thread (arg=0x7f555d6f76a0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/storage/perfschema/pfs.cc:1860
#10 0x00007f769d0fddf3 in start_thread () from /lib64/libpthread.so.0
#11 0x00007f769b7713dd in clone () from /lib64/libc.so.6
....
Thread 50 (Thread 0x7f55337ff700 (LWP 3002)):
#0  0x00007f769d103f7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f769d0ffd77 in _L_lock_974 () from /lib64/libpthread.so.0
#2  0x00007f769d0ffd20 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x0000000000738116 in inline_mysql_mutex_lock (src_file=0xbd31e8 "/mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc", src_line=7315, that=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/include/mysql/psi/mysql_thread.h:688
#4  fill_status (thd=thd@entry=0x7f5576042000, tables=tables@entry=0x7f55d2c1d358, cond=0x0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:7315
#5  0x000000000073e692 in do_fill_table (join_table=0x7f55d2c1e9e0, table_list=0x7f55d2c1d358, thd=0x7f5576042000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:7986
#6  get_schema_tables_result (join=join@entry=0x7f55d2c1dcb8, executed_place=executed_place@entry=PROCESSED_BY_JOIN_EXEC) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:8087
#7  0x000000000071f425 in JOIN::prepare_result (this=this@entry=0x7f55d2c1dcb8, columns_list=columns_list@entry=0x7f55337fc960) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:823
#8  0x00000000006d9e7c in JOIN::exec (this=0x7f55d2c1dcb8) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_executor.cc:116
#9  0x0000000000723c05 in mysql_execute_select (free_join=true, select_lex=0x7f5576044880, thd=0x7f5576042000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:1100
#10 mysql_select (thd=thd@entry=0x7f5576042000, tables=0x7f55d2c1d358, wild_num=0, fields=..., conds=0x0, order=order@entry=0x7f5576044a48, group=group@entry=0x7f5576044980, having=0x0, select_options=2684652288, result=result@entry=0x7f55d2c1dc90, unit=unit@entry=0x7f5576044238, select_lex=select_lex@entry=0x7f5576044880) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:1221
#11 0x0000000000724465 in handle_select (thd=thd@entry=0x7f5576042000, result=result@entry=0x7f55d2c1dc90, setup_tables_done_option=setup_tables_done_option@entry=0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:110
#12 0x0000000000581a38 in execute_sqlcom_select (thd=thd@entry=0x7f5576042000, all_tables=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:5665
#13 0x00000000006fd731 in mysql_execute_command (thd=thd@entry=0x7f5576042000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:2952
#14 0x0000000000702c98 in mysql_parse (thd=thd@entry=0x7f5576042000, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f55337fe020) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:6950
#15 0x00000000007044ab in dispatch_command (command=<optimized out>, thd=thd@entry=0x7f5576042000, packet=<optimized out>, packet_length=30) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:1442
#16 0x0000000000706219 in do_command (thd=thd@entry=0x7f5576042000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:1054
#17 0x000000000078f368 in threadpool_process_request (thd=0x7f5576042000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_common.cc:311
#18 0x000000000079033d in handle_event (connection=0x7f556fea9ca0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1553
#19 worker_main (param=param@entry=0x134fc00 <all_groups+6144>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1606
#20 0x0000000000b050e3 in pfs_spawn_thread (arg=0x7f555e413e80) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/storage/perfschema/pfs.cc:1860
#21 0x00007f769d0fddf3 in start_thread () from /lib64/libpthread.so.0
#22 0x00007f769b7713dd in clone () from /lib64/libc.so.6
.....
Thread 46 (Thread 0x7f5531a79700 (LWP 3181)):
#0  0x00007f769d103f7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f769d0ffd77 in _L_lock_974 () from /lib64/libpthread.so.0
#2  0x00007f769d0ffd20 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x0000000000738116 in inline_mysql_mutex_lock (src_file=0xbd31e8 "/mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc", src_line=7315, that=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/include/mysql/psi/mysql_thread.h:688
#4  fill_status (thd=thd@entry=0x7f55761e9000, tables=tables@entry=0x7f55d441d358, cond=0x0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:7315
#5  0x000000000073e692 in do_fill_table (join_table=0x7f55d441e9e0, table_list=0x7f55d441d358, thd=0x7f55761e9000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:7986
#6  get_schema_tables_result (join=join@entry=0x7f55d441dcb8, executed_place=executed_place@entry=PROCESSED_BY_JOIN_EXEC) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:8087
#7  0x000000000071f425 in JOIN::prepare_result (this=this@entry=0x7f55d441dcb8, columns_list=columns_list@entry=0x7f5531a76960) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:823
#8  0x00000000006d9e7c in JOIN::exec (this=0x7f55d441dcb8) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_executor.cc:116
#9  0x0000000000723c05 in mysql_execute_select (free_join=true, select_lex=0x7f55761eb880, thd=0x7f55761e9000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:1100
#10 mysql_select (thd=thd@entry=0x7f55761e9000, tables=0x7f55d441d358, wild_num=0, fields=..., conds=0x0, order=order@entry=0x7f55761eba48, group=group@entry=0x7f55761eb980, having=0x0, select_options=2684652288, result=result@entry=0x7f55d441dc90, unit=unit@entry=0x7f55761eb238, select_lex=select_lex@entry=0x7f55761eb880) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:1221
#11 0x0000000000724465 in handle_select (thd=thd@entry=0x7f55761e9000, result=result@entry=0x7f55d441dc90, setup_tables_done_option=setup_tables_done_option@entry=0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_select.cc:110
#12 0x0000000000581a38 in execute_sqlcom_select (thd=thd@entry=0x7f55761e9000, all_tables=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:5665
#13 0x00000000006fd731 in mysql_execute_command (thd=thd@entry=0x7f55761e9000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:2952
#14 0x0000000000702c98 in mysql_parse (thd=thd@entry=0x7f55761e9000, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f5531a78020) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:6950
#15 0x00000000007044ab in dispatch_command (command=<optimized out>, thd=thd@entry=0x7f55761e9000, packet=<optimized out>, packet_length=30) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:1442
#16 0x0000000000706219 in do_command (thd=thd@entry=0x7f55761e9000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_parse.cc:1054
#17 0x000000000078f368 in threadpool_process_request (thd=0x7f55761e9000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_common.cc:311
#18 0x000000000079033d in handle_event (connection=0x7f556fec3070) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1553
#19 worker_main (param=param@entry=0x1350400 <all_groups+8192>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1606
#20 0x0000000000b050e3 in pfs_spawn_thread (arg=0x7f555d6f7b00) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/storage/perfschema/pfs.cc:1860
#21 0x00007f769d0fddf3 in start_thread () from /lib64/libpthread.so.0
#22 0x00007f769b7713dd in clone () from /lib64/libc.so.6
.....
Thread 43 (Thread 0x7f5531b3c700 (LWP 3340)):
#0  0x00007f769d103f7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f769d0ffd77 in _L_lock_974 () from /lib64/libpthread.so.0
#2  0x00007f769d0ffd20 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000006cde10 in inline_mysql_mutex_lock (src_file=0xbc9938 "/mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_class.cc", src_line=1760, that=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/include/mysql/psi/mysql_thread.h:688
#4  THD::release_resources (this=this@entry=0x7f5573f8a000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_class.cc:1760
#5  0x000000000078f1e7 in threadpool_remove_connection (thd=0x7f5573f8a000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_common.cc:257
#6  0x00000000007902b6 in connection_abort (connection=0x7f556fe17ac0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1363
#7  handle_event (connection=0x7f556fe17ac0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1564
#8  worker_main (param=param@entry=0x1350a00 <all_groups+9728>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1606
#9  0x0000000000b050e3 in pfs_spawn_thread (arg=0x7f555e413fc0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/storage/perfschema/pfs.cc:1860
#10 0x00007f769d0fddf3 in start_thread () from /lib64/libpthread.so.0
#11 0x00007f769b7713dd in clone () from /lib64/libc.so.6
Thread 42 (Thread 0x7f5531bbe700 (LWP 3353)):
#0  0x00007f769d103f7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f769d0ffd77 in _L_lock_974 () from /lib64/libpthread.so.0
#2  0x00007f769d0ffd20 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000006cde10 in inline_mysql_mutex_lock (src_file=0xbc9938 "/mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_class.cc", src_line=1760, that=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/include/mysql/psi/mysql_thread.h:688
#4  THD::release_resources (this=this@entry=0x7f55747ed000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_class.cc:1760
#5  0x000000000078f1e7 in threadpool_remove_connection (thd=0x7f55747ed000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_common.cc:257
#6  0x00000000007902b6 in connection_abort (connection=0x7f556fec36a0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1363
#7  handle_event (connection=0x7f556fec36a0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1564
#8  worker_main (param=param@entry=0x1350c00 <all_groups+10240>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_unix.cc:1606
#9  0x0000000000b050e3 in pfs_spawn_thread (arg=0x7f555e414060) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/storage/perfschema/pfs.cc:1860
#10 0x00007f769d0fddf3 in start_thread () from /lib64/libpthread.so.0
#11 0x00007f769b7713dd in clone () from /lib64/libc.so.6

二、分析大多数线程的等待MUTEX

实际上分析pstack可以发现,基本所有的等待线程可以分为:

  • KILL SESSION等待
Thread 111 (Thread 0x7f5531afb700 (LWP 15742)):
#0  0x00007f769d103f7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f769d0ffd77 in _L_lock_974 () from /lib64/libpthread.so.0
#2  0x00007f769d0ffd20 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000006cde10 in inline_mysql_mutex_lock (src_file=0xbc9938 "/mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_class.cc", src_line=1760, that=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/include/mysql/psi/mysql_thread.h:688
#4  THD::release_resources (this=this@entry=0x7f55762ba000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_class.cc:1760
#5  0x000000000078f1e7 in threadpool_remove_connection (thd=0x7f55762ba000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/threadpool_common.cc:257
.....

等待的MUTEX为:

void THD::release_resources()
{
  mysql_mutex_assert_not_owner(&LOCK_thread_count);
  DBUG_ASSERT(m_release_resources_done == false);

  mysql_mutex_lock(&LOCK_status);  //等待的MUTEX
  add_to_status(&global_status_var, &status_var);
  mysql_mutex_unlock(&LOCK_status);
  • SHOW GLOBAL STATUS等待
Thread 91 (Thread 0x7f553373c700 (LWP 17935)):
#0  0x00007f769d103f7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f769d0ffd77 in _L_lock_974 () from /lib64/libpthread.so.0
#2  0x00007f769d0ffd20 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x0000000000738116 in inline_mysql_mutex_lock (src_file=0xbd31e8 "/mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc", src_line=7315, that=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/include/mysql/psi/mysql_thread.h:688
#4  fill_status (thd=thd@entry=0x7f5573db0000, tables=tables@entry=0x7f55736f6178, cond=0x7f55736f5d70) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:7315
#5  0x000000000073e692 in do_fill_table (join_table=0x7f5564145c78, table_list=0x7f55736f6178, thd=0x7f5573db0000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:7986
.....

等待的MUTEX为:

int fill_status(THD *thd, TABLE_LIST *tables, Item *cond)
{
  .......
  /*
    Avoid recursive acquisition of LOCK_status in cases when WHERE clause
    represented by "cond" contains subquery on I_S.SESSION/GLOBAL_STATUS.
  */
  if (thd->fill_status_recursion_level++ == 0) 
    mysql_mutex_lock(&LOCK_status); //等待的MUTEX

实际上我们发现他们的共同点为都需要等待获取MUTEX:LOCK_status,

三、分析那个线程获取了MUTEX:LOCK_status而又处于等待

那么可以在整个pstack中试图找出获取LOCK_status的线程,实际上就是

Thread 80 (Thread 0x7f553916a700 (LWP 1306)):
#0  0x00007f769d103f7d in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f769d0ffd41 in _L_lock_790 () from /lib64/libpthread.so.0
#2  0x00007f769d0ffc47 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000008a0014 in inline_mysql_mutex_lock (src_file=0xc31a00 "/mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc", src_line=7536, that=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/include/mysql/psi/mysql_thread.h:688
#4  MYSQL_BIN_LOG::set_status_variables (this=this@entry=0x135e6c0 <mysql_bin_log>, thd=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:7536
#5  0x00000000008a007b in show_binlog_vars (thd=<optimized out>, var=0x7f5539166c70, buff=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:9476
#6  0x00000000007375ff in show_status_array (thd=thd@entry=0x7f5573c2c000, wild=wild@entry=0x0, variables=0x7f75f43f9030, value_type=value_type@entry=OPT_GLOBAL, status_var=0x7f55391671b0, prefix=prefix@entry=0xc2ce39 "", table=0x7f556345d010, ucase_names=false, cond=cond@entry=0x7f55636380d0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:2635
#7  0x0000000000737f69 in fill_status (thd=thd@entry=0x7f5573c2c000, tables=tables@entry=0x7f5563638578, cond=0x7f55636380d0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:7321
#8  0x000000000073e692 in do_fill_table (join_table=0x7f5563636610, table_list=0x7f5563638578, thd=0x7f5573c2c000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/sql_show.cc:7986
....

显然这也是一个show global status命令。而他正在等待获取另外一把MUTEX:LOCK_log如下:

/* fill_status MYSQL_BIN_LOG::ordered_commit
  Copy out current values of status variables, for SHOW STATUS or
  information_schema.global_status.

  This is called only under LOCK_status, so we can fill in a static array.
*/
void MYSQL_BIN_LOG::set_status_variables(THD *thd)
{
....
  mysql_mutex_lock(&LOCK_log); //这里是需要获取MUTEX LOCK_log
  if (!have_snapshot)
  {
    set_binlog_snapshot_file(log_file_name);
    binlog_snapshot_position= my_b_tell(&log_file); //获取binlog的位置这里就是状态值Binlog_snapshot_position 
  }
  mysql_mutex_unlock(&LOCK_log);
.....

显然这里要获取的状态值Binlog_snapshot_position ,因此必须获取LOCK_log MUTEX,来保证没有并发的线程正在写入binlog物理文件,当然这里的写入是指写入操作系统的缓存而非FSYNC ,:

mysql> show global status like '%pos%';
+--------------------------+-------+
| Variable_name            | Value |
+--------------------------+-------+
| Binlog_snapshot_position | 6363  |
+--------------------------+-------+
1 row in set (2.05 sec)

四、分析堵塞的根源

那么堵塞线程 (LWP 17935) 的很可能是开始说的那个大事物正在做flush了因此我们找到slave的 sql_thread的栈帧如下:

Thread 112 (Thread 0x7f75ef237700 (LWP 82013)):
#0  0x00007f769d10425d in read () from /lib64/libpthread.so.0
#1  0x00000000008f12ba in read (__nbytes=5242880, __buf=0x7f5565800000, __fd=181) at /usr/include/bits/unistd.h:45
#2  my_read (Filedes=181, Buffer=0x7f5565800000 "\224\200錦224\234\215錦212℃\234\211閈231\220錦205\217竆b", Count=5242880, MyFlags=<optimized out>) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/mysys/my_read.c:50
#3  0x00000000008dbd7d in my_b_fill (info=0x7f556546cb80) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/mysys/mf_iocache2.c:226
#4  0x000000000089cba9 in MYSQL_BIN_LOG::do_write_cache (this=this@entry=0x135e6c0 <mysql_bin_log>, thd=thd@entry=0x7f55764d6000, cache=cache@entry=0x7f556546cb80) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:6005
#5  0x00000000008a5f7b in MYSQL_BIN_LOG::write_cache (this=this@entry=0x135e6c0 <mysql_bin_log>, thd=thd@entry=0x7f55764d6000, cache_data=cache_data@entry=0x7f556546cb78) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:6144
#6  0x00000000008a6282 in binlog_cache_data::flush (this=0x7f556546cb78, thd=0x7f55764d6000, bytes_written=0x7f75ef2349e0, wrote_xid=0x7f75ef2349c0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:1261
#7  0x00000000008a6336 in flush (wrote_xid=0x7f75ef2349c0, bytes_written=<synthetic pointer>, thd=0x7f55764d6000, this=0x7f556546ca00) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:778
#8  MYSQL_BIN_LOG::flush_thread_caches (this=this@entry=0x135e6c0 <mysql_bin_log>, thd=thd@entry=0x7f55764d6000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:6779
#9  0x00000000008a6469 in MYSQL_BIN_LOG::process_flush_stage_queue (this=this@entry=0x135e6c0 <mysql_bin_log>, total_bytes_var=total_bytes_var@entry=0x7f75ef234ad0, rotate_var=rotate_var@entry=0x7f75ef234ab0, out_queue_var=out_queue_var@entry=0x7f75ef234ae0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:6835
#10 0x00000000008a674c in MYSQL_BIN_LOG::ordered_commit (this=this@entry=0x135e6c0 <mysql_bin_log>, thd=thd@entry=0x7f55764d6000, all=all@entry=true, skip_commit=skip_commit@entry=false) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/binlog.cc:7265
.....
#15 0x0000000000888670 in Xid_log_event::do_apply_event (this=0x7f557591d380, rli=0x7f555da1a000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/log_event.cc:7632
#16 0x000000000088425a in Log_event::apply_event (this=this@entry=0x7f557591d380, rli=rli@entry=0x7f555da1a000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/log_event.cc:3057
#17 0x00000000008bb52e in apply_event_and_update_pos (ptr_ev=ptr_ev@entry=0x7f75ef236860, thd=thd@entry=0x7f55764d6000, rli=rli@entry=0x7f555da1a000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/rpl_slave.cc:3818
#18 0x00000000008befbb in exec_relay_log_event (rli=0x7f555da1a000, thd=0x7f55764d6000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/rpl_slave.cc:4315
#19 handle_slave_sql (arg=arg@entry=0x7f555da14000) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/sql/rpl_slave.cc:6206
#20 0x0000000000b050e3 in pfs_spawn_thread (arg=0x7f557009e0c0) at /mnt/workspace/percona-server-5.6-binaries-release/label_exp/centos6-64/percona-server-5.6.25-73.0/storage/perfschema/pfs.cc:1860
#21 0x00007f769d0fddf3 in start_thread () from /lib64/libpthread.so.0
#22 0x00007f769b7713dd in clone () from /lib64/libc.so.6

我们很清楚的看到这里正处于flush阶段

 MYSQL_BIN_LOG::process_flush_stage_queue

源码中如下:

/*
    Stage #1: flushing transactions to binary log

    While flushing, we allow new threads to enter and will process
    them in due time. Once the queue was empty, we cannot reap
    anything more since it is possible that a thread entered and
    appointed itself leader for the flush phase.
  */
  if (change_stage(thd, Stage_manager::FLUSH_STAGE, thd, NULL, &LOCK_log)) //这里获取MUTEX LOCK_log知道flush 结束
  {
    DBUG_PRINT("return", ("Thread ID: %lu, commit_error: %d",
                          thd->thread_id, thd->commit_error));
    DBUG_RETURN(finish_commit(thd));
  }

五、结论

  • 本例子中等待MUTEX有如下的图:

image.png

因此我们能在show processlist中发现大量的会话都处于挂起状态。

  • 负载不高是因为这里基本都是MUTEX等待CPU负载不高,IO不高是因为这里处于的是flush阶段还没有做到FSYNC阶段。
  • 当然大事物是有可能堵塞SHOW GLOBAL STATUS 命令的,如本例。
  • 最后还是那句话MySQL不适合大事物。

作者微信:gp_22389860

相关实践学习
如何快速连接云数据库RDS MySQL
本场景介绍如何通过阿里云数据管理服务DMS快速连接云数据库RDS MySQL,然后进行数据表的CRUD操作。
全面了解阿里云能为你做什么
阿里云在全球各地部署高效节能的绿色数据中心,利用清洁计算为万物互联的新世界提供源源不断的能源动力,目前开服的区域包括中国(华北、华东、华南、香港)、新加坡、美国(美东、美西)、欧洲、中东、澳大利亚、日本。目前阿里云的产品涵盖弹性计算、数据库、存储与CDN、分析与搜索、云通信、网络、管理与监控、应用服务、互联网中间件、移动服务、视频服务等。通过本课程,来了解阿里云能够为你的业务带来哪些帮助 &nbsp; &nbsp; 相关的阿里云产品:云服务器ECS 云服务器 ECS(Elastic Compute Service)是一种弹性可伸缩的计算服务,助您降低 IT 成本,提升运维效率,使您更专注于核心业务创新。产品详情: https://www.aliyun.com/product/ecs
相关文章
|
5月前
|
存储 关系型数据库 MySQL
初步了解MySQL数据库的基本命令
初步了解MySQL数据库的基本命令
52 0
|
1月前
|
SQL 存储 关系型数据库
MySQL进阶突击系列(01)一条简单SQL搞懂MySQL架构原理 | 含实用命令参数集
本文从MySQL的架构原理出发,详细介绍其SQL查询的全过程,涵盖客户端发起SQL查询、服务端SQL接口、解析器、优化器、存储引擎及日志数据等内容。同时提供了MySQL常用的管理命令参数集,帮助读者深入了解MySQL的技术细节和优化方法。
|
3月前
|
tengine 关系型数据库 MySQL
Tengine、Nginx安装MySQL数据库命令教程
本指南详细介绍了在Linux系统上安装与配置MySQL数据库的步骤。首先通过下载并安装MySQL社区版本,接着启动MySQL服务,使用`systemctl start mysqld.service`命令。若启动失败,可尝试使用`sudo /etc/init.d/mysqld start`。利用`systemctl status mysqld.service`检查MySQL的服务状态,确保其处于运行中。通过日志文件获取初始密码,使用该密码登录数据库,并按要求更改初始密码以增强安全性。随后创建一个名为`tengine`的数据库,最后验证数据库创建是否成功以及完成整个设置流程。
|
4月前
|
存储 关系型数据库 MySQL
MySQL基础命令及使用示例
这些基础命令构成了与MySQL数据库交互的核心,理解并掌握它们对于进行有效的数据库操作至关重要。在实际使用中,建议结合实际案例和需求来练习这些命令,以加深理解和提高效率。
90 4
|
4月前
|
存储 关系型数据库 MySQL
MySQL基础命令及使用示例
这些基础命令构成了与MySQL数据库交互的核心,理解并掌握它们对于进行有效的数据库操作至关重要。在实际使用中,建议结合实际案例和需求来练习这些命令,以加深理解和提高效率。
53 3
|
3月前
|
关系型数据库 MySQL 数据库
Mysql 常用命令
Mysql 常用命令
33 0
|
6月前
|
存储 关系型数据库 MySQL
(十五)MySQL命令大全:以后再也不用担心忘记SQL该怎么写啦~
相信大家在编写SQL时一定有一个困扰,就是明明记得数据库中有个命令/函数,可以实现自己需要的功能,但偏偏不记得哪个命令该怎么写了,这时只能靠盲目的去百度,以此来寻找自己需要的命令。
199 28
|
6月前
|
SQL 关系型数据库 MySQL
MySQL删除表数据、清空表命令(truncate、drop、delete 区别)
MySQL删除表数据、清空表命令(truncate、drop、delete区别) 使用原则总结如下: 当你不需要该表时(删除数据和结构),用drop; 当你仍要保留该表、仅删除所有数据表内容时,用truncate; 当你要删除部分记录、且希望能回滚的话,用delete;
|
6月前
|
SQL 关系型数据库 MySQL
mysql性能调优:EXPLAIN命令21
【7月更文挑战第21天】掌握SQL性能调优:深入解析EXPLAIN命令的神奇用法!
67 1
|
6月前
|
SQL 存储 数据库
MySQL设计规约问题之性能分析工具如Sql explain、show profile和mysqlsla在数据库性能优化中有什么作用
MySQL设计规约问题之性能分析工具如Sql explain、show profile和mysqlsla在数据库性能优化中有什么作用