ITPub博客

首页 > 数据库 > Oracle > [20210115]sqlnet.ora设置sqlnet.expire_time断开时oracle如何探测.txt

[20210115]sqlnet.ora设置sqlnet.expire_time断开时oracle如何探测.txt

原创 Oracle 作者:lfree 时间:2021-01-15 16:31:26 0 删除 编辑

[20210115]sqlnet.ora设置sqlnet.expire_time断开时oracle如何探测.txt

--//测试sqlnet.ora设置sqlnet.expire_time断开时oracle如何探测的,这个测试我以前做过,链接找不到了,重新测试加强记忆.

1.环境:
SYS@192.168.31.8:1521/hrp430> @ ver1

PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx            11.2.0.3.0     Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production

--//今天上午发现设置sqlnet.expire_time=1也不行.正好测试看看.
$ grep sqlnet.expire_time $ORACLE_HOME/network/admin/sqlnet.ora
sqlnet.expire_time=1

2.测试:
--//服务端执行:
# seq 100000 | xargs -IQ bash -c "netstat -tonp | grep 192.168.100.78:|ts.awk;sleep 0.999999" | tee aa.txt
--//注:我sleep 0.999999可能避免一些命令执行时的误差.看了以前测试我以前这里使用tcpdump来跟踪的.

--//客户端执行:
$ rlsql sys/XXXX@192.168.31.8:1521/hrp430 as sysdba
SQL*Plus: Release 11.2.0.4.0 Production on Fri Jan 15 10:10:18 2021
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

--//注登录后不要再执行任何命令,另外最好使用NTP保证客户端端与服务器时间同步,这样好诊断问题.
--//剩下就是等待问题出现.如果你想模拟有不想等2*sqlnet.expire_time时间,注我这里设置很短,许多用户无法模拟这个问题的.
--//可以拔掉客户端网线或者使用iptables阻塞连接(小心不要设置错误!!),并且服务端最好在tmux或者screen下操作,这样服务端的连接不会断开.

3.中间查看情况:
# seq 100000 | xargs -IQ bash -c "netstat -tonp | grep 192.168.100.78:|ts.awk;sleep 0.999999" | tee aa.txt
[2021-01-15 10:10:19] tcp        0      0 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  off (0.00/0/0)
[2021-01-15 10:10:20] tcp        0      0 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  off (0.00/0/0)
...
[2021-01-15 10:12:17] tcp        0      0 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  off (0.00/0/0)
[2021-01-15 10:12:18] tcp        0     10 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (0.12/0/0)
~~~~~~~~~~~~~~~~~~~~~
[2021-01-15 10:12:19] tcp        0     10 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (0.24/2/0)

--//注意看下划线内容,登录10:10:18,10:12:18断开正好2分钟.
--//后面的状态从off变成on.

4.分析:
--//出现on后大约等925秒(15分钟),连接就会断开.这个时候你可以出去聊天干别的事情.
# seq 100000 | xargs -IQ bash -c "netstat -tonp | grep 192.168.100.78:|ts.awk;sleep 0.999999" | tee aa.txt
[2021-01-15 10:27:45] tcp        0    160 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (5.03/15/0)
[2021-01-15 10:27:46] tcp        0    160 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (3.90/15/0)
[2021-01-15 10:27:47] tcp        0    160 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (2.77/15/0)
[2021-01-15 10:27:48] tcp        0    160 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (1.65/15/0)
[2021-01-15 10:27:49] tcp        0    160 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (0.52/15/0)

--//(27-12)*60+49-18 = 931 断开.分析aa.txt文件.

# awk '{print $10}' aa.txt  | grep off|wc
    105     105     420
--//105行,看来sleep 要设置0.99才行.正确占120秒.

# grep off aa.txt  | head -1 ; grep off aa.txt | tail -1
[2021-01-15 10:10:19] tcp        0      0 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  off (0.00/0/0)
[2021-01-15 10:12:17] tcp        0      0 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  off (0.00/0/0)

# grep on aa.txt  | head -1 ; grep on aa.txt | tail -1
[2021-01-15 10:12:18] tcp        0     10 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (0.12/0/0)
[2021-01-15 10:27:49] tcp        0    160 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (0.52/15/0)
--//(27-12)*60+49-18 = 931 断开.分析aa.txt文件.

# awk '{print $10}' aa.txt  | grep on|wc
    822     822    2466

# awk '{if ($10=="on") print $11}' aa.txt  | cut -d'/' -f2| uniq -c
      1 0
      1 2
      1 3
      3 4
      6 5
     12 6
     23 7
     47 8
     93 9
    106 10
    105 11
    106 12
    106 13
    106 14
    106 15
-//实际上最后几次探测120秒.

# awk '{if ($10=="on") print $11}' aa.txt  | cut -d'/' -f1,2 --output-delimiter=' ' | sed 's/^(//' >| aaa.txt

# grep on aa.txt | head -4
[2021-01-15 10:12:18] tcp        0     10 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (0.12/0/0)
[2021-01-15 10:12:19] tcp        0     10 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (0.24/2/0)
[2021-01-15 10:12:20] tcp        0     10 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (0.76/3/0)
[2021-01-15 10:12:21] tcp        0     10 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:7763  ESTABLISHED 27737/oraclehrp430  on (2.94/4/0)
--//前面3次探测时间很短.不到1秒.前面从0-3的占2秒时间,注意探测从0开始到15,也就是探测16次.

# seq 4 15 | xargs -IQ bash -c "grep ' Q' aaa.txt|head -1" | awk '{print $2 " " $1}'
4 2.94
5 6.16
6 12.59
7 25.45
8 52.26
9 104.95
10 119.15
11 118.86
12 119.80
13 119.71
14 119.44
15 119.38

# seq 4 15 | xargs -IQ bash -c "grep ' Q' aaa.txt|head -1" | awk '{print $2 " " int($1+1)}'
4 3
5 7
6 13
7 26
8 53
9 105
10 120
11 119  --> 下面计算选择120
12 120
13 120
14 120
15 120
--//3+7+13+26+53+105+120+120+120+120+120+120+2 = 929秒
--//还是换成tcpdump跟踪.重复测试:
# seq 100000 | xargs -IQ bash -c "netstat -tonp | grep 192.168.100.78:|ts.awk;sleep 0.99" | tee bb.txt
# tcpdump -i eth0 host 192.168.100.78 -nn -vv -w tcp.out

# tcpdump -r tcp.out
reading from file tcp.out, link-type EN10MB (Ethernet)
10:44:47.592896 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: S 2215388911:2215388911(0) win 14600 <mss 1440,sackOK,timestamp 3524648198 0,nop,wscale 7>
10:44:47.592903 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: S 581299505:581299505(0) ack 2215388912 win 5792 <mss 1460,sackOK,timestamp 2839961348 3524648198,nop,wscale 7>
10:44:47.593258 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: . ack 1 win 115 <nop,nop,timestamp 3524648199 2839961348>
10:44:47.593636 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: P 1:214(213) ack 1 win 115 <nop,nop,timestamp 3524648199 2839961348>
10:44:47.593646 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: . ack 214 win 54 <nop,nop,timestamp 2839961349 3524648199>
10:44:47.613375 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 1:9(8) ack 214 win 54 <nop,nop,timestamp 2839961368 3524648199>
10:44:47.613863 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: . ack 9 win 115 <nop,nop,timestamp 3524648220 2839961368>
10:44:47.613908 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: P 214:427(213) ack 9 win 115 <nop,nop,timestamp 3524648220 2839961368>
10:44:47.613971 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 9:41(32) ack 427 win 62 <nop,nop,timestamp 2839961369 3524648220>
10:44:47.615235 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: P 427:588(161) ack 41 win 115 <nop,nop,timestamp 3524648221 2839961369>
10:44:47.615382 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 41:168(127) ack 588 win 71 <nop,nop,timestamp 2839961370 3524648221>
10:44:47.616461 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: P 588:626(38) ack 168 win 115 <nop,nop,timestamp 3524648222 2839961370>
10:44:47.616576 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 168:386(218) ack 626 win 71 <nop,nop,timestamp 2839961372 3524648222>
10:44:47.617609 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: P 626:707(81) ack 386 win 123 <nop,nop,timestamp 3524648223 2839961372>
10:44:47.618946 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 386:412(26) ack 707 win 71 <nop,nop,timestamp 2839961374 3524648223>
10:44:47.620616 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: P 707:951(244) ack 412 win 123 <nop,nop,timestamp 3524648226 2839961374>
10:44:47.623234 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 412:802(390) ack 951 win 79 <nop,nop,timestamp 2839961378 3524648226>
10:44:47.624811 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: P 951:2337(1386) ack 802 win 131 <nop,nop,timestamp 3524648230 2839961378>
10:44:47.629411 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 802:1936(1134) ack 2337 win 101 <nop,nop,timestamp 2839961384 3524648230>
10:44:47.630500 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: P 2337:2397(60) ack 1936 win 149 <nop,nop,timestamp 3524648236 2839961384>
10:44:47.630587 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 1936:2115(179) ack 2397 win 101 <nop,nop,timestamp 2839961386 3524648236>
10:44:47.631110 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: P 2397:2410(13) ack 2115 win 167 <nop,nop,timestamp 3524648237 2839961386>
10:44:47.631195 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2115:2132(17) ack 2410 win 101 <nop,nop,timestamp 2839961386 3524648237>
10:44:47.631588 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: P 2410:2423(13) ack 2132 win 167 <nop,nop,timestamp 3524648237 2839961386>
10:44:47.631642 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2132:2149(17) ack 2423 win 101 <nop,nop,timestamp 2839961387 3524648237>
10:44:47.671774 IP 192.168.100.78.8592 > kkkkkzzz.ncube-lm: . ack 2149 win 167 <nop,nop,timestamp 3524648278 2839961387>
10:46:47.626867 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840081382 3524648278>
--//10:44:47.671774 10:46:47.626867 间隔2分钟
10:46:47.832843 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840081588 3524648278>
10:46:48.244848 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840082000 3524648278>
10:46:49.068849 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840082824 3524648278>
10:46:50.716874 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840084472 3524648278>
10:46:54.012923 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840087768 3524648278>
10:47:00.605007 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840094360 3524648278>
10:47:13.789169 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840107544 3524648278>
10:47:40.156509 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840133912 3524648278>
10:48:32.893179 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840186648 3524648278>
10:50:18.364513 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840292120 3524648278>
10:52:18.365036 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840412120 3524648278>
10:54:18.364560 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840532120 3524648278>
10:56:18.365089 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840652120 3524648278>
10:58:18.364609 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840772120 3524648278>
11:00:18.348079 IP kkkkkzzz.ncube-lm > 192.168.100.78.8592: P 2149:2159(10) ack 2423 win 101 <nop,nop,timestamp 2840892120 3524648278>
--//探测16次.

--//截取前面时间,手工计算如下:
10:46:47.626867
10:46:47.832843   0.832843-0.626867   = .205976
10:46:48.244848   8.244848-7.832843   = .412005
10:46:49.068849   9.068849-8.244848   = .824001
10:46:50.716874   50.716874-49.068849 = 1.648025
10:46:54.012923   54.012923-50.716874 = 3.296049
10:47:00.605007   60.605007-54.012923 = 6.592084
10:47:13.789169   13.789169-00.605007 = 13.184162
10:47:40.156509   40.156509-13.789169 = 26.36734
10:48:32.893179   92.893179-40.156509 = 52.73667
10:50:18.364513   120+18.364513-32.893179 = 105.471334
10:52:18.365036   18.365036-18.364513+120 = 120.000523
10:54:18.364560   18.364560-18.365036+120 = 119.999524
10:56:18.365089   18.365089-18.364560+120 = 120.000529
10:58:18.364609   18.364609-18.365089+120 = 119.99952
11:00:18.348079   18.348079-18.364609+120 = 119.98347

--//在2021-01-15 11:02:17结束.
# tail -1 bb.txt
[2021-01-15 11:02:17] tcp        0    160 ::ffff:192.168.31.8:1521    ::ffff:192.168.100.78:8592  ESTABLISHED 3520/oraclehrp430   on (0.59/15/0)

--//我单独截取时间使用bash shell计算看看.

# cat aa1.txt
10:46:47.626867
10:46:47.832843
10:46:48.244848
10:46:49.068849
10:46:50.716874
10:46:54.012923
10:47:00.605007
10:47:13.789169
10:47:40.156509
10:48:32.893179
10:50:18.364513
10:52:18.365036
10:54:18.364560
10:56:18.365089
10:58:18.364609
11:00:18.348079

# cat aa1.txt | xargs -I{} date -d "2021/01/15 {}" "+%s.%N" | awk 'NR==1{a=$1} NR>1{print $1-a;a=$1}'
0.205976
0.412005
0.824001
1.64802
3.29605
6.59208
13.1842
26.3673
52.7367
105.471
120.001
120
120.001
120
119.983
-//开始间隔0.21秒,以后间隔2倍递增.到105秒后,按照120秒间隔(探测6次).

# cat aa1.txt | xargs -I{} date -d "2021/01/15 {}" "+%s.%N" | awk 'NR==1{a=$1} NR>1{print $1-a;a=$1}' | paste -sd"+" | bc -l
810.722332
--//补上最后120秒,810.722332+120 = 930.722332.

5.总结:
--//我个人并主张采用sqlnet.ora设置sqlnet.expire_time方式,12c以上除外.因为12c设置sqlnet.expire_time,采用的是
--//TCP KEEPALIVE套接字选项来检查连接是否仍然可用。

--//我以前就遇到dblink连接断开,SQL*Net message from dblink 出现awr报表的情况.
--//链接 http://blog.itpub.net/267265/viewspace-2150510/ =>0124奇怪的SQL*Net message from dblink
--//我当时的理解确实存在许多错误.

--//找到以前测试的链接:
http://blog.itpub.net/267265/viewspace-2150431/ -> [20180123]测试SQLNET.EXPIRE_TIME参数.txt


来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/267265/viewspace-2750356/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
熟悉oracle相关技术,擅长sql优化,rman备份与恢复,熟悉linux shell编程。

注册时间:2008-01-03

  • 博文量
    2855
  • 访问量
    6643915