Inactive JDBC connection can cause "Pool has been closed" exception #206
Description
An inactive JDBC connection can cause a Pool has been closed exception to be thrown.
The information below has been copied from GoogleCloudPlatform/google-cloud-spanner-hibernate#202 where the issue was originally reported.
Error Message
Exception in thread "main" java.lang.IllegalStateException: Pool has been closed
at com.google.cloud.spanner.SessionPool.getReadWriteSession(SessionPool.java:1292)
at com.google.cloud.spanner.DatabaseClientImpl.getReadWriteSession(DatabaseClientImpl.java:57)
at com.google.cloud.spanner.DatabaseClientImpl.transactionManager(DatabaseClientImpl.java:181)
at com.google.cloud.spanner.jdbc.ReadWriteTransaction.<init>(ReadWriteTransaction.java:120)
at com.google.cloud.spanner.jdbc.ReadWriteTransaction.<init>(ReadWriteTransaction.java:55)
at com.google.cloud.spanner.jdbc.ReadWriteTransaction$Builder.build(ReadWriteTransaction.java:106)
at com.google.cloud.spanner.jdbc.ConnectionImpl.createNewUnitOfWork(ConnectionImpl.java:835)
at com.google.cloud.spanner.jdbc.ConnectionImpl.getCurrentUnitOfWorkOrStartNewUnitOfWork(ConnectionImpl.java:803)
at com.google.cloud.spanner.jdbc.ConnectionImpl.internalExecuteQuery(ConnectionImpl.java:748)
at com.google.cloud.spanner.jdbc.ConnectionImpl.parseAndExecuteQuery(ConnectionImpl.java:681)
at com.google.cloud.spanner.jdbc.ConnectionImpl.executeQuery(ConnectionImpl.java:654)
at com.google.cloud.spanner.jdbc.AbstractJdbcStatement.executeQuery(AbstractJdbcStatement.java:157)
at com.google.cloud.spanner.jdbc.JdbcPreparedStatement.executeQuery(JdbcPreparedStatement.java:55)
at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:57)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.getResultSet(AbstractLoadPlanBasedLoader.java:390)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeQueryStatement(AbstractLoadPlanBasedLoader.java:163)
at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:104)
at org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader.load(AbstractLoadPlanBasedEntityLoader.java:197)
at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:4350)
at org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:569)
at org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:537)
at org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:208)
at org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:332)
at org.hibernate.event.internal.DefaultLoadEventListener.doOnLoad(DefaultLoadEventListener.java:108)
at org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:74)
at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:118)
at org.hibernate.internal.SessionImpl.fireLoadNoChecks(SessionImpl.java:1168)
at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1157)
at org.hibernate.internal.SessionImpl.access$2000(SessionImpl.java:197)
at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.doLoad(SessionImpl.java:2795)
at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.lambda$load$1(SessionImpl.java:2776)
at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.perform(SessionImpl.java:2732)
at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2776)
at org.hibernate.internal.SessionImpl.find(SessionImpl.java:3326)
at org.hibernate.internal.SessionImpl.find(SessionImpl.java:3293)
at bin.Main.main(Main.java:32)
Cause
This bug is caused by another bug in google-cloud-spanner-jdbc: com.google.cloud.spanner.jdbc.SpannerPool.SpannerPoolKey.hashCode() includes com.google.auth.Credentials in its hashCode target, but OAuth2Credentials.requestMetadata and OAuth2Credentials.temporaryAccess (the actual implementation of Credentials) is not initialized first but initialized via Credentials.getRequestMetadata() by mutation.
This intervenes SpannerPoolKey to work as "key" of java.util.HashMap, in which the key must not be modified after registration as the key.
This causes error in com.google.cloud.spanner.jdbc.SpannerPool.closeUnusedSpanners, which is called every 60 secs, and potentially cause the "Pool has been closed" error.
Workaround
The patch workaround is calling GoogleCredentials.getApplicationDefault().getRequestMetadata() before creating a connection. This initializes global Credential object and prevents the incongruence. However, this might not work for rotation of OAuth2Credentials.temporaryAccess, so better idea might be necessary as permanent measures.