开发者社区> 重庆八怪> 正文
阿里云
为了无法计算的价值
打开APP
阿里云APP内打开

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

简介:
+关注继续查看

这个问题是一个朋友发给我的@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

版权声明:本文内容由阿里云实名注册用户自发贡献,版权归原作者所有,阿里云开发者社区不拥有其著作权,亦不承担相应法律责任。具体规则请查看《阿里云开发者社区用户服务协议》和《阿里云开发者社区知识产权保护指引》。如果您发现本社区中有涉嫌抄袭的内容,填写侵权投诉表单进行举报,一经查实,本社区将立刻删除涉嫌侵权内容。

相关文章
基于Canal和Kafka实现MySQL的Binlog近实时同步
近段时间,业务系统架构基本完备,数据层面的建设比较薄弱,因为笔者目前工作重心在于搭建一个小型的数据平台。优先级比较高的一个任务就是需要近实时同步业务系统的数据(包括保存、更新或者软删除)到一个另一个数据源,持久化之前需要清洗数据并且构建一个相对合理的便于后续业务数据统计、标签系统构建等扩展功能的数据模型。基于当前团队的资源和能力,优先调研了Alibaba开源中间件Canal的使用。这篇文章简单介绍一下如何快速地搭建一套Canal相关的组件。
78 0
使用HaaS Studio开发AliOS Things C/C++应用
本文章将介绍使用HaaS Studio 进行AliOS-Things C/C++应用开发。
185 0
OS_MUTEX.C
1 /* 2 ************************************************************************************************* 3 * uC/OS-II实时控制内核 4 * 互
1340 0
【STM32 .Net MF开发板学习-27】GPRS通信实现
GPRS是General Packet Radio Service(通用分组无线服务技术)的简称,它是GSM移动电话用户可用的一种移动数据业务。
647 0
使用Global.asax实现ASP.Net的URL重写
URL重写也就是让动态页面伪装成“静态页面”,一方面可以隐藏真实的页面文件地址,另一方面对被搜索引擎的也有好处。(在不支持URLWRITE.NET组件的空间里面这是最好的方法)    在ASP.NET中,使用Global.
788 0
+关注
重庆八怪
10年ORACLE/MYSQL DBA,有一定C/C++基础
661
文章
0
问答
文章排行榜
最热
最新
相关电子书
更多
低代码开发师(初级)实战教程
立即下载
阿里巴巴DevOps 最佳实践手册
立即下载
冬季实战营第三期:MySQL数据库进阶实战
立即下载