/u01/oracle/product/10.2.0/db/admin/orcl/udump/orcl_ora_2091.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bit Production
With the Partitioning, Data Mining and Real Application Testing options
ORACLE_HOME = /u01/oracle/product/10.2.0/db
System name:	SunOS
Node name:	sol10
Release:	5.10
Version:	Generic_141445-09
Machine:	i86pc
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 21
Unix process pid: 2091, image: oracle@sol10

*** ACTION NAME:() 2012-12-19 16:33:21.746
*** MODULE NAME:(SQL*Plus) 2012-12-19 16:33:21.746
*** SERVICE NAME:(orcl) 2012-12-19 16:33:21.746
*** SESSION ID:(141.94) 2012-12-19 16:33:21.746
=====================
PARSING IN CURSOR #1 len=32 dep=0 uid=62 oct=42 lid=62 tim=17823200618 hv=0 ad='fdb4fc08'
alter session set sql_trace=true
END OF STMT
EXEC #1:c=0,e=83,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=17823200612
=====================
PARSING IN CURSOR #2 len=52 dep=0 uid=62 oct=3 lid=62 tim=17823204758 hv=194023787 ad='b8d04608'
select --+ index(test)
       count(pad)
  from test
END OF STMT
PARSE #2:c=0,e=41,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17823204753
EXEC #2:c=0,e=105,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17823206341
FETCH #2:c=3660000,e=3576367,p=0,cr=41405,cu=0,mis=0,r=1,dep=0,og=1,tim=17826782741
FETCH #2:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17826783187
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=41405 pr=0 pw=0 time=3576410 us)'
STAT #2 id=2 cnt=10000000 pid=1 pos=1 obj=58407 op='TABLE ACCESS BY INDEX ROWID TEST (cr=41405 pr=0 pw=0 time=20000072 us)'
STAT #2 id=3 cnt=10000000 pid=2 pos=1 obj=58410 op='INDEX FULL SCAN IDX (cr=23560 pr=0 pw=0 time=42040 us)'
=====================
PARSING IN CURSOR #1 len=52 dep=0 uid=62 oct=3 lid=62 tim=17826787752 hv=194023787 ad='b8d04608'
select --+ index(test)
       count(pad)
  from test
END OF STMT
PARSE #1:c=0,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17826787750
EXEC #1:c=0,e=42,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17826787827
FETCH #1:c=3490000,e=3401522,p=0,cr=41405,cu=0,mis=0,r=1,dep=0,og=1,tim=17830189380
FETCH #1:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17830189834
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=41405 pr=0 pw=0 time=3401530 us)'
STAT #1 id=2 cnt=10000000 pid=1 pos=1 obj=58407 op='TABLE ACCESS BY INDEX ROWID TEST (cr=41405 pr=0 pw=0 time=20000043 us)'
STAT #1 id=3 cnt=10000000 pid=2 pos=1 obj=58410 op='INDEX FULL SCAN IDX (cr=23560 pr=0 pw=0 time=41119 us)'
=====================
PARSING IN CURSOR #2 len=75 dep=0 uid=62 oct=3 lid=62 tim=17830193981 hv=3722109354 ad='b8cca7b0'
select * from table(dbms_xplan.display_cursor(null, null, 'allstats last'))
END OF STMT
PARSE #2:c=0,e=58,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17830193980
EXEC #2:c=0,e=58,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17830194068
=====================
PARSING IN CURSOR #1 len=158 dep=1 uid=62 oct=3 lid=62 tim=17830194929 hv=1197953942 ad='b8cc3960'
select /* EXEC_FROM_DBMS_XPLAN */ 1, prev_sql_id, prev_child_number from v$session where sid=userenv('sid') and username is not null and prev_hash_value <> 0 
END OF STMT
PARSE #1:c=0,e=24,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17830194928
EXEC #1:c=0,e=32,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17830194999
FETCH #1:c=0,e=202,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17830195316
FETCH #1:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17830195375
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op='NESTED LOOPS  (cr=0 pr=0 pw=0 time=184 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=0 op='FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=193 us)'
STAT #1 id=3 cnt=1 pid=1 pos=2 obj=0 op='FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=9 us)'
=====================
PARSING IN CURSOR #1 len=2135 dep=1 uid=62 oct=3 lid=62 tim=17830195715 hv=295968972 ad='b8cd8900'
SELECT /*+ opt_param('parallel_execution_enabled', 'false') */
                       /* EXEC_FROM_DBMS_XPLAN */ id, position, depth , operation, options, object_name, cardinality, bytes, temp_space, cost, io_cost, cpu_cost, time, partition_start, partition_stop, object_node, other_tag, distribution, null, access_predicates, filter_predicates, null, null, null, other_xml, starts, outrows, crgets, cugets, reads, writes, etime, 
                 mem_opt, mem_one, last_mem_used, last_mem_usage, opt_cnt, 
                 one_cnt, multi_cnt, max_tmp, last_tmp from (select /*+ no_merge */ 
                          id, depth, position, operation, options,
                          cost, time, cardinality, bytes, object_node,
                          object_name, other_tag, partition_start,
                          partition_stop, distribution, temp_space, io_cost,
                          cpu_cost, filter_predicates, access_predicates, other,
                          projection, qblock_name, object_alias, other_xml,  last_starts starts,
                                     last_output_rows outrows, 
                                     last_cr_buffer_gets crgets, 
                                     last_cu_buffer_gets cugets, 
                                     last_disk_reads reads,
                                     last_disk_writes writes, 
                                     last_elapsed_time etime,
                                     estimated_optimal_size mem_opt,
                                     estimated_onepass_size mem_one,
                                     last_memory_used last_mem_used,
                                     last_execution last_mem_usage,
                                     optimal_executions opt_cnt,
                                     onepass_executions one_cnt,
                                     multipasses_executions multi_cnt,
                                     max_tempseg_size max_tmp,
                                     last_tempseg_size last_tmp
               from V$SQL_PLAN_STATISTICS_ALL vp where SQL_ID = '9pzmsyh5t14bb' and child_number=0)
END OF STMT
PARSE #1:c=0,e=23,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17830195713
EXEC #1:c=0,e=152,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17830195967
=====================
PARSING IN CURSOR #3 len=110 dep=1 uid=62 oct=3 lid=62 tim=17830196045 hv=4293044569 ad='b8cc41e8'
SELECT PLAN_TABLE_OUTPUT FROM TABLE(CAST(DBMS_XPLAN.PREPARE_RECORDS(:B1 , :B2 ) AS SYS.DBMS_XPLAN_TYPE_TABLE))
END OF STMT
PARSE #3:c=0,e=32,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17830196044
EXEC #3:c=0,e=127,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17830196206
FETCH #1:c=0,e=209,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17830196813
FETCH #1:c=0,e=192,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17830197081
=====================
PARSING IN CURSOR #4 len=448 dep=2 uid=62 oct=3 lid=62 tim=17830197387 hv=3191283681 ad='b8cb7010'
SELECT /*+ opt_param('parallel_execution_enabled', 'false') */ extractvalue(xmlval, '/*/info[@type = "sql_profile"]'), extractvalue(xmlval, '/*/info[@type = "outline"]'), extractvalue(xmlval, '/*/info[@type = "dynamic_sampling"]'), extractvalue(xmlval, '/*/info[@type = "row_shipping"]'), extractvalue(xmlval, '/*/info[@type = "index_size"]'), extractvalue(xmlval,'/*/info[@type = "plan_hash"]') from (select xmltype(:v_other_xml) xmlval from dual)
END OF STMT
PARSE #4:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17830197385
EXEC #4:c=0,e=348,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17830197773
=====================
PARSING IN CURSOR #6 len=47 dep=3 uid=0 oct=3 lid=0 tim=17830201145 hv=1023521005 ad='bfa87640'
select metadata from kopm$  where name='DB_FDO'
END OF STMT
PARSE #6:c=0,e=28,p=0,cr=0,cu=0,mis=0,r=0,dep=3,og=4,tim=17830201143
EXEC #6:c=0,e=61,p=0,cr=0,cu=0,mis=0,r=0,dep=3,og=4,tim=17830201246
FETCH #6:c=0,e=26,p=0,cr=2,cu=0,mis=0,r=1,dep=3,og=4,tim=17830201291
STAT #6 id=1 cnt=1 pid=0 pos=1 obj=364 op='TABLE ACCESS BY INDEX ROWID KOPM$ (cr=2 pr=0 pw=0 time=48 us)'
STAT #6 id=2 cnt=1 pid=1 pos=1 obj=365 op='INDEX UNIQUE SCAN I_KOPM1 (cr=1 pr=0 pw=0 time=11 us)'
FETCH #4:c=20000,e=18455,p=0,cr=8,cu=0,mis=0,r=1,dep=2,og=1,tim=17830216243
FETCH #1:c=0,e=47,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17830216519
FETCH #1:c=0,e=20,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17830216581
FETCH #1:c=0,e=7,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17830216632
FETCH #3:c=20000,e=20932,p=0,cr=8,cu=0,mis=0,r=10,dep=1,og=1,tim=17830217151
=====================
PARSING IN CURSOR #6 len=179 dep=1 uid=62 oct=3 lid=62 tim=17830217270 hv=3761447641 ad='b8cb4378'
select /* EXEC_FROM_DBMS_XPLAN */ rtrim(sql_text) 
                         from v$sql where SQL_ID=:v_sql_id 
                                    and child_number=:v_child_number
END OF STMT
PARSE #6:c=0,e=32,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17830217269
EXEC #6:c=0,e=25,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17830217334
FETCH #6:c=0,e=108,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17830217452
FETCH #2:c=20000,e=23413,p=0,cr=8,cu=0,mis=0,r=1,dep=0,og=1,tim=17830217512
STAT #1 id=1 cnt=4 pid=0 pos=1 obj=0 op='VIEW  (cr=0 pr=0 pw=0 time=194 us)'
STAT #1 id=2 cnt=4 pid=1 pos=1 obj=0 op='FIXED TABLE FIXED INDEX X$QESRSTATALL (ind:4) (cr=0 pr=0 pw=0 time=172 us)'
FETCH #2:c=0,e=126,p=0,cr=0,cu=0,mis=0,r=14,dep=0,og=1,tim=17830218048
STAT #2 id=1 cnt=15 pid=0 pos=1 obj=0 op='COLLECTION ITERATOR PICKLER FETCH DISPLAY_CURSOR (cr=8 pr=0 pw=0 time=23417 us)'
=====================
PARSING IN CURSOR #1 len=52 dep=0 uid=62 oct=42 lid=62 tim=17830224354 hv=119769663 ad='0'
alter session set "_rowsource_statistics_sampfreq"=0
END OF STMT
PARSE #1:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17830224351
EXEC #1:c=0,e=18,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17830224419
=====================
PARSING IN CURSOR #2 len=52 dep=0 uid=62 oct=3 lid=62 tim=17830227479 hv=194023787 ad='b8d04608'
select --+ index(test)
       count(pad)
  from test
END OF STMT
PARSE #2:c=0,e=23,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17830227475
EXEC #2:c=0,e=45,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17830227584
*** 2012-12-19 16:33:32.228
FETCH #2:c=3280000,e=3208750,p=0,cr=41405,cu=0,mis=0,r=1,dep=0,og=1,tim=17833436378
FETCH #2:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17833436864
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=41405 pr=0 pw=0 time=0 us)'
STAT #2 id=2 cnt=10000000 pid=1 pos=1 obj=58407 op='TABLE ACCESS BY INDEX ROWID TEST (cr=41405 pr=0 pw=0 time=0 us)'
STAT #2 id=3 cnt=10000000 pid=2 pos=1 obj=58410 op='INDEX FULL SCAN IDX (cr=23560 pr=0 pw=0 time=0 us)'
=====================
PARSING IN CURSOR #1 len=75 dep=0 uid=62 oct=3 lid=62 tim=17833440620 hv=3722109354 ad='b8cca7b0'
select * from table(dbms_xplan.display_cursor(null, null, 'allstats last'))
END OF STMT
PARSE #1:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17833440619
EXEC #1:c=0,e=28,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17833440675
=====================
PARSING IN CURSOR #2 len=158 dep=1 uid=62 oct=3 lid=62 tim=17833440977 hv=1197953942 ad='b8cc3960'
select /* EXEC_FROM_DBMS_XPLAN */ 1, prev_sql_id, prev_child_number from v$session where sid=userenv('sid') and username is not null and prev_hash_value <> 0 
END OF STMT
PARSE #2:c=0,e=13,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17833440975
EXEC #2:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17833441025
FETCH #2:c=0,e=120,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17833441171
FETCH #2:c=0,e=24,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17833441218
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=2 cnt=1 pid=1 pos=1 obj=0 op='FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=3 cnt=1 pid=1 pos=2 obj=0 op='FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=0 us)'
=====================
PARSING IN CURSOR #2 len=2135 dep=1 uid=62 oct=3 lid=62 tim=17833441344 hv=295968972 ad='b8cd8900'
SELECT /*+ opt_param('parallel_execution_enabled', 'false') */
                       /* EXEC_FROM_DBMS_XPLAN */ id, position, depth , operation, options, object_name, cardinality, bytes, temp_space, cost, io_cost, cpu_cost, time, partition_start, partition_stop, object_node, other_tag, distribution, null, access_predicates, filter_predicates, null, null, null, other_xml, starts, outrows, crgets, cugets, reads, writes, etime, 
                 mem_opt, mem_one, last_mem_used, last_mem_usage, opt_cnt, 
                 one_cnt, multi_cnt, max_tmp, last_tmp from (select /*+ no_merge */ 
                          id, depth, position, operation, options,
                          cost, time, cardinality, bytes, object_node,
                          object_name, other_tag, partition_start,
                          partition_stop, distribution, temp_space, io_cost,
                          cpu_cost, filter_predicates, access_predicates, other,
                          projection, qblock_name, object_alias, other_xml,  last_starts starts,
                                     last_output_rows outrows, 
                                     last_cr_buffer_gets crgets, 
                                     last_cu_buffer_gets cugets, 
                                     last_disk_reads reads,
                                     last_disk_writes writes, 
                                     last_elapsed_time etime,
                                     estimated_optimal_size mem_opt,
                                     estimated_onepass_size mem_one,
                                     last_memory_used last_mem_used,
                                     last_execution last_mem_usage,
                                     optimal_executions opt_cnt,
                                     onepass_executions one_cnt,
                                     multipasses_executions multi_cnt,
                                     max_tempseg_size max_tmp,
                                     last_tempseg_size last_tmp
               from V$SQL_PLAN_STATISTICS_ALL vp where SQL_ID = '9pzmsyh5t14bb' and child_number=0)
END OF STMT
PARSE #2:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17833441343
EXEC #2:c=0,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17833441460
EXEC #3:c=0,e=19,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17833441500
FETCH #2:c=0,e=163,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17833441848
FETCH #2:c=0,e=61,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17833441959
EXEC #4:c=0,e=96,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17833442117
FETCH #4:c=10000,e=2735,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17833444865
FETCH #2:c=0,e=41,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17833445090
FETCH #2:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17833445158
FETCH #2:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17833445195
FETCH #3:c=10000,e=4020,p=0,cr=0,cu=0,mis=0,r=10,dep=1,og=1,tim=17833445529
EXEC #6:c=0,e=23,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17833445651
FETCH #6:c=0,e=107,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17833445772
FETCH #1:c=10000,e=5165,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=17833445868
STAT #2 id=1 cnt=4 pid=0 pos=1 obj=0 op='VIEW  (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=2 cnt=4 pid=1 pos=1 obj=0 op='FIXED TABLE FIXED INDEX X$QESRSTATALL (ind:4) (cr=0 pr=0 pw=0 time=0 us)'
FETCH #1:c=0,e=135,p=0,cr=0,cu=0,mis=0,r=14,dep=0,og=1,tim=17833446484
STAT #1 id=1 cnt=15 pid=0 pos=1 obj=0 op='COLLECTION ITERATOR PICKLER FETCH DISPLAY_CURSOR (cr=0 pr=0 pw=0 time=0 us)'
=====================
PARSING IN CURSOR #2 len=54 dep=0 uid=62 oct=42 lid=62 tim=17833452268 hv=2352624425 ad='0'
alter session set "_rowsource_statistics_sampfreq"=128
END OF STMT
PARSE #2:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17833452266
EXEC #2:c=10000,e=15,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17833452333
=====================
PARSING IN CURSOR #1 len=52 dep=0 uid=62 oct=3 lid=62 tim=17833454810 hv=194023787 ad='b8d04608'
select --+ index(test)
       count(pad)
  from test
END OF STMT
PARSE #1:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17833454806
EXEC #1:c=0,e=42,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17833454897
FETCH #1:c=3520000,e=3450036,p=0,cr=41405,cu=0,mis=0,r=1,dep=0,og=1,tim=17836904963
FETCH #1:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17836905371
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=41405 pr=0 pw=0 time=3450042 us)'
STAT #1 id=2 cnt=10000000 pid=1 pos=1 obj=58407 op='TABLE ACCESS BY INDEX ROWID TEST (cr=41405 pr=0 pw=0 time=20000044 us)'
STAT #1 id=3 cnt=10000000 pid=2 pos=1 obj=58410 op='INDEX FULL SCAN IDX (cr=23560 pr=0 pw=0 time=41654 us)'
=====================
PARSING IN CURSOR #2 len=75 dep=0 uid=62 oct=3 lid=62 tim=17836907933 hv=3722109354 ad='b8cca7b0'
select * from table(dbms_xplan.display_cursor(null, null, 'allstats last'))
END OF STMT
PARSE #2:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17836907931
EXEC #2:c=0,e=29,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17836908227
=====================
PARSING IN CURSOR #1 len=158 dep=1 uid=62 oct=3 lid=62 tim=17836908454 hv=1197953942 ad='b8cc3960'
select /* EXEC_FROM_DBMS_XPLAN */ 1, prev_sql_id, prev_child_number from v$session where sid=userenv('sid') and username is not null and prev_hash_value <> 0 
END OF STMT
PARSE #1:c=0,e=10,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17836908452
EXEC #1:c=0,e=15,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17836908495
FETCH #1:c=0,e=124,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17836908645
FETCH #1:c=0,e=27,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17836908694
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op='NESTED LOOPS  (cr=0 pr=0 pw=0 time=122 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=0 op='FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=137 us)'
STAT #1 id=3 cnt=1 pid=1 pos=2 obj=0 op='FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=4 us)'
=====================
PARSING IN CURSOR #1 len=2135 dep=1 uid=62 oct=3 lid=62 tim=17836908816 hv=295968972 ad='b8cd8900'
SELECT /*+ opt_param('parallel_execution_enabled', 'false') */
                       /* EXEC_FROM_DBMS_XPLAN */ id, position, depth , operation, options, object_name, cardinality, bytes, temp_space, cost, io_cost, cpu_cost, time, partition_start, partition_stop, object_node, other_tag, distribution, null, access_predicates, filter_predicates, null, null, null, other_xml, starts, outrows, crgets, cugets, reads, writes, etime, 
                 mem_opt, mem_one, last_mem_used, last_mem_usage, opt_cnt, 
                 one_cnt, multi_cnt, max_tmp, last_tmp from (select /*+ no_merge */ 
                          id, depth, position, operation, options,
                          cost, time, cardinality, bytes, object_node,
                          object_name, other_tag, partition_start,
                          partition_stop, distribution, temp_space, io_cost,
                          cpu_cost, filter_predicates, access_predicates, other,
                          projection, qblock_name, object_alias, other_xml,  last_starts starts,
                                     last_output_rows outrows, 
                                     last_cr_buffer_gets crgets, 
                                     last_cu_buffer_gets cugets, 
                                     last_disk_reads reads,
                                     last_disk_writes writes, 
                                     last_elapsed_time etime,
                                     estimated_optimal_size mem_opt,
                                     estimated_onepass_size mem_one,
                                     last_memory_used last_mem_used,
                                     last_execution last_mem_usage,
                                     optimal_executions opt_cnt,
                                     onepass_executions one_cnt,
                                     multipasses_executions multi_cnt,
                                     max_tempseg_size max_tmp,
                                     last_tempseg_size last_tmp
               from V$SQL_PLAN_STATISTICS_ALL vp where SQL_ID = '9pzmsyh5t14bb' and child_number=0)
END OF STMT
PARSE #1:c=0,e=15,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17836908814
EXEC #1:c=0,e=18,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17836908918
EXEC #3:c=0,e=19,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17836908957
FETCH #1:c=0,e=86,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17836909157
FETCH #1:c=0,e=77,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17836909277
EXEC #4:c=0,e=31,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17836909398
FETCH #4:c=0,e=2721,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17836912130
FETCH #1:c=0,e=53,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17836912405
FETCH #1:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17836912476
FETCH #1:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17836912514
FETCH #3:c=10000,e=3902,p=0,cr=0,cu=0,mis=0,r=10,dep=1,og=1,tim=17836912868
EXEC #6:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17836912986
FETCH #6:c=0,e=42,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17836913040
FETCH #2:c=10000,e=4845,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=17836913101
STAT #1 id=1 cnt=4 pid=0 pos=1 obj=0 op='VIEW  (cr=0 pr=0 pw=0 time=78 us)'
STAT #1 id=2 cnt=4 pid=1 pos=1 obj=0 op='FIXED TABLE FIXED INDEX X$QESRSTATALL (ind:4) (cr=0 pr=0 pw=0 time=57 us)'
FETCH #2:c=0,e=137,p=0,cr=0,cu=0,mis=0,r=14,dep=0,og=1,tim=17836913672
STAT #2 id=1 cnt=15 pid=0 pos=1 obj=0 op='COLLECTION ITERATOR PICKLER FETCH DISPLAY_CURSOR (cr=0 pr=0 pw=0 time=4837 us)'
=====================
PARSING IN CURSOR #1 len=53 dep=0 uid=62 oct=42 lid=62 tim=17836918408 hv=3674036439 ad='0'
alter session set "_rowsource_statistics_sampfreq"=16
END OF STMT
PARSE #1:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17836918406
EXEC #1:c=0,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17836918458
=====================
PARSING IN CURSOR #2 len=52 dep=0 uid=62 oct=3 lid=62 tim=17836920540 hv=194023787 ad='b8d04608'
select --+ index(test)
       count(pad)
  from test
END OF STMT
PARSE #2:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17836920535
EXEC #2:c=0,e=51,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17836920666
FETCH #2:c=5240000,e=5122524,p=0,cr=41405,cu=0,mis=0,r=1,dep=0,og=1,tim=17842043231
FETCH #2:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17842043690
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=41405 pr=0 pw=0 time=5122530 us)'
STAT #2 id=2 cnt=10000000 pid=1 pos=1 obj=58407 op='TABLE ACCESS BY INDEX ROWID TEST (cr=41405 pr=0 pw=0 time=20000059 us)'
STAT #2 id=3 cnt=10000000 pid=2 pos=1 obj=58410 op='INDEX FULL SCAN IDX (cr=23560 pr=0 pw=0 time=318373 us)'
=====================
PARSING IN CURSOR #1 len=75 dep=0 uid=62 oct=3 lid=62 tim=17842046994 hv=3722109354 ad='b8cca7b0'
select * from table(dbms_xplan.display_cursor(null, null, 'allstats last'))
END OF STMT
PARSE #1:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17842046991
EXEC #1:c=0,e=37,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17842047083
=====================
PARSING IN CURSOR #2 len=158 dep=1 uid=62 oct=3 lid=62 tim=17842047402 hv=1197953942 ad='b8cc3960'
select /* EXEC_FROM_DBMS_XPLAN */ 1, prev_sql_id, prev_child_number from v$session where sid=userenv('sid') and username is not null and prev_hash_value <> 0 
END OF STMT
PARSE #2:c=0,e=12,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17842047400
EXEC #2:c=0,e=18,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17842047449
FETCH #2:c=0,e=127,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17842047603
FETCH #2:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17842047652
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='NESTED LOOPS  (cr=0 pr=0 pw=0 time=125 us)'
STAT #2 id=2 cnt=1 pid=1 pos=1 obj=0 op='FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=139 us)'
STAT #2 id=3 cnt=1 pid=1 pos=2 obj=0 op='FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=4 us)'
=====================
PARSING IN CURSOR #2 len=2135 dep=1 uid=62 oct=3 lid=62 tim=17842047768 hv=295968972 ad='b8cd8900'
SELECT /*+ opt_param('parallel_execution_enabled', 'false') */
                       /* EXEC_FROM_DBMS_XPLAN */ id, position, depth , operation, options, object_name, cardinality, bytes, temp_space, cost, io_cost, cpu_cost, time, partition_start, partition_stop, object_node, other_tag, distribution, null, access_predicates, filter_predicates, null, null, null, other_xml, starts, outrows, crgets, cugets, reads, writes, etime, 
                 mem_opt, mem_one, last_mem_used, last_mem_usage, opt_cnt, 
                 one_cnt, multi_cnt, max_tmp, last_tmp from (select /*+ no_merge */ 
                          id, depth, position, operation, options,
                          cost, time, cardinality, bytes, object_node,
                          object_name, other_tag, partition_start,
                          partition_stop, distribution, temp_space, io_cost,
                          cpu_cost, filter_predicates, access_predicates, other,
                          projection, qblock_name, object_alias, other_xml,  last_starts starts,
                                     last_output_rows outrows, 
                                     last_cr_buffer_gets crgets, 
                                     last_cu_buffer_gets cugets, 
                                     last_disk_reads reads,
                                     last_disk_writes writes, 
                                     last_elapsed_time etime,
                                     estimated_optimal_size mem_opt,
                                     estimated_onepass_size mem_one,
                                     last_memory_used last_mem_used,
                                     last_execution last_mem_usage,
                                     optimal_executions opt_cnt,
                                     onepass_executions one_cnt,
                                     multipasses_executions multi_cnt,
                                     max_tempseg_size max_tmp,
                                     last_tempseg_size last_tmp
               from V$SQL_PLAN_STATISTICS_ALL vp where SQL_ID = '9pzmsyh5t14bb' and child_number=0)
END OF STMT
PARSE #2:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17842047767
EXEC #2:c=0,e=24,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17842048196
EXEC #3:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17842048243
FETCH #2:c=0,e=92,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17842048435
FETCH #2:c=0,e=115,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17842048651
EXEC #4:c=0,e=37,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17842048759
FETCH #4:c=10000,e=2590,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17842051362
FETCH #2:c=0,e=41,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17842051614
FETCH #2:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17842051680
FETCH #2:c=0,e=7,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17842051721
FETCH #3:c=10000,e=3788,p=0,cr=0,cu=0,mis=0,r=10,dep=1,og=1,tim=17842052040
EXEC #6:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17842052141
FETCH #6:c=0,e=39,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17842052191
FETCH #1:c=10000,e=5098,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=17842052264
STAT #2 id=1 cnt=4 pid=0 pos=1 obj=0 op='VIEW  (cr=0 pr=0 pw=0 time=83 us)'
STAT #2 id=2 cnt=4 pid=1 pos=1 obj=0 op='FIXED TABLE FIXED INDEX X$QESRSTATALL (ind:4) (cr=0 pr=0 pw=0 time=63 us)'
FETCH #1:c=0,e=252,p=0,cr=0,cu=0,mis=0,r=14,dep=0,og=1,tim=17842053882
STAT #1 id=1 cnt=15 pid=0 pos=1 obj=0 op='COLLECTION ITERATOR PICKLER FETCH DISPLAY_CURSOR (cr=0 pr=0 pw=0 time=5087 us)'
=====================
PARSING IN CURSOR #2 len=52 dep=0 uid=62 oct=42 lid=62 tim=17842059412 hv=1901644751 ad='0'
alter session set "_rowsource_statistics_sampfreq"=8
END OF STMT
PARSE #2:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17842059410
EXEC #2:c=0,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17842059456
=====================
PARSING IN CURSOR #1 len=52 dep=0 uid=62 oct=3 lid=62 tim=17842061947 hv=194023787 ad='b8d04608'
select --+ index(test)
       count(pad)
  from test
END OF STMT
PARSE #1:c=0,e=24,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17842061942
EXEC #1:c=0,e=54,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17842062073
*** 2012-12-19 16:33:48.249
FETCH #1:c=7180000,e=7020020,p=0,cr=41405,cu=0,mis=0,r=1,dep=0,og=1,tim=17849082134
FETCH #1:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17849082649
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=41405 pr=0 pw=0 time=7020028 us)'
STAT #1 id=2 cnt=10000000 pid=1 pos=1 obj=58407 op='TABLE ACCESS BY INDEX ROWID TEST (cr=41405 pr=0 pw=0 time=20000055 us)'
STAT #1 id=3 cnt=10000000 pid=2 pos=1 obj=58410 op='INDEX FULL SCAN IDX (cr=23560 pr=0 pw=0 time=634778 us)'
=====================
PARSING IN CURSOR #2 len=75 dep=0 uid=62 oct=3 lid=62 tim=17849085981 hv=3722109354 ad='b8cca7b0'
select * from table(dbms_xplan.display_cursor(null, null, 'allstats last'))
END OF STMT
PARSE #2:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17849085979
EXEC #2:c=0,e=27,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17849086034
=====================
PARSING IN CURSOR #1 len=158 dep=1 uid=62 oct=3 lid=62 tim=17849086229 hv=1197953942 ad='b8cc3960'
select /* EXEC_FROM_DBMS_XPLAN */ 1, prev_sql_id, prev_child_number from v$session where sid=userenv('sid') and username is not null and prev_hash_value <> 0 
END OF STMT
PARSE #1:c=0,e=10,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17849086228
EXEC #1:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17849086322
FETCH #1:c=0,e=121,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17849086470
FETCH #1:c=0,e=42,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17849086554
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op='NESTED LOOPS  (cr=0 pr=0 pw=0 time=119 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=0 op='FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=149 us)'
STAT #1 id=3 cnt=1 pid=1 pos=2 obj=0 op='FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=4 us)'
=====================
PARSING IN CURSOR #1 len=2135 dep=1 uid=62 oct=3 lid=62 tim=17849086687 hv=295968972 ad='b8cd8900'
SELECT /*+ opt_param('parallel_execution_enabled', 'false') */
                       /* EXEC_FROM_DBMS_XPLAN */ id, position, depth , operation, options, object_name, cardinality, bytes, temp_space, cost, io_cost, cpu_cost, time, partition_start, partition_stop, object_node, other_tag, distribution, null, access_predicates, filter_predicates, null, null, null, other_xml, starts, outrows, crgets, cugets, reads, writes, etime, 
                 mem_opt, mem_one, last_mem_used, last_mem_usage, opt_cnt, 
                 one_cnt, multi_cnt, max_tmp, last_tmp from (select /*+ no_merge */ 
                          id, depth, position, operation, options,
                          cost, time, cardinality, bytes, object_node,
                          object_name, other_tag, partition_start,
                          partition_stop, distribution, temp_space, io_cost,
                          cpu_cost, filter_predicates, access_predicates, other,
                          projection, qblock_name, object_alias, other_xml,  last_starts starts,
                                     last_output_rows outrows, 
                                     last_cr_buffer_gets crgets, 
                                     last_cu_buffer_gets cugets, 
                                     last_disk_reads reads,
                                     last_disk_writes writes, 
                                     last_elapsed_time etime,
                                     estimated_optimal_size mem_opt,
                                     estimated_onepass_size mem_one,
                                     last_memory_used last_mem_used,
                                     last_execution last_mem_usage,
                                     optimal_executions opt_cnt,
                                     onepass_executions one_cnt,
                                     multipasses_executions multi_cnt,
                                     max_tempseg_size max_tmp,
                                     last_tempseg_size last_tmp
               from V$SQL_PLAN_STATISTICS_ALL vp where SQL_ID = '9pzmsyh5t14bb' and child_number=0)
END OF STMT
PARSE #1:c=0,e=15,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17849086685
EXEC #1:c=0,e=19,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17849086791
EXEC #3:c=0,e=19,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17849086829
FETCH #1:c=0,e=87,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17849087001
FETCH #1:c=0,e=57,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17849087101
EXEC #4:c=0,e=30,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17849087190
FETCH #4:c=0,e=2446,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17849089647
FETCH #1:c=0,e=34,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17849089835
FETCH #1:c=0,e=23,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17849089897
FETCH #1:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17849089932
FETCH #3:c=10000,e=3346,p=0,cr=0,cu=0,mis=0,r=10,dep=1,og=1,tim=17849090183
EXEC #6:c=0,e=15,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17849090258
FETCH #6:c=0,e=35,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17849090304
FETCH #2:c=10000,e=4293,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=17849090355
STAT #1 id=1 cnt=4 pid=0 pos=1 obj=0 op='VIEW  (cr=0 pr=0 pw=0 time=80 us)'
STAT #1 id=2 cnt=4 pid=1 pos=1 obj=0 op='FIXED TABLE FIXED INDEX X$QESRSTATALL (ind:4) (cr=0 pr=0 pw=0 time=60 us)'
FETCH #2:c=0,e=133,p=0,cr=0,cu=0,mis=0,r=14,dep=0,og=1,tim=17849090946
STAT #2 id=1 cnt=15 pid=0 pos=1 obj=0 op='COLLECTION ITERATOR PICKLER FETCH DISPLAY_CURSOR (cr=0 pr=0 pw=0 time=4314 us)'
=====================
PARSING IN CURSOR #1 len=52 dep=0 uid=62 oct=42 lid=62 tim=17849096574 hv=2011143002 ad='0'
alter session set "_rowsource_statistics_sampfreq"=4
END OF STMT
PARSE #1:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17849096572
EXEC #1:c=0,e=12,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17849096612
=====================
PARSING IN CURSOR #2 len=52 dep=0 uid=62 oct=3 lid=62 tim=17849099497 hv=194023787 ad='b8d04608'
select --+ index(test)
       count(pad)
  from test
END OF STMT
PARSE #2:c=0,e=19,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17849099493
EXEC #2:c=0,e=43,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17849099588
*** 2012-12-19 16:33:59.522
FETCH #2:c=11250000,e=10991168,p=0,cr=41405,cu=0,mis=0,r=1,dep=0,og=1,tim=17860090790
FETCH #2:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17860091677
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=41405 pr=0 pw=0 time=10991175 us)'
STAT #2 id=2 cnt=10000000 pid=1 pos=1 obj=58407 op='TABLE ACCESS BY INDEX ROWID TEST (cr=41405 pr=0 pw=0 time=20000047 us)'
STAT #2 id=3 cnt=10000000 pid=2 pos=1 obj=58410 op='INDEX FULL SCAN IDX (cr=23560 pr=0 pw=0 time=1286545 us)'
=====================
PARSING IN CURSOR #1 len=75 dep=0 uid=62 oct=3 lid=62 tim=17860095557 hv=3722109354 ad='b8cca7b0'
select * from table(dbms_xplan.display_cursor(null, null, 'allstats last'))
END OF STMT
PARSE #1:c=0,e=21,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17860095555
EXEC #1:c=0,e=34,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17860095622
=====================
PARSING IN CURSOR #2 len=158 dep=1 uid=62 oct=3 lid=62 tim=17860095954 hv=1197953942 ad='b8cc3960'
select /* EXEC_FROM_DBMS_XPLAN */ 1, prev_sql_id, prev_child_number from v$session where sid=userenv('sid') and username is not null and prev_hash_value <> 0 
END OF STMT
PARSE #2:c=0,e=13,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17860095952
EXEC #2:c=0,e=18,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17860096014
FETCH #2:c=0,e=130,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17860096169
FETCH #2:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17860096220
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='NESTED LOOPS  (cr=0 pr=0 pw=0 time=128 us)'
STAT #2 id=2 cnt=1 pid=1 pos=1 obj=0 op='FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=141 us)'
STAT #2 id=3 cnt=1 pid=1 pos=2 obj=0 op='FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=5 us)'
=====================
PARSING IN CURSOR #2 len=2135 dep=1 uid=62 oct=3 lid=62 tim=17860096332 hv=295968972 ad='b8cd8900'
SELECT /*+ opt_param('parallel_execution_enabled', 'false') */
                       /* EXEC_FROM_DBMS_XPLAN */ id, position, depth , operation, options, object_name, cardinality, bytes, temp_space, cost, io_cost, cpu_cost, time, partition_start, partition_stop, object_node, other_tag, distribution, null, access_predicates, filter_predicates, null, null, null, other_xml, starts, outrows, crgets, cugets, reads, writes, etime, 
                 mem_opt, mem_one, last_mem_used, last_mem_usage, opt_cnt, 
                 one_cnt, multi_cnt, max_tmp, last_tmp from (select /*+ no_merge */ 
                          id, depth, position, operation, options,
                          cost, time, cardinality, bytes, object_node,
                          object_name, other_tag, partition_start,
                          partition_stop, distribution, temp_space, io_cost,
                          cpu_cost, filter_predicates, access_predicates, other,
                          projection, qblock_name, object_alias, other_xml,  last_starts starts,
                                     last_output_rows outrows, 
                                     last_cr_buffer_gets crgets, 
                                     last_cu_buffer_gets cugets, 
                                     last_disk_reads reads,
                                     last_disk_writes writes, 
                                     last_elapsed_time etime,
                                     estimated_optimal_size mem_opt,
                                     estimated_onepass_size mem_one,
                                     last_memory_used last_mem_used,
                                     last_execution last_mem_usage,
                                     optimal_executions opt_cnt,
                                     onepass_executions one_cnt,
                                     multipasses_executions multi_cnt,
                                     max_tempseg_size max_tmp,
                                     last_tempseg_size last_tmp
               from V$SQL_PLAN_STATISTICS_ALL vp where SQL_ID = '9pzmsyh5t14bb' and child_number=0)
END OF STMT
PARSE #2:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17860096331
EXEC #2:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17860096482
EXEC #3:c=0,e=21,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17860096525
FETCH #2:c=0,e=97,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17860096776
FETCH #2:c=0,e=72,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17860096923
EXEC #4:c=0,e=39,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17860097038
FETCH #4:c=0,e=2619,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17860099669
FETCH #2:c=0,e=43,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17860099911
FETCH #2:c=0,e=23,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17860099974
FETCH #2:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17860100011
FETCH #3:c=0,e=3711,p=0,cr=0,cu=0,mis=0,r=10,dep=1,og=1,tim=17860100271
EXEC #6:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17860100361
FETCH #6:c=0,e=36,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17860100408
FETCH #1:c=0,e=4806,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=17860100463
STAT #2 id=1 cnt=4 pid=0 pos=1 obj=0 op='VIEW  (cr=0 pr=0 pw=0 time=97 us)'
STAT #2 id=2 cnt=4 pid=1 pos=1 obj=0 op='FIXED TABLE FIXED INDEX X$QESRSTATALL (ind:4) (cr=0 pr=0 pw=0 time=65 us)'
FETCH #1:c=0,e=129,p=0,cr=0,cu=0,mis=0,r=14,dep=0,og=1,tim=17860101027
STAT #1 id=1 cnt=15 pid=0 pos=1 obj=0 op='COLLECTION ITERATOR PICKLER FETCH DISPLAY_CURSOR (cr=0 pr=0 pw=0 time=4813 us)'
=====================
PARSING IN CURSOR #2 len=52 dep=0 uid=62 oct=42 lid=62 tim=17860106159 hv=2092216607 ad='0'
alter session set "_rowsource_statistics_sampfreq"=2
END OF STMT
PARSE #2:c=0,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17860106157
EXEC #2:c=0,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17860106200
=====================
PARSING IN CURSOR #1 len=52 dep=0 uid=62 oct=3 lid=62 tim=17860108677 hv=194023787 ad='b8d04608'
select --+ index(test)
       count(pad)
  from test
END OF STMT
PARSE #1:c=0,e=19,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17860108672
EXEC #1:c=0,e=51,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17860108774
*** 2012-12-19 16:34:18.552
FETCH #1:c=19010000,e=18566641,p=0,cr=41405,cu=0,mis=0,r=1,dep=0,og=1,tim=17878675448
FETCH #1:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17878675932
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=41405 pr=0 pw=0 time=18566649 us)'
STAT #1 id=2 cnt=10000000 pid=1 pos=1 obj=58407 op='TABLE ACCESS BY INDEX ROWID TEST (cr=41405 pr=0 pw=0 time=20000057 us)'
STAT #1 id=3 cnt=10000000 pid=2 pos=1 obj=58410 op='INDEX FULL SCAN IDX (cr=23560 pr=0 pw=0 time=2567322 us)'
=====================
PARSING IN CURSOR #2 len=75 dep=0 uid=62 oct=3 lid=62 tim=17878679644 hv=3722109354 ad='b8cca7b0'
select * from table(dbms_xplan.display_cursor(null, null, 'allstats last'))
END OF STMT
PARSE #2:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17878679642
EXEC #2:c=0,e=38,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17878679709
=====================
PARSING IN CURSOR #1 len=158 dep=1 uid=62 oct=3 lid=62 tim=17878679953 hv=1197953942 ad='b8cc3960'
select /* EXEC_FROM_DBMS_XPLAN */ 1, prev_sql_id, prev_child_number from v$session where sid=userenv('sid') and username is not null and prev_hash_value <> 0 
END OF STMT
PARSE #1:c=0,e=11,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17878679952
EXEC #1:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17878679996
FETCH #1:c=0,e=144,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17878680377
FETCH #1:c=0,e=27,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17878680433
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op='NESTED LOOPS  (cr=0 pr=0 pw=0 time=143 us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=0 op='FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=158 us)'
STAT #1 id=3 cnt=1 pid=1 pos=2 obj=0 op='FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=4 us)'
=====================
PARSING IN CURSOR #1 len=2135 dep=1 uid=62 oct=3 lid=62 tim=17878680544 hv=295968972 ad='b8cd8900'
SELECT /*+ opt_param('parallel_execution_enabled', 'false') */
                       /* EXEC_FROM_DBMS_XPLAN */ id, position, depth , operation, options, object_name, cardinality, bytes, temp_space, cost, io_cost, cpu_cost, time, partition_start, partition_stop, object_node, other_tag, distribution, null, access_predicates, filter_predicates, null, null, null, other_xml, starts, outrows, crgets, cugets, reads, writes, etime, 
                 mem_opt, mem_one, last_mem_used, last_mem_usage, opt_cnt, 
                 one_cnt, multi_cnt, max_tmp, last_tmp from (select /*+ no_merge */ 
                          id, depth, position, operation, options,
                          cost, time, cardinality, bytes, object_node,
                          object_name, other_tag, partition_start,
                          partition_stop, distribution, temp_space, io_cost,
                          cpu_cost, filter_predicates, access_predicates, other,
                          projection, qblock_name, object_alias, other_xml,  last_starts starts,
                                     last_output_rows outrows, 
                                     last_cr_buffer_gets crgets, 
                                     last_cu_buffer_gets cugets, 
                                     last_disk_reads reads,
                                     last_disk_writes writes, 
                                     last_elapsed_time etime,
                                     estimated_optimal_size mem_opt,
                                     estimated_onepass_size mem_one,
                                     last_memory_used last_mem_used,
                                     last_execution last_mem_usage,
                                     optimal_executions opt_cnt,
                                     onepass_executions one_cnt,
                                     multipasses_executions multi_cnt,
                                     max_tempseg_size max_tmp,
                                     last_tempseg_size last_tmp
               from V$SQL_PLAN_STATISTICS_ALL vp where SQL_ID = '9pzmsyh5t14bb' and child_number=0)
END OF STMT
PARSE #1:c=0,e=15,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17878680543
EXEC #1:c=0,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17878680658
EXEC #3:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17878680704
FETCH #1:c=0,e=111,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17878680996
FETCH #1:c=0,e=65,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17878681110
EXEC #4:c=0,e=61,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17878681333
FETCH #4:c=0,e=2539,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17878683886
FETCH #1:c=0,e=38,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17878684086
FETCH #1:c=0,e=23,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17878684148
FETCH #1:c=0,e=7,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17878684187
FETCH #3:c=0,e=3772,p=0,cr=0,cu=0,mis=0,r=10,dep=1,og=1,tim=17878684487
EXEC #6:c=0,e=18,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17878684569
FETCH #6:c=0,e=34,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17878684613
FETCH #2:c=0,e=4929,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=17878684668
STAT #1 id=1 cnt=4 pid=0 pos=1 obj=0 op='VIEW  (cr=0 pr=0 pw=0 time=178 us)'
STAT #1 id=2 cnt=4 pid=1 pos=1 obj=0 op='FIXED TABLE FIXED INDEX X$QESRSTATALL (ind:4) (cr=0 pr=0 pw=0 time=104 us)'
FETCH #2:c=0,e=154,p=0,cr=0,cu=0,mis=0,r=14,dep=0,og=1,tim=17878685245
STAT #2 id=1 cnt=15 pid=0 pos=1 obj=0 op='COLLECTION ITERATOR PICKLER FETCH DISPLAY_CURSOR (cr=0 pr=0 pw=0 time=5115 us)'
=====================
PARSING IN CURSOR #1 len=52 dep=0 uid=62 oct=42 lid=62 tim=17878690817 hv=4230847953 ad='0'
alter session set "_rowsource_statistics_sampfreq"=1
END OF STMT
PARSE #1:c=0,e=16,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17878690815
EXEC #1:c=0,e=19,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17878690862
=====================
PARSING IN CURSOR #2 len=52 dep=0 uid=62 oct=3 lid=62 tim=17878693450 hv=194023787 ad='b8d04608'
select --+ index(test)
       count(pad)
  from test
END OF STMT
PARSE #2:c=0,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17878693445
EXEC #2:c=0,e=62,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17878693776
*** 2012-12-19 16:34:52.636
FETCH #2:c=34030000,e=33265928,p=0,cr=41405,cu=0,mis=0,r=1,dep=0,og=1,tim=17911959756
FETCH #2:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=17911960260
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=41405 pr=0 pw=0 time=33265938 us)'
STAT #2 id=2 cnt=10000000 pid=1 pos=1 obj=58407 op='TABLE ACCESS BY INDEX ROWID TEST (cr=41405 pr=0 pw=0 time=30000065 us)'
STAT #2 id=3 cnt=10000000 pid=2 pos=1 obj=58410 op='INDEX FULL SCAN IDX (cr=23560 pr=0 pw=0 time=5055078 us)'
=====================
PARSING IN CURSOR #1 len=75 dep=0 uid=62 oct=3 lid=62 tim=17911963303 hv=3722109354 ad='b8cca7b0'
select * from table(dbms_xplan.display_cursor(null, null, 'allstats last'))
END OF STMT
PARSE #1:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17911963302
EXEC #1:c=0,e=34,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=17911963363
=====================
PARSING IN CURSOR #2 len=158 dep=1 uid=62 oct=3 lid=62 tim=17911963602 hv=1197953942 ad='b8cc3960'
select /* EXEC_FROM_DBMS_XPLAN */ 1, prev_sql_id, prev_child_number from v$session where sid=userenv('sid') and username is not null and prev_hash_value <> 0 
END OF STMT
PARSE #2:c=0,e=10,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17911963600
EXEC #2:c=0,e=15,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17911963641
FETCH #2:c=0,e=119,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17911963785
FETCH #2:c=0,e=29,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17911963835
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='NESTED LOOPS  (cr=0 pr=0 pw=0 time=145 us)'
STAT #2 id=2 cnt=1 pid=1 pos=1 obj=0 op='FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=137 us)'
STAT #2 id=3 cnt=1 pid=1 pos=2 obj=0 op='FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=4 us)'
=====================
PARSING IN CURSOR #2 len=2135 dep=1 uid=62 oct=3 lid=62 tim=17911963946 hv=295968972 ad='b8cd8900'
SELECT /*+ opt_param('parallel_execution_enabled', 'false') */
                       /* EXEC_FROM_DBMS_XPLAN */ id, position, depth , operation, options, object_name, cardinality, bytes, temp_space, cost, io_cost, cpu_cost, time, partition_start, partition_stop, object_node, other_tag, distribution, null, access_predicates, filter_predicates, null, null, null, other_xml, starts, outrows, crgets, cugets, reads, writes, etime, 
                 mem_opt, mem_one, last_mem_used, last_mem_usage, opt_cnt, 
                 one_cnt, multi_cnt, max_tmp, last_tmp from (select /*+ no_merge */ 
                          id, depth, position, operation, options,
                          cost, time, cardinality, bytes, object_node,
                          object_name, other_tag, partition_start,
                          partition_stop, distribution, temp_space, io_cost,
                          cpu_cost, filter_predicates, access_predicates, other,
                          projection, qblock_name, object_alias, other_xml,  last_starts starts,
                                     last_output_rows outrows, 
                                     last_cr_buffer_gets crgets, 
                                     last_cu_buffer_gets cugets, 
                                     last_disk_reads reads,
                                     last_disk_writes writes, 
                                     last_elapsed_time etime,
                                     estimated_optimal_size mem_opt,
                                     estimated_onepass_size mem_one,
                                     last_memory_used last_mem_used,
                                     last_execution last_mem_usage,
                                     optimal_executions opt_cnt,
                                     onepass_executions one_cnt,
                                     multipasses_executions multi_cnt,
                                     max_tempseg_size max_tmp,
                                     last_tempseg_size last_tmp
               from V$SQL_PLAN_STATISTICS_ALL vp where SQL_ID = '9pzmsyh5t14bb' and child_number=0)
END OF STMT
PARSE #2:c=0,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17911963945
EXEC #2:c=0,e=22,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17911964286
EXEC #3:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17911964335
FETCH #2:c=0,e=95,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17911964561
FETCH #2:c=0,e=63,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17911964670
EXEC #4:c=0,e=96,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17911964858
FETCH #4:c=10000,e=2918,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17911967790
FETCH #2:c=0,e=48,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17911968030
FETCH #2:c=0,e=29,p=0,cr=0,cu=0,mis=0,r=1,dep=2,og=1,tim=17911968121
FETCH #2:c=0,e=5,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,tim=17911968162
FETCH #3:c=10000,e=4217,p=0,cr=0,cu=0,mis=0,r=10,dep=1,og=1,tim=17911968562
EXEC #6:c=0,e=26,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=17911968698
FETCH #6:c=0,e=47,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=17911968760
FETCH #1:c=20000,e=5435,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=17911968826
STAT #2 id=1 cnt=4 pid=0 pos=1 obj=0 op='VIEW  (cr=0 pr=0 pw=0 time=203 us)'
STAT #2 id=2 cnt=4 pid=1 pos=1 obj=0 op='FIXED TABLE FIXED INDEX X$QESRSTATALL (ind:4) (cr=0 pr=0 pw=0 time=133 us)'
FETCH #1:c=0,e=190,p=0,cr=0,cu=0,mis=0,r=14,dep=0,og=1,tim=17911969461