关于tnsping跟踪

很多时候，我们在对客户端到服务端的连接问题非常头疼，中间网络层的复杂度造成了故障的难以定位，而且也许客户端到服务层的网络可以ping通，但是单单网络可以通并不能保证我们数据库的正常连接，oracle的连接涉及的东西太多，中间件的长连接问题，端口的开放问题，大小字节包的问题，等等都会造成我们连接出现问题，很多时候，对于连接出现问题，或者无法连接的情况下，我们往往很难确认问题的根本原因在哪里，而oracle很好的提供了各种工具帮组我们跟踪分析整个连接过程，比如对连接的跟踪，对tnsping结果的跟踪等等，本次故障就是通过对tnsping结果的跟踪分析，查找问题所在，本文旨在提供大家基本的tnsping跟踪技巧及分析过程，并不详细解释tnsping oracle NET等基础知识


跟踪参数设置：


和连接跟踪一样，默认的tnsping也是关闭的，如果需要开启跟踪也同样是在客户端sqlnet.ora文件中编入参数：


TNSPING.TRACE_LEVEL=SUPPORT
TNSPING.TRACE_DIRECTORY=d:\oracle\trace


首先 TNSPING.TRACE_LEVEL指的是跟踪的级别，SUPPORT为最高级别，该参数可选的级别包括：off，user，admin，support 一般来说我比较喜欢采用support级别，分析粒度够大，结果也越明确
编入以上参数，我们即可执行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


Copyright (c) 1997, 2005, Oracle.  All rights reserved.
###########################本次跟踪的信息读取，包括跟踪级别，基本的跟踪参数读取位置###########################
--- 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: ORACLE = (DESCRIPTION = (ADDRESS_LIST = (ADDRESS = (PROTOCOL = TCP)(HOST = 127.0.0.1)(PORT = 1521))) (CONNECT_DATA = (SID = orcl)))
nncpdpt_dump_ptable: ORACLE_157 = (DESCRIPTION = (ADDRESS_LIST = (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.155)(PORT = 1521))) (CONNECT_DATA = (SID = credit1)))
nncpdpt_dump_ptable: ORACLE_63 = (DESCRIPTION = (ADDRESS_LIST = (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.63)(PORT = 1521))) (CONNECT_DATA = (SID = credit2)))
nncpdpt_dump_ptable: ORCL_86 = (DESCRIPTION = (ADDRESS_LIST = (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.86)(PORT = 1521))) (CONNECT_DATA = (SID = orcl)))
nncpdpt_dump_ptable: ORACLE_88 = (DESCRIPTION = (ADDRESS_LIST = (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.88)(PORT = 1521))) (CONNECT_DATA = (SID = orcl)))
nncpdpt_dump_ptable: EXTPROC_CONNECTION_DATA = (DESCRIPTION = (ADDRESS_LIST = (ADDRESS = (PROTOCOL = IPC)(KEY = EXTPROC1))) (CONNECT_DATA = (SID = PLSExtProc) (PRESENTATION = RO)))
nncpdpt_dump_ptable: ORCL_89_ZJ_YJ_DS = (DESCRIPTION = (ADDRESS_LIST = (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.89)(PORT = 1522))) (CONNECT_DATA = (SID = orcl)))
nncpdpt_dump_ptable: zjcreditwebnew = (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)))
nncpdpt_dump_ptable: ORCL_89_WENZHOU = (DESCRIPTION = (ADDRESS_LIST = (ADDRESS = (PROTOCOL = TCP)(HOST = 10.20.10.89)(PORT = 1521))) (CONNECT_DATA = (SID = orcl)))
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
nnftrne: exit
nnfgrne: exit
nlolgserv: entry
nnfggav: entry
nnftgav: entry
nnftgav: exit
nnfgfrm: entry
nnftfrm: entry
nnftfrm: exit
nnfgfrm: exit
nlolgserv: exit
nlolgobj: exit
nlolfmem: entry
nlolfmem: exit
nnfun2awanm: Getting the path of sqlnet.ora
nnfun2awanm: Getting the adapter name
nnfun2awanm: exit
nscall: entry
nsmal: entry
#########解析连接串结果并开始跟踪########
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文件）
snlinFreeAddrInfo: entry
snlinFreeAddrInfo: exit
nttbnd2addr: exit
nsc2addr: normal exit
nsopen: entry
nsmal: entry
nsmal: 736 bytes at 0xf32ef0
nsmal: normal exit
nsopenmplx: entry
nsmal: entry
nsmal: 1644 bytes at 0xf331d8
nsmal: normal exit
nsiorini: entry
nsbal: entry
nsbgetfl: entry
nsbgetfl: normal exit
nsmal: entry
nsmal: 84 bytes at 0xf32de0
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字节的包####################
nsopen: transport is open
nsoptions: entry
nsoptions: lcl[0]=0x0, lcl[1]=0x900001, gbl[0]=0x0, gbl[1]=0x0, cha=0x0
nsoptions: lcl[0]=0xf4ffefff, lcl[1]=0x900001, gbl[0]=0xfabf, gbl[1]=0x0
nsoptions: normal exit
nsnainit: entry
nsnainit: call
nsnainit: NA not wanted - disabling and returning
nsopen: global context check-in (to slot 0) complete
nsopen: lcl[0]=0xf4ffefff, lcl[1]=0x900001, gbl[0]=0xfabf, gbl[1]=0x0, tdu=32767, sdu=2048
nsdo: entry
nsdo: cid=0, opcode=65, *bl=0, *what=0, uflgs=0x0, cflgs=0x2
nsdo: rank=64, nsctxrnk=0
nsdo: nsctx: state=7, flg=0x4001, mvd=0
nsbal: entry
nsbgetfl: entry
nsbgetfl: normal exit
nsmal: entry
nsmal: 84 bytes at 0xf34848
nsmal: normal exit
nsbal: normal exit
nsbal: entry
nsbgetfl: entry
nsbgetfl: normal exit
nsmal: entry
nsmal: 84 bytes at 0xf350c8
nsmal: normal exit
nsbal: normal exit
nsdo: nsctxrnk=0
nsdo: normal exit
nsopen: normal exit
nsdo: entry
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 00 00 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防火墙的阻隔
通过对以上结果的分析，我们有理由确信在中间的网络层面出现了阻隔导致返回包的过程中出现了问题，就此将问题提交网络工程师
nsclose: entry
nstimarmed: entry
nstimarmed: no timer allocated
nstimarmed: normal exit
nttctl: entry
nttctl: entry
nsdo: entry
nsdo: cid=0, opcode=98, *bl=0, *what=0, uflgs=0x440, cflgs=0x2
nsdo: rank=64, nsctxrnk=0
nsdo: nsctx: state=1, flg=0x4001, mvd=0
nsbfr: entry
nsbaddfl: entry
nsbaddfl: normal exit
nsbfr: normal exit
nsbfr: entry
nsbaddfl: entry
nsbaddfl: normal exit
nsbfr: normal exit
nsdo: nsctxrnk=0
nsdo: normal exit
nsiocancel: entry
nsiofrrg: entry
nsbfr: entry
nsbaddfl: entry
nsbaddfl: normal exit
nsbfr: normal exit
nsiofrrg: exit
nsiocancel: exit
nsclose: closing transport
nttdisc: entry
nttdisc: Closed socket 1808
nttdisc: exit
nsclose: global context check-out (from slot 0) complete
nsnadisc: entry
nsnadisc: no native services in use - returning
nsopenfree_nsntx: nlhthdel from mplx_ht_nsgbu, ctx=f32ef0 nsntx=f331d8
nsiocancel: entry
nsiofrrg: entry
nsiofrrg: exit
nsiocancel: exit
nsmfr: entry
nsmfr: 1644 bytes at 0xf331d8
nsmfr: normal exit
nsmfr: entry
nsmfr: 736 bytes at 0xf32ef0
nsmfr: normal exit
nsclose: normal exit
nscall: error exit
nscall: entry
nscall: connecting...
nsclose: entry
nsclose: normal exit
nladget: entry
nladget: exit
nsmfr: entry
nsmfr: 212 bytes at 0xee81d8
nsmfr: normal exit
nladtrm: entry
nladtrm: exit
nscall: error exit
nlse_term_audit: entry
nlse_term_audit: exit

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

转载于:http://blog.itpub.net/23732248/viewspace-1978451/