Cloud Spanner の自動クリーンアップ機能を試してみた

はじめに

こんにちは、クラウドエース データソリューション部所属の後藤です。

データソリューション部では、Google Cloud が提供しているデータ領域のプロダクトについて、新規リリースをキャッチアップするための調査報告会を毎週実施しています。
新規リリースの中でも、特に重要と考えるリリースを記事としてまとめ、本ページのように公開しています。

今回は、11月16日のリリースで追加された、Cloud Spanner の「セッションリークの自動クリーンアップ」機能について紹介します。

記事執筆時点（2024/2/16）では、プレビューの機能になります。

概要

セッションリークとは

Cloud Spanner ではクライアントからクエリを実行したり、トランザクションを利用する際には、セッションで実行されます。
セッションについての詳細は、公式ドキュメントを参照ください。
通常は、クエリの実行やトランザクションでの処理の実行が終わると、セッションを再利用できるようにセッションプールに戻します。

このセッションの最大数は、SessionPoolConfig.MaxOpened で定義されます。

既にセッションが全て使われており、セッションプールが空の場合、新規セッションを作成しようとしますが、
作成済みセッション数が SessionPoolConfig.MaxOpened に達している場合、セッションの作成ができません。
この場合、セッションプールにセッションが戻されるまで待機することになります。

セッションがセッションプールに戻されない限り、新たな処理を行うことができません。

セッションリークとは、セッションプールに戻す処理が実装されていなかったり、トランザクションがコミットされていないことなどが原因で、セッションをセッションプールに戻せていないことを指します。

また、本機能を利用したセッションリークの見つけ方についての Google Cloud 公式ブログもご参照ください。

自動クリーンアップ

今回紹介する自動クリーンアップ機能は、セッションリークを検知して警告ログを出力したり、セッションを解放させて再利用可能な状態にすることができます。

自動クリーンアップ機能のオプションには、以下の4つがあります。

オプション	内容
NoAction	デフォルト値。従来通り、特に検知を行わない。
Warn	セッションリークを検知し、警告ログを出力する。
Close	セッションリークを検知し、セッションを強制的に解放する。
WarnAndClose	セッションリークを検知し、警告ログの出力して、セッションを強制的に解放する。

検証

まず、検証環境の用意のため、Go のクイックスタートに従い、Cloud Spanner のインスタンス・データベースの作成および Go 用の Spanner クライアントライブラリの準備を行います。

今後は、クイックスタートで利用する snippet.goを利用して、検証を行っていきます。

自動クリーンアップについて検証するため、まずセッションリークを起こします。
検証のため以下のように、セッションの最大オープン数（SessionPoolConfig.MaxOpened）を小さい値（今回は2）に設定します。

dataClient, err := spanner.NewClientWithConfig(ctx, db, spanner.ClientConfig{
	SessionPoolConfig: spanner.SessionPoolConfig{
		MinOpened: 0,
		MaxOpened: 2,
	},
	DatabaseRole: databaseRole,
},

この状態で以下のようなクエリを実行します。
これは、*spanner.RowIterator 型の値を生成したあとに Stop メソッドを実行しないように、Stop メソッドをコメントアウトしました。
これにより、セッションをセッションプールに戻さない状態となり、セッションリークが引き起こされます。

stmt := spanner.Statement{SQL: `SELECT SingerId, AlbumId, AlbumTitle FROM Albums`}
iter := client.Single().Query(ctx, stmt)
//defer iter.Stop()

結果のログは以下のように出力されました。
セッションを作成するメソッドの前後で、Start と End のログを出力するようにしています。
セッションを2つ作成後、どちらもセッションプールに戻されかったことが原因で、セッション3つ目を作成時に処理が行われなくなりました。
このあと、タイムアウトになり処理が終了しています。

2023/12/22 15:29:58 Session 1 Start
1 1 Total Junk
1 2 Go, Go, Go
2023/12/22 15:29:59 Session 1 End
2023/12/22 15:29:59 Session 2 Start
1 1 Total Junk
1 2 Go, Go, Go
2023/12/22 15:29:59 Session 2 End
2023/12/22 15:29:59 Session 3 Start

続いて、今回紹介する自動クリーンアップ機能を試してみます。

まず、警告ログを出力しつつ、セッションを解放する設定WarnAndCloseを利用します。

dataClient, err := spanner.NewClientWithConfig(ctx, db, spanner.ClientConfig{
    SessionPoolConfig: spanner.SessionPoolConfig{
        MinOpened: 0,
        MaxOpened: 2,
        InactiveTransactionRemovalOptions: spanner.InactiveTransactionRemovalOptions{
            ActionOnInactiveTransaction: spanner.WarnAndClose,
        },
    },
    DatabaseRole: databaseRole,
},

WarnAndClose の設定を利用した場合、長時間セッションリークの状態であると判断されたセッションを検知し、警告ログの出力を行い、当該セッションを強制的に解放します。

2023/12/22 16:41:56 Session 1 Start
1 1 Total Junk
1 2 Go, Go, Go
2023/12/22 16:41:57 Session 1 End
2023/12/22 16:44:57 Session 2 Start
1 1 Total Junk
1 2 Go, Go, Go
2023/12/22 16:44:57 Session 2 End
2023/12/22 16:47:57 Session 3 Start
2023/12/22 17:43:56 session projects/<プロジェクト名>/instances/test-instance/databases/example-db/sessions/AH67Lq4W9twJHN5FuD_AkS_F46fXNauZGcAWB3L6hOZ7WWPQbk9LKoE5NicJGw checked out of pool at 2023-12-22T16:41:57+09:00 is long running and will be removed due to possible session leak for goroutine: 
Enable SessionPoolConfig.TrackSessionHandles to get stack trace associated with the session
1 1 Total Junk
1 2 Go, Go, Go
2023/12/22 17:43:57 Session 3 End
2023/12/22 17:45:56 session projects/<プロジェクト名>/instances/test-instance/databases/example-db/sessions/AH67Lq4Og74WfXrF9YpTCeS-b9w4gMnMftwKHOb09G6NebgBjjmp4YT9b8nH6A checked out of pool at 2023-12-22T16:44:57+09:00 is long running and will be removed due to possible session leak for goroutine: 
Enable SessionPoolConfig.TrackSessionHandles to get stack trace associated with the session

1つ目のセッション作成時間の16:42頃から、約1時間後の、17:44頃に警告ログが出力されセッションが解放されています。
その直後に、実行できなかった3つ目のクエリも正常に実行されていることがわかります。
これは、デフォルト設定では、検知対象となる時間のしきい値が、60分に設定されているためです。

次に、警告ログを出力し、セッションの解放を行わない設定Warnを利用します。
以下のように、警告ログは出力されますが、セッションの解放が行われないため、3つ目のクエリが実行されずタイムアウトになりました。

2023/12/22 15:24:08 session projects/<プロジェクト名>/instances/test-instance/databases/example-db/sessions/AH67Lq6e_MYREJl67i46auqdox6mCclos8jQLQ1n1imOLuvppNlKgxJjbJcGuQ checked out of pool at 2023-12-22T14:22:09+09:00 is long running due to possible session leak for goroutine: 
goroutine 1 [running]:
Enable SessionPoolConfig.TrackSessionHandles to get stack trace associated with the session
2023/12/22 15:24:08 session projects/<プロジェクト名>/instances/test-instance/databases/example-db/sessions/AH67Lq7XfxkusfJRmyE2enY-PW3cwvHVEQ-YFwsEORG7-E8uP9aKWRUl5oAhaw checked out of pool at 2023-12-22T14:22:09+09:00 is long running due to possible session leak for goroutine: 
goroutine 1 [running]:
Enable SessionPoolConfig.TrackSessionHandles to get stack trace associated with the session

まとめ

今回は Cloud Spanner の「セッションリークの自動クリーンアップ」機能について紹介しました。

セッションリークを起こさないような実装をするべきではありますが、複雑な実装の場合、気付かないうちにセッションリークを引き起こしていることもあるかもしれません。
そのような場合にセッションリークを検知できる本機能は、改善の助けになりそうです。

ただし、本機能によりセッションを強制的に解放する場合、必要があるために長時間利用されているようなセッションを誤って解放してしまう危険もあります。どのオプションを利用するかは、十分注意して検討する必要があります。