0126奇怪的SQLNet message from dblink模擬

[20180126]奇怪的SQLNet message from dblink(模擬).txt

--//連結:http://blog.itpub.net/267265/viewspace-2150510/,但是是由於狀態防火牆問題,導致連結斷開,再次使用鏈路時報
--//'SQL*Net message from dblink'錯誤.

--//我前面測試設定SQLNET.EXPIRE_TIME引數,網路監測出現問題時重試以及發探測包間隔的情況.
--//這次使用核心引數tcp_keepalive的情況:

1.環境:
SCOTT@book> @ &r/ver1
PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx            11.2.0.4.0     Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production

--//註解SQLNET.EXPIRE_TIME引數.設定核心引數如下:

# 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: 60

--//建立dblink:
SCOTT@book> CREATE  PUBLIC DATABASE LINK LOOPBACK CONNECT TO SCOTT IDENTIFIED BY book USING 'localhost:1521/book:DEDICATED';
Database link created.
--//後面不上DEDICATED,避免使用共享模式.測試
SCOTT@book> select sysdate from dual@loopback ;
SYSDATE
-------------------
2018-01-26 11:50:10
--//測試ok,退出.

2.測試前準備:
# netstat -tunlp | grep 127.0.0.1
tcp        0      0 127.0.0.1:1521              0.0.0.0:*                   LISTEN      24802/tnslsnr
tcp        0      0 127.0.0.1:631               0.0.0.0:*                   LISTEN      29590/cupsd

# lsof -i -P -n | grep 127.0.0.1:
oracle    14308  oracle   11u  IPv4 41475691      0t0  TCP 127.0.0.1:7801->127.0.0.1:1521 (ESTABLISHED)
tnslsnr   24802  oracle    7u  IPv4 41438030      0t0  TCP 127.0.0.1:1521 (LISTEN)
tnslsnr   24802  oracle   14u  IPv4 41481937      0t0  TCP 127.0.0.1:1521->127.0.0.1:7801 (ESTABLISHED)
cupsd     29590    root    4u  IPv4 23111711      0t0  TCP 127.0.0.1:631 (LISTEN)

--//這樣使用tcpdump要過濾631,7801埠.

# tcpdump -i lo tcp and host 127.0.0.1 and not port 6150 and not port 631 and not port 7801 and -nn -ttt
tcpdump: listening on lo, link-type EN10MB (Ethernet), capture size 96 bytes

--//遠端登入資料庫:
R:\fyhis>sqlplus scott/book@78
SQL*Plus: Release 12.1.0.1.0 Production on Fri Jan 26 11:52:17 2018
Copyright (c) 1982, 2013, 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

# tcpdump -i lo tcp and host 127.0.0.1 and not port 6150 and not port 631 and not port 7801 -nn -vvv
tcpdump: listening on lo, link-type EN10MB (Ethernet), capture size 96 bytes

--//執行sql語句:
SCOTT@78> select sysdate from dual@loopback ;
SYSDATE
-------------------
2018-01-26 11:53:54
---
11:53:54.803792 IP (tos 0x0, ttl  64, id 40513, offset 0, flags [DF], proto: TCP (6), length: 370) 127.0.0.1.9444 > 127.0.0.1.1521: P 3589150680:3589150998(318) ack 2600078046 win 385
11:53:54.804158 IP (tos 0x0, ttl  64, id 27704, offset 0, flags [DF], proto: TCP (6), length: 369) 127.0.0.1.1521 > 127.0.0.1.9444: P 1:318(317) ack 318 win 385
11:53:54.804247 IP (tos 0x0, ttl  64, id 40514, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.9444 > 127.0.0.1.1521: ., cksum 0xfe28 (incorrect (-> 0x7ecc), 318:318(0) ack 318 win 385
11:53:54.804401 IP (tos 0x0, ttl  64, id 40515, offset 0, flags [DF], proto: TCP (6), length: 194) 127.0.0.1.9444 > 127.0.0.1.1521: P 318:460(142) ack 318 win 385
11:53:54.804508 IP (tos 0x0, ttl  64, id 27705, offset 0, flags [DF], proto: TCP (6), length: 83) 127.0.0.1.1521 > 127.0.0.1.9444: P 318:349(31) ack 460 win 385
11:53:54.804881 IP (tos 0x0, ttl  64, id 40516, offset 0, flags [DF], proto: TCP (6), length: 365) 127.0.0.1.9444 > 127.0.0.1.1521: P 460:773(313) ack 349 win 385
11:53:54.805248 IP (tos 0x0, ttl  64, id 27706, offset 0, flags [DF], proto: TCP (6), length: 432) 127.0.0.1.1521 > 127.0.0.1.9444: P 349:729(380) ack 773 win 385
11:53:54.807364 IP (tos 0x0, ttl  64, id 40517, offset 0, flags [DF], proto: TCP (6), length: 73) 127.0.0.1.9444 > 127.0.0.1.1521: P, cksum 0xfe3d (incorrect (-> 0x5f64), 773:794(21) ack 729 win 385
11:53:54.807563 IP (tos 0x0, ttl  64, id 27707, offset 0, flags [DF], proto: TCP (6), length: 224) 127.0.0.1.1521 > 127.0.0.1.9444: P 729:901(172) ack 794 win 385
11:53:54.846786 IP (tos 0x0, ttl  64, id 40518, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.9444 > 127.0.0.1.1521: ., cksum 0xfe28 (incorrect (-> 0x7a7b), 794:794(0) ack 901 win 385
...//等...不執行任何有關dblink操作.
11:55:55.000981 IP (tos 0x0, ttl  64, id 27709, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.1521 > 127.0.0.1.9444: ., cksum 0xfe28 (incorrect (-> 0xba1d), 900:900(0) ack 794 win 385
11:55:55.001004 IP (tos 0x0, ttl  64, id 40520, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.9444 > 127.0.0.1.1521: ., cksum 0xfe28 (incorrect (-> 0xa51f), 794:794(0) ack 901 win 385
11:56:55.161017 IP (tos 0x0, ttl  64, id 27710, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.1521 > 127.0.0.1.9444: ., cksum 0xfe28 (incorrect (-> 0xe49b), 900:900(0) ack 794 win 385
11:56:55.161042 IP (tos 0x0, ttl  64, id 40521, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.9444 > 127.0.0.1.1521: ., cksum 0xfe28 (incorrect (-> 0xba1e), 794:794(0) ack 901 win 385

--//可以發現間隔1分鐘.如何實現網路埠呢? 我想到幾種方法,
1.kill 有關連結程式.
2.kill -19  SIGSTOP 有關連結程式.
3.使用iptables防火牆,阻塞包的傳送.
--//理論講使用第3個方法更加保險.

# lsof -i -n -P | grep 127.0.0.1.9444
oracle    26397  oracle    7u  IPv4 41479570      0t0  TCP 127.0.0.1:9444->127.0.0.1:1521 (ESTABLISHED)
oracle    26400  oracle   15u  IPv4 41377471      0t0  TCP 127.0.0.1:1521->127.0.0.1:9444 (ESTABLISHED)

# ps -ef | egrep "2639[7]|2640[0]"
oracle   26397     1  0 11:52 ?        00:00:00 oraclebook (LOCAL=NO)
oracle   26400     1  0 11:52 ?        00:00:00 oraclebook (LOCAL=NO)

--//服務端程式是26400,客戶端程式是26397.在客戶端執行如下也可以確定:
SCOTT@78> @ &r/spid
       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
       274         45 8452:8216                DEDICATED 26397       21         20 alter system kill session '274,45' immediate;

# iptables -A INPUT -p tcp -s 127.0.0.1 -d 127.0.0.1 --dport 9444 -i lo -j DROP

# tcpdump -i lo tcp and host 127.0.0.1 and not port 6150 and not port 631 and not port 7801 -nn -vvv
...
12:08:57.081298 IP (tos 0x0, ttl  64, id 27722, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.1521 > 127.0.0.1.9444: ., cksum 0xfe28 (incorrect (-> 0xdc85), 900:900(0) ack 794 win 385
12:08:57.081361 IP (tos 0x0, ttl  64, id 40533, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.9444 > 127.0.0.1.1521: ., cksum 0xfe28 (incorrect (-> 0xb613), 794:794(0) ack 901 win 385
--//這裡啟動防火牆
SCOTT@78> SELECT count(*) FROM V$ACTIVE_SESSION_HISTORY WHERE event = 'SQL*Net message from dblink' AND sample_time > '2018-01-26 12:08:55';
  COUNT(*)
----------
         0
# iptables -A INPUT -p tcp -s 127.0.0.1 -d 127.0.0.1 --dport 9444 -i lo -j DROP
--//等...
12:09:57.241304 IP (tos 0x0, ttl  64, id 27723, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.1521 > 127.0.0.1.9444: ., cksum 0xfe28 (incorrect (-> 0x0684), 900:900(0) ack 794 win 385
12:10:07.257024 IP (tos 0x0, ttl  64, id 27724, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.1521 > 127.0.0.1.9444: ., cksum 0xfe28 (incorrect (-> 0xdf63), 900:900(0) ack 794 win 385
12:10:17.272859 IP (tos 0x0, ttl  64, id 27725, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.1521 > 127.0.0.1.9444: ., cksum 0xfe28 (incorrect (-> 0xb843), 900:900(0) ack 794 win 385
12:10:27.289085 IP (tos 0x0, ttl  64, id 27726, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.1521 > 127.0.0.1.9444: ., cksum 0xfe28 (incorrect (-> 0x9123), 900:900(0) ack 794 win 385
12:10:37.305371 IP (tos 0x0, ttl  64, id 27727, offset 0, flags [DF], proto: TCP (6), length: 52) 127.0.0.1.1521 > 127.0.0.1.9444: R, cksum 0xfe28 (incorrect (-> 0x69fe), 901:901(0) ack 794 win 385
--//第1個間隔60秒,以後間隔10秒,一共4次.
--//注意包傳送方向都是單向的(127.0.0.1.1521 > 127.0.0.1.9444)

# lsof -i -P -n | grep 127.0.0.1:
oracle    14308  oracle   11u  IPv4 41475691      0t0  TCP 127.0.0.1:7801->127.0.0.1:1521 (ESTABLISHED)
tnslsnr   24802  oracle    7u  IPv4 41438030      0t0  TCP 127.0.0.1:1521 (LISTEN)
tnslsnr   24802  oracle   14u  IPv4 41481937      0t0  TCP 127.0.0.1:1521->127.0.0.1:7801 (ESTABLISHED)
oracle    26397  oracle    7u  IPv4 41479570      0t0  TCP 127.0.0.1:9444->127.0.0.1:1521 (ESTABLISHED)
cupsd     29590    root    4u  IPv4 23111711      0t0  TCP 127.0.0.1:631 (LISTEN)

--//對比前面的結果,可以僅僅存在127.0.0.1:9444->127.0.0.1:1521,而127.0.0.1:1521->127.0.0.1:9444(也就是服務端發出的連結埠)
--//在會話執行:
SCOTT@78> SELECT count(*) FROM V$ACTIVE_SESSION_HISTORY WHERE event = 'SQL*Net message from dblink' AND sample_time > '2018-01-26 12:08:55';
  COUNT(*)
----------
         0
--//並沒有發生事件'SQL*Net message from dblink'.我還可以執行.

SCOTT@78> select sysdate from dual@loopback ;
SYSDATE
-------------------
2018-01-26 12:35:16

--//等很久結果才出來.因為已經阻塞了.不過等927秒後會開啟新的dblink連線.

SCOTT@78> SELECT count(*) FROM V$ACTIVE_SESSION_HISTORY WHERE event = 'SQL*Net message from dblink' AND sample_time > '2018-01-26 12:08:55';
  COUNT(*)
----------
       927

SCOTT@78> SELECT count(*),min(sample_time),max(sample_time),max(sample_time)-min(sample_time) FROM V$ACTIVE_SESSION_HISTORY WHERE event = 'SQL*Net message from dblink' AND sample_time > '2018-01-26 12:08:55';
COUNT(*) MIN(SAMPLE_TIME)        MAX(SAMPLE_TIME)        MAX(SAMPLE_TIME)-MIN(SAMPLE_TIME)
-------- ----------------------- ----------------------- --------------------------------
     927 2018-01-26 12:19:48.503 2018-01-26 12:35:15.685 +000000000 00:15:27.182

--//出現記數927,需要927秒.也就是我執行的時候時.也是我們生產系統遇到的情況.
--//這裡並不依賴核心引數tcp_keepalive,因為執行select sysdate from dual@loopback ;是由client發起的連線.

# lsof -i -P -n | grep 127.0.0.1:
oracle    14308  oracle   11u  IPv4 41475691      0t0  TCP 127.0.0.1:7801->127.0.0.1:1521 (ESTABLISHED)
tnslsnr   24802  oracle    7u  IPv4 41438030      0t0  TCP 127.0.0.1:1521 (LISTEN)
tnslsnr   24802  oracle   14u  IPv4 41481937      0t0  TCP 127.0.0.1:1521->127.0.0.1:7801 (ESTABLISHED)
oracle    26397  oracle    7u  IPv4 41479609      0t0  TCP 127.0.0.1:9952->127.0.0.1:1521 (ESTABLISHED)
oracle    26788  oracle   15u  IPv4 41474821      0t0  TCP 127.0.0.1:1521->127.0.0.1:9952 (ESTABLISHED)
cupsd     29590    root    4u  IPv4 23111711      0t0  TCP 127.0.0.1:631 (LISTEN)

--//埠已經發生了變化.

收尾:取消防火牆設定:
# iptables -D INPUT -p tcp -s 127.0.0.1 -d 127.0.0.1 --dport 9444 -i lo -j DROP