Oracle-TNS-12170/TNS-12535/TNS-12560/TNS-00505问题分析

目录

• 问题背景
• 问题分析
• 问题复现
  • 1、环境准备
  • 2、实验过程

问题背景

客户在系统切换之后，RAC Linux 11.2.0.4环境，系统主连1个节点，但是日志经常出现TNS-12535、TNS-00505报错，具体报错信息如下，希望给出合理解释。

问题分析

• 问题出现原因
  根据MOS官方的文档显示，TNS-12535、TNS-00505这样的错误为服务器和客户端建立的链接，长时间空闲，期间网络中断造成，具体展示流程如下：
  1）会话A，在上10：30分连入数据库操作；
  2）10：35分操作完成之后一直保持空闲链接状态，直到12：35分，这期间经过2个小时空闲；
  3）在2个小时内，会话连接可能被防火墙或者其他设备中断，但是数据库服务端并不知晓；
  4）数据库会通过系统网络参数，tcp_keepalive_time、tcp_keepalive_probes、tcp_keepalive_intvl进行判断，如果为异常链接，则写入alert日志中。
• 解决方法
  1）检查防火墙是否有空闲链接断开的设置
  2）在服务端sqlnet.ora中设置SQLNET.EXPIRE_TIME=n（单位分钟）
  3）服务器端sqlnet.ora中设置DIAG_ADR_ENABLED = OFF，服务器端 listener.ora中设置DIAG_ADR_ENABLED_ = OFF（DIAG_ADR_ENABLED_LISTENER = OFF）屏蔽报错信息

expire_time参数，来主动向客户端发送检测请求，如果客户端还活着，则不做操 作，如果检测发现客户端的连接已经不存在或没有反映，则回收这个session的资源。这样，如果DCD(Dead Connection Detection)的检测时间小于防火墙设置的空闲连接 最大存活时间，那么由于DCD检测客户端存活性需要从服务端发送一个空包到客户端，防火墙就会重新计算这个连接的空闲时间，就不会中断这个会话了

• 参考文档

Alert Log Errors: 12170 TNS-12535/TNS-00505: Operation Timed Out (Doc ID 1628949.1)
在 11g 12c已经更高版本的数据库中 alert 日志中报 Fatal NI Connect Error 12170, 'TNS-12535: TNS:operation timed out' (Doc ID 2226594.1)
A Demonstration of the Alert Log Timeouts Occur: TNS-12170/TNS-12535/TNS-12560/TNS-00505 (Doc ID 2461900.1)

问题复现

1、环境准备

调整系统网络参数，模拟keepalive判断空闲时间，此处设置表示
数据库针对空闲链接会在（60+12+12）=84s之后检测到TCP断开，如果这个链接已经异常的话。

[root@zstest ~]# sysctl -a|grep keep
net.ipv4.tcp_keepalive_intvl = 12
net.ipv4.tcp_keepalive_probes = 2
net.ipv4.tcp_keepalive_time = 60

• net.ipv4.tcp_keepalive_time - 在第一次keep alive请求发送后，不活动连接的时间
• net.ipv4.tcp_keepalive_probes - 在这个连接被认为是断开之前，keep alive请求被重发的次数
• net.ipv4.tcp_keepalive_intvl - keep alive探测的时间间隔

2、实验过程

1） 模拟客户端连接

Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.4 - 64bit Production

SQL> select s.sid,s.serial#,p.spid,s.port from v$session s, v$process p, (select * from v$mystat where rownum=1) ms where s.paddr=p.addr and s.sid=ms.sid;

 SYSDATE        SID    SERIAL# SPID            port 
---------- ---------- --------  ---------   -------
16:41:45       142      45921 9275           60583

2） listener.log日志发现有心链接进来

15-JUL-2020 16:41:45 * (CONNECT_DATA=(SERVICE_NAME=orcl)(CID=(PROGRAM=D:Program?FilesPLSQL?Developerplsqldev.exe)(HOST=DESKTOP-0319KP6)(USER=pc_zhangs))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.70.26)(PORT=60583)) * establish * orcl * 0

3） 再次触发客户端会话，之后通过iptables模拟链接中断，记录最后一次会话活跃时间 16：44：17

SQL> select sysdate,s.sid,s.serial#,p.spid,s.port from v$session s, v$process p, (select * from v$mystat where rownum=1) ms where s.paddr=p.addr and s.sid=ms.sid;

 SYSDATE        SID    SERIAL# SPID            port 
---------- ---------- --------  ---------   -------
16：44：17       142      45921 9275           60583

4） 通过iptables，模拟会话被drop,lsof 命令可以看到会话被iptables drop之后，oracle依然处于连接状态，这也说明Oracle内部记录此链接仍然是建立，只是会话状态为INACTIVE

[root@zstest ~]# iptables -A INPUT -p tcp -s 192.168.70.26 --sport 60583 -j DROP
[root@zstest ~]# date
Wed Jul 15 16:44:27 CST 2020
[root@zstest ~]# iptables -nL
Chain INPUT (policy ACCEPT)
target     prot opt source               destination         
ACCEPT     udp  --  0.0.0.0/0            0.0.0.0/0            udp dpt:53
ACCEPT     tcp  --  0.0.0.0/0            0.0.0.0/0            tcp dpt:53
ACCEPT     udp  --  0.0.0.0/0            0.0.0.0/0            udp dpt:67
ACCEPT     tcp  --  0.0.0.0/0            0.0.0.0/0            tcp dpt:67
DROP       tcp  --  192.168.70.26        0.0.0.0/0            tcp spt:60583
[root@zstest ~]# lsof -Pani :60583
COMMAND  PID   USER   FD   TYPE   DEVICE SIZE/OFF NODE NAME
oracle  9275 oracle   14u  IPv6 27811724      0t0  TCP 192.168.20.242:1521->192.168.70.26:60583 (ESTABLISHED)

5） 通过Oracle内部视图查看链接状态

SQL> select sysdate,s.sid,s.serial#,p.spid,event,status,state from v$session s, v$process p where s.paddr=p.addr and s.sid=49;

SYSDATE               SID   SERIAL# SPID   EVENT                          STATUS   STATE
-------------------   ---- --------- ------ ------------------------------ -------- -------
2020-07-15 16：44：50   142    45921 9275   SQL*Net message from client    INACTIVE WAITING

6）根据之前系统 (tcp keepalive timeout）设置，在会话最后一次执行16：44：17之后84s，Oracle会判断此链接异常，并写入alert日志，从日志可以看出，alert日志记录时间为16:45:42。
最后一次会话执行时间 A：16:44:17
alert日志报错时间 B：16:45:42
B-A=85s
系统设置如果网络会话在空闲84s后检测出链接异常（本实验通过iptables已经中断会话），则会报TNS-12535TNS-00505错误，与预期结果相符，实验结束。

Fatal NI connect error 12170.

  VERSION INFORMATION:
        TNS for Linux: Version 11.2.0.4.0 - Production
        Oracle Bequeath NT Protocol Adapter for Linux: Version 11.2.0.4.0 - Production
        TCP/IP NT Protocol Adapter for Linux: Version 11.2.0.4.0 - Production
  Time: 15-JUL-2020 16:45:42
  Tracing not turned on.
  Tns error struct:
    ns main err code: 12535
    
TNS-12535: TNS:operation timed out
    ns secondary err code: 12560
    nt main err code: 505
    
TNS-00505: Operation timed out
    nt secondary err code: 110
    nt OS err code: 0
  Client address: (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.70.26)(PORT=60583))