4 Replies Latest reply on Jun 13, 2014 7:40 AM by miguelgl

Problems using WildFly 8.1 with a MySQL XA DataSource

miguelgl Jun 11, 2014 1:00 PM

Dear all, I've been dealing with the following problem for the whole day on a setup using wildfly and mysql. More precisely:

wildfly-8.1.0.Final
plain standalone mode
mysql-server-5.5
using mysql-connector-java-5.1.31-bin.jar via a deployed module within $WILDFLY_HOME/modules/...
both running in separate ubuntu 12.04 64bits machines
Both are Azure virtual machines, 1 CPU 1.7 GB RAM
Java 8 64bits

The problem I'm facing is blocked operations after maybe a couple of interactions with my server are made. For example, after accessing some REST endpoints and/or browsing through some JSF pages. Actions, which are all implemented in EJB's end up blocking.

After some time (order of minutes) I start getting a bunch of traces in my server.log about db connections, transactions and the like. But I am finding it hard to diagnose the problem. Seems there are communication failures between the server and the database, but I cannot make that sure from the log.

I'm appending my datasource relevant configuration and the server log. I'd really appreciate if anyone could help me diagnosing the problem. Thanks in advance!

<connection-url>jdbc:h2:mem:test;DB_CLOSE_DELAY=-1;DB_CLOSE_ON_EXIT=FALSE</connection-url>

<user-name>sa</user-name>

</security>

</datasource>

<xa-datasource jndi-name="java:jboss/datasources/WorzelXADS" pool-name="MySQLXADS" enabled="true" use-java-context="true">

<xa-datasource-property name="ServerName">

mydbserverhost.cloudapp.net

</xa-datasource-property>

<xa-datasource-property name="DatabaseName">

databasename

</xa-datasource-property>

<xa-datasource-property name="URL">

jdbc:mysql://mydbserverhost.cloudapp.net:3306/databasename?zeroDateTimeBehavior=convertToNull

</xa-datasource-property>

<driver>mysql</driver>

<xa-pool>

<min-pool-size>10</min-pool-size>

<max-pool-size>20</max-pool-size>

</xa-pool>

<user-name>databaseuser</user-name>

<password>databasepass</password>

</security>

<valid-connection-checker class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLValidConnectionChecker"/>

<validate-on-match>true</validate-on-match>

<exception-sorter class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLExceptionSorter"/>

</validation>

</xa-datasource>

<driver-class>com.mysql.jdbc.Driver</driver-class>

<xa-datasource-class>com.mysql.jdbc.jdbc2.optional.MysqlXADataSource</xa-datasource-class>

</driver>

<xa-datasource-class>org.h2.jdbcx.JdbcDataSource</xa-datasource-class>

</driver>

</drivers>

</datasources>

</subsystem>

server-fail.log.zip 10.1 KB

1. Re: Problems using WildFly 8.1 with a MySQL XA DataSource

jaikiran Jun 12, 2014 12:08 AM (in response to miguelgl)

2014-06-11 18:26:48,645 WARN [org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLValidConnectionChecker] (XNIO-1 task-2) Unexpected error: java.lang.reflect.InvocationTargetException

    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.8.0_05]

    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [rt.jar:1.8.0_05]

    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_05]

    at java.lang.reflect.Method.invoke(Method.java:483) [rt.jar:1.8.0_05]

    at org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLValidConnectionChecker.isValidConnection(MySQLValidConnectionChecker.java:83) [ironjacamar-jdbc-1.1.5.Final.jar:1.1.5.Final]

    at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnectionFactory.isValidConnection(BaseWrapperManagedConnectionFactory.java:1301) [ironjacamar-jdbc-1.1.5.Final.jar:1.1.5.Final]

    at org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.checkValid(BaseWrapperManagedConnection.java:502) [ironjacamar-jdbc-1.1.5.Final.jar:1.1.5.Final]

    at org.jboss.jca.adapters.jdbc.xa.XAManagedConnectionFactory.matchManagedConnections(XAManagedConnectionFactory.java:553) [ironjacamar-jdbc-1.1.5.Final.jar:1.1.5.Final]

    at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreArrayListManagedConnectionPool.getConnection(SemaphoreArrayListManagedConnectionPool.java:377) [ironjacamar-core-impl-1.1.5.Final.jar:1.1.5.Final]

    at org.jboss.jca.core.connectionmanager.pool.AbstractPool.internalTestConnection(AbstractPool.java:740) [ironjacamar-core-impl-1.1.5.Final.jar:1.1.5.Final]

    at org.jboss.jca.core.connectionmanager.pool.strategy.OnePool.testConnection(OnePool.java:91) [ironjacamar-core-impl-1.1.5.Final.jar:1.1.5.Final]

    at org.jboss.as.connector.subsystems.common.pool.PoolOperations$TestConnectionInPool.invokeCommandOn(PoolOperations.java:206) [wildfly-connector-8.1.0.Final.jar:8.1.0.Final]

    at org.jboss.as.connector.subsystems.common.pool.PoolOperations$1.execute(PoolOperations.java:87) [wildfly-connector-8.1.0.Final.jar:8.1.0.Final]

    at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:606) [wildfly-controller-8.1.0.Final.jar:8.1.0.Final]

    at org.jboss.as.controller.AbstractOperationContext.doCompleteStep(AbstractOperationContext.java:484) [wildfly-controller-8.1.0.Final.jar:8.1.0.Final]

    at org.jboss.as.controller.AbstractOperationContext.completeStepInternal(AbstractOperationContext.java:281) [wildfly-controller-8.1.0.Final.jar:8.1.0.Final]

    at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:276) [wildfly-controller-8.1.0.Final.jar:8.1.0.Final]

    at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:271) [wildfly-controller-8.1.0.Final.jar:8.1.0.Final]

    at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:145) [wildfly-controller-8.1.0.Final.jar:8.1.0.Final]

    at org.jboss.as.domain.http.server.DomainApiHandler.handleRequest(DomainApiHandler.java:170)

    at org.jboss.as.domain.http.server.security.SubjectDoAsHandler$1.run(SubjectDoAsHandler.java:72)

    at org.jboss.as.domain.http.server.security.SubjectDoAsHandler$1.run(SubjectDoAsHandler.java:68)

    at java.security.AccessController.doPrivileged(Native Method) [rt.jar:1.8.0_05]

    at javax.security.auth.Subject.doAs(Subject.java:422) [rt.jar:1.8.0_05]

    at org.jboss.as.controller.AccessAuditContext.doAs(AccessAuditContext.java:94) [wildfly-controller-8.1.0.Final.jar:8.1.0.Final]

    at org.jboss.as.domain.http.server.security.SubjectDoAsHandler.handleRequest(SubjectDoAsHandler.java:68)

    at org.jboss.as.domain.http.server.security.SubjectDoAsHandler.handleRequest(SubjectDoAsHandler.java:63)

    at io.undertow.server.handlers.BlockingHandler.handleRequest(BlockingHandler.java:50)

    at org.jboss.as.domain.http.server.DomainApiCheckHandler.handleRequest(DomainApiCheckHandler.java:83)

    at io.undertow.security.handlers.AuthenticationCallHandler.handleRequest(AuthenticationCallHandler.java:52)

    at io.undertow.server.Connectors.executeRootHandler(Connectors.java:177)

    at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:727)

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_05]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_05]

    at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_05]

Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 474,385 milliseconds ago. The last packet sent successfully to the server was 124,248 milliseconds ago.

    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) [rt.jar:1.8.0_05]

    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) [rt.jar:1.8.0_05]

    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) [rt.jar:1.8.0_05]

    at java.lang.reflect.Constructor.newInstance(Constructor.java:408) [rt.jar:1.8.0_05]

    at com.mysql.jdbc.Util.handleNewInstance(Util.java:408)

    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1137)

    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3715)

    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3604)

    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4149)

    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2615)

    at com.mysql.jdbc.ConnectionImpl.pingInternal(ConnectionImpl.java:4378)

    at com.mysql.jdbc.ConnectionImpl.ping(ConnectionImpl.java:4355)

    at com.mysql.jdbc.jdbc2.optional.ConnectionWrapper.ping(ConnectionWrapper.java:867)

    ... 35 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:3161)

    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3615)

    ... 41 more

Are you sure there wasn't a DB server downtime or some such thing? You also note that the DB server is hosted on a VM, perhaps that's playing a part in slowing things down and maybe even communication failures?
1 of 1 people found this helpful
Actions
2. Re: Problems using WildFly 8.1 with a MySQL XA DataSource

miguelgl Jun 12, 2014 6:41 AM (in response to jaikiran)

Indeed, my #1 suspicion is for connectivity issues. I'm using a SaaS MySQL DB instance from a third-party provider and do not control the whole networking environment.

My problem is turning this suspicion into an authoritative answer, I do not feel 100% confident concluding connectivity issues from the log I sent. I can see this

Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

message, but many other (possibly related?) error messages follow. Could please you clarify wether they are a consequence of the communication failure or due to something else?

Thanks again!
Actions
3. Re: Problems using WildFly 8.1 with a MySQL XA DataSource

jaikiran Jun 13, 2014 12:47 AM (in response to miguelgl)

Those subsequent error messages are most likely because of the network communication failure. It looks like at some point the DB connectivity was working fine and some successful connections were maintained in the datasource pool of the application server. Then at some point the DB connectivity issues due to the network communication failure started to happen and DB operations started failing. Furthermore, the datasource does a validity check on the pooled connections before handing it out to code which requires those connections. Those subsequent WARN messages that you see are from this very verification check failing because of the communication issue.
Actions
4. Re: Problems using WildFly 8.1 with a MySQL XA DataSource

miguelgl Jun 13, 2014 7:40 AM (in response to jaikiran)

Thank you so much for your quick and so concise clarifications! Best Regards!
Actions

Go to original post