tom__bo’s Blog

MySQL!! MySQL!! @tom__bo

トップ > MySQL > Dive into Binary logs

Dive into Binary logs

MySQL

この記事はMySQL Advent Calendar 2019の9日目の記事です。

binary logとはなにか

binary log(以降binlog)はMySQL serverで実行した更新をイベントという形式で出力したログ。トランザクションのコミット時に出力され、コミットの順番で1トランザクションの変更がシーケンシャルに出力されている。
MySQLではこれを利用することでreplicationやrecoveryを行っている(server crash後のcrash recoveryにはinnodb_log(いわゆるredo log)も使われている)。

レプリケーションに利用される際は、Masterで更新された内容をbinlogとして出力し、この内容をslaveに転送してSlaveのIO threadがrelay_logとして保存する。これをSQL threadが読み出して適用することでMasterとSlaveのデータが同期されるという仕組みになっている。

f:id:tom__bo:20191209184433p:plain:w700 (参考1より)

MySQLのreplicationは非同期レプリケーションもしくは準同期レプリケーションと呼ばれるもので、Master, Slave間のデータ同期のためによく使われるのは準同期レプリケーションでしょう。 今回はbinary log自体の中身に注目するので、説明は省略します。 (もちろんGroup Replicationを使っている場合はこの限りではないです。)

binary logに関連するファイル

  • binlog.index
    • 保持しているbinlogを管理するメタデータファイル
    • 中身は単純に保持しているbinlogのファイル名が書かれている
  • binlog.00000n
    • イベント単位のbinary logそのものは入っている
    • 拡張子部部分が6桁の連番になっている
    • 1ファイルのサイズがmax_binlog_sizeを超えた場合、またはMySQL serverが再起動されたときにローテートされる
    • max_binlog_size文が1ファイルに記録される

binlogのフォーマットに影響を与えるパラメータ

  • binlog_format
    • statement: 実行したクエリをそのまま文字列としてlogに書く
    • row: 変更分を行ごとにイベントとして書く
    • mixed: statementとrowのいいところどり

すべてstatementで書いても良いのではないか？と思うかもしれないが、実行時に結果が決まるようなクエリが実行される場合masterとslaveで結果が異なる可能性がある。実はnow()やrand()といった関数はreplicationのために対応されているが、推奨されないformatとなっている。
rowベースでは更新された内容を記述するため、MasterとSlaveのデータが同じならば、replicationによる変更も同じ結果になるが、例えば1つのupdate文で10万行を変更した場合10万行すべての変更を1イベントとしてreplicationするため、実行が遅くなったりreplication遅延の原因になる。
そこで同じ結果になることが保証される場合はstatement形式で送るなどうまくstatementとrow形式を使い分けてくれるのがmixedとなっている。
最新のMySQL 8.0ではrow baseがdefaultになっていて、今後はrowが推奨されるのかもしれない。

  • binlog_row_image
    • full: すべてのカラムの情報を記録
    • minimal: 行の特定に必要なカラム値(PKE: Primary Key Equivalent)と、変更されたカラムの値を記録
    • noblob: 更新に関係ないBLOB, TEXTカラムを除いてログに記録

binlog_row_imageは前述のbinlog_format = rowで出力される場合に有効な設定となっている。 PKEとはPriamry Keyと同等なデータのことで、例えばupdate文の結果は変このあった行を1意に特定できるPK相当のデータをbefore imageとして指定し、変更結果をafter imageとして記録することでレプリケーションができるようになっている。

mysqlbinlogでbinlogの中身をみる

binlogの中身はMySQL標準のmysqlbinlogコマンドを利用することで確認できる。 mysqlbinlogで必要な特定時間の変更分を確認したり、それらをSQLファイルとして抽出してPITRに利用したりする。

例えば、mysqlbinlog --no-defaults --base64-output=DECODE-ROWS -v binlog.000009と適当なbinlogを指定して中を確認すると以下のような出力を得ることができた。

f:id:tom__bo:20191209184531p:plain:w800

56行目あたりを見ると、DECODE-ROWSを指定しているため、コメントアウトされた状態でSQLとして復元されたINSERTクエリを確認することができる。 MySQLを利用している人なら一度は使ったことがあると思うので、省略するが、詳しく知りたい人はドキュメントを参照してください。

binlogの内部構造を見ていく

binlogは先頭の4byteを0xfe 0x62 0x69 0x6e (0xfe bin)という文字列から始めて、それ以降はイベント(events)という形式で更新データやメタデータを保持している。

f:id:tom__bo:20191209184552p:plain:w200

すべてのeventはheaderとdata部からなり、header部は1つのファイル内で固定(基本的に同じMySQL versionなら構造は一定)でheaderに含まれるtypeコードによって指定されるtypeごとにdata部の中身が変化する。

f:id:tom__bo:20191209184631p:plain:w300

binlogにもversionがあり、有効なversionは1,3,4でMySQL 5.0以降はversion4となっている。 version4として変更がないのはおそらくformatの構造で、新しいeventや使われなくなったeventもあるという状態。

  • version 1: 3.23　(で利用されていた)
  • version 3: 4.0.2~4.1
  • version 4: 5.0以上

現時点で30個以上のeventがあるがここではいくつかのイベントを紹介する。

binlogのフォーマットを規定するevent

binlog自体のフォーマットはbinlogの先頭4byteの次に最初のeventとして出力されるformat_description_eventによって規定される。
つまり、このeventを読むことでそのbinlogファイルのeventをパースすることができるようになる。 おそらくこのformat_description_eventに変更が加わるときにbinlogのversionが変更されるのだと思う。

format_description_eventには以下の5つのデータが記述されている。

  • binlog_version
  • server_version
  • create_timestamp
  • header_length
  • post_header_length

実際中身をparseするにはformatされた各値を読み取る必要があるのだが、ここでは割愛する。 実際に読んでみたい場合はMySQL Internals Manualとここにかけている情報をsource codeから理解しながら読むしかないです。

(一番右の列はbyte数)
f:id:tom__bo:20191209184655p:plain:w350

DML実行によるイベント

query_log_event

statement based logging(以降SBL, binlog_formatがstatementとして出力されるログイベント)の場合に実行されたクエリがそのまま出力されるevent. binlog_formatに関わらずDDLはSBLで出力されるので、DDLはこのeventで出力される

実行自体には不要と思えるメタデータもあるが以下のような形式で最後の値として生のsql_statementが入っている。

f:id:tom__bo:20191209184719p:plain:w350

intvar_event

query_log_eventではauto_incrementの値やlast_insert_id()を利用している場合にこれらの情報が含まれない、そこで、query_log_eventの前にintvar_eventによってこれらの値を指定する。

  • option 1の値
    • 1の場合、valueがauto_incrementの値
    • 2の場合、last_insert_id()の値

f:id:tom__bo:20191209184737p:plain:w350

これ以外にもに更新がありそうだが、Internals Manualから確認できたのはこの2つの値でした。

write_rows_event (update_rows_event, delete_rows_event)

row based logging(以降RBL, binlog_formatがrowとして出力されるログイベント)の場合に更新分が行単位で出力されるevent。insert, update, deleteがそれぞれ、{write,update,delete}_rows_eventとして出力される。

下記の図はupdate_rows_eventで、write,deleteの場合はbefore imageがないので、この部分がなくなる。

f:id:tom__bo:20191209184757p:plain:w350

table_map_event

RBLの場合に、table情報を適用時にマッピングするためのevent。 上記の{write,update,delete}_rows_eventの前に出力され、このイベントを利用することでmasterとslaveのテーブル定義が異なる場合でもreplicationを行えるようにする役割がある。

schemaのことなるmaster, slave間でのレプリケーションについては(参考2)を参照すると理解が深まると思います。

f:id:tom__bo:20191209184824p:plain:w350

終わりに

お気づきの方もいるかも知れませんが、このブログ記事はMySQL Casual Talks vol.12で話した、binlogの内部構造調査の内容を改めてまとめたものです。

speakerdeck.com

binlogをうまく活用することでレプリケーションに関連するパフォーマンス問題を解決したり、自前のbinlog serverを実装しようかと思っていましたが、予想以上にbinlogのすべてを理解するのは難しそうだとわかりました。

当時は比較的実装範囲が少なく実験として面白そうなFlash back(binlowを遡ることでロールバックする)を試そうとbinlogのparaserであるmybinlogを作ったりしていました。ですが、Internals Manualだけからbinlogの構造を把握することは難しく、source codeから必要な情報を理解することも大変です。いくつかbinlogをparseしているツールを見つけたり紹介してもらったりしたのでまた戻ってくると思います。

最近はibdファイルやstorage engineの仕組みのほうが気になってしまっていて、放置気味担ってしまっていますが、この内容を読んで興味を持ってくれた方がいたらぜひ声をかけてください。

参考

  1. 奥野幹也, "エキスパートのためのMySQL 運用+管理トラブルシューティングガイド", p321, 図5-1
  2. "チョットワカル Row-Based Replication" シリーズ (GREE Engineer Blog) その1 ~ その5