select count(*) from dba_objects a ,dba_objects b where rownum<20000000;
COUNT(*)
----------
19999999
Elapsed: 00:00:14.27
select username,sql_id,sid,sql_text,cpu_time,buffer_gets,disk_reads from v$sql_monitor where sql_id='03pnx6pjjsp5a';
USERNAME SQL_ID SID SQL_TEXT CPU_TIME BUFFER_GETS DISK_READS
--------------- -------------------------- ------ ------------------------------------------------ ---------- ----------- ----------
TEST 03pnx6pjjsp5a 2475 select count(*) from dba_objects a ,dba_objects 15539637 257848 0
b where rownum<20000000
不出所料,执行过程信息也被成功捕获到了。
我们还可以通过SQL调优包DBMS_SQLTUNE的REPORT_SQL_MONITOR函数来获取更加详细的信息:
test@DLSP>select DBMS_SQLTUNE.REPORT_SQL_MONITOR(
2 session_id=>nvl('&&sid',sys_context('userenv','sid')),
3 session_serial=>decode('2475',null,null,
4 sys_context('userenv','sid'),(select serial# from v$session where audsid = sys_context('userenv','sessionid')),
5 null),
6 sql_id=>'03pnx6pjjsp5a',
7 sql_exec_id=>'16777217',
8 report_level=>'ALL')
9 as report
10 from dual;
REPORT
------------------------------------------------------------------------------------------------------------------------------------------------------
SQL Monitoring Report
SQL Text
------------------------------
select count(*) from dba_objects a ,dba_objects b where rownum<20000000
Global Information
------------------------------
Status : DONE (ALL ROWS)
Instance ID : 1
Session : TEST (2475:4035)
SQL ID : 03pnx6pjjsp5a
SQL Execution ID : 16777217
Execution Started : 07/11/2014 14:37:17
First Refresh Time : 07/11/2014 14:37:23
Last Refresh Time : 07/11/2014 14:37:31
Duration : 14s
Module/Action : SQL*Plus/-
Service : SYS$USERS
Program : sqlplus@wxlab30 (TNS V1-V3)
Fetch Calls : 1
Global Stats
=================================================
| Elapsed | Cpu | Other | Fetch | Buffer |
| Time(s) | Time(s) | Waits(s) | Calls | Gets |
=================================================
| 14 | 14 | 0.00 | 1 | 421K |
=================================================
SQL Plan Monitoring Details (Plan Hash Value=3737909826)
===================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Mem | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | (Max) | (%) | (# samples) |
===================================================================================================================================================
| 0 | SELECT STATEMENT | | | | 9 | +6 | 1 | 1 | | | |
| 1 | SORT AGGREGATE | | 1 | | 9 | +6 | 1 | 1 | | | |
| 2 | COUNT STOPKEY | | | | 9 | +6 | 1 | 20M | | | |
| 3 | NESTED LOOPS | | 26G | 443K | 9 | +6 | 1 | 20M | | | |
| 4 | VIEW | DBA_OBJECTS | 1304 | 48 | 9 | +6 | 1 | 1303 | | | |
| 5 | UNION-ALL | | | | 9 | +6 | 1 | 1303 | | | |
| 6 | FILTER | | | | 9 | +6 | 1 | 1303 | | | |
| 7 | HASH JOIN | | 1303 | 47 | 9 | +6 | 1 | 1303 | 2M | | |
| 8 | INDEX FULL SCAN | I_USER2 | 42 | 1 | 1 | +6 | 1 | 42 | | | |
| 9 | HASH JOIN | | 1303 | 46 | 9 | +6 | 1 | 1303 | 1M | | |
| 10 | INDEX FULL SCAN | I_USER2 | 42 | 1 | 1 | +6 | 1 | 42 | | | |
| 11 | TABLE ACCESS FULL | OBJ$ | 1303 | 44 | 9 | +6 | 1 | 1303 | | | |
| 12 | NESTED LOOPS | | 1 | 2 | | | | | | | |
| 13 | INDEX FULL SCAN | I_USER2 | 1 | 1 | | | | | | | |
| 14 | INDEX RANGE SCAN | I_OBJ4 | 1 | 1 | | | | | | | |
| 15 | NESTED LOOPS | | 1 | 1 | | | | | | | |
| 16 | INDEX FULL SCAN | I_LINK1 | 1 | | | | | | | | |
| 17 | INDEX RANGE SCAN | I_USER2 | 1 | 1 | | | | | | | |
| 18 | VIEW | DBA_OBJECTS | 20M | 340 | 9 | +6 | 1303 | 20M | | | |
| 19 | UNION-ALL | | | | 9 | +6 | 1303 | 20M | | | |
| 20 | FILTER | | | | 9 | +6 | 1303 | 20M | | 14.29 | Cpu (2) |
| 21 | HASH JOIN | | 20M | 339 | 13 | +2 | 1303 | 20M | 1M | 42.86 | Cpu (6) |
| 22 | NESTED LOOPS | | 1764 | 12 | 9 | +6 | 1303 | 2M | | | |
| 23 | INDEX FULL SCAN | I_USER2 | 42 | 1 | 9 | +6 | 1303 | 54726 | | | |
| 24 | INDEX FAST FULL SCAN | I_USER2 | 42 | | 12 | +3 | 54726 | 2M | | 7.14 | Cpu (1) |
| 25 | TABLE ACCESS FULL | OBJ$ | 20M | 170 | 14 | +1 | 1303 | 20M | | 35.71 | Cpu (5) |
| 26 | NESTED LOOPS | | 1 | 2 | | | | | | | |
| 27 | INDEX FULL SCAN | I_USER2 | 1 | 1 | | | | | | | |
| 28 | INDEX RANGE SCAN | I_OBJ4 | 1 | 1 | | | | | | | |
| 29 | NESTED LOOPS | | 1 | 1 | | | 1302 | | | | |
| 30 | INDEX FULL SCAN | I_LINK1 | 1 | | | | 1302 | | | | |
| 31 | INDEX RANGE SCAN | I_USER2 | 1 | 1 | | | | | | | |
===================================================================================================================================================
通过v$sql_monitor你还可以非常容易获取SQL语句所使用的绑定变量值。
test@DLSP>var a number
test@DLSP>select count(*) from dba_objects a ,dba_objects b where rownum
test@DLSP>exec :a :=20000000
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.00
test@DLSP>select count(*) from dba_objects a ,dba_objects b where rownum< :a;
COUNT(*)
----------
19999999
Elapsed: 00:00:15.69
test@DLSP>@findsql
Enter value for sql_text: %:a%
Enter value for sql_id:
SQL_ID CHILD PLAN_HASH EXECS AVG_ETIME AVG_LIO SQL_TEXT
-------------------------- ------ ---------- ---------- ------------- ------------ ------------------------------------------------------------
dbcb4ghxxdxa9 0 2117244413 1 15.69 257,856 select count(*) from dba_objects a ,dba_objects b where rown
um< :a
test@DLSP>select xmltype(binds_xml) a from v$sql_monitor where sql_id='dbcb4ghxxdxa9';
A
--------------------------------------------------------------------------------------
20000000
你可能会有些需求,想对某些执行时间小于5秒的SQL进行监控(比如为了获取绑定变量,为了了解这个SQL执行时候的性能状况)你可以通过以下两种方式来达到目的:
修改隐含参数_sqlmon_threshold的阀值来具体设定对执行时间超过设定值的SQL进行监控,不建议以这种方式进行监控。不过就像一开头提到的,此隐含参数的单位为s,对于运行时间小于s的SQL,就无能为力了。
通过为SQL添加hint /*+ monitor */来进行,有多种方式可以在不修改SQL语句的情况下,动态的添加hint到相应的SQL上,例如:sql profile ,baseline,sql patch等等,我最喜欢的是sql profile,对SQL添加/*+ monitor */hint后,就可以从相关的数据字典视图获取这个SQL的监控信息,监控完成后,删除sql profile/baseline/sql patch。例如:
test@DLSP>select count(*) from a;
COUNT(*)
----------
15355
Elapsed: 00:00:00.00
test@DLSP>@findsql
Enter value for sql_text: %count(*) from a%
Enter value for sql_id:
SQL_ID CHILD PLAN_HASH EXECS AVG_ETIME AVG_LIO SQL_TEXT
-------------------------- ------ ---------- ---------- ------------- ------------ ------------------------------------------------------------
0a7q9v9nd2qc1 0 3747789477 1 .00 1 select count(*) from association$ where obj# = :1
68bgnf5vcx08y 0 3918351354 2 .01 205 select count(*) from a
@DLSP>select username,sql_id,sid,sql_text,cpu_time,buffer_gets,disk_reads from v$sql_monitor where sql_id='68bgnf5vcx08y';
no rows selected
可以看到由于SQL执行时间太短,还没被监控到。
@DLSP>@profile
Enter value for sql_id: 68bgnf5vcx08y
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 68bgnf5vcx08y, child number 0
-------------------------------------
select count(*) from a
Plan hash value: 3918351354
-------------------------------------------------------------------
| Id | Operation | Name | Rows | Cost (%CPU)| Time |
-------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | 21944 (100)| |
| 1 | SORT AGGREGATE | | 1 | | |
| 2 | TABLE ACCESS FULL| A | 1000K| 21944 (1)| 00:04:24 |
-------------------------------------------------------------------
Outline Data
-------------
/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE('11.2.0.3')
DB_VERSION('11.2.0.3')
OPT_PARAM('_optim_peek_user_binds' 'false')
OPT_PARAM('_optimizer_skip_scan_enabled' 'false')
ALL_ROWS
OUTLINE_LEAF(@"SEL$1")
FULL(@"SEL$1" "A"@"SEL$1")
END_OUTLINE_DATA
*/
30 rows selected.
Enter value for hint_text: monitor
Profile profile_68bgnf5vcx08y_dwrose created.
test@DLSP>select count(*) from a;
COUNT(*)
----------
15355
1 row selected.
select username,sql_id,sid,sql_text,cpu_time,buffer_gets,disk_reads from v$sql_monitor where sql_id='68bgnf5vcx08y';
USERNAME SQL_ID SID SQL_TEXT CPU_TIME BUFFER_GETS DISK_READS
--------------- -------------------------- ---------- ------------------------------------------------ ---------- ----------- ----------
TEST 68bgnf5vcx08y 2475 select count(*) from a 8999 205 15
可以看到添加过/*+ monitor */ hint的SQL已经成功被ORACLE监控到了,最后删除这个SQL的 SQL PROFILE
exec DBMS_SQLTUNE.drop_sql_profile('profile_68bgnf5vcx08y_dwrose')
默认的Real Time SQL Monitoring对于每个捕获的SQL最多捕获480次(11gr1),640次(11gr2)执行时的信息。此行为通过隐含参数_sqlmon_max_plan来控制,不建议把此值设置的过大,以免占用过多的SGA的内存。
例如以下是我在11GR2下做的测试:
declare
c number;
begin
for i in 1 .. 1000 loop
select /*+ monitor */ count(*) into c from test;
end loop;
end;
/
@DLSP>@findsql
Enter value for sql_text: %from test
Enter value for sql_id:
SQL_ID CHILD PLAN_HASH EXECS AVG_ETIME AVG_LIO SQL_TEXT
-------------------------- ------ ---------- ---------- ------------- ------------ ------------------------------------------------------------
4kn8gdu4v7nxc 0 1950795681 2000 .00 207 SELECT /*+ monitor */ COUNT(*) FROM TEST
@DLSP>select count(*) from v$sql_monitor where sql_id='4kn8gdu4v7nxc';
COUNT(*)
----------
640
虽然SQL执行了1000次,但是v$sql_monitor中只记录了640次此SQL的执行信息。