(c)2011, OraPub, Inc. Warranty: There is none. Use at your own risk. Use at your own risk. OraPub is not responsible for the research related script. File : vsqlstat_collection Author : Craig Shallahamer, craig@orapub.com Original : 06-Jan-2011 Last : 08-Jan-2011 The purpose of this toolkit is to determine when v$sqlstats is updated. For example, before, during, or after a statement is run. And perhaps the various stats are updated at different points. And perhaps it different for sql statements and procedures, etc.? This "timing" knowledge becomes important when running experiments that depend on v$sqlstats data. The general strategy I used was to use two users; monitoring and application. There is actually a third, the data repository user which, I used SYSTEM. The monitoring user continuously checks v$sqlstats (actually its x$ equivalent) for a change in the specific SQL we're looking for. This is a tight loop with, by default, no delay. (You can change this delay, it's define troll_delay_in.) I could have used v$sqlstats instead of the x$, but this is lower overhead and I was already using the x$ for some other experiments, so it ended up this way. The results are inserted into the op_results_raw table, which I created within the SYSTEM schema. (I feel uncomfortable about create objects in the SYS schema.) The key is they are timestamped, so when the application user also inserts rows that are time stamped, after the experiment we can view the order of the timing together. The application user runs the SQL that is monitored. I have three tests; basic select, a procedure with the same select, and a procedure that runs the select twice. As with the monitored users, the application user inserts the results into the SYSTEM's op_results_raw table. The SYSTEM user own the results table, op_results_raw. It probably would have been cleaner to have the application user be the owner, but it is what it is. One of the keys to make this work is clearly identify the application SQL. To do this we need its SQL_ID and PLAN_HASH_VALUE columns. If you look closely at the "Setup application stuff" section below, you'll see that immediately after I run the application SQL, I query from the v$sqlstats and v$session looking for the "just run" sql. This works wonderfully! If you want to try this yourself, scan through the entire file. Pay attention to what is user (monitor, application, or SYSTEM user) is involved. While you can copy and paste most of the code directly in a sqlplus session, you will need to make some modification based on your system and also to ensure you are looking for and at the correct sql. Whether run using the data and SQL provided or using your own SQL statements, this experiment requires two Oracle sessions working in unison; monitoring user and an application user. Have fun! Craig. -------------- Setup application stuff...as application user connect mg/mg alter session set commit_write="batch,nowait"; drop table test1; create table test1 as select * from all_objects; insert into test1 select * from test1; insert into test1 select * from test1; insert into test1 select * from test1; commit; def the_test_sql=" /* orapub 3 */ avg(t0.object_id+t1.object_id+t2.object_id) from test1 t0, test1 t1, test1 t2 where t0.object_id=t1.object_id and t1.object_id=t2.object_id" select &the_test_sql; set timing on select &the_test_sql; select sql_id,plan_hash_value,substr(sql_text,1,60) the_sql from v$sqlstats where sql_id = (select prev_sql_id from v$session where sid=(select sid from v$mystat where rownum=1)); set timing off prompt prompt Note the sql_id and plan_hash_value for both the SELECT statement. prompt -- Make sure serveroutput is OFF or dbms_output will be the previous sql statement run! set serveroutput off create or replace procedure op_test4 as begin declare nothingness number; begin select /* orapub 4 */ avg(t0.object_id+t1.object_id+t2.object_id) into nothingness from test1 t0, test1 t1, test1 t2 where t0.object_id=t1.object_id and t1.object_id=t2.object_id; end; end; / exec op_test4; select sql_id,plan_hash_value,substr(sql_text,1,60) the_sql from v$sqlstats where sql_id = (select prev_sql_id from v$session where sid=(select sid from v$mystat where rownum=1)) / create or replace procedure op_test5 as begin declare nothingness number; i number; begin for i in 1..2 loop select /* orapub 5 */ avg(t0.object_id+t1.object_id+t2.object_id) into nothingness from test1 t0, test1 t1, test1 t2 where t0.object_id=t1.object_id and t1.object_id=t2.object_id; end loop; end; end; / exec op_test5; select sql_id,plan_hash_value,substr(sql_text,1,60) the_sql from v$sqlstats where sql_id = (select prev_sql_id from v$session where sid=(select sid from v$mystat where rownum=1)) / create or replace procedure op_test6 as begin declare nothingness number; begin select /* orapub 6a */ avg(t0.object_id+t1.object_id+t2.object_id) into nothingness from test1 t0, test1 t1, test1 t2 where t0.object_id=t1.object_id and t1.object_id=t2.object_id; select /* orapub 6b */ dbms_random.random into nothingness from dual; end; end; / exec op_test6; select sql_id,plan_hash_value,substr(sql_text,1,60) the_sql from v$sqlstats where sql_id = (select prev_sql_id from v$session where sid=(select sid from v$mystat where rownum=1)); create or replace procedure op_test7 as begin declare nothingness number; begin select /* orapub 7 */ avg(t0.object_id+t1.object_id+t2.object_id) into nothingness from test1 t0, test1 t1, test1 t2 where t0.object_id=t1.object_id and t1.object_id=t2.object_id; dbms_output.put_line('orapub 7 put_line'); end; end; / exec op_test7; select sql_id,plan_hash_value,substr(sql_text,1,60) the_sql from v$sqlstats where sql_id = (select prev_sql_id from v$session where sid=(select sid from v$mystat where rownum=1)); prompt prompt Note the sql_id and plan_hash_value for both the PROCEDURE statement. prompt -------------- Setup experimental results storage stuff...as SYSTEM -- Do NOT create the results table as user SYS. def userid=system def passwd=manager connect &userid/&passwd drop table op_results_raw; create table op_results_raw ( mark_time timestamp, happening varchar2(500) ); --- A little test... insert into op_results_raw values (systimestamp,'Test row 1'); insert into op_results_raw values (systimestamp,'Test row 2'); insert into op_results_raw values (systimestamp,'Test row 3'); commit; -- -- The "simple report" -- You can use the below SQL to easily report from the data collection table -- set tab off set linesize 250 col Mark format a14 col happening format a85 select to_char(mark_time,'HH24:MI:SS.FF4') Mark, happening from op_results_raw order by mark_time; -------------- Setup data collect stuff...as SYS (because querying from x$) connect sys as sysdba create or replace function get_interval_s(i_intrvl interval day to second) return number is begin return extract(day from i_intrvl) * 86400 + extract(hour from i_intrvl) * 3600 + extract(minute from i_intrvl) * 60 + extract(second from i_intrvl); exception when others then begin return null; end; end; / -- You will need to modify this appropriately... -- then copy/paste the defines and the pl/sql into SYS session to start sampling/gathering data. -- def results_owner_in=system ----- for the procedure test; op_test4 --def sql_id_in='chcnm5mqawby0' --def plan_hash_value_in=0 --def troll_secs_in=230 ----- for the procedure test; op_test5 --def sql_id_in='15xm7vr1v2xah' --def plan_hash_value_in=0 --def troll_secs_in=450 ----- for the procedure test; op_test6 def sql_id_in='8881dk0hc4ju4' def plan_hash_value_in=0 def troll_secs_in=140 ----- for the procedure test; op_test7 def sql_id_in='ds4a2b40vgf5r' def plan_hash_value_in=0 def troll_secs_in=140 ----- for the simple SQL statement test --def sql_id_in='7un4pb76n3sqc' --def plan_hash_value_in=772987886 --def troll_secs_in=300 def troll_delay_in=0 truncate table &results_owner_in..op_results_raw; set serveroutput on declare time_mark timestamp; curr_last_active_time date; curr_executions number; curr_disk_reads number; curr_buffer_gets number; old_last_active_time date := sysdate; old_executions number := 0; tot_loops number := 0; tot_exceptions number := 0; tot_inserts number := 0; begin insert into &results_owner_in..op_results_raw values (systimestamp,'Started v$sqlstats collection'); select systimestamp into time_mark from dual; loop tot_loops := tot_loops+1; curr_executions := -9; begin select last_active_time,executions,disk_reads,buffer_gets into curr_last_active_time,curr_executions,curr_disk_reads,curr_buffer_gets from x$kkssqlstat where sql_id = '&sql_id_in' and plan_hash_value = &plan_hash_value_in; exception when others then null; tot_exceptions := tot_exceptions + 1; end; if ( (curr_last_active_time > old_last_active_time) OR ( curr_executions > old_executions ) ) then insert into &results_owner_in..op_results_raw values ( systimestamp,'v$sqlstats change for &sql_id_in,&plan_hash_value_in exec='||curr_executions||' dskrds='||curr_disk_reads||' lio='||curr_buffer_gets ); tot_inserts := tot_inserts + 1; end if; old_last_active_time := curr_last_active_time; old_executions := curr_executions; if ( get_interval_s( systimestamp-time_mark ) > &troll_secs_in ) then exit; end if; dbms_lock.sleep(&troll_delay_in); end loop; insert into &results_owner_in..op_results_raw values (systimestamp,'Finished v$sqlstats collection'); commit; dbms_output.put_line('tot_loops='||tot_loops||' tot_exceptions='||tot_exceptions||' tot_inserts='||tot_inserts||' curr_executions='||curr_executions); end; / -- You can now report from op_results_raw to see the results! A sample report is in the section above. --------------------------------------------------- SELECT TEST ---------------------------------------------- -------------- Setup application testing stuff... -- After I start the collection (above), then I copy and paste the below into the APPLICATION user's session. -- -- Make sure you set the sql_id, etc. in the Monitoring sesson's defines, including the sample time. -- The sleeps below make it easier to distinguish between the ending and starting of the statements. def results_owner_in=system insert into &results_owner_in..op_results_raw values (systimestamp,'Started with SQL execution test.'); insert into &results_owner_in..op_results_raw values (systimestamp,'SQL start...'); select &the_test_sql; insert into &results_owner_in..op_results_raw values (systimestamp,'SQL end...'); exec dbms_lock.sleep(7); insert into &results_owner_in..op_results_raw values (systimestamp,'SQL start...'); select &the_test_sql; insert into &results_owner_in..op_results_raw values (systimestamp,'SQL end...'); exec dbms_lock.sleep(7); insert into &results_owner_in..op_results_raw values (systimestamp,'SQL start...'); select &the_test_sql; insert into &results_owner_in..op_results_raw values (systimestamp,'SQL end...'); exec dbms_lock.sleep(7); insert into &results_owner_in..op_results_raw values (systimestamp,'SQL start...'); select &the_test_sql; insert into &results_owner_in..op_results_raw values (systimestamp,'SQL end...'); exec dbms_lock.sleep(7); insert into &results_owner_in..op_results_raw values (systimestamp,'SQL start...'); select &the_test_sql; insert into &results_owner_in..op_results_raw values (systimestamp,'SQL end...'); exec dbms_lock.sleep(7); insert into &results_owner_in..op_results_raw values (systimestamp,'SQL start...'); select &the_test_sql; insert into &results_owner_in..op_results_raw values (systimestamp,'SQL end...'); insert into &results_owner_in..op_results_raw values (systimestamp,'Finished with SQL execution test.'); commit; -- Here is a sample run. I used the "simple report" to create this. MARK HAPPENING -------------- ------------------------------------------------------------------------------------- 13:59:20.9452 Started v$sqlstats collection 13:59:21.0485 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=20 dskrds=6736027 lio=922219 13:59:26.4489 Started with SQL execution test. 13:59:26.4513 SQL start... 13:59:26.4519 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=20 dskrds=6736027 lio=922219 13:59:26.4522 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6736027 lio=922219 13:59:28.4311 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6759000 lio=964528 13:59:30.4383 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6768115 lio=968314 13:59:32.4460 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6777124 lio=968314 13:59:34.4633 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6785370 lio=968314 13:59:36.4791 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6806930 lio=968314 13:59:38.4904 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6831248 lio=968314 13:59:40.4937 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6850232 lio=968314 13:59:42.4970 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6874578 lio=968314 13:59:44.5149 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6899099 lio=968314 13:59:46.5275 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6925426 lio=968314 13:59:48.5392 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6954364 lio=968314 13:59:50.5485 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=6982980 lio=968314 13:59:52.5510 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=7001446 lio=968314 13:59:54.7300 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=7022460 lio=968314 13:59:56.5887 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=7037188 lio=968314 13:59:58.5933 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=7059028 lio=968314 14:00:00.5970 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=21 dskrds=7083143 lio=968314 14:00:00.8328 SQL end... 14:00:07.8464 SQL start... 14:00:07.8472 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7085215 lio=968314 14:00:09.6418 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7111639 lio=1014409 14:00:11.6577 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7119745 lio=1014409 14:00:13.6618 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7126990 lio=1014409 14:00:15.6690 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7134767 lio=1014409 14:00:17.6774 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7156453 lio=1014409 14:00:19.6725 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7180428 lio=1014409 14:00:21.6753 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7203787 lio=1014409 14:00:23.6856 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7224780 lio=1014409 14:00:25.6993 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7250876 lio=1014409 14:00:27.7148 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7271624 lio=1014409 14:00:29.7313 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7296502 lio=1014409 14:00:31.7474 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7317614 lio=1014409 14:00:33.7648 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7343990 lio=1014409 14:00:35.7690 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7362064 lio=1014409 14:00:37.7889 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7387957 lio=1014409 14:00:39.8017 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7410259 lio=1014409 14:00:41.3582 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=22 dskrds=7434402 lio=1014409 14:00:41.3595 SQL end... 14:00:48.3642 SQL start... 14:00:48.3687 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7434402 lio=1014409 14:00:48.3688 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7434402 lio=1014409 14:00:49.8822 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7454620 lio=1051246 14:00:51.8621 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7462180 lio=1060504 14:00:53.8674 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7468389 lio=1060504 14:00:55.8673 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7472911 lio=1060504 14:00:57.8813 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7479022 lio=1060504 14:00:59.8977 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7484643 lio=1060504 14:01:01.9080 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7508562 lio=1060504 14:01:03.9168 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7532425 lio=1060504 14:01:05.9297 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7558108 lio=1060504 14:01:07.9439 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7582370 lio=1060504 14:01:09.9904 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7611917 lio=1060504 14:01:11.9697 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7635465 lio=1060504 14:01:13.9775 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7660490 lio=1060504 14:01:15.9864 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7679719 lio=1060504 14:01:17.9971 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7696876 lio=1060504 14:01:19.0071 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7707943 lio=1060504 14:01:21.0179 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7733577 lio=1060504 14:01:23.0196 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7756138 lio=1060504 14:01:24.7060 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7783592 lio=1060504 14:01:24.7069 SQL end... 14:01:31.7119 SQL start... 14:01:31.7150 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=23 dskrds=7783592 lio=1060504 14:01:31.7152 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7783592 lio=1060504 14:01:33.1283 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7797151 lio=1085245 14:01:35.0921 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7814118 lio=1106599 14:01:37.1056 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7822707 lio=1106599 14:01:39.1187 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7832738 lio=1106599 14:01:41.1217 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7850084 lio=1106599 14:01:43.1222 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7873177 lio=1106599 14:01:45.1263 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7897012 lio=1106599 14:01:47.1417 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7926790 lio=1106599 14:01:49.1439 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7949974 lio=1106599 14:01:51.1577 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=7980781 lio=1106599 14:01:53.1736 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=8011511 lio=1106599 14:01:55.1896 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=8040953 lio=1106599 14:01:57.2032 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=8071641 lio=1106599 14:01:59.2052 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=8100334 lio=1106599 14:02:01.2087 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=24 dskrds=8127732 lio=1106599 14:02:01.4489 SQL end... 14:02:08.4540 SQL start... 14:02:08.4548 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8132786 lio=1106599 14:02:10.2788 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8160666 lio=1152694 14:02:12.2934 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8168800 lio=1152694 14:02:14.3105 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8172986 lio=1152694 14:02:16.3170 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8179503 lio=1152694 14:02:18.3188 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8194777 lio=1152694 14:02:20.3219 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8218696 lio=1152694 14:02:22.3233 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8245667 lio=1152694 14:02:24.3307 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8274192 lio=1152694 14:02:26.3402 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8300414 lio=1152694 14:02:28.3473 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8316710 lio=1152694 14:02:30.3642 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8335736 lio=1152694 14:02:32.3833 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8356974 lio=1152694 14:02:34.3914 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8385107 lio=1152694 14:02:36.3937 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8413429 lio=1152694 14:02:38.4053 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8442409 lio=1152694 14:02:40.4199 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8468099 lio=1152694 14:02:41.3474 SQL end... 14:02:48.3518 SQL start... 14:02:48.3525 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=25 dskrds=8481973 lio=1152694 14:02:48.3526 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8481973 lio=1152694 14:02:49.4673 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8507018 lio=1198789 14:02:51.4868 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8515768 lio=1198789 14:02:53.4955 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8522985 lio=1198789 14:02:55.5073 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8531581 lio=1198789 14:02:57.5089 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8536908 lio=1198789 14:02:59.5211 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8542053 lio=1198789 14:03:01.5239 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8546442 lio=1198789 14:03:03.5251 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8551041 lio=1198789 14:03:05.5356 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8560806 lio=1198789 14:03:07.5423 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8587021 lio=1198789 14:03:09.5520 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8607629 lio=1198789 14:03:11.5574 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8624548 lio=1198789 14:03:13.5668 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8650623 lio=1198789 14:03:15.5704 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8673268 lio=1198789 14:03:17.5904 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8683754 lio=1198789 14:03:19.4199 v$sqlstats change for 7un4pb76n3sqc,772987886 exec=26 dskrds=8707085 lio=1198789 14:03:19.4212 SQL end... 14:03:19.4224 Finished with SQL execution test. 14:03:40.9669 Finished v$sqlstats collection 127 rows selected. --------------------------------------------------- PROCEDURE TEST ---------------------------------------------- -------------- Setup application testing stuff... -- After I start the collection (above), then I copy and paste the below into the APPLICATION user's session. -- -- Make sure you set the sql_id, etc. in the Monitoring sesson's defines, including the sample time. -- The sleeps below make it easier to distinguish between the ending and starting of the statements. def prc_name=op_test7 -- def results_owner_in=system insert into &results_owner_in..op_results_raw values (systimestamp,'Started with PRC execution test.'); insert into &results_owner_in..op_results_raw values (systimestamp,'PRC start...'); exec &prc_name; insert into &results_owner_in..op_results_raw values (systimestamp,'PRC end...'); exec dbms_lock.sleep(7); insert into &results_owner_in..op_results_raw values (systimestamp,'PRC start...'); exec &prc_name; insert into &results_owner_in..op_results_raw values (systimestamp,'PRC end...'); exec dbms_lock.sleep(7); insert into &results_owner_in..op_results_raw values (systimestamp,'PRC start...'); exec &prc_name; insert into &results_owner_in..op_results_raw values (systimestamp,'PRC end...'); exec dbms_lock.sleep(7); insert into &results_owner_in..op_results_raw values (systimestamp,'PRC start...'); exec &prc_name; insert into &results_owner_in..op_results_raw values (systimestamp,'PRC end...'); exec dbms_lock.sleep(7); insert into &results_owner_in..op_results_raw values (systimestamp,'PRC start...'); exec &prc_name; insert into &results_owner_in..op_results_raw values (systimestamp,'PRC end...'); exec dbms_lock.sleep(7); insert into &results_owner_in..op_results_raw values (systimestamp,'PRC start...'); exec &prc_name; insert into &results_owner_in..op_results_raw values (systimestamp,'PRC end...'); insert into &results_owner_in..op_results_raw values (systimestamp,'Finished with PRC execution test.'); commit; For procedure: op_test4 MARK HAPPENING -------------- ------------------------------------------------------------------------------------- 17:20:13.7554 Started v$sqlstats collection 17:20:13.7887 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=760213 lio=124219 17:20:17.6207 Started with PRC execution test. 17:20:17.8577 PRC start... 17:20:17.8584 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=760213 lio=124219 17:20:19.4002 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=782882 lio=146913 17:20:21.4135 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=792512 lio=149206 17:20:23.4313 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=800212 lio=149206 17:20:25.4449 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=808066 lio=149206 17:20:27.4509 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=817278 lio=149206 17:20:29.4622 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=846552 lio=149206 17:20:31.4687 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=872291 lio=149206 17:20:33.4857 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=901348 lio=149206 17:20:35.5041 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=927899 lio=149206 17:20:37.5196 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=949081 lio=149206 17:20:39.5314 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=965041 lio=149206 17:20:41.5336 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=995792 lio=149206 17:20:43.5458 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=1024611 lio=149206 17:20:45.5664 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=1047893 lio=149206 17:20:47.5802 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=1071028 lio=149206 17:20:49.5903 v$sqlstats change for chcnm5mqawby0,0 exec=3 dskrds=1100540 lio=149206 17:20:50.0857 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1109395 lio=149206 17:20:50.1243 PRC end... 17:20:57.1721 PRC start... 17:20:57.1727 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1109395 lio=149206 17:20:58.6511 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1131141 lio=170985 17:21:00.6632 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1143823 lio=174193 17:21:02.6938 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1151572 lio=174193 17:21:04.7077 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1159027 lio=174193 17:21:06.7085 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1178410 lio=174193 17:21:08.7114 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1196533 lio=174193 17:21:10.7255 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1215902 lio=174193 17:21:12.7413 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1240913 lio=174193 17:21:15.0142 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1264426 lio=174193 17:21:16.7681 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1286049 lio=174193 17:21:18.7707 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1304522 lio=174193 17:21:20.7747 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1330926 lio=174193 17:21:22.7838 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1354068 lio=174193 17:21:24.7932 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1383454 lio=174193 17:21:26.8116 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1411552 lio=174193 17:21:28.8233 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1433791 lio=174193 17:21:30.8343 v$sqlstats change for chcnm5mqawby0,0 exec=4 dskrds=1453958 lio=174193 17:21:31.1759 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1458564 lio=174193 17:21:31.1773 PRC end... 17:21:38.1846 PRC start... 17:21:38.1851 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1458564 lio=174193 17:21:39.8759 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1482325 lio=197985 17:21:41.8949 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1490264 lio=199180 17:21:43.8981 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1496431 lio=199180 17:21:45.9096 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1505118 lio=199180 17:21:47.9030 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1516059 lio=199180 17:21:49.9080 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1533874 lio=199180 17:21:51.9240 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1560481 lio=199180 17:21:53.9329 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1585961 lio=199180 17:21:55.9444 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1606583 lio=199180 17:21:57.9512 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1626036 lio=199180 17:21:59.9722 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1651208 lio=199180 17:22:01.9874 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1675449 lio=199180 17:22:04.0018 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1699851 lio=199180 17:22:06.0125 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1729034 lio=199180 17:22:08.0144 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1750160 lio=199180 17:22:10.0167 v$sqlstats change for chcnm5mqawby0,0 exec=5 dskrds=1779525 lio=199180 17:22:11.9592 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1807749 lio=199180 17:22:11.9598 PRC end... 17:22:18.9625 PRC start... 17:22:18.9661 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1807749 lio=199180 17:22:20.0952 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1830541 lio=222000 17:22:22.1056 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1843167 lio=224167 17:22:24.1516 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1850622 lio=224167 17:22:26.1114 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1857804 lio=224167 17:22:28.1222 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1871013 lio=224167 17:22:30.1348 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1896269 lio=224167 17:22:32.1371 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1920139 lio=224167 17:22:34.1420 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1946368 lio=224167 17:22:36.1565 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=1973241 lio=224167 17:22:38.1742 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=2000387 lio=224167 17:22:40.5360 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=2029703 lio=224167 17:22:42.1886 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=2048456 lio=224167 17:22:44.1889 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=2074867 lio=224167 17:22:46.2065 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=2098842 lio=224167 17:22:48.2250 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=2120451 lio=224167 17:22:50.2368 v$sqlstats change for chcnm5mqawby0,0 exec=6 dskrds=2149900 lio=224167 17:22:50.5933 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2156928 lio=224167 17:22:50.5938 PRC end... 17:22:57.5965 PRC start... 17:22:57.5971 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2156928 lio=224167 17:22:59.2846 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2183259 lio=249154 17:23:01.2974 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2189573 lio=249154 17:23:03.3211 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2196825 lio=249154 17:23:05.3859 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2202705 lio=249154 17:23:07.3398 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2214465 lio=249154 17:23:09.3450 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2237509 lio=249154 17:23:11.3480 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2258810 lio=249154 17:23:13.3569 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2277360 lio=249154 17:23:15.3750 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2300684 lio=249154 17:23:17.3874 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2322496 lio=249154 17:23:19.3955 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2348438 lio=249154 17:23:21.3976 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2379231 lio=249154 17:23:23.4007 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2408561 lio=249154 17:23:25.4088 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2436155 lio=249154 17:23:27.4182 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2464470 lio=249154 17:23:29.5176 v$sqlstats change for chcnm5mqawby0,0 exec=7 dskrds=2489593 lio=249154 17:23:30.7336 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2506113 lio=249154 17:23:30.7341 PRC end... 17:23:37.7373 PRC start... 17:23:37.7377 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2506113 lio=249154 17:23:39.5163 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2531853 lio=274141 17:23:41.5267 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2540589 lio=274141 17:23:43.5421 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2548667 lio=274141 17:23:45.6193 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2556661 lio=274141 17:23:47.5626 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2577045 lio=274141 17:23:49.5754 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2598290 lio=274141 17:23:51.5946 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2622839 lio=274141 17:23:53.6043 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2652239 lio=274141 17:23:55.6071 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2679084 lio=274141 17:23:57.6114 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2706349 lio=274141 17:23:59.6198 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2721175 lio=274141 17:24:01.6302 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2748216 lio=274141 17:24:03.6418 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2768621 lio=274141 17:24:05.6520 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2787507 lio=274141 17:24:07.6537 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2812833 lio=274141 17:24:09.6612 v$sqlstats change for chcnm5mqawby0,0 exec=8 dskrds=2837473 lio=274141 17:24:11.1179 v$sqlstats change for chcnm5mqawby0,0 exec=9 dskrds=2855295 lio=274141 17:24:11.1185 PRC end... 17:24:11.2403 Finished with PRC execution test. 17:24:33.9201 Finished v$sqlstats collection 126 rows selected. For procedure: op_test5 MARK HAPPENING -------------- ------------------------------------------------------------------------------------- 18:50:26.0991 Started v$sqlstats collection 18:50:26.1003 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13208886 lio=1041322 18:50:31.8619 Started with PRC execution test. 18:50:31.8632 PRC start... 18:50:31.8638 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13208886 lio=1041322 18:50:33.1397 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13213295 lio=1045734 18:50:35.1491 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13235541 lio=1066291 18:50:37.1664 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13245467 lio=1066291 18:50:39.1851 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13254210 lio=1066291 18:50:41.1814 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13269428 lio=1066291 18:50:43.1905 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13295986 lio=1066291 18:50:45.2008 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13322936 lio=1066291 18:50:47.2068 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13345301 lio=1066291 18:50:49.2215 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13366140 lio=1066291 18:50:51.2360 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13395232 lio=1066291 18:50:53.2461 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13425878 lio=1066291 18:50:55.2568 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13454228 lio=1066291 18:50:57.2667 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13482963 lio=1066291 18:50:59.2773 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13511796 lio=1066291 18:51:01.2874 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13540790 lio=1066291 18:51:03.3626 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13572985 lio=1081190 18:51:05.3116 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13589234 lio=1091260 18:51:07.3208 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13597291 lio=1091260 18:51:09.3422 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13606335 lio=1091260 18:51:11.3462 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13617416 lio=1091260 18:51:13.3581 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13631339 lio=1091260 18:51:15.3706 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13649798 lio=1091260 18:51:17.3838 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13673486 lio=1091260 18:51:19.3963 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13695242 lio=1091260 18:51:21.4012 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13722794 lio=1091260 18:51:23.4195 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13743318 lio=1091260 18:51:25.4304 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13763450 lio=1091260 18:51:27.4457 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13780411 lio=1091260 18:51:29.4586 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13796728 lio=1091260 18:51:31.4737 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13810980 lio=1091260 18:51:33.4729 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13830916 lio=1091260 18:51:35.4911 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13855325 lio=1091260 18:51:37.5069 v$sqlstats change for 15xm7vr1v2xah,0 exec=20 dskrds=13884991 lio=1091260 18:51:38.9183 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=13907265 lio=1091260 18:51:38.9194 PRC end... 18:51:46.2494 PRC start... 18:51:46.2513 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=13907265 lio=1091260 18:51:47.5500 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=13917643 lio=1101648 18:51:49.5649 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=13936621 lio=1116247 18:51:51.5751 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=13946869 lio=1116247 18:51:53.5959 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=13954863 lio=1116247 18:51:55.6021 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=13974470 lio=1116247 18:51:57.6165 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=13998403 lio=1116247 18:51:59.6288 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14023428 lio=1116247 18:52:01.6305 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14045240 lio=1116247 18:52:03.6322 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14073975 lio=1116247 18:52:05.6359 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14098062 lio=1116247 18:52:07.6530 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14122317 lio=1116247 18:52:09.6486 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14139943 lio=1116247 18:52:11.6525 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14158997 lio=1116247 18:52:13.6660 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14180039 lio=1116247 18:52:15.6810 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14198106 lio=1116247 18:52:17.6932 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14220422 lio=1116247 18:52:19.7061 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14243746 lio=1116247 18:52:21.7165 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14276808 lio=1136601 18:52:23.7293 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14287914 lio=1141216 18:52:25.7410 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14294956 lio=1141216 18:52:27.7613 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14301228 lio=1141216 18:52:29.7629 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14311812 lio=1141216 18:52:31.7672 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14342241 lio=1141216 18:52:33.7807 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14371207 lio=1141216 18:52:35.7989 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14402658 lio=1141216 18:52:37.8039 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14430350 lio=1141216 18:52:39.8129 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14456369 lio=1141216 18:52:41.8287 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14482507 lio=1141216 18:52:43.8470 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14502359 lio=1141216 18:52:45.8523 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14524045 lio=1141216 18:52:47.8633 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14544002 lio=1141216 18:52:49.8795 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14562482 lio=1141216 18:52:51.8954 v$sqlstats change for 15xm7vr1v2xah,0 exec=21 dskrds=14586303 lio=1141216 18:52:53.1498 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14605637 lio=1141216 18:52:53.1511 PRC end... 18:53:00.1632 PRC start... 18:53:00.1638 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14605637 lio=1141216 18:53:01.9271 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14631721 lio=1166203 18:53:03.9347 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14639862 lio=1166203 18:53:05.9485 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14646715 lio=1166203 18:53:07.9369 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14655374 lio=1166203 18:53:09.9454 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14678551 lio=1166203 18:53:11.9597 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14696800 lio=1166203 18:53:13.9698 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14720236 lio=1166203 18:53:15.9829 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14746080 lio=1166203 18:53:17.9982 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14766926 lio=1166203 18:53:19.0061 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14780744 lio=1166203 18:53:21.0228 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14803438 lio=1166203 18:53:23.0482 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14825145 lio=1166203 18:53:25.0313 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14843184 lio=1166203 18:53:27.0336 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14870183 lio=1166203 18:53:29.0398 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14900374 lio=1166203 18:53:31.0491 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14929760 lio=1166203 18:53:33.0544 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14959010 lio=1170371 18:53:35.0678 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14984617 lio=1191172 18:53:37.0868 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=14995061 lio=1191172 18:53:39.0990 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15004021 lio=1191172 18:53:41.1188 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15025651 lio=1191172 18:53:43.1206 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15051579 lio=1191172 18:53:45.1226 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15072026 lio=1191172 18:53:47.1332 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15096876 lio=1191172 18:53:49.1388 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15126178 lio=1191172 18:53:51.1501 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15156565 lio=1191172 18:53:53.1621 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15183249 lio=1191172 18:53:55.1782 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15210304 lio=1191172 18:53:57.1963 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15236064 lio=1191172 18:53:59.2086 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15263665 lio=1191172 18:54:01.2083 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15283433 lio=1191172 18:54:03.2105 v$sqlstats change for 15xm7vr1v2xah,0 exec=22 dskrds=15300121 lio=1191172 18:54:03.5769 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15303999 lio=1191172 18:54:03.5779 PRC end... 18:54:10.5839 PRC start... 18:54:10.5843 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15303999 lio=1191172 18:54:12.2569 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15326420 lio=1213614 18:54:14.2684 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15334652 lio=1216159 18:54:16.2843 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15343157 lio=1216159 18:54:18.2944 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15349121 lio=1216159 18:54:20.3027 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15354938 lio=1216159 18:54:22.3025 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15381300 lio=1216159 18:54:24.3139 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15404365 lio=1216159 18:54:26.3272 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15428501 lio=1216159 18:54:28.3367 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15452833 lio=1216159 18:54:30.3550 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15476318 lio=1216159 18:54:32.3669 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15500097 lio=1216159 18:54:34.3795 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15526830 lio=1216159 18:54:36.3979 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15552898 lio=1216159 18:54:38.4385 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15581794 lio=1216159 18:54:40.4052 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15601821 lio=1216159 18:54:42.4071 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15630787 lio=1216159 18:54:44.4180 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15666979 lio=1229933 18:54:46.4247 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15684503 lio=1241128 18:54:48.4398 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15693134 lio=1241128 18:54:50.4590 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15697621 lio=1241128 18:54:52.4692 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15704376 lio=1241128 18:54:54.4810 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15727448 lio=1241128 18:54:56.4827 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15757828 lio=1241128 18:54:58.4848 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15786913 lio=1241128 18:55:00.4960 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15816936 lio=1241128 18:55:02.8186 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15843984 lio=1241128 18:55:04.5160 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15857438 lio=1241128 18:55:06.5334 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15864529 lio=1241128 18:55:08.5502 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15871494 lio=1241128 18:55:10.5669 v$sqlstats change for 15xm7vr1v2xah,0 exec=23 dskrds=15878291 lio=1241128 18:55:11.2379 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=15883597 lio=1241128 18:55:11.2389 PRC end... 18:55:18.2473 PRC start... 18:55:18.2581 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=15883597 lio=1241128 18:55:19.5912 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=15908732 lio=1266115 18:55:21.5997 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=15916544 lio=1266115 18:55:23.6102 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=15923446 lio=1266115 18:55:25.6069 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=15931902 lio=1266115 18:55:27.6226 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=15948443 lio=1266115 18:55:29.6359 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=15971725 lio=1266115 18:55:31.6447 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=15996533 lio=1266115 18:55:33.6492 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16014341 lio=1266115 18:55:35.6492 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16039569 lio=1266115 18:55:37.6644 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16061402 lio=1266115 18:55:39.6804 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16084754 lio=1266115 18:55:41.6872 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16109660 lio=1266115 18:55:43.6897 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16133299 lio=1266115 18:55:45.6929 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16161040 lio=1266115 18:55:47.7078 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16182439 lio=1266115 18:55:49.7242 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16204874 lio=1266115 18:55:51.7348 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16231026 lio=1266115 18:55:53.7504 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16260326 lio=1291084 18:55:55.7426 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16268516 lio=1291084 18:55:57.8109 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16275320 lio=1291084 18:55:59.7648 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16281501 lio=1291084 18:56:01.7661 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16303684 lio=1291084 18:56:03.7710 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16333119 lio=1291084 18:56:05.7870 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16362232 lio=1291084 18:56:07.7982 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16383008 lio=1291084 18:56:09.8004 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16408026 lio=1291084 18:56:11.8083 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16435109 lio=1291084 18:56:13.8230 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16463830 lio=1291084 18:56:15.8386 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16485383 lio=1291084 18:56:17.8538 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16512095 lio=1291084 18:56:19.8555 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16532787 lio=1291084 18:56:21.8616 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16557042 lio=1291084 18:56:23.8773 v$sqlstats change for 15xm7vr1v2xah,0 exec=24 dskrds=16576292 lio=1291084 18:56:24.1354 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16581969 lio=1291084 18:56:24.1359 PRC end... 18:56:31.1413 PRC start... 18:56:31.1426 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16581969 lio=1291084 18:56:32.9722 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16608398 lio=1316071 18:56:34.9605 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16616140 lio=1316071 18:56:36.9530 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16623364 lio=1316071 18:56:38.9579 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16631127 lio=1316071 18:56:40.9678 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16652911 lio=1316071 18:56:42.9843 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16681422 lio=1316071 18:56:45.4814 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16706426 lio=1316071 18:56:46.0108 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16716058 lio=1316071 18:56:48.0191 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16741762 lio=1316071 18:56:50.0382 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16765576 lio=1316071 18:56:52.0533 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16791441 lio=1316071 18:56:54.0697 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16814366 lio=1316071 18:56:56.0746 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16833728 lio=1316071 18:56:58.0845 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16849114 lio=1316071 18:57:00.0878 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16871402 lio=1316071 18:57:02.0944 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16897281 lio=1316071 18:57:04.1140 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16919639 lio=1316071 18:57:06.2783 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16951511 lio=1336419 18:57:08.1307 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16962652 lio=1341040 18:57:10.1453 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16968630 lio=1341040 18:57:12.1514 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16978311 lio=1341040 18:57:14.1657 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=16997148 lio=1341040 18:57:16.1701 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17018288 lio=1341040 18:57:18.1805 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17037069 lio=1341040 18:57:20.1908 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17058783 lio=1341040 18:57:22.2027 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17078747 lio=1341040 18:57:24.2080 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17105004 lio=1341040 18:57:26.2124 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17132003 lio=1341040 18:57:28.2210 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17161011 lio=1341040 18:57:30.2370 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17184923 lio=1341040 18:57:32.2458 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17212615 lio=1341040 18:57:34.2478 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17242358 lio=1341040 18:57:36.2597 v$sqlstats change for 15xm7vr1v2xah,0 exec=25 dskrds=17262000 lio=1341040 18:57:37.8937 v$sqlstats change for 15xm7vr1v2xah,0 exec=26 dskrds=17280340 lio=1341040 18:57:37.8945 PRC end... 18:57:37.8957 Finished with PRC execution test. 18:57:56.1001 Finished v$sqlstats collection 223 rows selected. For procedure: op_test6 MARK HAPPENING -------------- ------------------------------------------------------------------------------------- 16:21:57.9886 Started v$sqlstats collection 16:21:57.9894 v$sqlstats change for 8881dk0hc4ju4,0 exec=25 dskrds=937907 lio=624657 16:22:05.7840 Started with PRC execution test. 16:22:05.7847 PRC start... 16:22:05.7849 v$sqlstats change for 8881dk0hc4ju4,0 exec=25 dskrds=937907 lio=624657 16:22:07.5003 v$sqlstats change for 8881dk0hc4ju4,0 exec=25 dskrds=963609 lio=649644 16:22:09.5084 v$sqlstats change for 8881dk0hc4ju4,0 exec=25 dskrds=965463 lio=649644 16:22:11.5073 v$sqlstats change for 8881dk0hc4ju4,0 exec=25 dskrds=967173 lio=649644 16:22:13.5417 v$sqlstats change for 8881dk0hc4ju4,0 exec=25 dskrds=969048 lio=649644 16:22:15.5542 v$sqlstats change for 8881dk0hc4ju4,0 exec=25 dskrds=970743 lio=649644 16:22:17.5569 v$sqlstats change for 8881dk0hc4ju4,0 exec=25 dskrds=972408 lio=649644 16:22:19.5811 v$sqlstats change for 8881dk0hc4ju4,0 exec=25 dskrds=974238 lio=649644 16:22:21.0560 v$sqlstats change for 8881dk0hc4ju4,0 exec=26 dskrds=975423 lio=649644 16:22:21.0572 PRC end... 16:22:28.0602 PRC start... 16:22:28.0606 v$sqlstats change for 8881dk0hc4ju4,0 exec=26 dskrds=975423 lio=649644 16:22:29.6187 v$sqlstats change for 8881dk0hc4ju4,0 exec=26 dskrds=1000887 lio=674631 16:22:31.6113 v$sqlstats change for 8881dk0hc4ju4,0 exec=26 dskrds=1002679 lio=674631 16:22:33.6267 v$sqlstats change for 8881dk0hc4ju4,0 exec=26 dskrds=1004404 lio=674631 16:22:35.6491 v$sqlstats change for 8881dk0hc4ju4,0 exec=26 dskrds=1006144 lio=674631 16:22:37.6707 v$sqlstats change for 8881dk0hc4ju4,0 exec=26 dskrds=1008004 lio=674631 16:22:39.6632 v$sqlstats change for 8881dk0hc4ju4,0 exec=26 dskrds=1009714 lio=674631 16:22:41.6777 v$sqlstats change for 8881dk0hc4ju4,0 exec=26 dskrds=1011454 lio=674631 16:22:43.3755 v$sqlstats change for 8881dk0hc4ju4,0 exec=27 dskrds=1012939 lio=674631 16:22:43.3761 PRC end... 16:22:50.3785 PRC start... 16:22:50.3788 v$sqlstats change for 8881dk0hc4ju4,0 exec=27 dskrds=1012939 lio=674631 16:22:51.7470 v$sqlstats change for 8881dk0hc4ju4,0 exec=27 dskrds=1038291 lio=699618 16:22:53.7641 v$sqlstats change for 8881dk0hc4ju4,0 exec=27 dskrds=1040165 lio=699618 16:22:55.7810 v$sqlstats change for 8881dk0hc4ju4,0 exec=27 dskrds=1041920 lio=699618 16:22:57.7839 v$sqlstats change for 8881dk0hc4ju4,0 exec=27 dskrds=1043660 lio=699618 16:22:59.7915 v$sqlstats change for 8881dk0hc4ju4,0 exec=27 dskrds=1045535 lio=699618 16:23:01.7818 v$sqlstats change for 8881dk0hc4ju4,0 exec=27 dskrds=1047230 lio=699618 16:23:03.7880 v$sqlstats change for 8881dk0hc4ju4,0 exec=27 dskrds=1048970 lio=699618 16:23:05.4659 v$sqlstats change for 8881dk0hc4ju4,0 exec=28 dskrds=1050455 lio=699618 16:23:05.4666 PRC end... 16:23:12.4704 PRC start... 16:23:12.4708 v$sqlstats change for 8881dk0hc4ju4,0 exec=28 dskrds=1050455 lio=699618 16:23:13.8580 v$sqlstats change for 8881dk0hc4ju4,0 exec=28 dskrds=1075933 lio=724605 16:23:15.8677 v$sqlstats change for 8881dk0hc4ju4,0 exec=28 dskrds=1077711 lio=724605 16:23:17.8581 v$sqlstats change for 8881dk0hc4ju4,0 exec=28 dskrds=1079421 lio=724605 16:23:19.8724 v$sqlstats change for 8881dk0hc4ju4,0 exec=28 dskrds=1081146 lio=724605 16:23:21.8801 v$sqlstats change for 8881dk0hc4ju4,0 exec=28 dskrds=1082991 lio=724605 16:23:23.8861 v$sqlstats change for 8881dk0hc4ju4,0 exec=28 dskrds=1084716 lio=724605 16:23:25.8836 v$sqlstats change for 8881dk0hc4ju4,0 exec=28 dskrds=1086441 lio=724605 16:23:27.6680 v$sqlstats change for 8881dk0hc4ju4,0 exec=29 dskrds=1087971 lio=724605 16:23:27.6687 PRC end... MARK HAPPENING -------------- ------------------------------------------------------------------------------------- 16:23:34.6718 PRC start... 16:23:34.6721 v$sqlstats change for 8881dk0hc4ju4,0 exec=29 dskrds=1087971 lio=724605 16:23:35.9440 v$sqlstats change for 8881dk0hc4ju4,0 exec=29 dskrds=1113211 lio=749592 16:23:37.9520 v$sqlstats change for 8881dk0hc4ju4,0 exec=29 dskrds=1114681 lio=749592 16:23:39.9651 v$sqlstats change for 8881dk0hc4ju4,0 exec=29 dskrds=1116442 lio=749592 16:23:41.9774 v$sqlstats change for 8881dk0hc4ju4,0 exec=29 dskrds=1118137 lio=749592 16:23:43.9960 v$sqlstats change for 8881dk0hc4ju4,0 exec=29 dskrds=1119907 lio=749592 16:23:46.0002 v$sqlstats change for 8881dk0hc4ju4,0 exec=29 dskrds=1121752 lio=749592 16:23:48.0087 v$sqlstats change for 8881dk0hc4ju4,0 exec=29 dskrds=1123462 lio=749592 16:23:49.0085 v$sqlstats change for 8881dk0hc4ju4,0 exec=29 dskrds=1124377 lio=749592 16:23:50.3846 v$sqlstats change for 8881dk0hc4ju4,0 exec=30 dskrds=1125487 lio=749592 16:23:50.3853 PRC end... 16:23:57.3877 PRC start... 16:23:57.3881 v$sqlstats change for 8881dk0hc4ju4,0 exec=30 dskrds=1125487 lio=749592 16:23:59.0794 v$sqlstats change for 8881dk0hc4ju4,0 exec=30 dskrds=1151196 lio=774579 16:24:01.0937 v$sqlstats change for 8881dk0hc4ju4,0 exec=30 dskrds=1153058 lio=774579 16:24:03.0971 v$sqlstats change for 8881dk0hc4ju4,0 exec=30 dskrds=1154798 lio=774579 16:24:05.0983 v$sqlstats change for 8881dk0hc4ju4,0 exec=30 dskrds=1156658 lio=774579 16:24:07.0959 v$sqlstats change for 8881dk0hc4ju4,0 exec=30 dskrds=1158398 lio=774579 16:24:09.1132 v$sqlstats change for 8881dk0hc4ju4,0 exec=30 dskrds=1160138 lio=774579 16:24:11.1273 v$sqlstats change for 8881dk0hc4ju4,0 exec=30 dskrds=1161968 lio=774579 16:24:12.4308 v$sqlstats change for 8881dk0hc4ju4,0 exec=31 dskrds=1163003 lio=774579 16:24:12.4315 PRC end... 16:24:12.4322 Finished with PRC execution test. 16:24:17.9893 Finished v$sqlstats collection 72 rows selected. --END