监听器控制程序lsnrctl跟踪trace file
上一篇 / 下一篇 2011-12-19 23:46:47 / 个人分类:安装配置工具使用
Oracle监听器是一个独立的数据库组件,在整个体系中扮演非常重要的作用。即使在windows平台上,监听器listener也被实现成为一个独立的进程程序。
在一些与网络相关的故障中,监听器相关故障占了很大部分。了解监听器的工作过程,分析每个环节出现问题的几率,是监听器发生故障时我们常常需要做的事情。这个过程我们就需要使用监听器trace功能。
本篇主要介绍如何使用lsnrctl工具获取到监听器跟踪文件(trace file),以及获取的跟踪级别。
1、环境介绍
本次我们选择10g监听器进行试验。
Microsoft Windows XP [版本5.1.2600]
(C)版权所有1985-2001 Microsoft Corp.
C:\Documents and Settings\Administrator>lsnrctl
LSNRCTL for 32-bit Windows: Version10.2.0.1.0 - Production on 19-12月-2011 20:31:59
Copyright (c) 1991, 2005, Oracle. All rights reserved.
欢迎来到LSNRCTL,请键入"help"以获得信息。
注意,lsnrctl并不是监听器程序本身,而是监听器控制的一个小工具。借助这个工具,我们可以操纵监听器行为、设置监听器参数。Lsnrctl命令行使用的命令很简单。
LSNRCTL> help
以下操作可用
星号(*)表示修改符或扩展命令:
start stop status
services version reload
save_config trace change_password
quit exit set*
show*
此时,数据库尚未启动。监听器处于运行状态。
LSNRCTL> status
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)))
LISTENER的STATUS
------------------------
别名 LISTENER
版本 TNSLSNR for 32-bit Windows: Version10.2.0.1.0 - Production
启动日期 19-12月-2011 20:28:53
正常运行时间 0天0小时3分32秒
跟踪级别 off
安全性 ON: Local OS Authentication
SNMP OFF
监听程序参数文件 D:\oracle\network\admin\listener.ora
监听程序日志文件 D:\oracle\network\log\listener.log
(篇幅原因,有省略……)
LSNRCTL>
此时,没有进行跟踪文件输出。
2、简单跟踪文件生成
我们先介绍如何使用一般监听跟踪方法。该配置从lsnrctl设置。在lsnrctl配置中,有一些与trace相关的内容。
LSNRCTL> show
show之后提供了以下操作
星号(*)表示修改符或扩展命令:
rawmode displaymode
rules trc_file
trc_directory trc_level
log_file log_directory
(篇幅原因,有省略……)
其中,以trc开头的几个参数显然是与trace文件操作生成有关。我们可以使用show命令加以显示。
--跟踪文件名称
LSNRCTL> show trc_file
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP) (HOST=www-0e6111dff74)(PORT=1521)))
LISTENER参数"trc_file"设为listener.trc
命令执行成功
--跟踪文件目录
LSNRCTL> show trc_directory
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)
))
LISTENER参数"trc_directory"设为D:\oracle\network\trace
命令执行成功
--跟踪程度
LSNRCTL> show trc_level
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)
))
LISTENER参数"trc_level"设为off
命令执行成功
通过上面参数,我们可以配置跟踪文件的位置、名称和跟踪级别。
开启跟踪,我们可以使用trace命令。具体格式如下:
LSNRCTL> help trace
trace OFF | USER | ADMIN | SUPPORT [<listener_name>] : set tracing to the specif
ied level
注意,我们开启跟踪是有三个级别的,分别为user、admin和support级别。具体含义如下:
ü Off或者数值0:表示对当前的监听器不开启跟踪;
ü User或者数值4:user trace information;
ü Admin或者数值10:administration trace information;
ü Support或者数值16:Oracle support Services trace information;
通常,我们使用support级别作为跟踪。
LSNRCTL> trace12
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)
))
打开的跟踪文件:D:\oracle\network\trace\listener.trc
LSNRCTL>show trc_level
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)
))
LISTENER参数"trc_level"设为admin
命令执行成功
从返回信息和status信息,都可以看出此时监听器是被监听状态。
LSNRCTL> status
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)))
LISTENER的STATUS
------------------------
别名 LISTENER
版本 TNSLSNR for 32-bit Windows: Version10.2.0.1.0 - Production
启动日期 19-12月-2011 20:28:53
正常运行时间 0天0小时15分5秒
跟踪级别 admin
安全性 ON: Local OS Authentication
SNMP OFF
监听程序参数文件 D:\oracle\network\admin\listener.ora
监听程序日志文件 D:\oracle\network\log\listener.log
监听程序跟踪文件 D:\oracle\network\trace\listener.trc
监听端点概要...
(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=www-0e6111dff74)(PORT=1521)))
(篇幅原因,有省略……)
LSNRCTL>
我们可以在这个过程中,尝试进行动态注册或者新连接连入等操作。最后关闭监听。
LSNRCTL> traceoff
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)))
命令执行成功
LSNRCTL> status
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)
))
LISTENER的STATUS
------------------------
别名 LISTENER
版本 TNSLSNR for 32-bit Windows: Version10.2.0.1.0 - Production
启动日期 19-12月-2011 20:28:53
正常运行时间 0天0小时17分16秒
跟踪级别 off
安全性 ON: Local OS Authentication
SNMP OFF
监听程序参数文件 D:\oracle\network\admin\listener.ora
监听程序日志文件 D:\oracle\network\log\listener.log
监听端点概要...
(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=www-0e6111dff74)(PORT=1521)))
此时,我们到监听目录下,就可以找到监听文件。下面是片段:
nsglrespond: entry
nsdo: cid=3, pcode=67, *bl=97, *what=1, uflgs=0x0, cflgs=0x3
nsdo: rank=64, nsctxrnk=0
nsdo: nsctx: state=8, flg=0x100400c, mvd=0
nsdo: gtn=206, gtc=206, ptn=10, ptc=2011
nsdo: 97 bytes to NS buffer
nsdo: nsctxrnk=0
nsglrespond: exit
nsgldissolve: entry
nstimarmed: no timer allocated
nsdo: cid=3, pcode=66, *bl=0, *what=0, uflgs=0x0, cflgs=0x2
nsdo: rank=64, nsctxrnk=0
nsdo: nsctx: state=8, flg=0x1004008, mvd=0
nsevunreg: cid=3, sgt=0, rdm=2
上面每一行记录,都对应监听器程序的动作信息。当然,直观上是不容易读懂的。我们以后再讨论如何读懂监听跟踪文件内容。
3、带时间信息的监听跟踪文件
上面部分中,我们已经获得了简单的跟踪文件。但是我们诊断问题的时候,通常是希望得到每个阶段操作执行时间的长短,从而发现问题瓶颈。
例如:我们发现通过监听器连接速度很慢,但是绕过监听器直接连接的速度很快。说明连接操作中,一个或者几个环节存在性能问题。具体是哪个?还是需要进一步时间间隔判断。
我们想要获得时间信息,需要配置两个参数在listener.ora文件中。
LISTENER =
(DESCRIPTION_LIST =
(DESCRIPTION =
(ADDRESS = (PROTOCOL = TCP)(HOST = www-0e6111dff74)(PORT = 1521))
)
)
TRACE_TIMESTAMP_LISTENER=true
TRACE_LEVEL_LISTENER=16
首先,需要在参数文件listener.ora中,加入两个参数取值。其中trace_timestamp_<listener_name>表示是否开启跟踪时间功能。如果设置为true/on,表示记录跟踪事件的时候,同时会记录上具体的时间。
另一个参数trace_level_<listener_name>表示启动监听程序时的跟踪级别。要让这两个参数生效,需要reload或者重新启动监听器。
LSNRCTL> start
启动tnslsnr:请稍候...
TNSLSNR for 32-bit Windows: Version10.2.0.1.0 - Production
系统参数文件为D:\oracle\network\admin\listener.ora
写入D:\oracle\network\log\listener.log的日志信息
写入D:\oracle\network\trace\listener.trc的跟踪信息
监听: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=www-0e6111dff74)(PORT=1521)))
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)
))
LISTENER的STATUS
------------------------
别名 LISTENER
版本 TNSLSNR for 32-bit Windows: Version10.2.0.1.0 - Produ
ction
启动日期 19-12月-2011 21:47:12
正常运行时间 0天0小时0分1秒
跟踪级别 support
安全性 ON: Local OS Authentication
SNMP OFF
监听程序参数文件 D:\oracle\network\admin\listener.ora
监听程序日志文件 D:\oracle\network\log\listener.log
监听程序跟踪文件 D:\oracle\network\trace\listener.trc
(篇幅原因,省略部分……)
LSNRCTL> trace 0
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)
))
命令执行成功
LSNRCTL> trace 16
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)
))
打开的跟踪文件: D:\oracle\network\trace\listener.trc
命令执行成功
此时生成的trace文件中,有如下内容:
[19-12月-2011 21:53:40:281] nsglrespond: entry
[19-12月-2011 21:53:40:281] nsdo: entry
[19-12月-2011 21:53:40:281] nsdo: cid=5, pcode=67, *bl=97, *what=1, uflgs=0x0, cflgs=0x3
[19-12月-2011 21:53:40:281] nsdo: rank=64, nsctxrnk=0
[19-12月-2011 21:53:40:281] nsdo: nsctx: state=8, flg=0x100400c, mvd=0
[19-12月-2011 21:53:40:281] nsdo: gtn=206, gtc=206, ptn=10, ptc=2011
[19-12月-2011 21:53:40:281] nsdo: 97 bytes to NS buffer
[19-12月-2011 21:53:40:281] nsdo: nsctxrnk=0
[19-12月-2011 21:53:40:281] nsiooverflow: entry
[19-12月-2011 21:53:40:281] nsdo: normal exit
[19-12月-2011 21:53:40:281] nsglrespond: exit
[19-12月-2011 21:53:40:281] nsgldissolve: entry
[19-12月-2011 21:53:40:281] nsdisc: entry
[19-12月-2011 21:53:40:281] nsclose: entry
记录在毫秒级别的跟踪信息。
4、结论
监听器是一个涉及网络、Oracle实例、连接、客户端和Oracle Net复杂组件。我们遇到的很多问题,根源其实都与监听器有或多或少的关系。掌握跟踪文件,对于监听器诊断至关重要。
相关阅读:
- ORACLE字符集 (ycpriscilla, 2011-12-15)
- Oracle Flashback技术总结 (OraFige, 2011-12-15)
- 不使用HACMP搭建AIX RAC环境 (尛样儿, 2011-12-16)
- oracle sqr工作学习小记 (wisdomone1, 2011-12-16)
- oracle sqr编写调试手记 (wisdomone1, 2011-12-16)
- Bulk Collect性能分析 (zhoudaoyu, 2011-12-16)
- java数组传入oracle (tyoodz, 2011-12-17)
- 在数据库服务器端养成设置NLS_LANG和NLS_DATE_FORMAT环境变量的习惯 (尛样儿, 2011-12-17)
- oracle 触发器 (mahongtao810, 2011-12-18)
- oracle sqr之不同判断写入不同的.LIS文件 (wisdomone1, 2011-12-19)
解析listener跟踪文件
上一篇 / 下一篇 2011-12-20 21:26:46 / 个人分类:oracle工作机制
在上篇《监听器控制程序lsnrctl跟踪trace file》(http://space.itpub.net/17203031/viewspace-713587)中,我们探讨了如何获取到监听器跟踪文件。本篇中,我们继续来研究如何分析跟踪文件,从而发现其中的问题。
1、实验文件获取
首先,我们先按照上篇中介绍的方法,获取一个跟踪文件片段。先对listener.ora文件进行配置参数。
LISTENER =
(DESCRIPTION_LIST =
(DESCRIPTION =
(ADDRESS = (PROTOCOL = TCP)(HOST = www-0e6111dff74)(PORT = 1521))
)
)
TRACE_TIMESTAMP_LISTENER=true
TRACE_LEVEL_LISTENER=16
重新reload监听器控制文件,应用参数。
Microsoft Windows XP [版本5.1.2600]
(C)版权所有1985-2001 Microsoft Corp.
C:\Documents and Settings\Administrator>lsnrctl
LSNRCTL for 32-bit Windows: Version10.2.0.1.0 - Production on 20-12月-2011 19:49:09
Copyright (c) 1991, 2005, Oracle. All rights reserved.
欢迎来到LSNRCTL,请键入"help"以获得信息。
--使用reload命令,重新加载参数文件;
LSNRCTL>reload
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)))
命令执行成功
此时,监听跟踪模式启动。
LSNRCTL> status
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)))
LISTENER的STATUS
------------------------
别名 LISTENER
版本 TNSLSNR for 32-bit Windows: Version10.2.0.1.0 - Produ
ction
启动日期 20-12月-2011 19:33:01
正常运行时间 0天0小时16分22秒
跟踪级别 support
安全性 ON: Local OS Authentication
SNMP OFF
监听程序参数文件 D:\oracle\network\admin\listener.ora
监听程序日志文件 D:\oracle\network\log\listener.log
监听程序跟踪文件 D:\oracle\network\trace\listener.trc
监听端点概要...
(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=www-0e6111dff74)(PORT=1521)))
服务摘要..
服务"PLSExtProc"包含1个例程。
例程"PLSExtProc",状态UNKNOWN,包含此服务的1个处理程序...
命令执行成功
其后,启动数据库orcl,使用sqlplus进行一次连接。之后关闭监听跟踪。
LSNRCTL> trace off
正在连接到(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=www-0e6111dff74)(PORT=1521)))
命令执行成功
LSNRCTL>
我们就可以在目录位置上找到listener.trc。
2、Trace文件处理和解析
我们使用的是带时间戳的trace文件生成。打开文件后,可以看到以操作调用为顺序的trace文件记录。
TNSLSNR for 32-bit Windows: Version10.2.0.1.0 - Production on 20-12月-2011 19:49:12
Copyright (c) 1991, 2005, Oracle. All rights reserved.
[20-12月-2011 19:49:12:031] --- TRACE CONFIGURATION INFORMATION FOLLOWS ---
[20-12月-2011 19:49:12:031] New trace stream is D:\oracle\network\trace\listener.trc
[20-12月-2011 19:49:12:031] New trace level is 16
[20-12月-2011 19:49:12:031] --- TRACE CONFIGURATION INFORMATION ENDS ---
[20-12月-2011 19:49:12:031] nscontrol: entry
[20-12月-2011 19:49:12:031] ntvlaarl: entry
原始跟踪文件的特点是详细记录了监听器的每个动作、每条信息。我们希望知道的和不希望知道的内容都在其中。缺点是不容易阅读,其中很多缩写对技术水平要求很高。
不过,要注意trace文件中的条目,都是按照entry+exit的体系嵌套起来的。如下:
[20-12月-2011 19:49:40:640]nau_gparams: entry
[20-12月-2011 19:49:40:640] nam_gbp: Reading parameter "sqlnet.authentication_required" from parameter file
[20-12月-2011 19:49:40:640] nam_gbp: Parameter not found
[20-12月-2011 19:49:40:640] nau_gparams: Using default value "FALSE"
[20-12月-2011 19:49:40:640]nau_gslf: entry
[20-12月-2011 19:49:40:640] nam_gic: entry
[20-12月-2011 19:49:40:640] nam_gic: Counting # of items in "sqlnet.authentication_services" parameter
[20-12月-2011 19:49:40:640] nam_gic: Parameter not found
[20-12月-2011 19:49:40:640] nam_gic: Found 0 items
[20-12月-2011 19:49:40:640] nam_gic: exit
[20-12月-2011 19:49:40:640] nau_gslf: Using default value "all available adapters"
[20-12月-2011 19:49:40:640] nauss_set_state: entry
[20-12月-2011 19:49:40:640] nauss_set_state: exit
[20-12月-2011 19:49:40:640]nau_gslf: exit
[20-12月-2011 19:49:40:640]nau_gparams: exit
上面片段说明监听器程序在获取sqlnet.ora参数中,没有取到而去应用默认值的过程。
另外,Oracle也提供了工具对监听器跟踪文件进行解析。Trcasst是Oracle提供的一个跟踪文件解析工具,可以帮我们分析跟踪文件内容。
D:\oracle\NETWORK\trace>trcasst
Trace Assistant实用程序:版本10.2.0.1.0正式版,平台:2011年12月20日21:14:45
版权所有(c) 2001, 2005, Oracle。保留所有权利。
TNS-04302: Trace Assistant用法错误:文件名缺失。
用法: trcasst [options] <filename>
[options] 默认值为-odt -e0 -s
<filename> 总是最后一个参数
-o[c|d][u|t][q] Net服务和TTC信息
[c] Net服务信息概要
[d] 详细的Net服务信息
[u] TTC信息概要
[t] 详细的TTC信息
[q] SQL命令(与u一起使用)
-s 统计数据
-e[0|1|2] 错误信息,默认为0
[0] 转换NS错误数
[1] 转换错误
[2] 没有转换的错误数
-l[a|i <connection_id>] 连接信息
[a] 列出跟踪文件中的所有连接
[i <connection_id>] 对指定的连接进行解码
D:\oracle\NETWORK\trace>dir
驱动器D中的卷没有标签。
卷的序列号是2294-1384
D:\oracle\NETWORK\trace的目录
2011-12-20 19:49 <DIR> .
2011-12-20 19:49 <DIR> ..
2011-12-20 19:50 315,912 listener.trc
1个文件 315,912字节
2个目录48,617,730,048可用字节
--将分析结果输出到res.txt文件中。
D:\oracle\NETWORK\trace>trcasst listener.trc>res.txt
D:\oracle\NETWORK\trace>
生成文件中:
Trace Assistant 实用程序: 版本10.2.0.1.0 正式版, 平台:2011年12月20日20:53:49
版权所有 (c) 2001, 2005, Oracle。保留所有权利。
*************************************************************************
* Trace Assistant *
*************************************************************************
3、Trace文件处理报告解析
本节介绍trace分析报告内容。大体上,分析报告有四部分内容:
ü 发送send信息部分
---> Send 88 bytes - Redirect packet timestamp=20-12月-2011 19:49:16:250
Redirect data length: 78
Redirect Data: (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(PIPENAME=\\.\pipe\NTN_D9C_D5ECB31F.ORA)))
ü 接受receive信息部分
<--- Received 207 bytes - Connect packet timestamp=20-12月-2011 19:50:31:171
Current NS version number is: 313.
Lowest NS version number can accommodate is: 300.
Global options for the connection:
Don't care
Maximum SDU size: 2048
Maximum TDU size: 32767
NT protocol characteristics:
Asynchronous mode
Callback mode
Test for more data
Full duplex I/O
Line turnaround value: 0
Connect data length: 149
Connect data offset: 58
Connect data maximum size: 2040
Disable NA services on this connection
No NA services are linked in
Disable NA services on this connection
No NA services are linked in
(DESCRIPTION=(CONNECT_DATA=(CID=(PROGRAM=)(HOST=)(USER=Administrator))
(COMMAND=trace)(TRACE=off)(ARGUMENTS=64)(SERVICE=LISTENER)(VERSION=169
869568)))
ü 错误信息
对连接运行中出现的错误,也会给予显示和解析。
///
Error found. Error Stack follows:
id:4
Operation code:72
NS Error 1:12586
NS Error 2:0
NT Generic Error:0
Protocol Error:0
OS Error:0
NS & NT Errors Translation
TNS-04315: Trace Assistant内部错误: Can't find resource for bundle oracle.net.trcasst.mesg.TnsError, key 12586
/
00000, 00000 "不是错误"
// *原因: 一切操作正常。
// *操作: 不必着急: 尽管放心。
/
00000, 00000 "不是错误"
// *原因: 一切操作正常。
// *操作: 不必着急: 尽管放心。
/
///
ü 统计信息
----------------------
跟踪文件统计数据:
----------------------
开始时间戳: 20-12月-2011 19:49:12:031
结束时间戳: 20-12月-2011 19:50:31:171
会话总数: 13
数据库:
操作计数: 打开次数 0, 语法分析次数 0, 执行次数 0, 提取次数 0
ORACLE NET SERVICES:
总调用数: 已发送 18 个, 已接收 16 个, 0 oci
总字节数: 已发送 3205 字节, 已接收 3583 字节
平均字节数: 每包发送 178 字节, 每包接收 223 字节
最大字节数: 已发送 965 字节, 已接收 714 字节
总计包数: 已发送 18 个, 已接收 16 个
如果存在问题,我们就可以从中发现这个跟踪时间段系统的工作情况。
相关阅读:
- 监听器控制程序lsnrctl跟踪trace file (realkid4, 2011-12-19)
- oracle sqr之多个procedure过程变量传递及同名变量定义 (wisdomone1, 2011-12-20)
- oracle游标使用的方方面面 (OraFige, 2011-12-20)
- ORACLE常用结构和函数使用方法总结 (OraFige, 2011-12-20)
- DBA常用的一些SQL和视图 (OraFige, 2011-12-20)
- oracle select for update (OraFige, 2011-12-20)
- oracle查询语句大全 (OraFige, 2011-12-20)
- oracle sqr之基于oracle表分组列打印不同.LIS文件 (wisdomone1, 2011-12-20)
- Oracle Database 11gR2 Preinstallation Setup on OEL5 (x86_64) (Rodery, 2011-12-20)