DBAsupport.com Forums - Powered by vBulletin
Results 1 to 6 of 6

Thread: understanding the output of TRACE file

  1. 07-28-2004, 04:22 AM #1
    newcomer
    newcomer is offline Member
    Join Date
    May 2002
    Posts
    163

    understanding the output of TRACE file

    Hi,

    Why there are so many FETCHES at a time, in the below trace file? Sometime 2 , sometime 1 and sometime a LOT. Any reason?

    Any reason to slow down the performance?

    Part of Trace file (TIMED_STATISTICS=FALSE)

    PARSING IN CURSOR #35 len=211 dep=0 uid=567 oct=6 lid=567 tim=0 hv=2584262820 ad='ce1c33a0'
    UPDATE xxxx SET xxxx.yyyy= :IN0,
    yyyyyy yyyyyyyyyyyyyyyyyyyyyyyyy yyyyyyyyyyyyyyyyyyyyyyy ......
    END OF STMT

    PARSE #35:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    EXEC #35:c=0,e=0,p=0,cr=2,cu=1,mis=0,r=1,dep=0,og=3,tim=0
    EXEC #5:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #5:c=0,e=0,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    XCTEND rlbk=0, rd_only=0
    EXEC #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=24,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=4,cr=25,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    EXEC #8:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #8:c=0,e=0,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    EXEC #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=25,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    EXEC #8:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #8:c=0,e=0,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    EXEC #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=24,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    EXEC #8:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #8:c=0,e=0,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    EXEC #8:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #8:c=0,e=0,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    EXEC #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=24,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    EXEC #8:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #8:c=0,e=0,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    EXEC #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=24,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    EXEC #8:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #8:c=0,e=0,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    EXEC #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=24,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    EXEC #8:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1108,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1113,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1108,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1112,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1112,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1108,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1112,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1108,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1112,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1112,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1109,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1112,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #9:c=0,e=0,p=0,cr=1111,cu=0,mis=0,r=100,dep=0,og=3,tim=0
    FETCH #10:c=0,e=0,p=0,cr=15,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #10:c=0,e=0,p=0,cr=154,cu=0,mis=0,r=7,dep=0,og=3,tim=0
    Nwcomer
    Student
    Reply With Quote Reply With Quote
  2. 07-28-2004, 10:10 AM #2
    tamilselvan
    tamilselvan is offline Senior Advisor
    Join Date
    May 2000
    Location
    ATLANTA, GA, USA
    Posts
    3,135
    FETCH #6:c=0,e=0,p=0,cr=24,cu=0,mis=0,r=1,dep=0,og=3,tim=0

    FETCH #9:c=0,e=0,p=0,cr=1110,cu=0,mis=0,r=100,dep=0,og=3,tim=0

    The r tells how many rows got from the table. Some times it got 1 row and another time 100.

    Do you update the table in a pl/sql block?

    How do you pass values to the bind variable?

    Tamil
    Reply With Quote Reply With Quote
  3. 07-28-2004, 10:33 AM #3
    DaPi's Avatar
    DaPi
    DaPi is offline Old Cranky Philosopher
    Join Date
    Nov 2002
    Location
    Geneva Switzerland
    Posts
    3,142
    Hi Tamil,

    How do you read that long list of "FETCH#9"?

    Always exactly 100 rows (OK , may be a function of e.g. a bulk fetch with LIMIT) BUT a remarkably constant number of consistant reads (cr) to do so! (constant to 0.2%!). That convinced me that I didn't understand what was going on.
    Reply With Quote Reply With Quote
  4. 07-28-2004, 12:17 PM #4
    rotem_fo
    rotem_fo is offline Hangin Around,,,
    Join Date
    Nov 2000
    Location
    Israel
    Posts
    268

    use tkprof

    use tkprof
    It is better to ask and appear ignorant, than to remain silent and remain ignorant.

    Oracle OCP DBA 9i,
    C++, Java developer
    Reply With Quote Reply With Quote
  5. 07-28-2004, 01:19 PM #5
    tamilselvan
    tamilselvan is offline Senior Advisor
    Join Date
    May 2000
    Location
    ATLANTA, GA, USA
    Posts
    3,135
    ===
    How do you read that long list of "FETCH#9"?
    ===
    You may be right - using bulk collect option Or they may use rownum < 101 , some thing like that.

    Tamil
    Reply With Quote Reply With Quote
  6. 07-29-2004, 04:12 AM #6
    newcomer
    newcomer is offline Member
    Join Date
    May 2002
    Posts
    163
    Hi
    Thanks for the clarification. But I still have a doubt

    EXEC #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=24,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=4,cr=25,cu=0,mis=0,r=1,dep=0,og=3,tim=0
    FETCH #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    EXEC #8:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=3,tim=0
    FETCH #8:c=0,e=0,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=3,tim=0

    1. Say first EXEC 0 rows
    2. Fetch 1 row (if teh cursor fetched 1 row only, then why there are
    3 more fetch after that?


    Lastly I have another doubt might be stupid!! forgive me !!

    When I am switching on my trace for an another session as
    dbms_system.set_sql_trace_in_session(100,12345,TRUE) and generating TKPROF. In the report I can see "Parsing user in (567, ....)

    1. Why the user is 567 here instead of 100 as SID mentioned above.


    And yes, for your info, we r setting up our commit after each 100 records.

    Regards
    Last edited by newcomer; 07-29-2004 at 04:24 AM.
    Nwcomer
    Student
    Reply With Quote Reply With Quote
« Previous Thread | Next Thread »

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •  

Forum Rules

Click Here to Expand Forum to Full Width