Keyboard shortcuts

Press or to navigate between chapters

Press S or / to search in the book

Press ? to show this help

Press Esc to hide this help

[インデックス 10756] ファイルの概要

このコミットは、Go言語の標準ライブラリであるnet/httpパッケージ内のHTTPサーバーがパニック(panic)を起こした際に、スタックトレースが確実に表示されるようにするための修正です。特にテスト環境下でローカルHTTPサーバーがパニックし、テストが終了してしまうと、スタックトレースが出力されないままになる問題を解決します。

コミット

commit 516168057e0b2a30bcda024892ed36badb731c00
Author: Roger Peppe <rogpeppe@gmail.com>
Date:   Tue Dec 13 16:34:22 2011 -0500

    http: close connection after printing panic stack trace
    In a testing situation, it's possible for a local http
    server to panic and the test exit without the stack trace
    ever being printed.
    Fixes #2480.
    
    R=rsc, bradfitz
    CC=golang-dev
    https://golang.org/cl/5414048

GitHub上でのコミットページへのリンク

https://github.com/golang/go/commit/516168057e0b2a30bcda024892ed36badb731c00

元コミット内容

http: close connection after printing panic stack trace
In a testing situation, it's possible for a local http
server to panic and the test exit without the stack trace
ever being printed.
Fixes #2480.

変更の背景

Go言語のnet/httpパッケージで提供されるHTTPサーバーは、リクエスト処理中に予期せぬエラー(パニック)が発生した場合、そのパニックを捕捉し、スタックトレースを出力するメカニズムを持っています。しかし、このコミットが修正しようとしている問題は、特にテスト環境のような状況で顕著でした。

具体的には、HTTPサーバーがパニックを起こした後、そのパニックを捕捉してスタックトレースをログに出力する処理が行われます。しかし、このログ出力が完了する前に、テストプロセス自体が終了してしまう可能性がありました。これは、パニックが発生したコネクションがすぐに閉じられてしまい、ログバッファがフラッシュされる前にプログラムが終了してしまうためと考えられます。結果として、開発者やテスターは、何が問題を引き起こしたのかを示す重要な情報であるスタックトレースを見ることができず、デバッグが困難になるという問題が発生していました。

この問題はGoのIssue #2480として報告されており、このコミットはその解決を目的としています。

前提知識の解説

Go言語のpanicrecover

Go言語には、プログラムの異常終了を扱うためのpanicrecoverというメカニズムがあります。

  • panic: 実行時エラーやプログラマが意図的に発生させることで、現在の関数の実行を中断し、呼び出し元の関数へと遡ってパニックを伝播させます。最終的にmain関数まで到達すると、プログラムは異常終了し、スタックトレースが出力されます。
  • recover: deferされた関数内でrecover()を呼び出すことで、パニックの伝播を停止し、パニックが発生した時点からのプログラムの実行を再開させることができます。これにより、予期せぬパニックによってプログラム全体がクラッシュするのを防ぎ、エラーハンドリングを行うことが可能になります。

net/httpパッケージのサーバー処理

Goのnet/httpパッケージは、HTTPサーバーを構築するための強力な機能を提供します。HTTPサーバーは通常、各クライアントからのリクエストを個別のゴルーチン(goroutine)で処理します。http.Server構造体には、リクエスト処理中に発生したパニックを捕捉し、適切に処理するための内部ロジックが含まれています。

debug.Stack()

runtime/debugパッケージのStack()関数は、現在のゴルーチンのスタックトレースをバイトスライスとして返します。これは、パニックが発生した際に、その時点でのプログラムの実行パスを特定するために非常に有用です。通常、パニックをrecoverした後に、この関数を使ってスタックトレースを取得し、ログに出力することで、デバッグ情報を得ます。

io.CloserClose()

Go言語では、リソース(ファイル、ネットワークコネクションなど)を扱う際に、io.Closerインターフェースがよく使われます。このインターフェースはClose()メソッドを一つだけ持ち、リソースを解放する責任を負います。ネットワークコネクションの場合、Close()を呼び出すことで、そのコネクションが閉じられ、関連するリソースが解放されます。

技術的詳細

このコミットの技術的な核心は、HTTPサーバーのパニックハンドリングロジックにおけるc.rwc.Close()の呼び出し順序の変更にあります。

net/http/server.go内のconn.serve()メソッドは、各HTTPコネクションの処理を担当するゴルーチン内で実行されます。このメソッドの冒頭には、deferステートメントを使ってパニックを捕捉し、スタックトレースをログに出力するリカバリー関数が設定されています。

元のコードでは、パニックを捕捉した後、スタックトレースをbytes.Bufferに書き込み、log.Printで出力する前にc.rwc.Close()(コネクションのクローズ)が呼び出されていました。

// 変更前
func (c *conn) serve() {
    defer func() {
        if err := recover(); err != nil {
            // ...
            if c.rwc != nil { // may be nil if connection hijacked
                c.rwc.Close() // ここでコネクションが閉じられる
            }

            var buf bytes.Buffer
            fmt.Fprintf(&buf, "http: panic serving %v: %v\n", c.remoteAddr, err)
            buf.Write(debug.Stack())
            log.Print(buf.String()) // その後ログ出力
        }
    }()
    // ...
}

この順序の問題点は、c.rwc.Close()が呼び出されると、基盤となるネットワークコネクションが閉じられてしまいます。特にテスト環境のような、プログラムのライフサイクルが短い状況では、コネクションが閉じられた直後にテストプロセス自体が終了してしまう可能性があります。その結果、log.Print(buf.String())によるスタックトレースの出力が完了する前にプログラムが終了し、ログがフラッシュされずに失われてしまうことがありました。

このコミットでは、c.rwc.Close()の呼び出しを、スタックトレースをlog.Printで出力した後ろに移動させました。

// 変更後
func (c *conn) serve() {
    defer func() {
        if err := recover(); err != nil {
            // ...
            var buf bytes.Buffer
            fmt.Fprintf(&buf, "http: panic serving %v: %v\n", c.remoteAddr, err)
            buf.Write(debug.Stack())
            log.Print(buf.String()) // まずログ出力

            if c.rwc != nil { // may be nil if connection hijacked
                c.rwc.Close() // その後コネクションを閉じる
            }
        }
    }()
    // ...
}

この変更により、パニックが発生した場合でも、まずスタックトレースがログバッファに書き込まれ、log.Printによって出力されることが保証されます。その後でコネクションが閉じられるため、ログ出力が完了する前にプログラムが終了してしまうリスクが大幅に低減されます。これにより、テスト環境などでのデバッグ時に、パニックの根本原因を特定するための重要な情報であるスタックトレースが確実に出力されるようになります。

コアとなるコードの変更箇所

diff --git a/src/pkg/net/http/server.go b/src/pkg/net/http/server.go
index fa9009517d..56f56cb044 100644
--- a/src/pkg/net/http/server.go
+++ b/src/pkg/net/http/server.go
@@ -569,14 +569,14 @@ func (c *conn) serve() {
 	\tif err == nil {\n \t\t\treturn\n \t\t}\n-\t\tif c.rwc != nil { // may be nil if connection hijacked\n-\t\t\tc.rwc.Close()\n-\t\t}\n-\n \t\tvar buf bytes.Buffer\n \t\tfmt.Fprintf(&buf, \"http: panic serving %v: %v\\n\", c.remoteAddr, err)\n \t\tbuf.Write(debug.Stack())\n \t\tlog.Print(buf.String())\n+\n+\t\tif c.rwc != nil { // may be nil if connection hijacked\n+\t\t\tc.rwc.Close()\n+\t\t}\n \t}()\n \n \tif tlsConn, ok := c.rwc.(*tls.Conn); ok {\n```

## コアとなるコードの解説

変更は`src/pkg/net/http/server.go`ファイルの`conn.serve()`メソッド内の`defer`されたリカバリー関数にあります。

- **変更前**:
  ```go
  if c.rwc != nil { // may be nil if connection hijacked
      c.rwc.Close()
  }

  var buf bytes.Buffer
  fmt.Fprintf(&buf, "http: panic serving %v: %v\n", c.remoteAddr, err)
  buf.Write(debug.Stack())
  log.Print(buf.String())

このコードでは、パニックをrecoverした後、まずc.rwc.Close()を呼び出してコネクションを閉じていました。その後、スタックトレースをbytes.Bufferに書き込み、log.Printで出力していました。

  • 変更後:
    var buf bytes.Buffer
    fmt.Fprintf(&buf, "http: panic serving %v: %v\n", c.remoteAddr, err)
    buf.Write(debug.Stack())
    log.Print(buf.String())
    
    if c.rwc != nil { // may be nil if connection hijacked
        c.rwc.Close()
    }
    
    変更後では、c.rwc.Close()の呼び出しがlog.Print(buf.String())の後ろに移動しています。これにより、スタックトレースのログ出力がコネクションを閉じる処理よりも先に行われるようになり、ログが確実に記録されるようになりました。c.rwcnilでないかどうかのチェックは、コネクションがハイジャック(hijacked)された場合にrwcnilになる可能性があるため、引き続き必要です。

このシンプルな順序の変更が、HTTPサーバーのパニック時のデバッグ情報の信頼性を大幅に向上させています。

関連リンク

参考にした情報源リンク

  • Go言語の公式ドキュメント (net/http, runtime/debugパッケージ)
  • Go言語のpanicrecoverに関する一般的な解説記事
  • Go言語のdeferステートメントに関する解説記事
  • GitHubのGoリポジトリのコミット履歴とIssueトラッカー