第25章デバッグ

Go言語におけるデバッグの基本

Go言語におけるデバッグの基本を理解するために、エラーハンドリング、パニックとリカバリー、ログ出力、デバッグツールの使用方法について具体的な事例を交えて説明します。

エラーハンドリング

Go言語では、エラーは関数の戻り値として返されます。これにより、エラーを明示的にチェックして処理することが推奨されます。

package main

import (
    "errors"
    "fmt"
)

// divideは、割り算を行いエラーを返す関数
func divide(a, b int) (int, error) {
    if b == 0 {
        return 0, errors.New("division by zero")
    }
    return a / b, nil
}

func main() {
    result, err := divide(10, 0)
    if err != nil {
        fmt.Println("Error:", err)
    } else {
        fmt.Println("Result:", result)
    }
}

この例では、divide関数が0での除算をチェックし、エラーを返します。main関数でエラーをチェックし、適切なメッセージを出力しています。

パニックとリカバリー

Go言語では、致命的なエラーが発生した場合に

panic

を使用します。また、

recover

を使ってパニックを回復し、プログラムの実行を続行することもできます。

package main

import "fmt"

// mayPanicは、パニックを発生させる関数
func mayPanic() {
    defer func() {
        if r := recover(); r != nil {
            fmt.Println("Recovered from panic:", r)
        }
    }()
    fmt.Println("About to panic")
    panic("something went wrong")
    fmt.Println("This will not be printed")
}

func main() {
    mayPanic()
    fmt.Println("Program continues")
}

この例では、mayPanic関数内でパニックが発生しますが、deferを使ってrecoverを呼び出し、パニックを回復しています。これにより、プログラムの実行が継続されます。

ログ出力

ログ出力は、プログラムの動作状況を確認するための重要な手法です。Go言語では、logパッケージを使ってログを出力することができます。

package main

import (
    "log"
    "errors"
)

func main() {
    log.Println("Starting the program")
    result, err := divide(10, 2)
    if err != nil {
        log.Println("Error:", err)
    } else {
        log.Println("Result:", result)
    }
}

func divide(a, b int) (int, error) {
    if b == 0 {
        return 0, errors.New("division by zero")
    }
    return a / b, nil
}

この例では、ログメッセージを出力してプログラムの実行状況を記録しています。エラーが発生した場合、そのエラーメッセージもログに記録されます。

Go言語の標準デバッグツール

Go言語には、デバッグを支援するためのいくつかの標準ツールが用意されています。これらのツールを使用することで、プログラムの動作を詳細に確認し、バグを特定して修正することができます。ここでは、Go言語の標準デバッグツールについて具体的な事例を交えて説明します。

fmtパッケージを使ったデバッグ出力

fmtパッケージを使って、標準出力にデバッグ情報を出力することは、最も基本的なデバッグ手法の一つです。

package main

import "fmt"

func main() {
    fmt.Println("Starting the program")
    result, err := divide(10, 2)
    if err != nil {
        fmt.Println("Error:", err)
    } else {
        fmt.Println("Result:", result)
    }
}

func divide(a, b int) (int, error) {
    if b == 0 {
        return 0, fmt.Errorf("division by zero")
    }
    return a / b, nil
}

この例では、fmt.Printlnを使ってプログラムの進行状況や変数の値を出力しています。これにより、プログラムの実行フローやエラーの発生箇所を確認できます。

logパッケージを使ったログ出力

logパッケージを使用すると、より詳細なログを記録し、プログラムの動作を追跡することができます。

package main

import (
    "log"
)

func main() {
    log.Println("Starting the program")
    result, err := divide(10, 2)
    if err != nil {
        log.Println("Error:", err)
    } else {
        log.Println("Result:", result)
    }
}

func divide(a, b int) (int, error) {
    if b == 0 {
        return 0, fmt.Errorf("division by zero")
    }
    return a / b, nil
}

この例では、log.Printlnを使ってログを出力しています。ログメッセージにはタイムスタンプが含まれており、デバッグ情報を詳細に記録できます。

runtimeパッケージを使ったスタックトレース

runtimeパッケージを使うと、プログラムのスタックトレースを出力し、パニックが発生した箇所や呼び出し元を確認できます。

package main

import (
    "fmt"
    "runtime"
)

func main() {
    defer func() {
        if r := recover(); r != nil {
            buf := make([]byte, 1024)
            n := runtime.Stack(buf, false)
            fmt.Printf("Panic: %s\nStack trace:\n%s", r, buf[:n])
        }
    }()
    fmt.Println("Starting the program")
    result := divide(10, 0)
    fmt.Println("Result:", result)
}

func divide(a, b int) int {
    if b == 0 {
        panic("division by zero")
    }
    return a / b
}

この例では、runtime.Stackを使ってパニック発生時のスタックトレースを出力しています。これにより、プログラムがクラッシュした際の詳細な情報を得ることができます。

go testによるユニットテストとデバッグ

Go言語には標準でユニットテストの機能が組み込まれており、go testコマンドを使ってテストを実行できます。ユニットテストを通じて、個々の関数やメソッドの動作を確認し、バグを特定することができます。

テスト対象のコードを用意します。

package main

import "fmt"

func divide(a, b int) (int, error) {
    if b == 0 {
        return 0, fmt.Errorf("division by zero")
    }
    return a / b, nil
}

テストコードを作成します。

package main

import "testing"

func TestDivide(t *testing.T) {
    result, err := divide(10, 2)
    if err != nil {
        t.Errorf("Unexpected error: %v", err)
    }
    if result != 5 {
        t.Errorf("Expected 5, but got %d", result)
    }

    _, err = divide(10, 0)
    if err == nil {
        t.Error("Expected an error, but got none")
    }
}

テストを実行します。

go test

この例では、go testコマンドを使ってdivide関数のテストを実行しています。テストが失敗した場合、詳細なエラーメッセージが表示されます。

Delveによるデバッグ

Delveは、Go言語専用のデバッグツールであり、Goプログラムのデバッグにおいて強力な機能を提供します。Delveを使用すると、プログラムの実行をステップごとに確認したり、ブレークポイントを設定したり、変数の値を調査したりできます。ここでは、Delveを使ったデバッグ方法について具体的な事例を交えて説明します。

Delveのインストール

まず、Delveをインストールします。Delveは、go installコマンドを使用してインストールできます。

go install github.com/go-delve/delve/cmd/dlv@latest

インストール後、dlvコマンドが使用可能になります。

デバッグ対象のプログラム

以下の簡単なプログラムを使用して、Delveによるデバッグの基本を学びます。このプログラムには、エラー処理と基本的な関数呼び出しが含まれています。

package main

import (
    "errors"
    "fmt"
)

func divide(a, b int) (int, error) {
    if b == 0 {
        return 0, errors.New("division by zero")
    }
    return a / b, nil
}

func main() {
    result, err := divide(10, 0)
    if err != nil {
        fmt.Println("Error:", err)
    } else {
        fmt.Println("Result:", result)
    }
}

デバッグの開始

Delveを使用してプログラムをデバッグモードで実行します。

dlv debug main.go

このコマンドでDelveが起動し、インタラクティブなデバッグセッションが開始されます。

ブレークポイントの設定

プログラムの特定の行にブレークポイントを設定します。例えば、

divide

関数のエラーチェック部分にブレークポイントを設定します。

(dlv) break main.go:10

これにより、プログラムが指定された行に到達したときに実行が一時停止します。

プログラムの実行と停止

ブレークポイントが設定されたら、プログラムを続行します。

(dlv) continue

プログラムがブレークポイントに到達すると、実行が停止し、次のコマンドを入力できるようになります。

変数の値を確認

停止した状態で、変数の値を確認します。例えば、err変数の値を確認します。

(dlv) print err

また、result変数の値も確認できます。

(dlv) print result

ステップ実行

プログラムを一行ずつ実行して、各行の実行結果を確認します。

(dlv) next

nextコマンドを使用すると、次の行に進みます。

コールスタックの確認

現在のコールスタックを表示します。これにより、現在の関数呼び出しの流れを確認できます。

(dlv) stack

変数のウォッチ

特定の変数をウォッチすることもできます。これにより、変数の値の変化を追跡できます。

(dlv) watch variableName

実行の再開と終了

プログラムの実行を再開します。

(dlv) continue

デバッグセッションを終了する場合は、以下のコマンドを使用します。

(dlv) exit

ロギングとモニタリング

ロギングとモニタリングは、Go言語で開発されたアプリケーションの運用と保守において非常に重要です。ロギングはアプリケーションの動作を記録し、エラーや警告をトラブルシューティングに役立てます。一方、モニタリングはアプリケーションの健康状態を監視し、パフォーマンスやリソース使用状況を追跡します。以下に、具体的な事例を交えてロギングとモニタリングについて説明します。

ロギングの基本

Go言語では、標準ライブラリのlogパッケージを使って簡単にログを記録できます。

package main

import (
    "log"
)

func main() {
    log.Println("Starting the application...")
    result, err := divide(10, 2)
    if err != nil {
        log.Fatalf("Error occurred: %v", err)
    }
    log.Printf("Result: %d", result)
}

func divide(a, b int) (int, error) {
    if b == 0 {
        return 0, fmt.Errorf("division by zero")
    }
    return a / b, nil
}

この例では、log.Println、log.Fatalf、log.Printfを使ってログメッセージを出力しています。

ログレベルの設定

ログの重要度に応じて、ログレベルを設定することができます。一般的なログレベルには、INFO、WARNING、ERRORなどがあります。Goの標準logパッケージにはログレベルの概念はないため、ログレベルを実装する場合はカスタムロガーを作成するか、外部ライブラリを使用します。

package main

import (
    "log"
    "os"
)

var (
    Info  *log.Logger
    Warning *log.Logger
    Error *log.Logger
)

func init() {
    file, err := os.OpenFile("app.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666)
    if err != nil {
        log.Fatal(err)
    }

    Info = log.New(file, "INFO: ", log.Ldate|log.Ltime|log.Lshortfile)
    Warning = log.New(file, "WARNING: ", log.Ldate|log.Ltime|log.Lshortfile)
    Error = log.New(file, "ERROR: ", log.Ldate|log.Ltime|log.Lshortfile)
}

func main() {
    Info.Println("Starting the application...")
    result, err := divide(10, 2)
    if err != nil {
        Error.Fatalf("Error occurred: %v", err)
    }
    Info.Printf("Result: %d", result)
}

func divide(a, b int) (int, error) {
    if b == 0 {
        return 0, fmt.Errorf("division by zero")
    }
    return a / b, nil
}

この例では、Info、Warning、Errorの各ロガーを使って異なるレベルのログメッセージを記録しています。

Prometheusを使ったモニタリング

Prometheusは、メトリクスを収集し監視するためのオープンソースツールです。Go言語でPrometheus用のメトリクスを収集するには、prometheus/client_golangライブラリを使用します。

ライブラリをインストールします。

go get github.com/prometheus/client_golang/prometheus
go get github.com/prometheus/client_golang/prometheus/promhttp

HTTPサーバーのメトリクスを収集するコードを作成します。

package main

import (
    "net/http"
    "github.com/prometheus/client_golang/prometheus"
    "github.com/prometheus/client_golang/prometheus/promhttp"
)

var (
    httpRequestsTotal = prometheus.NewCounterVec(
        prometheus.CounterOpts{
            Name: "http_requests_total",
            Help: "Total number of HTTP requests",
        },
        []string{"path"},
    )
    httpDuration = prometheus.NewHistogramVec(
        prometheus.HistogramOpts{
            Name:    "http_request_duration_seconds",
            Help:    "Duration of HTTP requests",
            Buckets: prometheus.DefBuckets,
        },
        []string{"path"},
    )
)

func init() {
    prometheus.MustRegister(httpRequestsTotal, httpDuration)
}

func main() {
    http.Handle("/metrics", promhttp.Handler())

    http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
        timer := prometheus.NewTimer(httpDuration.WithLabelValues(r.URL.Path))
        defer timer.ObserveDuration()
        httpRequestsTotal.WithLabelValues(r.URL.Path).Inc()

        w.Write([]byte("Hello, World!"))
    })

    http.ListenAndServe(":8080", nil)
}

この例では、http_requests_totalというカウンタと、http_request_duration_secondsというヒストグラムを定義しています。これらのメトリクスは、Prometheusサーバーによって収集され、HTTPサーバーのリクエスト数やリクエストの処理時間を監視するために使用されます。

Grafanaを使った可視化

Grafanaは、Prometheusなどのデータソースからデータを取得し、ダッシュボードを作成してデータを可視化するためのツールです。Grafanaを使用することで、収集したメトリクスを視覚的に監視することができます。

プロファイリング

プロファイリングは、アプリケーションのパフォーマンスを分析し、リソースの使用状況やボトルネックを特定するための重要な手法です。Go言語には、プロファイリングを支援するための標準ツールが組み込まれています。ここでは、Go言語におけるプロファイリングの基本的な方法を、具体的な事例を交えて説明します。

pprofパッケージを使ったプロファイリング

Go言語には、CPUプロファイリングやメモリプロファイリングを行うためのpprofパッケージが標準で含まれています。このパッケージを使用すると、プログラムのプロファイルデータを収集し、分析することができます。

package main

import (
    "log"
    "os"
    "runtime/pprof"
    "time"
)

func busyWork() {
    sum := 0
    for i := 0; i < 1000000; i++ {
        sum += i
    }
    log.Println("Sum:", sum)
}

func main() {
    // CPUプロファイリングの開始
    f, err := os.Create("cpu_profile.prof")
    if err != nil {
        log.Fatal("could not create CPU profile: ", err)
    }
    if err := pprof.StartCPUProfile(f); err != nil {
        log.Fatal("could not start CPU profile: ", err)
    }
    defer pprof.StopCPUProfile()

    log.Println("Starting busy work...")
    busyWork()

    time.Sleep(2 * time.Second) // プロファイリングのために少し待つ
    log.Println("Finished busy work")
}

この例では、pprof.StartCPUProfileを使ってCPUプロファイリングを開始し、pprof.StopCPUProfileを使ってプロファイリングを停止しています。プロファイリングデータはcpu_profile.profファイルに保存されます。

プロファイルの解析

プロファイルデータを取得した後、go tool pprofコマンドを使用してプロファイルを解析します。

go tool pprof cpu_profile.prof

プロファイルインターフェースが起動し、コマンドラインでさまざまな操作ができます。例えば、topコマンドを入力して、CPU使用率の高い関数を表示します。

(pprof) top

メモリプロファイリング

メモリプロファイリングも同様に行えます。以下のコードでは、メモリプロファイリングを追加しています。

package main

import (
    "log"
    "os"
    "runtime/pprof"
    "time"
)

func allocateMemory() {
    var s []string
    for i := 0; i < 100000; i++ {
        s = append(s, "Go is great!")
    }
    log.Println("Allocated memory")
}

func main() {
    // メモリプロファイリングの開始
    f, err := os.Create("mem_profile.prof")
    if err != nil {
        log.Fatal("could not create memory profile: ", err)
    }
    defer f.Close()

    // メモリの割り当て
    log.Println("Starting memory allocation...")
    allocateMemory()

    // メモリプロファイリングの停止
    if err := pprof.WriteHeapProfile(f); err != nil {
        log.Fatal("could not write memory profile: ", err)
    }

    time.Sleep(2 * time.Second) // プロファイリングのために少し待つ
    log.Println("Finished memory allocation")
}

この例では、pprof.WriteHeapProfileを使ってメモリプロファイルを作成し、mem_profile.profファイルに保存しています。

メモリプロファイルデータもgo tool pprofコマンドを使って解析できます。

HTTPサーバーでのプロファイリング

Goのnet/http/pprofパッケージを使用すると、HTTPサーバーを通じてプロファイリング情報を取得できます。これは、長時間動作するサーバーアプリケーションに対して有用です。

package main

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

func busyWork() {
    sum := 0
    for i := 0; i < 1000000; i++ {
        sum += i
    }
    log.Println("Sum:", sum)
}

func main() {
    // HTTPプロファイリングサーバーの開始
    go func() {
        log.Println("Starting HTTP server for profiling on :6060")
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    log.Println("Starting busy work...")
    busyWork()

    time.Sleep(2 * time.Minute) // プロファイリングのために少し待つ
    log.Println("Finished busy work")
}

この例では、net/http/pprofパッケージをインポートし、HTTPサーバーをlocalhost:6060で起動しています。ブラウザでhttp://localhost:6060/debug/pprof/にアクセスすると、プロファイリング情報を取得できます。

Prometheusを使ったモニタリング

Prometheusを使ってアプリケーションのメトリクスを収集し、プロファイリングと併せて詳細なパフォーマンス解析を行うことも可能です。

package main

import (
    "net/http"
    "github.com/prometheus/client_golang/prometheus"
    "github.com/prometheus/client_golang/prometheus/promhttp"
)

var (
    requestDuration = prometheus.NewHistogramVec(
        prometheus.HistogramOpts{
            Name: "request_duration_seconds",
            Help: "Histogram of response latency (seconds)",
        },
        []string{"path"},
    )
)

func init() {
    prometheus.MustRegister(requestDuration)
}

func main() {
    http.Handle("/metrics", promhttp.Handler())

    http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
        timer := prometheus.NewTimer(requestDuration.WithLabelValues(r.URL.Path))
        defer timer.ObserveDuration()

        w.Write([]byte("Hello, Prometheus!"))
    })

    http.ListenAndServe(":8080", nil)
}

この例では、HTTPリクエストの応答時間を計測するメトリクスを収集しています。Prometheusサーバーを使用してこれらのメトリクスを監視し、分析できます。

練習問題1.

以下のコードには、実行時にパニックが発生するバグがあります。Delveを使ってデバッグし、パニックの原因を特定し修正してください。

package main

import (
    "fmt"
)

func main() {
    numbers := []int{1, 2, 3}
    fmt.Println("Accessing index 3:", numbers[3])
}

練習問題2.

以下のコードにはメモリリークが発生しています。pprofを使ってメモリプロファイリングを行い、メモリリークを発見し修正してください。

package main

import (
    "log"
    "runtime"
    "time"
)

func leakyFunction() {
    data := make([]int, 1000000)
    for i := range data {
        data[i] = i
    }
    log.Println("Data allocated")
}

func main() {
    go func() {
        for {
            leakyFunction()
            runtime.GC()
            time.Sleep(1 * time.Second)
        }
    }()

    select {}
}

練習問題3.

以下のコードでは、busyWork関数が高いCPU使用率を引き起こしています。pprofを使ってCPUプロファイリングを行い、CPU使用率の高い箇所を特定し最適化してください。

package main

import (
    "log"
    "os"
    "runtime/pprof"
)

func busyWork() {
    sum := 0
    for i := 0; i < 1000000000; i++ {
        sum += i
    }
    log.Println("Sum:", sum)
}

func main() {
    f, err := os.Create("cpu_profile.prof")
    if err != nil {
        log.Fatal("could not create CPU profile: ", err)
    }
    if err := pprof.StartCPUProfile(f); err != nil {
        log.Fatal("could not start CPU profile: ", err)
    }
    defer pprof.StopCPUProfile()

    busyWork()
}

第25章 デバッグ

Go言語におけるデバッグの基本

エラーハンドリング

パニックとリカバリー

ログ出力

Go言語の標準デバッグツール

fmtパッケージを使ったデバッグ出力

logパッケージを使ったログ出力

runtimeパッケージを使ったスタックトレース

go testによるユニットテストとデバッグ

Delveによるデバッグ

Delveのインストール

デバッグ対象のプログラム

デバッグの開始

ブレークポイントの設定

プログラムの実行と停止

変数の値を確認

ステップ実行

コールスタックの確認

変数のウォッチ

実行の再開と終了

ロギングとモニタリング

ロギングの基本

ログレベルの設定

Prometheusを使ったモニタリング

ライブラリをインストールします。

Grafanaを使った可視化

プロファイリング

pprofパッケージを使ったプロファイリング

メモリプロファイリング

HTTPサーバーでのプロファイリング

Prometheusを使ったモニタリング

練習問題1.

練習問題2.

練習問題3.

第25章デバッグ