Oracle FAQ | Your Portal to the Oracle Knowledge Grid |
Home -> Community -> Usenet -> c.d.o.server -> Inconsistency in 10046 trace result with 'ela=' value ?
Hi,
I've just traced an insert that annoys us (takes about 6 minutes);
then I edited the trc file, isolated the lines related to the INSERT
statement and kept only the values of the 'ela=' variable in a small
file called 'elaVals', and quickly did the following in ksh:
integer j=0
cat elaVals | while read fig;do
let j=$fig+$j
echo "ela=$fig, total=$j"
done>result
At the end of my 'result' file I get
...
ela=20, total=5329048
ela=23, total=5329071
so apart from all the rest in my trace file the insert itself took a
bit
more than 5 seconds OK ? (see Metalink note 352184.1)
1/ how come that my trace file shows a duration of a few seconds
when I know my insert lasts about 6 minutes really (the rest of
the trc file contents -recursive sql- is negligible) ???
2/ now if I use the 'tim=' values to compute the duration of the
execution I get totally unconsistent results with those previously
calculated with 'ela=' (18 seconds):
# > head -1 elaVals
WAIT #26: nam='SQL*Net message to dblink' ela= 8 driver id=1413697536
#bytes=1 p3=0 obj#=-1 tim=3366162081889
# > tail -1 elaVals
WAIT #26: nam='SQL*Net more data from dblink' ela= 23 driver
id=1413697536 #bytes=37 p3=0 obj#=73496 tim=3366180179725
# > echo $((3366180179725-3366162081889))
18097836
Where does this difference (5.3 seconds on one side, 18 seconds on the
other) come from ? When you sum up 'ela=' values shoudn't it amount
to the difference between the last timer values and the first one ?
Thanks.
SR
Received on Tue Apr 24 2007 - 07:28:46 CDT