前几天，我的一位同事兼朋友 Peter Boros 遇到了一个案例，我们的一位客户不得不追踪关闭 MySQL 的进程。该博客基于我们内部对此进行的讨论。
我们的客户希望彼得找出周期性停机背后的罪魁祸首。事实证明，这比平时稍微困难一些，原因您可能会从本博客的标题中猜到。
这是彼得在日志中看到的内容：
150928 15:15:33 [Note] /usr/sbin/mysqld: Normal shutdown
150928 15:15:36 [Note] Event Scheduler: Purging the queue. 0 events
150928 15:15:39 [Warning] /usr/sbin/mysqld: Forcing close of thread 411515 user: 'dashboard'
150928 15:15:40 InnoDB: Starting shutdown...
150928 15:15:59 InnoDB: Shutdown completed; log sequence number 4873840375
150928 15:16:00 [Note] /usr/sbin/mysqld: Shutdown complete
你们中的一些人可能还记得我写了一篇关于工具的 博客文章 ，这些工具可以帮助您识别向 mysqld 发送信号的其他进程。 Peter 选择了 SystemTap 来追踪进程。他用来追踪它的脚本来自 David Busby 的博客 ：
150928 15:15:33 [Note] /usr/sbin/mysqld: Normal shutdown
150928 15:15:36 [Note] Event Scheduler: Purging the queue. 0 events
150928 15:15:39 [Warning] /usr/sbin/mysqld: Forcing close of thread 411515 user: 'dashboard'
150928 15:15:40 InnoDB: Starting shutdown...
150928 15:15:59 InnoDB: Shutdown completed; log sequence number 4873840375
150928 15:16:00 [Note] /usr/sbin/mysqld: Shutdown complete
使用这个 SystemTap 脚本，Peter 发现“杀手”是 mysqld：
150928 15:15:33 [Note] /usr/sbin/mysqld: Normal shutdown
150928 15:15:36 [Note] Event Scheduler: Purging the queue. 0 events
150928 15:15:39 [Warning] /usr/sbin/mysqld: Forcing close of thread 411515 user: 'dashboard'
150928 15:15:40 InnoDB: Starting shutdown...
150928 15:15:59 InnoDB: Shutdown completed; log sequence number 4873840375
150928 15:16:00 [Note] /usr/sbin/mysqld: Shutdown complete
正如您在上面看到的，mysqld 从 mysqld 收到了一个 SIGTERM。这怎么可能？让我们试着解释一下这里发生了什么！
根据 手册 ，可以通过不同的方式启动服务器关闭。例如：
- SIGTERM 由 UNIX 用户发送到 mysqld
-
服务器由特权 mysql 用户通过
mysqladmin shutdown以管理方式关闭
假设我们正在讨论第一个示例，其中特权进程/脚本向 mysqld 发送 SIGTERM。如果是这样的话，我们会得到：
150928 15:15:33 [Note] /usr/sbin/mysqld: Normal shutdown
150928 15:15:36 [Note] Event Scheduler: Purging the queue. 0 events
150928 15:15:39 [Warning] /usr/sbin/mysqld: Forcing close of thread 411515 user: 'dashboard'
150928 15:15:40 InnoDB: Starting shutdown...
150928 15:15:59 InnoDB: Shutdown completed; log sequence number 4873840375
150928 15:16:00 [Note] /usr/sbin/mysqld: Shutdown complete
150928 15:15:33 [Note] /usr/sbin/mysqld: Normal shutdown
150928 15:15:36 [Note] Event Scheduler: Purging the queue. 0 events
150928 15:15:39 [Warning] /usr/sbin/mysqld: Forcing close of thread 411515 user: 'dashboard'
150928 15:15:40 InnoDB: Starting shutdown...
150928 15:15:59 InnoDB: Shutdown completed; log sequence number 4873840375
150928 15:16:00 [Note] /usr/sbin/mysqld: Shutdown complete
上面输出中的第一行显示了向 MySQL 发出 TERM 信号的客户端进程 (bash)。作为响应，MySQL 启动了一个信号处理程序线程并使用该线程处理关闭 ( COM_SHUTDOWN )。反过来，引用的函数 kill_mysqld() 可以代表启动进程向 current_pid 发送信号。
作为旁注，在上面的输出中您看不到任何与线程相关的内容。如果您要修改 tapscript 以包含 tgkill 系统调用并显示相关的线程 ID，您可以获得有关 MySQL 操作的更多详细信息：
150928 15:15:33 [Note] /usr/sbin/mysqld: Normal shutdown
150928 15:15:36 [Note] Event Scheduler: Purging the queue. 0 events
150928 15:15:39 [Warning] /usr/sbin/mysqld: Forcing close of thread 411515 user: 'dashboard'
150928 15:15:40 InnoDB: Starting shutdown...
150928 15:15:59 InnoDB: Shutdown completed; log sequence number 4873840375
150928 15:16:00 [Note] /usr/sbin/mysqld: Shutdown complete
虽然这可能有助于更好地理解 mysqld 的行为方式，但它与我们搜索罪魁祸首进程无关，因此我不打算在此处包含该脚本的输出 - 亲爱的读者，这个练习将留给您！
现在，如果具有管理权限的 MySQL 用户改为通过控制台启动关闭，会发生什么情况？我们得到：
150928 15:15:33 [Note] /usr/sbin/mysqld: Normal shutdown
150928 15:15:36 [Note] Event Scheduler: Purging the queue. 0 events
150928 15:15:39 [Warning] /usr/sbin/mysqld: Forcing close of thread 411515 user: 'dashboard'
150928 15:15:40 InnoDB: Starting shutdown...
150928 15:15:59 InnoDB: Shutdown completed; log sequence number 4873840375
150928 15:16:00 [Note] /usr/sbin/mysqld: Shutdown complete
150928 15:15:33 [Note] /usr/sbin/mysqld: Normal shutdown
150928 15:15:36 [Note] Event Scheduler: Purging the queue. 0 events
150928 15:15:39 [Warning] /usr/sbin/mysqld: Forcing close of thread 411515 user: 'dashboard'
150928 15:15:40 InnoDB: Starting shutdown...
150928 15:15:59 InnoDB: Shutdown completed; log sequence number 4873840375
150928 15:16:00 [Note] /usr/sbin/mysqld: Shutdown complete
您会看到这次发件人是 mysqld，这与 Peter 的原始输出非常相似。因此，我们现在知道我们正在寻找的是一个名为
mysqladmin shutdown
的程序！
不幸的是，这意味着该程序可能不是本地的，并且客户端可以从不同的主机连接。本地递归 grep 可能会也可能不会解决我们的问题。但是，如果我们使用 log-warnings=2 启用 general-log，它可能会产生如下结果：
150928 15:15:33 [Note] /usr/sbin/mysqld: Normal shutdown
150928 15:15:36 [Note] Event Scheduler: Purging the queue. 0 events
150928 15:15:39 [Warning] /usr/sbin/mysqld: Forcing close of thread 411515 user: 'dashboard'
150928 15:15:40 InnoDB: Starting shutdown...
150928 15:15:59 InnoDB: Shutdown completed; log sequence number 4873840375
150928 15:16:00 [Note] /usr/sbin/mysqld: Shutdown complete
因此，我们现在知道在哪里为流氓
mysqladmin shutdown
（或类似的 API-leveraging）进程运行我们的递归 grep！在我的例子中，它在远程主机 192.168.3.1 上运行，并以 MySQL 用户“robert”的身份连接。
当然，您可以找到其他方法来跟踪 MySQL 连接，但这超出了我打算包含在本博客中的范围。也许在下一个？
Robert 于 2014 年加入 Percona 美国咨询团队。他是开源和所有 IT 事物的狂热粉丝。在加入 Percona 之前，他曾在一家财富 500 强制造公司担任过各种职务，最近担任基础设施架构师/工程师。他来自欧洲，匈牙利，他曾在那里担任讲师，并在欧洲教授各种 Sun Microsystems 课程。罗伯特有一定的学术背景，他曾经管理过他以前的部门和宿舍的网络服务。在他不在电脑前的那些罕见的时间里，他会花时间与家人在一起或玩他的遥控设备。