$30 off During Our Annual Pro Sale. View Details »

ISUCONでログの可視化と分析をやってみた話

nagatech
March 27, 2022

 ISUCONでログの可視化と分析をやってみた話

2022/03/27 #traP_LT にて発表
https://connpass.com/event/242713/

nagatech

March 27, 2022
Tweet

More Decks by nagatech

Other Decks in Technology

Transcript

  1. @nagatech 2022 年03 月27 日( 日) traP LT 2022 ISUCON

    でログの分析と可視化を やってみた話 2022/03/27 traP LT 2022 #traP_LT
  2. nagatech( ながてち) Twitter: @_nagatech ex-traQ サーバー管理者 4 月から社会人3 年目 都内でサーバーエンジニアやってます

    最近DJ 始めました Twitch(@nagatea_p) で配信してる フォローしてくれ!!! 自己紹介 2022/03/27 traP LT 2022 #traP_LT
  3. 今日話すこと ISUCON とは システムの紹介 デモンストレーション ハマったところ ISUCON で競技中リアルタイムにベンチマークのロ グを収集し結果を分析できるシステムを構築し予選 を戦ったので、詳細と運用した顛末を紹介します。

    “ “ 2022/03/27 traP LT 2022 #traP_LT
  4. ISUCON とは ISUCON 8, 9 は本選出場 ISUCON 10, 11 は予選落ちました

    お題となるWeb アプリケーションを時間内にいかに高速化できるか を競うコンテスト 高速化手法は( レギュレーションを守れば) なんでもやっていい 1 〜3 人1 チームで600 チーム予選参加→30 チームが本戦出場 2022/03/27 traP LT 2022 #traP_LT
  5. ISUCON において大事なこと なんでしょう? ISUCON LINE スタンプ発売中! 2022/03/27 traP LT 2022

    #traP_LT
  6. ISUCON において大事なこと 答え ISUCON LINE スタンプ発売中! 2022/03/27 traP LT 2022

    #traP_LT
  7. ISUCON において大事なこと 推測するな計測せよ 計測した結果に基づいて高速化を検討しようということ あなたはプログラムがどこで時間を消費しているか を理解していない。ボトルネックは予想外のところ にある。推測するな。どこにボトルネックがあるか 証明されるまで高速化するな。 計測せよ。計測するまで高速化するな。計測して、 コードの一部分が他の部分より圧倒的に時間を消費

    しているのでなければ、高速化をするな。 “ “ 2022/03/27 traP LT 2022 #traP_LT  引用: https://scrapbox.io/nishio/ 推測するな、計測せよ
  8. 計測手段とツールいろいろ( 一例) kataribe リクエストログからリクエスト数や処理時間を計測 myprofiler MySQL の実行計画からクエリの実行回数を計測 pt-query-digest MySQL のスロークエリログから遅いクエリを計測

    dstat CPU 使用率等のパフォーマンスを計測 2022/03/27 traP LT 2022 #traP_LT
  9. 計測手段とツールいろいろ( 一例) ISUCON 10 ではMakefile で一連のコマンドを叩いて 結果をSlack に投稿するまで自動化してた 各ツールを毎回実行して見比べるのは大変 いつのベンチマークの結果か分からなくなる

    2022/03/27 traP LT 2022 #traP_LT
  10. ログ分析システムを構築した 2022/03/27 traP LT 2022 #traP_LT

  11. 2022/03/27 traP LT 2022 #traP_LT

  12. kataribe をイメージして作成 fluentd のnginx プラグインを使 用して収集 データを正規表現で置換して 定量化 例: /view/isu/123

    → /view/isu/* リクエストログの分析 2022/03/27 traP LT 2022 #traP_LT
  13. myprofiler をイメージして作成 fluentd のnata2 プラグインを使 用して収集 データを正規表現で置換して 定量化 MySQL スロークエリログの分析

    例: SELECT * FROM isu_condition WHERE jia_isu_uuid = "hoge" LIMIT 10 → SELECT * FROM isu_condition WHERE jia_isu_uuid = S LIMIT N 2022/03/27 traP LT 2022 #traP_LT
  14. よくみるやつ CPU 、メモリ、帯域etc... fluentd のdstat プラグインを使 用して収集 パフォーマンスモニタリングだ けでなく、負荷が大きいプロセ スを記録して分析できるように

    した サーバーパフォーマンスの分析 2022/03/27 traP LT 2022 #traP_LT
  15. 環境のセットアップ 分析側( ながてちサーバー) docker で「elasticsearch 」と 「kibana 」のイメージを立ち 上げる ログ送信側(

    競技サーバー) fluentd とプラグインをインストール 各サーバーに設定ファイルを配置 事前に仕込んでおいたMakefile でコマンド一発 2022/03/27 traP LT 2022 #traP_LT
  16. デモンストレーション システムとデータがまだ残ってたので実際に動かしながら ISUCON 11 初回ベンチマークの様子を見せたいと思います お題のWeb アプリケーション IoT デバイス記録& 閲覧アプリ「ISUCONDITION

    」 ISU のコンディションを記録するWeb サービス IoT デバイスから送られてくるデータとトレンドの閲覧を いかに捌くかがポイントだった 2022/03/27 traP LT 2022 #traP_LT
  17. パフォーマンスモニタリングが動かなかった なぜかfluentd がエラーを吐いてログが送信されない 2022/03/27 traP LT 2022 #traP_LT

  18. 原因その1 Ubuntu20.04LTS で apt でインストールできるdstat で dstat --output log.csv がエラーで実行できない

    isucon@ip-192-168-0-11:~$ dstat --output tmp.csv You did not select any stats, using -cdngy by default. Traceback (most recent call last): File "/usr/bin/dstat", line 2847, in <module> main() File "/usr/bin/dstat", line 2687, in main scheduler.run() [.. 省略] if isinstance(self.val[name], types.ListType) or isinstance(self.val[name], types.TupleType): NameError: name 'types' is not defined 2022/03/27 traP LT 2022 #traP_LT
  19. 原因その2 dstat --output log.csv がプロセスを終了するまで log.csv に結果を書き込まないようにコードが変更されていた 結論として dstat のバグだった

    システムを構築した際に気づかなかったのは、ISUCON 10 予選 のイメージ(Ubuntu18.04LTS) で検証していたため dstat のバージョンが違う そしてdstat は開発が終了している... 直そうにも無理 後継は直っているぽいがプラグインが依存している... 2022/03/27 traP LT 2022 #traP_LT
  20. まとめ ログを可視化して分析できるシステムを構築しました 構成自体はよくある 今後レギュが変わる場合もあるから注意してね バグってうまく活用できなかった バグってても競技中に直そうとしてはいけない 原因は特定できたので来年は活用できる 来年こそは予選突破するぞ!!!!! 2022/03/27 traP

    LT 2022 #traP_LT
  21. その他余談 本番中はインスタンスのメモリそこそこにしないと まともに動かない 戻し忘れないようにしましょう( 一敗) 2022/03/27 traP LT 2022 #traP_LT