有趣的`events_statements_current`表问题

• GreatSQL社区原创内容未经授权不得随意使用，转载请联系小编并注明来源。
• GreatSQL是MySQL的国产分支版本，使用上与MySQL一致。
• 作者： bruce
• 文章来源：GreatSQL社区原创

什么是events_statements_current表

在MySQL中，PFS下有一张内存表: events_statements_current，看到这个名称"xxx_current"，小白如我可能会认为这张表中的数据就是当前系统的活跃(active)语句。该表的描述如下(有部分省略):

mysql> desc events_statements_current;
+-------------------------+------------------------------------------------+------+-----+---------+-------+
| Field                   | Type                                           | Null | Key | Default | Extra |
+-------------------------+------------------------------------------------+------+-----+---------+-------+
| THREAD_ID               | bigint unsigned                                | NO   | PRI | NULL    |       |
| EVENT_ID                | bigint unsigned                                | NO   | PRI | NULL    |       |
| END_EVENT_ID            | bigint unsigned                                | YES  |     | NULL    |       |
| EVENT_NAME              | varchar(128)                                   | NO   |     | NULL    |       |
| SOURCE                  | varchar(64)                                    | YES  |     | NULL    |       |
| TIMER_START             | bigint unsigned                                | YES  |     | NULL    |       |
| TIMER_END               | bigint unsigned                                | YES  |     | NULL    |       |
| TIMER_WAIT              | bigint unsigned                                | YES  |     | NULL    |       |
| LOCK_TIME               | bigint unsigned                                | NO   |     | NULL    |       |
| SQL_TEXT                | longtext                                       | YES  |     | NULL    |       |
| DIGEST                  | varchar(64)                                    | YES  |     | NULL    |       |
| DIGEST_TEXT             | longtext                                       | YES  |     | NULL    |       |
| CURRENT_SCHEMA          | varchar(64)                                    | YES  |     | NULL    |       |
...
| MYSQL_ERRNO             | int                                            | YES  |     | NULL    |       |
| RETURNED_SQLSTATE       | varchar(5)                                     | YES  |     | NULL    |       |
| MESSAGE_TEXT            | varchar(128)                                   | YES  |     | NULL    |       |
...
+-------------------------+------------------------------------------------+------+-----+---------+-------+
44 rows in set (0.01 sec)

直接使用当前语句表的问题

直接做个小实验，终端1：

SELECT sleep(1);

终端2：

USE performance_schema;

-- 查看最近用户语句
SELECT s.thread_id, s.sql_text FROM events_statements_current s, threads t 
    WHERE s.thread_id = t.thread_id AND t.type = 'FOREGROUND';

输出:

mysql> SELECT s.thread_id, s.sql_text FROM events_statements_current s, threads t WHERE s.thread_id = t.thread_id AND t.type = 'FOREGROUND';
+-----------+--------------------------------------------------------------------------------------------------------------------------------------+
| thread_id | sql_text                                                                                                                             |
+-----------+--------------------------------------------------------------------------------------------------------------------------------------+
|        58 | select sleep(1)                                                                                                                      |
|      1849 | SELECT s.thread_id, s.sql_text FROM events_statements_current s, threads t WHERE s.thread_id = t.thread_id AND t.type = 'FOREGROUND' |
+-----------+--------------------------------------------------------------------------------------------------------------------------------------+
2 rows in set (0.00 sec)

反复执行上述语句，发现终端1当前执行的语句都是：SELECT sleep(1)，看起来有点像BUG呀 。

真的是这样吗? 来细看一下文档的定义：

The events_statements_current table contains current statement events. The table stores one row per thread showing the current status of the thread's most recent monitored statement event, so there is no system variable for configuring the table size.

发现了一些关键信息: "showing the current status of the thread's most recent monitored statement event"，也就是说：保存的是线程最近被检测到的语句事件，并非当前正在处于执行状态的语句

获取当前活跃的语句方法

为了了解这个问题的解决方案，来看看具体实现的代码：

void pfs_end_statement_vc(PSI_statement_locker *locker, void *stmt_da) {
  PSI_statement_locker_state *state =
      reinterpret_cast<PSI_statement_locker_state *>(locker);
  ...
  if (state->m_discarded) {
    return;
  }

  ...
  // storage/perfschema/pfs.cc:6462 
  if (flags & STATE_FLAG_TIMED) {
    timer_end = get_statement_timer();
    wait_time = timer_end - state->m_timer_start;
  }
  ...

  if (flags & STATE_FLAG_THREAD) {
    ...
    if(flags & STATE_FLAG_EVENT) {
      ...
      // storage/perfschema/pfs.cc:6528
      pfs->m_timer_end = timer_end;
      pfs->m_cpu_time = cpu_time;
      pfs->m_end_event_id = thread->m_event_id;
      ...
    }
  }

说明，在语句运行结束的时候，PFS会更新记录：

• m_timer_end 运行结束时间
• m_end_event_id 语句结束事件ID

继续阅读代码，发现除了在：pfs_start_statement_vc中对该值进行初始化外，修改该值的代码仅有这一处，基本可以得出结论：m_timer_end > 0 或 m_end_event_id >0 代表语句运行已经结束。

整个简易工具测一下:

. ./setenv

FOR i IN $(seq 1 1000000)
DO
mysql -h127.0.0.1 -P3306 -uroot <<EOF
USE performance_schema;

-- 打印所有的进行中用户SQL(除了自身)
SELECT s.* FROM events_statements_current s, threads t WHERE s.thread_id = t.thread_id AND t.type = 'FOREGROUND' AND sql_text like '%FOREGROUND%' = FALSE AND s.end_event_id IS NULL \G
EOF
    sleep 0.1 # 每0.1秒跑一下
DONE

运行结果:

*************************** 1. row ***************************
              THREAD_ID: 15082
               EVENT_ID: 127
           END_EVENT_ID: NULL
             EVENT_NAME: statement/sql/select
                 SOURCE: init_net_server_extension.cc:95
            TIMER_START: 19879433851621000
              TIMER_END: 19880288626029000
             TIMER_WAIT: 854774408000
              LOCK_TIME: 0
               SQL_TEXT: select sleep(1), 3
...

将工具SQL替换成

-- 移除原来的 s.end_event_id is NULL
SELECT s.* FROM events_statements_current s, threads t 
    WHERE s.thread_id = t.thread_id AND t.type = 'FOREGROUND' AND sql_text like '%FOREGROUND%' = FALSE AND s.timer_end = 0 \G

再次运行：

## 真的是啥也没有啊，真的是啥也没有啊，

再仔细看看文档 (https://dev.mysql.com/doc/refman/5.7/en/performance-schema-events-statements-current-table.html):

TIMER_START, TIMER_END, TIMER_WAIT

Timing information for the event. The unit for these values is picoseconds (trillionths of a second). 
The TIMER_START and TIMER_END values indicate when event timing started and ended. TIMER_WAIT is the event elapsed time (duration).

If an event has not finished, TIMER_END is the current timer value and TIMER_WAIT is the time elapsed so far (TIMER_END − TIMER_START).

重要信息: 当事件没有完成，TIMER_END会持续参考当前时间更新

与想象的很不一样，无奈打开源码，看看有什么线索

//storage/perfschema/table_events_statements.cc:315(table_events_statements_common)
  if (m_row.m_end_event_id == 0) {
    timer_end = get_statement_timer();
  } else {
    timer_end = statement->m_timer_end;
  }

换句话说：运行未结束时，statement->m_timer_end的值确实是0，但是timer_end赋值用的是语句计时器的当前时间。

测试结论：events_statements_current可以用于描述当前活跃语句，活跃这个条件可以使用：END_EVENT_ID IS NULL来过滤。