[jboss-jira] [JBoss JIRA] (WFLY-10749) Artemis with JDBC store on slow or high latency database crashed on: Critical IO Error. Failed to process JDBC Record statements: java.sql.BatchUpdateException: IO Error: Socket read timed out

[Miroslav Novak (JIRA)]

Miroslav Novak created WFLY-10749:
-------------------------------------

             Summary: Artemis with JDBC store on slow or high latency database crashed on: Critical IO Error.  Failed to process JDBC Record statements: java.sql.BatchUpdateException: IO Error: Socket read timed out
                 Key: WFLY-10749
                 URL: https://issues.jboss.org/browse/WFLY-10749
             Project: WildFly
          Issue Type: Bug
          Components: JMS
    Affects Versions: 13.0.0.Final, 12.0.0.Final
            Reporter: Miroslav Novak
            Assignee: Martyn Taylor
            Priority: Critical


Artemis configured with JDBC store is not robust if database is slow/under high load and when there is higher latency to database. Artemis has tendency to shutdown itself on "Critical IO Error" under low load. It is visible when EAP QE moved Jenkins to Central CI where is higher latency to used Oracle12cR2 database. In following test scenario:
* Start 2 WF/EAP server in cluster. There is queue InQueue and OutQueue deployed on both of the servers. 
* Send 10 000 small messages to InQueue to server 1
* Then deploy MDB on server 2. MDB consumes messages from InQueue and resends to OutQueue
* Wait until MDB processes all messages and check that 10 000 messages is in OutQueue

Result:
Sometimes happens that Artemis in server 1 crashes due to following exception:
{code}
20:13:45,641 WARN  [org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl] (Thread-17 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$3 at 4de066d8)) IO Error: Socket read 
timed out: java.sql.BatchUpdateException: IO Error: Socket read timed out
        at oracle.jdbc.driver.OraclePreparedStatement.executeLargeBatch(OraclePreparedStatement.java:10032)
        at oracle.jdbc.driver.T4CPreparedStatement.executeLargeBatch(T4CPreparedStatement.java:1364)
        at oracle.jdbc.driver.OraclePreparedStatement.executeBatch(OraclePreparedStatement.java:9839)
        at oracle.jdbc.driver.OracleStatementWrapper.executeBatch(OracleStatementWrapper.java:234)
        at org.jboss.jca.adapters.jdbc.WrappedStatement.executeBatch(WrappedStatement.java:1180)
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl.sync(JDBCJournalImpl.java:228) [artemis-jdbc-store-1.5.5.jbossorg-012.jar:1.5.5.jbossorg-012]
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl$JDBCJournalSync.run(JDBCJournalImpl.java:991) [artemis-jdbc-store-1.5.5.jbossorg-012.jar:1.5.5.jbossorg-012]
        at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent$2.run(ActiveMQScheduledComponent.java:284) [artemis-commons-1.5.5.jbossorg-012.jar:1.5.5.jbossorg-012]
        at org.apache.activemq.artemis.utils.OrderedExecutorFactory$OrderedExecutor$ExecutorTask.run(OrderedExecutorFactory.java:122) [artemis-commons-1.5.5.jbossorg-012.jar:1.5.5.jbossorg-012]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_171]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_171]
        at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_171]

20:13:45,652 WARN  [org.apache.activemq.artemis.core.server] (Thread-17 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$3 at 4de066d8)) AMQ222010: Critical IO Error, shutting down the server. file=NULL, message=Critical IO Error.  Failed to process JDBC Record statements: java.sql.BatchUpdateException: IO Error: Socket read timed out
        at oracle.jdbc.driver.OraclePreparedStatement.executeLargeBatch(OraclePreparedStatement.java:10032)
        at oracle.jdbc.driver.T4CPreparedStatement.executeLargeBatch(T4CPreparedStatement.java:1364)
        at oracle.jdbc.driver.OraclePreparedStatement.executeBatch(OraclePreparedStatement.java:9839)
        at oracle.jdbc.driver.OracleStatementWrapper.executeBatch(OracleStatementWrapper.java:234)
        at org.jboss.jca.adapters.jdbc.WrappedStatement.executeBatch(WrappedStatement.java:1180)
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl.sync(JDBCJournalImpl.java:228) [artemis-jdbc-store-1.5.5.jbossorg-012.jar:1.5.5.jbossorg-012]
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl$JDBCJournalSync.run(JDBCJournalImpl.java:991) [artemis-jdbc-store-1.5.5.jbossorg-012.jar:1.5.5.jbossorg-012]
        at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent$2.run(ActiveMQScheduledComponent.java:284) [artemis-commons-1.5.5.jbossorg-012.jar:1.5.5.jbossorg-012]
        at org.apache.activemq.artemis.utils.OrderedExecutorFactory$OrderedExecutor$ExecutorTask.run(OrderedExecutorFactory.java:122) [artemis-commons-1.5.5.jbossorg-012.jar:1.5.5.jbossorg-012]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_171]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_171]
        at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_171]

20:13:45,655 WARN  [org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl] (Thread-17 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$3 at 4de066d8)) java.sql.SQLRecoverableException: Closed Connection
{code}

This thing can be very frustrating for customers who would rely on JDBC store in production. We should provide more robust solution and guide how to configure JDBC store to avoid this situation. 



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