javaee论坛

普通会员

225648

帖子

324

回复

338

积分

楼主
发表于 2017-07-31 11:25:57 | 查看: 1606 | 回复: 2


一、概述 

 

通常,DBA 确定通过 Oracle 的顶级活动会话图确定 Top SQL,有了 SQL 的执行会话信息和 SQL 文本,可以和开发人员确定 Top SQL 来自哪些应用模块的。有时候,Oracle DBA 需要自己确认 SQL 的来源,本文将演示如何使用 Oracle 提供丰富的跟踪功能,来确认递归 SQL 的调用者来源。

 

二、问题描述 

 

通过顶级会话页面,DBA 发现一个异常的 Top SQL,SQL ID 为c7452agj0s0t6,消耗了9%的数据库时间。

 

20161128100430811.jpg

 

通过 SQL 详情页面,可以确定 SQL c7452agj0s0t6 的用户名和模块,但是没有确定 SQL c7452agj0s0t6 是哪个客户机器造成的。

 

20161128100450144.jpg

 

从 SQL 的文本中,这是一个针对系统视图 V$ACTIVE_SESSION_HISTORY 的查询。

SELECT GROUP_TYPE, BUCKET_START, BUCKET_END, TM_GROUP_TYPE, TM_BUCKET_START,

      TM_BUCKET_END, SUM(TM_CPU_FIRST_BUCKET_VALUE) TM_CPU_FIRST_BUCKET_VALUE,

      SUM(TM_CPU_MIDDLE_BUCKETS_VALUE) TM_CPU_MIDDLE_BUCKETS_VALUE,

... 省略大量 SQL 文本

    FROM TABLE(SYS.GV$(CURSOR(

... 省略大量 SQL 文本       

    SELECT ASH0.*

    FROM V$ACTIVE_SESSION_HISTORY ASH0

... 省略大量 SQL 文本

 

通过 SQL 的活动会话信息,可以确定执行该 SQL 的进程为后台 PZ 进程,这些会话的 QC(query coordinator)不为空,也就是这是针对视图 V$ACTIVE_SESSION_HISTORY 的并行查询造成的。因为执行时间很短,并且执行此 SQL 的会话为短连接,无法查询到 QC 会话的来源。

 

20161128100505547.jpg

 

三、SQL ID 级别的跟踪分析 

 

为了确定 SQL c7452agj0s0t6 的来源,我们使用 Oracle 11g 中的新功能,对单个 SQL ID 打开10046事件跟踪,命令如下:

alter system set events 'sql_trace [sql:c7452agj0s0t6] wait=true,bind=true,plan_stat=all_executions,level=12';

 

通过以下查询确定 trace 文件的产生目录:

select value from v$diag_info where name='Default Trace File';

 

对最新生成的 PRDDB_oraxxx.trc 执行 grep c7452agj0s0t6,找到跟踪文件如下,可以确定该的客户端为 testapp。通过 dep=2,知道 SQL c7452agj0s0t6 为深度二级的递归 SQL,并不是用户直接提交的 SQL。我们依然不知道这个递归 SQL 具体由什么 SQL 调用的。

*** 2016-10-14 09:34:13.921

*** SESSION ID:(329.41269) 2016-10-14 09:34:13.921

*** CLIENT ID:() 2016-10-14 09:34:13.921

*** SERVICE NAME:(PRDDB) 2016-10-14 09:34:13.921

*** MODULE NAME:(python@testapp (TNS V1-V3)) 2016-10-14 09:34:13.921

*** ACTION NAME:() 2016-10-14 09:34:13.921

... 省略大量文本

=====================

PARSING IN CURSOR #139987897061528 len=11079 dep=2 uid=87 oct=3 lid=87 tim=1476408854404253 hv=3792438054 ad='21b01ba960' sqlid='c7452agj0s0t6'

 

关闭 SQL ID 跟踪的命令如下:

alter system set events 'sql_trace [sql:c7452agj0s0t6] off';

 

四、会话级别的跟踪分析 

 

为了确认什么 SQL 调用了 c7452agj0s0t6,我们需要在会话级别打开10046跟踪,因为执行 SQL c7452agj0s0t6 的会话是短连接,我们创建一个针对用户 APPUSER 的 logon 触发器,下次这个用户登录时会启动10046跟踪。

create or replace trigger sys.set_trace

after logon on database

when (user in ('APPUSER'))

declare

begin

execute immediate 'alter session set statistics_level=all';

execute immediate 'alter session set max_dump_file_size=unlimited';

execute immediate 'alter session set events ''10046 trace name context forever, level 12''';

end set_trace;

/

 

接着,在跟踪文件目录中找到最新生成的跟踪文件 PRDDB1_ora_10452.trc 包含 SQL ID c7452agj0s0t6。接着我们使用 orasrp 这个工具分析10046跟踪文件. orasrp 为 Oracle Session Resource Profiler,出自一位俄罗斯 DBA 的强大的10046分析工具,网址为:http://oracledba.ru/orasrp/

orasrp PRDDB1_ora_10452.trc PRDDB1_ora_10452.html

 

orasrp相对于 Oracle 自带的 tkprof,功能更加强大,其中一大优势是会生成会话的递归调用树。递归调用树(Session Call Graph)部分如下图,SQL hash value=3792438054 为 SQL c7452agj0s0t6,深度为2,顶级的 SQL hash value = 2036392974。

 

20161128100518405.jpg

 

顶级 SQL 文本如下,原来 SQL c7452agj0s0t6 是由 dbms_sqltune.report_sql_monitor 这个生成 SQL Monitor 报告的函数递归调用的。确定是前几天新部署的监控 job,在后台定时抓取和保存新生成的 SQL monitor 报告,但是执行过于频繁。解决的方法为降低后台 job 的执行频率,对每次抓取 SQL monitor 的执行时间提高限制。

select dbms_sqltune.report_sql_monitor(type=>:1, sql_id=>:2, sql_exec_id=>:3, report_level=>'ALL') monitor_report from dual;

 

确定问题来源之后,删除 logon 触发器,避免过多的跟踪文件产生:

drop trigger sys.set_trace;

 

五、总结 

 

本文演示了如果在 Oracle 中分别使用 SQL ID 和会话级别的10046跟踪,以确定递归 SQL 的调用源头来自 PL/SQL 函数 dbms_sqltune.report_sql_monitor。现实工作中,使用类似的方法,可以对 PL/SQL 代码性能,Oracle 解析时间过长等疑难杂症进行分析。对于 DBA 来说,使用 orasrp 对10046跟踪文件生成的递归调用树,也是研究应用负载特征的一个好手段。



您的帖子在2017-07-31 11:29:44被admin编辑
超级管理员"admin"于2017-07-31 11:29:56将帖子从“杂七杂八”板块“杂七杂八”主题移动到“数据库知识”板块“oracle”主题

普通会员

0

帖子

292

回复

293

积分
沙发
发表于 2019-12-17 18:52:34

楼主节操掉了,还不快捡起来

普通会员

0

帖子

307

回复

317

积分
板凳
发表于 2024-03-17 08:31:16

楼主节操掉了,还不快捡起来

您需要登录后才可以回帖 登录 | 立即注册

触屏版| 电脑版

技术支持 历史网 V2.0 © 2016-2017