データが主食

データエンジニアの備忘録。分析だったり、読んだ本のメモだったり。

MySQLのbinlogを眺めてみた

binlogとは

MySQLでは、データの更新があった際にbinlogを出力します。 このログデータを活用する事で、ロールフォワードができたりします。 日常的に使うことはないので、コマンドの使い方などを備忘録的にまとめてみました。

MySQLの起動

my.cnf

[mysqld]
server-id=1
log-bin=/var/log/mysql/bin-log
docker run \
  --rm \
  -e MYSQL_ROOT_PASSWORD=password \
  -e MYSQL_DATABASE=my_db \
  -p 33061:3306 \
  -v /path/to/my.cnf:/etc/mysql/conf.d/my.cnf \
  --name mysql-bin \
  mysql:5.7

SQLの実行

mysql -uroot -ppassword -P 33061 -h 127.0.0.1 my_db

で接続した上で下記のSQLを実行します。

CREATE TABLE test_table(test_column integer);

INSERT INTO test_table values(1);

UPDATE test_table SET test_column = 2 WHERE test_column = 1;

DELETE FROM test_table where test_column = 2;

mysqlbinlogの実行

mysqlbinlog というコマンドを実行することでbinlogの中身を閲覧できます。

$ docker exec -it mysql-bin /bin/bash
# mysqlbinlog -v --base64-output=DECODE-ROWS /var/log/mysql/bin-log.000003
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#200425 10:58:04 server id 1  end_log_pos 123 CRC32 0xa8077c0c  Start: binlog v 4, server v 5.7.29-log created 200425 10:58:04 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
# at 123
#200425 10:58:04 server id 1  end_log_pos 154 CRC32 0x00ba1545  Previous-GTIDs
# [empty]
# at 154
#200425 10:59:45 server id 1  end_log_pos 219 CRC32 0x60a87c90  Anonymous_GTID  last_committed=0    sequence_number=1        rbr_only=no
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 219
#200425 10:59:45 server id 1  end_log_pos 339 CRC32 0xe67adb87  Query   thread_id=2     exec_time=0 error_code=0
use `my_db`/*!*/;
SET TIMESTAMP=1587812385/*!*/;
SET @@session.pseudo_thread_id=2/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1436549152/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8mb4 *//*!*/;
SET @@session.character_set_client=45,@@session.collation_connection=45,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
CREATE TABLE test_table(test_column integer)
/*!*/;
# at 339
#200425 10:59:45 server id 1  end_log_pos 404 CRC32 0x62668095  Anonymous_GTID  last_committed=1    sequence_number=2        rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 404
#200425 10:59:45 server id 1  end_log_pos 477 CRC32 0x35241038  Query   thread_id=2     exec_time=0 error_code=0
SET TIMESTAMP=1587812385/*!*/;
BEGIN
/*!*/;
# at 477
#200425 10:59:45 server id 1  end_log_pos 531 CRC32 0xa295cdb7  Table_map: `my_db`.`test_table` mapped to number 108
# at 531
#200425 10:59:45 server id 1  end_log_pos 571 CRC32 0x067ae23f  Write_rows: table id 108 flags: STMT_END_F
### INSERT INTO `my_db`.`test_table`
### SET
###   @1=1
# at 571
#200425 10:59:45 server id 1  end_log_pos 602 CRC32 0x77d30058  Xid = 6
COMMIT/*!*/;
# at 602
#200425 10:59:45 server id 1  end_log_pos 667 CRC32 0xba64cfe3  Anonymous_GTID  last_committed=2    sequence_number=3        rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 667
#200425 10:59:45 server id 1  end_log_pos 740 CRC32 0xa47d0534  Query   thread_id=2     exec_time=0 error_code=0
SET TIMESTAMP=1587812385/*!*/;
BEGIN
/*!*/;
# at 740
#200425 10:59:45 server id 1  end_log_pos 794 CRC32 0x6bb3a343  Table_map: `my_db`.`test_table` mapped to number 108
# at 794
#200425 10:59:45 server id 1  end_log_pos 840 CRC32 0xc5c9202e  Update_rows: table id 108 flags: STMT_END_F
### UPDATE `my_db`.`test_table`
### WHERE
###   @1=1
### SET
###   @1=2
# at 840
#200425 10:59:45 server id 1  end_log_pos 871 CRC32 0x7ac3edac  Xid = 7
COMMIT/*!*/;
# at 871
#200425 10:59:45 server id 1  end_log_pos 936 CRC32 0x87672aac  Anonymous_GTID  last_committed=3    sequence_number=4        rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 936
#200425 10:59:45 server id 1  end_log_pos 1009 CRC32 0xef9fd19e         Query   thread_id=2     exec_time=0  error_code=0
SET TIMESTAMP=1587812385/*!*/;
BEGIN
/*!*/;
# at 1009
#200425 10:59:45 server id 1  end_log_pos 1063 CRC32 0xa3428933         Table_map: `my_db`.`test_table` mapped to number 108
# at 1063
#200425 10:59:45 server id 1  end_log_pos 1103 CRC32 0xed8fb576         Delete_rows: table id 108 flags: STMT_END_F
### DELETE FROM `my_db`.`test_table`
### WHERE
###   @1=2
# at 1103
#200425 10:59:45 server id 1  end_log_pos 1134 CRC32 0x70c60618         Xid = 8
COMMIT/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;