Oracle Real Time SQL Monitoring

Oracle Real Time SQL Monitoring


术语说明

  • Table Queue,消息缓冲区,在并行操作中使用,用于PX进程之间的通信,或者PX进程与QC进程之间的通信,是内存中的一些page,每个消息缓冲区的大小由参数parallel_execution_message_size控制,11GR2版本默认为16K,之前的各个大版本这个值都不一样,详细请参考ORACLE官方文档。
  • 墙面时间、持续时间指的是物理时间、钟表时间。
  • HASH JOIN左边,the build side of hash join,一般为小表。
  • HASH JOIN右边,the probe side of hash join,一般为大表。
  • M代表百万
  • 行源 row source,指的是执行计划特定的一行操作,例如
-----------------------------------------------------------------------------
| Id  | Operation            | Name | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |      |     1 |    10 | 59167   (1)| 00:00:03 |
|   1 |  SORT AGGREGATE      |      |     1 |    10 |            |          |
|*  2 |   COUNT STOPKEY      |      |       |       |            |          |
|   3 |    NESTED LOOPS      |      |   100 |  1000 | 59167   (1)| 00:00:03 |
|   4 |     TABLE ACCESS FULL| TEST |   126K|   619K|     2   (0)| 00:00:01 |
|*  5 |     TABLE ACCESS FULL| TEST |     1 |     5 |   592   (1)| 00:00:01 |
-----------------------------------------------------------------------------

上面执行计划的第一列,Id列0-5,每一行都是一个行源

概述

Oracle每个版本总有一些新特性惊艳到我们,SQL MONITORING对我来说就是这样一个新特性,虽然它还未广为人知,它在11GR1版本被提供,而且后续的几个版本(11GR2,12CR1)这个功能也被不断的加强,说明ORACLE对它非常的重视,它能够把查询 涉及到的所有关键性能统计信息集中在一个页面上,特别是对于并行查询的语句会自动启用这个特性。这个功能在国外的ORACLE 用户组被多次的分享,但是目前国内对它的介绍还非常少,本文主要介绍Oracle Real Time SQL Monitoring的核心特性,意图使DBA能够有一种新的手段(更先进的手段)来诊断SQL性能,进而提升优化效率。

SQL优化是一个DBA必备的技能,然而即使一个有丰富SQL优化经验的老DBA估计碰到几十行甚至上百行的执行计划也要皱皱眉头,他如何能快速知道:

  • 在这么庞大的执行计划中哪一行源消耗的资源最多。如果一个SQL的执行计划包含5个行源,行源1消耗的DB TIME占取了3%,那你即使把这3%的DB TIME全部消灭掉,也只让SQL的性能提升了3%,对于整体的DB TIME提升效果并不明显。
  • 如何知道整个SQL执行过程中消耗的哪一类资源最多,IO?CPU?,这让我们对SQL的性能有一个整体的认识,你可能观察性能指标后会说,奥,这是一个IO比较重的SQL,如果需要大幅提升SQL性能,也许要考虑提升数据库系统IO的能力。
  • 对于一个正在执行的SQL语句,如何知道它当前执行到哪一步了?甚至知道执行完这一步还需要多久?
  • 如何知道执行这个SQL语句都经历了哪些等待事件,甚至知道这些等待里哪一类等待最为严重?

要想知道这些问题的答案,在11G之前都是非常不容易的,要通过各种V$视图的关联去获取,而且展示的结果不够一目了然。
11G以后这些信息全部可以在SQL MONITORING中找到答案,SQL MONITORING提供的功能还不仅仅是上面提到的这些,通过SQL MONITORING还可以轻松获取语句的绑定变量、监控索引的整个创建过程及创建完索引剩余的工作量。
文本会着重讲解SQL MONITORING的核心功能,其他的相关信息就请读者们去尽情挖掘吧。

什么SQL会被SQL MONITORING监控到

对于绝大多数OLTP系统来说,SQL相对比较简单,每次的运行时间都非常快,绝大部分SQL的响应时间都应该在10MS以下,优化的复杂度也比较低,SQL MONITORING功能的出现并不是为了帮助DBA发现、诊断OLTP SQL的性能问题,而是为了加快DBA优化数据仓库类SQL的效率,这些SQL是偏OLAP系统的,特点是并发量低、运行时间久、SQL复杂度高。满足以下条件的任意SQL都会被SQL MONITORING监控到:

  • 如果串行执行的SQL,消耗的CPU时间或IO时间超过5秒,那么这些SQL 将会被监控到,通过修改隐含参数_sqlmon_threshold可以控制这一行为,默认为5秒,如果设置为0将关闭SQL MONITORING功能 。注意我这里提到的是SQL消耗的CPU时间或IO时间,而不是SQL的执行时间,之所以需要限制CPU时间或IO时间是为了防止数据库某一时刻如果有大量lock/latch的话,那么将有大量的SQL满足5秒执行时间的条件,而SQL监控本身比较消耗资源,需要拷贝运行时的性能统计信息到SGA,每一个受监控的SQL都有一个单独的内存结构,在11G可能会导致大量的latch竞争,CPU飙高,12C对这个问题做了优化不存在该问题了。如果你发现你的SQL运行时间明显超过了5秒但是却没被SQL MONITORING监控到,那么你该仔细检查是否是由于SQL本身消耗的CPU或IO并没有超过5秒(由于锁、网络?)。
  • 并行执行的SQL将全部被监控到,不需要等待CPU或IO时间超过5秒。对于这一点也比较好理解,一般并行查询的SQL都是报表类或比较重的任务类的SQL,因此会自动打开SQL MONITORING的功能。
  • 增加HINT /+ monitor /的SQL会立即开启SQL MONITORING功能。

除了以上条件外,你还需要检查一些系统参数是否设置正确:

  • statistics_level需要为TYPICAL(默认)或者ALL.
  • control_management_pack_access需要为DIAGNOSTIC+TUNING(默认)

SQL MONITORING并不会监控非常大的执行计划,默认不会监控超过300行的执行计划,可以通过隐含参数_sqlmon_max_planlines来控制。具体请参照MOS ID:1613163.1

找到Real Time SQL Monitoring入口

可以从这几个位置找到、使用SQL Monitoring的功能:

  • Enterprise Manager
  • Enterprise Manager Cloud Control(EMCC)
  • SQL Developer
  • DBMS_SQLTUNE包

这里我们主要介绍通过Enterprise Manager Cloud Control(EMCC)页面来使用Real Time SQL Monitoring,文章的后面也会有单独一节简单介绍如何通过SQL包DBMS_SQLTUNE来获取Real Time SQL Monitoring的输出。

首先登陆Oracle EMCC,进入到【数据库】页面,选择你需要监控的数据库,这里以clouddb1为例:

enter image description here

进入到clouddb1数据库后,选择【性能】下的SQL监视功能。

enter image description here

然后就进入到了SQL MONTORING的主界面,这里包含了最近被监控到的SQL,查看状态列,可以知道SQL当前的执行状态。

enter image description here

状态列一般包含以下4种状态:运行、完成、排队、错误,将鼠标放在状态列的符号上面,会看到符号所代表的状态。这几个状态除了【排队】状态都比较好理解,排队这个状态只会在大于11GR2版本出现。ORACLE 11GR2在并行设置方面起了很大变化:自动并行度调整、并行语句队列、内存并行执行,启用此三项新特性需要设置参数parallel_degree_policy为auto,默认值为MANUAL。设置为auto后,三项新特性全部被打开,这里我们主要说下并行语句队列,启用该特性后,通过设置parallel_servers_target来指定总的可用的并行子进程的目标数,运行语句时,如果发现可用的并行进程数已经小于待运行语句的目标数,那么语句将会放入队列中等待直到拥有足够可用的并行进程。一单被加入队列,你就会在SQL MONITORING的监控页面上看到,语句的当前运行状态为【排队】。

SQL监视页面显示的SQL列表不是针对特定的SQL文本的,而是针对特定SQL语句的一次特定的执行,因此如果两个会话运行相同的语句,你会在此列表中看到两个单独的条目,因此它与v$sql的表现行为不一样,如果2个会话在运行同一个SQL,在 v$sql里只能对应到汇总了SQL执行统计信息的一个记录。针对SQL MONITOR的这个特点,允许你针对一个特定的用户(他正在抱怨性能问题)检查这个语句到底出了什么问题,而不是首先观察汇总了所有用户的语句级的性能指标,像V$SQL里的,再试着从中发现你所关注的用户问题。

详解Real Time SQL Monitoring

找到Real Time SQL Monitoring的入口后,可以点击SQL_ID进入到Real Time SQL Monitoring的展示页面,是不是很炫酷?

enter image description here

也许你对页面上的很多指标还感觉很陌生,别着急,我接下来会对页面上的核心部分进行介绍。

一般信息

enter image description here

一般信息部分显示了SQL执行的一些基本的细节,例如SQL的文本,SQL语句采用的并行度,SQL的执行开始时间,本次统计值最后一次的刷新时间,执行SQL的用户、取数操作等。注意【SQL文本】后带有…的标记(红色框标记),点击它,你会获得完整的SQL语句文本,从版本11.2.0.2开始,你还会看到绑定变量的值。
例如:

SQL>var c number
SQL>exec :c :=1
SQL>select /*+ parallel(a 6)*/ count(*) from hash_t1 a where id=:c;

  COUNT(*)
----------
         1

上面的代码我对一个带有绑定变量的SQL以并行度6执行了查询,然后通过EMCC的SQL MONITORING页面点击【SQL文本】后面部分的…,这时会出现一个新窗口:

enter image description here

点击show SQL Binds:

enter image description here

这时就可以看到绑定变量的列表,是不是非常的方便?
当然就像上面提到的,SQL MONITORING主要用于监控数据仓库类型的SQL,对于长时间运行查询,是否应该使用绑定变量是另外一个单独的话题,在数据仓库中,一般的最佳实践为:不该为长时间运行的查询使用绑定变量,因为相对于整个SQL的运行时间,SQL解析只占到可以忽略不计的时间,而且数据仓库的系统本身的SQL执行频率也非常低,因此我们可以考虑对所有查询都进行硬解析,即使这样会消耗掉一些响应时间(可以忽略不计),但我们尽可能保证每一组参数组合都能生成一个最优的执行计划,因为就绑定变量和文本常量来说,文本常量是最适合产生最优执行计划的。
言归正传,就像上面已经演示的,得到被监控查询的绑定变量值在Oracle 11.2.0.2或更高版本上变得容易,以前你可能需要查询v$sql_bind_capture,dba_hist_sqlbind来获取绑定变量的值(历史绑定值),甚至通过oradebug errorstack这类命令来获得当前运行SQL的正在使用的绑定变量的值,现在你终于可以抛弃这些方法了。
【一般信息】模块还包含了取数操作(fetch calls)的次数,简单来说它代表了数据库和应用端网络交互的次数,如果是count,sum这类操作,一般这个值为1,只需要一次网络交互,但是对于select *这样的查询,返回的数据量越大,这个值也会越大。

enter image description here

例如从上图我们知道,返回1000条记录一共分了11次才传输完成。每次传输90条记录。
取数操作我们在后面的章节还会继续讲到,这里先点到为止。

时间和等待统计信息

enter image description here

这一部分内容非常少,但是信息量非常大,显示的是持续时间、数据库时间和等待活动百分比。把鼠标移动到数据库时间的条状图上,会看到消耗在各类等待事件和CPU上的时间,这让你知道你的SQL时间都花哪了,是IO操作多,还是CPU操作多,这非常的棒。等待活动百分比条状图则显示了详细的等待事件分布,例如上图中蓝色部分代表整个语句执行过程中,45%的等待发生在direct path read temp这个等待事件上,注意这里等待活动百分比条状图的100(100%)指的是数据库里的等待事件时间,而不是整个数据库时间,即并不包括CPU时间,这部分的信息可以告诉DBA在SQL执行过程中,遭遇了哪些等待事件,以及这些等待事件占取的比例,当然,你应该关注这些等待事件里最为惹眼的。

你可能对持续时间和数据库时间的含义感到疑惑,没关系,我们接下来就会着重介绍这两个时间代表的含义和两者的差异:

持续时间

持续时间(墙面时间)是用户非常关注的时间,它显示一个语句已经处于活动状态多久,它代表着语句从开始执行直到结束的时间跨度,对于正在运行的语句,则是从开始执行到当前的时间。当然,最终用户可能还要等待更长的时间,因为除了数据库的响应时间之外,时间还可能会被花在应用系统上,或者是数据库和应用服务器之间的网络上。例如SQL的持续时间为5秒,但是应用本身处理这些数据需要1秒,那么用户端感受到的时间就可能是6秒,而不是数据库端看到的持续时间5秒。
需要再次强调的是,持续时间衡量的是从SQL开始执行即游标打开直到游标被关闭或取消的时间跨度,这意味着如果数据库1分钟内完成一个查询,但随后产生的数百万结果每次只能返回几行,从应用的角度看,这个查询将需要很长的时间(需要数百万次的网络传输)才能完成,但是数据库端只花了一点时间来处理。对于网络传输的情况,SQL MONITORING会有一个指标进行反应,就是上面已经提到过的取数操作(fetch calls),如果网络传输量比较大的话,这个值会比较大。

SQL>set autotrace traceonly
SQL>select /*+ monitor */ *  from hash_t1;

例如我通过monitor这个hint强制让ORACLE监控这个SQL,这个SQL会返回大量的结果集给客户端,我们通过EMCC来监控这个SQL的相关监控信息:

enter image description here

取数操作值非常大,因为数据库要跟应用(我们这里是SQLPLUS客户端)有大量的网络交互。

数据库时间

数据库时间即DB Time,显示的是一个查询在数据库中执行花费的总时间,就DML操作来说,一般数据库时间基本等于持续时间,因为DML操作不用返回结果集,没有网络交互时间,但是如果运行的是一个SELECT语句并返回很多行,那么持续时间一般会大于数据库时间,因为很多的网络时间会被统计在持续时间中,数据库会把数据分批发送给应用程序,因此对于一个select语句你可能会看到数据库时间只有30秒,而持续时间却有50秒,其中30秒用于服务你的请求,其余的时间数据库则是空闲的,等待应用取下一批数据。我们再次看一下上面已经使用过的一张图,对于这个查询来说,由于要返回大量的结果集给客户端,因此持续时间远远大于数据库时间。

enter image description here

对于串行查询来说,持续时间都是大于等于数据库时间的,但是对于并行查询来说,情况有所改变:当运行一个并行查询时,会有多个服务器进程(甚至可能是多个服务器上的服务器进程)参与进来,每个服务器进程都可以使用单独的CPU资源,也就是1分钟的墙面时间(wall time),但是数据库时间可能有1*N分钟(N为CPU逻辑核数),并行查询最终的数据库时间可能会比持续时间(wall time)长的多。

enter image description here

这个语句的持续时间只有19秒,而数据库时间则有1.8分钟,从【一般信息】的Execution Plan部分可以看到这个语句是以并行度6来运行,这意味着数据库里有多个进程同时服务于这个查询,所有这些会话的数据库时间加上协调进程的时间都被汇总到了数据库时间中。数据库时间代表着大致有多少时间必须在数据库中完成,但是因为该语句是并行的,因此你其实不必等待那么长的时间。

IO统计信息

enter image description here

显示了语句执行时的一些关键的IO统计信息。
缓冲区获取数,即buffer gets,显示了数据库层的逻辑IO总数。IO请求包含了总的IO请求次数,例如db file sequential read,db file scattered read,direct path read等等的次数,IO字节代表了读取/写入的IO的总字节数。通过条状图的不同有颜色部分,能获取到更详细的统计值,例如上图中显示10GB的IO字节,其中有42%是读取请求产生的,等等。
需要注意的是,这里的IO请求次数和IO字节数统计可能超出你的预期,例如针对一个1G表的全表扫描按照某个字段排序,不但要统计表本身的IO,而且还要统计排序产生的读、写临时段的IO。

详细信息

enter image description here

详细信息页本身包含了一些子tab页面,例如上图中包含了【计划统计信息】、【计划】、【并行】、【活动】、【度量】子tab页。详细信息页主要包含了执行计划在在行源(rowsource)细节上的一些统计信息。
首先我们先看下页面的最左侧一列,如果某个行源操作是被并行执行的,会用多个小人的图标标识,相反如果是被串行执行的会用一个小人的图标标识,如果你观察仔细的话,会发现多个小人的图标有时也会有颜色的区分(下图),这是因为并行执行中,生产者和消费者角色的不同导致的。例如图中的红色是生产者负责扫描表,而图中蓝色的进程是消费者负责把接收过来的数据做排序。
再者,我们会看到多人小图标的后面有向右箭头的指示,这个代表了目前的查询正在进行,执行计划正在执行到这个(些)行源(右箭头所在的行源),也就是通过SQL MONITORING可以知道目前执行计划执行到了哪一个行源,nice job!如果SQL执行结束,或者这个(些)行源执行结束,这些向右的小箭头也会消失。

enter image description here

然后我们关注下【估计行数】和【实际行数】,如果两者差异巨大,可能是由于你的数据库系统统计信息缺失或者陈旧,或者是优化器自身的算法导致。这里我并不会介绍CBO优化的相关信息,读者可以自行参阅相关文章。【实际行数】列真实的反应了扫描进程需要产生的工作量。

虽然Oracle CBO技术发展了这么久,相关书籍、文章也非常多,但是笔者认为,阅读、了解CBO最好的书籍仍然是jonathon lewis的基于成本的ORACLE优化法则,不过中文版貌似已经买不到了。

【时间表列】(Timeline)是一个很重要的列,通过它可以知道这个SQL执行计划每一行活跃的时间段。上图中的Timeline列基于执行计划每一行的活动构造出了一个可视化的时间进度图,它基于ASH的采样,从ORACLE 11G开始,ASH基于SQL执行计划的每一行源收集信息,观察上图中Timeline列标题里的括号内的数字,它显示了这个SQL总的运行持续时间,在这里是21秒,现在很容易根据这个,然后观察每个行源上的条状图和条状图位置进行可视化的解析。
然后将我们的目光移动到【临时】列,它代表了SQL运行过程中消耗的临时表空间大小,如果发现SQL消耗的临时表空间非常大,可以查看是否并行度不够或者PGA参数设置过小,不过对于创建索引、大表HASH JOIN、SQL排序等操作来说,完全避免临时段的使用也是一件可望不可即的事。
【IO请求】列代表了每一个行源所产生的IO请求数,根据可视化的条形图,很容易发现哪一个行源产生了最多的IO请求。
【活动百分比】列代表了在此行源产生的等待,CPU也会被统计在内,它的数据是从ASH的基表v$active_session_history获取的,也就是说数据是采样而来的(1秒采样一次)。例如:

SQL>select /*+ parallel(a 6)*/ * from hash_t1 a ;
SQL>select sql_plan_line_id,event from v$active_session_history where sql_id='8s2vhn4cwv140';

SQL_PLAN_LINE_ID EVENT
---------------- ----------------------------------------
               6 direct path read
               6 direct path read
               6 direct path read
               6
               6 direct path read
               6 direct path read
               
SQL>desc v$active_session_history
 Name                               Null?    Type
 ---------------------------------- -------- -------------------
 SAMPLE_ID                                   NUMBER
 SAMPLE_TIME                                 TIMESTAMP(3)
 IS_AWR_SAMPLE                               VARCHAR2(1)
 SESSION_ID                                  NUMBER
 SESSION_SERIAL#                             NUMBER
 SESSION_TYPE                                VARCHAR2(10)
 FLAGS                                       NUMBER
 USER_ID                                     NUMBER
 SQL_ID                                      VARCHAR2(13)
 IS_SQLID_CURRENT                            VARCHAR2(1)
 SQL_CHILD_NUMBER                            NUMBER
 SQL_OPCODE                                  NUMBER
 SQL_OPNAME                                  VARCHAR2(64)
 FORCE_MATCHING_SIGNATURE                    NUMBER
 TOP_LEVEL_SQL_ID                            VARCHAR2(13)
 TOP_LEVEL_SQL_OPCODE                        NUMBER
 SQL_ADAPTIVE_PLAN_RESOLVED                  NUMBER
 SQL_FULL_PLAN_HASH_VALUE                    NUMBER
 SQL_PLAN_HASH_VALUE                         NUMBER
 SQL_PLAN_LINE_ID                            NUMBER
 SQL_PLAN_OPERATION                          VARCHAR2(30)
 SQL_PLAN_OPTIONS                            VARCHAR2(30)
 SQL_EXEC_ID                                 NUMBER
 SQL_EXEC_START                              DATE,

11G的v$active_session_history视图新增了SQL_PLAN_LINE_ID、SQL_PLAN_OPERATION、SQL_PLAN_OPERATION列,可以跟踪到具体发生等待的行源信息,非常有利用与DBA做性能诊断。上面SQL执行过程中,ASH共采样到了6条数据,其中五次等待事件为direct path read,一次为空,即为CPU操作。 SQL_PLAN_LINE_ID 代表产生等待的行源,这里为6,观察下图【行ID】列,ID为6的行源执行的正是全表扫描操作,【活动百分比】条状图显示了产生了5次的direct path read等待,与我们从ASH视图里查询的结果完全相符。

enter image description here

因此【活动百分比】列非常重要,通过此列,我们能够知道DB TIME的去向,例如上图中,绝大部分的DB TIME都会花在了全表扫描阶段。除了全表扫描行源,其他行源都为空,但是这并不代表其他行源没有花取数据库时间,而是因为这块的内容是依据ASH采样而来的,如果行源操作执行比较快的话,ASH就不容易捕获到。通过【活动百分比】列,我们可以定位到最消耗资源的行源,然后可以有针对性的做优化,达到事半功倍的效果。
我们来看【详细信息】 的【并行】tab页,这个页面汇集了每一个并行进程完成的工作,由于ORACLE的并行采用了生产者消费者模型,首先是按照实例做的分组,然后再按照生产者和消费者把进程做了分组,我的测试例子里,只有一个RAC节点实例,另一个节点被关闭了。

enter image description here

切换到【详细信息】的【活动】页,展示了从开始执行到结束执行时间跨度内,有多少进程处于活跃状态。由于我们设置了并行度6,因此可以从页面上看到SQL执行的后期大部分时间有6个进程处于活跃状态。

enter image description here

【详细信息】的【度量】页显示了查询 过程中对CPU、内存、IO的占用率。

enter image description here

这里我们基本上把SQL MONITORING的核心内容做了减少,这个页面包含了大量的信息,而且这个页面本身具有非常大的互动性,对这个页面你可以充分发挥你的好奇心,把你的鼠标尽情的放在任何一个可以放的位置,尽情发掘里面的宝藏。

通过SQL MONITORING监控索引创建过程

之所以专门写一节通过SQL MONITORING监控索引创建过程是源于一个客户的需求,他由于业务上的需要想要知道重建索引大概需要多久,即使不能知道准确的时间,也希望能大概知道索引创建开始后,已经完成了多少的工作,大约还有多少工作未完成 。如果是使用的11G版本 ,可以很轻松的通过SQL MONITORING实现这个需求。
索引的创建大体上分为两个阶段:第一,全表扫描过程 第二,排序创建索引过程。
我们这里给出一个索引创建的例子,为了保证可以让SQL MONITORING监控到这个语句,我使用了并行语句,当然也可以造取一个足够大的表来确保索引创建语句运行的时间足够长来开启SQL MONITOR功能 。

alter index tt rebuild online parallel 6;
enter image description here

索引创建开始后,我们观察SQL MONITORING页面的【详细信息】部分,【详细信息】页面的最左边列的多人图标显示了这是一个并行执行的语句,这里红色为生产者,负责扫描HASH_T1表,根据全表扫描行源(ID=8)的父操作PX BLOCK ITERATOR可以知道,PX SLAVE按照ROWID划分工作,每个PX SLAVE负责一部分数据块的扫描(我这里为分区表,并没有按照分区划分工作),扫描后的数据写入TQ10000 table queue,消费者PX SLAVE进程从table queue TQ10000读取数据,这样通过table queue TQ10000表,两组并行进程完成了数据的传递。消费者PX SLAVE把接收到的数据做排序并创建索引。

enter image description here

从上图可以看出,向右的箭头处于排序创建索引阶段(行源3,4,5),全表扫描阶段已经结束,正在进行排序和创建索引,根据【实际行数】列可以知道目前排序已经完成的行数是531K,而真正需要的排序量为47M,从其他行源可以知道需要排序的总量(ID=5-8的实际行数列都显示了这个信息)。接下来的工作就是刷新页面看排序的实际行数什么时候能够到47M了。【进度百分比】列显示了已经完成的百分比,这个对于工作量的估算非常的有意义。有一点比较遗憾,【进度百分比】对于很多操作都不能进行显示,很多时候【进度百分比】会在SQL运行过程中动态出现。不过对于索引创建来说,这个并不重要,根据真正的数据量和已经完成的排序量就能大概知道剩余的工作量。

enter image description here

刷新后已经完成了28M的排序工作。

enter image description here

再次刷新,发现索引创建已经完成,因为最左边的已经没有向右的箭头,而且实际行数(行源4)已经为47M,完成了所有数据的排序。我们观察【活动百分比】这一列,整个索引创建过程中,绝大部分的时间都消耗在ID=4这个行源上,即排序和创建索引操作上,从【时间表】(Timeline)列也可以看出它的活跃时间跨度也最长。

一个例子

上面介绍了相关的SQL MONITORING的核心特性,但是它只能协助我们发现性能问题,如何解决问题它并不能帮助到我们,解决问题的过程还需要我们具备各种SQL优化的技能,如CBO的知识,操作系统的知识等等。
我们来通过一个小例子来进阶我们对于SQL MONITORING的理解:
表的物理信息:
hash_t1 大小 4416M
查询语句

select /*+ parallel(6) pq_distribute(b broadcast none) */count(*)  from hash_t1 a,hash_t1 b where a.id=b.id;

SQL运行时间2分钟,由于使用了并行我们从上图可以看到DB TIME 12.6分钟远大于SQL运行时间2分钟。


enter image description here

根据【活动百分比】这一列看到HASH JOIN本身占取的数据库时间最多,达到了51%(ASH采样的结果),再仔细观察执行计划的相关内容,HASH JOIN的左边使用了广播的分发方式PX SEND BROADCAST,但是需要广播的数据量非常的大,有40M,由于采用了6个并发,因此广播之后,每一个PX进程都接收到了40M的数据量,因此总共的数据量为240M。HASH JOIN右边的表的数据量也是40M,跟HASH JOIN左边的表大小一样,数据的分发方式一般包括广播和HASH,12C新增加了replicat方式,对于HASH JOIN左边是小表的情况一般使用广播方式的分发,对于HASH JOIN的左边、右边都是大表的情况,一般使用HASH分发比较好。这里由于每个PX消费者进程都需要完整持有HASH JOIN左边表的数据,因此消耗的临时段的空间也比较大,达到了4GB。

enter image description here

我们来看下尝试使用HASH 分布效果怎么样:SQL运行时间从2分钟缩减到了1.3分钟,DB TIME也从12.6分钟缩减到了8.3分钟。

enter image description here

查看执行计划发现数据分发方式已经变为PX SEND HASH,使用了HASH分发的方式,观察【实际行数列】数据量也和表的记录数相同,临时表空间也从4GB大小缩减为966MB。HASH JOIN操作本身占取的活动百分比也从51%下降为22%。

enter image description here

相关视图

Grid Control上所有漂亮的图表都来源于v$或DBA_视图或许没有必要为日常监控和调优任务经常去访问这些v$视图,但知道这些信息来自哪里仍人是很有用处的,因为这会让自定义监控和对问题的高级诊断变得更方便,例如我所在的沃趣科技就在自动研发一套监控系统,也在考虑将SQL MONITORING这个功能增加到我们的监控产品里,如果能了解到这些功能的底层视图就对我们开发这个功能非常有好处。下面是一些要知道的关键视图:

  • GV$SQL_MONITOR视图包含了语句执行时的监控数据。当有多个会话在运行相同的语句时,这个视图会有多个记录与之对应,所以请确保使用了正确的搜索过滤条件来获得你所关注的SQL执行情况。例如,应该注意SID和INST_ID是不是你正在寻找的会话,对于并行执行则是PX_QCSID和PX_QCINST_ID,如果在诊断一条当前正在运行的查询,则要检查列status是否显示为executing状态。
  • GV$SQL_PLAN_MONITOR 视图包含了执行计划每一行的性能指标,这些指标会被实时监控和更新。
  • GV$ACTIVE_SESSION_HISTORY 视图从ORACLE 11GR1开始包含了如SQL_PLAN_LINE_ID、SQL_PLAN_OPERATION和SQL_PLAN_OPTIONS这些列。通过查询这些列,加上SQL_ID,就可以找到一个SQL执行计划中最显著的行源,而不仅仅找到最显著的执行计划。

控制SQL监控

对于并行执行的SQL,SQL监控会马上对他们启用,而不管他们运行的时间有多久。对于串行执行的SQL,SQL监控不会马上启用,因为SQL监控并不是用来监控通常运行速度很快的OLTP查询的,这类查询每秒都会被执行很多遍。然而,如果一个SQL串行查询消耗多余5S的CPU和IO等待时间,他将会被认为是一个长查询,SQL监控也会对此类查询启用。这是自动发生的,查询语句不需要重新运行。
可以使用提示MONITOR和NO_MONITOR来控制对一个语句的监控与否。如果你对某一个运行时间比较长的SQL不想做监控,可以使用NO_MONITOR这个HINT。需要注意有一个跟NO_MONITOR非常相像的HINT NO_MONITORING,它是与SQL MONITORING功能完全不相关的东西,通过NO_MONITORING这个HINT可以禁止对表里先关字段的谓词使用情况进行监控,这些监控数据会被放入到sys.col_usage$中。

SQL>SELECT NAME FROM V$SQL_HINT where name like '%MONITOR%';

NAME
---------------------
NO_MONITORING
MONITOR
NO_MONITOR

使用SQL获取SQL MONITORING的输出

经过上面一系列的介绍,我们再来看通过SQL包获取SQL MONITORING的输出就变得极为简单,这里我不会再花费笔墨来对输出做详细的解释,大部分的信息上面我都已经讲到过了。
这个主要是通过dbms_sqltune.report_sql_monitor来进行的。下面的SQL的含义是,把SQL_ID为4vnz8232nugv9的查询,最近的SQL MONITORING的信息以text格式打印出来:

col comm format a300
SELECT dbms_sqltune.report_sql_monitor(
sql_id => '4vnz8232nugv9',
report_level => 'ALL',
type=>'text'
) comm
FROM dual;

SQL Monitoring Report

SQL Text
------------------------------
select /*+ full(a) parallel(a 6)*/ count(*) from ORDER_ITEMS a

Global Information
------------------------------
 Status              :  DONE (ALL ROWS)
 Instance ID         :  1
 Session             :  SOE (857:1095)
 SQL ID              :  dgxh9275fun36
 SQL Execution ID    :  16777218
 Execution Started   :  08/24/2015 12:57:24
 First Refresh Time  :  08/24/2015 12:57:25
 Last Refresh Time   :  08/24/2015 12:57:40
 Duration            :  16s
 Module/Action       :  SQL*Plus/-
 Service             :  SYS$USERS
 Program             :  sqlplus@rac1 (TNS V1-V3)
 Fetch Calls         :  1

Global Stats
============================================================================================
| Elapsed |   Cpu   |    IO    | Application | Concurrency | Fetch | Buffer | Read | Read  |
| Time(s) | Time(s) | Waits(s) |  Waits(s)   |  Waits(s)   | Calls |  Gets  | Reqs | Bytes |
============================================================================================
|      90 |      16 |       73 |        0.00 |        0.29 |     1 |     3M | 185K |  22GB |
============================================================================================

Parallel Execution Details (DOP=6 , Servers Allocated=6)
===================================================================================================================================
|      Name      | Type  | Server# | Elapsed |   Cpu   |    IO     | Concurrency | Buffer | Read  | Read  |      Wait Events      |
|                |       |         | Time(s) | Time(s) | Waits(s)  |  Waits(s)   |  Gets  | Reqs  | Bytes |      (sample #)       |
===================================================================================================================================
| PX Coordinator | QC    |         |    0.30 |    0.01 |           |        0.29 |    139 |       |     . | os thread startup (1) |
| p000           | Set 1 |       1 |      15 |    2.69 |       12  |             |   498K | 30764 |   4GB | direct path read (10) |
| p001           | Set 1 |       2 |      15 |    2.72 |       12  |             |   498K | 30772 |   4GB | direct path read (10) |
| p002           | Set 1 |       3 |      15 |    2.71 |       12  |             |   498K | 30771 |   4GB | direct path read (11) |
| p003           | Set 1 |       4 |      15 |    2.78 |       12  |             |   498K | 30763 |   4GB | direct path read (11) |
| p004           | Set 1 |       5 |      15 |    2.68 |       12  |             |   498K | 30769 |   4GB | direct path read (11) |
| p005           | Set 1 |       6 |      15 |    2.71 |       12  |             |   498K | 30762 |   4GB | direct path read (12) |
===================================================================================================================================

SQL Plan Monitoring Details (Plan Hash Value=1446499772)
====================================================================================================================================
| Id |        Operation         |   Name     | Rows   | Cost |  Time    |Execs |   Rows   | Read |Activity |    Activity Detail    |
|    |                          |            |(Estim) |      |Active(s) |      | (Actual) | Reqs |  (%)    |      (# samples)      |
====================================================================================================================================
|  0 | SELECT STATEMENT         |            |        |      |        1 |    1 |        1 |      |         |                       |
|  1 |   SORT AGGREGATE         |            |      1 |      |        1 |    1 |        1 |      |         |                       |
|  2 |    PX COORDINATOR        |            |        |      |       16 |    7 |        6 |      |    1.18 | os thread startup (1) |
|  3 |     PX SEND QC (RANDOM)  |:TQ10000    |      1 |      |        2 |    6 |        6 |      |         |                       |
|  4 |      SORT AGGREGATE      |            |      1 |      |       14 |    6 |        6 |      |         |                       |
|  5 |       PX BLOCK ITERATOR  |            |   343M | 116K |       14 |    6 |     357M |      |         |                       |
|  6 |        TABLE ACCESS FULL |ORDER_ITEMS |   343M | 116K |       15 |   78 |     357M | 185K |   98.82 | Cpu (19)              |
|    |                          |            |        |      |          |      |          |      |         | direct path read (65) |
====================================================================================================================================

dbms_sqltune.report_sql_monitor包的type除了我例子给出的text外,还可以有HTML,ACTIVE(11GR2),XML。如果你想查看某个SQL历史的执行统计信息而不是最近一次的,可以通过指定SQL_EXEC_ID 参数来进行。详细可以参考:

https://oracle-base.com/articles/11g/real-time-sql-monitoring-11gr1#active_html_reports_offline

参考信息

  • ORACLE-BASE 著名ORACLE博客网站
  • TANEL PODER博客,ORACLE业界著名人物
  • ORACLE官方文档

作者信息

魏兴华,沃趣科技高级数据库技术专家,8年ORACLE数据库使用经验,Oracle ACE-A ,DBGEEK用户组联合创始人之一,ACOUG、SHOUG核心成员。ORACLE INTERNAL达人,原阿里高级数据库工程师,曾在ORACLE技术嘉年华、ORCL-CON、YY分享平台等公开场合多次做过数据库技术专题分享并获得好评。
个人邮箱:xinghua.wei@woqutech.com
DB GEEK QQ群:516293316
公司主页:www.woqutech.com

推荐阅读更多精彩内容