[jboss-jira] [JBoss JIRA] (JBJCA-1373) MySQLValidConnectionChecker swallow a root cause of the exception

[Petr Jurak (JIRA)]

    [ https://issues.jboss.org/browse/JBJCA-1373?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13559337#comment-13559337 ] 

Petr Jurak commented on JBJCA-1373:
-----------------------------------

Log after applied fix:
WARN  [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (External Management Request Threads -- 7) IJ030027: Destroying connection that is not valid, due to the following exception: com.mysql.jdbc.JDBC4Connection at 33921022: java.sql.SQLException: Ping failed: java.lang.reflect.InvocationTargetException
	at org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLValidConnectionChecker.isValidConnection(MySQLValidConnectionChecker.java:93)
	at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.isValidConnection(BaseWrapperManagedConnectionFactory.java:1285)
	at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.getInvalidConnections(BaseWrapperManagedConnectionFactory.java:1086)
	at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.getConnection(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:379)
	at org.jboss.jca.core.connectionmanager.pool.AbstractPool.internalTestConnection(AbstractPool.java:1067)
	at org.jboss.jca.core.connectionmanager.pool.strategy.OnePool.testConnection(OnePool.java:93)
	at org.jboss.as.connector.subsystems.common.pool.PoolOperations$TestConnectionInPool.invokeCommandOn(PoolOperations.java:240)
	at org.jboss.as.connector.subsystems.common.pool.PoolOperations$1.execute(PoolOperations.java:97)
	at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:982)
	at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:726)
	at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:450)
	at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1402)
	at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:418)
	at org.jboss.as.controller.ModelControllerImpl.lambda$execute$1(ModelControllerImpl.java:243)
	at org.wildfly.security.auth.server.SecurityIdentity.runAs(SecurityIdentity.java:263)
	at org.wildfly.security.auth.server.SecurityIdentity.runAs(SecurityIdentity.java:229)
	at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:243)
	at org.jboss.as.domain.http.server.DomainApiHandler.handleRequest(DomainApiHandler.java:221)
	at io.undertow.server.handlers.encoding.EncodingHandler.handleRequest(EncodingHandler.java:72)
	at org.jboss.as.domain.http.server.DomainApiCheckHandler.handleRequest(DomainApiCheckHandler.java:93)
	at org.jboss.as.domain.http.server.security.ElytronIdentityHandler.lambda$handleRequest$0(ElytronIdentityHandler.java:62)
	at org.wildfly.security.auth.server.SecurityIdentity.runAs(SecurityIdentity.java:287)
	at org.wildfly.security.auth.server.SecurityIdentity.runAs(SecurityIdentity.java:244)
	at org.jboss.as.controller.AccessAuditContext.doAs(AccessAuditContext.java:254)
	at org.jboss.as.controller.AccessAuditContext.doAs(AccessAuditContext.java:225)
	at org.jboss.as.domain.http.server.security.ElytronIdentityHandler.handleRequest(ElytronIdentityHandler.java:61)
	at io.undertow.server.handlers.BlockingHandler.handleRequest(BlockingHandler.java:56)
	at io.undertow.server.Connectors.executeRootHandler(Connectors.java:330)
	at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:812)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)
	at org.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLValidConnectionChecker.isValidConnection(MySQLValidConnectionChecker.java:83)
	... 32 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 25,237 milliseconds ago.  The last packet sent successfully to the server was 5 milliseconds ago.
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
	at com.mysql.jdbc.Util.handleNewInstance(Util.java:377)
	at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1036)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3427)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3327)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3814)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2435)
	at com.mysql.jdbc.ConnectionImpl.pingInternal(ConnectionImpl.java:3967)
	at com.mysql.jdbc.ConnectionImpl.ping(ConnectionImpl.java:3947)
	... 37 more
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2914)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3337)
	... 42 more 

> MySQLValidConnectionChecker swallow a root cause of the exception
> -----------------------------------------------------------------
>
>                 Key: JBJCA-1373
>                 URL: https://issues.jboss.org/browse/JBJCA-1373
>             Project: IronJacamar
>          Issue Type: Bug
>          Components: JDBC
>            Reporter: Lin Gao
>            Assignee: Petr Jurak
>
> When  java.sql.SQLException is thrown, the root cause should be logged at the same time by MySQLValidConnectionChecker validation.
> ~~~
> WARN  [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) IJ030027: Destroying connection that is not valid, due to the following exception: com.mysql.jdbc.JDBC4Connection at 5d0ae267: java.sql.SQLException: Ping failed: java.lang.reflect.InvocationTargetException
>     at org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLValidConnectionChecker.isValidConnection(MySQLValidConnectionChecker.java:93)
>     at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.isValidConnection(BaseWrapperManagedConnectionFactory.java:1272)
>     at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.getInvalidConnections(BaseWrapperManagedConnectionFactory.java:1085)
> ~~~
> However, the current code is :
> return new SQLException("Ping failed: " + e.toString());
> so this should be modified by:
> return new SQLException("Ping failed: " + e.toString(), e);
> and logged message with root cause.



--
This message was sent by Atlassian JIRA
(v7.5.0#75005)