unless’s blog

日々のちょっとした技術的なことの羅列

Datadog Profilerで継続的なProfilingを実施できるようにした話

Go エンジニア Datadog profiling モニタリング 監視

おまえだれ?

株式会社Kyash でサーバサイドエンジニアをしている @uncke__ko です
Fundsチームに所属していて主にお金の入出金部分を担当しています

これは何?

Kyashではシステムの監視やモニタリングにDatadogを使用しています

www.datadoghq.com

Datadogにある Continuous Profilerという機能を使い、継続的にProfilingできる環境を整えたのでその話になります

docs.datadoghq.com

Profilerとは

プロファイラとはアプリケーションの性能を解析するためのツールです
ソフトウェア開発をしていると下記のようなことが度々起こった経験が1度はあると思います

  • OOMが発動するようになる
  • latencyが遅くなる
  • アプリケーションの動作が徐々に重くなる

Profilerがあると、このようなときにアプリケーションのCPU使用率やメモリ使用率、関数のCall数など様々な情報が手に入るので調査が行いやすくなり原因を特定できるようになることが多いです

いままでのKyash

KyashのサーバサイドではGolangを使用しています
Golangにはpprofというツールが用意されているので、Kyashでもこれを使用して問題が起こったときにProfileを取得していました Call GraphやFlame Graphなどもあり見やすいです

CallGraph https://github.com/google/pprof/blob/master/doc/images/callgraph.png

https://github.com/google/pprof/blob/master/doc/images/callgraph.png?raw=true

なぜDatadog Profilerに移行したか

Profilingするだけであればpprofでも問題はありませんでした
しかし、pprofの特性上、webサーバに対してProfileを取得する場合はhttpRequestを行わなければなりません
どこからhttpRequestを行うのか、portはどこに当てるのか、ECS Fargateにインフラを移行中なのでServiceによってProfileの取得方法に差異がでてしまったりしました
また、profilerを導入してる企業だとあるあるかと思いますが、問題が起こったときにしかProfilerを見ずに、継続的にProfilingを実施して改善するActionにつなげにくいという問題もあります
そこでKyashで使っているDatadogにProfiler機能が追加されたので移行することにしました
メリットとしては下記かと思います

  • 見るべきツールが統一されるのでDatadogだけを気にしていればいい
  • Serviceのインフラにより取得方法が変わることがない
  • 簡単にGUIで結果が見れる
  • 定期的にProfilingしてくれるので障害時の情報もサクッと見れる
  • 定期的にProfilingしてくれるのでEngineerの参入障壁が低く継続的にProfileベースでコードを改善していけるポテンシャルがある

GolangでProfilerを有効にする

すでにDatadogを導入しているならかなり簡単です

  1. agentのverを 7.20.2以上 or 6.20.2以上にする

  2. packageをinstallする

go get gopkg.in/DataDog/dd-trace-go.v1/profiler
  1. profilerをimportする
import "gopkg.in/DataDog/dd-trace-go.v1/profiler"
  1. profilerを開始する
err := profiler.Start(
    profiler.WithService("<SERVICE_NAME>"),
    profiler.WithEnv("<ENVIRONMENT>"),
    profiler.WithVersion("<APPLICATION_VERSION>"),
    profiler.WithTags("<KEY1>:<VALUE1>,<KEY2>:<VALUE2>"),
    profiler.WithProfileTypes(
      profiler.CPUProfile,
      profiler.HeapProfile,
      // The profiles below are disabled by default to keep overhead
      // low, but can be enabled as needed.

      // profiler.BlockProfile,
      // profiler.MutexProfile,
      // profiler.GoroutineProfile,
    ),
)
if err != nil {
    log.Fatal(err)
}
defer profiler.Stop()

導入方法なども公式にDocmentにしっかり記載されてるので迷うことはないと思います

docs.datadoghq.com

GolangのProfilerで取得できる項目

GolangのDatadog Profilerは裏でpprofが使用されています

github.com

ですので基本的にpprofで取得できる内容とほぼ同じですが下記が取得できる内容です(documentからの引用です)

CPU Time

各関数がCPUでの実行に費やした時間を示します。ネットワーキング、チャンネル、ミューテックス、スリープの待機のような Off-CPU の時間は、このプロファイルでキャプチャされません。ミューテックスおよびブロックのプロファイルをご確認ください。

Allocations

アプリケーションの開始以降、各関数によってヒープメモリに割り当てられたオブジェクトの数を示します。これには、後で解放された割り当ても含まれます。これは、ガベージコレクションの負荷を調査する際に役立ちます。

Allocated Memory

アプリケーションの開始以降、各関数によって割り当てられたヒープメモリの量を示します。これには、後で解放された割り当ても含まれます。 Go ではこれを alloc_space と呼びます。これは、ガベージコレクションの負荷を調査する際に役立ちます。

Heap Live Objects

各関数によってヒープメモリに割り当てられたオブジェクトの数と、アプリケーションの開始以降に割り当てられたまま残り、最後のガベージコレクション以降存在するオブジェクトの数を示します。これは、サービスの全体的なメモリ使用量を調査する際に役立ちます。

Heap Live Size

各関数によって割り当てられ、アプリケーションの開始以降に割り当てられたまま残り、最後のガベージコレクション以降存在するヒープメモリの量を示します。Go ではこれを inuse_space と呼びます。これは、サービスの全体的なメモリ使用量を調査する際に役立ちます。

Mutex

アプリケーションの開始以降、関数がミューテックスを待機している時間を示します。このプロファイルのスタックトレースは、ミューテックスで続行をブロックされた別の goroutine を許可した Unlock() 演算子をポイントします。スピンロックを使用したショートミューテックスの競合はこのプロファイルでキャプチャされませんが、CPU プロファイルで確認できます。

Block

アプリケーションの開始以降、関数がミューテックスおよびチャンネルオペレーションを待機している時間を示します。スリープ、GC、ネットワーク、Syscall オペレーションは、このプロファイルでキャプチャされません。ブロッキングオペレーションは、ブロックが解除されてからのみキャプチャされるため、スタックしていると思われるアプリケーションのデバッグにこのプロファイルを使用することはできません。ミューテックスの競合の場合、このプロファイルのスタックトレースはブロックされた Lock() 演算子をポイントします。これにより、ブロックされているプログラムがわかり、ミューテックスプロファイルにより、競合の原因となっているプログラムの部分がわかります。この点に関する詳しい情報は、Go におけるプロファイリングのブロックリサーチをご覧ください。

Goroutines

同じ関数（CPU 上および待機中の Off-CPU）で現在実行中の goroutines の数のスナップショットを示します。スナップショット間での goroutines の増加は、プログラムで goroutines がリークしていることを示しています。最も健康なアプリケーションでは、このプロファイルはワーカープールにより使用され、その goroutines 使用数が表示されます。遅延の影響を非常に受けやすく、大量の goroutines（10.000 以上）を使用するアプリケーションの場合、このプロファイルを有効にすると O(N) stop-the-world 型の一時停止が必要になることにご留意ください。一時停止はプロファイリング期間（デフォルトは 60 秒）ごとに発生し、通常 goroutine あたり ~1µsec 継続します。~100ms の p99 レイテンシー SLO の典型的なアプリケーションでは、この警告を無視することが可能です。より詳しい情報については、Go における Goroutine プロファイリングリサーチをご覧ください。

docs.datadoghq.com

実際にProfilingしてみる

APM->Profile Search でprofilerを確認します

CPU Timeはこのような感じ
frame grapthも出て見やすいです call数が出てくれないのが少し不便なところなので、今後のupdateに期待です

HeapLiveSizeはこんな感じです こちらもかなり見やすくgrapth化してくれています

個人的にGolangでDatadog Profilerを使う上で便利だと感じているのはGoroutineの項目です
Goroutineのリークなどの調査に役立っていてとても助かっています
とはいえ、Goroutinesの項目でも触れてますがSTWが発生するので高頻度でのGoroutinesの取得は慎重になったほうがよいかもしれません
リーク周りでおもしろい記事を弊社メンバーが書いてるので興味があればこちらもぜひご覧ください

ECSへ移行したらマシンリソースを使い果たした問題がnet/httpのhttp.Transportの使い方の誤りにあった話 - Qiita

移行してみてどうだったか

まだすべてのマイクロサービスの移行が完了したわけではありませんが、主要なマイクロサービスには導入できてきました
実際に導入してみて、logやdashboardを見るついでにprofilerが気軽に見れる状態なので、profilerを見ることへの抵抗は減ったのかなと思います
また、障害時にもProfilerのおかげで調査の足がかりになったこともあり、改めてProfilerを見ることの大切さに気が付きました
とはいえ、まだまだ継続的にProfilerをみて改善する環境には程遠いと思ってますので、この辺は徐々に改善していきたいなと思っています

おわりに

最近、Kyashに導入したDatadogProfilerの話を書いてみました DatadogはかなりDocumentが充実しているので導入に詰まるようなことはないと思います 継続的なProfilingを気軽にできる点はとても素晴らしいと思いますので、Datadogを使用していて、まだProfilerを導入していない企業の方はぜひ導入を検討してみてください

また、Kyashでは一緒に働くエンジニアの皆様を募集しております
もしご興味ありましたら、以下のリンクをご覧ください

Kyash募集職種一覧
カジュアル面談の申し込み
Podcast kyash.fm