首页 » ORACLE 9i-23ai, 系统相关 » 分析SQL*Net message from client连接间断性问题

分析SQL*Net message from client连接间断性问题

之前在我的blog记录过Troubleshooting Dataguard SYNC同步模式时网络问题 一则网络诊断的问题,通常如果因为网络不通因数白名单或防护墙问题较常见,或网络不稳定丢包使用ping traceroute也可能辅助诊断,但是对于一些客户端执行了几个SQL后随机出现中断或挂起还是比较少见,这里结合一个案例提供一个诊断方法。

现象

sqlplus xxx/xxx@rmtdb
SQL*Plus: Release 19.0.0.0.0 - Production on Fri Sep 17 15:38:00 2023
Version 19.3.0.0.0

SQL> SELECT 1 FROM DUAL;  
SQL>   --等1分钟
SQL> SELECT 1 FROM DUAL; --查询挂起

Note:
客户端随机性挂起,服务端查询会话等待是SQL*Net message from the client,并且是inactive状态

1,长期traceoute或ping 观察客户端挂起时的网络丢包情况
2, 检查包重组或overflow
3, 检查DCD或是否有tcp idle timeout配置
4,在客户端与服务端启用SQL*Net Trace
5, 对进程做操作系统层strace跟踪

Strace

#0  0x00007f814bfb875d in read () from /lib64/libpthread.so.0
#1  0x00007f815051e070 in snttread () from /u01/oracle/app/19.3.0/lib/libclntsh.so.19.1
#2  0x00007f814da0b243 in nttrd () from /u01/oracle/app/19.3.0/lib/libclntsh.so.19.1
#3  0x00007f814d8deb17 in nsprecv () from /u01/oracle/app/19.3.0/lib/libclntsh.so.19.1
#4  0x00007f814d8e7492 in nsrdr () from /u01/oracle/app/19.3.0/lib/libclntsh.so.19.1
#5  0x00007f814ec642c9 in nsfull_pkt_rcv () from /u01/oracle/app/19.3.0/lib/libclntsh.so.19.1
#6  0x00007f814ec6b58e in nsfull_brc () from /u01/oracle/app/19.3.0/lib/libclntsh.so.19.1
#7  0x00007f8150503116 in nioqrc () from /u01/oracle/app/19.3.0/lib/libclntsh.so.19.1
#0  0x00007f19cb24d8c2 in read () from /lib64/libpthread.so.0
#1  0x0000000015414d85 in read ()
#2  0x000000001540eae0 in snttread ()
#3  0x0000000006f7ffe2 in nttrd ()
#4  0x0000000006e6c8d7 in nsprecv ()
#5  0x0000000006e738f0 in nsrdr ()
#6  0x00000000144173ec in nsfull_pkt_rcv ()

两个进程都在等待TCP套接字上的read

SQL*Net Trace

(4182797376) [17-SEP-2023 15:49:38:923] snsbitts_ts: normal exit
(4182797376) [17-SEP-2023 15:49:38:923] snsbitcl_ts: entry
(4182797376) [17-SEP-2023 15:49:38:923] snsbitcl_ts: normal exit
(4182797376) [17-SEP-2023 15:49:38:923] nsfull_pkt_rcv: switching to application buffer
(4182797376) [17-SEP-2023 15:49:38:923] nsrdr: entry
(4182797376) [17-SEP-2023 15:49:38:923] nsrdr: recving a packet
(4182797376) [17-SEP-2023 15:49:38:923] nsprecv: entry
(4182797376) [17-SEP-2023 15:49:38:923] nsprecv: reading from transport...
(4182797376) [17-SEP-2023 15:49:38:923] nttrd: entry

正如我们所看到的,客户端发送了数据,然后开始从 TCP 套接字读取数据。同时,服务器没有收到任何消息。SQL*Net 跟踪确认了网络层中的中断。

TCP Dump
怀疑 TCP 存在问题,尝试使用 netcat 重现该问题,并观察与 tcpdump 的通信。
# db server

$yum install nc
$yum install tcpdump

root@19c1:/root $nc -vl 50000
Ncat: Version 7.50 ( https://nmap.org/ncat )
Ncat: Listening on :::50000
Ncat: Listening on 0.0.0.0:50000
Ncat: Connection from 172.20.22.134.
Ncat: Connection from 172.20.22.134:64792.
hello1
hello2

# db client

root@19c1:/root $nc 19c1 50000
hello1
hello2
hello3

可以分别在客户端和服务器上的并发会话中运行 tcpdump,以观察两台计算机上的 TCP 数据包流

tcpdump -nnnvv -i any host servername

# 观察arp表
arp -a

有一则案例是从tcpdump 发现了一新的IP, 实际是db server的另一个网卡的Ip, (x.x.221.18 是客户端;x.x.225.51 是数据库服务器。

15:21:13.930354 ARP, Ethernet (len 6), IPv4 (len 4), Request who-has x.x.221.18 tell x.x.221.119, length 42
15:21:13.930369 ARP, Ethernet (len 6), IPv4 (len 4), Reply x.x.221.18 is-at z:z:z:z:z:z, length 28

由于此通信中涉及的所有三个 IP 地址都属于同一子网,在DB server产生了错误的 ARP 表条目,导致传输异常。

总结
以下症状可能表示 TCP 数据包未到达其目标:
1.应用程序正在执行查询,但会话正在等待来自客户端的 SQL*Net 消息,并且是inactive状态
2.应用程序和数据库服务器进程都从 TCP 套接字读取数据。
3.SQL*Net 跟踪显示数据已发送,但服务器端缺少相应的 SQL*Net 跟踪条目。

您可以使用 netcat 重现该问题,并使用 tcpdump 捕获流量,以查看 TCP 数据包是否未到达并进一步调查。

 

References:
https://nenadnoveljic.com/blog/troubleshooting-a-networking-issue-from-the-database-perspective/

打赏

对不起,这篇文章暂时关闭评论。