java.sql.SQLRecoverableException:IOError:Socketreadtimedout排查历程

一:

创新互联公司是一家集网站建设,沽源企业网站建设,沽源品牌网站建设,网站定制,沽源网站建设报价,网络营销,网络优化,沽源网站推广为一体的创新建站企业，帮助传统企业提升企业形象加强企业竞争力。可充分满足这一群体相比中小企业更为丰富、高端、多元的互联网需求。同时我们时刻保持专业、时尚、前沿，时刻以成就客户成长自我，坚持不断学习、思考、沉淀、净化自己，让我们为更多的企业打造出实用型网站。

12c迁移19c工程，针对大数据相关定时作业进行性能对比，发现部分作业连接19c 出现 Socket read timed out 问题，并且可以复现，该部分作业连接12c并无异常

初步排查情况如下：

1)在执行到某部分sql时jdbc抛出Error: java.io.IOException: SQLException in nextKeyValue 错误，导致的原因是Caused by: java.sql.SQLRecoverableException: IO Error: Socket read timed out 

2）jdbc堆栈信息无ora错误，看起来是一个客户端单方面错误

3）连续查看几次报错日志，发现每次报错都是在发起sql后的第11分钟才抛出异常，询问客户是否有进行timeout相关测试，客户反馈连接串中未设置任何参数

4）对该场景进行重现测试，发现客户端报出Socket read timed out，数据库会话依然在执行直到sql执行结束

5）关于socket read timed out初步了解到是客户端在向数据库发起查询时等待数据返回时超过了某个时间限制导致超时

6）了解到jdbc driver版本是11.2.0.1.0

二：

1)jdbc driver 版本11.2.0.1是不兼容19c，建议客户先进行升级测试

2）需要进一步排查网络是否有超时设置

3）通过以上步骤来缩小排查范围

2.讨论进展如下：

1）客户否认网络存在问题，但我认为是否可以继续进行抓包排查

2）客户表示驱动包问题可以进行升级驱动测试，确认是否驱动包问题

3）提出每次报错都是在第11分钟开始报错，客户提出可能应用平台有配置过10分钟的超时设置，开发排查代码发现有10分钟超时设置，后面增加超时时间再进行测试，发现不再报错

4)客户存在疑问，为何同样的配置在12c不生效，而在19c能够生效

5）现场同时排查了数据库端sqlnet参数，12c和19c并无差别

三：

1）询问中间件同事，表示针对不同数据库版本可能会有不同的超时时间设置，这一点找不到相关资料，询问sr，gcs表示没有不同的设置说法

2）中间件同事和sr同时也建议排查操作系统层，目前只能看到数据库端os，目前看到的网络相关参数不确认。

3)客户在测试环境使用11.2.0.4版本jdbc 进行测试，发现同样在12c不会超时，而在19c会出现超时

4）为了排除数据版本不同造成socket超时不生效原因，我使用一段java代码指定不同版本的jdbc driver 分别连接12c和19c 进行查询操作一段，设置socket timeout 时间为10s，发现11.2.0.1和11.2.0.4 的jdbc driver 连接12c和19c 查询超过10s后 都能出现超时情况，进一步可以说明超时是否生效与数据库版本无关，同时也和jdbc版本无关，所以问题还是出现在应用端配置上，将此情况向客户反馈。

四：

1)将java测试代码 readtimeout 从10秒钟调整为10分钟，看是否能复现客户的问题。

2）调整为10分钟进行测试，结果是19c 正常10分钟超时，12c 10分钟超时。

3）与gcs jdbc 工程师讨论，怀疑12c超时不生效是因为客户端socket api在监测时不断接收到数据包，导致超时时间被不断延长。

4）协调系统工程师进行连接12c和19c的网络抓包测试，发现连接12c时，db端每2分钟会发送一个10 bytes的tns包到client端，随后client端会返回ack包。而连接19c时，db端每2分钟发送一个keep-alive包到client端。从db端来看，目前配置了sqlnet.expire_time=2,可能与此有关。

5）与gcs工程师讨论，12c为何timeout不生效就应该是定时tns包影响，而19c timeout生效是因为keep-alive 包是相对比较底层的数据包，client端操作系统直接过滤掉。

五：

1）查询文档 Oracle Net 12c: Changes to the Functionality of Dead Connection Detection (DCD) (Doc ID 1591874.1) 发现 在12c后 ，开启dcd后db端检测死连接的方式是从每n分钟发送10 bytes tns包改成了 tcp keep-alive包，这里可以解释19c网络抓包中看到的每2分钟一个的keep-alive包。

2）但目前来看，连接12c是使用了传统的tns包，而19c是使用了新的keep-alive包， 从文档1591874.1中看是12.1之后就默认使用了新的模式，但如果操作系统不支持或者认为设定，可以改为传统发送tns包的模式，目前12c是solaris 11.3操作系统，是支持keep -alive的，理论是应该支持新模式的，目前找不到更多资料说明，这仍是是个谜团。

当前标题：java.sql.SQLRecoverableException:IOError:Socketreadtimedout排查历程
本文链接：http://6mz.cn/article/jgsdpj.html