Create and Analyze ASH dumps

Overview

  • Don’t use time_waited column as ASH reports display results every second and sum up this data may create wrong results
  • Use the count(*) as a meaure how often a wait event is active

Getting an ASHDump

Gather ASH Dumps from ALL database instances at approximately the same time, this needs to be collected 
DURING the time of the issue (to be analyzed by CHMDB): 
SQL> oradebug setmypid 
SQL> oradebug dump ashdump 30  # this will gather 30 minutes of ASH data, you may increase this if you feel 
                               #  necessary but please do keep it under 1 hour 
SQL> oradebug tracefile_name   # upload the file shown here Repeat the above on every database instance 
                               #            (one immediately following the previous)
/u01/app/oracle/diag/rdbms/grac4/grac41/trace/grac41_ora_14901.trc
[oracle@grac41 ASH]$ cp /u01/app/oracle/diag/rdbms/grac4/grac41/trace/grac41_ora_14901.trc ash_grac41.trc
Note ash_grac41.trc has detailed info to create ashdump table and loader control file ashldr.ctl

Create ashdump table and load data

$ cat cr_tab.sql
CREATE TABLE ashdump AS SELECT * FROM SYS.WRH$_ACTIVE_SESSION_HISTORY WHERE rownum < 0;
$ sqlplus system/sys @cr_tab

Load Data
$ sqlldr system/sys  control=ashldr.ctl data=ash_grac41.trc errors=1000000
SQL*Loader: Release 11.2.0.4.0 - Production on Thu Feb 20 10:25:21 2014
Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.
Commit point reached - logical record count 19
Commit point reached - logical record count 37
Commit point reached - logical record count 55
Commit point reached - logical record count 73
Commit point reached - logical record count 91
Commit point reached - logical record count 109
Commit point reached - logical record count 127
Commit point reached - logical record count 145
Commit point reached - logical record count 161

Analyze data

SQL> select a.event_id, ev.name, count(*)  from ashdump a, v$event_name ev where a.event_id = ev.event_id
     group by a.event_id, ev.name having count(*) >= 5 order by  count(*) desc;
  EVENT_ID NAME 							  COUNT(*)
---------- ------------------------------------------------------------ ----------
1714089451 row cache lock						       274
 866018717 rdbms ipc message							89
1328744198 log file sync							62
1620694733 db file parallel write						36
1565566389 Streams AQ: qmn coordinator waiting for slave to start		33
3480025058 gcs log flush sync							32
3905407295 gc current request							18
2701629120 gc current block busy						14
3999721902 log file parallel write						13
3213517201 control file sequential read 					13
1421975091 SQL*Net message from client						13
 218649935 wait for unread message on broadcast channel 			13
3046984244 gc cr block 3-way							12

--> Row Cache Lock is the top Wait Event

Display all Wait Events in a chronological order 
SQL> select	to_char(sample_time,'HH24:MI:SS') T_STAMP,to_char(INSTANCE_NUMBER) INST, a.program,
    	ev.name,  ev.parameter1||': ' || a.p1 || '  '
   	||ev.parameter2 ||': ' || a.p2 || '  '	|| ev.parameter3||': ' || a.p3 param
    	from ashdump a, v$event_name ev where a.event_id = ev.event_id order by sample_time;
T_STAMP  INST PROGRAM				       NAME							    PARAM
-------- ---- ---------------------------------------- ------------------------------------------------------------ ------------------------------------------------------------
...
12:14:37 1    oracle@grac41.example.com (LGWR)	       log file parallel write					    files: 1  blocks: 1  requests: 1
12:14:37 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:37 1    JDBC Thin Client			       gc current grant busy					    : 4  : 587523  : 33619969
12:14:38 1    JDBC Thin Client			       SQL*Net message from client				    driver id: 1413697536  #bytes: 1  : 0
12:14:38 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:38 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:38 1    oracle@grac41.example.com (LGWR)	       log file parallel write					    files: 1  blocks: 2  requests: 1
12:14:39 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:39 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:39 1    JDBC Thin Client			       gc current request					    file#: 1  block#: 667  id#: 33554433
12:14:40 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:40 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:40 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:41 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:41 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:42 1    JDBC Thin Client			       row cache lock						    cache id: 13  mode: 0  request: 5
12:14:42 1    JDBC Thin Client			       log file sync						    buffer#: 7859  sync scn: 30731295  : 0

 

Leave a Reply

Your email address will not be published. Required fields are marked *