Currently browsing category

xtrace

Xtrace: an Oracle session trace browser – exec flow

Tracing a session is extremely useful when you need to investigate how a client interacts with the database – the client could be an application of yours, a third-party application, or an Oracle module such as dbms_stats or dbms_mview. To get the perfect picture of the client-server dialogue, you “simply” need to consider all EXEC lines in the trace file, and associate to each line the executed statement and the bind variable values; a very tedious and error-prone task when done manually, that Xtrace can make for you (and for free).…

Xtrace: an Oracle session trace browser (introduction)

Xtrace is a graphical tool that can navigate Oracle trace files, manipulate them, and optionally get them back as a text file. It actually makes (much) more, but in this first post we are going to focus on its basic browsing capabilities.

Let’s see the tool in action on the trace file produced by this simple PL/SQL block:
[sql]
begin
for r in (select * from t) loop
null;
end loop;
end;
[/sql]

The resulting trace file is
[text wraplines=”false” gutter=”false”]
WAIT #2: nam=’SQL*Net message from client’ ela= 61126 driver id=1413697536 #bytes=1 p3=0 obj#=76357 tim=5789636384898
=====================
PARSING IN CURSOR #26 len=66 dep=0 uid=73 oct=47 lid=73 tim=5789636385129 hv=3421439103 ad=’aeb809c8′
begin
for r in (select * from t) loop
null;
end loop;
end;
END OF STMT
PARSE #26:c=0,e=153,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=5789636385122
BINDS #26:
=====================
PARSING IN CURSOR #28 len=15 dep=1 uid=73 oct=3 lid=73 tim=5789636386184 hv=1406298530 ad=’a0503300′
SELECT * FROM T
END OF STMT
PARSE #28:c=0,e=804,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,tim=5789636386181
BINDS #28:
EXEC #28:c=0,e=64,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=5789636386284
WAIT #28: nam=’db file sequential read’ ela= 19 file#=4 block#=59 blocks=1 obj#=76357 tim=5789636386383
WAIT #28: nam=’db file sequential read’ ela= 11 file#=4 block#=60 blocks=1 obj#=76357 tim=5789636386457
FETCH #28:c=0,e=243,p=2,cr=3,cu=0,mis=0,r=100,dep=1,og=1,tim=5789636386566
FETCH #28:c=0,e=54,p=0,cr=1,cu=0,mis=0,r=100,dep=1,og=1,tim=5789636386663
FETCH #28:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=5789636386693
EXEC #26:c=0,e=1543,p=2,cr=4,cu=0,mis=0,r=1,dep=0,og=1,tim=5789636386746
WAIT #26: nam=’SQL*Net message to client’ ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=76357 tim=5789636387057
WAIT #26: nam=’SQL*Net message from client’ ela= 42743 driver id=1413697536 #bytes=1 p3=0 obj#=76357 tim=5789636429824
STAT #28 id=1 cnt=200 pid=0 pos=1 obj=76357 op=’TABLE ACCESS FULL T (cr=4 pr=2 pw=0 time=363 us)’
[/text]
Even for this artificially simple trace file, it takes a lot of effort to read and understand it; for example, it takes a while to associate the recursive SQL lines to the execution of the PL/SQL blocks (the “EXEC #26” line).…

Bitnami