mysqltimeoutexception: statement cancelled due to timeout or client request

SQL 执行超时异常

项目中有个 SQL 语句执行了 30 秒还没执行完成，最后抛出异常MySQLTimeoutException: Statement cancelled due to timeout or client request：

2018-01-25 04:10:00.032 -INFO  --- [ Thread-34] com.example.test.task.CustomerTask : start execute task
2018-01-25 04:10:30.062 -ERROR --- [ Thread-34] com.example.test.task.CustomerTask : execute task failure
org.springframework.dao.QueryTimeoutException:
### Error querying database. Cause: com.mysql.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request
### Cause: com.mysql.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request; SQL []; Statement cancelled due to timeout or client request;
nested exception is com.mysql.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request
    at org.springframework.jdbc.support.SQLStateSQLExceptionTranslator.doTranslate(SQLStateSQLExceptionTranslator.java:118)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:82)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:82)
    at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:73)
    at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:446)
    at com.sun.proxy.$Proxy142.selectOne(Unknown Source)
    at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:166)
    at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:75)
    at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:53)
    at com.sun.proxy.$Proxy215.syncCoffeeStock(Unknown Source)

解决方法

在对应的 Service 方法上指定事务超时的时间为 120 秒：

@Transactional(timeout = 120)

或者是为某个 Service 中的方法打开新事务：

@Transactional(timeout = 60, propagation = Propagation.REQUIRES_NEW)

spring 相关源码简单说明

上面这个事务超时时间是此方法调用中包括的所有查询的总时间，并不等同于Statement#setQueryTimeout(int)设置的时间，如果事务里只有一个 SQL，那二者会接近，但仍不等同，下面会摘录 spring 的相关源码简单说明。

DataSourceTransactionManager#doBegin(Object transaction, TransactionDefinition definition)

以DataSourceTransactionManager为例，摘录其中与timeout相关的代码如下，在txObject.getConnectionHolder().setTimeoutInSeconds(timeout)这一个方法调用中设置超时时间：

public class DataSourceTransactionManager extends AbstractPlatformTransactionManager
        implements ResourceTransactionManager, InitializingBean {

    private DataSource dataSource;

    /**
     * This implementation sets the isolation level but ignores the timeout.
     */
    @Override
    protected void doBegin(Object transaction, TransactionDefinition definition) {
        DataSourceTransactionObject txObject = (DataSourceTransactionObject) transaction;
        Connection con = null;

        try {
            if (!txObject.hasConnectionHolder() || txObject.getConnectionHolder().isSynchronizedWithTransaction()) {
                Connection newCon = this.dataSource.getConnection();
                txObject.setConnectionHolder(new ConnectionHolder(newCon), true);
            }

            txObject.getConnectionHolder().setSynchronizedWithTransaction(true);
            con = txObject.getConnectionHolder().getConnection();

            Integer previousIsolationLevel = DataSourceUtils.prepareConnectionForTransaction(con, definition);
            txObject.setPreviousIsolationLevel(previousIsolationLevel);

            // Switch to manual commit if necessary. This is very expensive in some JDBC drivers,
            // so we don't want to do it unnecessarily (for example if we've explicitly
            // configured the connection pool to set it already).
            if (con.getAutoCommit()) {
                txObject.setMustRestoreAutoCommit(true);
                // 关闭事务的自动提交
                con.setAutoCommit(false);
            }

            prepareTransactionalConnection(con, definition);
            txObject.getConnectionHolder().setTransactionActive(true);

            // 从事务定义中得到 timeout 的设置，如 timeout=90，这里开启的事务定义的属性就是
            int timeout = determineTimeout(definition);
            if (timeout != TransactionDefinition.TIMEOUT_DEFAULT) {
                // 在 ResourceHolderSupport 中设置事务超时时间
                txObject.getConnectionHolder().setTimeoutInSeconds(timeout);
            }
        } catch (Throwable ex) {
            if (txObject.isNewConnectionHolder()) {
                DataSourceUtils.releaseConnection(con, this.dataSource);
                txObject.setConnectionHolder(null, false);
            }
            throw new CannotCreateTransactionException("Could not open JDBC Connection for transaction", ex);
        }
    }
}

ResourceHolderSupport#setTimeoutInSeconds(int)

ResourceHolderSupport#setTimeoutInSeconds(int)这个方法调用的相关代码如下，并注意这个时间设置进去被转化为一个Date对象deadline，以供事务超时控制方法getTimeToLiveInSeconds()和checkTransactionTimeout(boolean)使用：

public abstract class ResourceHolderSupport implements ResourceHolder {

    private boolean synchronizedWithTransaction = false;

    private boolean rollbackOnly = false;

    private Date deadline;

    /**
     * Set the timeout for this object in seconds.
     * @param seconds number of seconds until expiration
     */
    public void setTimeoutInSeconds(int seconds) {
        setTimeoutInMillis(seconds * 1000);
    }

    /**
     * Set the timeout for this object in milliseconds.
     * @param millis number of milliseconds until expiration
     */
    public void setTimeoutInMillis(long millis) {
        this.deadline = new Date(System.currentTimeMillis() + millis);
    }

    /**
     * Return whether this object has an associated timeout.
     */
    public boolean hasTimeout() {
        return (this.deadline != null);
    }

    /**
     * Return the expiration deadline of this object.
     * @return the deadline as Date object
     */
    public Date getDeadline() {
        return this.deadline;
    }

    /**
     * Return the time to live for this object in seconds.
     * Rounds up eagerly, e.g. 9.00001 still to 10.
     * @return number of seconds until expiration
     * @throws TransactionTimedOutException if the deadline has already been reached
     */
    public int getTimeToLiveInSeconds() {
        double diff = ((double) getTimeToLiveInMillis()) / 1000;
        int secs = (int) Math.ceil(diff);
        checkTransactionTimeout(secs <= 0);
        return secs;
    }

    /**
     * Return the time to live for this object in milliseconds.
     * @return number of millseconds until expiration
     * @throws TransactionTimedOutException if the deadline has already been reached
     */
    public long getTimeToLiveInMillis() throws TransactionTimedOutException{
        if (this.deadline == null) {
            throw new IllegalStateException("No timeout specified for this resource holder");
        }
        long timeToLive = this.deadline.getTime() - System.currentTimeMillis();
        checkTransactionTimeout(timeToLive <= 0);
        return timeToLive;
    }

    /**
     * Set the transaction rollback-only if the deadline has been reached,
     * and throw a TransactionTimedOutException.
     */
    private void checkTransactionTimeout(boolean deadlineReached) throws TransactionTimedOutException {
        if (deadlineReached) {
            setRollbackOnly();
            throw new TransactionTimedOutException("Transaction timed out: deadline was " + this.deadline);
        }
    }
}

DataSourceUtils#applyTimeout(Statement stmt, DataSource dataSource, int timeout)

ResourceHolderSupport#getTimeToLiveInSeconds(int)这个方法在外部有一个关键的调用位置，DataSourceUtils#applyTimeout(Statement, DataSource, int)，相关源码如下：

public abstract class DataSourceUtils {

    /**
     * Apply the current transaction timeout, if any,
     * to the given JDBC Statement object.
     * @param stmt the JDBC Statement object
     * @param dataSource the DataSource that the Connection was obtained from
     * @throws SQLException if thrown by JDBC methods
     * @see java.sql.Statement#setQueryTimeout
     */
    public static void applyTransactionTimeout(Statement stmt, DataSource dataSource) throws SQLException {
        applyTimeout(stmt, dataSource, -1);
    }

    /**
     * Apply the specified timeout - overridden by the current transaction timeout,
     * if any - to the given JDBC Statement object.
     * @param stmt the JDBC Statement object
     * @param dataSource the DataSource that the Connection was obtained from
     * @param timeout the timeout to apply (or 0 for no timeout outside of a transaction)
     * @throws SQLException if thrown by JDBC methods
     * @see java.sql.Statement#setQueryTimeout
     */
    public static void applyTimeout(Statement stmt, DataSource dataSource, int timeout) throws SQLException {
        Assert.notNull(stmt, "No Statement specified");
        ConnectionHolder holder = null;
        if (dataSource != null) {
            holder = (ConnectionHolder) TransactionSynchronizationManager.getResource(dataSource);
        }
        // 下面这几句代码是 spring 中，SQL 语句执行超时设置的关键代码
        // 这也是为何事务的超时为何不能等同与 statement.queryTimeout 的原因
        if (holder != null && holder.hasTimeout()) {
            // Remaining transaction timeout overrides specified value.
            stmt.setQueryTimeout(holder.getTimeToLiveInSeconds());
        } else if (timeout >= 0) {
            // No current transaction timeout -> apply specified value.
            stmt.setQueryTimeout(timeout);
        }
        // 同时这里没有默认的 else 子句，也就是即没有事务超时设置，也没有在类似 JdbcTemplate 中设置 queryTimeout，那么 timeout 默认值就是-1
    }

}

JdbcTemplate#setQueryTimeout(int)

JdbcTemplate#setQueryTimeout(int)中关于timeout相关说明，其中指出了事务运行的剩余超时时间会覆盖这个值，另外jdbcTemplate这个 bean 在 spring 容器内一般都是单例的，所以JdbcTemplate#setQueryTimeout(int)方法设置需要注意一下，必要时可以使用new JdbcTemplate(DataSource dataSource)构建特定的jdbcTemplate实例后再设置其queryTimeout。

public class JdbcTemplate extends JdbcAccessor implements JdbcOperations {

    /**
     * Construct a new JdbcTemplate, given a DataSource to obtain connections from.
     * <p>Note: This will not trigger initialization of the exception translator.
     * @param dataSource the JDBC DataSource to obtain connections from
     */
    public JdbcTemplate(DataSource dataSource) {
        setDataSource(dataSource);
        afterPropertiesSet();
    }

    /**
     * Set the query timeout for statements that this JdbcTemplate executes.
     * <p>Default is -1, indicating to use the JDBC driver's default
     * (i.e. to not pass a specific query timeout setting on the driver).
     * <p>Note: Any timeout specified here will be overridden by the remaining
     * transaction timeout when executing within a transaction that has a
     * timeout specified at the transaction level.
     * @see java.sql.Statement#setQueryTimeout
     */
    public void setQueryTimeout(int queryTimeout) {
        this.queryTimeout = queryTimeout;
    }
}

Statement#setQueryTimeout(int)

最后执行的相关接口和实现类，部分代码如下：

public interface Statement extends Wrapper, AutoCloseable {

    /**
     * Sets the number of seconds the driver will wait for a
     * <code>Statement</code> object to execute to the given number of seconds.
     *By default there is no limit on the amount of time allowed for a running
     * statement to complete. If the limit is exceeded, an
     * <code>SQLTimeoutException</code> is thrown.
     * A JDBC driver must apply this limit to the <code>execute</code>,
     * <code>executeQuery</code> and <code>executeUpdate</code> methods.
     * <p>
     * <strong>Note:</strong> JDBC driver implementations may also apply this
     * limit to {@code ResultSet} methods
     * (consult your driver vendor documentation for details).
     * <p>
     * <strong>Note:</strong> In the case of {@code Statement} batching, it is
     * implementation defined as to whether the time-out is applied to
     * individual SQL commands added via the {@code addBatch} method or to
     * the entire batch of SQL commands invoked by the {@code executeBatch}
     * method (consult your driver vendor documentation for details).
     *
     * @param seconds the new query timeout limit in seconds; zero means
     *        there is no limit
     * @exception SQLException if a database access error occurs,
     * this method is called on a closed <code>Statement</code>
     *            or the condition {@code seconds >= 0} is not satisfied
     * @see #getQueryTimeout
     */
    void setQueryTimeout(int seconds) throws SQLException;

}

public class StatementImpl implements Statement {

    /**
     * Sets the queryTimeout limit
     *
     * @param seconds
     *            -
     *            the new query timeout limit in seconds
     *
     * @exception SQLException
     *                if a database access error occurs
     */
    public void setQueryTimeout(int seconds) throws SQLException {
        synchronized (checkClosed().getConnectionMutex()) {
            if (seconds < 0) {
                throw SQLError.createSQLException(Messages.getString("Statement.21"), SQLError.SQL_STATE_ILLEGAL_ARGUMENT, getExceptionInterceptor());
            }

            this.timeoutInMillis = seconds * 1000;
        }
    }
}

AbstractPlatformTransactionManager#defaultTimeout

AbstractPlatformTransactionManager#defaultTimeout属性可以设置应用中事务超时的默认值，相关代码如下：

public abstract class AbstractPlatformTransactionManager implements PlatformTransactionManager, Serializable {

    private int defaultTimeout = TransactionDefinition.TIMEOUT_DEFAULT;

}

管理超时的计时器线程

有设置queryTimeout属性的 Statement 执行时，会启动一个Cancellation Timer线程，负责管理这个 SQL 执行的timeout处理，线程栈如下：

"MySQL Statement Cancellation Timer@10671" daemon prio=5 tid=0x46 nid=NA waiting
  java.lang.Thread.State: WAITING
     at java.lang.Object.wait(Object.java:-1)
     at java.lang.Object.wait(Object.java:502)
     at java.util.TimerThread.mainLoop(Timer.java:526)
     at java.util.TimerThread.run(Timer.java:505)

Cancellation Timer线程启动和执行KILL QUERY相关代码如下：

public class PreparedStatement extends com.mysql.jdbc.StatementImpl implements java.sql.PreparedStatement {

    protected ResultSetInternalMethods executeInternal(int maxRowsToRetrieve, Buffer sendPacket, boolean createStreamingResultSet,
            boolean queryIsSelectOnly, Field[] metadataFromCache, boolean isBatch) throws SQLException {
        MySQLConnection locallyScopedConn = checkClosed();
        CancelTask timeoutTask = null;
        if (locallyScopedConnection.getEnableQueryTimeouts() && this.timeoutInMillis != 0 && locallyScopedConnection.versionMeetsMinimum(5, 0, 0)) {
            // 在此启动 Timer 线程
            timeoutTask = new CancelTask(this);
            locallyScopedConnection.getCancelTimer().schedule(timeoutTask, this.timeoutInMillis);
        }

        statementBegins();

        // timeout 发生之后，就在这里执行 KILL QUERY 指令
        rs = locallyScopedConn.execSQL(this, sql, this.maxRows, null, this.resultSetType, this.resultSetConcurrency, createStreamingResultSet(),
            this.currentCatalog, cachedFields);

        if (timeoutTask != null) {
            if (timeoutTask.caughtWhileCancelling != null) {
                throw timeoutTask.caughtWhileCancelling;
            }

            timeoutTask.cancel();
            locallyScopedConn.getCancelTimer().purge();
            timeoutTask = null;
        }

        synchronized (this.cancelTimeoutMutex) {
            if (this.wasCancelled) {
                SQLException cause = null;

                if (this.wasCancelledByTimeout) {
                    // SQL 执行超时，在此抛出超时异常
                    cause = new MySQLTimeoutException();
                } else {
                    cause = new MySQLStatementCancelledException();
                }

                resetCancelledState();

                throw cause;
            }
        }
    }
}

MySQLConnection的实现类ConnectionImpl相关代码如下：

public class ConnectionImpl extends ConnectionPropertiesImpl implements MySQLConnection {

    public Timer getCancelTimer() {
        synchronized (getConnectionMutex()) {
            if (this.cancelTimer == null) {
                this.cancelTimer = new Timer("MySQL Statement Cancellation Timer", true);
            }
            return this.cancelTimer;
        }
    }

}

JDBC timeout 相关示意图

上图展示了简化的WAS(web application server)和DBMS数据库通信时的超时层次。更上层的超时依赖于下层的超时，只有当较低层的超时机制正常工作，上层的超时才会正常。如果JDBC驱动程序的socket超时工作不正常，那么更上层的超时比如Statement超时和事务超时都不会正常工作。

不推荐使用socket超时来限制一个Statement的执行时间，因此socket超时的值必须要高于Statement的超时时间，否则socket超时将会先生效，这样Statement超时就没有意义，也无法生效。

示意图中的各种不同的timeout值与DBMS本身并没有直接关系，除了建立的数据库连接会受DBMS的系统设置wait_timeout影响，MySQL 中这个值默认为86400，即 8 小时，连接闲置 8 小时会被 MySQL 服务器断开。

DBCP连接池位于上图的左边。你会发现各种层面的超时与DBCP是分开的。DBCP负责数据库连接的创建和管理，并不涉及超时的处理。当在DBCP中创建了一个数据库连接或发送了一条查询校验的 SQL 语句用于检查连接有效性时，socket超时会影响这些过程的处理，但并不直接影响应用程序。另外有一个从DBCP获取数据库连接的超时设置，即在应用程序中调用DBCP的getConnection()方法时，你能指定应用程序获取数据库连接的超时时间，但这和JDBC的连接超时无关。

MySQL 中的 Statement 超时处理

1. 调用Connection#createStatement()方法创建一个Statement对象
2. 调用Statement#executeQuery()方法
3. Statement通过内部的Connection将查询命令传输到MySqlServer数据库
4. Statement创建一个新的超时执行线程Cancellation Timer来处理超时
5. MySQL-5.1 以上版本改为每个连接分配一个线程
6. 向Cancellation Timer线程注册当前的Statement
7. 发生超时
8. Cancellation Timer线程创建一个相同配置的Connection
9. 用新创建的Connection发送取消查询的命令，MySQL-5.1.9 中新增加了一个参数queryTimeoutKillsConnection，默认为false，如果为true则会将连接关闭，而不是发送KILL QUERY指令

取消查询的相关代码

public class StatementImpl implements Statement {
    class CancelTask extends TimerTask {
        @Override
        public void run() {

            Thread cancelThread = new Thread() {

                @Override
                public void run() {
                    // ......
                    // 省略前面的代码
                    synchronized (StatementImpl.this.cancelTimeoutMutex) {
                        if (CancelTask.this.origConnURL.equals(physicalConn.getURL())) {
                            // All's fine
                            // 在这里复制当前连接，并发送 KILL QUERY 指令
                            cancelConn = physicalConn.duplicate();
                            cancelStmt = cancelConn.createStatement();
                            cancelStmt.execute("KILL QUERY " + physicalConn.getId());
                        } else {
                            try {
                                cancelConn = (Connection) DriverManager.getConnection(CancelTask.this.origConnURL, CancelTask.this.origConnProps);
                                cancelStmt = cancelConn.createStatement();
                                cancelStmt.execute("KILL QUERY " + CancelTask.this.origConnId);
                            } catch (NullPointerException npe) {
                                // Log this? "Failed to connect to " + origConnURL + " and KILL query"
                            }
                        }
                        CancelTask.this.toCancel.wasCancelled = true;
                        CancelTask.this.toCancel.wasCancelledByTimeout = true;
                    }
                    // ......
                }
            };
            cancelThread.start();
        }
    }
}

异常重现

重现异常MySQLTimeoutException: Statement cancelled due to timeout or client request。

简单示例一

@Test
public void test1() {
    Connection connection = null;
    Statement statement = null;
    try {
        Class.forName("com.mysql.jdbc.Driver");
        connection = DriverManager.getConnection("jdbc:mysql://localhost/test", "dbusername", "dbpassword");
        statement = connection.createStatement();
        // statement.setQueryTimeout(3);
        // statement.execute("select 1 from dual");

        // debugger break point
        throw new java.lang.Exception(new com.mysql.jdbc.exceptions.MySQLTimeoutException());
    } catch (Exception e) {
        e.printStackTrace();
        try {
            if (connection != null) {
                connection.close();
            }
            if (statement != null) {
                statement.close();
            }
        } catch (SQLException sqlException) {
            sqlException.printStackTrace();
        }
    } finally {
        // debugger break point
        System.out.println("finally");
    }
}

程序运行之后输出如下异常信息：

java.lang.Exception: com.mysql.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request
    at com.example.spring.jdbc.dao.JdbcStatementTest.test1(JdbcStatementTest.java:27)
Caused by: com.mysql.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request
    ... 23 more

简单示例二

@Test
public void test2() {
    Connection connection = null;
    Statement statement = null;
    try {
        Class.forName("com.mysql.jdbc.Driver");
        // connection = DriverManager.getConnection("jdbc:mysql://localhost/jdbc?queryTimeoutKillsConnection=true", "dbuser", "dbpass");
        connection = DriverManager.getConnection("jdbc:mysql://localhost/jdbc", "dbuser", "dbpass");
        statement = connection.createStatement();
        statement.setQueryTimeout(3);
        System.out.println("Start Time: " + System.currentTimeMillis());
        // DB will wait for 10 Seconds
        statement.executeQuery("SELECT SLEEP(10)");
    } catch (Exception e) {
        System.out.println("End   Time: " + System.currentTimeMillis());
        e.printStackTrace();
        try {
            if (connection != null) {
                connection.close();
            }
            if (statement != null) {
                statement.close();
            }
        } catch (SQLException sqlException) {
            sqlException.printStackTrace();
        }
    } finally {
        // debugger break point
        System.out.println("finally");
    }
}

程序运行之后输出如下异常信息：

Start Time: 1516887672140
End   Time: 1516887675154
com.mysql.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request
    at com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1401)
    at com.example.spring.jdbc.dao.JdbcStatementTest.test2(JdbcStatementTest.java:92)

References

1. Understanding JDBC Internals & Timeout Configuration
2. 深入理解 JDBC 的超时
3. MySQLTimeoutException: Statement cancelled due to timeout or client request