一、背景
MySQL系统变量提供关于服务器的一些配置和能力信息,大部分变量可在mysqld服务进程启动时设置,部分变量可在mysqld服务进程运行时设置。合理的系统变量设值范围,是保障MySQL稳定提供服务的重要因素。本文主要描述MySQL数据库的超时timeout相关的一些系统变量,部分参数同程序应用中常见到的CommunicationsException: Communications link failure
异常息息相关。
本文也结合数据同步的场景,对使用DataX3进行MySQL数据同步时遇到的几个经典案例进行阐述,期望对遇到类似问题的同学有一定的参考作用。
安利一下:DataX 是一个异构数据源离线同步工具,致力于实现包括关系型数据库(MySQL、Oracle等)、HDFS、Hive、ODPS、HBase、FTP等各种异构数据源之间稳定高效的数据同步功能。详细介绍可见:阿里云开源离线同步工具DataX3.0介绍、开源代码仓库WIKI地址
二、超时系统变量介绍
MySQL同超时相关的系统变量名大都包含timeout关键字,使用MySQL show variables
即可查询当前变量值状态,查询SQL以及结果如下:
show variables like '%timeout%';
下面具体介绍各个超时系统变量的含义,内容主要翻译和参考了MySQL官方文档。
1.connect_timeout
connect_timeout是MySQL服务端进程mysqld等待连接建立完成的时间,单位为秒。如果超过connect_timeout时间范围内,仍然无法完成协议握手话,MySQL客户端会收到异常,异常消息类似于:Lost connection to MySQL server at 'XXX', system error: errno.
遇到此类错误,一般可尝试性增加connect_timeout时间的大小。
顺便介绍下MySQL应用协议握手发包过程: MySQL协议握手
以Plain Handshake为例,在TCP三次握手建立后,进入MySQL应用层协议握手阶段,过程如下:
- server sending Initial Handshake Packet
- client replying with Handshake Response Packet
MySQL服务端会有监听线程循环接收请求,当有客户端请求过来时,会创建线程(或者从线程池中取)来处理这个客户端请求(一般基于网络的应用都是这个套路,监听线程不具体处理客户请求)。由于MySQL连接基于TCP协议,在MySQL应用层协议建立前,需要完成TCP三次握手,在TCP三次握手成功之后,客户端会进入阻塞,等待服务端的消息,进入应用层协议握手阶段。后续服务端会创建线程(或者从线程池中取)来处理请求,这里会进行权限相关的验证,比如host、用户名、密码验证等。host验证即用grant命令授权用户的时候是有指定host的(比如设置了仅允许指定ip的客户端连接数据库);用户名密码认证则是服务端先生成一个随机数发送给客户端,客户端用该随机数和密码进行多次sha1加密后发送给服务端验证。如果在connect_timeout时间范围内无法完成握手,则报告建立连接异常。
相对于MySQL数据查询Query来说,连接握手相对耗时较少,系统默认的10秒一般足够了,不太会出现需要修改的场景。
2.delayed_insert_timeout
delayed_insert_timeout用于控制MySQL的延迟插入(DELAYED inserts)超时时间,由于在MySQL 5.6.7后,延迟插入不在支持,此系统变量也不建议修改或使用。
3.innodb_lock_wait_timeout
innodb_lock_wait_timeout指的是事务等待获取资源等待的最长时间,超过这个时间还未分配到资源则会返回应用事务失败。参数的时间单位是秒,最小可设置为1s(一般不会设置得这么小),最大可设置1073741824秒(34年),默认值是50秒。当锁等待超过设置时间的时候,类似会报如下的错误; ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction。
innodb_lock_wait_timeout只针对InnoDB存储引擎下的行锁,不影响或限制表锁,可以通过SET GLOBAL 或者 SET SESSION语句在运行时修改此值。
在数据同步场景下,MySQL写出使用了批量batch提交模式,每个batch会开启一个事务的,innodb引擎下,会受到此参数的影响。
4.innodb_rollback_on_timeout
innodb_rollback_on_timeout只针对InnoDB存储引擎,默认为为OFF。ON表示回滚整个事务,OFF表示只回滚最后一条报错的sql。如果事务因为加锁超时,根据innodb_rollback_on_timeout进行回滚(完整事务或最后一条出错SQL),客户端会收到报错异常,用户可以选择是继续提交,或者回滚之前的操作,由用户选择是否进一步提交或者回滚事务。
此系统变量是一个布尔状态的参量,不是超时时间。
5.interactive_timeout
interactive_timeout表示服务器关闭交互式连接前等待活动的秒数,参数默认值28800秒(8小时)。交互式客户端(如mysql命令行)定义为在mysql_real_connect()中使用CLIENT_INTERACTIVE选项的客户端。如果某个交互式客户连接在interactive_timeout秒内没有操作动作,MySQL服务器就认为该客户连接不再有保留的必要并自动关闭这个连接。对于非交互式的客户连接,MySQL服务器将使用wait_timeout变量的值作为这种超时等待时间。
一个交互式客户连接断开并重连的例子(mysql命令行客户端)如下:
DataX进行MySQL数据同步时,使用的MySQL驱动是mysql-connector-java 5.1.34版本,属于非交互式客户端。
6.wait_timeout
wait_timeout表示服务器关闭非交互连接之前等待活动的秒数,参数默认值:28800秒(8小时)。在线程启动时,根据全局wait_timeout值或全局interactive_timeout值初始化会话wait_timeout值,取决于客户端类型(由mysql_real_connect()的连接选项CLIENT_INTERACTIVE定义)。如果某个非交互的客户连接在wait_timeout秒内没有操作动作,MySQL服务器就将认为该客户连接不再有保留的必要并自动关闭这个连接。对于交互式的客户连接,MySQL服务器使用interactive_timeout变量的值作为这种超时等待的秒数。这个变量仅使用于TCP/IP连接和Unix系统上的套接字文件连接。
DataX进行MySQL数据同步时,使用的MySQL驱动是mysql-connector-java 5.1.34版本,属于非交互式客户端。
这里介绍和wait_timeout相关的2个场景。
6.1MySQL经典的8小时连接超时问题
假设你的数据库是MySQL,如果数据源配置不当,将可能发生经典的8小时问题。原因是MySQL在默认情况下,如果发现一个连接的空闲时间超过8小时,将会在数据库端自动关闭这个连接。而数据源并不知道这个连接已经关闭了,当它将这个无用的连接返回给应用时,应用在此连接上执行的SQL Statement都会失败。一般数据库连接池(如c3p0、dbcp)都有保活机制、或者返回连接前检查连接的可用性。
此问题的相关异常栈一般如下所示:
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.] with root cause
java.net.SocketException: Software caused connection abort: socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3852)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2484)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2664)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2809)
at com.mysql.jdbc.ConnectionImpl.setReadOnlyInternal(ConnectionImpl.java:5484)
at com.mysql.jdbc.ConnectionImpl.setReadOnly(ConnectionImpl.java:5477)
at sun.reflect.GeneratedMethodAccessor145.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
6.2DataX MySQL数据读取连接断开问题
此系统变量对于DataX数据同步有较大影响。使用DataX进行MySQL数据同步时,DataX是通过JDBC 相关接口发送数据读取SELECT SQL语句,进而读取MySQL数据库表数据的。如果MySQL表过大、或者有不合适的数据抽取控制where条件、或者数据表缺少相关的索引机制,导致数据读取SQL长时间不返回,有可能到达wait_timeout时间限制值,导致连接被MySQL服务端关闭,数据同步任务失败。
此时需要增大wait_timeout大小或者尝试优化数据读取SQL(表索引、有索引列的where条件、减少不必要的函数列等)的性能。
7.lock_wait_timeout
lock_wait_timeout是元数据锁等待超时,任意锁元数据的语句都会用到这个超时参数,默认为一年。为了保证事务可串行化,不管是myisam还是innodb引擎的表,只要是先在一个session里面开启一个事务,就会获取操作表的元数据锁,这时候如果另一个session要对表的元数据进行修改,则会阻塞直到超时。这个超时会影响对表DML/DDL操作、视图、存储过程、存储函数、LOCK TABLES、FLUSH TABLES WITH READ LOCK、HANDLER 语句等。
8.net_read_timeout
在MySQL服务器接收客户数据的场合,如果MySQL服务器在等待了net_read_timeout秒之后仍未收到来自客户连接的数据,就会产生一个读操作超时错误。这种倒计时只适用于TCP/IP连接。
这里介绍一个net_read_timeout相关的异常情景。
8.1超时问题案例
另一个数据同步任务,在数据写DRDS(分布式关系型数据库服务)的过程中,出现连接被关闭异常:
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
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:377)
at com.mysql.jdbc.Util.getInstance(Util.java:360)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:935)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:924)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:870)
at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1232)
at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1225)
at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4568)
at com.alibaba.datax.plugin.rdbms.writer.CommonRdbmsWriter$Task.doBatchInsert(CommonRdbmsWriter.java:361)
at com.alibaba.datax.plugin.rdbms.writer.CommonRdbmsWriter$Task.startWriteWithConnection(CommonRdbmsWriter.java:291)
at com.alibaba.datax.plugin.rdbms.writer.CommonRdbmsWriter$Task.startWrite(CommonRdbmsWriter.java:319)
at com.alibaba.datax.plugin.writer.mysqlwriter.MysqlWriter$Task.startWrite(MysqlWriter.java:78)
at com.alibaba.datax.core.taskgroup.runner.WriterRunner.run(WriterRunner.java:56)
at java.lang.Thread.run(Thread.java:662)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure
The last packet successfully received from the server was 302,332 milliseconds ago. The last packet sent successfully to the server was 0 milliseconds ago.
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:377)
at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1036)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3427)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3327)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3814)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2435)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2582)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2526)
at com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:4846)
at com.alibaba.datax.plugin.rdbms.writer.CommonRdbmsWriter$Task.doBatchInsert(CommonRdbmsWriter.java:348)
... 5 more
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:2914)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3337)
... 12 more
这里分析判断出现问题的原因是net_read_timeout过小导致的,MySQL服务端没有在net_read_timeout时间范围内读取到客户端MySQL驱动发送过来的数据,导致连接中断。
另外,这类错误不一定是net_read_timeout、net_write_timeout、net_retry_count设置值不合适导致的,也可能是网络基础环境、数据库负载压力、客户端负载压力等有异常情况,遇到问题时需要具体分析找到rootCase。
9. net_write_timeout
在MySQL服务器往客户发送数据的场合,如果MySQL服务器在经过了net_write_timeout秒之后仍未收到来自客户端的响应,就将产生一个写操作超时错误。这种倒计时只适用于TCP/IP连接。
这里介绍一个net_write_timeout相关的异常情景。
9.1超时问题案例
一个数据同步任务,在数据读MySQL的数据过程中,出现连接中断异常,问题报错关键异常信息如下:
2016-08-23 16:16:21.113 [9322429-0-0-reader] INFO CommonRdbmsReader$Task - Begin to read record by Sql: [select hashcode,address from geohash6_address
] jdbcUrl:[jdbc:mysql://ip:3306/database?yearIsDateType=false&zeroDateTimeBehavior=convertToNull&tinyInt1isBit=false&rewriteBatchedStatements=true].
...
2016-08-23 16:22:54.894 [job-9322429] INFO LocalJobContainerCommunicator - Total 429248 records, 371587338 bytes | Speed 343.11KB/s, 329 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 44.462s | All Task WaitReaderTime 333.361s | Percentage 0.00%
2016-08-23 16:22:57.904 [9322429-0-0-reader] ERROR ReaderRunner - Reader runner Received Exceptions:
com.alibaba.datax.common.exception.DataXException: Code:[DBUtilErrorCode-07], Description:[读取数据库数据失败. 请检查您的配置的 column/table/where/querySql或者向 DBA 寻求帮助.]. - 执行的SQL为: select hashcode,address from geohash6_address 具体错误信息为:com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure
The last packet successfully received from the server was 10 milliseconds ago. The last packet sent successfully to the server was 396,755 milliseconds ago.
at com.alibaba.datax.common.exception.DataXException.asDataXException(DataXException.java:26) ~[datax-common-0.0.1-SNAPSHOT.jar:na]
at com.alibaba.datax.plugin.rdbms.util.RdbmsException.asQueryException(RdbmsException.java:81) ~[plugin-rdbms-util-0.0.1-SNAPSHOT.jar:na]
at com.alibaba.datax.plugin.rdbms.reader.CommonRdbmsReader$Task.startRead(CommonRdbmsReader.java:220) ~[plugin-rdbms-util-0.0.1-SNAPSHOT.jar:na]
at com.alibaba.datax.plugin.reader.mysqlreader.MysqlReader$Task.startRead(MysqlReader.java:81) ~[mysqlreader-0.0.1-SNAPSHOT.jar:na]
at com.alibaba.datax.core.taskgroup.runner.ReaderRunner.run(ReaderRunner.java:57) ~[datax-core-0.0.1-SNAPSHOT.jar:na]
at java.lang.Thread.run(Thread.java:662) [na:1.6.0_32]
- 此DataX任务数据读取SQL为:select hashcode,address from geohash6_address
- 此DataX任务已经运行一段时间,通过日志可以看到MySQL读取数据情况: Total 429248 records, 371587338 bytes | Speed 343.11KB/s, 329 records/s
- 在2016-08-23 16:22:57.904时(距离开始发起读取SQL 390秒左右)出现了CommunicationsException异常,上次从服务端获取到数据为10毫秒前,上次驱动发送数据到服务端(即服务端收到确认)396,755毫秒(396秒)前
- MySQL服务和超时相关的系统变量如下图:
- 这里分析判断出现问题的原因是net_write_timeout过小导致的,MySQL服务端没有在net_write_timeout时间范围内获取MySQL驱动的ACK,连接中断。
另外,这类错误不一定是net_read_timeout、net_write_timeout、net_retry_count设置值不合适导致的,也可能是网络基础环境、数据库负载压力、客户端负载压力等有异常情况,遇到问题时需要具体分析找到rootCase。
10.net_retry_count
如果MySQL服务端在读写数据时,出现连接中断,会重试net_retry_count指定的次数。
11.slave-net-timeout
如果从服务器在经过slave-net-timeout秒之后仍未接收到来自主服务器的数据,就将产生一个超时错误,这种倒计时仅仅使用TCP/IP连接。在超时连接错误后,从服务器会尝试重连,第一次尝试重连发生在slave-net-timeout超时触发时,后续的重连间隔、重连次数都有相关的配置可自定义。
三、在数加Data IDE中测试连通性
大数据开发套件(Data IDE),提供了可视化开发界面、离线任务调度运维、快速数据集成、多人协同工作等功能,为您提供一个高效、安全的离线数据开发环境。并且拥有强大的Open API为数据应用开发者提供良好的再创作生态。用户可在其中添加数据源,配置数据同步任务,数据源添加时可进行连通性测试,具体效果如下:
如果您在数据源测试联通时遇到一些问题,大致遇到的情况有:
用户名、或密码错误
由于白名单、或者MySQL数据库host访问限制,不允许连通测试机器访问您的数据库
网络或数据库相关问题,没有在指定时间内3秒联通测试成功并返回
您的数据库连接格式有误,不符合MySQL JDBC URL格式要求
您配置的数据库IP、端口、有防火墙限制、是否路由可达等,此类错误一般异常消息大致如下:
Communications link failure The last packet sent successfully to the server was 0 milliseconds ago. The driver has not received any packets from the server.
针对数据库连接超时相关,可能遇到的情况有:
1.socket超时
套接字或插座(socket)是一种软件形式的抽象,用于表达两台机器间一个连接的“终端”。针对一个特定的连接,每台机器上都有一个“套接字”,可以想象它们之间有一条虚拟的“线缆”。JAVA有两个基于数据流的套接字类:ServerSocket,服务器用它“侦听”进入的连接;Socket,客户端用它初始一次连接。侦听套接字只能接收新的连接请求,不能接收实际的数据包。
以基于TCP/IP协议栈为例介绍,每一次网络交互的sync和ack都有等待时间的上限。假如建立连接是设置socket超时时间为10s,那么当客户端发送sync之后在10s内没有收到服务端的ack信息就会超时。通常java会抛SocketTimeoutException。socket通信失效后下面除login timeout的其他超时机制均会失效。
socket超时时间可以在连接的url中指定。对于MySQL,可以在JDBC URL中指定socket超时时间,如将设置socket超时为10s:
jdbc:mysql:host:port/database?socketTimeout=10000
2.login超时
login timeout是jdbc尝试连接database最长等待时间。在jdbc和database握手过程中每个阶段都会检查是否超时,如果超时会抛SocketException异常,退出登录连接。可以通过DriverManager.setLoginTimeout(10)设置。
目前阿里云数加平台中,数据源连通性检查MySQL的登录超时时间是3秒。
3. connection超时
对应上面MySQL系统变量的connect_timeout参数
客户端和服务器建立的应用层连接,与服务器端无交互状态的连接,直到被服务器端强制关闭而等待的时间,此参数只对基于TCP/IP或基于Socket通信协议建立的连接才有效,单位为秒。连接的建立涉及到资源的分配,如连接池资源。可以通过连接串设置。如:
jdbc:mysql:host:port/database?connectTimeout=10000
4. statement超时
客户端发送一个sql等待服务器返回最大等待时间,客户端在发送sql之前会设置一个timer,如果在指定等待时间内还未收到服务器的执行结果,则会向服务器发出取消sql执行命令。并抛出SQLException。设置方法:statement.setQueryTimeout(100);注意:如果socket通信阻塞,这个异常是抛不出来的,方法调用会阻塞在向服务器发送取消命令。