This is just a short note to point out that I finally uploaded a new version of TVD$XTAT. To download it click here. Not only I introduced some new features, but I also fixed several bugs.
The detailed change log since Beta 10 is the following:
- Added support for bind sets using array processing
- Added support for client driver (12.1)
- Added support for container ID (12.1)
- Added “active” template (JavaScript/jQuery required)
- Improved “html” and “text” template (including changes in tvdxtat.xsd)
- Improved processing of recursive statements
- Improved processing of parse errors
- Improved processing of missing parent cursors
- Extended the list of recognized SQL statements (12.1 + 12.2)
- Fix to correctly handle 12.2 timestamps
- Fix to correctly handle adaptive execution plans
- Fix to correctly handle empty lines and special characters located in bind sections
- Fix to correctly handle CDATA sections into the text of SQL statements
- Fix to correctly handle timestamps into the text of SQL statements
- Fix to correctly handle RPC call statistics
- Fix to use correct “less-than or equal” character in output file
- Fix to correctly handle invalid trace files
- New defaults in tvdxtat.properties: “active” template and release 12
As always, your feedback is welcome!
[…] I was running the test case multiple times letting the database grow bigger with every run. I kept running until the performance got unbearable. On my VirtualBox VM setup it took 9 runs with 10 concurrent processes for the performance to go way down south. To make it happen early I set SGA_TARGET to 800 MB which resulted in a buffer cache of about 500 MB. The larger the buffer cache the longer you can sustain. Let’s look at resource usage profile of one of the sessions from run 9. I processed the raw extended SQL trace file using Chris Antognini’s TVD$XTAT. […]
It’s a great tool Christian, thank you very much! :)
Do you have a plan to release any other updates?
Actual plan, no. But I implemented some enhancements since v11… hence, it would like to find the time to publish it.
Hi,
Thanks for your reply. But What I mean here,There is a “select statement”, Which is not recursive but time is different between tvd$xtat and tkprof.
Statement is huge so I am attaching only the relevant section. Please let me know if I am missing something here.
call count cpu elapsed disk query current rows
——- —— ——– ———- ———- ———- ———- ———-
Parse 1 0.00 0.00 0 0 6 0
Execute 3 0.62 0.64 0 0 0 0
Fetch 3 0.06 0.06 0 87 0 3
——- —— ——– ———- ———- ———- ———- ———-
total 7 0.69 0.71 0 87 6 3
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: FIRST_ROWS
Parsing user id: 113 (recursive depth: 1)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
———- ———- ———- —————————————————
1 1 1 NESTED LOOPS (cr=20 pr=0 pw=0 time=271 us starts=1 cost=4 size=935 card=1)
1 1 1 NESTED LOOPS (cr=15 pr=0 pw=0 time=243 us starts=1 cost=3 size=825 card=1)
1 1 1 NESTED LOOPS (cr=10 pr=0 pw=0 time=194 us starts=1 cost=2 size=726 card=1)
1 1 1 PARTITION HASH SINGLE PARTITION: KEY KEY (cr=5 pr=0 pw=0 time=128 us starts=1 cost=1 size=423 card=1)
1 1 1 TABLE ACCESS BY INDEX ROWID RESERVATION_NAME_E (cr=5 pr=0 pw=0 time=120 us starts=1 cost=1 size=423 card=1)
1 1 1 INDEX UNIQUE SCAN RESV_NAME_IDX PARTITION: KEY KEY (cr=3 pr=0 pw=0 time=41 us starts=1 cost=1 size=0 card=1)(object id 87324)
1 1 1 PARTITION HASH ITERATOR PARTITION: KEY KEY (cr=5 pr=0 pw=0 time=62 us starts=1 cost=1 size=303 card=1)
1 1 1 TABLE ACCESS BY INDEX ROWID NAME_E (cr=5 pr=0 pw=0 time=56 us starts=1 cost=1 size=303 card=1)
1 1 1 INDEX UNIQUE SCAN NAME_NAMEID_IDX PARTITION: KEY KEY (cr=3 pr=0 pw=0 time=12 us starts=1 cost=1 size=0 card=1)(object id 90695)
1 1 1 TABLE ACCESS BY INDEX ROWID RESV_DAILY_ELEMENT_NAME_E (cr=5 pr=0 pw=0 time=44 us starts=1 cost=1 size=99 card=1)
1 1 1 INDEX UNIQUE SCAN RESV_DAILY_ELEMENT_NAME_PK (cr=4 pr=0 pw=0 time=36 us starts=1 cost=1 size=0 card=1)(object id 91132)
1 1 1 TABLE ACCESS BY INDEX ROWID RESERVATION_DAILY_ELEMENTS_E (cr=5 pr=0 pw=0 time=22 us starts=1 cost=1 size=110 card=1)
1 1 1 INDEX UNIQUE SCAN RESERVATION_DAILY_ELEMENTS_PK (cr=4 pr=0 pw=0 time=17 us starts=1 cost=1 size=0 card=1)(object id 89712)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
—————————————- Waited ———- ————
library cache lock 67 0.00 0.01
library cache pin 78 0.00 0.01
PGA memory operation 24 0.00 0.00
********************************************************************************
Bind Variables current hide
3 bind variable sets were used to execute this statement.
Execution Batch Bind Datatype Value
1 1 1 VARCHAR2 “PROP030”
2 NUMBER “91244562”
2 1 1 VARCHAR2 “PROP030”
2 NUMBER “91244562”
3 1 1 VARCHAR2 “PROP030”
2 NUMBER “91244562”
Execution Plans current hide
Optimizer Mode FIRST_ROWS
Hash Value 3676526361
Rows Operation
1 NESTED LOOPS (cr=20 pr=0 pw=0 str=1 time=271 us cost=4 size=935 card=1)
1 NESTED LOOPS (cr=15 pr=0 pw=0 str=1 time=243 us cost=3 size=825 card=1)
1 NESTED LOOPS (cr=10 pr=0 pw=0 str=1 time=194 us cost=2 size=726 card=1)
1 PARTITION HASH SINGLE PARTITION: KEY KEY (cr=5 pr=0 pw=0 str=1 time=128 us cost=1 size=423 card=1)
1 TABLE ACCESS BY INDEX ROWID RESERVATION_NAME_E (cr=5 pr=0 pw=0 str=1 time=120 us cost=1 size=423 card=1)
1 INDEX UNIQUE SCAN RESV_NAME_IDX PARTITION: KEY KEY (cr=3 pr=0 pw=0 str=1 time=41 us cost=1 size=0 card=1) (object id 87324)
1 PARTITION HASH ITERATOR PARTITION: KEY KEY (cr=5 pr=0 pw=0 str=1 time=62 us cost=1 size=303 card=1)
1 TABLE ACCESS BY INDEX ROWID NAME_E (cr=5 pr=0 pw=0 str=1 time=56 us cost=1 size=303 card=1)
1 INDEX UNIQUE SCAN NAME_NAMEID_IDX PARTITION: KEY KEY (cr=3 pr=0 pw=0 str=1 time=12 us cost=1 size=0 card=1) (object id 90695)
1 TABLE ACCESS BY INDEX ROWID RESV_DAILY_ELEMENT_NAME_E (cr=5 pr=0 pw=0 str=1 time=44 us cost=1 size=99 card=1)
1 INDEX UNIQUE SCAN RESV_DAILY_ELEMENT_NAME_PK (cr=4 pr=0 pw=0 str=1 time=36 us cost=1 size=0 card=1) (object id 91132)
1 TABLE ACCESS BY INDEX ROWID RESERVATION_DAILY_ELEMENTS_E (cr=5 pr=0 pw=0 str=1 time=22 us cost=1 size=110 card=1)
1 INDEX UNIQUE SCAN RESERVATION_DAILY_ELEMENTS_PK (cr=4 pr=0 pw=0 str=1 time=17 us cost=1 size=0 card=1) (object id 89712)
Database Call Statistics current hide
Call Count Misses CPU [s] Elapsed [s] PIO [b] LIO [b] Consistent [b] Current [b] Rows
Parse 1 1 0.003 0.003 0 6 0 6 0
Execute 3 1 0.629 0.651 0 107 107 0 0
Fetch 3 0 0.864 0.963 120 5,189 5,045 144 3
Total 7 2 1.496 1.617 120 5,302 5,152 150 3
Average (per execution) 2 0 0.499 0.539 40 1,767 1,717 50 1
Average (per row) 2 0 0.499 0.539 40 1,767 1,717 50 1
Resource Usage Profile overall current hide
Component Total Duration [s] % Number of Events Duration per Event [s]
CPU 1.496 97.934 n/a n/a
library cache pin 0.016 1.053 78 0.000
library cache lock 0.015 0.981 67 0.000
PGA memory operation 0.000 0.033 24 0.000
Total 1.527 100.000