NPE in server.log when running jdbc_all tests

[dmatej]

Current master branch, as of 11. January 2023. Tests passed, so it seems this is some consequence of tested behavior, but it would be good to replace the generic NPE by another runtime exception with developer-friendly message.

I lost one hour thinking that I broke it when I was doing changes in WebappCL, now I see the log is same in both branches. You know - "It is Nullpointer, how that could happen, this is not normal!" :-D

Note: Seems to me this will need larger changes too. The connection can be reset, but getter is not prepared for that, and it's clients too. Also I am not sure if it would be possible to replace it with SQLException or some custom runtime exception would be better (no collision with specs?).

[2023-01-11T16:15:48.354999+01:00] [GlassFish 7.0] [INFO] [] [jakarta.enterprise.logging.stdout] [tid: _ThreadID=127 _ThreadName=p: thread-pool-1; w: 2] [levelValue: 800] [[
Marking conn in Test-7: com.sun.gjc.spi.jdbc40.ConnectionWrapper40@b4552e5]]

[2023-01-11T16:15:48.357231+01:00] [GlassFish 7.0] [INFO] [jdbc.markedForRemoval_txCompleted] [jakarta.enterprise.resource.resourceadapter.com.sun.gjc.spi] [tid: _ThreadID=127 _ThreadName=p: thread-pool-1; w: 2] [levelValue: 800] [[
RAR7112: destroying connection during txCompleted since this connection is marked for removal]]

[2023-01-11T16:15:48.357715+01:00] [GlassFish 7.0] [WARNING] [managed_con.cleanup-failed] [jakarta.enterprise.resource.resourceadapter.com.sun.enterprise.resource.allocator] [tid: _ThreadID=127 _ThreadName=p: thread-pool-1; w: 2] [levelValue: 900] [[
RAR7093 : Error while cleaning up ManagedConnection
java.lang.NullPointerException
at com.sun.gjc.spi.ManagedConnectionImpl.getActualConnection(ManagedConnectionImpl.java:680)
at com.sun.gjc.spi.ManagedConnectionFactoryImpl.resetIsolation(ManagedConnectionFactoryImpl.java:518)
at com.sun.gjc.spi.ManagedConnectionImpl.resetConnectionProperties(ManagedConnectionImpl.java:457)
at com.sun.gjc.spi.ManagedConnectionImpl.cleanup(ManagedConnectionImpl.java:318)
at com.sun.enterprise.resource.allocator.AbstractConnectorAllocator.cleanup(AbstractConnectorAllocator.java:148)
at com.sun.enterprise.resource.pool.ConnectionPool.cleanupResource(ConnectionPool.java:1045)
at com.sun.enterprise.resource.pool.ConnectionPool.freeResource(ConnectionPool.java:1021)
at com.sun.enterprise.resource.pool.ConnectionPool.transactionCompleted(ConnectionPool.java:1140)
at com.sun.enterprise.resource.pool.PoolManagerImpl.transactionCompleted(PoolManagerImpl.java:285)
at com.sun.enterprise.resource.pool.PoolManagerImpl$SynchronizationListener.afterCompletion(PoolManagerImpl.java:612)
at com.sun.jts.jta.SynchronizationImpl.after_completion(SynchronizationImpl.java:139)
at com.sun.jts.CosTransactions.RegisteredSyncs.distributeAfter(RegisteredSyncs.java:157)
at com.sun.jts.CosTransactions.TopCoordinator.afterCompletion(TopCoordinator.java:2504)
at com.sun.jts.CosTransactions.CoordinatorTerm.commit(CoordinatorTerm.java:392)
at com.sun.jts.CosTransactions.TerminatorImpl.commit(TerminatorImpl.java:199)
at com.sun.jts.CosTransactions.CurrentImpl.commit(CurrentImpl.java:591)
at com.sun.jts.jta.TransactionManagerImpl.commit(TransactionManagerImpl.java:299)
at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.commitDistributedTransaction(JavaEETransactionManagerJTSDelegate.java:154)
at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:869)
at com.sun.ejb.containers.EJBContainerTransactionManager.completeNewTx(EJBContainerTransactionManager.java:695)
at com.sun.ejb.containers.EJBContainerTransactionManager.postInvokeTx(EJBContainerTransactionManager.java:483)
at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:3980)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1799)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1772)
at com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:180)
at com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:91)
at com.sun.proxy.$Proxy411.test7(Unknown Source)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie.dispatchToMethod(ReflectiveTie.java:122)
at com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie._invoke(ReflectiveTie.java:152)
at com.sun.corba.ee.impl.protocol.ServerRequestDispatcherImpl.dispatchToServant(ServerRequestDispatcherImpl.java:501)
at com.sun.corba.ee.impl.protocol.ServerRequestDispatcherImpl.dispatch(ServerRequestDispatcherImpl.java:172)
at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleRequestRequest(MessageMediatorImpl.java:1529)
at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleRequest(MessageMediatorImpl.java:1405)
at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleInput(MessageMediatorImpl.java:910)
at com.sun.corba.ee.impl.protocol.giopmsgheaders.RequestMessage_1_2.callback(RequestMessage_1_2.java:192)
at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleRequest(MessageMediatorImpl.java:674)
at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.dispatch(MessageMediatorImpl.java:476)
at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.doWork(MessageMediatorImpl.java:2202)
at com.sun.corba.ee.impl.threadpool.ThreadPoolImpl$WorkerThread.performWork(ThreadPoolImpl.java:476)
at com.sun.corba.ee.impl.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:519)
]]

[2023-01-11T16:15:48.358431+01:00] [GlassFish 7.0] [WARNING] [cleanup.resource.failed] [jakarta.enterprise.resource.resourceadapter.com.sun.enterprise.resource.pool] [tid: _ThreadID=127 _ThreadName=p: thread-pool-1; w: 2] [levelValue: 900] [[
RAR8066: Cleanup of a resource from pool [ org.glassfish.resourcebase.resources.api.PoolInfo@d39218a1[jndiName=jdbc-shareable-pool, applicationName=null, moduleName=null] ] failed. Exception : com.sun.appserv.connectors.internal.api.PoolingException: java.lang.NullPointerException]]

[2023-01-11T16:15:48.382896+01:00] [GlassFish 7.0] [INFO] [] [jakarta.enterprise.logging.stdout] [tid: _ThreadID=126 _ThreadName=p: thread-pool-1; w: 1] [levelValue: 800] [[
Marking conn in Test-8: com.sun.gjc.spi.jdbc40.ConnectionWrapper40@10fab7ae]]

[pzygielo]

Assuming non-null wass passed to https://github.com/eclipse-ee4j/glassfish/blob/f7687e86c1f20682f6218067b1e96d76a1d16e3b/appserver/jdbc/jdbc-ra/jdbc-core/src/main/java/com/sun/gjc/spi/ManagedConnectionImpl.java#L166 the only other assignment in this class I see is https://github.com/eclipse-ee4j/glassfish/blob/f7687e86c1f20682f6218067b1e96d76a1d16e3b/appserver/jdbc/jdbc-ra/jdbc-core/src/main/java/com/sun/gjc/spi/ManagedConnectionImpl.java#L372 (Unfortunately https://github.com/eclipse-ee4j/glassfish/blob/f7687e86c1f20682f6218067b1e96d76a1d16e3b/appserver/jdbc/jdbc-ra/jdbc-core/src/main/java/com/sun/gjc/spi/ManagedConnectionImpl.java#L91 but I can't locate any other sub-class.) But given that, could https://github.com/eclipse-ee4j/glassfish/blob/f7687e86c1f20682f6218067b1e96d76a1d16e3b/appserver/jdbc/jdbc-ra/jdbc-core/src/main/java/com/sun/gjc/spi/ManagedConnectionImpl.java#L665 be checkIfValided? This would throw ResourceException that the clients are prepared for.

[dmatej]

Another idea I have is to check the order of operations ... something like if it would do first cleanup and then tried to use nulled field. I don't know yet. Another thing is that in my experience when I fix things like this, something else breaks, because this failed fast, so I expect big fun with it :-D

[pzygielo]

Just for clarification - the current master causes NPEx in 669 https://github.com/eclipse-ee4j/glassfish/blob/f7687e86c1f20682f6218067b1e96d76a1d16e3b/appserver/jdbc/jdbc-ra/jdbc-core/src/main/java/com/sun/gjc/spi/ManagedConnectionImpl.java#L665-L680

at com.sun.gjc.spi.ManagedConnectionImpl.getActualConnection(ManagedConnectionImpl.java:669)

not as originally reported ManagedConnectionImpl.java:680.

[dmatej]

Right, I probably used to second tab in Konsole. My Eclipse added some @Override annotations, so it moved.

[github-actions[bot]]

This issue has been marked as inactive and old and will be closed in 7 days if there is no further activity. If you want the issue to remain open please add a comment