RDSのGeneralLogをパケットキャプチャに切り替える

三年以上前に サービス品質の改善効率を高める仕組み | 外道父の匠 の一部にて、GeneralLog と EXPLAIN を使って、クエリ品質を自動算出していることを書きました。

この仕組みは2011年に開発して以降、言語変更や新環境に適応させたりしつつも、ほぼそのまま稼働し続けていて、最近はRDSが対象になることが多いのですが、RDSだとGeneralLogの採取に問題が発生したので、DBサーバーではなく、ClientでのPythonを使った採取に切り替えてみました、という話になります。



RDSのGeneralLogは高QPSでは非推奨

RDSで GeneralLog を採取するには、パラメータグループで general_log を ON にするしかないのですが、数百qps 程度なら問題なく動いても、数千～万qps となると、ほぼ期待通りに切り替わってくれなくなります。

それまでは、APIを叩いて general_log = ON にし、実際にONになったことを確認できた瞬間をスタートとして、30秒経過 もしくは ログが100MB 溜まったら general_log = OFF にする という処理を行っていました。しかし、このAPIでON/OFFの切り替えを実行してから、実際にそれが反映されるのが、QPSが高くなるほどに遅延することがわかりました。酷いときには OFF にしてから3～5分後にログ追記が停止される、という事象になり、そうなると100MB以下の予定だったログ容量が数GBになったり、悪くするとインスタンスとしてのパフォーマンスにまで影響して、サービスのレスポンスが悪くなったりもします。

この件についてはサポートにも問い合わせましたが、パラメータグループでの方法しか存在しない以上、改善は見込めない印象でしたので、スパッと異なる手法に切り替えることにしました。


パケットキャプチャ方式に方針転換

そうなると選択肢は１つしかなくて、WEB/APサーバーといったクライアント側で採取することになります。ただ、これにはデメリットがあり、DBサーバー側のGeneralLogだと実行されたSQL全てが記録されるのに対し、仕込んだクライアントサーバー分のSQLのみになってしまうという点です。

ただでさえ元から、数十秒分のGeneralLogによるサンプリング集計だったのに、さらに数十台の中の数台分という、サンプリング中のサンプリングになってしまいます。が、それだけなら単に数が減るだけなので問題なく、できるだけクエリの種類を漏らさないために Role毎（web/job/admin とか）に数台ずつ仕込むことでヨシとしました。

採取する方法の１つに、アプリケーションからSQLログを吐き出してもらう、というのがありますが、アプリケーションに手を加えさせることは全く本意ではないため、パケットキャプチャをすることにしました。似たようなクエリ集計に、PERCONA toolkit の pt-query-digest がありますが、既存の仕組みをできるだけ変えないためにも、私が欲しかったのはあくまで GeneralLog モドキなので、tcpdump を扱うことはやめ、軽量言語でパケットキャプチャし、GeneralLogっぽく成形して保存することにしました。


Pythonでパケットキャプチャ

GeneralLogの解析スクリプトは、最初はPHP、次にRubyで書き直してきたのに、パケットキャプチャのスクリプトはPythonで書くことにしました。これは、Lambdaで慣れたというのもありますが、小規模のインフラスクリプトは総合的にPythonが適していると判断したからです。AWS様が一発目のLambda用言語に採用しただけあって、非常に扱いやすいです。おそらく数年は戦えるでしょうし、今後はもう黒魔術Bashを書くこともないでしょう。

で、キャプチャ用のPythonスクリプトはこちらです。ちょっと長いのでリンクだけ貼っておきます。
  • Gist : GedowFather/general_log_dump.py

    • Python自体は素人に毛の生えた程度なので細かいところはご容赦いただくとして。あとはテストや運用のためにローカル対応とかタグとか余計な処理が入ってますが、その辺をカットしようとするとブログ書く気力が萎えるので、ほぼそのままアップしてあります。

    ポイントとしては、
  • pcapy 使ったらパケットデータを扱いやすかったよ
  • 実際のログの解析処理で必要だったから、DBのアドレスを記録したよ
  • クエリの処理を簡単にするために綺麗な一行にして記録したよ
  • Windows Server でも動くよ
  • Client <-> DB の通信が暗号化されてたら当然中身は見えないよ

    • って感じです。必要なところだけ参考にしていただければレベルでお願いしますだ。


    環境準備

    権限

    ログはS3に送るので、送信先のバケットを別の中央アカウントのものに集約する場合、バケットポリシーを編集して送信元アカウントIDを許可しておきます。

    もう１つは、EC2上で実行するので、EC2 profile用のRoleを作成または編集し、S3:ListBucket , S3:PutObject , EC2:DescribeTags を付与しておきます。

    CentOS7

    Pythonを実行するために必要なパッケージを入れます。

    あとは定期的に実行するためにcronをおいて終わりです。色んなサーバーで実行するので、S3にスクリプトを置いて逐一取得することで、更新時の手間を省いています。

    もちろん、手動で実行して、実行中に手動でSQLを実行してテストすることも可能です。

    Windows Server2012

    Windows Server は好きじゃないですが、必要があったのでスクリプトを両対応にしました。ホントに好きじゃないので雑にですが記録しておきます。

    • Pythonをインストールします
      • Python.org からインストーラをダウンロードします（今回は2.7）
      • インストールして動作確認します C:\Python27\python.exe -V
    • Vimをインストールします（開発・確認用）
      • Vim — KaoriYa からダウンロードします
      • 解凍して適当な場所に配置して利用します
    • pcapy用に Visual C++ をインストールします
    • WinPcapをインストールします
    • Developer’s Pack をインストールします
    • pip でパッケージをインストールします
      • PowerShellを起動します
      • C:\Python27\python.exe -m pip install boto3 impacket netaddr netifaces pytz
        set-item env:WPDPACK_BASE -value C:\WpdPack
        C:\Python27\python.exe -m pip install pcapy
    • Wireshark もあると通信内容の確認に便利です
      • dst port 3306 でフィルタすると見えます
      • 平文になっていれば接続からSQL発行まで全部みえます
    • 上記インストーラ群は、手元で集めてからRDP経由でコピペ転送する方が多分楽です

    これでスクリプトを実行＆SQL実行で、任意のS3に保存されれば成功です。
    ログが読めない場合は、平文になってないのでクライアントの調整が必要になります。

    成功したら、タスクスケジューラで定期実行を仕込んで終了です。


    使用感など

    tcpdump のデータは独自のことをするには扱いづらいので、好きな言語でパケットの内容を詳細に分解して、好きなように処理した方が、開発の手間を考慮してもシステムの仕上がりとしてはかなり綺麗で効果的になりますね。

    さて、今回のPythonスクリプトを実行した場合の負荷ですが、c3 のCPUでは約5000qps 程度で 1thread 100% となりました。微妙なラインではありますが、通常はサーバー1台あたりでは 数千qps も発行しないので、多くても 10%/thread 以下程度の負荷が 30～60s かかるだけになり、全thread合わせた100%換算では微々たるものとなるので、その辺の心配はなさそうでした。



    まぁなんというか、インフラエンジニアとしては、たまにこういうスクリプトでも書いてないと頭が腐るというか、ストレス発散になるというか。個人的にはそういう面で非常に効果的なのです。調査と検証・実装(コーディング含む)・運用 を上手に三角食べするのが、長続きのコツじゃないかと思うのです。

    そんなワケで、楽しい時間が終わってしまいました。ｶﾞｯｸﾘ

    Posted on 2018/03/06   カテゴリー: Aurora, AWS, Python タグ: , , パーマリンク