暂无图片
暂无图片
暂无图片
暂无图片
暂无图片

如何使用 MySQL performance_schema 来排查和解决数据库问题

数据库驾驶舱 2024-07-15
341

本文讨论了如何利用 MySQL 的 performance_schema
进行数据库性能问题排查,并提供了一些具体的方法和示例。以下是文章的概要:

什么是 performance_schema

performance_schema
是 MySQL 中的一个引擎,通过它可以收集数据库的各种性能统计数据。启用与否可以通过 SHOW ENGINES
命令查看。

Instruments 介绍

Instruments 是 performance_schema
的核心组件,用于监控各种数据库操作。它们由多个部分组成,如等待(wait)、I/O(io)、SQL(sql)、二进制日志(binlog)、文件(file)等。每个 Instrument 都具有特定用途,帮助定位性能问题的根源。

查询 Instruments

可以在 performance_schema.setup_instruments
表中找到所有可用的 Instruments。不同版本的 MySQL Instruments 数量不同。

为了便于理解,Instruments可以分为七个不同的部分,如下所示。我这里使用的MySQL版本是8.0.26。在早期版本中,我们只有四个部分,所以如果你使用的是不同的/较低版本,可能会看到不同类型的Instruments。

select substring_index(name,'/',1) instruments,count(*from performance_schema.setup_instruments group by substring_index(name,'/',1);
+-------------+----------+
| instruments | count(*|
+-------------+----------+
| wait        |      386 |
| idle        |        1 |
| stage       |      130 |
| statement   |      212 |
| transaction |        1 |
| memory      |      495 |
| error       |        1 |
+-------------+----------+
7 rows in set (0.00 sec)

  1. 「阶段(Stage)」 - 以‘stage’开头的Instruments提供任何查询的执行阶段,如读取数据、发送数据、ALTER TABLE、检查查询缓存等。例如stage/sql/altering table

  2. 「等待(Wait)」 - 以‘wait’开头的Instruments属于这一类,如互斥等待、文件等待、I/O等待和表等待。此类Instruments可以是wait/io/file/sql/map

  3. 「内存(Memory)」 - 以“memory”开头的Instruments提供关于每个线程内存使用情况的信息。例如memory/sql/MYSQL_BIN_LOG

  4. 「语句(Statement)」 - 以“statement”开头的Instruments提供关于SQL类型和存储过程的信息。

  5. 「空闲(Idle)」 - 提供关于套接字连接和线程相关的信息。

  6. 「事务(Transaction)」 - 提供与事务相关的信息,只有一个Instruments。

  7. 「错误(Error)」 - 这个单一的Instruments提供用户活动生成的错误信息。此Instruments没有进一步的组件。

如何找到所需的Instruments

Instruments从左到右读取,我们可以找到所需的Instruments,然后找到其相应的性能。

例如 - 我需要观察MySQL实例的redo log的性能,并需要检查线程/连接是否需要等待redo log文件刷新后才能继续写入,如果是这样,那么需要等待多长时间。

select * from performance_schema.setup_instruments where name like '%innodb_log_file%';
+-------------------------------------+---------+-------+------------+------------+---------------+
| NAME                                | ENABLED | TIMED | PROPERTIES | VOLATILITY | DOCUMENTATION |
+-------------------------------------+---------+-------+------------+------------+---------------+
| wait/io/file/innodb/innodb_log_file | YES     | YES   |            |          0 | NULL          |
+-------------------------------------+---------+-------+------------+------------+---------------+
1 row in set (0.00 sec)

在这里,你可以看到redo log文件的I/O等待状态。

示例二 - 你需要找出可以计算所需时间的操作或Instruments,即大规模更新需要多少时间。以下是帮助你找到这些操作的所有Instruments。

select * from performance_schema.setup_instruments where PROPERTIES='progress';
+------------------------------------------------------+---------+-------+------------+------------+---------------+
| NAME                                                 | ENABLED | TIMED | PROPERTIES | VOLATILITY | DOCUMENTATION |
+------------------------------------------------------+---------+-------+------------+------------+---------------+
| stage/sql/copy to tmp table                          | YES     | YES   | progress   |          0 | NULL          |
| stage/sql/Applying batch of row changes (write)      | YES     | YES   | progress   |          0 | NULL          |
| stage/sql/Applying batch of row changes (update)     | YES     | YES   | progress   |          0 | NULL          |
| stage/sql/Applying batch of row changes (delete)     | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/alter table (end)                       | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/alter table (flush)                     | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/alter table (insert)                    | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/alter table (log apply index)           | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/alter table (log apply table)           | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/alter table (merge sort)                | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/alter table (read PK and internal sort) | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/alter tablespace (encryption)           | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/buffer pool load                        | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/clone (file copy)                       | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/clone (redo copy)                       | YES     | YES   | progress   |          0 | NULL          |
| stage/innodb/clone (page copy)                       | YES     | YES   | progress   |          0 | NULL          |
+------------------------------------------------------+---------+-------+------------+------------+---------------+
16 rows in set (0.00 sec)

上述Instruments是那些可以跟踪进度的Instruments。

如何准备这些Instruments以解决性能问题

为了利用这些Instruments,首先需要启用它们,以便performance_schema记录相关数据。除了记录运行线程的信息外,还可以保持这些线程(语句/阶段或任何特定操作)的历史记录。让我们看看,在我使用的版本中,默认情况下启用了多少Instruments。我没有显式启用任何其他Instruments。

select count(*from performance_schema.setup_instruments where ENABLED='YES';

+----------+
| count(*|
+----------+
|      780 |
+----------+

1 row in set (0.00 sec)

以下查询列出了前30个启用的Instruments,这些Instruments将记录在表中。

select * from performance_schema.setup_instruments where enabled='YES' limit 30;
+---------------------------------------+---------+-------+------------+------------+---------------+
| NAME                                  | ENABLED | TIMED | PROPERTIES | VOLATILITY | DOCUMENTATION |
+---------------------------------------+---------+-------+------------+------------+---------------+
| wait/io/file/sql/binlog               | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/binlog_cache         | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/binlog_index         | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/binlog_index_cache   | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/relaylog             | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/relaylog_cache       | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/relaylog_index       | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/relaylog_index_cache | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/io_cache             | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/casetest             | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/dbopt                | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/ERRMSG               | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/select_to_file       | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/file_parser          | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/FRM                  | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/load                 | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/LOAD_FILE            | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/log_event_data       | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/log_event_info       | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/misc                 | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/pid                  | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/query_log            | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/slow_log             | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/tclog                | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/trigger_name         | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/trigger              | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/init                 | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/SDI                  | YES     | YES   |            |          0 | NULL          |
| wait/io/file/sql/hash_join            | YES     | YES   |            |          0 | NULL          |
| wait/io/file/mysys/proc_meminfo       | YES     | YES   |            |          0 | NULL          |
+---------------------------------------+---------+-------+------------+------------+---------------+
30 rows in set (0.00 sec)

如前所述,还可以保持事件的历史记录。例如,如果你正在运行负载测试,并希望在其完成后分析查询的性能,则需要激活以下消费者(如果尚未激活)。

select * from performance_schema.setup_consumers;

+----------------------------------+---------+
| NAME                             | ENABLED |
+----------------------------------+---------+
| events_stages_current            | YES     |
| events_stages_history            | NO      |
| events_stages_history_long       | NO      |
| events_statements_current        | YES     |
| events_statements_history        | YES     |
| events_statements_history_long   | NO      |
| events_transactions_current      | YES     |
| events_transactions_history      | YES     |
| events_transactions_history_long | NO      |
| events_waits_current             | NO      |
| events_waits_history             | NO      |
| events_waits_history_long        | NO      |
| global_instrumentation           | YES     |
| thread_instrumentation           | YES     |
| statements_digest                | YES     | -- 允许SQL语句的摘要文本
+----------------------------------+---------+
15 rows in set (0.00 sec)

假设你想分析一个查询的大多数时间花费在哪些阶段,你需要使用以下查询启用相应的日志记录。

MySQL> update performance_schema.setup_consumers set ENABLED='YES' where NAME='events_stages_current';

如何利用MySQL performance_schema

现在我们知道了什么是Instruments,如何启用它们以及我们想要存储的数据量,是时候了解如何使用这些Instruments了。为了便于理解,我从我的测试用例中获取了一些Instruments的输出,因为不可能涵盖所有Instruments,因为有超过一千种Instruments。

请注意,为了生成假负载,我使用了「sysbench」(如果你不熟悉它,可以在这里阅读相关内容)来创建读写流量,使用以下详细信息:

lua : oltp_read_write.lua
Number of tables : 1
table_Size : 100000
threads : 4/10 
rate - 10

例如,想象一个场景,你想找出内存被使用在哪里。为了找出这一点,让我们在与内存相关的表中执行以下查询。

select * from performance_schema.memory_summary_global_by_event_name order by SUM_NUMBER_OF_BYTES_ALLOC desc limit 3 \G
*************************** 1. row ***************************
                  EVENT_NAME: memory/innodb/buf_buf_pool
                 COUNT_ALLOC: 24
                  COUNT_FREE: 0
   SUM_NUMBER_OF_BYTES_ALLOC: 3292102656
    SUM_NUMBER_OF_BYTES_FREE: 0
              LOW_COUNT_USED: 0
          CURRENT_COUNT_USED: 24
             HIGH_COUNT_USED: 24
    LOW_NUMBER_OF_BYTES_USED: 0
CURRENT_NUMBER_OF_BYTES_USED: 3292102656
   HIGH_NUMBER_OF_BYTES_USED: 3292102656
*************************** 2. row ***************************
                  EVENT_NAME: memory/sql/THD::main_mem_root
                 COUNT_ALLOC: 138566
                  COUNT_FREE: 138543
   SUM_NUMBER_OF_BYTES_ALLOC: 2444314336
    SUM_NUMBER_OF_BYTES_FREE: 2443662928
              LOW_COUNT_USED: 0
          CURRENT_COUNT_USED: 23
             HIGH_COUNT_USED: 98
    LOW_NUMBER_OF_BYTES_USED: 0
CURRENT_NUMBER_OF_BYTES_USED: 651408
   HIGH_NUMBER_OF_BYTES_USED: 4075056
*************************** 3. row ***************************
                  EVENT_NAME: memory/sql/Filesort_buffer::sort_keys
                 COUNT_ALLOC: 58869
                  COUNT_FREE: 58868
   SUM_NUMBER_OF_BYTES_ALLOC: 2412676319
    SUM_NUMBER_OF_BYTES_FREE: 2412673879
              LOW_COUNT_USED: 0
          CURRENT_COUNT_USED: 1
             HIGH_COUNT_USED: 13
    LOW_NUMBER_OF_BYTES_USED: 0
CURRENT_NUMBER_OF_BYTES_USED: 2440
   HIGH_NUMBER_OF_BYTES_USED: 491936

上面是前三条记录,显示内存主要被消耗在哪里。

Instruments「memory/innodb/buf_buf_pool」「缓冲池」有关,占用了3GB内存,我们可以从「SUM_NUMBER_OF_BYTES_ALLOC」中获取此信息。另一个对我们来说也很重要的数据是「CURRENT_COUNT_USED」,它告诉我们当前分配了多少数据块,一旦工作完成,这列的值将被修改。查看此记录的统计数据,由于MySQL经常使用缓冲池(例如,在写入数据、加载数据、修改数据时),因此3GB的消耗不是问题。但问题在于你有内存泄漏问题或缓冲池未被使用时。在这种情况下,此Instruments非常有用来进行分析。

查看第二个Instruments「memory/sql/THD::main_mem_root」,它占用了2GB内存,与「sql」有关(这就是我们应该从最左边开始读取的方式)。「THD::main_mem_root」是线程类之一。让我们尝试理解这个Instruments:

「THD」代表线程

「main_mem_root」是mem_root的一个类。MEM_ROOT是一个结构体,用于在解析查询时、执行计划期间、执行嵌套查询/子查询时以及查询执行期间进行其他分配时为线程分配内存。现在,在我们的案例中,我们想检查哪个线程/主机正在消耗内存,以便我们可以进一步优化查询。在进一步深入之前,让我们先了解一下第三个Instruments,这是一个需要关注的重要Instruments。

「memory/sql/filesort_buffer::sort_keys」 – 正如我之前提到的,Instruments名称应从左边开始读取。在这种情况下,它与分配给sql的内存有关。此Instruments的下一个组件是「filesort_buffer::sort_keys」,负责对数据进行排序(它可以是一个缓冲区,其中存储的数据需要排序。此类的各种示例可以是索引创建或普通的ORDER BY子句)

「现在是深入分析的时候了」,分析哪个连接正在使用这些内存。为此,我使用了表「memory_summary_by_host_by_event_name」,并筛选了来自我的应用服务器的记录。

select * from memory_summary_by_host_by_event_name where HOST='172.16.20.141' order by SUM_NUMBER_OF_BYTES_ALLOC desc limit 2 \G

*************************** 1. row ***************************
                        HOST: 172.16.20.141
                  EVENT_NAME: memory/sql/THD::main_mem_root
                 COUNT_ALLOC: 73817
                  COUNT_FREE: 73810
   SUM_NUMBER_OF_BYTES_ALLOC: 1300244144
    SUM_NUMBER_OF_BYTES_FREE: 1300114784
              LOW_COUNT_USED: 0
          CURRENT_COUNT_USED: 7
             HIGH_COUNT_USED: 39
    LOW_NUMBER_OF_BYTES_USED: 0
CURRENT_NUMBER_OF_BYTES_USED: 129360
   HIGH_NUMBER_OF_BYTES_USED: 667744
*************************** 2. row ***************************
                        HOST: 172.16.20.141
                  EVENT_NAME: memory/sql/Filesort_buffer::sort_keys
                 COUNT_ALLOC: 31318
                  COUNT_FREE: 31318
   SUM_NUMBER_OF_BYTES_ALLOC: 1283771072
    SUM_NUMBER_OF_BYTES_FREE: 1283771072
              LOW_COUNT_USED: 0
          CURRENT_COUNT_USED: 0
             HIGH_COUNT_USED: 8
    LOW_NUMBER_OF_BYTES_USED: 0
CURRENT_NUMBER_OF_BYTES_USED: 0
   HIGH_NUMBER_OF_BYTES_USED: 327936

事件名称「memory/sql/THD::main_mem_root」已由主机「172.16.20.141」(这是我在执行此查询时的应用主机)消耗了超过1GB的内存(总和)。现在,既然我们知道这个主机在消耗内存,我们可以进一步深入查找嵌套或子查询之类的查询,然后尝试优化它。

同样,如果我们看到「filesort_buffer::sort_keys」分配的内存在执行时也是超过1GB(总和)。这样的Instruments提醒我们查看使用排序的任何查询,即ORDER BY子句。

连接所有点的时间

让我们尝试找出某些情况下文件排序占用了大部分内存的罪魁祸首线程。「第一个」查询帮助我们找到主机和事件名称(Instruments):

select * from memory_summary_by_host_by_event_name order by SUM_NUMBER_OF_BYTES_ALLOC desc limit 1 \G
*************************** 1. row ***************************
                        HOST: 172.16.4.152
                  EVENT_NAME: memory/sql/Filesort_buffer::sort_keys
                 COUNT_ALLOC: 5617297
                  COUNT_FREE: 5617297
   SUM_NUMBER_OF_BYTES_ALLOC: 193386762784
    SUM_NUMBER_OF_BYTES_FREE: 193386762784
              LOW_COUNT_USED: 0
          CURRENT_COUNT_USED: 0
             HIGH_COUNT_USED: 20
    LOW_NUMBER_OF_BYTES_USED: 0
CURRENT_NUMBER_OF_BYTES_USED: 0
   HIGH_NUMBER_OF_BYTES_USED: 819840
   
select * from memory_summary_by_account_by_event_name where HOST='172.16.4.152' order by SUM_NUMBER_OF_BYTES_ALLOC desc limit 1 \G
*************************** 1. row ***************************
                        USER: sbuser
                        HOST: 172.16.4.152
                  EVENT_NAME: memory/sql/Filesort_buffer::sort_keys
                 COUNT_ALLOC: 5612993
                  COUNT_FREE: 5612993
   SUM_NUMBER_OF_BYTES_ALLOC: 193239513120
    SUM_NUMBER_OF_BYTES_FREE: 193239513120
              LOW_COUNT_USED: 0
          CURRENT_COUNT_USED: 0
             HIGH_COUNT_USED: 20
    LOW_NUMBER_OF_BYTES_USED: 0
CURRENT_NUMBER_OF_BYTES_USED: 0
   HIGH_NUMBER_OF_BYTES_USED: 819840
   
select * from memory_summary_by_thread_by_event_name where EVENT_NAME='memory/sql/Filesort_buffer::sort_keys' order by SUM_NUMBER_OF_BYTES_ALLOC desc limit 1 \G
*************************** 1. row ***************************
                   THREAD_ID: 84
                  EVENT_NAME: memory/sql/Filesort_buffer::sort_keys
                 COUNT_ALLOC: 565645
                  COUNT_FREE: 565645
   SUM_NUMBER_OF_BYTES_ALLOC: 19475083680
    SUM_NUMBER_OF_BYTES_FREE: 19475083680
              LOW_COUNT_USED: 0
          CURRENT_COUNT_USED: 0
             HIGH_COUNT_USED: 2
    LOW_NUMBER_OF_BYTES_USED: 0
CURRENT_NUMBER_OF_BYTES_USED: 0
   HIGH_NUMBER_OF_BYTES_USED: 81984


现在,我们已经掌握了用户及其线程ID的完整详细信息。让我们看看这个线程正在执行哪些类型的查询。

select * from events_statements_history where THREAD_ID=84 order by SORT_SCAN desc \G
*************************** 1. row ***************************
              THREAD_ID: 84
               EVENT_ID: 48091828
           END_EVENT_ID: 48091833
             EVENT_NAME: statement/sql/select
                 SOURCE: init_net_server_extension.cc:95
            TIMER_START: 145083499054314000
              TIMER_END: 145083499243093000
             TIMER_WAIT: 188779000
              LOCK_TIME: 1000000
               SQL_TEXT: SELECT c FROM sbtest2 WHERE id BETWEEN 5744223 AND 5744322 ORDER BY c
                 DIGEST: 4f764af1c0d6e44e4666e887d454a241a09ac8c4df9d5c2479f08b00e4b9b80d
            DIGEST_TEXT: SELECT `c` FROM `sbtest2` WHERE `id` BETWEEN ? AND ? ORDER BY `c`
         CURRENT_SCHEMA: sysbench
            OBJECT_TYPE: NULL
          OBJECT_SCHEMA: NULL
            OBJECT_NAME: NULL
  OBJECT_INSTANCE_BEGIN: NULL
            MYSQL_ERRNO: 0
      RETURNED_SQLSTATE: NULL
           MESSAGE_TEXT: NULL
                 ERRORS: 0
               WARNINGS: 0
          ROWS_AFFECTED: 0
              ROWS_SENT: 14
          ROWS_EXAMINED: 28
CREATED_TMP_DISK_TABLES: 0
     CREATED_TMP_TABLES: 0
       SELECT_FULL_JOIN: 0
 SELECT_FULL_RANGE_JOIN: 0
           SELECT_RANGE: 1
     SELECT_RANGE_CHECK: 0
            SELECT_SCAN: 0
      SORT_MERGE_PASSES: 0
         SORT_RANGE: 0
              SORT_ROWS: 14
          SORT_SCAN: 1
          NO_INDEX_USED: 0
     NO_GOOD_INDEX_USED: 0
       NESTING_EVENT_ID: NULL
     NESTING_EVENT_TYPE: NULL
    NESTING_EVENT_LEVEL: 0
           STATEMENT_ID: 49021382
               CPU_TIME: 185100000
       EXECUTION_ENGINE: PRIMARY

我只粘贴了一个按rows_scan(指表扫描)排序的记录,但你可以在你的案例中找到类似的其他查询,然后尝试通过创建索引或其他适当的解决方案来优化它。

「示例二」

让我们试着找出表锁的情况,即哪个锁,即读锁、写锁等,已被放置在用户表上,以及持续时间(以皮秒为单位)。

用写锁锁定表:

mysql> lock tables sbtest2 write;

Query OK, 0 rows affected (0.00 sec)

mysql> show processlist;
+----+--------+---------------------+--------------------+-------------+--------+-----------------------------------------------------------------+------------------+-----------+-----------+---------------+
| Id | User   | Host                | db                 | Command     | Time   | State                                                           | Info             | Time_ms   | Rows_sent | Rows_examined |
+----+--------+---------------------+--------------------+-------------+--------+-----------------------------------------------------------------+------------------+-----------+-----------+---------------+
|  8 | repl   | 172.16.39.171:53860 | NULL               | Binlog Dump | 421999 | Source has sent all binlog to replica; waiting for more updates | NULL             | 421998368 |         0 |             0 |
|  9 | repl   | 172.16.23.98:51212  | NULL               | Binlog Dump | 421998 | Source has sent all binlog to replica; waiting for more updates | NULL             | 421998262 |         0 |             0 |
| 25 | sbuser | 172.16.4.152:38060  | sysbench           | Sleep       |  65223 |                                                                 | NULL             |  65222573 |         0 |             1 |
| 26 | sbuser | 172.16.4.152:38080  | sysbench           | Sleep       |  65222 |                                                                 | NULL             |  65222177 |         0 |             1 |
| 27 | sbuser | 172.16.4.152:38090  | sysbench           | Sleep       |  65223 |                                                                 | NULL             |  65222438 |         0 |             0 |
| 28 | sbuser | 172.16.4.152:38096  | sysbench           | Sleep       |  65223 |                                                                 | NULL             |  65222489 |         0 |             1 |
| 29 | sbuser | 172.16.4.152:38068  | sysbench           | Sleep       |  65223 |                                                                 | NULL             |  65222527 |         0 |             1 |
| 45 | root   | localhost           | performance_schema | Sleep       |   7722 |                                                                 | NULL             |   7722009 |        40 |           348 |
| 46 | root   | localhost           | performance_schema | Sleep       |   6266 |                                                                 | NULL             |   6265800 |        16 |          1269 |
| 47 | root   | localhost           | performance_schema | Sleep       |   4904 |                                                                 | NULL             |   4903622 |         0 |            23 |
| 48 | root   | localhost           | performance_schema | Sleep       |   1777 |                                                                 | NULL             |   1776860 |         0 |             0 |
| 54 | root   | localhost           | sysbench           | Sleep       |    689 |                                                                 | NULL             |    688740 |         0 |             1 |
| 58 | root   | localhost           | NULL               | Sleep       |     44 |                                                                 | NULL             |     44263 |         1 |             1 |
| 59 | root   | localhost           | sysbench           | Query       |      0 | init                                                            | show processlist |         0 |         0 |             0 |
+----+--------+---------------------+--------------------+-------------+--------+-----------------------------------------------------------------+------------------+-


现在,假设一个情况,你不知道这个会话,你正试图读取这个表,因此等待元数据锁。在这种情况下,我们需要借助于与锁相关的Instruments(找出哪个会话正在锁定这个表)即wait/table/lock/sql/handler
(table_handles是负责表锁Instruments的表):

mysql> select * from table_handles where object_name='sbtest2' and OWNER_THREAD_ID is not null;

+-------------+---------------+-------------+-----------------------+-----------------+----------------+---------------+----------------+
| OBJECT_TYPE | OBJECT_SCHEMA | OBJECT_NAME | OBJECT_INSTANCE_BEGIN | OWNER_THREAD_ID | OWNER_EVENT_ID | INTERNAL_LOCK | EXTERNAL_LOCK  |
+-------------+---------------+-------------+-----------------------+-----------------+----------------+---------------+----------------+
| TABLE       | sysbench      | sbtest2     |       140087472317648 |             141 |             77 | NULL          | WRITE EXTERNAL |
+-------------+---------------+-------------+-----------------------+-----------------+----------------+---------------+----------------+
mysql> select * from metadata_locks;
+---------------+--------------------+------------------+-------------+-----------------------+----------------------+---------------+-------------+-------------------+-----------------+----------------+
| OBJECT_TYPE   | OBJECT_SCHEMA      | OBJECT_NAME      | COLUMN_NAME | OBJECT_INSTANCE_BEGIN | LOCK_TYPE            | LOCK_DURATION | LOCK_STATUS | SOURCE            | OWNER_THREAD_ID | OWNER_EVENT_ID |
+---------------+--------------------+------------------+-------------+-----------------------+----------------------+---------------+-------------+-------------------+-----------------+----------------+
| GLOBAL        | NULL               | NULL             | NULL        |       140087472151024 | INTENTION_EXCLUSIVE  | STATEMENT     | GRANTED     | sql_base.cc:5534  |             141 |             77 |
| SCHEMA        | sysbench           | NULL             | NULL        |       140087472076832 | INTENTION_EXCLUSIVE  | TRANSACTION   | GRANTED     | sql_base.cc:5521  |             141 |             77 |
| TABLE         | sysbench           | sbtest2          | NULL        |       140087471957616 | SHARED_NO_READ_WRITE | TRANSACTION   | GRANTED     | sql_parse.cc:6295 |             141 |             77 |
| BACKUP TABLES | NULL               | NULL             | NULL        |       140087472077120 | INTENTION_EXCLUSIVE  | STATEMENT     | GRANTED     | lock.cc:1259      |             141 |             77 |
| TABLESPACE    | NULL               | sysbench/sbtest2 | NULL        |       140087471954800 | INTENTION_EXCLUSIVE  | TRANSACTION   | GRANTED     | lock.cc:812       |             141 |             77 |
| TABLE         | sysbench           | sbtest2          | NULL        |       140087673437920 | SHARED_READ          | TRANSACTION   | PENDING     | sql_parse.cc:6295 |             142 |             77 |
| TABLE         | performance_schema | metadata_locks   | NULL        |       140088117153152 | SHARED_READ          | TRANSACTION   | GRANTED     | sql_parse.cc:6295 |             143 |            970 |
| TABLE         | sysbench           | sbtest1          | NULL        |       140087543861792 | SHARED_WRITE         | TRANSACTION   | GRANTED     | sql_parse.cc:6295 |             132 |            156 |
+---------------+--------------------+------------------+-------------+-----------------------+----------------------+---------------+-------------+-------------------+-----------------+----------------+


从这里我们知道线程ID 141持有锁“「SHARED_NO_READ_WRITE」”在「sbtest2」上,因此我们可以采取纠正措施,即一旦我们意识到其需求,就提交会话或终止它。我们需要从线程表中找到相应的processlist_id以终止它。

mysql> kill 63;

Query OK, 0 rows affected (0.00 sec)

mysql> select * from table_handles where object_name='sbtest2' and OWNER_THREAD_ID is not null;

Empty set (0.00 sec)

「示例三」

在某些情况下,我们需要找出我们的MySQL服务器大部分时间在等待什么,以便我们采取进一步措施:

mysql> select * from events_waits_history order by TIMER_WAIT desc limit 2 \G
*************************** 1. row ***************************
            THREAD_ID: 88
             EVENT_ID: 124481038
         END_EVENT_ID: 124481038
           EVENT_NAME: wait/io/file/sql/binlog
               SOURCE: mf_iocache.cc:1694
          TIMER_START: 356793339225677600
            TIMER_END: 420519408945931200
           TIMER_WAIT: 63726069720253600
                SPINS: NULL
        OBJECT_SCHEMA: NULL
          OBJECT_NAME: /var/lib/mysql/mysqld-bin.000009
           INDEX_NAME: NULL
          OBJECT_TYPE: FILE
OBJECT_INSTANCE_BEGIN: 140092364472192
     NESTING_EVENT_ID: 124481033
   NESTING_EVENT_TYPE: STATEMENT
            OPERATION: write
      NUMBER_OF_BYTES: 683
                FLAGS: NULL
*************************** 2. row ***************************
            THREAD_ID: 142
             EVENT_ID: 77
         END_EVENT_ID: 77
           EVENT_NAME: wait/lock/metadata/sql/mdl
               SOURCE: mdl.cc:3443
          TIMER_START: 424714091048155200
            TIMER_END: 426449252955162400
           TIMER_WAIT: 1735161907007200
                SPINS: NULL
        OBJECT_SCHEMA: sysbench
          OBJECT_NAME: sbtest2
           INDEX_NAME: NULL
          OBJECT_TYPE: TABLE
OBJECT_INSTANCE_BEGIN: 140087673437920
     NESTING_EVENT_ID: 76
   NESTING_EVENT_TYPE: STATEMENT
            OPERATION: metadata lock
      NUMBER_OF_BYTES: NULL
                FLAGS: NULL
2 rows in set (0.00 sec)

在上面的示例中,「binlog文件」等待了大部分时间(timer_wait以皮秒为单位)来执行IO操作到「mysqld-bin.000009」中。这可能是由于多种原因,例如存储已满。

关于「performance schema」,大家可以贴评论区一起讨论学习。

「欢迎关注我们的公众号,获取更多技术分享与经验交流。」


文章转载自数据库驾驶舱,如果涉嫌侵权,请发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论