Go Wiki: Go 1.23 タイマーチャネルの変更点

Go 1.23 には、time.NewTimertime.Aftertime.NewTicker、およびtime.Tickによって作成されるチャネルベースのタイマーの新しい実装が含まれています。

新しい実装には、2つの重要な変更点があります。

  1. 参照されなくなった停止されていないタイマーとティッカーは、ガベージコレクションの対象になります。Go 1.23より前は、停止されていないタイマーはタイマーが発動するまでガベージコレクションされず、停止されていないティッカーはガベージコレクションされることはありませんでした。Go 1.23の実装では、t.Stopを使用しないプログラムでのリソースリークが回避されます。

  2. タイマーチャネルは同期(バッファなし)になり、t.Resetおよびt.Stopメソッドに強力な保証が与えられます。これらのメソッドのいずれかが返った後、タイマーチャネルからの将来の受信では、古いタイマー構成に対応する古い時間が観測されません。Go 1.23より前は、t.Resetで古い値を回避することは不可能であり、t.Stopで古い値を回避するには、t.Stopからの戻り値を注意深く使用する必要がありました。Go 1.23の実装では、この懸念が完全に解消されます。

実装の変更には、次のセクションで説明するように、本番環境の動作やテストに影響を与える可能性のある2つの観察可能な副作用があります。

新しい実装は、パッケージmainがgo.modgo 1.23以降を宣言しているモジュール内にあるプログラムでのみ使用されます。他のプログラムは引き続き古いセマンティクスを使用します。GODEBUG設定 asynctimerchan=1 は、古いセマンティクスを強制します。逆に、 asynctimerchan=0 は、新しいセマンティクスを強制します。

CapとLen

Go 1.23より前は、タイマーチャネルのcapは1で、タイマーチャネルのlenは受信を待機している値があるかどうかを示していました(ある場合は1、ない場合は0)。Go 1.23の実装では、常にcaplenが0のタイマーチャネルが作成されます。

一般的に、lenを使用してチャネルをポーリングすることは通常役に立ちません。別のゴルーチンが同時にチャネルから受信する可能性があり、いつでもlenの結果が無効になるためです。lenを使用してタイマーチャネルをポーリングするコードは、代わりにノンブロッキングのselectを使用する必要があります。

つまり、次のことを行うコードは

if len(t.C) == 1 {
    <-t.C
    more code
}

代わりに次のようにする必要があります

select {
default:
case <-t.C:
    more code
}

Selectの競合

Go 1.23より前は、0nsや1nsなどの非常に短い間隔で作成されたタイマーは、スケジューリングの遅延により、チャネルが受信可能になるまでにその間隔よりも大幅に長い時間がかかっていました。その遅延は、selectの前に準備完了状態のチャネルと、非常に短いタイムアウトの新しいタイマーの間でselectするコードで観測できます。

c := make(chan bool)
close(c)

select {
case <-c:
    println("done")
case <-time.After(1*time.Nanosecond):
    println("timeout")
}

selectの引数が評価され、selectが関係するチャネルを確認するまでに、タイマーは期限切れになっているはずです。つまり、両方のケースが処理に進む準備ができています。Selectは、複数の準備完了状態のケースから1つをランダムに選択するため、このプログラムは各ケースを約半分の時間選択する必要があります。

Go 1.23より前のタイマー実装におけるスケジューリングの遅延により、このようなプログラムは誤って「done」ケースを100%実行していました。

Go 1.23のタイマー実装は、同じスケジューリングの遅延の影響を受けないため、Go 1.23では、そのプログラムは各ケースを約半分の時間実行します。

GoogleのコードベースでGo 1.23をテストしている間、selectを使用して、進む準備ができたチャネル(多くの場合、コンテキストDoneチャネル)と、非常に短いタイムアウトのタイマーを競合させるテストをいくつか発見しました。通常、本番環境のコードは実際のタイムアウトを使用するため、競合は面白くありませんが、テストではタイムアウトが非常に小さい値に設定されます。そして、テストはタイムアウトでないケースが実行されることを主張し、タイムアウトに達すると失敗します。縮小された例は次のようになります。

select {
case <-ctx.Done():
    return nil
case <-time.After(timeout):
    return errors.New("timeout")
}

次に、テストはtimeoutを1nsに設定してこのコードを呼び出し、コードがエラーを返すと失敗します。

このようなテストを修正するには、呼び出し側をタイムアウトが起こりうることを理解するように変更するか、タイムアウトの場合でもdoneチャネルを優先するようにコードを変更できます。たとえば、次のようにします。

select {
case <-ctx.Done():
    return nil
case <-time.After(timeout):
    // Double-check that Done is not ready,
    // in case of short timeout during test.
    select {
    default:
    case <-ctx.Done():
        return nil
    }
    return errors.New("timeout")
}

デバッグ

Go 1.23を使用してプログラムまたはテストが失敗したが、Go 1.22を使用して動作していた場合、asynctimerchan GODEBUG設定を使用して、新しいタイマー実装が失敗を引き起こすかどうかを確認できます。

GODEBUG=asynctimerchan=0 mytest  # force Go 1.23 timers
GODEBUG=asynctimerchan=1 mytest  # force Go 1.22 timers

プログラムまたはテストがGo 1.22を使用して一貫して合格したが、Go 1.23を使用して一貫して失敗する場合は、タイマーに関連する問題である可能性が高いことを示す強力な兆候です。

これまで観察されたすべてのテストの失敗では、問題はタイマーの実装ではなく、テスト自体にありました。そのため、次のステップは、mytest内のどのコードが古い実装に依存しているかを正確に特定することです。これを行うには、bisectツールを使用できます。

go install golang.org/x/tools/cmd/bisect@latest
bisect -godebug asynctimerchan=1 mytest

このように呼び出された場合、bisectは、タイマー呼び出しにつながるスタックトレースに応じて、新しいタイマー実装のオンとオフを切り替えながら、mytestを繰り返し実行します。バイナリ検索を使用すると、特定スタックトレース中に新しいタイマーを有効にすることによる誘導された失敗を絞り込み、それをレポートします。bisectが実行中は、試行に関するステータスメッセージを出力します。これは主に、テストが遅い場合にまだ実行中であることを知るためです。

bisectの実行例は次のようになります。

$ bisect -godebug asynctimerchan=1 ./view.test
bisect: checking target with all changes disabled
bisect: run: GODEBUG=asynctimerchan=1#n ./view.test... FAIL (7 matches)
bisect: run: GODEBUG=asynctimerchan=1#n ./view.test... FAIL (7 matches)
bisect: checking target with all changes enabled
bisect: run: GODEBUG=asynctimerchan=1#y ./view.test... ok (7 matches)
bisect: run: GODEBUG=asynctimerchan=1#y ./view.test... ok (7 matches)
bisect: target fails with no changes, succeeds with all changes
bisect: searching for minimal set of disabled changes causing failure
bisect: run: GODEBUG=asynctimerchan=1#!+0 ./view.test... FAIL (3 matches)
bisect: run: GODEBUG=asynctimerchan=1#!+0 ./view.test... FAIL (3 matches)
bisect: run: GODEBUG=asynctimerchan=1#!+00 ./view.test... ok (1 matches)
bisect: run: GODEBUG=asynctimerchan=1#!+00 ./view.test... ok (1 matches)
bisect: run: GODEBUG=asynctimerchan=1#!+10 ./view.test... FAIL (2 matches)
bisect: run: GODEBUG=asynctimerchan=1#!+10 ./view.test... FAIL (2 matches)
bisect: run: GODEBUG=asynctimerchan=1#!+0010 ./view.test... ok (1 matches)
bisect: run: GODEBUG=asynctimerchan=1#!+0010 ./view.test... ok (1 matches)
bisect: run: GODEBUG=asynctimerchan=1#!+1010 ./view.test... FAIL (1 matches)
bisect: run: GODEBUG=asynctimerchan=1#!+1010 ./view.test... FAIL (1 matches)
bisect: confirming failing change set
bisect: run: GODEBUG=asynctimerchan=1#v!+x65a ./view.test... FAIL (1 matches)
bisect: run: GODEBUG=asynctimerchan=1#v!+x65a ./view.test... FAIL (1 matches)
bisect: FOUND failing change set
--- change set #1 (disabling changes causes failure)
internal/godebug.(*Setting).Value()
    go/src/internal/godebug/godebug.go:165
time.syncTimer()
    go/src/time/sleep.go:25
time.NewTimer()
    go/src/time/sleep.go:144
time.After()
    go/src/time/sleep.go:202
region_dash/regionlist.(*Cache).Top()
    region_dash/regionlist/regionlist.go:89
region_dash/view.(*Page).ServeHTTP()
    region_dash/view/view.go:45
region_dash/view.TestServeHTTPStatus.(*Router).Handler.func2()
    httprouter/httprouter/params_go17.go:27
httprouter/httprouter.(*Router).ServeHTTP()
    httprouter/httprouter/router.go:339
region_dash/view.TestServeHTTPStatus.func1()
    region_dash/view/view.test.go:105
testing.tRunner()
    go/src/testing/testing.go:1689
runtime.goexit()
    go/src/runtime/asm_amd64.s:1695

---
bisect: checking for more failures
bisect: run: GODEBUG=asynctimerchan=1#!-x65a ./view.test... ok (6 matches)
bisect: run: GODEBUG=asynctimerchan=1#!-x65a ./view.test... ok (6 matches)
bisect: target succeeds with all remaining changes disabled

この場合、スタックトレースは、新しいタイマーを使用すると失敗を引き起こすtime.Afterの呼び出しを正確に示しています。


このコンテンツは、Go Wikiの一部です。