MySQL JDBC Connector/J + DBCP + Spring framework (+Spring Security)でDB再接続時に例外発生

MySQL+DBCPでDB接続するときは、DB接続タイムアウト時の対策として検証クエリを入れましょうというお話。

現象

MySQLのサーバパラメータ "wait_timeout" の秒数(デフォルト:28800秒 = 8時間) を超過してDBに再接続しようとすると以下の例外が発生した。

org.springframework.security.AuthenticationServiceException:
PreparedStatementCallback; SQL [SELECT user_id, password, role_id FROM user WHERE user_id = ?]; The last packet successfully received from the server was 54,586,800 milliseconds ago.  The last packet sent successfully to the server was 54,586,801 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.; nested exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 54,586,800 milliseconds ago. The last packet sent successfully to the server was 54,586,801 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.; nested exception is org.springframework.dao.RecoverableDataAccessException:
PreparedStatementCallback; SQL [SELECT user_id, password, role_id FROM user WHERE user_id = ?]; The last packet successfully received from the server was 54,586,800 milliseconds ago.  The last packet sent successfully to the server was 54,586,801 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.; nested exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException:
The last packet successfully received from the server was 54,586,800 milliseconds ago.  The last packet sent successfully to the server was 54,586,801 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
        at org.springframework.security.providers.dao.DaoAuthenticationProvider.retrieveUser(DaoAuthenticationProvider.java:86)
        at org.springframework.security.providers.dao.AbstractUserDetailsAuthenticationProvider.authenticate(AbstractUserDetailsAuthenticationProvider.java:121)
        at org.springframework.security.providers.ProviderManager.doAuthentication(ProviderManager.java:188)
        at org.springframework.security.AbstractAuthenticationManager.authenticate(AbstractAuthenticationManager.java:46)
        ... 73 more
Caused by: org.springframework.dao.RecoverableDataAccessException:
PreparedStatementCallback; SQL [SELECT user_id, password, role_id FROM user WHERE user_id = ?]; The last packet successfully received from the server was 54,586,800 milliseconds ago.  The last packet sent successfully to the server was 54,586,801 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.; nested exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException:
The last packet successfully received from the server was 54,586,800 milliseconds ago.  The last packet sent successfully to the server was 54,586,801 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
        at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:97)
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80)
        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:607)
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:641)
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:666)
        at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:698)
        at org.springframework.jdbc.object.SqlQuery.execute(SqlQuery.java:112)
        at org.springframework.jdbc.object.SqlQuery.execute(SqlQuery.java:199)
        at org.springframework.jdbc.object.SqlQuery.execute(SqlQuery.java:207)
        at org.springframework.security.userdetails.jdbc.JdbcDaoImpl.loadUsersByUsername(JdbcDaoImpl.java:214)
        at org.springframework.security.userdetails.jdbc.JdbcDaoImpl.loadUserByUsername(JdbcDaoImpl.java:175)
        at org.springframework.security.providers.dao.DaoAuthenticationProvider.retrieveUser(DaoAuthenticationProvider.java:83)
        ... 77 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 54,586,800 milliseconds ago.  The last packet sent successfully to the server was 54,586,801 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
        at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1074)
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3313)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1940)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2109)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2648)
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2077)
        at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2228)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
        at org.springframework.jdbc.core.JdbcTemplate$1.doInPreparedStatement(JdbcTemplate.java:648)
        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:591)
        ... 86 more
Caused by: java.net.SocketException: Broken pipe
        at java.net.SocketOutputStream.socketWrite0(Native Method)
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
        at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
        at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3294)
        ... 94 more

例外メッセージにあるように、DB接続文字列のパラメータに'autoReconnect=true'を追加しても症状は改善せず。

対処

org.apache.commons.dbcp.BasicDataSourceのプロパティ validationQueryに 'SELECT 1' を設定するようにした。

protected String validationQuery
このプールにコネクションが返された後にコネクションのチェックに使用される SQL クエリです。 指定する場合にはこのクエリは少なくとも1つの列を返す SQL SELECT ステートメントでなくてはなりません。

BasicDataSource (Jakarta Commons Database Connection Pool)

applicationContext.xml

<bean id="dataSource" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
    <property name="driverClassName" value="com.mysql.jdbc.Driver" />
    <property name="url" value="jdbc:mysql://localhost:3306/dbname?characterEncoding=UTF-8&amp;characterSetResults=UTF-8" />
    <property name="username" value="dbuser" />
    <property name="password" value="dbuser" />
    <property name="validationQuery" value="SELECT 1" /> <!-- 追加 -->
</bean>

余談

なんだかんだで調べるのに半日くらい費やしてしまいました。例外メッセージで検索したら深みにはまるパターン。
対処方法が分かったところで後でいろいろ調べたら、他のところでいっぱい書かれてました。

例外メッセージの内容は違うけど、原因と対処方法は同じでした。
もうちょい早く気づければ。