誰動了我的MySQL？

背景介紹

前兩天，一位開發的小夥伴找到我，向我反饋了這樣一個問題：

一個 PHP 的常駐程式的任務，會定時執行一條更新 MySQL 資料的操作。由於這裡的邏輯處理有問題，他已經把執行更新的操作註釋了，然後更新了程式碼，並重啟了程式（注：常駐程式更新程式碼後需要重啟程式才會生效）。但是發現這條更新操作還是會定時執行，很明顯還有沒有重啟的程式仍在呼叫之前的邏輯。但是應該如何定位到是哪臺機器的程式執行的呢？

分析定位

我們先來梳理下這個業務場景的架構關係，如下圖所示：

如上圖所示，現在需要定位到是哪一個常駐程式執行了這條更新的 SQL。

因為常駐程式可能存在於不同的機器上，所以我們首先要定位到這條 SQL 是哪個在哪個機器上呼叫的，定位到機器以後再來定位是哪個程式執行的。

我們都知道，MySQL的 binlog 記錄了 MySQL 的執行過的語句，常用於資料恢復和問題定位，這裡我們看能不能透過 binlog 找到一些和執行 SQL 相關的客戶端資訊。

首先我們需要確認是否開啟了 binlog，在 MySQL 控制檯執行以下語句：

SHOW VARIABLES LIKE 'log_bin';

結果如下：

可以看到，現在 binlog 狀態是開啟的，如果沒有開啟的話，可以使用以下命令開啟：

SET GLOBAL general_log = ON;

然後我們需要確定 binlog 檔案的位置，執行以下語句：

SHOW MASTER STATUS;

結果如下：

這條語句可以查到 binlog 的檔名稱，還需要透過以下語句查詢到 binlog 的完整路徑：

SHOW VARIABLES LIKE 'log_bin_basename';

結果如下：

因為我們的 MySQL 是安裝在伺服器上的，所以可以直接在伺服器上進行分析 binlog。直接使用文字檢視工具開啟 binlog 的話是一堆亂碼，這是因為 binlog 本身是以二進位制檔案儲存的，所以需要透過其他工具處理以後檢視，這裡我們使用 MySQL 自帶的 mysqlbinlog 進行處理。

使用 mysqlbinlog 命令將反編譯以後的內容輸出到一個文字檔案中：

/usr/local/mysql/bin/mysqlbinlog /usr/local/mysql/var/mysql-bin.000030  > ~/binlog.txt

說明：mysqlbinlog 客戶端一般安裝在 MySQL 的命令目錄下。

檢視檔案，按照關鍵字搜尋到 SQL 執行到相關資訊：

cat ~/binlog.txt | grep -B5 '{keyword}'  | tail -5

輸出結果如下：

這裡可以看到執行 SQL 的執行緒ID（thread_id）是 116，根據這個線索，我們可以查詢到這個執行緒執行到相關資訊，使用如下語句：

SELECT
    `HOST`
FROM
    `information_schema`.`PROCESSLIST`
WHERE
    `id` = {thread_id}

查詢到的結果如下（這裡只關注客戶端連線資訊即可）：

透過 HOST 欄位我們可以定位到連線客戶端的 IP 和 埠號，到這裡，我們已經看到勝利的曙光了。接下來我們只要看一下這個埠被哪個程式佔用就可以了。

登入到目標伺服器（這裡是 localhost 是指 MySQL 本地伺服器），使用以下命令檢視佔用埠號的程式：

lsof -i:埠號

輸出結果如下：

從結果可以看出是 22617 這個程式建立的 MySQL 連線並執行了這條更新，可以透過以下命令檢視程式的相關資訊：

ps -p {pid} -f

輸出結果如下：

根據程式的啟動時間可以分析出來，這個程式沒有重啟或關閉，導致一直執行之前的程式碼邏輯。直接 kill 掉這個程式，發現資料不會被更新了，恢復正常。

總結

透過這個例子，我們可以總結到以下經驗：

• 透過 binlog 可以定位到執行 SQL 的執行緒相關資訊；
• 透過 PROCESSLIST 表可以定位到執行緒的基本資訊，包括連線客戶端的 IP 和 埠號；
• 結合 lsof、netstat 和 ps 等程式相關的命令，可以定位到具體的程式資訊，從而找到問題的根本。

本作品採用《CC 協議》，轉載必須註明作者和本文連結