Slide 1

Slide 1 text

@nagatech 2022 年03 月27 日( 日) traP LT 2022 ISUCON でログの分析と可視化を やってみた話 2022/03/27 traP LT 2022 #traP_LT

Slide 2

Slide 2 text

nagatech( ながてち) Twitter: @_nagatech ex-traQ サーバー管理者 4 月から社会人3 年目 都内でサーバーエンジニアやってます 最近DJ 始めました Twitch(@nagatea_p) で配信してる フォローしてくれ!!! 自己紹介 2022/03/27 traP LT 2022 #traP_LT

Slide 3

Slide 3 text

今日話すこと ISUCON とは システムの紹介 デモンストレーション ハマったところ ISUCON で競技中リアルタイムにベンチマークのロ グを収集し結果を分析できるシステムを構築し予選 を戦ったので、詳細と運用した顛末を紹介します。 “ “ 2022/03/27 traP LT 2022 #traP_LT

Slide 4

Slide 4 text

ISUCON とは ISUCON 8, 9 は本選出場 ISUCON 10, 11 は予選落ちました お題となるWeb アプリケーションを時間内にいかに高速化できるか を競うコンテスト 高速化手法は( レギュレーションを守れば) なんでもやっていい 1 〜3 人1 チームで600 チーム予選参加→30 チームが本戦出場 2022/03/27 traP LT 2022 #traP_LT

Slide 5

Slide 5 text

ISUCON において大事なこと なんでしょう? ISUCON LINE スタンプ発売中! 2022/03/27 traP LT 2022 #traP_LT

Slide 6

Slide 6 text

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

Slide 7

Slide 7 text

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

Slide 8

Slide 8 text

計測手段とツールいろいろ( 一例) kataribe リクエストログからリクエスト数や処理時間を計測 myprofiler MySQL の実行計画からクエリの実行回数を計測 pt-query-digest MySQL のスロークエリログから遅いクエリを計測 dstat CPU 使用率等のパフォーマンスを計測 2022/03/27 traP LT 2022 #traP_LT

Slide 9

Slide 9 text

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

Slide 10

Slide 10 text

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

Slide 11

Slide 11 text

2022/03/27 traP LT 2022 #traP_LT

Slide 12

Slide 12 text

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

Slide 13

Slide 13 text

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

Slide 14

Slide 14 text

よくみるやつ CPU 、メモリ、帯域etc... fluentd のdstat プラグインを使 用して収集 パフォーマンスモニタリングだ けでなく、負荷が大きいプロセ スを記録して分析できるように した サーバーパフォーマンスの分析 2022/03/27 traP LT 2022 #traP_LT

Slide 15

Slide 15 text

環境のセットアップ 分析側( ながてちサーバー) docker で「elasticsearch 」と 「kibana 」のイメージを立ち 上げる ログ送信側( 競技サーバー) fluentd とプラグインをインストール 各サーバーに設定ファイルを配置 事前に仕込んでおいたMakefile でコマンド一発 2022/03/27 traP LT 2022 #traP_LT

Slide 16

Slide 16 text

デモンストレーション システムとデータがまだ残ってたので実際に動かしながら ISUCON 11 初回ベンチマークの様子を見せたいと思います お題のWeb アプリケーション IoT デバイス記録& 閲覧アプリ「ISUCONDITION 」 ISU のコンディションを記録するWeb サービス IoT デバイスから送られてくるデータとトレンドの閲覧を いかに捌くかがポイントだった 2022/03/27 traP LT 2022 #traP_LT

Slide 17

Slide 17 text

パフォーマンスモニタリングが動かなかった なぜかfluentd がエラーを吐いてログが送信されない 2022/03/27 traP LT 2022 #traP_LT

Slide 18

Slide 18 text

原因その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 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

Slide 19

Slide 19 text

原因その2 dstat --output log.csv がプロセスを終了するまで log.csv に結果を書き込まないようにコードが変更されていた 結論として dstat のバグだった システムを構築した際に気づかなかったのは、ISUCON 10 予選 のイメージ(Ubuntu18.04LTS) で検証していたため dstat のバージョンが違う そしてdstat は開発が終了している... 直そうにも無理 後継は直っているぽいがプラグインが依存している... 2022/03/27 traP LT 2022 #traP_LT

Slide 20

Slide 20 text

まとめ ログを可視化して分析できるシステムを構築しました 構成自体はよくある 今後レギュが変わる場合もあるから注意してね バグってうまく活用できなかった バグってても競技中に直そうとしてはいけない 原因は特定できたので来年は活用できる 来年こそは予選突破するぞ!!!!! 2022/03/27 traP LT 2022 #traP_LT

Slide 21

Slide 21 text

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