よっしー
こんにちは。よっしーです(^^)
本日は、Go言語のガベージコレクターついて解説しています。
スポンサーリンク
背景
Goのガベージコレクター（GC）は、多くの開発者にとって「ブラックボックス」のような存在です。メモリ管理を自動で行ってくれる便利な仕組みである一方、アプリケーションのパフォーマンスに大きな影響を与える要因でもあります。「なぜ突然レスポンスが遅くなるのか？」「メモリ使用量が想定より多いのはなぜか？」「GCの停止時間をもっと短くできないか？」—— こうした疑問は、Goで高性能なアプリケーションを開発する上で避けて通れない課題です。
本記事では、Go公式ドキュメントの「ガベージコレクションガイド」を日本語で紹介します。このガイドは、GCの動作原理を理解し、その知見を活用してアプリケーションのリソース使用効率を改善することを目的としています。特筆すべきは、このドキュメントがガベージコレクションの前提知識を一切要求しない点です。Go言語の基本的な知識さえあれば、誰でもGCの仕組みを深く理解できるよう設計されています。
なぜ今、GCの理解が重要なのでしょうか。クラウドネイティブ時代において、リソースの効率的な活用はコスト削減に直結します。また、マイクロサービスアーキテクチャでは、各サービスのレイテンシが全体のユーザー体験に影響するため、GCによる一時停止を最小限に抑えることが求められます。このガイドを通じて、「なんとなく動いている」から「理解して最適化できる」レベルへとステップアップし、より高品質なGoアプリケーションの開発を目指しましょう。
実行トレース
CPUプロファイルは、集約的にどこで時間が費やされているかを特定するのに優れていますが、より微妙で、まれで、または特にレイテンシに関連するパフォーマンスコストを示すのにはあまり役立ちません。一方、実行トレースは、Goプログラムの実行の短いウィンドウに対して、豊かで深い視点を提供します。これらには、Go GCに関連するさまざまなイベントが含まれており、特定の実行パスを直接観察でき、アプリケーションがGo GCとどのように相互作用するかも確認できます。追跡されるすべてのGCイベントは、トレースビューアーで便利にラベル付けされています。
実行トレースの使い方については、runtime/traceパッケージのドキュメントを参照してください
実行トレース – GCの動作を時系列で見る
実行トレースは、プログラムの動作を時間軸で記録した詳細なログです。
CPUプロファイル vs 実行トレース
CPUプロファイル: 集計データ
「どこで時間を使ったか」の合計
例:
- 関数A: 30%の時間
- 関数B: 20%の時間
- GC: 15%の時間
でも...
- いつGCが実行されたか → わからない
- なぜそのタイミングか → わからない
- 他の処理への影響 → わからない
例え話: 月の家計簿
- 食費: 5万円
- 交通費: 2万円
- → 合計はわかるが、いつ何を買ったかは不明
実行トレース: タイムライン
「いつ何が起きたか」の詳細記録
例:
0.0秒: プログラム開始
0.5秒: リクエスト1処理開始
0.7秒: GC開始 ← このタイミング!
0.8秒: リクエスト1がブロック ← GCの影響!
0.9秒: GC終了
1.0秒: リクエスト1再開
例え話: 家計簿アプリ
- 1月5日 10:30 コンビニで弁当 500円
- 1月5日 12:00 電車賃 200円
- → いつ何にいくら使ったか全部わかる
実行トレースが得意なこと
1. レイテンシの問題
CPUプロファイル:
「この関数は平均50msかかる」
実行トレース:
「この関数は通常10msだが、
GC中は200msかかる!」
← 問題を特定できる!
2. まれに起きる問題
CPUプロファイル:
「gcAssistAllocは全体の2%」
→ 問題なさそう
実行トレース:
「1秒に1回、100msブロックされる!」
→ これが遅延の原因!
3. GCとの相互作用
実行トレース:
┌────────────────────────────┐
│ Goroutine 1 │
│ [処理中]──[待機]──[処理中] │
│ ↑ │
│ GCで │
│ ブロック │
└────────────────────────────┘
┌────────────────────────────┐
│ GC │
│ ─────[マーク]────[終了]─── │
└────────────────────────────┘
実行トレースの取得方法
方法1: コードに埋め込む
package main
import (
"os"
"runtime/trace"
)
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()
// アプリケーションの処理
// この間の動作がすべて記録される
runApplication()
}
方法2: テストで取得
package main
import (
"os"
"runtime/trace"
"testing"
)
func TestWithTrace(t *testing.T) {
// トレース開始
f, _ := os.Create("test_trace.out")
defer f.Close()
trace.Start(f)
defer trace.Stop()
// テスト実行
runTest()
}
方法3: ベンチマークで取得
# ベンチマークと同時にトレース取得
go test -bench=. -trace=trace.out
トレースファイルの解析
# トレースビューアーを起動
go tool trace trace.out
# ブラウザが自動的に開く
# http://localhost:xxxxx
トレースビューアーの画面
メイン画面
┌──────────────────────────────────────┐
│ View Trace (タイムライン表示) │
│ ↓ ここをクリック │
└──────────────────────────────────────┘
┌──────────────────────────────────────┐
│ Goroutine analysis (goroutine分析) │
└──────────────────────────────────────┘
┌──────────────────────────────────────┐
│ Network blocking profile │
└──────────────────────────────────────┘
┌──────────────────────────────────────┐
│ Synchronization blocking profile │
└──────────────────────────────────────┘
View Trace画面の見方
時間軸 →
┌────────────────────────────────────────┐
│ Goroutines (goroutineの状態) │
│ ████▓▓▓▓░░░░████ │
│ ██████▓▓░░████ │
├────────────────────────────────────────┤
│ Heap (ヒープサイズ) │
│ /\ /\ /\ │
│ / \ / \ / \ │
├────────────────────────────────────────┤
│ GC (GCイベント) │
│ ▓▓ ▓▓ ▓▓ │
└────────────────────────────────────────┘
凡例:
████ = 実行中
▓▓▓▓ = 実行可能(待機中)
░░░░ = ブロック中
GCイベントの見方
GCイベントの色
トレース画面では、GC関連イベントが
色分けされて表示されます:
🟦 青: GCマークフェーズ
🟩 緑: GCスイープフェーズ
🟨 黄: GCアシスト
🟥 赤: STW(ストップ・ザ・ワールド)
具体例: GCの影響
時間軸 →
0.0s 0.5s 1.0s 1.5s
├───────┼───────┼───────┼───────┤
Goroutine 1 (Webリクエスト処理):
████████▓▓▓▓░░░░████████
↑ ↑
│ └─ GCアシストで待機
└─ GC開始
GC:
🟥🟦🟦🟦🟦🟩
│ └─マーク
└─ STW
解釈:
1. 0.5秒: GC開始(短いSTW)
2. 0.5-0.8秒: マークフェーズ
3. 0.6-0.8秒: リクエスト処理がブロック
4. 0.8秒: GC終了
5. 0.8秒: リクエスト処理再開
実践例: 問題の発見
例1: レイテンシスパイクの原因
// 問題のコード
func handleRequest(w http.ResponseWriter, r *http.Request) {
start := time.Now()
// リクエスト処理
result := processData()
latency := time.Since(start)
if latency > 100*time.Millisecond {
log.Printf("High latency: %v", latency)
}
w.Write(result)
}
// トレースで判明:
// 通常: 50ms
// GC中: 200ms ← GCアシストが原因!
トレースでの発見:
Normal request:
[処理]──────────[完了]
50ms
During GC:
[処理]──[待機]──[処理]──[完了]
20ms 100ms 80ms = 200ms
↑
GCアシスト
例2: Goroutineのブロック
// 問題のコード
func worker() {
for task := range taskChan {
// メモリを大量に割り当て
data := make([]byte, 10*1024*1024) // 10MB
process(data)
}
}
// トレースで判明:
// make()の呼び出しでGCアシストが発生
// 各タスクが50ms余分にブロックされる
トレースでの発見:
Worker goroutines:
[Task1]──[Wait]──[Task2]──[Wait]──[Task3]
↑GC ↑GC
GC:
────────[Mark]──────────[Mark]────────
トレースの読み方: ステップバイステップ
ステップ1: 全体像を把握
# トレースを開く
go tool trace trace.out
# View Traceをクリック
# 確認すること:
□ GCがどのくらいの頻度で実行されているか
□ Goroutineがどう動いているか
□ ヒープサイズの推移
ステップ2: GCイベントを見る
# GCイベント(青い領域)をクリック
表示される情報:
- Duration: 5.2ms (GCの実行時間)
- Start: 1.234s (開始時刻)
- Type: GC mark phase
# 複数のGCイベントを比較
□ 実行時間は一定か?
□ 頻度は適切か?
□ STWは短いか?
ステップ3: Goroutineの影響を確認
# Goroutineをクリック
表示される情報:
- State: Running / Runnable / Blocked
- Duration: ブロックされた時間
- Reason: なぜブロックされたか
# 確認:
□ GC中にブロックされているか?
□ どのくらいの時間か?
□ 頻繁に起きているか?
ステップ4: ヒープの変化を見る
# Heapグラフを見る
波形の意味:
/\ ← メモリ割り当て
/ \ ← GC実行
↓ ↓
\/
確認:
□ 急激な増加はないか?
□ GC後に減っているか?
□ リークの兆候はないか?
トレースで見つかる典型的な問題
問題1: 頻繁なGCアシスト
症状:
Goroutineが黄色い領域で頻繁にブロック
原因:
割り当て速度が速すぎる
対処:
1. 割り当てを減らす
2. GOGCを上げる
3. オブジェクトプールを使う
問題2: 長いSTW
症状:
すべてのGoroutineが赤い領域で停止
原因:
- 大量のGoroutine
- 大きなスタック
対処:
1. Goroutine数を減らす
2. スタックサイズを小さくする
問題3: メモリリーク
症状:
Heapグラフが右肩上がり
原因:
メモリが解放されていない
対処:
1. pprofでヒープを分析
2. 不要な参照を削除
トレースの制限と注意点
制限1: 短い時間しか記録できない
理由:
- トレースファイルが巨大になる
- パフォーマンスへの影響
推奨:
- 数秒〜数十秒のトレース
- 問題が起きる部分だけ記録
制限2: オーバーヘッドがある
// トレース中はプログラムが遅くなる
通常: 100ms
トレース中: 120ms ← 20%遅い
対処:
- 本番環境では使わない
- テスト/開発環境で使用
実用的なトレースパターン
パターン1: 問題の再現
func TestReproduceProblem(t *testing.T) {
// 問題が起きる条件を再現
f, _ := os.Create("problem_trace.out")
defer f.Close()
trace.Start(f)
defer trace.Stop()
// 問題を再現
for i := 0; i < 1000; i++ {
problematicFunction()
}
}
パターン2: 比較分析
// Before: 最適化前
func TestBefore(t *testing.T) {
f, _ := os.Create("before_trace.out")
trace.Start(f)
oldImplementation()
trace.Stop()
}
// After: 最適化後
func TestAfter(t *testing.T) {
f, _ := os.Create("after_trace.out")
trace.Start(f)
newImplementation()
trace.Stop()
}
// 2つのトレースを比較して改善を確認
パターン3: 条件付きトレース
var enableTrace = flag.Bool("trace", false, "enable tracing")
func main() {
flag.Parse()
if *enableTrace {
f, _ := os.Create("trace.out")
defer f.Close()
trace.Start(f)
defer trace.Stop()
}
runApp()
}
// 使い方:
// go run main.go -trace # トレース有効
トレースの活用チェックリスト
□ CPUプロファイルで全体像を把握済み
□ 問題が特定できていない(レイテンシなど)
□ 短い時間でトレースを取得
□ View Traceで時系列を確認
□ GCイベントの頻度と影響を確認
□ Goroutineのブロック状況を確認
□ Heapの変化を確認
□ 問題の根本原因を特定
□ 最適化案を考える
□ 改善後に再度トレースで検証
まとめ表
| 特徴 | CPUプロファイル | 実行トレース |
|---|---|---|
| データ | 集計 | タイムライン |
| 時間窓 | 長い(秒〜分) | 短い(秒) |
| 詳細度 | 低 | 高 |
| オーバーヘッド | 小 | 大 |
| 用途 | 全体最適化 | 詳細分析 |
| GC可視化 | 割合のみ | 完全 |
いつどちらを使うか
CPUプロファイルを使う:
✅ 最初の調査
✅ どの関数が遅いか知りたい
✅ 全体的な最適化
実行トレースを使う:
✅ レイテンシの問題
✅ タイミングが重要
✅ GCとの相互作用を見たい
✅ まれに起きる問題
最重要ポイント:
CPUプロファイルで「何が」問題かを特定 実行トレースで「なぜ・いつ」を理解
この2つを組み合わせて使うことで、最も効果的な分析ができます! 🔍
おわりに
本日は、Go言語のガベージコレクターについて解説しました。
よっしー
何か質問や相談があれば、コメントをお願いします。また、エンジニア案件の相談にも随時対応していますので、お気軽にお問い合わせください。
それでは、また明日お会いしましょう(^^)
コメント