10046事件和tkprof命令

一.在ORACLE数据库里,我们通常可以使用如下这些方法(包括但不限于)得到目标SQL的执行计划:

1,explain plan

2,DBMS_XPLAN包

3,SQLPLUS中的AUTOTRACE开关

4,10046事件

5,10053事件

6,AWR报告或者STATSPACK报告

前面的四种方法比较普遍。

二.下面介绍下第四种即10046事件如何得到目标SQL的执行计划

10046与使用explain plan命令,DBMS_XPLAN包和AUTOTRACE开关的不同之处在于,所得到的执行计划中明确显示了目标SQL的实际执行计划中每一个步骤所消耗的逻辑度(cr:consistent read),物理读(pr:physical read)和花费的时间(time)。

用10046事件得到的目标SQL的执行计划只需要依次执行下面三步:

  • 在当前SESSION中激活10046事件
  • 在此SESSION中执行目标SQL
  • 在此SESSION中关闭10046事件

执行完上面的步骤后,ORACLE会将目标SQL的执行计划和明细资源消耗写入此SESSION对应的TRACE文件中,此文件一把会在USER_DUMP_DEST目录下,其命名格式是: 实例名_ora_当前SESSION的SPID.trc.

 通常可以用下面两种方法激活10046事件:

  • 在当前SESSION中执行alter session set events '10046 trace name context forever,level 12'
  • 在当前SESSION中执行oradebug event 10046 trace name context forever,level 12

对应的在当前SESSION中关闭10046事件的方法为:

  • alter session set events '10046 trace name context off'
  • oradebug event 10046 trace name context off

10046生成的TRACE文件,我们称之为裸文件(raw trace),ORACCLE 提供了工具TKPROF来查看他。下面我们来做一个实验来演示如何通过10046事件来获取和查看目标SQL的实际执行计划

 

三.以下面sql来说明10046事件:

SELECT e.last_name || ' ,' || e.first_name AS full_name,
       e.phone_number,
       e.email,
       e.department_id,
       d.department_id,
       c.country_name,
       l.city,
       l.state_province,
       r.region_name
  FROM hr.employees   e,
       hr.departments d,
       hr.countries   c,
       hr.locations   l,
       hr.regions     r
 WHERE e.department_id = d.department_id
   AND d.location_id = l.location_id
   AND l.country_id = c.country_id
   AND c.region_id = r.region_id;

 SQL> oradebug help

HELP           [command]                 Describe one or all commands
SETMYPID                                 Debug current process
SETOSPID       <ospid>                   Set OS pid of process to debug
SETORAPID      <orapid> ['force']        Set Oracle pid of process to debug
SHORT_STACK                              Dump abridged OS stack
DUMP           <dump_name> <lvl> [addr]  Invoke named dump
DUMPSGA        [bytes]                   Dump fixed SGA
DUMPLIST                                 Print a list of available dumps
EVENT          <text>                    Set trace event in process
SESSION_EVENT  <text>                    Set trace event in session
DUMPVAR        <p|s|uga> <name> [level]  Print/dump a fixed PGA/SGA/UGA variable
DUMPTYPE       <address> <type> <count>  Print/dump an address with type info
SETVAR         <p|s|uga> <name> <value>  Modify a fixed PGA/SGA/UGA variable
PEEK           <addr> <len> [level]      Print/Dump memory
POKE           <addr> <len> <value>      Modify memory
WAKEUP         <orapid>                  Wake up Oracle process
SUSPEND                                  Suspend execution
RESUME                                   Resume execution
FLUSH                                    Flush pending writes to trace file
CLOSE_TRACE                              Close trace file
TRACEFILE_NAME                           Get name of trace file
LKDEBUG                                  Invoke global enqueue service debugger
NSDBX                                    Invoke CGS name-service debugger
-G             <Inst-List | def | all>   Parallel oradebug command prefix
-R             <Inst-List | def | all>   Parallel oradebug prefix (return output
SETINST        <instance# .. | all>      Set instance list in double quotes
SGATOFILE      <SGA dump dir>         Dump SGA to file; dirname in double quotes
DMPCOWSGA      <SGA dump dir> Dump & map SGA as COW; dirname in double quotes
MAPCOWSGA      <SGA dump dir>         Map SGA as COW; dirname in double quotes
HANGANALYZE    [level] [syslevel]        Analyze system hang
FFBEGIN                                  Flash Freeze the Instance
FFDEREGISTER                             FF deregister instance from cluster
FFTERMINST                               Call exit and terminate instance
FFRESUMEINST                             Resume the flash frozen instance
FFSTATUS                                 Flash freeze status of instance
SKDSTTPCS      <ifname>  <ofname>        Helps translate PCs to names
WATCH          <address> <len> <self|exist|all|target>  Watch a region of memory
DELETE         <local|global|target> watchpoint <id>    Delete a watchpoint
SHOW           <local|global|target> watchpoints        Show  watchpoints
CORE                                     Dump core without crashing process
IPC                                      Dump ipc information
UNLIMIT                                  Unlimit the size of the trace file
PROCSTAT                                 Dump process statistics
CALL           <func> [arg1] ... [argn]  Invoke function with arguments

(a)SQL> oradebug setmypid
Statement processed.
(b)SQL> oradebug event 10046 trace name context forever,level 12
Statement processed.

(c)SELECT e.last_name || ' ,' || e.first_name AS full_name,

       e.phone_number,
       e.email,
       e.department_id,
       d.department_id,
       c.country_name,
       l.city,
       l.state_province,
       r.region_name
  FROM hr.employees   e,
       hr.departments d,
       hr.countries   c,
       hr.locations   l,
       hr.regions     r
 WHERE e.department_id = d.department_id
   AND d.location_id = l.location_id
   AND l.country_id = c.country_id
 18     AND c.region_id = r.region_id;


FULL_NAME PHONE_NUMBER     EMAIL       DEPARTMENT_ID DEPARTMENT_ID COUNTRY_NAME    CITY
----------------------------------------------- -------------------- ------------------------- ------------- ------------- ---------------------------------------- ------------------------------
STATE_PROVINCE  REGION_NAME
------------------------- -------------------------
OConnell ,Donald 650.507.9833     DOCONNEL  50 50 United States of America    South San Francisco
California  Americas

106 rows selected.

用oradebug tracefile_name命令就可以一目了然的看到当前session激活10046事件后所对应的trace文件的路径和名称:

SQL> oradebug tracefile_name;
/u01/app/oracle/diag/rdbms/mecbs/MECBS1/trace/MECBS1_ora_7389.trc

关掉10046事件:

SQL> oradebug event 10046 trace name context off
Statement processed.

查看/u01/app/oracle/diag/rdbms/mecbs/MECBS1/trace/MECBS1_ora_7389.trc文件

[oracle@node1 ~]$ cat /u01/app/oracle/diag/rdbms/mecbs/MECBS1/trace/MECBS1_ora_7389.trc
Trace file /u01/app/oracle/diag/rdbms/mecbs/MECBS1/trace/MECBS1_ora_7389.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/11.2.0/db_1
System name: Linux
Node name: node1
Release: 2.6.32-300.10.1.el5uek
Version: #1 SMP Wed Feb 22 17:37:40 EST 2012
Machine: x86_64
VM name: VMWare Version: 6
Instance name: MECBS1
Redo thread mounted by this instance: 1
Oracle process number: 36
Unix process pid: 7389, image: oracle@node1 (TNS V1-V3)--
*** 2014-11-25 09:44:22.203
*** SESSION ID:(13.9) 2014-11-25 09:44:22.203
*** CLIENT ID:() 2014-11-25 09:44:22.203
*** SERVICE NAME:(SYS$USERS) 2014-11-25 09:44:22.203
*** MODULE NAME:(sqlplus@node1 (TNS V1-V3)) 2014-11-25 09:44:22.203
*** ACTION NAME:() 2014-11-25 09:44:22.203
Processing Oradebug command 'event 10046 trace name context forever,level 12'
*** 2014-11-25 09:57:21.754

Processing Oradebug command 'tracefile_name'
PARSING IN CURSOR #140134982066512 len=497 dep=0 uid=0 oct=3 lid=0 tim=1416880688267812 hv=940757165 ad='720722b8' sqlid='1xhyf6hw15n5d'
SELECT e.last_name || ' ,' || e.first_name AS full_name,
       e.phone_number,
       e.email,
       e.department_id,
       d.department_id,
       c.country_name,
       l.city,
       l.state_province,
       r.region_name
  FROM hr.employees   e,
       hr.departments d,
       hr.countries   c,
       hr.locations   l,
       hr.regions     r
 WHERE e.department_id = d.department_id
   AND d.location_id = l.location_id
   AND l.country_id = c.country_id
   AND c.region_id = r.region_id
END OF STMT
PARSE #140134982066512:c=43992,e=88497,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=231184628,tim=1416880688267797

FETCH #140134982066512:c=0,e=226,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=231184628,tim=1416880688447535

c=cpu消耗时间,单位是毫秒
e=逃离时间,4.723秒
p=物理读次数
cr=consistent read一致性读
cu=db block gets当前读
mis=软解析的次数,错过缓存的次数。
r=表示这个SQL取到的行数
dep=递归调用的深度
og=optimizer mode 1表示CBO
tim=时间戳

STAT #140134982066512 id=1 cnt=106 pid=0 pos=1 obj=0 op='HASH JOIN  (cr=31 pr=0 pw=0 time=5298 us cost=11 size=10600 card=106)'
STAT #140134982066512 id=2 cnt=27 pid=1 pos=1 obj=0 op='HASH JOIN  (cr=18 pr=0 pw=0 time=4554 us cost=8 size=1593 card=27)'
STAT #140134982066512 id=3 cnt=27 pid=2 pos=1 obj=0 op='NESTED LOOPS  (cr=12 pr=0 pw=0 time=4857 us cost=5 size=1215 card=27)'
STAT #140134982066512 id=4 cnt=27 pid=3 pos=1 obj=0 op='MERGE JOIN  (cr=8 pr=0 pw=0 time=4148 us cost=5 size=810 card=27)'
STAT #140134982066512 id=5 cnt=19 pid=4 pos=1 obj=88049 op='TABLE ACCESS BY INDEX ROWID LOCATIONS (cr=2 pr=0 pw=0 time=490 us cost=2 size=529 card=23)'
STAT #140134982066512 id=6 cnt=19 pid=5 pos=1 obj=88141 op='INDEX FULL SCAN LOC_ID_PK (cr=1 pr=0 pw=0 time=99 us cost=1 size=0 card=23)'
STAT #140134982066512 id=7 cnt=27 pid=4 pos=2 obj=0 op='SORT JOIN (cr=6 pr=0 pw=0 time=3445 us cost=3 size=189 card=27)'
STAT #140134982066512 id=8 cnt=27 pid=7 pos=1 obj=0 op='VIEW  index$_join$_002 (cr=6 pr=0 pw=0 time=3294 us cost=2 size=189 card=27)'
STAT #140134982066512 id=9 cnt=27 pid=8 pos=1 obj=0 op='HASH JOIN  (cr=6 pr=0 pw=0 time=3291 us)'
STAT #140134982066512 id=10 cnt=27 pid=9 pos=1 obj=88147 op='INDEX FAST FULL SCAN DEPT_ID_PK (cr=3 pr=0 pw=0 time=198 us cost=1 size=189 card=27)'
STAT #140134982066512 id=11 cnt=27 pid=9 pos=2 obj=88146 op='INDEX FAST FULL SCAN DEPT_LOCATION_IX (cr=3 pr=0 pw=0 time=129 us cost=1 size=189 card=27)'
STAT #140134982066512 id=12 cnt=27 pid=3 pos=2 obj=88034 op='INDEX UNIQUE SCAN COUNTRY_C_ID_PK (cr=4 pr=0 pw=0 time=126 us cost=0 size=15 card=1)'
STAT #140134982066512 id=13 cnt=4 pid=2 pos=2 obj=88050 op='TABLE ACCESS FULL REGIONS (cr=6 pr=0 pw=0 time=66 us cost=3 size=56 card=4)'
STAT #140134982066512 id=14 cnt=107 pid=1 pos=2 obj=88047 op='TABLE ACCESS FULL EMPLOYEES (cr=13 pr=0 pw=0 time=51 us cost=3 size=4387 card=107)'
WAIT #140134982066512: nam='SQL*Net message to client' ela= 10 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880688504047

*** 2014-11-25 09:59:20.611
WAIT #140134982066512: nam='SQL*Net message from client' ela= 72107005 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760611195
WAIT #140134982066512: nam='SQL*Net break/reset to client' ela= 330 driver id=1650815232 break?=0 p3=0 obj#=-1 tim=1416880760612011
WAIT #140134982066512: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760612149
WAIT #140134982066512: nam='SQL*Net message from client' ela= 454 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760621215
CLOSE #140134982066512:c=0,e=37,dep=0,type=0,tim=1416880760621478
=====================
PARSING IN CURSOR #140134982066512 len=497 dep=0 uid=0 oct=3 lid=0 tim=1416880760622734 hv=940757165 ad='720722b8' sqlid='1xhyf6hw15n5d'
SELECT e.last_name || ' ,' || e.first_name AS full_name,
       e.phone_number,
       e.email,
       e.department_id,
       d.department_id,
       c.country_name,
       l.city,
       l.state_province,
       r.region_name
  FROM hr.employees   e,
       hr.departments d,
       hr.countries   c,
       hr.locations   l,
       hr.regions     r
 WHERE e.department_id = d.department_id
   AND d.location_id = l.location_id
   AND l.country_id = c.country_id
   AND c.region_id = r.region_id
END OF STMT
PARSE #140134982066512:c=1000,e=1037,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=231184628,tim=1416880760622731
EXEC #140134982066512:c=0,e=115,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=231184628,tim=1416880760623584
WAIT #140134982066512: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760623673
FETCH #140134982066512:c=6999,e=6016,p=0,cr=20,cu=0,mis=0,r=1,dep=0,og=1,plh=231184628,tim=1416880760629761
WAIT #140134982066512: nam='SQL*Net message from client' ela= 1929 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760632016
WAIT #140134982066512: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760632259
FETCH #140134982066512:c=0,e=366,p=0,cr=5,cu=0,mis=0,r=15,dep=0,og=1,plh=231184628,tim=1416880760632560
WAIT #140134982066512: nam='SQL*Net message from client' ela= 3900 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760636614
WAIT #140134982066512: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760637086
FETCH #140134982066512:c=0,e=237,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,plh=231184628,tim=1416880760637245
WAIT #140134982066512: nam='SQL*Net message from client' ela= 14483 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760652143
WAIT #140134982066512: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760654704
FETCH #140134982066512:c=0,e=307,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,plh=231184628,tim=1416880760654935
WAIT #140134982066512: nam='SQL*Net message from client' ela= 7584 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760662652
WAIT #140134982066512: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760663042
FETCH #140134982066512:c=0,e=221,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,plh=231184628,tim=1416880760663181
WAIT #140134982066512: nam='SQL*Net message from client' ela= 7556 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760672175
WAIT #140134982066512: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760672646
FETCH #140134982066512:c=0,e=296,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,plh=231184628,tim=1416880760672860
WAIT #140134982066512: nam='SQL*Net message from client' ela= 17180 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760690219
WAIT #140134982066512: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760691565
FETCH #140134982066512:c=1000,e=479,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,plh=231184628,tim=1416880760691739
WAIT #140134982066512: nam='SQL*Net message from client' ela= 8436 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760700515
WAIT #140134982066512: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760701006
FETCH #140134982066512:c=0,e=448,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,plh=231184628,tim=1416880760701149
WAIT #140134982066512: nam='SQL*Net message from client' ela= 4130 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760705532
FETCH #140134982066512:c=0,e=174,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=231184628,tim=1416880760706102
STAT #140134982066512 id=1 cnt=106 pid=0 pos=1 obj=0 op='HASH JOIN  (cr=31 pr=0 pw=0 time=6009 us cost=11 size=10600 card=106)'
STAT #140134982066512 id=2 cnt=27 pid=1 pos=1 obj=0 op='HASH JOIN  (cr=18 pr=0 pw=0 time=5022 us cost=8 size=1593 card=27)'
STAT #140134982066512 id=3 cnt=27 pid=2 pos=1 obj=0 op='NESTED LOOPS  (cr=12 pr=0 pw=0 time=5158 us cost=5 size=1215 card=27)'
STAT #140134982066512 id=4 cnt=27 pid=3 pos=1 obj=0 op='MERGE JOIN  (cr=8 pr=0 pw=0 time=4447 us cost=5 size=810 card=27)'
STAT #140134982066512 id=5 cnt=19 pid=4 pos=1 obj=88049 op='TABLE ACCESS BY INDEX ROWID LOCATIONS (cr=2 pr=0 pw=0 time=426 us cost=2 size=529 card=23)'
STAT #140134982066512 id=6 cnt=19 pid=5 pos=1 obj=88141 op='INDEX FULL SCAN LOC_ID_PK (cr=1 pr=0 pw=0 time=161 us cost=1 size=0 card=23)'
STAT #140134982066512 id=7 cnt=27 pid=4 pos=2 obj=0 op='SORT JOIN (cr=6 pr=0 pw=0 time=3858 us cost=3 size=189 card=27)'
STAT #140134982066512 id=8 cnt=27 pid=7 pos=1 obj=0 op='VIEW  index$_join$_002 (cr=6 pr=0 pw=0 time=3786 us cost=2 size=189 card=27)'
STAT #140134982066512 id=9 cnt=27 pid=8 pos=1 obj=0 op='HASH JOIN  (cr=6 pr=0 pw=0 time=3730 us)'
STAT #140134982066512 id=10 cnt=27 pid=9 pos=1 obj=88147 op='INDEX FAST FULL SCAN DEPT_ID_PK (cr=3 pr=0 pw=0 time=524 us cost=1 size=189 card=27)'
STAT #140134982066512 id=11 cnt=27 pid=9 pos=2 obj=88146 op='INDEX FAST FULL SCAN DEPT_LOCATION_IX (cr=3 pr=0 pw=0 time=313 us cost=1 size=189 card=27)'
STAT #140134982066512 id=12 cnt=27 pid=3 pos=2 obj=88034 op='INDEX UNIQUE SCAN COUNTRY_C_ID_PK (cr=4 pr=0 pw=0 time=127 us cost=0 size=15 card=1)'
STAT #140134982066512 id=13 cnt=4 pid=2 pos=2 obj=88050 op='TABLE ACCESS FULL REGIONS (cr=6 pr=0 pw=0 time=210 us cost=3 size=56 card=4)'
STAT #140134982066512 id=14 cnt=107 pid=1 pos=2 obj=88047 op='TABLE ACCESS FULL EMPLOYEES (cr=13 pr=0 pw=0 time=67 us cost=3 size=4387 card=107)'
WAIT #140134982066512: nam='SQL*Net message to client' ela= 10 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880760718531
*** 2014-11-25 10:00:44.237
WAIT #140134982066512: nam='SQL*Net message from client' ela= 83518465 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880844237161
CLOSE #140134982066512:c=0,e=31,dep=0,type=0,tim=1416880844237781
*** 2014-11-25 10:00:44.238
Processing Oradebug command 'tracefile_name'
** 2014-11-25 10:00:44.238
Oradebug command 'tracefile_name' console output: 
/u01/app/oracle/diag/rdbms/mecbs/MECBS1/trace/MECBS1_ora_7389.trc
WAIT #0: nam='SQL*Net message to client' ela= 8 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880844238709
*** 2014-11-25 10:01:15.108
WAIT #0: nam='SQL*Net message from client' ela= 30870019 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416880875108822
*** 2014-11-25 10:01:15.109

Processing Oradebug command 'event 10046 trace name context off'
上面文件格式比较乱,不方便阅读,我们用tkprof格式化一下:

[oracle@node1 ~]$ tkprof /u01/app/oracle/diag/rdbms/mecbs/MECBS1/trace/MECBS1_ora_7389.trc
output = /home/oracle/MECBS1_ora_7389.trc.tkf

TKPROF: Release 11.2.0.4.0 - Development on Tue Nov 25 10:03:20 2014

Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.

[oracle@even ~]$ tkprof /u01/app/oracle/admin/OMR/udump/omr_ora_16192.trc /u01/app/oracle/admin/OMR/udump/watson_omr_ora_16192_tkprof.trc

TKPROF: Release 10.2.0.1.0 - Production on Fri Dec 6 12:57:28 2013

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

以下是格式化的trace文件:

[oracle@node1 ~]$ cat MECBS1_ora_7389.trc.tkf 


TKPROF: Release 11.2.0.4.0 - Development on Tue Nov 25 10:03:20 2014


Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.


Trace file: /u01/app/oracle/diag/rdbms/mecbs/MECBS1/trace/MECBS1_ora_7389.trc
Sort options: default
********************************************************************************
count    = number of times OCI procedure was executed   --次数
cpu      = cpu time in seconds executing     --cpu时间
elapsed  = elapsed time in seconds executing   --逃离时间
disk     = number of physical reads of buffers from disk   --物理读次数
query    = number of buffers gotten for consistent read   --一致性读次数
current  = number of buffers gotten in current mode (usually for update)  --当前读次数
rows     = number of rows processed by the fetch or execute call   --返回的行数
********************************************************************************
SELECT e.last_name || ' ,' || e.first_name AS full_name,
       e.phone_number,
       e.email,
       e.department_id,
       d.department_id,
       c.country_name,
       l.city,
       l.state_province,
       r.region_name
  FROM hr.employees   e,
       hr.departments d,
       hr.countries   c,
       hr.locations   l,
       hr.regions     r
 WHERE e.department_id = d.department_id
   AND d.location_id = l.location_id
   AND l.country_id = c.country_id
   AND c.region_id = r.region_id
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.04       0.08          0          0          0           0
Execute      2      0.00       0.00          0          0          0           0
Fetch       18      0.01       0.01          0         62          0         212
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       22      0.06       0.10          0         62          0         212
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 2
Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
       106        106        106  HASH JOIN  (cr=31 pr=0 pw=0 time=5654 us cost=11 size=10600 card=106)
        27         27         27   HASH JOIN  (cr=18 pr=0 pw=0 time=4788 us cost=8 size=1593 card=27)
        27         27         27    NESTED LOOPS  (cr=12 pr=0 pw=0 time=5008 us cost=5 size=1215 card=27)
        27         27         27     MERGE JOIN  (cr=8 pr=0 pw=0 time=4298 us cost=5 size=810 card=27)
        19         19         19      TABLE ACCESS BY INDEX ROWID LOCATIONS (cr=2 pr=0 pw=0 time=458 us cost=2 size=529 card=23)
        19         19         19       INDEX FULL SCAN LOC_ID_PK (cr=1 pr=0 pw=0 time=130 us cost=1 size=0 card=23)(object id 88141)
        27         27         27      SORT JOIN (cr=6 pr=0 pw=0 time=3652 us cost=3 size=189 card=27)
        27         27         27       VIEW  index$_join$_002 (cr=6 pr=0 pw=0 time=3540 us cost=2 size=189 card=27)
        27         27         27        HASH JOIN  (cr=6 pr=0 pw=0 time=3510 us)
        27         27         27         INDEX FAST FULL SCAN DEPT_ID_PK (cr=3 pr=0 pw=0 time=361 us cost=1 size=189 card=27)(object id 88147)
        27         27         27         INDEX FAST FULL SCAN DEPT_LOCATION_IX (cr=3 pr=0 pw=0 time=221 us cost=1 size=189 card=27)(object id 88146)
        27         27         27     INDEX UNIQUE SCAN COUNTRY_C_ID_PK (cr=4 pr=0 pw=0 time=126 us cost=0 size=15 card=1)(object id 88034)
         4          4          4    TABLE ACCESS FULL REGIONS (cr=6 pr=0 pw=0 time=138 us cost=3 size=56 card=4)
       107        107        107   TABLE ACCESS FULL EMPLOYEES (cr=13 pr=0 pw=0 time=59 us cost=3 size=4387 card=107)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                      19        0.00          0.00
  SQL*Net message from client                    19       83.51        155.85
  SQL*Net break/reset to client                   1        0.00          0.00

********************************************************************************
汇总的结果
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS  --非递归调用的操作统计


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.04       0.08          0          0          0           0
Execute      2      0.00       0.00          0          0          0           0
Fetch       18      0.01       0.01          0         62          0         212
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       22      0.06       0.10          0         62          0         212
Misses in library cache during parse: 1
Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                      21        0.00          0.00
  SQL*Net message from client                    21       83.51        198.30
  SQL*Net break/reset to client                   1        0.00          0.00

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS --递归调用的操作统计,在硬解析阶段

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        0      0.00       0.00          0          0          0           0
Execute      0      0.00       0.00          0          0          0           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        0      0.00       0.00          0          0          0           0

Misses in library cache during parse: 0


    2  user  SQL statements in session.
    0  internal SQL statements in session.
    2  SQL statements in session.
********************************************************************************
Trace file: /u01/app/oracle/diag/rdbms/mecbs/MECBS1/trace/MECBS1_ora_7389.trc
Trace file compatibility: 11.1.0.7
Sort options: default


       1  session in tracefile.
       2  user  SQL statements in trace file.
       0  internal SQL statements in trace file.
       2  SQL statements in trace file.
       1  unique SQL statements in trace file.
     214  lines in trace file.

      72  elapsed seconds in trace file

以下是通过explain plan得到的执行计划:

SQL> select * from table(dbms_xplan.display);
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------------------- 
Plan hash value: 231184628

----------------------------------------------------------------------------------------------------
| Id  | Operation | Name   | Rows  | Bytes | Cost (%CPU)| Time   |
----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT |   |   106 | 10600 | 11  (10)| 00:00:01 |
|*  1 |  HASH JOIN |   |   106 | 10600 | 11  (10)| 00:00:01 |
|*  2 |   HASH JOIN |   | 27 |  1593 | 8  (13)| 00:00:01 |
|   3 |    NESTED LOOPS |   | 27 |  1215 | 5  (20)| 00:00:01 |
|   4 |     MERGE JOIN |   | 27 |   810 | 5  (20)| 00:00:01 |
|   5 |      TABLE ACCESS BY INDEX ROWID| LOCATIONS   | 23 |   529 | 2   (0)| 00:00:01 |
|   6 |       INDEX FULL SCAN | LOC_ID_PK   | 23 |   | 1   (0)| 00:00:01 |
|*  7 |      SORT JOIN |   | 27 |   189 | 3  (34)| 00:00:01 |
|   8 |       VIEW | index$_join$_002 | 27 |   189 | 2   (0)| 00:00:01 |
|*  9 |        HASH JOIN |   |   |   | |   |
|  10 | INDEX FAST FULL SCAN | DEPT_ID_PK   | 27 |   189 | 1   (0)| 00:00:01 |
|  11 | INDEX FAST FULL SCAN | DEPT_LOCATION_IX | 27 |   189 | 1   (0)| 00:00:01 |
|* 12 |     INDEX UNIQUE SCAN | COUNTRY_C_ID_PK  | 1 | 15 | 0   (0)| 00:00:01 |
|  13 |    TABLE ACCESS FULL | REGIONS   | 4 | 56 | 3   (0)| 00:00:01 |
|  14 |   TABLE ACCESS FULL | EMPLOYEES   |   107 |  4387 | 3   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("E"."DEPARTMENT_ID"="D"."DEPARTMENT_ID")
   2 - access("C"."REGION_ID"="R"."REGION_ID")
   7 - access("D"."LOCATION_ID"="L"."LOCATION_ID")
       filter("D"."LOCATION_ID"="L"."LOCATION_ID")
   9 - access(ROWID=ROWID)
  12 - access("L"."COUNTRY_ID"="C"."COUNTRY_ID")

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值