Home > まめ知識 | 開発裏話 > MySQLのmysqlbinlogは使いづらいので、mysqlbinlogexを作ってみました。

MySQLのmysqlbinlogは使いづらいので、mysqlbinlogexを作ってみました。

仕事でしょっちゅうmysqlのバイナリログを掘っているのですが、mysqlbinlogが使いづらくて困っていました。なんせmysqlのバイナリログは、以下の問題があります。

・すぐサイズが大きくなるため、1つのDBのログを追うために、相当時間がかかる。

・mysqlbinlogコマンドから出るデータは、1行になっていないため、grepとかしづらい。

・バイナリデータ突っ込んだりしている場合は、文字化けて、続きが読めなくなったりする。

・mysqlbinlogコマンドも、1Gクラスのログだと、とにかく遅い。

・ログを追ったり調査するだけの人間からすると、無意味なログが多すぎる。

apacheのログみたいに、1行1リクエストになっていれば、grepですぐに引けるのですが、目的のクエリ探すのが、しんどい、しんどい。

また、うちは1システムで、1日1GBクラスのログがたまるため(バイナリアップロード分はほとんど入っていないにもかかわらず・・)ログローテートサイズを1Gにしているのですが、このログをmysqlbinlogコマンドで掘るのに時間がかかりすぎて・・

ついに、やってられなくなったため、木曜から2日かけて(やっつけですが)、以下の仕様で、バイナリログを閲覧するコマンドアプリを作ってみました。

・高速化のため、バイナリログを直接読み込む

・ログはgrepとか行いやすいように、「1行1クエリ」にする。(クエリ内改行は、スペース置換)

・クエリは、utf8mb4文字列以外であれば「?」に置換して、化けないようにする。

・DB(スキーマ)ごとにログをフォルダに振り分けて保存してくれる。

・時間フィルタとかも使いたい。

* 名付けて、mysqlbinlogexです。(パクリくさい名前ですね)

ソースはここ(github)に置いてあります。同じような悩みを抱えている方、一緒にブラッシュアップしていきませんか?(行ベースロギングには現時点(2014/05/24)では対応していません・・。)

なお、mysqlのバイナリログのフォーマットが、探しかたが悪いのか、どこを探しても断片的にしか無く、結局mysqlのソース追う羽目になったため、以下に調査内容をまとめておきます。


* mysqlのバイナリログフォーマットについて

1. 全体のおおまかなフォーマット

  ・ はじめの4byteは、必ず「0xfe 0x62 0x69 0x6e」。これがmysqlのバイナリログの証です。

  ・ その後は、次の形式のがループして最後まで続きます。

| ログヘッダ(19Byte) | クエリとクエリステータス(可変) |

  ・ つまり、binlogファイルの中身は、以下のような感じです。

0xfe 0x62 0x69 0x6e
| ログヘッダ(19Byte) | クエリとクエリステータス(可変) |
| ログヘッダ(19Byte) | クエリとクエリステータス(可変) |
| ログヘッダ(19Byte) | クエリとクエリステータス(可変) |
| ログヘッダ(19Byte) | クエリとクエリステータス(可変) |
・・・・・

 2. 各クエリセグメントのフォーマット

・ 各クエリセグメントは、上記のように、以下の形式です。

| ログヘッダ(19Byte) | クエリとクエリステータス(可変) |

・ 19byteのログヘッダは、下記の内容を含んでいます。なお、すべてリトルエンディアンです。ここ(本家)が詳しいです。

| ts(4byte) | type(1byte) | masterID(4byte) | size(4byte) | master_pos(4byte) | flags(2byte) |

– ts(4byte):クエリ動作日時。unix_timestamp。

– type(1byte):0x0f(バイナリログ開始)、0x02(通常のステートメントログ)、0x17-0x19(rowベースステートメント)とか。重要

– masterID(4byte):読んで字の如く。自分の場合は、自分のID。

– size(4byte):このセグメントのバイト長。ログヘッダの19byteを含む。超重要

– master_pos:読んで字の如く。

– flags:普通のログは、0x00。その他は本家(上にリンクあり)参照。

・ 19byteのデータを読んだら、「クエリとクエリステータス」の長さが決まります。「クエリとクエリステータス」は以下のフォーマットです。

 | クエリヘッダ(13byte) | ステータスデータ(可変) | データベース名称(可変) | 0x00 | クエリ(可変) |

・ クエリヘッダは以下のフォーマットです。

 | thread_id(4byte) | exec_time_sec(4byte) | error_code(2byte) | status_size(2byte) |

– thread_id(4byte):クエリ実行者のスレッドID。同じであれば、同じコネクションで動作したことがわかる。

– exec_time_sec(1byte):クエリ実行時間

– error_code(2byte):エラーコードらしい。内容はあまりよくわからない。

– size(4byte):続きの「ステータスデータ」のバイト数。超重要

・ ここまで来て、やっと最も大事なDB名称とクエリの位置がわかります。データベース名称は0x00が入っているわけないので、ステータスデータが終わったところから、初めて0x00が来たところまでが、DB名です。空の場合もあります。(useしないで動作させると空になるようです。sequel proとか、navicatとかで操作した場合とか。)残りがクエリです。ただし、mysql5.6.1以降のバージョンが吐き出したバイナリログの場合、クエリ部の最後に、crc32チェックサムが付いています。このため、mysql5.6.1以上の場合は、終わり4byteを削ってあげる必要性があります。

・ クエリセグメントについて全部記載すると、以下のようになります。こいつが何度も繰り返されているイメージです。

| ts(4byte) | type(1byte) | masterID(4byte) | size(4byte) | master_pos(4byte) | flags(2byte) |
| thread_id(4byte) | exec_time_sec(4byte) | error_code(2byte) | status_size(2byte) |
| ステータスデータ(可変) | データベース名称(可変) | 0x00 | クエリ(可変) |

久しぶりに投稿しました。次は、いつになるだろ。予定は、「mysqlレプリケーションで、マスタが落ちた場合にスレーブを落とさなければならないときの注意事項」を書きたいと思います。(5.6.17で4台レプリ組んで、検証していたときにはまりました。)

全然関係ないですが、弊社では、現在、開発チームメンバを大々募集中です。このブログをこの位置まで読んでいただいた方、ぜひ応募してみてください。給与アップも(きっと)間違いなし(かも・・)。一緒にwebシステムのジェネラリストになりませんか?

Home > まめ知識 | 開発裏話 > MySQLのmysqlbinlogは使いづらいので、mysqlbinlogexを作ってみました。

Search
Feeds

Return to page top