解析listener跟踪文件

在上篇《监听器控制程序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 个

 

 

如果存在问题，我们就可以从中发现这个跟踪时间段系统的工作情况。