MySQL mysqlbinlogを使用したバイナリログの解析方法

MySQLで意図しないデータが存在した時、いつの時点でどんなSQLが実行されたかを追跡したい事があると思います。

今回はMySQLのバイナリログを解析できるツール mysqlbinlog コマンドの使い方と、バイナリログの見方を紹介します。

サンプルデータの準備

まずバイナリログを分析するために、まずはサンプルデータを用意して、一般的なSQLを流します。

データベース作成 (CREATE DATABASE)

mysql> create database dekien;

テーブル作成 (CREATE TABLE)

mysql> create table dekien.sampletbl (no int, name varchar(30));

データ挿入 (INSERT)

mysql> insert into dekien.sampletbl values (1, 'hogetaro');

データ参照 (SELECT)

mysql> select no,name from dekien.sampletbl;
+------+----------+
| no   | name     |
+------+----------+
|    1 | hogetaro |
+------+----------+

データ更新 (UPDATE)

mysql> update dekien.sampletbl set name = 'fugajiro' where no = 1;

データ削除 (DELETE)

mysql> delete from dekien.sampletbl where no = 1;

全データ削除 (TRUNCATE)

mysql> truncate table dekien.sampletbl;

テーブル削除 (DROP TABLE)

mysql> drop table dekien.sampletbl;

バイナリログの分析

最新のバイナリログを mysqlbinlog コマンドでテキスト化します。

-v オプションを使用すると、UPDATEやDELETEなどのデータ操作DMLをコメント行で出力できます。

※SELECT 等のデータを参照するだけのSQLは、バイナリログには入っていません

[root@cent76 ~]# mysqlbinlog -v /var/lib/mysql/binlog.000001 > /tmp/binlog.txt

出力されるファイルの内容を、SQL毎に記載していきます。いつ・どんなSQLが発行されたかがわかります。

データベース作成 (CREATE DATABASE)

# at 750
#2020118 23:31:46 server id 1  end_log_pos 864 CRC32 0x23ec9df2  Query   thread_id=12    exec_time=0     error_code=0
Xid = 20
SET TIMESTAMP=1579685506/*!*/;
/*!80016 SET @@session.default_table_encryption=0*//*!*/;
create database dekien
/*!*/;

テーブル作成 (CREATE TABLE)

# at 941
#2020118 23:31:49 server id 1  end_log_pos 1083 CRC32 0xdf5ac7ba         Query   thread_id=12    exec_time=2     error_code=0    Xid = 21
SET TIMESTAMP=1579685509/*!*/;
/*!80013 SET @@session.sql_require_primary_key=0*//*!*/;
create table dekien.sampletbl (no int, name varchar(30))
/*!*/;

データ挿入 (INSERT)

# at 1298
#2020118 23:31:54 server id 1  end_log_pos 1347 CRC32 0x434fd9e0         Write_rows: table id 108 flags: STMT_END_F

BINLOG '
ihYoXhMBAAAAQQAAABIFAAAAAGwAAAAAAAEABmRla2llbgAJc2FtcGxldGJsAAIDDwJ4AAMBAQAC
A/z/AO5p20M=
ihYoXh4BAAAAMQAAAEMFAAAAAGwAAAAAAAEAAgAC/wABAAAACGhvZ2V0YXJv4NlPQw==
'/*!*/;
### INSERT INTO `dekien`.`sampletbl`
### SET
###   @1=1
###   @2='hogetaro'

データ参照 (SELECT)

select等のデータが変更されないSQLはバイナリログには出ません。

データ更新 (UPDATE)

# at 1602
#2020118 23:31:57 server id 1  end_log_pos 1666 CRC32 0xac95a5ca         Update_rows: table id 108 flags: STMT_END_F

BINLOG '
jRYoXhMBAAAAQQAAAEIGAAAAAGwAAAAAAAEABmRla2llbgAJc2FtcGxldGJsAAIDDwJ4AAMBAQAC
A/z/ALZTPVM=
jRYoXh8BAAAAQAAAAIIGAAAAAGwAAAAAAAEAAgAC//8AAQAAAAhob2dldGFybwABAAAACGZ1Z2Fq
aXJvyqWVrA==
'/*!*/;
### UPDATE `dekien`.`sampletbl`
### WHERE
###   @1=1
###   @2='hogetaro'
### SET
###   @1=1
###   @2='fugajiro'

データ削除 (DELETE)

# at 1912
#2020118 23:32:00 server id 1  end_log_pos 1961 CRC32 0xdbc23f4a         Delete_rows: table id 108 flags: STMT_END_F

BINLOG '
kBYoXhMBAAAAQQAAAHgHAAAAAGwAAAAAAAEABmRla2llbgAJc2FtcGxldGJsAAIDDwJ4AAMBAQAC
A/z/AAByzXk=
kBYoXiABAAAAMQAAAKkHAAAAAGwAAAAAAAEAAgAC/wABAAAACGZ1Z2FqaXJvSj/C2w==
'/*!*/;
### DELETE FROM `dekien`.`sampletbl`
### WHERE
###   @1=1
###   @2='fugajiro'

全データ削除 (TRUNCATE)

# at 2069
#2020118 23:32:03 server id 1  end_log_pos 2175 CRC32 0xb9939023         Query   thread_id=12    exec_time=1     error_code=0    Xid = 25
SET TIMESTAMP=1579685523/*!*/;
truncate table dekien.sampletbl
/*!*/;

テーブル削除 (DROP TABLE)

# at 2252
#2020118 23:32:06 server id 1  end_log_pos 2393 CRC32 0x3f2b85a3         Query   thread_id=12    exec_time=0     error_code=0    Xid = 26
SET TIMESTAMP=1579685526/*!*/;
SET @@session.pseudo_thread_id=12/*!*/;
DROP TABLE `dekien`.`sampletbl` /* generated by server */