Amir,
Thanks for letting the list know.
Seeing olutions to unexpected little problems can save people a lot of time.
Regards
Jonathan Lewis
On Tue, 1 Feb 2022 at 14:16, Amir Hameed <axhameed@xxxxxxxxx> wrote:
Copying Oracle List.
Thank you Jonathan for pointing out the anomaly which was the root cause
of the incorrect data getting displayed in the TKP file. The file that I
have also contain the same characters at the same location, which shows
that it somehow got corrupted during tracing.
Thank you,
Amir
On Tuesday, February 1, 2022, 04:09:02 AM EST, Jonathan Lewis <
jlewisoracle@xxxxxxxxx> wrote:
Unless the trace file has been corrupted in zipping or in transit then the
problem is simply that a spurious batch of zero bytes has got into the file.
When I unzipped the file it held 447,145 lines
When I applied tkprof it reported " 116645 lines in trace file."
When I opened the file and jumped to line 116645 I saw the line after is
held 131 "^@" symbols, which I think is the representation of ascii 0 in vi
So one line of nulls got printed, and tkprof stopped when it hit them.
After deleting the line and re-running tkprof I got a summary showing:
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
----------
Parse 1245 0.23 0.27 0 111 6
0
Execute 53646 3.41 5.26 185 38683 12318
1328
Fetch 51956 69.15 1205.38 263481 1536458 60
58954
------- ------ -------- ---------- ---------- ---------- ----------
----------
total 106847 72.80 1210.93 263666 1575252 12384
60282
Misses in library cache during parse: 234
Misses in library cache during execute: 219
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total
Waited
---------------------------------------- Waited ----------
------------
library cache pin 289 0.00
0.11
library cache lock 360 0.00
0.13
db file sequential read 263725 0.53
1142.32
Disk file operations I/O 206 0.01
0.15
gc cr grant 2-way 95 0.00
0.03
gc current block 3-way 406 0.00
0.25
row cache lock 55 0.00
0.02
gc current block 2-way 10254 0.04
4.18
gc cr multi block request 1 0.00
0.00
gc cr block 2-way 590 0.00
0.24
gc cr block busy 66 0.00
0.14
gc current grant busy 201 0.00
0.12
latch: shared pool 1 0.00
0.00
enq: TO - contention 7 0.00
0.00
enq: TT - contention 3 0.00
0.00
gc current block congested 120 0.02
0.08
latch: gc element 12 0.00
0.00
gc cr block congested 12 0.00
0.00
gc cr block 3-way 157 0.00
0.09
latch: cache buffers lru chain 1 0.00
0.00
latch: gcs resource hash 1 0.00
0.00
latch: object queue header operation 1 0.00
0.00
latch: row cache objects 2 0.00
0.00
gc cr grant congested 1 0.00
0.00
gc current grant 2-way 155 0.00
0.04
gc current block busy 14 0.01
0.04
KJC: Wait for msg sends to complete 2 0.00
0.00
gc current grant congested 2 0.00
0.00
gc buffer busy release 1 0.00
0.00
gc current split 1 0.00
0.00
enq: TX - index contention 1 0.01
0.01
enq: HW - contention 1 0.00
0.00
enq: FB - contention 1 0.00
0.00
gc current multi block request 1 0.00
0.00
utl_file I/O 24 0.00
0.00
307 user SQL statements in session.
163 internal SQL statements in session.
470 SQL statements in session.
********************************************************************************
Trace file: temp1.trc
Trace file compatibility: 12.2.0.0
Sort options: default
1 session in tracefile.
307 user SQL statements in trace file.
163 internal SQL statements in trace file.
470 SQL statements in trace file.
329 unique SQL statements in trace file.
447144 lines in trace file.
1215 elapsed seconds in trace file.
Regards
Jonathan Lewis
On Mon, 31 Jan 2022 at 23:33, Amir Hameed <axhameed@xxxxxxxxx> wrote:
Hi Cary,
Attached, please find the trace file in zipped format. I am also copying
Jonathan as he was the first person who had provided his feedback, in case
he would like to look at it as well.
Thank you,
Amir