Skip to Main Content

Oracle Database Discussions

Announcement

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

10046 trace confused

KramerApr 24 2012 — edited Apr 26 2012
=====================
PARSING IN CURSOR #2 len=657 dep=0 uid=358 oct=3 lid=358 tim=1182070262728 hv=2222393979 ad='de83b938'
SELECT v_user.pm_logon_id,v_user.home_department_c, v_user.ic_n, v_user.staff_n, v_user.roster_scheme_n, v_user.meal_pref_c, v_user.work_department_c,v_user.
meal_payment_i, v_user.end_dt, v_user.ic_n as staff_work_ic_n
FROM v_ccs_op_user v_user
WHERE (v_user.end_dt IS NULL OR (TRUNC(v_user.end_dt, 'dd')>=TRUNC(to_date('2012-04-05 00:00:00','YYYY-MM-DD HH24:MI:SS'), 'dd'))) AND TRUNC(v_user.start_dt,
'dd')<=TRUNC(to_date('2012-04-05 00:00:00','YYYY-MM-DD HH24:MI:SS'), 'dd')
AND (v_user.HOME_DEPARTMENT_C IN (SELECT d.department_c FROM department d WHERE d.DIVISION_C='C') OR v_user.home_department_c IN ('Q'))
ORDER BY v_user.end_dt, v_user.start_dt ASC
END OF STMT
PARSE #2:c=0,e=4764,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1182070262719
BINDS #2:
EXEC #2:c=0,e=255,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1182070263378
WAIT #2: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=258 tim=1182070263514
*** 2012-04-24 15:41:49.623

FETCH #2:c=306350000,e=299174653,p=0,cr=22298,cu=0,mis=0,r=1,dep=0,og=1,tim=1182369438322

WAIT #2: nam='SQL*Net message from client' ela= 1454 driver id=1650815232 #bytes=1 p3=0 obj#=258 tim=1182369440799
WAIT #2: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=258 tim=1182369441012
FETCH #2:c=0,e=293,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=1,tim=1182369441265
WAIT #2: nam='SQL*Net message from client' ela= 7437 driver id=1650815232 #bytes=1 p3=0 obj#=258 tim=1182369448858
WAIT #2: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=258 tim=1182369449007
FETCH #2:c=0,e=283,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=1,tim=1182369449257
WAIT #2: nam='SQL*Net message from client' ela= 6701 driver id=1650815232 #bytes=1 p3=0 obj#=258 tim=1182369456082
WAIT #2: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=258 tim=1182369456222


-----------

I was using 10046 to trace one SQL. I used command "tail -f" to monitor the raw trace file while running the SQL. During the monitoring, I found that most of the time was spend at this step FETCH #2:c=306350000,e=299174653,p=0,cr=22298,cu=0,mis=0,r=1,dep=0,og=1,tim=1182369438322. It is high lightened on the above output.
My question is
1. what does e=299174653 mean? is it meaning the elapsed time for the fetch step or the previous step which is EXEC ?

2. if the e=299174653 means elapsed time for the current fetch step, then why this fetch cost so much of time? what is the different between this first fetch and other fetches?

3. what is the exec and fetch means here? I thought the fetch is merely reading data from buffer or data file, and exec is some other actions. but seems my understanding is not correct.

4. is there any docs or something can help to understand the trace file?


thank you very much in advance :)

Edited by: Kramer on 2012-4-24 下午7:51
Comments
Locked Post
New comments cannot be posted to this locked post.
Post Details
Locked on May 24 2012
Added on Apr 24 2012
10 comments
1,300 views