Table of Contents
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