暂无图片
暂无图片
暂无图片
暂无图片
暂无图片

Oracle Alert 日志频繁出现 12170、TNS-12535/TNS-00505 错误,如何排查和解决?

大家好,这里是公众号 DBA学习之路,致力于分享数据库领域相关知识。

前言

节后巡检一套 Oracle 11GR2 的库,发现 alert 日志很大,于是看看 alert 日志里都记录了啥?好家伙,一打开日志发现全是告警 TNS-12170/12535/12560/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: 06-FEB-2025 00:16:10
  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
Thu Feb 06 00:20:32 2025
***********************************************************************

这明显是个老朋友了,对 Oracle DBA 来说太常见了,但是大多数人往往都选择视而不见,正好有案例,我打算记录一下解决过程。

记得点击 "DBA学习之路设为星标

后台回复【进群】,申请加入数据库学习交流群

DataDocks 数据码头 💬

最近联合几个大佬开通了一个付费微信群,加群后会有很多会员福利(分享各类技术文档,干货资源,问题解答等等),更有特邀嘉宾会定期在群内直播,解读 AWR,快问快答等!有兴趣联系微:ywu0613

问题描述

首先可以通过 oerr
 看一下这个报错的描述:

[oracle@lucifer:~]$ oerr ora 12170
12170, 00000, "TNS:Connect timeout occurred"
// *Cause:  The server shut down because connection establishment or
// communication with a client failed to complete within the allotted time
// interval. This may be a result of network or system delays; or this may
// indicate that a malicious client is trying to cause a Denial of Service
// attack on the server.
// *Action: If the error occurred because of a slow network or system,
// reconfigure one or all of the parameters SQLNET.INBOUND_CONNECT_TIMEOUT,
// SQLNET.SEND_TIMEOUT, SQLNET.RECV_TIMEOUT in sqlnet.ora to larger values.
// If a malicious client is suspected, use the address in sqlnet.log to
// identify the source and restrict access. Note that logged addresses may
// not be reliable as they can be forged (e.g. in TCP/IP).

简单来说,就是连接超时了,可能是网络慢或者有人搞破坏。例如,拔网线、防火墙断开连接或客户端崩溃且未通知服务器等。

再看这次的案例:

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: 06-FEB-2025 00:16:10
  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
Thu Feb 06 00:20:32 2025

错误堆栈依次为 12170/TNS-12535/12560/TNS-00505
,这表示已建立的连接由于网络问题而超时。在这种情况下 Oracle 服务器进程无法确定客户端状态,它必须等到 TCP keepalive 超时(可能是几个小时),然后该进程将终止,上述消息将打印在 alert 日志中。所以,这是一个网络/应用程序问题,而不是数据库的错误。

📢 注意:Oracle 11GR1 版本之前同样的信息 'Fatal NI connect error 12170' 是写入 sqlnet.log 中的。

当 Oracle 安装在不同的操作系统(OS)时,对于 nt secondary err code
 错误代码有所不同:

  • Solarisnt secondary err code: 145(ETIMEDOUT 145 * Connection timed out */)
  • Linuxnt secondary err code: 110(ETIMEDOUT 110 Connection timed out)
  • HP-UXnt secondary err code: 238(ETIMEDOUT 238 * Connection timed out */)
  • AIXnt secondary err code: 78(ETIMEDOUT 78 * Connection timed out */)
  • Windowsnt secondary err code: 60(Winsock 错误:10060

很明显,当前案例的操作系统就是 Linux 了。

问题重现

为了更深入的理解,我们可以重现一下这个问题。

在模拟开始前,我们先了解一下操作系统 TCP KeepAlive 机制的原理:

当建立 TCP 链接后,如果应用程序或者上层协议一直不发送数据,或者隔很长一段时间才发送数据,当链接很久没有数据报文传输时就需要通过 keepalive 机制去确定对方是否在线,链接是否需要继续保持。当超过一定时间没有发送数据时,TCP 会自动发送一个数据为空的报文给对方,如果对方回应了报文,说明对方在线,链接可以继续保持,如果对方没有报文返回,则在重试一定次数之后认为链接丢失,就不会释放链接。

TCP的keepalive机制是用来在非活跃的连接上发送保活探测数据包,以检测对端是否仍然活跃。如果对端不响应,可以断定连接已经断开,并且可以采取相应的动作。

操作系统的 TCP keepalive 有 3 个参数(这是 Linux 参数,当然其它操作系统也有类似的参数):

  • tcp_keepalive_time:在开始发送保活探测数据包之前,TCP 连接处于非活动状态的时间。
  • tcp_keepalive_intvl:如果对端没有任何响应,保活探测包的发送间隔。
  • tcp_keepalive_probes:在认定连接失效之前,发送保活探测包的次数。

查看 Linux 系统的默认值:

## 保活时间,默认为 7200s
[root@oracle11g:/root]# sysctl net.ipv4.tcp_keepalive_time
net.ipv4.tcp_keepalive_time = 7200
## 发生间隔,默认为 75s
[root@oracle11g:/root]# sysctl net.ipv4.tcp_keepalive_intvl
net.ipv4.tcp_keepalive_intvl = 75
## 重试次数,默认为 9次
[root@oracle11g:/root]# sysctl net.ipv4.tcp_keepalive_probes
net.ipv4.tcp_keepalive_probes = 9

这里为了快速模拟,我已经提前将服务端的 tcp_keepalive 临时改变为 5 分钟,重试次数为 3 次(需要在最初客户端建立连接前修改,否则不生效):

## 第一步就需要执行修改,然后再在客户端模拟连接
[root@oracle11g:/root]# sysctl -w net.ipv4.tcp_keepalive_time=300
net.ipv4.tcp_keepalive_time = 300
[root@oracle11g:/root]# sysctl -w net.ipv4.tcp_keepalive_probes=3
net.ipv4.tcp_keepalive_probes = 3

使用客户端连接一套 11GR2 测试环境,确定会话和服务器进程:

[oracle@oracle19c:/home/oracle]$ sqlplus lucifer/oracle@192.168.6.60/lucifer

SQL*Plus: Release 19.0.0.0.0 - Production on Thu Feb 6 10:56:38 2025
Version 19.3.0.0.0

Copyright (c) 1982, 2019, Oracle.  All rights reserved.


Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

LUCIFER@192.168.6.60/lucifer SQL> select s.sid,s.serial#,p.spid 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;

       SID    SERIAL# SPID
---------- ---------- ------------------------
      2273         31 36644

客户端的端口可以通过 listener.log 来标识,在本例中为 61809

Thu Feb 06 10:56:39 2025
06-FEB-2025 10:56:39 * (CONNECT_DATA=(SERVICE_NAME=lucifer)(CID=(PROGRAM=sqlplus)(HOST=oracle19c)(USER=oracle))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.6.194)(PORT=61809)) * establish * lucifer * 0
06-FEB-2025 10:56:42 * service_update * lucifer * 0

拔掉客户端和服务器之间的网线,或者通过 iptables
 命令断开连接,监控服务器的连接:

## 宕掉网卡
[root@oracle19c:/root]# nmcli connection show 
NAME    UUID                                  TYPE      DEVICE 
ens192  882d9815-b6c2-4a6d-a1d9-514e120be9bd  ethernet  ens192 
virbr0  34fa23fb-9193-4872-85d7-0a7615a12311  bridge    virbr0 
[root@oracle19c:/root]# nmcli connection down ens192 

## 防火墙断开
## iptables -A INPUT -p tcp -s 192.168.6.194 --sport 61809 -j DROP
## iptables -nL

可以看到,即使网线已被拔出(或连接已被 iptables 断开),操作系统 角度来看 TCP 连接仍处于已建立状态:

[root@oracle11g:/root]# date
Thu Feb  6 10:58:02 CST 2025
[root@oracle11g:/root]# lsof -Pani :61809
COMMAND   PID   USER   FD   TYPE DEVICE SIZE/OFF NODE NAME
oracle  36644 oracle   14u  IPv6  70337      0t0  TCP 192.168.6.60:1521->192.168.6.194:61809 (ESTABLISHED)

服务器进程在 oracle 端仍然存在:

SYS@lucifer 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=2273;

SYSDATE                   SID    SERIAL# SPID                     EVENT                                                            STATUS   STATE
------------------ ---------- ---------- ------------------------ ---------------------------------------------------------------- -------- -------------------
06-FEB-25                2273         31 36644                    SQL*Net message from client                                      INACTIVE WAITING

使用 ss 命令可以确定当前连接的 keepalive 时间:

[root@oracle11g:/root]# ss -tuanop '( sport = :1521 and dport = :61809 )'
Netid               State                Recv-Q                Send-Q                                       Local Address:Port                                         Peer Address:Port                Process               
tcp                 ESTAB                0                     0                                    [::ffff:192.168.6.60]:1521                               [::ffff:192.168.6.194]:61809                users:(("oracle",pid=36644,fd=14)) timer:(keepalive,27sec,0)

等待一会儿后,数据库 alert 告警日志显示以下消息:

***********************************************************************

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: 06-FEB-2025 11:12:18
  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.6.194)(PORT=61809))

再次查看进程已经不存在:

[root@oracle11g:/root]# ss -tuanop '( sport = :1521 and dport = :61809 )'
Netid                  State                  Recv-Q                  Send-Q                                   Local Address:Port                                   Peer Address:Port                 Process  
[root@oracle11g:/root]# lsof -Pani :61809

📢 注意:在 12C 或更高版本上,如果启用了 DCD,则服务器进程的 tcp keepalive 时间将更改为 DCD 间隔值。

具体可参考:Oracle Net 12c: DCD (Dead Connection Detection ) 功能的改变 (Doc ID 2403921.1)

到这,这个问题的模拟也就结束了。

解决方案

说了这么多,还没有给解决方案,别急,来了!

调整防火墙

防火墙 (FW) 在当今的网络中已经很常见,用于保护网络环境。防火墙识别 TCP 协议并记录客户端服务器套接字端点。此外,FW 识别 TCP 连接关闭,然后将释放为记录打开连接而分配的资源。对于每对端点,防火墙还必须分配一些资源(可能很小)。

当客户端或服务器关闭通信时,它会发送 TCP FIN 类型数据包,这是正常的套接字关闭行为。然而,客户端服务器通信突然终止而没有通过发送 FIN 数据包正确关闭端点的情况并不罕见。例如,当客户端或服务器崩溃、断电或网络错误导致无法向另一端发送关闭数据包时。在这种情况下,防火墙并不知道端点是否继续使用仍然处于打开的那些通道。作为被动模式,它无法确定端点是否仍然处于活动状态。因为不可能永远维护资源,而且,在未知的时间内一直保持端口开放是一种安全威胁。因此,防火墙会对那些在预定时间内保持空闲状态的连接实施封锁。

最初,FW 旨在保护应用程序服务器、网络,然后保护客户端/服务器连接。考虑到这些,以小时为单位的超时(大多数固件默认为 1 小时)是合理的。随着更复杂的安全方案的出现,FW 不仅存在于客户端和服务器之间,还存在于不同的应用服务器(内网、非军事区(DMZ)等)和数据库服务器之间。因此,服务器之间通信的 1 小时空闲时间范围可能不合适。

建议调整防火墙设置,以获得最大空闲时间。当然这是一个安全设置,所以应该由网络或系统管理员完成。

调整 Oracle 参数

数据库连接中,如果一端是监听进程(可能是专用进程或调度程序进程),当连接被阻断时,后端无法知道客户端是否还能发送请求。这会导致资源浪费,比如数据库会话、锁和文件描述符等。

解决办法是让后端“主动”一点,使用 DCD(死连接检测)来检查连接是否还正常。

具体操作是在服务器端的 $ORACLE_HOME/network/admin/sqlnet.ora
 文件中设置 SQLNET.EXPIRE_TIME=10
(10分钟)。这样,如果10分钟内没有活动,服务器会向客户端发送一个小探测包。如果客户端没有回应,服务器就会关闭连接并释放资源。

DCD(死连接检测)有两个好处

  1. 如果 SQLNET.EXPIRE_TIME
     比防火墙的空闲超时时间短,防火墙会把这个探测包当作活动信号,不会中断连接,除非客户端或服务器真的出了问题。
  2. 如果 SQLNET.EXPIRE_TIME
     比防火墙的空闲超时时间长,一旦连接中断,数据库会很快发现并关闭连接。

第一种情况适合连接来自应用服务器时使用,第二种情况则适合客户端应用。

DCD 是在应用层和 TCP/IP 协议上工作的。如果你设置了 SQLNET.EXPIRE_TIME=10
,也就是说如果断电或网络中断 10 分钟,连接不会被立即标记为死亡。

一旦你修改了 SQLNET.EXPIRE_TIME
 的设置,不需要重启监听器或数据库,新的连接会立刻生效。但是,已经存在的连接不会受到影响,只有新建立的连接才会使用这个新设置。所以,在全部连接都更新之前,你可能还会遇到一些超时问题。

治标不治本

最后,还有一个治标不治本的方法,就是屏蔽掉这些告警日志,不让他写入 alert 日志。可以通过设置以下参数来关闭 **Automatic Diagnostic Repository (ADR)**,这样 Oracle 的网络诊断信息就不会被写入到 alert 日志文件中。

1.关闭 SQLNET 的 ADR

在服务器的 sqlnet.ora
 文件中添加以下参数 DIAG_ADR_ENABLED = OFF

2.关闭监听器的 ADR

在服务器的 listener.ora
 文件中添加以下参数:DIAG_ADR_ENABLED_<监听器名称> = OFF
,将 <监听器名称>
 替换为实际的监听器名字。比如,如果监听器名字是 LISTENER
,参数就写成:DIAG_ADR_ENABLED_LISTENER = OFF

修改后,需要重新加载 reload
 或重启 restart
 监听,让设置生效。

简单来说,就是通过改这两个文件,关掉 ADR,避免网络诊断信息写进日志,改完后别忘了重启监听!

写在最后

大家处理问题的时候,一定要见微知著,深入研究,这样才能真正学习到东西,干中学,学中干


本文部分内容参考自 MOS 文章:

  • Alert Log Errors: 12170 TNS-12535/TNS-00505: Operation Timed Out (Doc ID 1628949.1)
  • 警报日志超时的演示:TNS-12170/TNS-12535/TNS-12560/TNS-00505 (Doc ID 2995380.1)
  • 在 11g 12c已经更高版本的数据库中 alert 日志中报 Fatal NI Connect Error 12170, 'TNS-12535: TNS:operation timed out' (Doc ID 2226594.1)
  • Resolving Problems with Connection Idle Timeout With Firewall (Doc ID 2999935.1)

文章转载自青年数据库学习互助会,如果涉嫌侵权,请发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论