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

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

このコミットは、Go言語の標準ライブラリos/execパッケージのテストコード（exec_test.go）における、TLSハンドシェイク失敗時のログ出力がテストの妨げになる問題を解決するためのものです。Go 1.3でTLSハンドシェイク失敗時のログ出力がより詳細になったことにより、テスト実行時に不要なログが大量に出力され、本来のテスト結果が見えにくくなるという問題が発生していました。このコミットは、テスト中に発生する特定のログ出力を抑制することで、テストの可読性を向上させることを目的としています。

コミット

os/exec: テスト中の邪魔なログ出力を抑制

TLSハンドシェイクの失敗は以前はログに出力されなかったが、Go 1.3では出力されるようになった。 これにより、例えば http://build.golang.org/log/ede7e12362a941d93bf1fe21db9208a3e298029e のようなビルドログで、実際の失敗が見えるようにするため、このログを抑制する。

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

https://github.com/golang/go/commit/e45141b86cad1b907b4193dd7401630acd55d5d0

元コミット内容

commit e45141b86cad1b907b4193dd7401630acd55d5d0
Author: Brad Fitzpatrick <bradfitz@golang.org>
Date:   Mon Apr 14 17:20:30 2014 -0700

    os/exec: quiet distracting log output during test
    
    TLS handshake failures didn't use to log, but do in Go 1.3.
    Shut it up so the actual failure can be seen in e.g.
    http://build.golang.org/log/ede7e12362a941d93bf1fe21db9208a3e298029e
    
    LGTM=adg
    R=adg
    CC=golang-codereviews
    https://golang.org/cl/87870043

変更の背景

この変更の背景には、Go 1.3における標準ライブラリのロギング挙動の変更があります。具体的には、TLS (Transport Layer Security) ハンドシェイクの失敗時に、以前のバージョンではログに出力されなかった情報が、Go 1.3からは詳細にログ出力されるようになりました。

os/execパッケージのTestExtraFilesというテスト関数は、ファイルディスクリプタのリークがないことを確認するために、TLSサーバーを起動し、ルート証明書の読み込みを強制する処理を含んでいます。このテストでは、意図的にTLSハンドシェイクを失敗させることで、特定のコードパスが実行されることを確認しています。しかし、Go 1.3でのロギング挙動の変更により、この意図的なTLSハンドシェイク失敗が大量のログメッセージとして出力されるようになりました。

これらのログメッセージは、テストの本来の目的であるファイルディスクリプタのリークチェックとは無関係であり、テストの出力が非常に冗長になるという問題を引き起こしました。特に、継続的インテグレーション（CI）システム上でのビルドログ（例: http://build.golang.org/log/ede7e12362a941d93bf1fe21db9208a3e298029e）において、本来確認すべきテストの失敗やエラーメッセージが、大量のTLS関連のログに埋もれて見つけにくくなるという実用上の問題が発生していました。

このコミットは、このような「邪魔な」ログ出力を抑制し、テストの出力をクリーンに保つことで、開発者やCIシステムがテスト結果をより効率的に分析できるようにすることを目的としています。

前提知識の解説

このコミットを理解するためには、以下のGo言語の概念と標準ライブラリに関する知識が必要です。

  1. os/execパッケージ: Go言語で外部コマンドを実行するためのパッケージです。このコミットでは、このパッケージのテストコードが変更されています。

  2. net/http/httptestパッケージ: HTTPサーバーのテストを容易にするためのユーティリティを提供するパッケージです。

    • httptest.NewTLSServer(handler http.Handler): テスト用のTLS (HTTPS) サーバーを起動し、そのURLと証明書情報を含むhttptest.Server構造体を返します。この関数は内部でサーバーを起動します。
    • httptest.NewUnstartedServer(handler http.Handler): NewTLSServerと同様にテスト用のHTTP/HTTPSサーバーを準備しますが、サーバーはまだ起動しません。これにより、サーバーの起動前に設定を変更する機会が提供されます。
    • httptest.Server.Config: httptest.Server構造体には、内部で使用される*http.ServerのインスタンスへのポインタであるConfigフィールドがあります。このConfigフィールドを通じて、基盤となるHTTPサーバーの詳細な設定（例: ErrorLog）にアクセスできます。
    • httptest.Server.StartTLS(): NewUnstartedServerで作成されたサーバーをTLSモードで起動します。

  3. TLSハンドシェイク: TLSは、インターネット上での安全な通信を確立するためのプロトコルです。TLSハンドシェイクは、クライアントとサーバーが安全な通信チャネルを確立するために行う一連のネゴシエーションプロセスです。これには、証明書の交換、暗号スイートの選択、鍵の生成などが含まれます。ハンドシェイクが失敗する原因は多岐にわたりますが、テストケースでは意図的に無効な証明書などを使用することで失敗を誘発することがあります。

  4. logパッケージ: Go言語の標準ロギングパッケージです。

    • log.New(out io.Writer, prefix string, flag int): 新しいロガーを作成します。out引数にはログの出力先となるio.Writerインターフェースを実装したオブジェクトを指定します。
    • log.Logger.SetOutput(w io.Writer): ロガーの出力先を設定します。

  5. io.Writerインターフェース: Go言語の基本的なI/Oインターフェースの一つで、Write([]byte) (n int, err error)メソッドを定義しています。データを書き込むことができる任意のオブジェクトがこのインターフェースを実装できます。

  6. io/ioutilパッケージ: I/Oユーティリティ関数を提供するパッケージです。

    • ioutil.Discard: io.Writerインターフェースを実装した特別な変数です。このWriterに書き込まれたデータはすべて破棄され、どこにも出力されません。これは、出力を完全に抑制したい場合（例: テスト中の不要なログ）に非常に便利です。

  7. Go 1.3の変更点: このコミットの直接的な原因は、Go 1.3でTLSハンドシェイク失敗時のロギングがより詳細になったことです。これは、Go言語の進化に伴うデバッグ情報の強化の一環として行われた可能性があります。

技術的詳細

このコミットが解決しようとしている技術的な問題は、httptest.NewTLSServerが内部で起動するHTTPサーバーが、TLSハンドシェイク失敗時に標準エラー出力（またはデフォルトのロガーが設定されている出力先）に詳細なエラーログを出力するようになったことです。TestExtraFilesテストでは、ファイルディスクリプタのリークをチェックするために、TLSルート証明書の読み込みを強制する目的でhttptest.NewTLSServerを使用し、そのサーバーに対してhttp.Getを実行しています。このhttp.Getは、テストの性質上、意図的にTLSハンドシェイクを失敗させる（例えば、クライアントがサーバーの証明書を信頼しない）ことで、エラーパスを通過させます。

Go 1.3以前では、このハンドシェイク失敗はログに出力されなかったため問題ありませんでした。しかし、Go 1.3以降では、この失敗が「remote error: bad certificate」のようなメッセージとしてログに出力されるようになり、テストの出力がノイズで埋め尽くされるようになりました。

この問題を解決するために、コミットでは以下の技術的なアプローチを採用しています。

  1. httptest.NewTLSServerからhttptest.NewUnstartedServerへの変更: NewTLSServerはサーバーを即座に起動するため、起動前にサーバーのロガー設定を変更する機会がありません。これに対し、NewUnstartedServerはサーバーインスタンスを作成するものの、起動は行いません。これにより、サーバーのConfigフィールドを通じて、基盤となるhttp.Serverのロガー設定をカスタマイズする時間的余裕が生まれます。

  2. httptest.Server.Config.ErrorLogの設定: http.Server構造体にはErrorLogというフィールドがあり、これはサーバー内部のエラーをログに出力するために使用される*log.Loggerのインスタンスです。このフィールドをカスタマイズすることで、サーバーのエラーログの出力先を制御できます。

  3. log.New(ioutil.Discard, "", 0)によるロガーの作成: 新しいロガーをlog.New関数で作成し、その出力先としてioutil.Discardを指定しています。ioutil.Discardは、書き込まれたデータをすべて破棄するio.Writerの実装です。これにより、このロガーを通じて出力されるすべてのメッセージは、実質的に「捨てられる」ことになり、コンソールやログファイルには何も出力されなくなります。""はログメッセージのプレフィックス、0はログフラグ（タイムスタンプなどを付加しない）を指定しています。

  4. httptest.Server.StartTLS()によるサーバーの起動: ロガーの設定が完了した後、StartTLS()を呼び出すことで、設定済みのTLSサーバーを起動します。これにより、以降のTLSハンドシェイク失敗ログはioutil.Discardに送られ、テスト出力がクリーンに保たれます。

この変更により、テストの意図的なTLSハンドシェイク失敗によって発生するログノイズが完全に抑制され、テストの本来の目的であるファイルディスクリプタのリークチェックに関する出力のみが残るようになります。これは、テストの信頼性と可読性を高める上で重要な改善です。

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

--- a/src/pkg/os/exec/exec_test.go
+++ b/src/pkg/os/exec/exec_test.go
@@ -13,6 +13,7 @@ import (
 	"fmt"
 	"io"
 	"io/ioutil"
+	"log"
 	"net"
 	"net/http"
 	"net/http/httptest"
@@ -401,11 +402,15 @@ func TestExtraFiles(t *testing.T) {
 
 	// Force TLS root certs to be loaded (which might involve
 	// cgo), to make sure none of that potential C code leaks fds.
-	ts := httptest.NewTLSServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
-		w.Write([]byte("Hello"))
-	}))
+	ts := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {}))
+	// quiet expected TLS handshake error "remote error: bad certificate"
+	ts.Config.ErrorLog = log.New(ioutil.Discard, "", 0)
+	ts.StartTLS()
 	defer ts.Close()
-	http.Get(ts.URL) // ignore result; just calling to force root cert loading
+	_, err = http.Get(ts.URL)
+	if err == nil {
+		t.Errorf("success trying to fetch %s; want an error", ts.URL)
+	}
 
 	tf, err := ioutil.TempFile("", "")
 	if err != nil {

コアとなるコードの解説

変更はsrc/pkg/os/exec/exec_test.goファイルのTestExtraFiles関数内で行われています。

  1. import "log" の追加: logパッケージを使用するために、インポート文が追加されました。

  2. httptest.NewTLSServer から httptest.NewUnstartedServer への変更: 変更前は、httptest.NewTLSServerを使用してTLSサーバーを直接起動していました。

    ts := httptest.NewTLSServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
    w.Write([]byte("Hello"))
}))

    変更後は、httptest.NewUnstartedServerを使用するように変わりました。これにより、サーバーが起動する前に設定を変更できるようになります。ハンドラ関数は、以前と同様にダミーのhttp.HandlerFuncが渡されていますが、今回はw.Write([]byte("Hello"))のような具体的な応答は不要なため、空の関数になっています。

    ts := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {}))

  3. エラーログの抑制設定: NewUnstartedServerでサーバーインスタンスが作成された後、そのConfigフィールドを通じて、基盤となるhttp.Serverのエラーロガーを設定しています。

    // quiet expected TLS handshake error "remote error: bad certificate"
ts.Config.ErrorLog = log.New(ioutil.Discard, "", 0)

    ここで、log.New(ioutil.Discard, "", 0)によって新しいロガーが作成されます。このロガーは、ioutil.Discardを書き込み先として指定しているため、このロガーに書き込まれるすべてのメッセージは破棄されます。これにより、TLSハンドシェイク失敗時に出力される「remote error: bad certificate」のようなログメッセージが完全に抑制されます。コメントで「期待されるTLSハンドシェイクエラーを静かにする」と明記されており、この変更の意図が明確に示されています。

  4. サーバーの起動: エラーログの設定が完了した後、ts.StartTLS()を呼び出すことで、設定済みのTLSサーバーが実際に起動されます。

    ts.StartTLS()

  5. http.Getの戻り値の利用とエラーチェックの追加: 変更前はhttp.Get(ts.URL)の戻り値（*http.Responseとerror）を無視していましたが、変更後はerrを受け取り、その値を確認するようになりました。

    _, err = http.Get(ts.URL)
if err == nil {
    t.Errorf("success trying to fetch %s; want an error", ts.URL)
}

    このテストの目的は、TLSハンドシェイクが意図的に失敗することを確認することであるため、http.Getがエラーを返さない場合はテストを失敗させるように変更されました。これは、ログ抑制の変更とは直接関係ありませんが、テストの堅牢性を高めるための改善です。

これらの変更により、TestExtraFilesテストは、TLSハンドシェイク失敗時の不要なログ出力を抑制しつつ、そのエラーパスが正しく機能していることを確認できるようになりました。

関連リンク

  • Go Code Review: https://golang.org/cl/87870043

参考にした情報源リンク

  • 特になし (コミットメッセージとGo言語の標準ライブラリの知識に基づいて解説を生成しました。)