spanner: Client library sending a high rate of BeginTransaction requests when database is deleted

[skuruppu]

Once a database is deleted and if the Java Spanner client is still left open, it starts sending a large number of BeginTransaction requests. The additional requests fail with status NOT_FOUND.

The following error just keeps repeating in the logs:

Nov 07, 2019 10:20:16 PM com.google.cloud.spanner.spi.v1.LoggingInterceptor$CallLogger log FINER: google.spanner.v1.Spanner/BeginTransaction[74f0a03d]: Start
Nov 07, 2019 10:20:16 PM com.google.cloud.spanner.spi.v1.LoggingInterceptor$CallLogger log FINER: google.spanner.v1.Spanner/BeginTransaction[74f0a03d]: Send: session: "projects/<project>/instances/<instance>/databases/<database>/sessions/<session>" options { read_write { } }
Nov 07, 2019 10:20:16 PM com.google.cloud.spanner.spi.v1.LoggingInterceptor$CallLogger log FINER: google.spanner.v1.Spanner/BeginTransaction[74f0a03d]: Closed with status Status{code=NOT_FOUND, description=Database not found: projects/<project>/instances/<instance>/databases/<database> resource_type: "type.googleapis.com/google.spanner.admin.database.v1.Database" resource_name: "projects/<project>/instances/<instance>/databases/<database>" description: "Database does not exist." , cause=null} and trailers Metadata(...)

I'm guessing this is happening in an attempt to replenish the pool.

[skuruppu]

@sebright

[olavloite]

This is caused by an infinite loop that can occur during preparing sessions in the session pool. The session pool will try to prepare a session with a read/write transaction when a session is released into the pool. This process follows this logic:

1. A session is released into the pool (either as part of the session pool initialization or because a session is returned to the pool by a client).
2. If the current fraction of write-prepared sessions in the pool is less than the configured writeFraction, a BeginTransaction RPC will be scheduled.
3. The BeginTransact RPC will fail with a 'Database does not exist.' error. This will cause the session to be released into the pool without a prepared read/write transaction.
4. The release of the session into the pool will start the process at step 1 again. As no BeginTransaction call will succeed, the process will continue until the Spanner instance is closed.

[sebright]

@olavloite Thanks for fixing this! I cherry-picked googleapis/google-cloud-java@7c66ee4, and it seems to have fixed the issue for me.

[snehashah16]

3. The BeginTransact RPC will fail with a 'Database does not exist.' error. This will cause the session to be released into the pool without a prepared read/write transaction.

@skuruppu
An orthogonal question related to this:
What should the client do when a database not found error is returned ?

options:

• execute backend rpcs all customer requests and return NOT_FOUND (for database admin APIs for this specific database that got deleted)
• for read / write APIs - should this invalidate the session pool (since sessions are no longer valid for a deleted db) and handle all subsequent requests with NOT_FOUND errors ?
  • this forces the customer to create a new db client after first NOT_FOUND error even though they recreate the database with the same name (but the backend database has obviously changed).
    DatabaseId db = DatabaseId.of(project, instance, database);
    DatabaseClient dbClient = spanner.getDatabaseClient(db);

[olavloite]

@skuruppu @snehashah16
Regarding what to do when a Database not found error is returned: We could also allow the read/write APIs handle this in the same way as the database admin APIs do, i.e. keep sending RPCs and let these return NOT_FOUND errors. If the user re-creates the database with the same name, the session pool will automatically heal as Session not found errors are automatically retried by the client by discarding the old session and creating a new session.

[skuruppu]

My take on this is that since the Java client connection is at a DB level, if the DB is deleted, then this invalidates the current connection. Essentially option 2 that @snehashah16 mentioned so that the customer is expected to create a new client if they recreate a DB with the same name.

I'm a bit weary of sending RPCs continuously until NOT_FOUND errors are no longer returned. In most cases, I suspect once a DB is deleted, users don't recreate the same DB shortly after in a production app. They probably do such things in tests but for that we would expect them to rerun the tests with a new connection.

Let me know if I misunderstood something here.