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
BasicDataSource (Jakarta Commons Database Connection Pool)
このプールにコネクションが返された後にコネクションのチェックに使用される SQL クエリです。 指定する場合にはこのクエリは少なくとも1つの列を返す SQL SELECT ステートメントでなくてはなりません。
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&characterSetResults=UTF-8" /> <property name="username" value="dbuser" /> <property name="password" value="dbuser" /> <property name="validationQuery" value="SELECT 1" /> <!-- 追加 --> </bean>
余談
なんだかんだで調べるのに半日くらい費やしてしまいました。例外メッセージで検索したら深みにはまるパターン。
対処方法が分かったところで後でいろいろ調べたら、他のところでいっぱい書かれてました。
例外メッセージの内容は違うけど、原因と対処方法は同じでした。
もうちょい早く気づければ。