[20180123]測試SQLNET.EXPIRE_TIME引數2

[20180123]測試SQLNET.EXPIRE_TIME引數2.txt

--//曾經寫過一篇linux核心網路引數測試tcp_keepalive,連結http://blog.itpub.net/267265/viewspace-2138391/
--//測試服務端會定時發起連線監測與client的連線狀態.

引數解析:
/proc/sys/net/ipv4/tcp_keepalive_time    當keepalive起用的時候，TCP傳送keepalive訊息的頻度。預設是2小時。
/proc/sys/net/ipv4/tcp_keepalive_intvl   當探測沒有確認時，keepalive探測包的傳送間隔。預設是75秒。
/proc/sys/net/ipv4/tcp_keepalive_probes  如果對方不予應答，keepalive探測包的傳送次數。預設值是9。

--//我發現我遺漏的一種情況的測試,使用SQLNET.EXPIRE_TIME引數,這個引數與前面的核心引數意思差不多.定時監測服務端與客戶端連
--//接情況.但是注意這種測試是有服務端發起,一些狀態防火牆不允許這樣的包透過,我們的分院與總院正好有這樣的環境,不知道是否網管
--//配置錯誤,正好利用這個環境測試看看.主要目的測試設定SQLNET.EXPIRE_TIME情況下,如果無法連上client,是否探測多次,間隔時間是多少.
--//知道這些數值對於理解我遇到的一個問題幫助很大,另發文寫一篇blog.

1.環境:
--//服務端IP:192.168.100.106
--//客戶端IP:192.168.90.14
--//服務端:
# echo /proc/sys/net/ipv4/tcp_keepalive* | xargs   -n 1  strings -1 -f
/proc/sys/net/ipv4/tcp_keepalive_intvl: 75
/proc/sys/net/ipv4/tcp_keepalive_probes: 9
/proc/sys/net/ipv4/tcp_keepalive_time: 7200

--//客戶端
# echo /proc/sys/net/ipv4/tcp_keepalive* | xargs   -n 1  strings -1 -f
/proc/sys/net/ipv4/tcp_keepalive_intvl: 10
/proc/sys/net/ipv4/tcp_keepalive_probes: 4
/proc/sys/net/ipv4/tcp_keepalive_time: 200

--//在sqlnet.ora檔案中配置
sqlnet.expire_time = 5

--//更正說明:實際上這個引數要修改oracle使用者的$ORACLE_HOME/network/admin/sqlnet.ora,而裡面的定義如下:
$  cat $ORACLE_HOME/network/admin/sqlnet.ora
SQLNET.EXPIRE_TIME=10

--//這樣結果基本一致.加上我當時執行一些命令檢視埠號,消耗一點時間.注意為什麼不是讀取grid使用者的
--//$ORACLE_HOME/network/admin/sqlnet.ora檔案的SQLNET.EXPIRE_TIME = 5引數,另外寫blog探究.

--//我前面測試服務端發起測試連線,開始間隔0.20秒,以後間隔2倍遞增.到110秒後,按照120秒間隔,測試16次.
--//以下測試模擬如果服務端發起測試連線時,如果這時客戶端執行sql語句會出現什麼情況呢?

2.測試:
--//客戶端使用sqlplus連線資料庫:
xxxxx>
SELECT s.sid, s.serial#, s.process, s.server, p.spid, p.pid, p.serial# p_serial#,'alter system kill session
       '''||s.sid||','||s.serial#||''''||' immediate;' c50
  FROM v$session s, v$process p
WHERE s.sid in (
        SELECT sid
          FROM v$mystat
WHERE rownum  = 1)
   AND s.paddr = p.addr;

       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
      3545      28775 5617                     DEDICATED 53003     1403        133 alter system kill session '3545,28775' immediate;
--//確定服務端程式號=53003

--//服務端:
# lsof -i -P -n | grep "53003 oracle"
oracle     53003 oracle    8u  IPv4 3838743032      0t0  UDP 127.0.0.1:32082
oracle     53003 oracle   18u  IPv4 3838743021      0t0  TCP 192.168.100.106:1521->192.168.90.14:46051 (ESTABLISHED)

--//確定client的埠號46051.

--//在服務端執行:
# tcpdump -i bondeth0 host 192.168.90.14 and port 46051 -nn -vv
tcpdump: listening on bondeth0, link-type EN10MB (Ethernet), capture size 96 bytes

--//客戶端開啟監測:(注意網路介面不要選擇錯誤!!我測試環境是是bond1):
# tcpdump -i bond1 host 192.168.90.14 and port 46051 -nn -vv
tcpdump: listening on bond1, link-type EN10MB (Ethernet), capture size 65535 bytes
...

--//客戶端執行一些sql語句以後:
xxxxx> select sysdate from dual ;
SYSDATE
-------------------
2018-01-23 16:04:52

--//服務端開啟監測:
# tcpdump -i bondeth0 host 192.168.90.14 and port 46051 -nn -vv
tcpdump: listening on bondeth0, link-type EN10MB (Ethernet), capture size 96 bytes
16:04:52.726861 IP (tos 0x0, ttl  61, id 22784, offset 0, flags [DF], proto: TCP (6), length: 346) 192.168.90.14.46051 > 192.168.100.106.1521: P 1857268049:1857268355(306) ack 1586784823 win 405
16:04:52.727189 IP (tos 0x0, ttl  64, id 61007, offset 0, flags [DF], proto: TCP (6), length: 418) 192.168.100.106.1521 > 192.168.90.14.46051: P 1:379(378) ack 306 win 330
16:04:52.727949 IP (tos 0x0, ttl  61, id 22785, offset 0, flags [DF], proto: TCP (6), length: 40) 192.168.90.14.46051 > 192.168.100.106.1521: ., cksum 0xd112 (correct), 306:306(0) ack 379 win 423
16:04:52.729120 IP (tos 0x0, ttl  61, id 22786, offset 0, flags [DF], proto: TCP (6), length: 61) 192.168.90.14.46051 > 192.168.100.106.1521: P, cksum 0xa810 (correct), 306:327(21) ack 379 win 423
16:04:52.729193 IP (tos 0x0, ttl  64, id 61008, offset 0, flags [DF], proto: TCP (6), length: 212) 192.168.100.106.1521 > 192.168.90.14.46051: P 379:551(172) ack 327 win 330
16:04:52.769464 IP (tos 0x0, ttl  61, id 22787, offset 0, flags [DF], proto: TCP (6), length: 40) 192.168.90.14.46051 > 192.168.100.106.1521: ., cksum 0xd03f (correct), 327:327(0) ack 551 win 441
---//等待看看:
--//因為閘道器配置成狀態防火牆的形式,從服務端發起的連線都會被拒接..等看看.
--//已經過了200秒,說明client的核心引數tcp_keepalive_*對於連線的服務端無用.也就是client不會主動發起連線測試.
16:21:29.804778 IP (tos 0x0, ttl  64, id 61009, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:21:30.021390 IP (tos 0x0, ttl  64, id 61010, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:21:30.456415 IP (tos 0x0, ttl  64, id 61011, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:21:31.326401 IP (tos 0x0, ttl  64, id 61012, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:21:33.064398 IP (tos 0x0, ttl  64, id 61013, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:21:36.544396 IP (tos 0x0, ttl  64, id 61014, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:21:43.512397 IP (tos 0x0, ttl  64, id 61015, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:21:57.432393 IP (tos 0x0, ttl  64, id 61016, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
--//這時在client端執行:
XXXX> select sysdate a from dual ;
--//一樣掛起.
16:23:20.952395 IP (tos 0x0, ttl  64, id 61018, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:25:12.440389 IP (tos 0x0, ttl  64, id 61019, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:27:12.760421 IP (tos 0x0, ttl  64, id 61020, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:29:13.080394 IP (tos 0x0, ttl  64, id 61021, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:31:13.400398 IP (tos 0x0, ttl  64, id 61022, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:33:13.720395 IP (tos 0x0, ttl  64, id 61023, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330
16:35:14.040393 IP (tos 0x0, ttl  64, id 61024, offset 0, flags [DF], proto: TCP (6), length: 50) 192.168.100.106.1521 > 192.168.90.14.46051: P, cksum 0x3fee (incorrect (-> 0xca82), 551:561(10) ack 327 win 330

--//在出現以上資料包過程中,在服務端執行如下:
--//伺服器:
# netstat -otun | egrep 'Active|Proto|192.168.90.14:46051'
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address               Foreign Address             State       Timer
tcp        0     10 192.168.100.106:1521        192.168.90.14:46051         ESTABLISHED on (38.44/8/0)
--//這裡有執行sql語句.
# netstat -otun | egrep 'Active|Proto|192.168.90.14:46051'
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address               Foreign Address             State       Timer
tcp        0    308 192.168.90.14:46051         192.168.100.106:1521        ESTABLISHED on (22.87/8/0)

# netstat -otun | egrep 'Active|Proto|192.168.90.14:46051'
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address               Foreign Address             State       Timer
tcp        0     20 192.168.100.106:1521        192.168.90.14:46051         ESTABLISHED on (54.49/14/0)

# netstat -otun | egrep 'Active|Proto|192.168.90.14:46051'
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address               Foreign Address             State       Timer

--//說明關於netstat -o 引數的解析參考連線:http://blog.itpub.net/267265/viewspace-2138396/
--//The interpretation of field is, first field = timer countdown value, second field = no. of retransmissions,
--//third field = number of keepalive probes sent.
--//可以發現前面的第1欄位逐漸減少,而第2欄位增加後,第1欄位重新記錄.

--//客戶端:
# netstat -otun | egrep 'Active|Proto|192.168.90.14:46051'
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address               Foreign Address             State       Timer
tcp        0    308 192.168.90.14:46051         192.168.100.106:1521        ESTABLISHED on (47.36/10/0)

# netstat -otun | egrep 'Active|Proto|192.168.90.14:46051'
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address               Foreign Address             State       Timer
tcp        0    308 192.168.90.14:46051         192.168.100.106:1521        ESTABLISHED on (36.55/13/0)

# netstat -otun | egrep 'Active|Proto|192.168.90.14:46051'
Active Internet connections (w/o servers)
Proto Recv-Q Send-Q Local Address               Foreign Address             State       Timer

--//這時客戶端也在做相同的測試.這時客戶端報如下錯誤:
*
ERROR at line 1:
ORA-03113: end-of-file on communication channel
Process ID: 53003
Session ID: 3545 Serial number: 28775

--//客戶端,在客戶端監測:
# tcpdump -i bond1 host 192.168.90.14 and port 46051 -nn -vv
tcpdump: listening on bond1, link-type EN10MB (Ethernet), capture size 65535 bytes
...
16:04:52.726417 IP (tos 0x0, ttl 64, id 22784, offset 0, flags [DF], proto TCP (6), length 346) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4116 (incorrect -> 0x3643), seq 327:633, ack 551, win 405, length 306
16:04:52.728591 IP (tos 0x0, ttl 61, id 61007, offset 0, flags [DF], proto TCP (6), length 418) 192.168.100.106.1521 > 192.168.90.14.46051: Flags [P.], cksum 0x60ae (correct), seq 551:929, ack 633, win 330, length 378
16:04:52.728623 IP (tos 0x0, ttl 64, id 22785, offset 0, flags [DF], proto TCP (6), length 40) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [.], cksum 0xd112 (correct), seq 633, ack 929, win 423, length 0
16:04:52.728800 IP (tos 0x0, ttl 64, id 22786, offset 0, flags [DF], proto TCP (6), length 61) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x3ff9 (incorrect -> 0xa810), seq 633:654, ack 929, win 423, length 21
16:04:52.730494 IP (tos 0x0, ttl 61, id 61008, offset 0, flags [DF], proto TCP (6), length 212) 192.168.100.106.1521 > 192.168.90.14.46051: Flags [P.], cksum 0x1558 (correct), seq 929:1101, ack 654, win 330, length 172
16:04:52.770133 IP (tos 0x0, ttl 64, id 22787, offset 0, flags [DF], proto TCP (6), length 40) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [.], cksum 0xd03f (correct), seq 654, ack 1101, win 441, length 0

--//這時在client端執行:
XXXX> select sysdate a from dual ;
--//一樣掛起.
16:23:07.348516 IP (tos 0x0, ttl 64, id 22788, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:23:07.551178 IP (tos 0x0, ttl 64, id 22789, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:23:07.957168 IP (tos 0x0, ttl 64, id 22790, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:23:08.769142 IP (tos 0x0, ttl 64, id 22791, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:23:10.393167 IP (tos 0x0, ttl 64, id 22792, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:23:13.641396 IP (tos 0x0, ttl 64, id 22793, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:23:20.137163 IP (tos 0x0, ttl 64, id 22794, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:23:33.129182 IP (tos 0x0, ttl 64, id 22795, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:23:59.113166 IP (tos 0x0, ttl 64, id 22796, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:24:51.081162 IP (tos 0x0, ttl 64, id 22797, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:26:35.017169 IP (tos 0x0, ttl 64, id 22798, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:28:35.017411 IP (tos 0x0, ttl 64, id 22799, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:30:35.017170 IP (tos 0x0, ttl 64, id 22800, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:32:35.017141 IP (tos 0x0, ttl 64, id 22801, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:34:35.017167 IP (tos 0x0, ttl 64, id 22802, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308
16:36:35.017165 IP (tos 0x0, ttl 64, id 22803, offset 0, flags [DF], proto TCP (6), length 348) 192.168.90.14.46051 > 192.168.100.106.1521: Flags [P.], cksum 0x4118 (incorrect -> 0xca89), seq 654:962, ack 1101, win 441, length 308

3.分析時間變化:
16:04:52.769464
16:21:29.804778
--//間隔17*60+29-52 = 997秒,為什麼不是SQLNET.EXPIRE_TIME*2分鐘=5*2*60 = 600秒呢?(我的伺服器是rac環境,不知道跟這個有關嗎)
--//時間變化不在計算,跟前面測試一樣.
--//開始間隔0.21秒,以後間隔2倍遞增.到110秒後,按照120秒間隔.另外一組資料測試如下,結果驚人的相似.
--//換一句話講如果伺服器發出測試連線如果不通,連線已經斷開.只不過要經歷這個過程回收網路連線以及資源.

--//換一句話講如果真要使用狀態防火牆不能使用SQLNET.EXPIRE_TIME引數,而且你設定太短問題可能更加嚴重.使用者體驗經常當機的感覺.

--//補充說明:
--//我少算了最後1次120秒,這樣實際上大約809+120 = 929秒才會退出.