[20180124]奇怪的SQL*Net message from dblink.txt
--//生产系统出现大量的SQL*Net message from dblink事件,自己分析看看.
1.环境:
--//这个环境是服务器在分院,有时候要通过dblink访问总院的数据库.
xxxx> @ 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
xxxx> @ ev_name.sql "SQL*Net message from dblink"
EVENT# EVENT_ID NAME PARAMETER1 PARAMETER2 PARAMETER3 WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS
------ ---------- --------------------------- ---------- ---------- ---------- ------------- ----------- ----------
356 4093028837 SQL*Net message from dblink driver id #bytes 2000153315 7 Network
--//P2参数表示传输的字节数量.我发现一个奇特现象:
xxxx> SELECT * FROM V$ACTIVE_SESSION_HISTORY WHERE event = 'SQL*Net message from dblink' AND p2 > 1;
no rows selected
xxxx> SELECT count(*) FROM V$ACTIVE_SESSION_HISTORY WHERE event = 'SQL*Net message from dblink' AND p2 = 1;
COUNT(*)
----------
181068
--//出现问题的都是1个字节的情况,按照道理这样的传输不会出现的SQL*Net message from dblink事件,虽然分院与总院租用的电信的线路,
--//至少10M的带宽,本想找网络管理员要网络出口的流量图,估计没做监控,失望.不过传输量这么小,网络应该问题不大.
--//我从总院内网的一台机器ping分院服务器.使用
# ping -s 9000 分院服务器
...
9 packets transmitted, 9 received, 0% packet loss, time 8007ms
rtt min/avg/max/mdev = 1.034/1.255/2.776/0.539 ms
# ping -s 9000 总院服务器
10 packets transmitted, 10 received, 0% packet loss, time 9000ms
rtt min/avg/max/mdev = 0.303/0.342/0.402/0.039 ms
--//大约1ms往返内网网之间,应该问题不大.而我执行如下:
/* Formatted on 2018/1/24 9:24:37 (QP5 v5.269.14213.34769) */
SELECT machine
,port
,session_id
,session_serial#
,MIN (sample_time) MIN
,MAX (sample_time) MAX
,MAX (sample_time) - MIN (sample_time) delta
FROM V$ACTIVE_SESSION_HISTORY
WHERE event = 'SQL*Net message from dblink'
GROUP BY machine
,port
,session_id
,session_serial#
ORDER BY 5 DESC;
--//我发现一个独特的规律,delta的间隔大多数都是+00 00:15:24.369000上下相差1秒.15*60+25 = 925.另外我使用如下查询:
SELECT sql_id,count(*) FROM V$ACTIVE_SESSION_HISTORY WHERE event = 'SQL*Net message from dblink' group by sql_id order by 2 desc;
--//反查sql语句,居然发现靠前的几个存在dblink访问外.其中一些执行如下:
select sysdate from dual;
--//很明显dblink链路出了问题,才会出现这样的情况.
2.分析:
--//分析我已经在链接:
http://blog.itpub.net/267265/viewspace-2150434/
http://blog.itpub.net/267265/viewspace-2150431/
--//问题在于使用总院服务器设置了SQLNET.EXPIRE_TIME参数,,定时监测服务端与客户端连接情况.对于这里监测dblink的连接情况.
--//但是在总院与分院之间配置的是状态防火墙,不允许这样的包通过,这样总院服务器发起的测试连接都被阻塞.而且根据前面的测试
--//一旦发出测试包发现不通,dblink的连接就出现问题.这样用户的应用程序如果仅仅访问分院的服务器数据库不会存在问题.因为这条
--//链接是通的,但是一旦执行事务提交就会挂起(注使用dblink是会产生小量的redo的).这就是我们现在生产系统遇到的问题.
--//补充说明,使用dblink会产生事务的.许多开发并不知道,关于如何关闭数据库会话的dblink,参考链接
--//http://blog.itpub.net/267265/viewspace-2123710/
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
SCOTT@book> @ &r/xid
XIDUSN_XIDSLOT_XIDSQN
------------------------------
no rows selected
SCOTT@book> select sysdate from dual@loopback ;
SYSDATE
-------------------
2018-01-24 09:43:27
SCOTT@book> @ &r/xid
XIDUSN_XIDSLOT_XIDSQN
------------------------------
10.21.21378
--//注xid.sql脚本:
select dbms_transaction.local_transaction_id() XIDUSN_XIDSLOT_XIDSQN from dual ;
--//一种情况很特殊,如果在dg上以只读打开数据库,使用dblink是没有问题在11g下(10g会存在问题),但是如果sql语句涉及2个dblink链
--//接,这个问题可以参考我以前的链接:http://blog.itpub.net/267265/viewspace-2138879/
--//这个时间大约就是925秒,与我前面链接http://blog.itpub.net/267265/viewspace-2150434/,http://blog.itpub.net/267265/viewspace-2150431/
--//是一致的,补充1点,我前面的测试少算了最后1次测试时间120.补上基本一致了.
3.解决访问:
--//最佳方法就是取消状态防火墙设置.这是最佳方案.
--//或者增加SQLNET.EXPIRE_TIME参数设置,规避服务器发起的监测,不过这样就失去这个参数的意义.
--//在访问dblink后,即使select最好加一个提交.这样虽然dblink连接不会断开,至少一些应用不会出错.因为一些应用的提交顺带提交访问dblink产生的事务.
--//如果这时dblink出问题,用户的操作也会挂起,rollback掉.
--//最后再次佩服我们的使用者,居然这样的问题也能忍耐,要是不是一次下班路上别人给我提起,我才关注这个问题.
--//更加佩服我们的团队,这个问题存在这么长时间,开发反应,我们数据库团队把问题归到网络,就没有任何人静下来思考解决问题.失望....
4.我自己也重复测试:
xxxx> select sysdate from dual@xhlis;
SYSDATE
-------------------
2018-01-24 10:05:52
xxxx> host sleep 900
xxxx>
xxxx> select sysdate from dual ;
SYSDATE
-------------------
2018-01-24 10:23:39
--//本地可以访问,如果你执行dml的提交问题再现
xxxx> commit;
--//挂起...