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

glassfish/appserver/jdbc/jdbc-ra/jdbc-core/src/main/java/com/sun/gjc/spi/ManagedConnectionImpl.java

Line 166 in f7687e8

pooledConnection = pooledConn;

the only other assignment in this class I see is

glassfish/appserver/jdbc/jdbc-ra/jdbc-core/src/main/java/com/sun/gjc/spi/ManagedConnectionImpl.java

Line 372 in f7687e8

pooledConnection = null;

(Unfortunately

glassfish/appserver/jdbc/jdbc-ra/jdbc-core/src/main/java/com/sun/gjc/spi/ManagedConnectionImpl.java

Line 91 in f7687e8

protected PooledConnection pooledConnection;

but I can't locate any other sub-class.)
But given that, could

glassfish/appserver/jdbc/jdbc-ra/jdbc-core/src/main/java/com/sun/gjc/spi/ManagedConnectionImpl.java

Line 665 in f7687e8

Connection getActualConnection() throws ResourceException {

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

glassfish/appserver/jdbc/jdbc-ra/jdbc-core/src/main/java/com/sun/gjc/spi/ManagedConnectionImpl.java

Lines 665 to 680 in f7687e8

	Connection getActualConnection() throws ResourceException {
	if (connectionType == ISXACONNECTION || connectionType == ISPOOLEDCONNECTION) {
	try {
	if (actualConnection == null) {
	actualConnection = pooledConnection.getConnection();
	// re-initialize lastAutoCommitValue such that resetAutoCommit() wont
	// affect autoCommit of actualConnection
	setLastAutoCommitValue(defaultAutoCommitValue);
	}
	} catch (SQLException sqle) {
	throw new ResourceException(sqle.getMessage(), sqle);
	}
	}

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]

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

[github-actions]

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

[dmatej]

Still happening in server.log on my "policy" branch based on master:

java.lang.NullPointerException: Cannot invoke "javax.sql.PooledConnection.getConnection()" because "this.pooledConnection" is null
        at Connector(__xa_jdbc_ra)//com.sun.gjc.spi.ManagedConnectionImpl.getActualConnection(ManagedConnectionImpl.java:693)
        at Connector(__xa_jdbc_ra)//com.sun.gjc.spi.ManagedConnectionFactoryImpl.resetIsolation(ManagedConnectionFactoryImpl.java:522)
        at Connector(__xa_jdbc_ra)//com.sun.gjc.spi.ManagedConnectionImpl.resetConnectionProperties(ManagedConnectionImpl.java:468)
        at Connector(__xa_jdbc_ra)//com.sun.gjc.spi.ManagedConnectionImpl.cleanup(ManagedConnectionImpl.java:329)
        at com.sun.enterprise.resource.allocator.AbstractConnectorAllocator.cleanup(AbstractConnectorAllocator.java:139)