Data mining SASH
-- (c) Kyle Hailey 2007
All the ahs data is stored in the table
- v$ash_all
Here is a query that looks at all the databases:
actallsum.sql - condensed overview of all targets over last hour
HOST ASL GRAPH --------------- ---------- ------------------------------ # of cpus ----1----2----3----4----5----6 bsn08 1.83 +++------2- control1 1.82 ++-------2- cont01 1.28 +----- 2 bsn02 .68 ++-- 4 tsukuba10 .53 -- 2 limerock .13 2 bsn03 .06 4 devnode .02 1
HOST ASL GRAPH --------------- ---------- ------------------------------ # of cpus ----1----2----3----4----5----6 control1 2.83 +++++++--2------- cont01 1.3 ++----- 2 bsn08 .44 +- 2 tsukuba10 .42 -- 2 bsn03 .33 +- 4 bsn02 .28 +- 4 limerock .15 2 devnode .02 1
- Explanation
- "1" or "2" or "4" - represents the # of CPU's on the machine
- "+" - # pluses represent avg user load on CPU
"-" - # minuses represent avg user load Waiting
actall.sql - detailed view on all targets
DB AVE_ACT_SESS WAIT_EVENT
-------------------- ------------ ----------------------------------------
bsn02.cdb .2 enqueue
control2.cdb .14 log file sync
.24 direct path read
.25 db file sequential read
.55 direct path write
1.34 db file scattered read
2.32 enqueue
5.98 ON CPU
bsn03.cdb .17 enqueue
In general I want to look at just one database at a time. (for example if one is having performance problems) I also want to keep the queries somewhat compatible with Oracle 10g's V$ACTIVE_SESSION_HISTORY (which most should work with just by "create view v$ash as select * from V$ACTIVE_SESSION_HISTORY" but I haven't tried this yet) Because the repository can contain data from many targets and I didn't want to include
where dbid = :dbid
in all the queries, I instead create views that filter by dbid
drop view v$ash; create view v$ash as select * from v$ash_all where dbid = &v_dbid ;
and use
v$ash
in my queries from then on out. If I want to change target, I run
This could probably be done more efficiently by just inserting the current target into a single row table and then basing the views on a join with this table but I haven't tried that yet)
Here are data mining query examples:
act.sql Like "top 5 timed events" in statspack, but it also gives the average active sessions which is more important. The script defaults to the last 15 minutes if you hit return otherwise you can give it a start time in measured in minutes ago and a duration window in minutes. WAIT_EVENT CNT % Active Ave_Act_Sess ---------------------------------------- ------ ---------- ------------ latch free 2 .12 .01 buffer busy waits 9 .53 .04 SQL*Net more data from client 15 .88 .07 log file sync 50 2.92 .23 db file sequential read 51 2.98 .24 db file scattered read 210 12.27 .97 enqueue 262 15.3 1.21 ON CPU 1111 64.89 5.12
aveact1.sql - 06/06/07 aveact2.sql - 08/02/07 made time buckets on the hour This shows activity in 15 minute intervals, added GRAPH (before it ws just #s) aveact3.sql - 08/03/07 - fixed anomaly with subtracting out BACKGROUND waits from total. I don't care about background waits but I do care about displaying BACKGROUND CPU Also rearranged the columns. I include NPTS (ie samples) to show accuracy. In a perfect world we would have 300 points (samples) per 15 minute bucket. This doesn't work out for a couple reasons. One sampling doesn't happen every 3 seconds as requested and two, if there is no data collected, then there is no insert. I'll probably change the collection to include place holders for no data so this isn't a problem.
This is like and ASCII version of OEM 10g's performance page
TM NPTS AVEACT GRAPH CPU WAITS ---------------- ------ ------- ------------------------------ ---------- ---------- 02-AUG 16:45:00 261 .03 2 2 5 02-AUG 17:00:00 285 .16 - 2 6 41 02-AUG 17:15:00 283 .36 +- 2 31 72 02-AUG 17:30:00 290 1.12 +---- 2 70 254 02-AUG 17:45:00 248 .12 - 2 4 26 02-AUG 18:00:00 211 .27 - 2 9 47 02-AUG 18:15:00 196 .34 +- 2 24 42 02-AUG 18:30:00 276 .76 +--- 2 54 156 02-AUG 18:45:00 268 1.22 +----- 2 78 248 02-AUG 19:00:00 186 1.54 +------- 2 36 251 02-AUG 19:15:00 205 .09 2 7 11 02-AUG 19:30:00 262 .69 +-- 2 65 115 02-AUG 20:45:00 219 1.81 ++------- 2 86 311
"+" - represent CPU usage "-" - represent wait time "2" in the GRAPH is the number of CPUS on this machine GRAPH is a graphical representation of AVEACT (ASL)
aveactn2.sql same as above but with top events TO_CHAR(STA SAMPLES FASL FIRST SASL SECOND GRAPH ----------- ------- ---- --------------- ---- --------------- --------------- 31 02:45:00 14 .71 db file sequent .50 CPU +++----- 2 31 03:00:00 258 .48 db file sequent .31 log file sync +------- 2 31 03:15:00 214 .17 CPU .15 log file sync +-- 2 31 03:30:00 268 .30 db file sequent .21 log file sync +---- 2 31 03:45:00 284 .55 db file sequent .27 CPU +------ 2 31 04:00:00 222 .55 db file sequent .47 log file sync +-------- 2 31 04:15:00 194 .30 CPU .26 log file sync +---- 2 31 04:30:00 251 .29 db file sequent .22 CPU +--- 2 31 04:45:00 280 .57 db file sequent .29 CPU +----- 2 31 05:00:00 212 .93 db file sequent .38 log file sync +---------2-- 31 05:15:00 210 .44 log file sync .36 db file sequent +------ 2 31 05:30:00 273 .26 db file sequent .23 log file sync +--- 2 31 05:45:00 276 .57 db file sequent .28 CPU +------ 2 31 06:00:00 234 1.09 db file sequent .50 db file scatter ++--------2---- "+" - represent CPU usage "-" - represent wait time "2" in the GRAPH is the number of CPUS on this machine "+" - represent CPU usage "-" - represent wait time "2" in the GRAPH is the number of CPUS on this machine ASL - Active Session Load FASL - first (top) event measuerd in ASL SASL - second most event measuerd in ASL
longsql.sql This shows the longest running queries. The higher the count the longer they have been running (you can't do this with 10g ASH) START_TIME COUNT(*) SQL_ID FIXED_TABLE_SEQUENCE TOPN ------------ ---------- ---------- -------------------- ---------- JUN-01 02:00 29 795857215 34254 1 JUN-01 02:00 29 795857215 34547 1 JUN-01 02:00 29 986013188 34305 1 JUN-01 02:15 105 452165714 35961 1 JUN-01 02:15 102 866152581 35999 2 JUN-01 02:30 119 2586830956 39017 1 JUN-01 02:30 109 452165714 39130 2
topsqln.sql This is really cool. It shows the top sql and then breaks their time down into the top 3 events SQL_ID TOT FPCT FIRST SPCT SECOND TPCT THIRD ---------- --- ----- -------------- ---- -------------- ---- ------------- 288152548 1 1.00 db file sequent 3417348745 4 .75 enqueue .25 db file sequent 2641200096 6 1.00 ON CPU 2053128062 13 .92 ON CPU .08 db file sequent 3186842843 18 .89 log file sync .11 ON CPU 3003979045 101 .59 enqueue .39 ON CPU .02 db file sequent 795857215 248 .50 db file scatter .46 ON CPU .02 buffer busy wai 986013188 248 .50 ON CPU .45 db file scatter .02 buffer busy wai 452165714 253 .97 ON CPU .03 db file scatter 866152581 253 1.00 ON CPU 2586830956 253 .99 ON CPU .01 db file scatter .00 db file sequent 2710468782 335 .49 ON CPU .35 enqueue .10 db file sequent
ash_waiters.sql just a formatted dump from v$ash also translates enqueues into type and mode SAMPLE_TIME USERNAME SID SERIAL HASH_VALUE STATUS --------------- ---------- ----- -------- ---------- -------------------- JUN-01 02:28:02 SIMULATOR 27 5 866152581 direct path read SIMULATOR 30 2 986013188 ON CPU SIMULATOR 32 1 452165714 direct path read SIMULATOR 36 489 2586830956 ON CPU SIMULATOR 38 543 795857215 ON CPU JUN-01 02:28:05 SIMULATOR 27 5 866152581 direct path write SIMULATOR 30 2 986013188 db file sequential r SIMULATOR 32 1 452165714 direct path read SIMULATOR 36 489 2586830956 direct path read SIMULATOR 38 543 795857215 db file scattered re JUN-01 02:28:08 SIMULATOR 27 5 866152581 direct path read SIMULATOR 30 2 986013188 db file sequential r SIMULATOR 32 1 452165714 direct path write SIMULATOR 36 489 2586830956 direct path read SIMULATOR 38 543 795857215 db file scattered re JUN-01 02:28:11 SIMULATOR 27 5 866152581 direct path read SIMULATOR 30 2 986013188 db file sequential r SIMULATOR 32 1 452165714 direct path read SIMULATOR 36 489 2586830956 direct path read SIMULATOR 38 543 795857215 db file scattered re topenq.sql shows the top locks /* some object names are missing, some block#s seem to be 0 */ OBJECT_NAME OBJ# FILE# BLOCK# COUNT(*) TY M ------------------------- ---------- ---------- ---------- ---------- -- - 115628 13 117610 98 TX 4 BX_CMTS_QOS_P_C 104667 10 0 98 TX 4 115628 4 453191 99 TX 4 115379 12 554559 100 TX 4 BX_CMTS_CPU_HOUR_FACTS_CM 104651 11 0 100 TX 4 BX_VA_CM_HOUR_CM 115842 13 124725 105 TX 4 115379 12 1306554 107 TX 4 topobj.sql shows the top objects and associated events OBJECT_NAME CURRENT_OBJ# COUNT(*) WAIT_NAME ------------------------- ------------ ---------- ------------------------------ CM_HOUR_FACTS 115393 23515 db file scattered read CM_HOUR_FACTS 115147 21765 db file scattered read CM_HOUR_FACTS 115639 21428 db file scattered read CM_HOUR_FACTS 116131 12331 db file scattered read BX_VA_CM_HOUR_CM 115380 7525 enqueue BX_VA_CM_HOUR_CM 115629 6932 enqueue CM_HOUR_FACTS 116652 5761 db file scattered read BX_VA_CM_HOUR_CM 115110 5578 enqueue CM_HOUR_FACTS 115885 5350 db file scattered read CM_HOUR_FACTS 114847 4613 db file scattered read BX_VA_CM_HOUR_CM 116130 4108 enqueue
topsesl.sql top sessions SID NAME PROGRAM CPU WAIT TOTAL ------ -------------- ---------------------------- ------ ------ ------ 26 SIMULATOR 2138 1832 3970 57 SIMULATOR 2644 1576 4220 35 SIMULATOR 2176 2346 4522 15 SIMULATOR 2151 2412 4563 38 SIMULATOR 2038 2533 4571 64 SIMULATOR 3060 1543 4603 70 SIMULATOR 3086 1797 4883 aveactcpu.sql shows the average active session load and then graphs that where the | represent maximum CPU sort of a ASCII version of the OEM 10g performance page
START_TIME AVEACT CPU WAITS GRAPH
------------ ------- ---------- ---------- ------------------------------
JUN 12 11:20 4.00 8 4 ++++|++---
JUN 12 11:20 .38 46 59 |
JUN 12 11:36 .06 1 16 |
JUN 12 11:51 .21 19 32 |
JUN 12 12:06 .72 115 62 +- |
JUN 12 12:20 .66 95 62 +- |
JUN 12 12:36 .05 4 10 |
JUN 12 12:51 .15 14 16 |
JUN 12 13:06 .95 137 93 +- |
JUN 12 13:20 .43 57 57 |
JUN 12 13:36 .08 1 22 |
JUN 12 13:51 .16 17 15 |
JUN 12 14:06 .64 84 76 +- |
JUN 12 14:20 .85 107 90 +- |
JUN 12 14:36 .13 0 22 |
JUN 12 15:23 .21 3 47 |
JUN 12 15:36 .14 2 38 |
JUN 12 15:51 .19 26 13 |
JUN 12 16:06 .59 80 54 + |
JUN 12 16:20 .95 126 102 +- |
JUN 12 16:36 .08 0 20 |
JUN 12 16:51 .24 29 18 |
sqlstats.sql
get statistics for a particular SQL statement
Enter value for hash_value: 418113968
old 10: where hash_value=&hash_value
new 10: where hash_value=418113968
TO_CHAR(SAMPLE_ EXECUTIONS ELAPSED_TIME ROWS_PROCESSED
--------------- ---------- ------------ --------------
13-JUN-07 12:46
13-JUN-07 13:00 0 0 0
13-JUN-07 14:00 1 9520780 75416
13-JUN-07 15:00 1 9036535 75416
13-JUN-07 16:00 1 10230288 75416
13-JUN-07 17:00 1 10933131 75416
Get the explain plan for a particular statement
(you need to get the address which the above queries don't do, yet,
but you can just add "address" in the return values of any of the
above sql related queries)
find the address for the sql statement and get the explain plan SELECT * FROM TABLE( dbms_xplan.display('V$ASH_SQLPLANS','540940D0') );
----------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| ----------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | | | | | 1 | SORT ORDER BY | | 939K| 337M| 75891 (1)| |* 2 | FILTER | | | | | | 3 | SORT GROUP BY | | 939K| 337M| 75891 (1)| | 4 | VIEW | | 939K| 337M| | | 5 | UNION-ALL | | | | | |* 6 | HASH JOIN | | 6183 | 603K| 309 (0)| |* 7 | TABLE ACCESS FULL | TOPOLOGY_LINK | 6137 | 113K| 51 (0)| |* 8 | HASH JOIN | | 6144 | 486K| 249 (0)| |* 9 | TABLE ACCESS FULL | TOPOLOGY_LINK | 6137 | 113K| 51 (0)| |* 10 | HASH JOIN | | 6140 | 371K| 190 (0)| |* 11 | TABLE ACCESS FULL | TOPOLOGY_LINK | 6137 | 113K| 51 (0)| |* 12 | HASH JOIN | | 6137 | 257K| 133 (0)| |* 13 | TABLE ACCESS FULL | TOPOLOGY_LINK | 6137 | 113K| 51 (0)| |* 14 | TABLE ACCESS FULL | TOPOLOGY_NODE | 37660 | 882K| 66 (0)| |* 15 | TABLE ACCESS FULL | CM_BYTES | 132K| 2971K| 370 (0)| |* 16 | TABLE ACCESS BY INDEX ROWID | CM_EVENTS | 1 | 8 | 2 (50)| |* 17 | INDEX SKIP SCAN | PK_CM_EVENTS | 1 | | | |* 18 | TABLE ACCESS FULL | CM_POWER_2 | 168K| 3464K| 467 (0)| |* 19 | TABLE ACCESS FULL | CM_POWER_1 | 170K| 2825K| 396 (0)| |* 20 | TABLE ACCESS FULL | CM_ERRORS | 168K| 4759K| 538 (0)| |* 21 | TABLE ACCESS FULL | CM_QOS_PROF | 172K| 3202K| 496 (0)| | 22 | INLIST ITERATOR | | | | | | 23 | TABLE ACCESS BY INDEX ROWID| CM_VA | 121K| 10M| 2 (50)| |* 24 | INDEX RANGE SCAN | PK_CM_VA | 1 | | 2 (0)| -----------------------------------------------------------------------------------------
Predicate Information (identified by operation id): ---------------------------------------------------
2 - filter(NVL(SUM("BYTES_UP"),0)+NVL(SUM("BYTES_DOWN"),0)+NVL(SUM("RESET_COUNT"),0)+N
VL(AVG("TXPOWER_UP"),0)+NVL(AVG("RXPOWER_DOWN"),0)+NVL(AVG("RXPOWER_UP"),0)+NVL(MAX("CER_
DOWN"),0)+NVL(MAX("CCER_DOWN"),0)+NVL(MIN("SNR_DOWN"),0)+NVL(MAX("NODE_PROFILE_ID"),0)<>0
AND MAX("CM_ID") IS NOT NULL AND MAX("UP_ID") IS NOT NULL AND MAX("DOWN_ID") IS NOT
NULL AND MAX("MAC_ID") IS NOT NULL AND MAX("CMTS_ID") IS NOT NULL)
6 - access("PARENTID"="TOPOLOGYID")
7 - filter("TOPOLOGYID_NODETYPEID"=128 AND "STATEID"=1)
8 - access("PARENTID"="TOPOLOGYID")
9 - filter("TOPOLOGYID_NODETYPEID"=127 AND "STATEID"=1)
10 - access("PARENTID"="TOPOLOGYID")
11 - filter("TOPOLOGYID_NODETYPEID"=129 AND "STATEID"=1)
12 - access("TOPOLOGYID"="TOPOLOGYID")
13 - filter("TOPOLOGYID_NODETYPEID"=2002 AND "STATEID"=1)
14 - filter("STATEID"=1)
15 - filter("SECONDID"=1181696520 OR "SECONDID"=1181696700 OR "SECONDID"=1181697600 OR
"SECONDID"=1181698500 OR "SECONDID"=1181699400)
16 - filter(TRUNC("TSTAMP",'fmhh24')=TRUNC(SYSDATE@!-.041666666666666666666666666666666
6666667,'fmhh24'))
17 - access("EVENTID"=3)
filter("EVENTID"=3)
18 - filter("SECONDID"=1181696520 OR "SECONDID"=1181696700 OR "SECONDID"=1181697600 OR
"SECONDID"=1181698500 OR "SECONDID"=1181699400)
19 - filter("SECONDID"=1181696520 OR "SECONDID"=1181696700 OR "SECONDID"=1181697600 OR
"SECONDID"=1181698500 OR "SECONDID"=1181699400)
20 - filter("SECONDID"=1181696520 OR "SECONDID"=1181696700 OR "SECONDID"=1181697600 OR
"SECONDID"=1181698500 OR "SECONDID"=1181699400)
21 - filter("SECONDID"=1181696520 OR "SECONDID"=1181696700 OR "SECONDID"=1181697600 OR
"SECONDID"=1181698500 OR "SECONDID"=1181699400)
24 - access("SECONDID"=1181696520 OR "SECONDID"=1181696700 OR "SECONDID"=1181697600 OR
"SECONDID"=1181698500 OR "SECONDID"=1181699400)
avewaits.sql
START_TIME TOT FPCT FIRST SPCT SECOND TPCT THIRD
------------ ------ ------- --------------- ------- --------------- ------- ---------------
JUL 16 16:35 4 .40 log file sync .20 ON CPU .20 control file pa
JUL 16 16:40 13 1.00 control file pa
JUL 16 16:50 5 .60 log file sync .40 ON CPU
JUL 16 16:56 7 1.00 control file pa
JUL 16 17:00 19 .63 direct path wri .26 ON CPU .11 SQL*Net more da
JUL 16 17:10 105 .74 ON CPU .10 db file paralle .10 log buffer spac
JUL 16 17:19 8 .50 direct path wri .38 log file sync .13 db file scatter
JUL 16 17:22 2 1.00 rdbms ipc reply
JUL 16 17:24 61 .67 ON CPU .16 log buffer spac .07 db file paralle