Djangoアプリケーション 運用のリアル 〜問題発生から可視化、最適化への道〜 #pyconshizu

PyCon mini Shizuoka 2024 continue
https://shizuoka.pycon.jp/
https://pycon-shizu.connpass.com/event/337283/
https://posfie.com/@ftnext/p/GiCxLWu

Transcript

1. Djangoアプリケーション 運用のリアル 〜問題発生から可視化、最適化への道〜 @kashew_nuts
2. お品書き • 会社と登壇者について紹介 • 発表の動機とゴール • アプリケーションを運用している中でのつらみ共有 • つらみをどのように解消できるようにしていったか • 取り組みの結果できるようになったこと • まとめ
3. Who am I? / お前誰よ • 吉田花春 (Yoshida Kashun) • 𝕏 @kashew_nuts • 🏢 BeProud Inc. • 󰞵 Software Developer • 開発環境整備とボルダリングが趣味 • 大学4年間を静岡県沼津市で過ごす ◦ 現在は閉校して先端農業の研究拠点に
4. What's • Pythonメインで受託開発・研修・自社サービスの運営 • 私は主にconnpassの開発/運営をしています • フルリモートワーキング (5days/week)
5. 発表の動機 • 開発が完了し、リリース後に不具合対応で土日出勤した 経験があった • それ以降も調査するための材料が足りなくて、非常に調 査が時間がかかることがあった • 運用に乗ってからも改善する中で見えることもあった • 過去の自分や似通った人の導入になればと思った
6. 想定する聞き手 • 現在アプリケーションの開発をしているが、リリースさ れた後の運用について知見を深めたい人 • アプリケーションの運用をもっと楽にしたい人 • 運用時のつらみを共有したい人
7. アプリケーションを運用する中でのつらみ • ユーザーからシステムエラーが発生したと言われたが、エラー が発生した箇所がわからない • ログが出力されていなくて、何が発生したのか調査できない • ログメッセージが適切でなく、対処方法がわからない • エラー通知が鳴り続けて現場が疲弊する • CPUやメモリの使用率が張り付いているが、原因がわからない • アラートの調査に時間が取られて、開発の時間が取れない
8. システムで何が起きているか 調査できるようにしたい
9. つらみをどのように観測していくか 1. エラーやログを取得する 2. APM(Application Performance Monitoring)を活用して ボトルネックを解消する 3. カスタムメトリクスを計装して、問題の原因を把握でき るようにする
10. 1. エラーやログを取得する
11. 【現実】ログから判断できない • 例外をキャッチして握りつぶしている try .. except: pass • アプリ側でログ出力の設定が未整備 • フロントからどの操作でAPIが呼ばれているかわからない • DEBUGログのみで、本番ではログ出力されない • エラーメッセージから何をしたらいいかわからない
12. 【理想】ログから判断できるようにする • 5W1Hがわかる：特にエラーログ ◦ 「いつ」「どこで」「誰が」「何を」「なぜ」「どのように」 • (例) ◦ 「request_id: xxx 10:00 INFO 指示書の確定処理が完了」 ◦ 「request_id: yyy 11:00 WARNING 外部システムとの接続に 失敗。〇〇に連絡してください。」
13. 【対策】ログから判断できるようにする 1. INFO、ERROR だけでなくログレベルを使い分ける 1.1. CRITICAL：システム全体や連携システムに影響する重大な問題発生時の情報 1.2. ERROR：プログラム上の処理が中断したり、停止した場合の情報 1.3. WARNING：プログラムの処理は続いているが何か良くないデータや通知の情報 1.4. INFO：プログラムの状況やデータ数など後で挙動を把握しやすくする情報 1.5. DEBUG：ローカル環境で開発するときだけつかう情報 2. APIリクエストのstart/end時にログを出力 2.1. リクエストID, 日時, エンドポイント, ステータスコード 2.2. django-structlogのような構造化ロギングを可能にするライブラリを活用する 3. 5W1Hがわかるようにメッセージ内容を修正する
14. django-structlogでのログ出力設定例 1. $ pip install django-structlog 2. getting_startedを例にsettings.pyに設定を追加 3. Pythonコードからログを出力する >>> import structlog >>> logger = structlog.get_logger(__name__) >>> logger.warning("外部システムとの接続に失敗。〇〇に連絡してください。 ") {"request_id": "3a8f801c-072b-4805-8f38-e1337f363ed4", "user_id": 1,"ip": "0.0.0.0","level": "warning", "event": "外部システムとの接続に失敗。〇〇に連絡してください。 ", "timestamp": "2025-02-08T10:07:31.089925Z", "logger": "my_awesome_project.my_awesome_module"}
15. 【現実】エラー発生時すぐ検知できない • ユーザーからエラーが発生したと連絡がくる • 渡されたエラーログはgrepした1行目の画面キャプチャ ◦ せめてトレースバックがほしい.... • ログだとどんなrequestデータだったのかわからない • 調査はサーバーにVPNでssh接続しjournalctlコマンド で.... • 調査してる間に別のエラーが....つらい....
16. 【理想】エラーがあったときすぐ検知できる • ERRORやWARNINGがあったらSlackに通知が届く！ ◦ だれでも調査開始できる • 問い合わせ前に原因把握と対策の検討まで終わってる！
17. 【対策】エラーがあったときすぐ検知できる • Sentry の導入 ◦ エラートラッキングサービスを活用 • ERRORやWARNINGがあったら Slackに通知がくる！ ◦ だれでも調査開始できる • ログ情報にとどまらず、様々な情報 がすぐわかる ◦ エラーが発生した環境 ◦ POSTされたデータや発行された SQL ◦ エラー発生頻度
18. Sentryの導入例 1. $ pip install sentry-sdk 2. settings.pyに以下の内容を追記 import sentry_sdk sentry_sdk.init( dsn="<your DSN here>", traces_sample_rate=1.0 ) 3. Sentry側の設定を有効にした後、エラー発生時はSentryに通知 4. ORM用の設定する際はDjango integrationの設定を参考にする
19. SentryでDjango integrationの設定 import sentry_sdk.utils sentry_sdk.utils.MAX_STRING_LENGTH = 2048 # monkey patch first import sentry_sdk from sentry_sdk.integrations.django import DjangoIntegration from sentry_sdk.integrations.logging import LoggingIntegration # デフォルトでは ERROR 以上しかevent登録されないので、WARNING以上にする sentry_logging = LoggingIntegration(level=logging.INFO, event_level=logging.WARNING) sentry_sdk.init( dsn=SENTRY_DSN, integrations=[sentry_logging, DjangoIntegration()], # Associate users to errors (if using django.contrib.auth) send_default_pii=True, _experiments={'record_sql_params': True} )
20. 2. APMを活用して ボトルネックを解消する
21. 【現実】アプリケーションがなぜか重い • お客さんから画面を開くのが遅いと報告がくる • メトリクスをみると何故かCPU利用率やI/Oが高い • 開発時は問題なかったが、データ量が増えると重い • コードをよく読むとN+1問題のあるコードが散在 • 非同期処理を活用できていなくてボトルネック化 ◦ ex) メール送信、ファイル操作
22. 【理想】アプリのどこが重いかがわかる • ツールを活用してAPIや画面のボトルネックが測定できる ◦ スロークエリの発見 ◦ リクエストIDごとに、処理にかかった時間を集計する • パフォーマンスに問題があったらSlackに通知が届く ◦ N+1が発生している箇所がわかる
23. 【対策】APMを活用してボトルネック解消 • APM：アプリケーションパフォーマンスモニタリング ◦ SentryのPerformance Monitoring ◦ DatadogのAPM • CloudWatch Logs Insightsでのログデータ分析も便利 ◦ スロークエリの発見
24. Sentryの導入例 1. $ pip install sentry-sdk 2. settings.pyに以下の内容を追記 import sentry_sdk sentry_sdk.init( dsn="<your DSN here>", traces_sample_rate=1.0 ) 3. エラー発生時にSentryに通知される
27. CloudWatch Logs Insightsでの分析例
28. 3. カスタムメトリクスを 計装し問題の原因を把握
29. 【現実】メトリクスはあるが原因が不明 • メトリクス：システムのパフォーマンスに関するデータ ◦ ex) CPUやメモリ、Diskなどリソース使用状況 • DBの使用率が突然高くなった ◦ 特定IPアドレス/UserAgentからの過度なアクセス ◦ 通知用のCeleryキューが溜まっている
30. 【理想】カスタムメトリクスで把握できる • 取得したログからメトリクスを作成できる • メトリクスはダッシュボードを活用して一覧化 • 各メトリクスの関連性をともなった状況を把握できる • 状況が把握できると、問題解決のために対策を打てる
31. 【対策】Datadogを活用する • ログ分析やAPM、各サービスとのインテグレーション、 カスタムメトリクスなど多種多様な機能を提供するSaaS • ダッシュボードを作成することで対象のメトリクスから どのようにシステムが連携しているかわかる
32. Datadog導入例 1. $ pip install ddtrace 2. settings.pyのLOGGINGにDatadog用の記述追加(後述) 3. # ログ分析と統合したAPMを有効にしている例 4. $ DD_LOGS_INJECTION=1 \ ddtrace-run gunicorn myapp.wsgi:application 5. Datadogのエージェントを有効にしメトリクスとログを収集
33. settings.py: python-json-loggerの設定例 LOGGING = { "formatters": { "json": { "class": "pythonjsonlogger.jsonlogger.JsonFormatter", "format": "%(pathname)s %(lineno)d %(asctime)s %(process)d %(thread)d %(levelname)s %(module)s %(message)s %(name)s %(dd.env)s %(dd.service)s %(dd.version)s %(dd.trace_id)s %(dd.span_id)s", }, }, "loggers": {"ddtrace": {"level": "WARNING"}}, # 以降略 }
34. Tips: manage.pyコマンドもトレース # REF: https://github.com/DataDog/dd-trace-py/issues/1341 import sys import ddtrace name = sys.argv[1] if len(sys.argv) > 1 else None @ddtrace.tracer.wrap(name=name) def main(): # 略
35. 監視項目を一覧表示
36. 監視項目を一覧表示: 最適化後
37. Appendix: 実際に今回取り組んだ事例はPyConJP 2024で弊社エンジニアが紹介 • WEBアプリケーションにおけるAWS Lambdaを用いた大規模な非 同期処理の実践
38. 取り組みの結果 できるようになったこと
39. 問題を観測し、解消できるようになってきた 1. エラーやログを取得して何が起きているか把握できる ✅ 2. APM(Application Performance Monitoring)を活用してボトル ネックを特定・解消できる ✅ 3. カスタムメトリクスを計装し、問題が把握できる ✅
40. 実現できたこと • Sentry: エラートラッキング • Datadog: ログ分析やモニタリング、アラート • Aurora(MySQL): レーテンシー, メモリ低下, コネクション増加 • ElastiCache(Redis)：Auroraの項目+SwapUsage • ELB: 5xx response, unhealthyホスト数 • OpenSearch(ElasticSearch): 死活監視 • Celeryのワーカー数／キュー数 • IPアドレス／UserAgent: アクセス数 • SQS: DLQ
41. 可視化できるようになり楽になったこと • メンバー(nonエンジニア)が直接調査できる ◦ 開発者が開発に専念しやすい • ログやAPM、メトリクスなど各機能を横断して閲覧 • 各画面をパーマリンクで開けるのでチームへの共有が楽 • リソースの負荷が高まったときに何が原因かわかる ◦ 人数が多いイベントの通知のキュー数 ◦ 特定のIPアドレス/UserAgentからの攻撃の発生 ◦ 想定外に実行時間がかかっているSQLの発見
42. TL;DR • 問題を調査しやすい環境づくりをしていきましょう ◦ これから用意するなら、まずはログから • アプリケーションをよく理解して計測していきましょう ◦ 自分たちのサービスを改善していくのは自分たち • 状況は人それぞれ違うので一歩一歩改善してきましょう ◦ 銀の弾丸はない。ツールは頼りになるが評価し試していく
43. 参考URL • 自走プログラマー • 入門監視 • エキスパートPythonプログラミング 改訂4版 • オブザーバビリティ・エンジニアリング • Python | Sentry Documentation • Datadog Docs • ddtrace documentation
44. ご清聴ありがとうございました！！ We Are Hiring ! Pythonエンジニア https://www.beproud.jp/careers/python/ カジュアル面談 https://onl.tw/LPVc2hd