Trace

一.请求Trace

1、在定义并发程序时，启用"启用跟踪"(做完trace后记得关闭，否则会产生大量的trace文件)

2、根据请求ID，查看请求对应的trace文件对应路径

   SELECT 'Request id: ' || request_id,

       'Trace id: ' || oracle_process_id,

       'Trace Flag: ' || req.enable_trace,

       'Trace Name:' || dest.value || '/' || lower(dbnm.value) || '_ora_' ||oracle_process_id || '.trc',

       'Prog. Name: ' || prog.user_concurrent_program_name,

       'File Name: ' || execname.execution_file_name ||execname.subroutine_name,

       'Status : ' || decode(phase_code, 'R', 'Running') || '-' ||decode(status_code, 'R', 'Normal'),

       'SID Serial: ' || ses.sid || ',' || ses.serial#,

       'Module : ' || ses.module

  FROM fnd_concurrent_requests req,

       v$session ses,

       v$process proc,

       v$parameter dest,

       v$parameter dbnm,

       fnd_concurrent_programs_vl prog,

       fnd_executables execname

 WHERE 1 = 1

   AND req.request_id = &request

   AND req.oracle_process_id = proc.spid(+)

   AND proc.addr = ses.paddr(+)

   AND dest.name = 'user_dump_dest'

   AND dbnm.name = 'db_name'

   AND req.concurrent_program_id = prog.concurrent_program_id

   AND req.program_application_id = prog.application_id

   AND prog.application_id = execname.application_id

   AND prog.executable_id = execname.executable_id;

 

 

3、进去数据库服务器，可能该路径下存在大量trace文件导致卡死，可复制出来，再进行格式转换

   cd /u02/uat/db/11.2.0/admin/UAT_ebsdb/diag/rdbms/uat/UAT/trace 

   cp  UAT_ora_56282.trc  /u02/uat/db/11.2.0/admin/UAT_ebsdb/diag/rdbms/uat/UAT（若做trace成功，则可在该路径下查看到该trace文件）

   格式转换（trc转换成txt):

   tkprof /u02/uat/db/11.2.0/admin/UAT_ebsdb/diag/rdbms/uat/UAT/UAT_ora_56282.trc  explain=apps/apps          output=/u02/uat/db/11.2.0/admin/UAT_ebsdb/diag/rdbms/uat/UAT/UAT_ora_56282.txt   aggregate=yes sys=no sort=fchela

   

tracefile：你要分析的trace文件

outputfile：格式化后的文件

explain=user/password@connectstring（如果需要生成执行计划，需要这项，默认是没有执行计划的，只有Row Source Operation）

table=schema.tablename

   注1：这两个参数是一起使用的，通过连接数据库对在trace文件中出现的每条sql语句查看执行计划，并将之输出到outputfile中

   注2：该table必须是数据库中不存在的，如果存在会报错

print=n：只列出最初N个sql执行语句

insert=filename：会产生一个sql文件，运行此文件可将收集到的数据insert到数据库表中

sys=no：过滤掉由sys执行的语句

record=filename：可将非嵌套执行的sql语句过滤到指定的文件中去

waits=yes|no：是否统计任何等待事件

aggregate=yes|no：是否将相同sql语句的执行信息合计起来，默认为yes

sort=option：设置排序选项，选项如下：

    prscnt：number of times parse was called 

    prscpu：cpu time parsing

    prsela：elapsed time parsing

    prsdsk：number of disk reads during parse

    prsqry：number of buffers for consistent read during parse

    prscu：number of buffers for current read during parse

    prsmis：number of misses in library cache during parse

    execnt：number of execute was called

    execpu：cpu time spent executing

    exeela：elapsed time executing

    exedsk：number of disk reads during execute

    exeqry：number of buffers for consistent read during execute

    execu：number of buffers for current read during execute

    exerow：number of rows processed during execute

    exemis：number of library cache misses during execute

    fchcnt：number of times fetch was called

    fchcpu：cpu time spent fetching

    fchela：elapsed time fetching

    fchdsk：number of disk reads during fetch

    fchqry：number of buffers for consistent read during fetch

    fchcu：number of buffers for current read during fetch

    fchrow：number of rows fetched

    userid：userid of user that parsed the cursor

 

 

4.Trace日志分析

    

 

CALL：每次SQL语句的处理都分成以下三个部分
  Parse：这步将SQL语句转换成执行计划，包括检查是否有正确的授权和所需要用到的表、列以及其他引用到的对象是否存在。
  Execute：这步是真正的由Oracle来执行语句。对于insert、update、delete操作，这步会修改数据，对于select操作，这步就只是确定选择的记录。
  Fetch：返回查询语句中所获得的记录，这步只有select语句会被执行。 

SQL处理的不同的阶段

COUNT:这个语句被parse、execute、fetch的次数。
CPU：这个语句对于所有的parse、execute、fetch所消耗的cpu的时间，以秒为单位。
ELAPSED：这个语句所有消耗在parse、execute、fetch的总的时间。
DISK：执行物理I/O次数，从磁盘上的数据文件中物理读取的块的数量。一般来说更想知道的是正在从缓存中读取的数据而不是从磁盘上读取的数据。
QUERY：在意一致性检索方式获得块时，执行逻辑I/O次数；在一致性读模式下，所有parse、execute、fetch所获得的buffer的数量。一致性模式的buffer是用于给一个长时间运行的事务提供一个一致性读的快照，缓存实际上在头部存储了状态。
CURRENT：逻辑I/O次数，在current模式下所获得的buffer的数量。一般在current模式下执行insert、update、delete操作都会获取buffer。在current模式下如果在高速缓存区发现有新的缓存足够给当前的事务使用，则这些buffer都会被读入了缓存区中。
ROWS: 此阶段，被处理或受影响的行数，所有SQL语句返回的记录数目，但是不包括子查询中返回的记录数目。对于select语句，返回记录是在fetch这步，对于insert、update、delete操作，返回记录则是在execute这步。

分析：

• Query + Current = Logical Reads (total number of buffers accessed)

      query+current/rows 平均每行所需的block数，太大的话（超过20）SQL语句效率太低

• Parse count/Execute count parse count应尽量接近1，如果太高的话，SQL会进行不必要的reparse
• rows Fetch/Fetch Fetch Array的大小，太小的话就没有充分利用批量Fetch的功能，增加了数据在客户端和服务器之间的往返次数。
• disk/query+current 磁盘IO所占逻辑IO的比例，太大的话有可能是db_buffer_size过小(也跟SQL的具体特性有关)
• elapsed/cpu 太大表示执行过程中花费了大量的时间等待某种资源
• cpu　Or　elapsed 太大表示执行时间过长，或消耗了了大量的CPU时间，应该考虑优化
• 执行计划中的Rows 表示在该处理阶段所访问的行数，要尽量减少

• DISK是从磁盘上的数据文件中物理读取的块的数量。一般来说更想知道的是正在从缓存中读取的数据而不是从磁盘上读取的数据