Intermittent failure in OracleConnectionTest.testConnectNoLeak

[tsegismont]

This intermittent failures happens in both scheduled 4.x and master builds. This seems to indicate Vert.x pooling of connections (in v5) is not the cause of the issue.

The error looks like:

2024-10-28T05:05:13.7614199Z [ERROR] io.vertx.oracleclient.test.tck.OracleConnectionTest.testConnectNoLeak -- Time elapsed: 1.120 s <<< ERROR!
2024-10-28T05:05:13.7615768Z io.vertx.oracleclient.OracleException: 
2024-10-28T05:05:13.7618122Z ORA-12516: Cannot connect to database. Listener at host localhost port 32769 does not have a protocol handler for TCP ready or registered for service FREEPDB1. (CONNECTION_ID=uYQ6BIcUQIuXB8PS8TuipA==)
2024-10-28T05:05:13.7622685Z https://docs.oracle.com/error-help/db/ora-12516/

Its is preceded by several occurrences of this error:

2024-10-21T04:09:40.6228654Z Running io.vertx.oracleclient.test.tck.OracleConnectionTest
2024-10-21T04:09:50.8631843Z Oct 21, 2024 4:09:50 AM oracle.jdbc.driver.PhysicalConnection connect
2024-10-21T04:09:50.8633822Z INFO: entering args (oracle.jdbc.datasource.impl.OracleDataSource$1@4deb2d65)
2024-10-21T04:09:50.8635133Z Oct 21, 2024 4:09:50 AM oracle.net.ns.NSProtocol connect
2024-10-21T04:09:50.8636295Z INFO: traceId=68A3522. 
2024-10-21T04:09:50.8689778Z Oct 21, 2024 4:09:50 AM oracle.net.ns.NSProtocol establishConnection
2024-10-21T04:09:50.8690865Z INFO: Session Attributes: 
2024-10-21T04:09:50.8691540Z sdu=8192, tdu=2097152
2024-10-21T04:09:50.8692988Z nt: host=localhost, port=32769, socketOptions={0=YES, 1=NO, 17=0, 18=false, 2=0, 20=true, 38=TLS, 23=40, 24=50, 40=false, 25=0}
2024-10-21T04:09:50.8694438Z     socket=Socket[unconnected]
2024-10-21T04:09:50.8697331Z client profile={oracle.net.encryption_types_client=(), oracle.net.crypto_seed=, oracle.net.authentication_services=(), oracle.net.setFIPSMode=false, oracle.net.kerberos5_mutual_authentication=false, oracle.net.encryption_client=ACCEPTED, oracle.net.crypto_checksum_client=ACCEPTED, oracle.net.crypto_checksum_types_client=()}
2024-10-21T04:09:50.8703566Z connection options=[host=localhost port=32769 protocol=TCP service_name=FREEPDB1 addr=(ADDRESS=(PROTOCOL=TCP)(HOST=localhost)(PORT=32769)) conn_data=(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(PORT=32769)(HOST=127.0.0.1)(HOSTNAME=localhost))(CONNECT_DATA=(CID=(PROGRAM=ForkedBooter)(HOST=fv-az1198-739)(USER=runner))(SERVICE_NAME=FREEPDB1))) done=true]
2024-10-21T04:09:50.8706788Z onBreakReset=false, dataEOF=false, negotiatedOptions=0x0, connected=false
2024-10-21T04:09:50.8708103Z TTIINIT enabled=false, TTC cookie enabled=false
2024-10-21T04:09:50.8708718Z 
2024-10-21T04:09:50.8709357Z Oct 21, 2024 4:09:50 AM oracle.net.ns.NSProtocol configureSessionAttsAno
2024-10-21T04:09:50.8710483Z INFO: traceId=68A3522, anoEnabled=true. 
2024-10-21T04:09:50.8711692Z Oct 21, 2024 4:09:50 AM oracle.net.ns.NSProtocolNIO handleOutboundTimeoutInterrupt
2024-10-21T04:09:50.8712913Z INFO: Connection establishment interrupted externally, exiting.
2024-10-21T04:09:50.8714170Z Oct 21, 2024 4:09:50 AM oracle.jdbc.driver.PhysicalConnection connect
2024-10-21T04:09:50.8715294Z INFO: throwing
2024-10-21T04:09:50.8748965Z java.sql.SQLRecoverableException: ORA-17002: I/O error: Socket read interrupted, Authentication lapse 0 ms.
2024-10-21T04:09:50.8750658Z https://docs.oracle.com/error-help/db/ora-17002/
2024-10-21T04:09:50.8751926Z 	at oracle.jdbc.driver.T4CConnection.handleLogonIOException(T4CConnection.java:1658)
2024-10-21T04:09:50.8754102Z 	at oracle.jdbc.driver.T4CConnection.handleLogonInterruptedIOException(T4CConnection.java:1519)
2024-10-21T04:09:50.8755930Z 	at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:1132)
2024-10-21T04:09:50.8801493Z 	at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:1178)
2024-10-21T04:09:50.8803469Z 	at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:105)
2024-10-21T04:09:50.8804939Z 	at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:886)
2024-10-21T04:09:50.8806452Z 	at oracle.jdbc.datasource.impl.OracleDataSource.getPhysicalConnection(OracleDataSource.java:707)
2024-10-21T04:09:50.8808669Z 	at oracle.jdbc.datasource.impl.OracleDataSource.getConnection(OracleDataSource.java:381)
2024-10-21T04:09:50.8931354Z 	at oracle.jdbc.datasource.impl.OracleDataSource.getConnectionInternal(OracleDataSource.java:2206)
2024-10-21T04:09:50.8933127Z 	at oracle.jdbc.datasource.impl.OracleDataSource$1.build(OracleDataSource.java:1915)
2024-10-21T04:09:50.8934767Z 	at oracle.jdbc.datasource.impl.OracleDataSource$1.build(OracleDataSource.java:1849)
2024-10-21T04:09:50.8936525Z 	at io.vertx.oracleclient.impl.OracleConnectionFactory.lambda$connect$0(OracleConnectionFactory.java:75)
2024-10-21T04:09:50.8938239Z 	at io.vertx.oracleclient.impl.Helper$SQLBlockingCodeHandler.handle(Helper.java:306)
2024-10-21T04:09:50.9213845Z 	at io.vertx.oracleclient.impl.Helper$SQLBlockingCodeHandler.handle(Helper.java:298)
2024-10-21T04:09:50.9291664Z 	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$4(ContextImpl.java:199)
2024-10-21T04:09:50.9293145Z 	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:270)
2024-10-21T04:09:50.9294479Z 	at io.vertx.core.impl.ContextImpl$1.execute(ContextImpl.java:215)
2024-10-21T04:09:50.9295525Z 	at io.vertx.core.impl.WorkerTask.run(WorkerTask.java:56)
2024-10-21T04:09:50.9296873Z 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
2024-10-21T04:09:50.9298617Z 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
2024-10-21T04:09:50.9300167Z 	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
2024-10-21T04:09:50.9301452Z 	at java.base/java.lang.Thread.run(Thread.java:840)
2024-10-21T04:09:50.9302683Z Caused by: java.io.IOException: Socket read interrupted, Authentication lapse 0 ms.
2024-10-21T04:09:50.9304079Z 	at oracle.jdbc.driver.T4CConnection.handleLogonIOException(T4CConnection.java:1653)
2024-10-21T04:09:50.9305188Z 	... 21 more
2024-10-21T04:09:50.9306395Z Caused by: java.io.InterruptedIOException: Socket read interrupted
2024-10-21T04:09:50.9307753Z 	at oracle.net.nt.TimeoutSocketChannel.doBlockedRead(TimeoutSocketChannel.java:612)
2024-10-21T04:09:50.9309117Z 	at oracle.net.nt.TimeoutSocketChannel.read(TimeoutSocketChannel.java:536)
2024-10-21T04:09:50.9310479Z 	at oracle.net.ns.NSProtocolNIO.doSocketRead(NSProtocolNIO.java:1224)
2024-10-21T04:09:50.9311656Z 	at oracle.net.ns.NIOPacket.readNIOPacket(NIOPacket.java:436)
2024-10-21T04:09:50.9312849Z 	at oracle.net.ns.NSProtocolNIO.negotiateConnection(NSProtocolNIO.java:216)
2024-10-21T04:09:50.9314156Z 	at oracle.net.ns.NSProtocol.connect(NSProtocol.java:352)
2024-10-21T04:09:50.9315484Z 	at oracle.jdbc.driver.T4CConnection.connectNetworkSessionProtocol(T4CConnection.java:3411)
2024-10-21T04:09:50.9317029Z 	at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:1016)
2024-10-21T04:09:50.9318048Z 	... 19 more
2024-10-21T04:09:50.9318320Z