Skip to Main Content

SQL & PL/SQL

Announcement

For appeals, questions and feedback about Oracle Forums, please email oracle-forums-moderators_us@oracle.com. Technical questions should be asked in the appropriate category. Thank you!

Sudden increase in buffer gets/exec for a select query

perfdbaJan 12 2017 — edited Jan 13 2017

Hi Friends,

I am noticing an gradual increase in gets/exec for a query . Usually it has 10 gets/exec but currently it is doing 10k gets/exec.

Can anyone please suggest how to go further to investigate why gets/exec are increasing. It is not causing any impact , i am posting for my academic understanding.

Below is the query and the plan .

SELECT * FROM ( SELECT objid, dev, create_time, evt_name,

transaction_id, sequence_id, action_type, service_name, routing_id,

dependent_id, partition_id, effective_date, sequence_key,

focus_obj_type, focus_objid, proc_inst_id, group_inst_id, activity_id,

ref_rel_id, is_proxy_ready, status_code, update_time, submit_count,

retry_after_time, cust_ack_check_count, cust_ack_chk_aft_time,

ack_timeout_aft_time, publisher_name, event_source, extern_data,

trig_name, trig_obj_type, trig_objid, operation, log_data,

dependency_type, conn_count, item_order, system_timestamp,

x_processed_code, bgstatus2hgbst_elm, bg_action2act_entry,

bg_action2user, bg_action2rqst_inst, bg_action2step_inst FROM

TABLE_X WHERE  (  action_type >  :1  and  (  status_code =  :2

and  partition_id >=  :3  and  partition_id <=  :4  )  and  (

effective_date <=  :5  )  )  ORDER BY 12,13,38 ASC ) WHERE ROWNUM <=

20000

Plan hash value: 3977323905

-------------------------------------------------------------------------------------------------------

| Id  | Operation                       | Name                | Rows  | Bytes | Cost (%CPU)| Time     |

-------------------------------------------------------------------------------------------------------

|   0 | SELECT STATEMENT                |                     |       |       |   415 (100)|          |

|*  1 |  COUNT STOPKEY                  |                     |       |       |            |          |

|   2 |   VIEW                          |                     |   129 |   421K|   415   (1)| 00:00:05 |

|*  3 |    SORT ORDER BY STOPKEY        |                     |   129 |   283K|   415   (1)| 00:00:05 |

|*  4 |     FILTER                      |                     |       |       |            |          |

|*  5 |      TABLE ACCESS BY INDEX ROWID| TABLE_X             |   129 |   283K|   414   (0)| 00:00:05 |

|*  6 |       INDEX RANGE SCAN          | TABLE_X_1IX         |  4643 |       |   368   (0)| 00:00:05 |

-------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):

---------------------------------------------------

   1 - filter(ROWNUM<=20000)

   3 - filter(ROWNUM<=20000)

   4 - filter(:4>=:3)

   5 - filter("EFFECTIVE_DATE"<=:5)

   6 - access("STATUS_CODE"=:2 AND "PARTITION_ID">=:3 AND "ACTION_TYPE">:1 AND

              "PARTITION_ID"<=:4)

       filter(("PARTITION_ID">=:3 AND "PARTITION_ID"<=:4 AND "ACTION_TYPE">:1))

Below is the output with monitor hint.

Plan hash value: 3977323905

-----------------------------------------------------------------------------------------------------------------

| Id  | Operation                       | Name                | Starts | E-Rows | A-Rows |   A-Time   | Buffers |

-----------------------------------------------------------------------------------------------------------------

|   0 | SELECT STATEMENT                |                     |      1 |        |      0 |00:00:00.25 |   10657 |

|*  1 |  COUNT STOPKEY                  |                     |      1 |        |      0 |00:00:00.25 |   10657 |

|   2 |   VIEW                          |                     |      1 |    129 |      0 |00:00:00.25 |   10657 |

|*  3 |    SORT ORDER BY STOPKEY        |                     |      1 |    129 |      0 |00:00:00.25 |   10657 |

|*  4 |     FILTER                      |                     |      1 |        |      0 |00:00:00.25 |   10657 |

|*  5 |      TABLE ACCESS BY INDEX ROWID| TABLE_X             |      1 |    129 |      0 |00:00:00.25 |   10657 |

|*  6 |       INDEX RANGE SCAN          | TABLE_X_1IX         |      1 |   4643 |      2 |00:00:00.25 |   10655 |

-----------------------------------------------------------------------------------------------------------------

Few details:

1. LOG_DATA is a CLOB column.

2. There is one insert going in the table all the time, but i doubt it is causing any issue.

3. DB version is 11.2.0.4

4. Because attachments are getting zipped after uploading, i am attaching the raw output below:

=============trace file

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

System name:    Linux

Release:    2.6.32-642.6.2.el6.x86_64

Version:    #1 SMP Mon Oct 24 10:22:33 EDT 2016

Machine:    x86_64

Redo thread mounted by this instance: 1

Oracle process number: 1709

Unix process pid: 82732,

*** 2017-01-12 16:03:10.933

*** SESSION ID:(2733.43633) 2017-01-12 16:03:10.933

*** CLIENT ID:() 2017-01-12 16:03:10.933

*** MODULE NAME:(SQL*Plus) 2017-01-12 16:03:10.933

*** ACTION NAME:() 2017-01-12 16:03:10.933

WAIT #140450836913968: nam='SQL*Net message to client' ela= 1 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254990933287

*** 2017-01-12 16:03:15.563

WAIT #140450836913968: nam='SQL*Net message from client' ela= 4630030 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995563735

CLOSE #140450836913968:c=0,e=11,dep=0,type=1,tim=1484254995563881

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

PARSING IN CURSOR #140450836912488 len=29 dep=0 uid=436 oct=47 lid=436 tim=1484254995564056 hv=2962593829 ad='5c5def0ea8' sqlid='072g4zus9b615'

BEGIN :b1 :=        5; END;

END OF STMT

PARSE #140450836912488:c=0,e=132,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1484254995564052

BINDS #140450836912488:

Bind#0

  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

  oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0

  kxsbbbfp=7fbd423e1520  bln=22  avl=00  flg=05

WAIT #140450836912488: nam='SQL*Net message to client' ela= 2 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995564268

EXEC #140450836912488:c=1000,e=149,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1484254995564299

WAIT #140450836912488: nam='SQL*Net message from client' ela= 6912 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995571244

CLOSE #140450836912488:c=0,e=9,dep=0,type=1,tim=1484254995571278

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

PARSING IN CURSOR #140450836911008 len=29 dep=0 uid=436 oct=47 lid=436 tim=1484254995571376 hv=1708206553 ad='5c5dd298a8' sqlid='4gvvsh9kx2aft'

BEGIN :b2 :=        0; END;

END OF STMT

PARSE #140450836911008:c=0,e=69,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1484254995571376

BINDS #140450836911008:

Bind#0

  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

  oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0

  kxsbbbfp=7fbd423e0f58  bln=22  avl=00  flg=05

WAIT #140450836911008: nam='SQL*Net message to client' ela= 1 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995571515

EXEC #140450836911008:c=0,e=93,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1484254995571531

WAIT #140450836911008: nam='SQL*Net message from client' ela= 6778 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995578334

CLOSE #140450836911008:c=0,e=8,dep=0,type=1,tim=1484254995578368

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

PARSING IN CURSOR #140450836909528 len=31 dep=0 uid=436 oct=47 lid=436 tim=1484254995578475 hv=512624773 ad='5c5b063c60' sqlid='0hs08wcg8w245'

BEGIN :b3 :=        500; END;

END OF STMT

PARSE #140450836909528:c=0,e=83,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1484254995578474

BINDS #140450836909528:

Bind#0

  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

  oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0

  kxsbbbfp=7fbd423e0990  bln=22  avl=00  flg=05

WAIT #140450836909528: nam='SQL*Net message to client' ela= 0 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995578613

EXEC #140450836909528:c=0,e=93,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1484254995578630

WAIT #140450836909528: nam='SQL*Net message from client' ela= 6830 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995585483

CLOSE #140450836909528:c=0,e=8,dep=0,type=1,tim=1484254995585514

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

PARSING IN CURSOR #140450836908048 len=31 dep=0 uid=436 oct=47 lid=436 tim=1484254995585599 hv=97894435 ad='5ccc8e4a30' sqlid='g215fc42xbh13'

BEGIN :b4 :=        749; END;

END OF STMT

PARSE #140450836908048:c=0,e=62,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1484254995585598

BINDS #140450836908048:

Bind#0

  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

  oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0

  kxsbbbfp=7fbd423e03c8  bln=22  avl=00  flg=05

WAIT #140450836908048: nam='SQL*Net message to client' ela= 0 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995585751

EXEC #140450836908048:c=0,e=96,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1484254995585771

WAIT #140450836908048: nam='SQL*Net message from client' ela= 6837 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995592632

CLOSE #140450836908048:c=0,e=7,dep=0,type=1,tim=1484254995592663

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

PARSING IN CURSOR #140450836906568 len=49 dep=0 uid=436 oct=47 lid=436 tim=1484254995592740 hv=3985422356 ad='5cddf22018' sqlid='a5sjm9vqstf0n'

BEGIN :b5 :=        '2016-12-13 17:41:58'; END;

END OF STMT

PARSE #140450836906568:c=0,e=54,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1484254995592740

BINDS #140450836906568:

Bind#0

  oacdty=01 mxl=2000(384) mxlc=00 mal=00 scl=00 pre=00

  oacflg=03 fl2=1000000 frm=01 csi=871 siz=2000 off=0

  kxsbbbfp=7fbd423df230  bln=2000  avl=00  flg=05

WAIT #140450836906568: nam='SQL*Net message to client' ela= 0 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995592893

EXEC #140450836906568:c=0,e=109,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1484254995592911

WAIT #140450836906568: nam='SQL*Net message from client' ela= 6979 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995599912

CLOSE #140450836906568:c=0,e=8,dep=0,type=1,tim=1484254995599951

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

PARSING IN CURSOR #140450836905088 len=970 dep=0 uid=436 oct=3 lid=436 tim=1484254995602329 hv=1991014628 ad='5c5768ed18' sqlid='0md54jpvasy74'

SELECT /* gather_plan_statistics monitor*/ * FROM ( SELECT objid, dev, create_time, evt_name,

transaction_id, sequence_id, action_type, service_name, routing_id,

dependent_id, partition_id, effective_date, sequence_key,

focus_obj_type, focus_objid, proc_inst_id, group_inst_id, activity_id,

ref_rel_id, is_proxy_ready, status_code, update_time, submit_count,

retry_after_time, cust_ack_check_count, cust_ack_chk_aft_time,

ack_timeout_aft_time, publisher_name, event_source, extern_data,

trig_name, trig_obj_type, trig_objid, operation, log_data,

dependency_type, conn_count, item_order, system_timestamp,

x_processed_code, bgstatus2hgbst_elm, bg_action2act_entry,

bg_action2user, bg_action2rqst_inst, bg_action2step_inst FROM

TABLE_X WHERE  (  action_type >  :b1  and  (  status_code =  :b2

and  partition_id >=  :b3  and  partition_id <=  :b4  )  and  (

effective_date <=  to_date(:b5,'YYYY-MM-DD HH24:MI:SS'))  )  ORDER BY 12,13,38 ASC ) WHERE ROWNUM <=

20000

END OF STMT

PARSE #140450836905088:c=2999,e=2351,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1484254995602329

BINDS #140450836905088:

Bind#0

  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

  oacflg=03 fl2=1000000 frm=00 csi=00 siz=2096 off=0

  kxsbbbfp=7fbd423d9b98  bln=22  avl=02  flg=05

  value=5

Bind#1

  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

  oacflg=03 fl2=1000000 frm=00 csi=00 siz=0 off=24

  kxsbbbfp=7fbd423d9bb0  bln=22  avl=01  flg=01

  value=0

Bind#2

  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

  oacflg=03 fl2=1000000 frm=00 csi=00 siz=0 off=48

  kxsbbbfp=7fbd423d9bc8  bln=22  avl=02  flg=01

  value=500

Bind#3

  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

  oacflg=03 fl2=1000000 frm=00 csi=00 siz=0 off=72

  kxsbbbfp=7fbd423d9be0  bln=22  avl=03  flg=01

  value=749

Bind#4

  oacdty=01 mxl=2000(384) mxlc=00 mal=00 scl=00 pre=00

  oacflg=03 fl2=1000000 frm=01 csi=871 siz=0 off=96

  kxsbbbfp=7fbd423d9bf8  bln=2000  avl=19  flg=01

  value="2016-12-13 17:41:58"

EXEC #140450836905088:c=2999,e=3477,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3977323905,tim=1484254995605992

WAIT #140450836905088: nam='Disk file operations I/O' ela= 52 FileOperation=8 fileno=0 filetype=8 obj#=-1 tim=1484254995606091

WAIT #140450836905088: nam='Disk file operations I/O' ela= 29 FileOperation=8 fileno=0 filetype=8 obj#=-1 tim=1484254995606155

WAIT #140450836905088: nam='SQL*Net message to client' ela= 0 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995606189

WAIT #140450836905088: nam='SQL*Net message from client' ela= 7276 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995613524

FETCH #140450836905088:c=195970,e=196150,p=0,cr=8341,cu=0,mis=0,r=0,dep=0,og=1,plh=3977323905,tim=1484254995809702

STAT #140450836905088 id=1 cnt=0 pid=0 pos=1 obj=0 op='COUNT STOPKEY (cr=8341 pr=0 pw=0 time=196184 us)'

STAT #140450836905088 id=2 cnt=0 pid=1 pos=1 obj=0 op='VIEW  (cr=8341 pr=0 pw=0 time=196176 us cost=415 size=431247 card=129)'

STAT #140450836905088 id=3 cnt=0 pid=2 pos=1 obj=0 op='SORT ORDER BY STOPKEY (cr=8341 pr=0 pw=0 time=196166 us cost=415 size=290637 card=129)'

STAT #140450836905088 id=4 cnt=0 pid=3 pos=1 obj=0 op='FILTER  (cr=8341 pr=0 pw=0 time=196127 us)'

STAT #140450836905088 id=5 cnt=0 pid=4 pos=1 obj=3426922 op='TABLE ACCESS BY INDEX ROWID TABLE_X (cr=8341 pr=0 pw=0 time=196124 us cost=414 size=290637 card=129)'

STAT #140450836905088 id=6 cnt=3 pid=5 pos=1 obj=3426930 op='INDEX RANGE SCAN TABLE_X_1IX (cr=8337 pr=0 pw=0 time=195925 us cost=368 size=0 card=4643)'

WAIT #140450836905088: nam='SQL*Net message to client' ela= 5 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995809999

WAIT #140450836905088: nam='SQL*Net message from client' ela= 7338 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1484254995817363

CLOSE #140450836905088:c=0,e=5,dep=0,type=0,tim=1484254995817403

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

PARSING IN CURSOR #140450836905088 len=55 dep=0 uid=436 oct=42 lid=436 tim=1484254995817493 hv=2655499671 ad='0' sqlid='0kjg1c2g4gdcr'

ALTER SESSION SET EVENTS '10046 trace name context off'

END OF STMT

PARSE #140450836905088:c=0,e=49,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1484254995817493

EXEC #140450836905088:c=0,e=492,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1484254995818053

========TKPROF output

TKPROF: Release 11.2.0.4.0 - Development on Thu Jan 12 15:07:41 2017

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

Trace file: TESTDB1_ora_82732_WATCH_10046.trc

Sort options: default

********************************************************************************

count    = number of times OCI procedure was executed

cpu      = cpu time in seconds executing

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

********************************************************************************

SQL ID: 072g4zus9b615 Plan Hash: 0

BEGIN :b1 :=        5; END;

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           1

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      0.00       0.00          0          0          0           1

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: 436 

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                       1        0.00          0.00

  SQL*Net message from client                     1        0.00          0.00

********************************************************************************

SQL ID: 4gvvsh9kx2aft Plan Hash: 0

BEGIN :b2 :=        0; END;

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           1

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      0.00       0.00          0          0          0           1

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: 436 

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                       1        0.00          0.00

  SQL*Net message from client                     1        0.00          0.00

********************************************************************************

SQL ID: 0hs08wcg8w245 Plan Hash: 0

BEGIN :b3 :=        500; END;

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           1

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      0.00       0.00          0          0          0           1

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: 436 

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                       1        0.00          0.00

  SQL*Net message from client                     1        0.00          0.00

********************************************************************************

SQL ID: g215fc42xbh13 Plan Hash: 0

BEGIN :b4 :=        749; END;

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           1

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      0.00       0.00          0          0          0           1

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: 436 

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                       1        0.00          0.00

  SQL*Net message from client                     1        0.00          0.00

********************************************************************************

SQL ID: a5sjm9vqstf0n Plan Hash: 0

BEGIN :b5 :=        '2016-12-13 17:41:58'; END;

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           1

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      0.00       0.00          0          0          0           1

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: 436 

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                       1        0.00          0.00

  SQL*Net message from client                     1        0.00          0.00

********************************************************************************

SELECT /* gather_plan_statistics monitor*/ * FROM ( SELECT objid, dev, create_time, evt_name,

transaction_id, sequence_id, action_type, service_name, routing_id,

dependent_id, partition_id, effective_date, sequence_key,

focus_obj_type, focus_objid, proc_inst_id, group_inst_id, activity_id,

ref_rel_id, is_proxy_ready, status_code, update_time, submit_count,

retry_after_time, cust_ack_check_count, cust_ack_chk_aft_time,

ack_timeout_aft_time, publisher_name, event_source, extern_data,

trig_name, trig_obj_type, trig_objid, operation, log_data,

dependency_type, conn_count, item_order, system_timestamp,

x_processed_code, bgstatus2hgbst_elm, bg_action2act_entry,

bg_action2user, bg_action2rqst_inst, bg_action2step_inst FROM

TABLE_X WHERE  (  action_type >  :b1  and  (  status_code =  :b2

and  partition_id >=  :b3  and  partition_id <=  :b4  )  and  (

effective_date <=  to_date(:b5,'YYYY-MM-DD HH24:MI:SS'))  )  ORDER BY 12,13,38 ASC ) WHERE ROWNUM <=

20000

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           0

Fetch        1      0.19       0.19          0       8341          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        3      0.20       0.20          0       8341          0           0

Misses in library cache during parse: 1

Optimizer mode: ALL_ROWS

Parsing user id: 436 

Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation

---------- ---------- ----------  ---------------------------------------------------

         0          0          0  COUNT STOPKEY (cr=8341 pr=0 pw=0 time=196184 us)

         0          0          0   VIEW  (cr=8341 pr=0 pw=0 time=196176 us cost=415 size=431247 card=129)

         0          0          0    SORT ORDER BY STOPKEY (cr=8341 pr=0 pw=0 time=196166 us cost=415 size=290637 card=129)

         0          0          0     FILTER  (cr=8341 pr=0 pw=0 time=196127 us)

         0          0          0      TABLE ACCESS BY INDEX ROWID TABLE_X (cr=8341 pr=0 pw=0 time=196124 us cost=414 size=290637 card=129)

         3          3          3       INDEX RANGE SCAN TABLE_X_1IX (cr=8337 pr=0 pw=0 time=195925 us cost=368 size=0 card=4643)(object id 3426930)

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  Disk file operations I/O                        2        0.00          0.00

  SQL*Net message to client                       2        0.00          0.00

  SQL*Net message from client                     2        0.00          0.01

********************************************************************************

SQL ID: 0kjg1c2g4gdcr Plan Hash: 0

ALTER SESSION SET EVENTS '10046 trace name context off'

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           0

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      0.00       0.00          0          0          0           0

Misses in library cache during parse: 0

Parsing user id: 436 

********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        7      0.00       0.00          0          0          0           0

Execute      7      0.00       0.00          0          0          0           5

Fetch        1      0.19       0.19          0       8341          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total       15      0.20       0.20          0       8341          0           5

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                       8        0.00          0.00

  SQL*Net message from client                     8        4.63          4.67

  Disk file operations I/O                        2        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

    7  user  SQL statements in session.

    0  internal SQL statements in session.

    7  SQL statements in session.

********************************************************************************

Trace file: TESTDB1_ora_82732_WATCH_10046.trc

Trace file compatibility: 11.1.0.7

Sort options: default

       1  session in tracefile.

       7  user  SQL statements in trace file.

       0  internal SQL statements in trace file.

       7  SQL statements in trace file.

       7  unique SQL statements in trace file.

     164  lines in trace file.

       0  elapsed seconds in trace file.

This post has been answered by AndrewSayer on Jan 13 2017
Jump to Answer
Comments
Locked Post
New comments cannot be posted to this locked post.
Post Details
Locked on Feb 10 2017
Added on Jan 12 2017
8 comments
954 views