Spanner DBX pool is unreliable

[elek]

Satellite API can be started with using Spanner, and during the first few minutes, everything works well.

But after a while, all database queries start failing, with an error related to spanner session pool:

{"severity":"INFO","message":"failed to add peer identity entry for ID","logging.googleapis.com/labels":{"node address":"72.52.83.206:4224","Node ID":"12jQEPWD9kqtyGVnwGD9ZQy4rm7jGJoRfu4pkS8hzKHwt86rTpT","error":"satellitedb: spanner: code = \"InvalidArgument\", desc = \"invalid session pool\"","errorVerbose":"satellitedb: spanner: code = \"InvalidArgument\", desc = \"invalid session pool\"
  storj.io/storj/shared/dbutil/txutil.withTxOnce:66
  storj.io/storj/shared/dbutil/txutil.WithTx:37
  storj.io/storj/satellite/satellitedb/dbx.(*DB).WithTx:72
  storj.io/storj/satellite/satellitedb.(*peerIdentities).Set:32
  storj.io/storj/satellite/contact.(*Endpoint).CheckIn:70
  storj.io/common/pb.DRPCNodeDescription.Method.func1:192
  storj.io/drpc/drpcmux.(*Mux).HandleRPC:33
  storj.io/common/rpc/rpctracing.(*Handler).HandleRPC:62
  storj.io/common/experiment.(*Handler).HandleRPC:43
  storj.io/drpc/drpcserver.(*Server).handleRPC:166
  storj.io/drpc/drpcserver.(*Server).ServeOne:108
  storj.io/drpc/drpcserver.(*Server).Serve.func2:156
  storj.io/drpc/drpcctx.(*Tracker).track:35","name":"contact:endpoint"},"timestamp":{"seconds":1724245362,"nanos":764127867},"logging.googleapis.com/sourceLocation":{"file":"/go/src/storj.io/storj/satellite/contact/endpoint.go","line":"72","function":"33018706"}}

[elek]

Looks like this is the moment when the SQL session is closed:

runtime/debug.Stack()
        /usr/lib/go/src/runtime/debug/stack.go:26 +0x5e
runtime/debug.PrintStack()
        /usr/lib/go/src/runtime/debug/stack.go:18 +0x13
cloud.google.com/go/spanner.(*sessionPool).close(0xc0019da000, {0x34b71a0, 0xc002098070})
        /home/elek/jr/google-cloud-go/spanner/session.go:888 +0x92
cloud.google.com/go/spanner.(*Client).Close(0xc00199e3c0)
        /home/elek/jr/google-cloud-go/spanner/client.go:574 +0x6f
github.com/googleapis/go-sql-spanner.(*conn).Close(0xc000ff0fd0)
        /home/elek/go/pkg/mod/github.com/googleapis/[email protected]/driver.go:963 +0xaa
database/sql.(*driverConn).finalClose.func2()
        /usr/lib/go/src/database/sql/sql.go:687 +0x32
database/sql.withLock({0x34a8098, 0xc0021e9600}, 0xc001f02e88)
        /usr/lib/go/src/database/sql/sql.go:3566 +0x71
database/sql.(*driverConn).finalClose(0xc0021e9600)
        /usr/lib/go/src/database/sql/sql.go:685 +0xef
database/sql.(*driverConn).Close(0xc0021e9600)
        /usr/lib/go/src/database/sql/sql.go:666 +0x143
database/sql.(*DB).connectionCleaner(0xc000c4a410, 0xc000dbc001?)
        /usr/lib/go/src/database/sql/sql.go:1113 +0x22f
created by database/sql.(*DB).startCleanerLocked in goroutine 1
        /usr/lib/go/src/database/sql/sql.go:1083 +0x105

[elek]

Code to reproduce it:

// Copyright 2021 Google LLC All Rights Reserved.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
//      http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.

package main

import (
	"context"
	"database/sql"
	"fmt"
	_ "github.com/googleapis/go-sql-spanner"
	"time"
)

// Simple sample application that shows how to use the Spanner Go sql driver.
//
// Execute the sample with the command `go run main.go` from this directory.
func helloWorld() error {
	ctx := context.Background()
	db, err := sql.Open("spanner", "projects/storj-test/instances/test-instance/databases/satellite")
	if err != nil {
		return fmt.Errorf("failed to open database connection: %v\n", err)
	}
	defer db.Close()
	db.SetConnMaxLifetime(time.Second * 20)

	for i := 0; i < 10000; i++ {
		err := selectOnce(ctx, db)
		if err != nil {
			return err
		}
		time.Sleep(1 * time.Second)
	}
	return nil
}

func selectOnce(ctx context.Context, db *sql.DB) error {
	rows, err := db.QueryContext(ctx, "SELECT 'Hello World!'")
	if err != nil {
		return fmt.Errorf("failed to execute query: %v", err)
	}
	defer rows.Close()

	var msg string
	for rows.Next() {
		if err := rows.Scan(&msg); err != nil {
			return fmt.Errorf("failed to scan row values: %v", err)
		}
		fmt.Printf("%s\n", msg)
	}
	if err := rows.Err(); err != nil {
		return fmt.Errorf("failed to execute query: %v", err)
	}
	return nil
}

func main() {
	err := helloWorld()
	if err != nil {
		panic(err)
	}
}

[egonelbre]

Upstream issue googleapis/go-sql-spanner#288 and fix googleapis/go-sql-spanner#290