search

brettwooldridge / HikariCP

光 HikariCP・A solid, high-performance, JDBC connection pool at last.
Apache License 2.0
19.87k stars 2.92k forks source link

Help me：Application was streaming results when the connection failed. Consider raising value of 'net_write_timeout' on the server. #1771

Open tanpenggood opened 3 years ago

tanpenggood commented 3 years ago

Please help me!

  1. it occurred CommunicationsException, when I use MySQL enableStreamingResults processing more than 1 million data.
  2. about 8 minutes after occurs the exception, when processing the data.
  3. How should I adjust the configuration?

Environment
Spring Boot 2.1.13.RELEASE
HikariCP 3.2.0
JDK 1.8.0_144-b01
Database MySQL 5.6
Driver mysql:mysql-connector-java:5.1.46
Mybatis Plus 3.2.0

Exception Stack

2021-04-30 00:31:13.669  WARN 6633 --- [           main] com.zaxxer.hikari.pool.ProxyConnection   : master - Connection com.mysql.jdbc.JDBC4Connection@178c4480 marked as broken because of SQLSTATE(08S01), ErrorCode(0)

com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Application was streaming results when the connection failed. Consider raising value of 'net_write_timeout' on the server.
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_73]
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_73]
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_73]
        at java.lang.reflect.Constructor.newInstance(Constructor.java:422) ~[na:1.8.0_73]
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:425) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:990) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3562) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3462) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3903) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:871) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:1999) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.mysql.jdbc.RowDataDynamic.nextRecord(RowDataDynamic.java:374) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.mysql.jdbc.RowDataDynamic.next(RowDataDynamic.java:354) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.mysql.jdbc.ResultSetImpl.next(ResultSetImpl.java:6312) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.zaxxer.hikari.pool.HikariProxyResultSet.next(HikariProxyResultSet.java) [HikariCP-3.2.0.jar!/:na]
        at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.handleRowValuesForSimpleResultMap(DefaultResultSetHandler.java:352) [mybatis-3.5.2.jar!/:3.5.2]
        at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.handleRowValues(DefaultResultSetHandler.java:328) [mybatis-3.5.2.jar!/:3.5.2]
        at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.handleResultSet(DefaultResultSetHandler.java:304) [mybatis-3.5.2.jar!/:3.5.2]
        at org.apache.ibatis.executor.resultset.DefaultResultSetHandler.handleResultSets(DefaultResultSetHandler.java:194) [mybatis-3.5.2.jar!/:3.5.2]
        at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:65) [mybatis-3.5.2.jar!/:3.5.2]
        at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:79) [mybatis-3.5.2.jar!/:3.5.2]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_73]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_73]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_73]
        at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_73]
        at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:63) [mybatis-3.5.2.jar!/:3.5.2]
        at com.sun.proxy.$Proxy74.query(Unknown Source) [na:na]
        at com.baomidou.mybatisplus.core.executor.MybatisSimpleExecutor.doQuery(MybatisSimpleExecutor.java:67) [mybatis-plus-core-3.2.0.jar!/:3.2.0]
        at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324) [mybatis-3.5.2.jar!/:3.5.2]
        at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156) [mybatis-3.5.2.jar!/:3.5.2]
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109) [mybatis-3.5.2.jar!/:3.5.2]
        at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:83) [mybatis-3.5.2.jar!/:3.5.2]
        at org.apache.ibatis.session.defaults.DefaultSqlSession.select(DefaultSqlSession.java:169) [mybatis-3.5.2.jar!/:3.5.2]
        at org.apache.ibatis.session.defaults.DefaultSqlSession.select(DefaultSqlSession.java:157) [mybatis-3.5.2.jar!/:3.5.2]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_73]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_73]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_73]
        at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_73]
        at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:426) [mybatis-spring-2.0.2.jar!/:2.0.2]
        at com.sun.proxy.$Proxy63.select(Unknown Source) [na:na]
        at org.mybatis.spring.SqlSessionTemplate.select(SqlSessionTemplate.java:247) [mybatis-spring-2.0.2.jar!/:2.0.2]
        at com.baomidou.mybatisplus.core.override.MybatisMapperMethod.executeWithResultHandler(MybatisMapperMethod.java:147) [mybatis-plus-core-3.2.0.jar!/:3.2.0]
        at com.baomidou.mybatisplus.core.override.MybatisMapperMethod.execute(MybatisMapperMethod.java:73) [mybatis-plus-core-3.2.0.jar!/:3.2.0]
        at com.baomidou.mybatisplus.core.override.MybatisMapperProxy.invoke(MybatisMapperProxy.java:61) [mybatis-plus-core-3.2.0.jar!/:3.2.0]
        at com.sun.proxy.$Proxy64.selectByStream(Unknown Source) [na:na]
        at com.itplh.demo.service.mc.impl.MemberServiceImpl.selectByStream(MemberServiceImpl.java:45) [classes!/:na]
        at com.itplh.demo.service.mc.impl.MemberServiceImpl$$FastClassBySpringCGLIB$$10b3d4d3.invoke(<generated>) [classes!/:na]
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) [spring-core-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:685) [spring-aop-5.1.14.RELEASE.jar!/:5.1.14.RELEASE]
        at com.itplh.demo.service.mc.impl.MemberServiceImpl$$EnhancerBySpringCGLIB$$91fde992.selectByStream(<generated>) [classes!/:na]
        at com.itplh.demo.runner.MultiThreadRunner.countDownRun(MultiThreadRunner.java:56) [classes!/:na]
        at com.itplh.demo.runner.MultiThreadRunner.doRun(MultiThreadRunner.java:45) [classes!/:na]
        at com.itplh.demo.runner.AbstractRunner.run(AbstractRunner.java:43) [classes!/:na]
        at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:781) [spring-boot-2.1.13.RELEASE.jar!/:2.1.13.RELEASE]
        at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:765) [spring-boot-2.1.13.RELEASE.jar!/:2.1.13.RELEASE]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:319) [spring-boot-2.1.13.RELEASE.jar!/:2.1.13.RELEASE]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1215) [spring-boot-2.1.13.RELEASE.jar!/:2.1.13.RELEASE]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1204) [spring-boot-2.1.13.RELEASE.jar!/:2.1.13.RELEASE]
        at com.itplh.demo.CrmMemberApplication.main(CrmMemberApplication.java:10) [classes!/:na]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_73]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_73]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_73]
        at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_73]
        at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49) [crm-member-1.0-SNAPSHOT.jar:na]
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:107) [crm-member-1.0-SNAPSHOT.jar:na]
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) [crm-member-1.0-SNAPSHOT.jar:na]
        at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88) [crm-member-1.0-SNAPSHOT.jar:na]
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:3014) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3472) ~[mysql-connector-java-5.1.46.jar!/:5.1.46]
        ... 60 common frames omitted

Hikari Config

I just custom under these attribute, other use default.

spring:
  datasource:
    dynamic:
      hikari:
        connection-timeout: 10000
        validation-timeout: 3000
        idle-timeout: 60000
        max-lifetime: 60000
        max-pool-size: 30
        min-idle: 5

MySQL Config

- SHOW GLOBAL VARIABLES LIKE '%timeout%'; SHOW VARIABLES LIKE '%timeout%';
VARIABLE_NAME VALUE VALUE
connect_timeout 10 10
delayed_insert_timeout 300 300
failover_resend_timeout
have_statement_timeout YES YES
innodb_flush_log_at_timeout 1 1
innodb_lock_wait_timeout 50 50
innodb_rollback_on_timeout OFF OFF
interactive_timeout 7200 7200
lock_wait_timeout 31536000 31536000
net_read_timeout 30 30
net_write_timeout 60 28800
rpl_semi_sync_master_timeout 1000 1000
rpl_semi_sync_slave_kill_conn_timeout 5 5
rpl_stop_slave_timeout 31536000 31536000
slave_net_timeout 60 60
thread_pool_idle_timeout 60 60
tokudb_last_lock_timeout
tokudb_lock_timeout 4000 4000
tokudb_lock_timeout_debug 1 1
wait_timeout 86400 28800

DAO Layer

<select id="selectByStream" resultType="com.itplh.demo.domain.MemberStreamDO"
        resultSetType="FORWARD_ONLY" fetchSize="-2147483648">
    SELECT id, member_id, member_tel FROM t_member
</select>
public interface MemberMapper extends BaseMapper<Member> {
    void selectByStream(ResultHandler<MemberStreamDO> resultHandler);
}

Runer

@Component
public class MyRunner implements CommandLineRunner {

    @Autowire
    private MemberMapper memberMapper;

     @Override
    public void run(String... args) throws Exception {
        memberMapper.selectByStream((context) -> {
            // do something
        });
    }
}
NoSugarCoffee commented 1 year ago

The streaming query will override server's "net_write_timeout" value by "netTimeoutForStreamingResults" arg, the default value in mysql/conect/j is 600s, you should add it to connection string, e.g. netTimeoutForStreamingResults=28800

NOTE: i am not the user of HikariCP, i meet this issue in mysql/pgsql migration.