導入: なぜGCのログを見る必要があるのか？
Go言語はガベージコレクション（GC）が自動でメモリを管理してくれるため、開発者がメモリ解放を意識する必要はほとんどありません。しかし、アプリケーションの規模が大きくなると「なぜか急にレスポンスが遅くなる」「メモリ使用量が想定以上に増え続ける」といった問題に直面することがあります。そんな時、GCが裏でどのような働きをしているかを可視化できるのが「GODEBUG=gctrace=1」です。本記事では、この便利なツールを使ってメモリ管理のボトルネックを特定する方法を解説します。
基礎知識: GCとSTW(Stop The World)
GCとは、プログラムが使用しなくなったメモリ領域を自動的に回収する仕組みです。GoのGCは非常に高速ですが、メモリ管理の過程で「STW (Stop The World)」という、プログラムの実行を一時的に止めてメモリの整合性を確認する処理が発生します。この時間が長すぎると、サービスのレスポンス遅延に直結します。GODEBUG=gctrace=1は、このGCの実行タイミングや、どれくらいのメモリを回収したか、そしてSTWにどれだけの時間がかかったかを標準エラー出力に表示してくれる設定です。
実装/解決策: GCログを有効にする方法
特別なコードを書く必要はありません。プログラムを実行する際に環境変数を指定するだけです。ターミナルで実行するコマンドに「GODEBUG=gctrace=1」を付与して起動してください。これにより、GCが発生するたびに詳細な情報がターミナルに流れるようになります。
サンプルプログラム: GCの動きを観察する
以下のコードを実行し、ターミナルでログがどう変化するかを確認してみましょう。
// main.go
package main
import (
“fmt”
“time”
)
func main() {
fmt.Println(“メモリ確保を開始します…”)
// 大量のメモリを一時的に確保してGCを誘発するループ
for i := 0; i < 5; i++ {
// 巨大なスライスを作成
data := make([]byte, 1010241024) // 10MB確保
_ = data // 使用する
fmt.Printf("ループ回数: %d\n", i+1)
time.Sleep(1 time.Second)
}
}
// 実行方法:
// GODEBUG=gctrace=1 go run main.go
/
実行結果の出力例:
gc 1 @0.001s 0%: 0.001+0.045+0.001 ms clock, ...
このログの「0.001+0.045+0.001 ms」の部分が、
各フェーズの所要時間を示しています。
/
応用・注意点: 現場で役立つ活用法
1. ログの読み方
ログに出力される「gc # @#s」は、何回目のGCか、開始からの経過時間を示します。特に注目すべきは「clock」の数値です。ここがミリ秒単位で大きくなっている場合、メモリの確保頻度が高すぎてGCが追い付いていないか、一度に確保するオブジェクトが巨大すぎる可能性があります。
2. 本番環境での注意
GODEBUG=gctrace=1は非常に有用ですが、GCが発生するたびにログを書き出すため、非常に高い負荷がかかっている環境ではログ出力自体がパフォーマンスを低下させる可能性があります。本番環境で常時有効にするのではなく、調査が必要な時や、パフォーマンスチューニングを行うステージング環境で活用するのがベストです。
3. 回避策
もしGCの頻度が高すぎて困っている場合は、メモリの再利用（sync.Poolの使用）や、スライスを必要以上に大きく確保しない工夫を行うことで、GCの負荷を劇的に下げることができます。まずはこのログを見て「どこでGCが頻発しているか」という事実を確認することから始めてみましょう。
コメント