mysqlbinlog:MySQLバイナリログの読み方と分析ガイド — 障害調査とデータベース監査の実践

MySQL tutorial - IT technology blog
MySQL tutorial - IT technology blog

5分ですぐに始める

production DBのordersテーブルから3万行が消えた際、原因を突き止めるのに2時間近くかかりました — コードのバグではなく、誰かがWHERE句なしでDELETEを実行してしまったのです。その日を境に、バイナリログとmysqlbinlogの真の価値を実感しました。

まず、バイナリログが有効になっているか確認しましょう:

mysql -u root -p -e "SHOW VARIABLES LIKE 'log_bin';"

結果がValue = ONであれば準備完了です。OFFの場合は、MySQLの設定ファイルに以下の行を追加してから再起動してください:

# /etc/mysql/mysql.conf.d/mysqld.cnf (Ubuntu/Debian)
# /etc/my.cnf.d/mysql-server.cnf (CentOS/RHEL)
[mysqld]
log_bin             = /var/lib/mysql/mysql-bin
binlog_format       = ROW
binlog_row_image    = FULL
server_id           = 1
binlog_expire_logs_seconds = 1209600   # 14日間
max_binlog_size     = 100M

現在のbinlogファイル一覧を確認する:

mysql -u root -p -e "SHOW BINARY LOGS;"
# +------------------+-----------+-----------+
# | Log_name         | File_size | Encrypted |
# +------------------+-----------+-----------+
# | mysql-bin.000001 |    524288 | No        |
# | mysql-bin.000002 |   1048576 | No        |
# +------------------+-----------+-----------+

最新のbinlogファイルの内容を読み込む:

mysqlbinlog /var/lib/mysql/mysql-bin.000002

これだけで、データベースで発生したすべての変更を確認できます。

binlog_formatを理解する:なぜROWを選ぶのか

binlogの記録モードは3種類あり、決定する前にすべて試しました:

  • STATEMENT:元のSQL文を記録します — コンパクトですが、リプレイ時にリスクがあります。NOW()UUID()RAND()などの関数は、再実行時に異なる値を返す可能性があります。
  • ROW:実際に変更された各行のデータ(before/after image)を記録します。最も安全で、production環境での私の選択です。
  • MIXED:単純なSQL文にはSTATEMENT、必要に応じてROWに自動切り替えします — 読み取りが多い環境では合理的な妥協案です。

私のproductionデータベースはMySQL 8.0で約50GBのデータを扱っています。binlog_format = ROWbinlog_row_image = FULLを設定して、before/after imageを完全にキャプチャしています。ディスク使用量は増えますが、調査が必要なときに情報が充実しています。

最もよく使うmysqlbinlogコマンド

時間範囲でフィルタリング

最もよくあるユースケースです — 障害発生時刻がわかっている場合、その時間帯に絞り込みます:

mysqlbinlog \
  --start-datetime="2026-06-17 14:00:00" \
  --stop-datetime="2026-06-17 14:30:00" \
  /var/lib/mysql/mysql-bin.000005

特定のデータベースでフィルタリング

mysqlbinlog --database=myapp_db /var/lib/mysql/mysql-bin.000005

ROWフォーマットを人間が読める形式で表示

binlog ROWフォーマットはデフォルトでデータをbase64エンコードするため、目視では読めません。2つのフラグを追加する必要があります:

mysqlbinlog --base64-output=DECODE-ROWS -v \
  /var/lib/mysql/mysql-bin.000005

出力には各行のbefore/after値が表示されます:

### UPDATE `myapp_db`.`orders`
### WHERE
###   @1=1234        /* id */
###   @2='pending'   /* status */
###   @3='2026-06-17 10:00:00' /* updated_at */
### SET
###   @1=1234
###   @2='completed'
###   @3='2026-06-17 14:17:05'

複数のbinlogファイルを連続して読み込む

mysqlbinlog --base64-output=DECODE-ROWS -v \
  /var/lib/mysql/mysql-bin.000003 \
  /var/lib/mysql/mysql-bin.000004 \
  /var/lib/mysql/mysql-bin.000005

リモートサーバーからbinlogを読み込む

mysqlbinlog --read-from-remote-server \
  --host=192.168.1.100 \
  --user=repl_user \
  --password \
  --database=myapp_db \
  mysql-bin.000005

実践的な活用:障害調査とPoint-in-Time Recovery

シナリオ1 — データを削除したのは誰か

シナリオ:productsテーブルから500行が15:30頃に消えました。調査の流れは以下の通りです:

# ステップ1: その時間帯を含むbinlogファイルを特定する
mysql -u root -p -e "SHOW BINARY LOGS;"

# ステップ2: テキストファイルに出力してgrepで検索しやすくする
mysqlbinlog --base64-output=DECODE-ROWS -v \
  --start-datetime="2026-06-17 15:25:00" \
  --stop-datetime="2026-06-17 15:35:00" \
  /var/lib/mysql/mysql-bin.000005 > /tmp/incident_15h.sql

# ステップ3: productsテーブルのDELETEを検索する
grep -i "DELETE.*products" /tmp/incident_15h.sql -A 5

SHOW PROCESSLISTログやgeneral query log(有効な場合)と組み合わせることで、そのコマンドを実行したセッションを特定できます。

シナリオ2 — Point-in-Time Recovery (PITR)

これはまさに私がordersテーブルから誤って削除された3万行を復元するために実施した手順です。フローは2つのステップで構成されます:

  1. 直近のバックアップを復元する(午前3時のバックアップ)
  2. mysqlbinlogを使ってバックアップ後から致命的なDELETE直前までのbinlogをリプレイする
# DELETEのpositionを特定して停止ポイントを確認する
mysqlbinlog --base64-output=DECODE-ROWS -v \
  /var/lib/mysql/mysql-bin.000005 | grep -B 10 "DELETE FROM orders" | head -30

# 出力は次の形式で表示される:# at 1234567
# これが停止すべきpositionです

# バックアップ後からそのposition直前までをリプレイする
mysqlbinlog \
  --start-datetime="2026-06-17 03:00:05" \
  --stop-position=1234567 \
  /var/lib/mysql/mysql-bin.000005 | mysql -u root -p myapp_db

重要なヒント:危険な操作(bulk delete、schema migrationなど)を行う前に、必ずSHOW MASTER STATUSを実行してFileとPositionを記録しておきましょう。これが問題発生時のロールバックポイントになります。

mysql -u root -p -e "SHOW MASTER STATUS\G"
# *************************** 1. row ***************************
#              File: mysql-bin.000005
#          Position: 1189432
#      Binlog_Do_DB:
#  Binlog_Ignore_DB:

シナリオ3 — 日次データベース活動の監査

# 当日のすべての変更をファイルに出力する
mysqlbinlog --base64-output=DECODE-ROWS -v \
  --start-datetime="2026-06-17 00:00:00" \
  --stop-datetime="2026-06-17 23:59:59" \
  /var/lib/mysql/mysql-bin.000005 > audit_20260617.sql

# UPDATE/DELETE/INSERTの回数をカウントする
echo "INSERT count: $(grep -c '^### INSERT' audit_20260617.sql)"
echo "UPDATE count: $(grep -c '^### UPDATE' audit_20260617.sql)"
echo "DELETE count: $(grep -c '^### DELETE' audit_20260617.sql)"

応用:自動化とbinlog暗号化

大量DELETEを検出するアラートスクリプト

このスクリプトをcronで毎時実行し、大量の行が削除された場合にアラートを送信します:

#!/bin/bash
# /opt/scripts/check_large_deletes.sh

MYSQL_PASS="your_password"
THRESHOLD=500
BINLOG_PATH="/var/lib/mysql"

CURRENT_FILE=$(mysql -u root -p"$MYSQL_PASS" -Nse "SELECT @@log_bin_basename;" 2>/dev/null)
LATEST=$(ls -t ${CURRENT_FILE}.* 2>/dev/null | head -1)

[ -z "$LATEST" ] && exit 0

DELETE_COUNT=$(mysqlbinlog --base64-output=DECODE-ROWS -v \
  --start-datetime="$(date -d '1 hour ago' '+%Y-%m-%d %H:%M:%S')" \
  "$LATEST" 2>/dev/null | grep -c '^### DELETE')

if [ "$DELETE_COUNT" -gt "$THRESHOLD" ]; then
  echo "[ALERT] 過去1時間で $DELETE_COUNT 件の DELETE イベントが $(hostname) で検出されました" | \
    mail -s "MySQL Binlog Alert" [email protected]
fi

MySQL 8.0.14+でのbinlog暗号化

binlog_encryption = ONを有効にすると、ディスク上のbinlogファイルを直接読み込むことができなくなります。サーバーを経由して接続する必要があります:

mysqlbinlog --read-from-remote-server \
  --host=127.0.0.1 \
  --user=root \
  --password \
  --base64-output=DECODE-ROWS -v \
  mysql-bin.000005

productionで6ヶ月使って得た実践的なヒント

  • binlogの保持期間を適切に設定する:私は14日間に設定しています — 調査には十分で、ディスクを使いすぎません。50GBのデータでは、トラフィックによって1日あたり1〜2GBのbinlogが生成されます。
  • 全体を読む代わりにpositionでフィルタリングする:binlogファイルが500MBを超える場合、--start-position--stop-positionを使うと、全体を読んでgrepするよりはるかに高速です。
  • mysqlbinlogはMySQLユーザーを記録しない:binlogは何が変更されたかを記録しますが、誰がログインしたかは記録しません。特定のユーザーの監査を行うには、MySQL Audit Log PluginまたはGeneral_logを追加で有効にする必要があります。
  • まずテスト環境でbinlogをリプレイする:PITRを実施する際は、必ずデータベースのコピーで先にテストしてください — 検証なしにproductionへbinlogをリプレイすると、重複やconflictが発生する可能性があります。
  • pt-query-digestと組み合わせるPercona Toolkitのこのツールはbinlogを読み込んでクエリパターンを集計できます — 週次監査レポートに役立ちます。

約50GBのデータを扱うMySQL 8.0のproduction環境を6ヶ月間運用した経験から、私はbinlogを飛行機の「ブラックボックス」のように捉えています — 普段はほとんど必要ありませんが、いざというときには非常に重要です。今のうちにmysqlbinlogに慣れておくことで、実際に障害が発生したときのストレスフルな調査時間を大幅に短縮できます。

Share: