[インデックス 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言語のpanic
とrecover
Go言語には、プログラムの異常終了を扱うためのpanic
とrecover
というメカニズムがあります。
panic
: 実行時エラーやプログラマが意図的に発生させることで、現在の関数の実行を中断し、呼び出し元の関数へと遡ってパニックを伝播させます。最終的にmain
関数まで到達すると、プログラムは異常終了し、スタックトレースが出力されます。recover
:defer
された関数内でrecover()
を呼び出すことで、パニックの伝播を停止し、パニックが発生した時点からのプログラムの実行を再開させることができます。これにより、予期せぬパニックによってプログラム全体がクラッシュするのを防ぎ、エラーハンドリングを行うことが可能になります。
net/http
パッケージのサーバー処理
Goのnet/http
パッケージは、HTTPサーバーを構築するための強力な機能を提供します。HTTPサーバーは通常、各クライアントからのリクエストを個別のゴルーチン(goroutine)で処理します。http.Server
構造体には、リクエスト処理中に発生したパニックを捕捉し、適切に処理するための内部ロジックが含まれています。
debug.Stack()
runtime/debug
パッケージのStack()
関数は、現在のゴルーチンのスタックトレースをバイトスライスとして返します。これは、パニックが発生した際に、その時点でのプログラムの実行パスを特定するために非常に有用です。通常、パニックをrecover
した後に、この関数を使ってスタックトレースを取得し、ログに出力することで、デバッグ情報を得ます。
io.Closer
とClose()
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.rwc
がnil
でないかどうかのチェックは、コネクションがハイジャック(hijacked)された場合にrwc
がnil
になる可能性があるため、引き続き必要です。
このシンプルな順序の変更が、HTTPサーバーのパニック時のデバッグ情報の信頼性を大幅に向上させています。
関連リンク
- GitHubコミットページ: https://github.com/golang/go/commit/516168057e0b2a30bcda024892ed36badb731c00
- Go Issue #2480: https://golang.org/issue/2480
- Go CL 5414048: https://golang.org/cl/5414048
参考にした情報源リンク
- Go言語の公式ドキュメント (
net/http
,runtime/debug
パッケージ) - Go言語の
panic
とrecover
に関する一般的な解説記事 - Go言語の
defer
ステートメントに関する解説記事 - GitHubのGoリポジトリのコミット履歴とIssueトラッカー