內容介紹

sqlnet是oracle提供的與網路層面互動的一個工具，比如如何解析客戶端發起的連線，如何對客戶端發起的連線進行辨別，如何對客戶端連線進行阻隔限制，或者啟用日誌及跟蹤（log and trace）功能等等一系列的功能，在以往的幾期技術通訊錄裡面，我們也曾提到過透過sqlnet工具跟蹤並分析oracle空閒回話中斷的原因，本次我們繼續透過sqlnet工具來詳細的分析一次透過對tnsping的跟蹤結果進行分析，查詢為何外部網路無法連線資料庫的原因。雖然說從很大程度上說，外部網路無法正常連線到資料庫伺服器，很大程度上都是因為網路問題造成的原因，無論是埠限制，安全加固等等，如果沒有很好的考慮資料庫方面的資源，往往會造成各種奇怪的連線問題。

故障說明

本次故障發生在一個客戶的RAC環境中，客戶的RAC環境一直採用的是隻連線一號節點，二號節點一直沒有連線，在最近的一次改造過程中，客戶決定啟用二號節點，於是調整了連線串，卻發現客戶端無法正常連線開放的二號節點上。應用和資料庫處於同一個網段。IP透過主機層面的ping沒有問題但是資料庫連線卻直接報錯，tnsping連線串也返回報錯資訊：TNS-12537: TNS: 連線關閉。

故障分析

由於故障報錯資訊相對簡單：TNS-12537: TNS: 連線關閉，往往這種報錯涉及的原因也很多，比如windows下的監聽日誌達到4G限制，後續連線如果無法寫監聽日誌，就會產生TNS-12537報錯，再比如從11g開始Automatic Diagnostic Repository中的 Oracle Net diagnostic在預設的情況下是開啟的，當資料庫和客戶端的連線超過特定時間，就會把這樣的資訊寫入到alert日誌中，但這並不是一個致命的問題，往往也不會造成tnsping不通這種結果。首先我們檢查了資料庫tnsping不通的節點的監聽，發現沒有問題，可以正常連線。我們檢查了客戶設定的連線串模式：

ORACLE_63 =

(DESCRIPTION =

(ADDRESS_LIST =

(ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.63)(PORT = 1521))

)

(CONNECT_DATA =

(SID = xxxx2)

)

ORACLE_157 =

(DESCRIPTION =

(ADDRESS_LIST =

(ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.157)(PORT = 1521))

)

(CONNECT_DATA =

(SID = xxxx1)

)

以上的連線串雖然說從連線模式上來說存在著一定的不合理性，沒有真正發揮RAC應用的負載均衡的特點，但是從連線串的寫法上來看，並沒有任何問題。並且在測試環境上，該連線串也沒有任何問題。

在檢查過程中我們發現，從正常的一節點透過網路服務名連線到二節點不存在任何的問題，而從應用端發起連線就不行。到這一步，我們可以有一個大致的判斷，資料庫伺服器層面不存在問題，兩節點之間可以透過網路服務名連通對方。而透過外網交換機的應用網路卻無法正常連線到資料庫，所以我們有理由相信，問題出現的層面應該在網路層面，或者應用層面，但是應用可以正常的連線到一節點，考慮到二節點之前也沒有連線應用，我們懷疑是否是整合商當初做安全加固將二節點的某些網路資源進行了限制，導致雖然IP能夠ping通但是資料庫卻連不上。如果問題出現在網路層面，我們需要和網路人員溝通，至少我們需要可以拿出資料庫層面關於網路問題的詳細報錯資訊。既然問題出現在tnsping就已經不通了，那麼我們嘗試透過對tnsping進行詳細的跟蹤。

跟蹤引數設定：

和連線跟蹤一樣，預設的tnsping也是關閉的，如果需要開啟跟蹤也同樣是在客戶端sqlnet.ora檔案中編入引數：（因此你的客戶端至少需要是完全安裝版本的，簡單綠色版的客戶端不行）

TNSPING.TRACE_LEVEL=SUPPORT

TNSPING.TRACE_DIRECTORY=d:\oracle\trace

TNSPING.TRACE_LEVEL指的是跟蹤的級別，SUPPORT為最高階別，該引數可選的級別包括：off，user，admin，support 一般來說既然是跟蹤錯誤原因，個人覺得還是將細粒度調整到最大為好，越詳細的日誌，對於我們分析問題幫助越大。

TNSPING.TRACE_DIRECTORY指的是跟蹤產生的trace檔案存放的位置

編入以上引數，我們即可執行tnsping過程：

C:\Users\frank-ying>tnsping oracle_157

已使用 TNSNAMES 介面卡來解析別名

Attempting to contact (DESCRIPTION = (ADDRESS_LIST = (ADDRESS = (PROTOCOL = TCP)

(HOST = 10.20.10.157)(PORT = 1521))) (CONNECT_DATA = (SID = credit1)))

TNS-12537: TNS: 連線關閉

結果獲取後我們可以對檔案進行分析，以下部分貼出整個跟蹤檔案結果集進行詳細分析：

詳細日誌分析過程

########！跟蹤檔案頭資訊記錄包括客戶端資訊，版本，跟蹤時#####################

TNS Ping Utility for 32-bit Windows: Version 10.2.0.1.0 - Production on 17-7月 -2014 08:52:31

#######本次跟蹤的資訊讀取，包括跟蹤級別，基本的跟蹤引數讀取位置##############

--- TRACE CONFIGURATION INFORMATION FOLLOWS ---

New trace stream is d:\oracle\trace\tnsping.trc

New trace level is 16

--- TRACE CONFIGURATION INFORMATION ENDS ---

--- PARAMETER SOURCE INFORMATION FOLLOWS ---

Attempted load of system pfile source D:\oracle\product\10.2.0\db_1\network\admin\sqlnet.ora

Parameter source loaded successfully

-> PARAMETER TABLE LOAD RESULTS FOLLOW

Successful parameter table load

-> PARAMETER TABLE HAS THE FOLLOWING CONTENTS

TNSPING.TRACE_LEVEL = SUPPORT

NAMES.DIRECTORY_PATH = (TNSNAMES, EZCONNECT)

TNSPING.TRACE_DIRECTORY = d:\oracle\trace

SQLNET.AUTHENTICATION_SERVICES = (NTS)

--- PARAMETER SOURCE INFORMATION ENDS ---

--- LOG CONFIGURATION INFORMATION FOLLOWS ---

Log stream will be "standard output"

Log stream validation not requested

--- LOG CONFIGURATION INFORMATION ENDS ---

以上是整個跟蹤檔案的標頭檔案，記錄包括客戶端資訊，版本，跟蹤時間，跟蹤級別，基本的跟蹤引數讀取位置等資訊。

#########################開始跟蹤tnsping過程##############################

nlstdipi: entry

nlstdipi: exit

nnfun2awanm: entry

nnfgiinit: entry

nncpcin_maybe_init: first request sent to name server will have ID 0

nncpcin_maybe_init: initial retry timeout for all name servers is 1500 csecs

nncpcin_maybe_init: max request retries per name server is 1

nngsini_init_streams: initializing stream subsystem, cache size is 10

nngtini_init_msg: initializing PDU subsystem, initial pool size is 2

nncpcin_maybe_init: default name server domain is [root]

nnfgiinit: Installing read path

nnfgsrsp: entry

####################讀取本地tnsnames.ora檔案##############################

nnfgsrsp: Obtaining path parameter from names.directory_path or native_names.directory_path

nnfgsrdp: entry

nnfgsrdp: Setting path:

nnfgsrdp: checking element TNSNAMES

nnfgsrdp: checking element EZCONNECT

nnfgsrdp: Path set

nnfun2a: entry

nlolgobj: entry

nnfgrne: entry

nnfgrne: Going though read path adapters

nnfgrne: Switching to TNSNAMES adapter

nnftboot: entry

nlpaxini: entry

nlpaxini: exit

nnftmlf_make_local_addrfile: entry

nnftmlf_make_local_addrfile: construction of local names file failed

nnftmlf_make_local_addrfile: exit

nlpaxini: entry

nlpaxini: exit

nnftmlf_make_system_addrfile: entry

nnftmlf_make_system_addrfile: system names file is D:\oracle\product\10.2.0\db_1\network\admin\tnsnames.ora

nnftmlf_make_system_addrfile: exit

nnftboot: exit

nnftrne: entry

####獲取本次需tnsping的連線串名，掃描整個tnsnames.ora檔案匹配該連線串名####

nnftrne: Original name: oracle_157

nnfttran: entry

nncpdpt_dump_ptable: --- D:\oracle\product\10.2.0\db_1\network\admin\tnsnames.ora TABLE HAS THE FOLLOWING CONTENTS ---

nncpdpt_dump_ptable: load_balance = (DESCRIPTION = (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.157)(PORT = 1521)) (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.63)(PORT = 1521)) (LOAD_BALANCE = yes) (CONNECT_DATA = (SERVER = DEDICATED) (SERVICE_NAME = credit_server_taf) (FAILOVER_MODE = (TYPE = SELECT) (METHOD = BASIC) (RETRIES = 180) (DELAY = 5))))

nncpdpt_dump_ptable: balance = (DESCRIPTION = (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.157)(PORT = 1521)) (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.63)(PORT = 1521)) (LOAD_BALANCE = yes) (CONNECT_DATA = (SERVER = DEDICATED) (SERVICE_NAME = creditmanager) (FAILOVER_MODE = (TYPE = SELECT) (METHOD = BASIC) (RETRIES = 180) (DELAY = 5))))

nncpdpt_dump_ptable: --- END D:\oracle\product\10.2.0\db_1\network\admin\tnsnames.ora TABLE ---

nnfttran: exit

############################結果正常獲取##################################

nnftrne: Using tnsnames.ora address (DESCRIPTION = (ADDRESS_LIST = (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.155)(PORT = 1521))) (CONNECT_DATA = (SID = credit1))) for name oracle_157

######################解析連線串結果並開始跟蹤############################

nsmal: 212 bytes at 0xee81d8

nsmal: normal exit

nscall: connecting...

nladini: entry

nladini: exit

nladget: entry

nladget: exit

nsc2addr: entry

nsc2addr: (DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=10.20.10.155)(PORT=1521))(CONNECT_DATA=(SID=credit1)))

nttbnd2addr: entry

snlinGetAddrInfo: entry

snlinGetAddrInfo: exit

nttbnd2addr: using host IP address: 10.20.10.155（此處可以看到，配置的是實際地址，所以不用在去解析DNS或者分析hosts檔案）

nsmal: normal exit

nsbal: normal exit

nsiorini: exit (0)

nscpxget: entry

nscpxget: normal exit

nsopenalloc_nsntx: nlhthput on mplx_ht_nsgbu:ctx=f32ef0, nsntx=f331d8

nsopenmplx: normal exit

########################開始建立連線######################################

nsopen: opening transport...

nttcon: entry

nttcon: toc = 1

nttcnp: entry

nttcnp: creating a socket.

nttcnp: exit

nttcni: entry

nttcni: trying to connect to socket 1808.

snlinGetNameInfo: entry

snlinGetNameInfo: Using numeric form of host's address 10.20.10.131

snlinGetNameInfo: exit

nttcni: connected on ipaddr 10.20.10.131（解析本地IP地址）

nttcni: exit

nttcon: NT layer TCP/IP connection has been established.（TCP/IP協議）

nttcon: set TCP_NODELAY on 1808

nttcon: exit

####################以下開始發包過程，傳送87位元組的包#######################

nsdo: cid=0, opcode=67, *bl=29, *what=8, uflgs=0x0, cflgs=0x3

nsdo: rank=64, nsctxrnk=0

nsdo: nsctx: state=14, flg=0x4005, mvd=0

nsdo: gtn=10, gtc=10, ptn=10, ptc=2011

nscon: entry

nscon: doing connect handshake...

nscon: sending NSPTCN packet

nspsend: entry

nspsend: plen=87, type=1

nttwr: entry

nttwr: socket 1808 had bytes written=87

nttwr: exit

nspsend: packet dump

nspsend: 00 57 00 00 01 00 00 00 |.W......|

nspsend: 01 39 01 2C 00 00 08 00 |.9.,....|

nspsend: 7F FF C6 0E 00 00 01 00 |........|

nspsend: 00 1D 00 3A 00 00 00 00 |...:....|

nspsend: 00 00 00 00 00 00 00 00 |........|

nspsend: 00 00 28 43 4F 4E 4E 45 |..(CONNE|

nspsend: 43 54 5F 44 41 54 41 3D |CT_DATA=|

nspsend: 28 43 4F 4D 4D 41 4E 44 |(COMMAND|

nspsend: 3D 70 69 6E 67 29 29 |=ping)) |

nspsend: 87 bytes to transport（發包成功返回）

nspsend: normal exit

nscon: exit (0)

nsdo: nsctxrnk=0

nsdo: normal exit

nsdo: entry

nsdo: cid=0, opcode=68, *bl=1024, *what=9, uflgs=0x2000, cflgs=0x3

nsdo: rank=64, nsctxrnk=0

nsdo: nsctx: state=2, flg=0x4005, mvd=0

nsdo: gtn=10, gtc=10, ptn=10, ptc=2011

nscon: entry

############################開始回包過程##################################

nscon: recving a packet

nsprecv: entry

nsprecv: reading from transport...

nttrd: entry

ntt2err: entry

ntt2err: soc 1808 error - operation=5, ntresnt[0]=530, ntresnt[1]=53, ntresnt[2]=0

ntt2err: exit

nttrd: exit

nsprecv: error exit

nserror: entry

nserror: nsres: id=0, op=68, ns=12570, ns2=12560; nt[0]=530, nt[1]=53, nt[2]=0; ora[0]=0, ora[1]=0, ora[2]=0

nscon: error exit

nsdo: nsctxrnk=0

nsdo: error exit

nscall: unexpected response

我們詳細分析上面的報錯過程，從目前來看，整個的發包過程沒有問題，但是在包返回過程中，直接報錯，返回錯誤ntt2err: soc 1808 error - operation=5, ntresnt[0]=530, ntresnt[1]=53, ntresnt[2]=0

從錯誤的資訊看，應該是在網路層面出了問題，據此我們搜尋了MOS相關文件：

ORA-3113 reported when using NitroSecurity Firewall. (文件 ID 1388804.1)

該文件報錯資訊一致，原因是NitroSecurity防火牆的阻隔

透過對以上結果的分析，我們有理由確信在中間的網路層面出現了阻隔導致返回包的過程中出現了問題，就此將問題提交網路工程師

技術結論

從以上的分析結果看，sqlnet跟蹤的分析過程其實並沒有我們想像的那麼複雜，tnsping透過解析主機及埠號，建立與資料庫伺服器的連線。透過一次發包及回包的過程來檢測網路是否存在問題，本次分析我們更多的是為了分析tnsping的結果而分析，在真正實際環境中，大家可以從跟蹤檔案的最後開始倒推分析。往往這種連線問題，透過相應的跟蹤日誌，基本都能大致的分析出問題的成因所在。

------------------------------------------------------------------------------------

原部落格地址：http://blog.itpub.net/23732248/
原作者：應以峰 (frank-ying)
-------------------------------------------------------------------------------------

SQLNET跟蹤tnsping過程

相關文章