Dateline – December 2015,
Grapevine TX, Hotsos World Headquarters
The latest and greatest version of the Harness is now available
for download from the Hotsos Education Downloads page.
This version is functionally quite different
from the old one. The use of it remains
the same, you provide a SQL script file name, a workspace and scenario name and
the test harness will run the SQL file and provide key statistics on the run, including
the Extended
SQL Trace File (10046).
How it works is quite different and it does show some
different and I believe more useful information then the old one. In version past the output included the explain
plan. However this is becoming less
useful with the new features like Cardinality Feedback in 11 and Adaptive Query
Optimization in 12. The new version of
the Harness now shows the execution plan using DBMS_XPLAN.DISPLAY_CURSOR. The format options are set to TYPICAL
ALLSTATS LAST ALIAS which I believe give you key information about
the run.
You still get the PARSE line and all the STAT
lines from the 10046 trace as part of the output. Also it still takes a snap shot of the
statistics before and after the run to show you the total work done by the
query.
But a really big change is that the Harness no longer requires
the use of a username and password. In
the old version the tool had to log off and back on a few times as trace files
were created. The new version uses the DBMS_MONITOR.SESSION_TRACE_ENABLE
and DISABLE
to create the 10046 trace file so logging off and on is no longer
required to get the full trace file. The
problem really was in the old style of creating trace file you might not get “everything”
if you just turned off trace when you were done with the statement. And a key part was the STAT lines didn’t
always get written to the trace file when you just “turned it off”. Now they do.
Also, the new Harness doesn’t create the 10053
trace anymore (CBO Enable optimizer trace). This is the trace of a hard parse and for the
most part it’s not used for performance optimization. Yes it can be interesting to look at to see
what the optimizer was “thinking” as it created a plan. There will be a separate utility to create
and load the 10053 trace added to the tool pack soon.
Please let me know of any issue you have while using the Harness.
A simple example of a run:
SQL>
@dosql emp emp emp
+-+-+-+-+-+-+
Starting
Test
+-+-+-+-+-+-+
Snapshot 1
collection OK.
Snapshot 2
collection OK.
+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
| Actual
PARSE and STAT line data for emp:emp
+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
PARSE
#383679648:c=0,e=51,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1445457117,tim=343535899973
STAT
#383679648 id=1 cnt=27 pid=0 pos=1 obj=116599 op='TABLE ACCESS FULL EMPLOYEES
(cr=363 pr=0 pw=0 time=1331 us cost=73 size=83 card=1)'
+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
| Plan using
DBMS_XPLAN.DISPLAY_CURSOR
| Format
options: TYPICAL ALLSTATS LAST ALIAS
+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
SQL_ID g76m74pycbct4, child number 0
-------------------------------------
select *
from employees where first_name = 'David'
Plan hash
value: 1445457117
----------------------------------------------------------------------------------------------------------
|Id |Operation |Name |Starts |E-Rows|E-Bytes|Cost (%CPU)|E-Time |A-Rows|
A-Time |Buffers|
----------------------------------------------------------------------------------------------------------
| 0|SELECT STATEMENT |
| 1 | |
| 73 (100)| | 27|00:00:00.01| 363|
|* 1| TABLE
ACCESS FULL|EMPLOYEES | 1 | 1|
83 | 73 (0)|00:00:01| 27|00:00:00.01| 363|
----------------------------------------------------------------------------------------------------------
Query Block
Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / EMPLOYEES@SEL$1
Predicate
Information (identified by operation id):
---------------------------------------------------
1 - filter("FIRST_NAME"='David')
+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
| Statistics
Snapshot for emp:emp
+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
Type Statistic Name Value
-----
---------------------------------------- --------------
Latch cache
buffers chains
1,040
row cache objects 55
shared pool 33
Stats buffer
is pinned count
0
consistent gets 363
consistent gets direct 0
db block changes 0
db block gets 0
execute count 6
index fast full scans (full) 0
parse count (hard) 0
parse count (total) 6
physical reads 0
physical writes 0
redo size 0
session logical reads 363
session pga memory 0
session pga memory max 0
session uga memory 0
session uga memory max 0
sorts (disk) 0
sorts (memory) 0
sorts (rows) 0
table fetch by rowid 0
table scan blocks gotten 355
table scans (long tables) 0
table scans (short tables) 1
Time elapsed time (centiseconds) 3
+-+-+-+-+-+-+
Test
Complete
+-+-+-+-+-+-+
SQL>
Happy Optimizing!
