よっしー
こんにちは。よっしーです(^^)
本日は、Go言語のパフォーマンス分析ついて解説しています。
スポンサーリンク
背景
Go言語でアプリケーションを開発していると、必ずと言っていいほど直面するのがパフォーマンスの問題や予期しないバグです。「なぜこんなにメモリを消費しているのか？」「どこで処理が遅くなっているのか？」「このゴルーチンはなぜデッドロックしているのか？」—— こうした疑問に答えるために、Goのエコシステムには強力な診断ツール群が用意されています。
しかし、これらのツールは種類が多く、それぞれ異なる目的と特性を持っているため、どのような場面でどのツールを使うべきか迷ってしまうことも少なくありません。プロファイリング、トレーシング、デバッギング、ランタイム統計…それぞれのツールが解決できる問題は異なり、時には相互に干渉し合うこともあります。
本記事では、Go公式ドキュメントの診断ツールに関する解説を日本語で紹介しながら、実際の開発現場でどのように活用できるかを探っていきます。適切なツールを選択し、効果的に問題を診断することで、より高品質で高性能なGoアプリケーションの開発が可能になるはずです。特に、パフォーマンスのボトルネックを特定し改善することは、ユーザー体験の向上やインフラコストの削減に直結する重要なスキルと言えるでしょう。
実行トレーサー
Goには、幅広いランタイムイベントをキャプチャするランタイム実行トレーサーが付属しています。スケジューリング、システムコール、ガベージコレクション、ヒープサイズ、その他のイベントがランタイムによって収集され、go tool traceによる可視化が可能です。実行トレーサーは、レイテンシと使用率の問題を検出するツールです。CPUがどの程度効率的に利用されているか、ネットワーキングやシステムコールがゴルーチンのプリエンプションの原因となっているかを調査できます。
トレーサーは以下の用途に有用です：
- ゴルーチンの実行方法を理解する
- GC実行などのコアランタイムイベントを理解する
- 並列化が不十分な実行を特定する
ただし、過度なメモリやCPU使用の原因分析などのホットスポットの特定には適していません。まずプロファイリングツールを使用してそれらに対処してください。
go tool traceの可視化は、実行が正常に開始され、その後シリアライズされたことを示しています。これは、ボトルネックを作成する共有リソースのロック競合がある可能性を示唆しています。
ランタイムトレースの収集と分析については、go tool traceを参照してください。
実行トレーサー – プログラムの「心電図」
実行トレーサーとは？
例え: 心電図が心臓の動きを波形で見るように、プログラムの実行を時系列で可視化するツール
プロファイリングが「写真」なら、トレーシングは「動画」です。
トレーサーが記録するイベント
// トレーサーが捉える主なイベント
type RuntimeEvents struct {
Goroutines []GoroutineEvent // ゴルーチンの生成・実行・停止
GC []GCEvent // ガベージコレクション
Syscalls []SyscallEvent // システムコール
Network []NetworkEvent // ネットワークI/O
Blocking []BlockEvent // ブロッキング操作
Scheduling []ScheduleEvent // スケジューリング
}
基本的な使い方
1. トレースの収集
package main
import (
"fmt"
"os"
"runtime/trace"
"sync"
"time"
)
func main() {
// トレースファイル作成
f, err := os.Create("trace.out")
if err != nil {
panic(err)
}
defer f.Close()
// トレース開始
err = trace.Start(f)
if err != nil {
panic(err)
}
defer trace.Stop()
// 実際の処理
runWorkload()
}
func runWorkload() {
var wg sync.WaitGroup
// 並列処理の例
for i := 0; i < 5; i++ {
wg.Add(1)
go func(id int) {
defer wg.Done()
// CPU集約的な処理
calculatePrime(id)
// I/O処理
time.Sleep(10 * time.Millisecond)
fmt.Printf("Worker %d completed\n", id)
}(i)
}
wg.Wait()
}
func calculatePrime(id int) {
// CPU負荷をかける処理
sum := 0
for i := 0; i < 1000000; i++ {
sum += i
}
}
2. トレースの分析
# トレースを可視化
$ go tool trace trace.out
# ブラウザが開いて以下のオプションが表示される：
# - View trace: タイムライン表示
# - Goroutine analysis: ゴルーチン分析
# - Network blocking profile: ネットワーク待機分析
# - Synchronization blocking profile: 同期待機分析
# - Syscall blocking profile: システムコール待機分析
トレースの可視化画面の読み方
時間軸 →
┌─────────────────────────────────────────────┐
│ Proc 0 [G1 実行中][GC ][G2 実行中] │ CPU 0
│ Proc 1 [ 待機 ][G3 実行中][G4 実行中] │ CPU 1
│ Proc 2 [G5 実行中][システムコール][待機] │ CPU 2
│ Proc 3 [G6 実行中][G7 実行中][GC ] │ CPU 3
└─────────────────────────────────────────────┘
凡例：
緑 = 実行中
青 = 実行可能（待機中）
赤 = ブロック中
黄 = システムコール
紫 = GC
実践的な問題検出パターン
パターン1: ロック競合の検出
package main
import (
"os"
"runtime/trace"
"sync"
"time"
)
var (
mu sync.Mutex
counter int
)
// 問題のあるコード：過度なロック競合
func badLocking() {
f, _ := os.Create("lock_contention.out")
defer f.Close()
trace.Start(f)
defer trace.Stop()
var wg sync.WaitGroup
// 多数のゴルーチンが同じロックを競合
for i := 0; i < 100; i++ {
wg.Add(1)
go func() {
defer wg.Done()
for j := 0; j < 1000; j++ {
mu.Lock()
counter++
time.Sleep(1 * time.Microsecond) // 問題：ロック保持時間が長い
mu.Unlock()
}
}()
}
wg.Wait()
}
// 改善版：ロック競合を減らす
func improvedLocking() {
f, _ := os.Create("lock_improved.out")
defer f.Close()
trace.Start(f)
defer trace.Stop()
var wg sync.WaitGroup
numWorkers := 100
// 各ゴルーチンでローカル集計
results := make(chan int, numWorkers)
for i := 0; i < numWorkers; i++ {
wg.Add(1)
go func() {
defer wg.Done()
localCounter := 0
for j := 0; j < 1000; j++ {
localCounter++
}
results <- localCounter
}()
}
// 結果を集約（ロック不要）
go func() {
wg.Wait()
close(results)
}()
total := 0
for v := range results {
total += v
}
}
トレース分析結果:
- 改善前：ゴルーチンが「赤」（ブロック）状態で並ぶ
- 改善後：ゴルーチンが「緑」（実行）状態で並列実行
パターン2: 並列化不足の検出
// 問題：逐次処理
func serialProcessing(items []int) {
f, _ := os.Create("serial.out")
defer f.Close()
trace.Start(f)
defer trace.Stop()
results := make([]int, len(items))
// 逐次処理（1つずつ）
for i, item := range items {
results[i] = expensiveOperation(item)
}
}
// 改善：並列処理
func parallelProcessing(items []int) {
f, _ := os.Create("parallel.out")
defer f.Close()
trace.Start(f)
defer trace.Stop()
results := make([]int, len(items))
var wg sync.WaitGroup
// CPUコア数に合わせてワーカーを起動
numWorkers := runtime.NumCPU()
workCh := make(chan int, len(items))
// ワーカー起動
for w := 0; w < numWorkers; w++ {
wg.Add(1)
go func() {
defer wg.Done()
for i := range workCh {
results[i] = expensiveOperation(items[i])
}
}()
}
// 作業を配布
for i := range items {
workCh <- i
}
close(workCh)
wg.Wait()
}
func expensiveOperation(n int) int {
// CPU集約的な処理
result := 0
for i := 0; i < 1000000; i++ {
result += n * i
}
return result
}
高度なトレース分析
カスタムリージョンとタスク
package main
import (
"context"
"fmt"
"os"
"runtime/trace"
"time"
)
func advancedTracing() {
f, _ := os.Create("advanced.out")
defer f.Close()
trace.Start(f)
defer trace.Stop()
// タスクの作成（大きな作業単位）
ctx, task := trace.NewTask(context.Background(), "MainTask")
defer task.End()
// データ準備フェーズ
trace.WithRegion(ctx, "DataPreparation", func() {
prepareData()
})
// 処理フェーズ
trace.WithRegion(ctx, "Processing", func() {
processData(ctx)
})
// 結果保存フェーズ
trace.WithRegion(ctx, "SaveResults", func() {
saveResults()
})
}
func processData(ctx context.Context) {
// 並列処理の各部分をリージョンとして記録
for i := 0; i < 4; i++ {
go func(id int) {
regionName := fmt.Sprintf("Worker-%d", id)
trace.WithRegion(ctx, regionName, func() {
// ログイベントも記録
trace.Log(ctx, "worker_start",
fmt.Sprintf("Worker %d started", id))
time.Sleep(10 * time.Millisecond)
trace.Log(ctx, "worker_end",
fmt.Sprintf("Worker %d completed", id))
})
}(i)
}
time.Sleep(50 * time.Millisecond) // 待機
}
トレース結果の解釈
よく見るパターンと対処法
type TracePattern struct {
Pattern string
Visual string
Problem string
Solution string
}
var commonPatterns = []TracePattern{
{
Pattern: "直列化",
Visual: "[G1実行][G2待機][G2実行][G3待機]...",
Problem: "ゴルーチンが順番待ち",
Solution: "ロックの粒度を細かくする",
},
{
Pattern: "CPU未使用",
Visual: "[ 空 ][ 空 ][G1][ 空 ]",
Problem: "CPUが遊んでいる",
Solution: "並列度を上げる",
},
{
Pattern: "過度なGC",
Visual: "[GC][実行][GC][実行][GC]",
Problem: "GCが頻繁すぎる",
Solution: "メモリ割り当てを減らす",
},
{
Pattern: "システムコール待ち",
Visual: "[syscall.............]",
Problem: "I/O待機が長い",
Solution: "非同期I/Oやバッファリング",
},
}
トレース分析スクリプト
#!/bin/bash
# analyze_trace.sh
echo "トレース収集と分析"
# 1. トレース収集
echo "1. トレース収集中..."
go test -trace=trace.out -bench=.
# 2. 基本分析
echo "2. 基本統計..."
go tool trace -pprof=net trace.out > net.pprof
go tool trace -pprof=sync trace.out > sync.pprof
go tool trace -pprof=syscall trace.out > syscall.pprof
# 3. プロファイル分析
echo "3. ボトルネック分析..."
go tool pprof -top net.pprof | head -10
go tool pprof -top sync.pprof | head -10
go tool pprof -top syscall.pprof | head -10
# 4. Web UIを起動
echo "4. Web UIを起動..."
go tool trace trace.out
ベストプラクティス
- 適切な期間でトレース
// 短すぎず長すぎず（通常10-30秒） time.AfterFunc(30*time.Second, trace.Stop) - 本番環境での使用
// サンプリングで負荷を軽減 if rand.Float32() < 0.01 { // 1%の確率 startTracing() } - 自動分析
// トレース結果を自動的に分析 analyzeTraceFile("trace.out")
トレーサー vs プロファイラー
| 用途 | 使うツール | 理由 |
|---|---|---|
| CPU使用率が高い | プロファイラー | ホットスポット特定 |
| 応答が遅い | トレーサー | タイムライン分析 |
| メモリリーク | プロファイラー | メモリ割り当て追跡 |
| 並列化不足 | トレーサー | 実行パターン確認 |
| GCが多い | 両方 | 原因と影響を確認 |
実行トレーサーは、プログラムの「動き」を時系列で見ることで、並列処理の問題や待機時間を視覚的に理解できる強力なツールです！
おわりに
本日は、Go言語のパフォーマンス分析について解説しました。
よっしー
何か質問や相談があれば、コメントをお願いします。また、エンジニア案件の相談にも随時対応していますので、お気軽にお問い合わせください。
それでは、また明日お会いしましょう(^^)
コメント