English 中文 العربية 日本語 Português

Go: Goのパフォーマンス分析：pprof（CPU/ヒープ/goroutine）、ベンチマーク、トレース、レース条件検出

最終更新：2026-08-26

パフォーマンス分析は決して難解なものではありません。pprof、benchmark、traceを組み合わせて使用すれば、GoプログラムにおけるCPU、メモリ、および並行処理のボトルネックを特定することができます。

Go APIの応答時間が50ミリ秒から5秒に延びた場合、問題のトラブルシューティングのためにコードにログを追加しますか、それともツールを使って問題の原因を特定しますか？このレッスンでは、Goのパフォーマンス分析に役立つ一連のツールを完全にマスターします。

1. 学習内容

2. バックエンドエンジニアの実話

(1) 課題：APIの応答時間が50ミリ秒から5秒に悪化し、原因を突き止めるのに1週間のログ調査を要した

ボブは決済チームのバックエンドエンジニアですが、彼が担当するAPIの処理速度がどんどん遅くなってきています：

「1ヶ月前までは決済インターフェースは問題なく動作していたのに、今週になって応答に5秒もかかるようになった。各関数の開始と終了にタイムスタンプを付けるためにfmt.Printlnを使って、50行のログ出力を追加した。コードを10回修正して10回デプロイしたが、それでも問題の原因が特定できなかった。上司から『もう1週間も経つのに、一体何が問題なんだ？』と聞かれた。」

彼の疑いの矛先は、以下の点に向けられている：

TEXT 📖 参照専用 
❌ Database too slow? — But queries only take 2ms
❌ Downstream service timeout? — Called it and the response is normal
❌ Network latency? — All in the same datacenter
✅ Actual cause: string concatenation causing massive memory allocation + frequent GC

(2) Goの解決策：精密なデバッグのためのpprof

GO 
import (
    "net/http"
    _ "net/http/pprof"  // One line to enable pprof
)

func main() {
    // pprof endpoints auto-registered at /debug/pprof/
    go func() {
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()
    // Business code continues running...
}

すると、ボブは走り出した：

BASH 
# Collect 30-second CPU profile
go tool pprof -http=:8081 http://localhost:6060/debug/pprof/profile?seconds=30

# Result: flame graph shows strings.Builder only uses 2% CPU,
# while strings.Join + garbage collection uses 78% CPU!

(3) メリット：推測とツールの比較

手法 所要時間 精度
fmt.Println ロギング 1週間（複数回のデプロイ） ❌ 推測
pprofによるCPUプロファイル 30秒 ✅ 負荷の高い関数の正確な特定
pprof ヒーププロファイル 1 秒 ✅ 行番号単位までのメモリ割り当ての詳細

3. pprof の起動方法

▶ サンプル：HTTPメソッド（最も一般的なもの）

GO 
package main

import (
    "fmt"
    "log"
    "net/http"
    _ "net/http/pprof"  // Import to auto-register pprof endpoints
    "time"
)

func slowFunction() {
    // Simulate a slow function
    var result string
    for i := 0; i < 100000; i++ {
        result += fmt.Sprintf("%d ", i) // Bad string concatenation
    }
}

func main() {
    // Start pprof HTTP service (separate port, not exposed externally)
    go func() {
        log.Println("pprof listening on :6060")
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    // Business service
    http.HandleFunc("/work", func(w http.ResponseWriter, r *http.Request) {
        slowFunction()
        fmt.Fprintln(w, "done")
    })

    log.Println("Business service listening on :8080")
    log.Fatal(http.ListenAndServe(":8080", nil))
}
▶ 試してみよう
BASH 
# pprof endpoints:
# http://localhost:6060/debug/pprof/          — index
# http://localhost:6060/debug/pprof/profile   — CPU profile (default 30s)
# http://localhost:6060/debug/pprof/heap      — Heap profile
# http://localhost:6060/debug/pprof/goroutine — goroutine info
# http://localhost:6060/debug/pprof/block     — block analysis
# http://localhost:6060/debug/pprof/mutex     — lock contention analysis

▶ サンプル：テスト手法（ベンチマーク + pprof）

GO 
// string_bench_test.go
package main

import (
    "strings"
    "testing"
)

// Bad approach: + concatenation
func BenchmarkStringPlus(b *testing.B) {
    for i := 0; i < b.N; i++ {
        var s string
        for j := 0; j < 1000; j++ {
            s += "a"
        }
    }
}

// Good approach: strings.Builder
func BenchmarkStringBuilder(b *testing.B) {
    for i := 0; i < b.N; i++ {
        var sb strings.Builder
        for j := 0; j < 1000; j++ {
            sb.WriteString("a")
        }
        _ = sb.String()
    }
}

// Good approach: pre-allocate
func BenchmarkStringBuilderPrealloc(b *testing.B) {
    for i := 0; i < b.N; i++ {
        var sb strings.Builder
        sb.Grow(1000)
        for j := 0; j < 1000; j++ {
            sb.WriteString("a")
        }
        _ = sb.String()
    }
}
▶ 試してみよう
BASH 
# Run benchmark (view memory allocations)
$ go test -bench=. -benchmem -count=3

# Generate CPU profile
$ go test -bench=. -cpuprofile=cpu.prof -memprofile=mem.prof

# Analyze profile
$ go tool pprof -http=:8081 cpu.prof

4. CPUプロファイル

▶ サンプル：CPUのホットスポットの特定

GO 
package main

import (
    "log"
    "net/http"
    _ "net/http/pprof"
    "strings"
)

func heavyCPU() string {
    var sb strings.Builder
    for i := 0; i < 10000; i++ {
        sb.WriteString("hello")
        sb.WriteString(" ")
        sb.WriteString("world")
        sb.WriteString("\n")
    }
    return sb.String()
}

func main() {
    go func() {
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    http.HandleFunc("/cpu", func(w http.ResponseWriter, r *http.Request) {
        result := heavyCPU()
        w.Write([]byte(result[:100]))
    })

    log.Fatal(http.ListenAndServe(":8080", nil))
}
▶ 試してみよう
BASH 
# Collect CPU profile (access /cpu endpoint multiple times within 30 seconds)
$ go tool pprof -http=:8081 http://localhost:6060/debug/pprof/profile?seconds=30

# CLI mode
$ go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30
(pprof) top       # Show Top 10 hot functions
(pprof) list main # View per-line time in the main package
(pprof) web       # Open visualization in browser

(2) pprof top の出力の解釈

TEXT 📖 参照専用 
(pprof) top
Showing nodes accounting for 4.56s, 82.31% of 5.54s total
Dropped 28 nodes (cum <= 0.03s)
      flat  flat%   sum%        cum   cum%
     2.34s 42.24% 42.24%      2.34s 42.24%  runtime.memmove
     1.12s 20.22% 62.46%      1.12s 20.22%  runtime.mallocgc
     0.56s 10.11% 72.57%      0.56s 10.11%  strings.(*Builder).copy
     ...
列 意味
flat 現在の関数自体の実行時間
flat% 「フラット」に費やした時間が総時間のうち占める割合
sum% 累積割合
cum 現在の関数およびそれが呼び出すすべてのサブ関数にかかる時間
cum% 累積時間が総時間のうち占める割合
💡 ヒント： flat の値が高い関数は「それ自体が処理が遅い」（ホットスポット）のに対し、cum の値は高いが flat の値が低い関数は「呼び出しが原因で処理が遅い」（管理上の問題）ものです。まず、flatの値が最も高い関数を最適化してください。そうすることで、最も早く結果が得られます。

5. ヒーププロファイル

▶ サンプル：メモリリークの特定

GO 
package main

import (
    "log"
    "net/http"
    _ "net/http/pprof"
)

var leak []string  // Global variable, never garbage collected

func memoryLeak() {
    // Appends 10000 entries on each call, never clears
    for i := 0; i < 10000; i++ {
        leak = append(leak, "leaked string data")
    }
}

func main() {
    go func() {
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    http.HandleFunc("/leak", func(w http.ResponseWriter, r *http.Request) {
        memoryLeak()
        w.Write([]byte("leaked"))
    })

    log.Fatal(http.ListenAndServe(":8080", nil))
}
▶ 試してみよう
BASH 
# Collect heap profile (view current memory allocation)
$ go tool pprof -http=:8081 http://localhost:6060/debug/pprof/heap

# View functions with the most allocations
$ go tool pprof -alloc_space http://localhost:6060/debug/pprof/heap
(pprof) top
(pprof) list main.memoryLeak

(2) ヒープ表示モード

BASH 
# Four viewing modes:
-inuse_space  # Currently in-use memory (default)
-inuse_objects # Currently in-use object count
-alloc_space  # Total allocated memory
-alloc_objects # Total allocated object count

# Use alloc_space to find leaks (see who allocates the most)
$ go tool pprof -alloc_space http://localhost:6060/debug/pprof/heap
モード 目的
inuse_space 現在のメモリ使用量（メモリリーク検出の最終結果）
inuse_objects 現在のオブジェクト数（多数の小さなオブジェクトを検索する場合）
alloc_space 総割り当て量（頻繁なGCの根本原因を特定するため）
alloc_objects 割り当て総数（短命なオブジェクトを特定するため）

6. ゴルーチンプロファイル

▶ サンプル：ゴルーチンリークの検出

BASH 
# View goroutine count and status
$ go tool pprof http://localhost:6060/debug/pprof/goroutine

# View goroutine stack trace (text)
$ curl http://localhost:6060/debug/pprof/goroutine?debug=2
GO 
package main

import (
    "fmt"
    "log"
    "net/http"
    _ "net/http/pprof"
    "time"
)

func leakyGoroutine() {
    ch := make(chan int)
    go func() {
        // This goroutine will never exit
        val := <-ch  // Blocks forever
        fmt.Println(val)
    }()
    // ch will never receive data
}

func main() {
    go func() {
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    http.HandleFunc("/leak", func(w http.ResponseWriter, r *http.Request) {
        leakyGoroutine()
        w.Write([]byte("leaked"))
    })

    log.Fatal(http.ListenAndServe(":8080", nil))
}
BASH 
$ curl http://localhost:6060/debug/pprof/goroutine?debug=2
# The output shows each goroutine's stack trace:
# goroutine 5 [chan receive]:
# main.leakyGoroutine.func1()
#     /app/main.go:14
# If you see many [chan receive] with no corresponding sender → leak

7. ベンチマークとトレース

▶ サンプル：Benchmark + -benchmem

GO 
// bench_test.go
package main

import (
    "encoding/json"
    "testing"
)

type Data struct {
    ID    int    `json:"id"`
    Name  string `json:"name"`
    Email string `json:"email"`
}

// Benchmark: JSON serialization performance
func BenchmarkJSONMarshal(b *testing.B) {
    data := Data{ID: 1, Name: "Alice", Email: "alice@example.com"}

    for i := 0; i < b.N; i++ {
        _, err := json.Marshal(data)
        if err != nil {
            b.Fatal(err)
        }
    }
}

// Benchmark: JSON serialization + pre-allocated buffer
func BenchmarkJSONMarshalBuffer(b *testing.B) {
    data := Data{ID: 1, Name: "Alice", Email: "alice@example.com"}
    buf := make([]byte, 0, 256)

    for i := 0; i < b.N; i++ {
        buf = buf[:0]
        result, err := json.Marshal(data)
        if err != nil {
            b.Fatal(err)
        }
        buf = append(buf, result...)
    }
}
▶ 試してみよう
BASH 
$ go test -bench=. -benchmem -count=5 ./...
BenchmarkJSONMarshal-8          10000000   156.2 ns/op   48 B/op   1 allocs/op
BenchmarkJSONMarshalBuffer-8    10000000   158.1 ns/op   48 B/op   1 allocs/op

▶ サンプル：トレース

GO 
package main

import (
    "fmt"
    "os"
    "runtime/trace"
    "sync"
)

func main() {
    // Create trace file
    f, _ := os.Create("trace.out")
    defer f.Close()

    // Start trace
    trace.Start(f)
    defer trace.Stop()

    // Run code under test
    var wg sync.WaitGroup
    for i := 0; i < 10; i++ {
        wg.Add(1)
        go func(id int) {
            defer wg.Done()
            result := fibonacci(30)
            fmt.Printf("Worker %d: %d\n", id, result)
        }(i)
    }
    wg.Wait()
}

func fibonacci(n int) int {
    if n <= 1 {
        return n
    }
    return fibonacci(n-1) + fibonacci(n-2)
}
▶ 試してみよう
BASH 
# After generating the trace file, view it in a browser
$ go tool trace trace.out
# Opens the browser, showing:
# - Goroutine analysis: how long each goroutine ran
# - Scheduling latency: when goroutines were scheduled
# - Network blocking: what goroutines are waiting for
# - System calls: when GC ran

8. 完全な例：「500 msの応答遅延」の特定

▶ サンプル：完全なデバッグデモ

GO 📖 参照専用 
// debug_demo.go
package main

import (
    "encoding/json"
    "fmt"
    "log"
    "net/http"
    _ "net/http/pprof"
    "strings"
)

// ---------- Slow API ----------

type UserResponse struct {
    ID    int    `json:"id"`
    Name  string `json:"name"`
    Email string `json:"email"`
    Bio   string `json:"bio"`
}

// Bad version: string concatenation + heavy allocation
func generateUserJSON(userID int) []byte {
    var bio strings.Builder
    // Simulate generating a large amount of text
    for i := 0; i < 1000; i++ {
        bio.WriteString(fmt.Sprintf("Line %d: User data for ID %d with some additional info\n", i, userID))
    }

    resp := UserResponse{
        ID:    userID,
        Name:  fmt.Sprintf("User_%d", userID),
        Email: fmt.Sprintf("user%d@example.com", userID),
        Bio:   bio.String(),
    }

    data, _ := json.Marshal(resp)
    return data
}

// Optimized version: pre-allocation + reduced formatting
func generateUserJSONOptimized(userID int) []byte {
    // Pre-allocate buffer
    var bio strings.Builder
    bio.Grow(50000)  // Estimated size

    for i := 0; i < 1000; i++ {
        bio.WriteString("Line ")
        bio.WriteString(fmt.Sprintf("%d", i))  // Can be further optimized with strconv.Itoa
        bio.WriteString(": User data for ID ")
        bio.WriteString(fmt.Sprintf("%d", userID))
        bio.WriteString(" with some additional info\n")
    }

    resp := UserResponse{
        ID:    userID,
        Name:  "User_" + fmt.Sprintf("%d", userID),
        Email: fmt.Sprintf("user%d@example.com", userID),
        Bio:   bio.String(),
    }

    data, _ := json.Marshal(resp)
    return data
}

// ---------- Analysis workflow ----------

/*
Debugging workflow:

(1) Step 1: Start pprof HTTP server
go run main.go (automatically starts pprof on :6060)

(2) Step 2: Load test
# In another terminal, send continuous requests
while true; do curl http://localhost:8080/user/1 > /dev/null; done

(3) Step 3: Collect CPU profile
go tool pprof -http=:8081 http://localhost:6060/debug/pprof/profile?seconds=30

(4) Step 4: View flame graph in browser
- Look for the widest color blocks → hot functions
- If you see runtime.memmove / runtime.mallocgc → excessive memory allocation
- Click main.generateUserJSON → view per-line code timing

(5) Step 5: View Heap profile
go tool pprof -alloc_space http://localhost:6060/debug/pprof/heap
(pprof) top
*/

func main() {
    // pprof
    go func() {
        log.Println("pprof on :6060")
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    // Business endpoint
    http.HandleFunc("/user/{id}", func(w http.ResponseWriter, r *http.Request) {
        id := r.PathValue("id")
        var userID int
        fmt.Sscanf(id, "%d", &userID)

        data := generateUserJSON(userID)
        w.Header().Set("Content-Type", "application/json")
        w.Write(data)
    })

    log.Println("Service listening on :8080")
    log.Fatal(http.ListenAndServe(":8080", nil))
}
論理コード 78 行（40 行制限超過、参照専用）
100% 
flowchart TD
    A[API slow response] --> B{Problem type?}
    B -->|High CPU| C[pprof CPU profile]
    B -->|High memory| D[pprof Heap profile]
    B -->|Many goroutines| E[pprof goroutine profile]
    B -->|Scheduling latency| F[go tool trace]

    C --> C1[View flame graph]
    C1 --> C2{Hot function?}
    C2 -->|runtime.memmove| G[Reduce memory allocation]
    C2 -->|Business function| H[Optimize algorithm / add cache]

    D --> D1[View alloc_space]
    D1 --> D2{Who allocates the most?}
    D2 -->|strings.Builder| I[Pre-allocate with Grow]
    D2 -->|Temporary objects| J[Use sync.Pool]

    E --> E1[View goroutine stack]
    E1 --> E2{Goroutine status?}
    E2 -->|chan receive blocked| K[Check channel sender]
    E2 -->|IO wait| L[Check connection pool]

    F --> F1[View goroutine analysis]
    F1 --> F2{Scheduling latency?}
    F2 -->|GC pause| M[Reduce memory allocation]
    F2 -->|System calls| N[Optimize IO operations]
💡 ヒント： パフォーマンス最適化のための3ステップのアプローチ：測定 → 特定 → 最適化。ボトルネックがどこにあるかを推測するのではなく、まず pprof を実行してデータを収集し、そのデータに基づいて判断を下しましょう。Goにおける最も一般的なパフォーマンスのボトルネックは、過剰なメモリ割り当て（GC負荷の高さ）と非効率的な文字列連結です。

❓ よくある質問

Q pprof を起動するにはどうすればよいですか？
A 2つの方法があります：(1) HTTP メソッド：import _ "net/http/pprof"、その後 HTTP サービスを起動します。エンドポイントは /debug/pprof/ に自動的に登録されます。(2) テストモード：go test -cpuprofile=cpu.prof -memprofile=mem.prof。本番環境では、専用ポート（外部に公開されていないもの）経由でHTTPメソッドを使用してください。
Q CPUプロファイルとヒーププロファイルの違いは何ですか？
A CPUプロファイルは「CPUが現在実行している関数」をサンプリング（時間ベースのサンプリング）し、CPUのホットスポットを特定するために使用されます。一方、ヒーププロファイルは「メモリに割り当てられたオブジェクト」をサンプリングし、メモリリークやGCの負荷を特定するために使用されます。これらは2つの異なる種類のプロファイルであり、同時に収集することができます。
Q ゴルーチンプロファイルでは何に注目すべきですか？
A ゴルーチン数とステータスを確認してください。curl /debug/pprof/goroutine?debug=2 を使用して、各ゴルーチンごとのスタックトレースを表示します。[chan receive] 状態のゴルーチンが多数ある場合は、チャネルリークを示している可能性があります。[IO wait] 状態のゴルーチンが多数ある場合は、接続プールが不足していることを示している可能性があります。
Q ベンチマークにおける -benchmem オプションの出力をどのように解釈すればよいですか？
A 3つの列があります：ns/op（1操作あたりの時間）、B/op（1操作あたりの割り当てバイト数）、allocs/op（1操作あたりの割り当て回数）です。最適化の目標：GC時間はオブジェクトの数に関係するため、allocs/op（割り当て回数）を減らすことです。
Q trace と pprof の違いは何ですか？
A pprof は「ボトルネックはどこか？」という問いに答えるために「スナップショット」（サンプリング）を撮影します。一方、trace は「なぜ遅いのか？」という問いに答えるために「動画」（イベントストリーム）を記録します。trace は、ゴルーチンのスケジューリングに関する完全なタイムライン（ゴルーチンがいつ実行され、いつブロックされ、GC がいつ一時停止するか）を提供します。まず pprof を使って問題のある箇所を特定し、次に trace を使って根本原因を分析します。
Q レース検出器はどのように使用しますか？
A go run -race main.go または go test -race ./... です。レース検出機能は、実行時にデータレースを検出します。同じ変数に対する並行した読み取りおよび書き込み（少なくとも1回の書き込みを含む）が発生すると、警告が表示されます。CI/CD環境では常に-raceを有効にすることを推奨しますが、実行速度が大幅に低下（5～20倍）するため、本番環境では有効にしないでください。
Q Goにおける一般的なパフォーマンスのボトルネックにはどのようなものがありますか？
A (1) 文字列連結に + ではなく strings.Builder を使用すること； (2) スライスやマップのサイズを事前に割り当て忘れること； (3) 頻繁なJSONのシリアライズ／デシリアライズ； (4) リソースが解放されないままになるゴーラウトンのリーク； (5) チャネルの不適切な使用によるブロッキング； (6) 激しいロック競合。pprofを使用してこれらの問題を特定し、一つずつ最適化してください。

📖 まとめ

📝 練習問題

  1. 基本（難易度 ⭐）：パフォーマンスの問題があるプログラム（+ を使用した大量の文字列連結を含む）を作成し、pprof の HTTP エンドポイントを有効にします。go tool pprof -http=:8081 を実行して CPU プロファイルを表示し、ホットスポットを特定してください。その後、strings.Builder を使用してコードを最適化し、変更前後の CPU プロファイルを比較してください。

  2. 上級 (難易度 ⭐⭐): ベンチマークと pprof を使用して、JSON シリアライゼーションのパフォーマンスを分析する。要件: (1) 100 個のフィールドを含む構造体を作成する; (2) json.Marshal と json.Encoder のパフォーマンスを比較する; (3) -benchmem を使用してメモリ割り当てを確認する；(4) -cpuprofile を使用してプロファイルを生成し、go tool pprof を使ってホットスポットを分析する。

  3. 課題（難易度 ⭐⭐⭐）：メモリリークのあるプログラムを診断し、修正してください。メモリリーク（ゴルーチンリーク＋スライスリーク）を含むGoコードが提供されます。要件：(1) pprofによるヒーププロファイリングを使用して、リークの発生源を特定すること；(2) ゴルーチンプロファイルを使用して、リークの数を確認すること；(3) -raceを使用して、並行処理上の問題を検出すること；(4) すべての問題を修正した後、pprofを使用してリークがなくなったことを確認すること；(5) 完全な診断レポートを作成すること。

Web-Tutorial.com

Web-Tutorial 技術チーム

複数の開発者によって共同維持されているプログラミングチュートリアルプラットフォーム。各チュートリアルは専門分野の開発者が執筆・レビューしています。正確で信頼性の高いコンテンツを目指しています — 問題を見つけた場合はお知らせください。

100%