Archives 2023

Get All The Wait Events With Respect To Their Class Oracle

SELECT distinct name,wait_class FROM v$event_name;
Executes (SQL) in AWR report

What is Executes (SQL) in the AWR report?

This statistics tell the total number of SQL executions in the database during the snap time period.

Add up all the SQL executions in the database with respect to parse, cpu, elapsed, shared memory, version count, buffer gets, physical IO reads etc.. and those counts lead to Executes (SQL)

SQL> SELECT dhs.STARTUP_TIME,count(dhash.sql_id) "Executes (SQL)" FROM dba_hist_snapshot dhs, dba_hist_active_sess_history dhash where dhs.snap_id = dhash.snap_id group by dhs.STARTUP_TIME;

STARTUP_TIME         Executes (SQL)
-------------------- --------------
23-NOV-23 01.42.32.0            829
00 PM

27-NOV-23 06.24.18.0          10374
00 PM

20-NOV-23 10.35.26.0           6634
00 AM

28-NOV-23 08.25.34.0            282
00 PM

STARTUP_TIME         Executes (SQL)
-------------------- --------------

22-NOV-23 09.57.28.0           2516
00 AM
Determine the SQL response time In Oracle Database

SYSMETRIC views contain a metric called “SQL Service Response Time ” which is essential to determine the response time of all the SQL statements executed in the database to the baseline.

SQL> SELECT METRIC_NAME,VALUE from v$sysmetric WHERE METRIC_NAME like '%SQL Service%';

METRIC_NAME                                                           VALUE
---------------------------------------------------------------- ----------
SQL Service Response Time                                        .011957718

SQL> SELECT dhs.begin_interval_time,dhss.metric_name,dhss.minval,dhss.maxval,dhss.average,dhss.standard_deviation FROM dba_hist_snapshot dhs
  2  INNER JOIN dba_hist_sysmetric_summary dhss on (dhs.snap_id = dhss.snap_id) WHERE dhss.metric_name like '%SQL Servic%';

BEGIN_INTERVAL_TIME  METRIC_NAME              MINVAL     MAXVAL    AVERAGE STANDARD_DEVIATION
-------------------- -------------------- ---------- ---------- ---------- ------------------
20-NOV-23 10.35.26.0 SQL Service Response          0 1.40889148 .575633399         .395105987
00 AM                 Time

20-NOV-23 01.30.26.3 SQL Service Response          0 .045405956  .01109194         .007332756
94 PM                 Time

20-NOV-23 02.30.00.5 SQL Service Response          0 .032247838 .013252627          .00527279
62 PM                 Time

20-NOV-23 07.30.09.3 SQL Service Response          0 .453042102 .044202427         .064546493
11 PM                 Time

22-NOV-23 03.30.54.2 SQL Service Response          0 .197997813 .074285082         .032879824
01 PM                 Time
Intermittent ORA-12012, ORA-00054, ORA-06512 Errors During Auto Stats Job

  • Intermittent ORA-12012, ORA-00054, ORA-06512 Errors During Auto Stats Job
  • High CPU usage is observed

Snap Time Load %busy %user %sys %idle %iowait
14-Apr 22:15:55 18.66 95.52<======= 69.32 26.20 4.48 2.83

*** SERVICE NAME:(SYS$USERS) 2023-04-06 22:01:59.511
*** MODULE NAME:(DBMS_SCHEDULER) 2023-04-06 22:01:59.511
*** ACTION NAME:(ST$AUTO10778_99) 2023-04-06 22:01:59.511
*** CLIENT DRIVER:() 2023-04-06 22:01:59.511

ORA-12012: error on auto execute of job “SYS”.”ST$AUTO10778_99″
<error barrier> at 0xfffffffffff1970 placed
ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired
ORA-06512: at “SYS.DBMS_STATS”, line 40807
ORA-06512: at “SYS.DBMS_STATS”, line 40361
ORA-06512: at “SYS.DBMS_STATS”, line 40083
ORA-06512: at “SYS.DBMS_STATS”, line 38960
ORA-06512: at “SYS.DBMS_STATS”, line 17786
ORA-04022: nowait requested, but had to wait to lock dictionary object
ORA-06512: at “SYS.DBMS_STATS”, line 1800
ORA-06512: at “SYS.DBMS_STATS”, line 17545
ORA-06512: at “SYS.DBMS_STATS”, line 38910
ORA-06512: at “SYS.DBMS_STATS”, line 39786
ORA-06512: at “SYS.DBMS_STATS”, line 40344
ORA-06512: at “SYS.DBMS_STATS”, line 40780
ORA-06512: at line 1

  • ‘concurrent’ option is enabled for statistics preference globally.
  • Auto stats jobs wait on event ‘library cache lock’ to acquire dictionary object with nowait.

Blocking Sid (Inst) % Activity Event Caused % Event User Program # Samples Active XIDs
208,63039( 1) 1.13 library cache lock 1.13 SYS oracle (J017) 6/180 [ 3%] 0

  •  High cpu usage is observed and Resource manager throttles the cpu usage due to consumer group threshold.

Event Waits Total Wait Time (sec) Avg Wait % DB time Wait Class
resmgr:cpu quantum 22,817 4736,7 207.59ms 28.5 Scheduler
enq: TM – contention 502 3461,9 6896.28ms 20.8 Application

  •  Concurrent sessions compete to access the same object and wait for enq: TM – contention.

SQL ID Plan Hash Executions % Activity Event % Event Top Row Source % Row Source SQL Text
gkq5kmbqpm2rf 171 13.80 enq: TM – contention 13.80 ** Row Source Not Available ** 13.80 lock table wri$_optstat_histhe…
ft7wcqu3hzvca 3729177937 93 6.84 enq: TM – contention 6.72 LOAD TABLE CONVENTIONAL 6.72 insert /* QOSH:OPEN_COL_STATS …

Either add more resource to the database, if concurrent option is set.

or

Lock the table statistics sys.WRI$_OPTSTAT_HISTHEAD_HISTORY which gets failed with ora-00054 during the time of auto stats job and regather manual statistics with ‘FORCE=>TRUE’ to override the lock at a later time. Check the size and purging history for the table and reorg if needed.

EXEC dbms_stats.lock_table_stats(‘SYS’,’WRI$_OPTSTAT_HISTHEAD_HISTORY’);  

or 

Changing concurrent = ‘false’ solved the issue without deadlocks.

EXEC dbms_stats.set_global_prefs(‘concurrent’,’false’);

DBMS_STATS Waits on Streams AQ: waiting for messages in the queue

High Streams AQ: waiting for messages in the queue event observed during execution of stats job with DBMS_STATS with concurrent setting.

SQL ID: 44pgaj5vdubxy Plan Hash: 0

BEGIN dbms_stats.gather_database_stats(); END;


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      3.51   11156.78        734       1484        934           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      3.51   11156.78        734       1484        934           0

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  Disk file operations I/O                        4        0.00          0.00
  db file sequential read                       721        0.34          6.75
  control file sequential read                  600        0.00          0.00
  latch: shared pool                              1        0.00          0.00
  Streams AQ: waiting for messages in the queue
                                               1106       12.53      11146.59
  SQL*Net break/reset to client                   1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      3.51   11156.78        734       1484        934           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      3.51   11156.78        734       1484        934           0

Misses in library cache during parse: 1

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       2        0.00          0.00
  SQL*Net message from client                     1       39.74         39.74
  Disk file operations I/O                        4        0.00          0.00
  db file sequential read                       750        0.34          6.78
  control file sequential read                  600        0.00          0.00
  latch: shared pool                              1        0.00          0.00
  Streams AQ: waiting for messages in the queue
                                               1106       12.53      11146.59
  SQL*Net break/reset to client                   1        0.00          0.00

Workaround:

Disable concurrent with DBMS_STATS

select 'AUTOSTATS_TARGET =====> '||DBMS_STATS.GET_PREFS('AUTOSTATS_TARGET')||'' as "STATS_PARAM" from dual
 union all
select 'CASCADE =====> '||DBMS_STATS.GET_PREFS('CASCADE')||'' from dual
 union all
select 'CONCURRENT =====> '||DBMS_STATS.GET_PREFS('CONCURRENT')||'' as "STATS_PARAM" from dual
 union all
select 'DEGREE =====> '||DBMS_STATS.GET_PREFS('DEGREE')||'' from dual
 union all
select 'ESTIMATE_PERCENT =====> '||DBMS_STATS.GET_PREFS('ESTIMATE_PERCENT')||'' from dual
 union all
select 'GRANULARITY =====> '||DBMS_STATS.GET_PREFS('GRANULARITY')||'' from dual
 union all
select 'INCREMENTAL =====> '||DBMS_STATS.GET_PREFS('INCREMENTAL')||'' from dual
 union all
select 'INCREMENTAL_LEVEL =====> '||DBMS_STATS.GET_PREFS('INCREMENTAL_LEVEL')||'' from dual
 union all
select 'INCREMENTAL_STALENESS =====> '||DBMS_STATS.GET_PREFS('INCREMENTAL_STALENESS')||'' from dual
 union all
select 'METHOD_OPT =====> '||DBMS_STATS.GET_PREFS('METHOD_OPT')||'' from dual
 union all
select 'OPTIONS =====> '||DBMS_STATS.GET_PREFS('OPTIONS')||'' from dual
  2   union all
select 'STALE_PERCENT =====> '||DBMS_STATS.GET_PREFS('STALE_PERCENT')||'' from dual; 

STATS_PARAM
--------------------------------------------------------------------------------

CONCURRENT =====> TRUE

Use procedure.

EXEC dbms_stats.set_global_prefs('CONCURRENT','FALSE');

PL/SQL procedure successfully completed.

WHY DO WE REQUIRE LOCAL UNDO IN ORACLE MULTITENANT?

During the introduction of multitenant in 12.1.0.2 , there used to be global or shared undo tablespace for all pdb which had lot of challenges like ,

  • cold clone of pdb in open read only mode
  • Unable to refresh snapshot of pdb
  • Flashback
  • Relocation of pdb

From 12.2, local undo was introduced, which lead to lot of new features

In 12c, there was no option to check local undo.

In 19c, there is an automatic option for local undo which is enabled. It is up to the DBA, to switch on or off local undo. But disabling it, may have lot of features useless.

Local undo is used and should be recommended to use to get the following benefits

  • Hot cloning
  • PDB relocation
  • PDB proxy

By default, the undo mode is true in 19c

kIsH<X>col PROPERTY_NAME for a20
kIsH<X>col PROPERTY_VALUE for a20
kIsH<X>SELECT DISTINCT property_name, property_value FROM cdb_properties WHERE property_name like '%LOCAL_UNDO%';

PROPERTY_NAME        PROPERTY_VALUE
-------------------- --------------------
LOCAL_UNDO_ENABLED   TRUE

HOW TO ENABLE AND DISABLE SPM IN ORACLE

If a auto baseline is already enabled in database and if that baseline is always used for a sql from the management base, then that may cause interruptions for a user defined query.

I expect optimizer to use result cache for a query but as the baseline is accepted for this query with a different plan,

SQL> set autotrace traceonly


SQL> SELECT /*+ RESULT_CACHE */ count(*) from dspm;


Execution Plan
----------------------------------------------------------
Plan hash value: 3894984268

-------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Cost (%CPU)| Time     |
-------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |     1 |  1569   (1)| 00:00:01 |
|   1 |  SORT AGGREGATE    |      |     1 |            |          |
|   2 |   TABLE ACCESS FULL| DSPM |   219K|  1569   (1)| 00:00:01 |
-------------------------------------------------------------------

Note
-----
   - dynamic statistics used: dynamic sampling (level=2)
   - SQL plan baseline "SQL_PLAN_bmkkb8jb4c4yx9671ac91" used for this statement

To disable SPM for the query, i use the below procedure to do it.

SQL> var xnum number;
SQL> EXEC :xnum := dbms_spm.alter_sql_plan_baseline(plan_name=>'SQL_PLAN_bmkkb8jb4c4yx9671ac91',attribute_name=>'ENABLED',attribute_value=>'NO');

PL/SQL procedure successfully completed.

To enable SPM for the query, i use the below procedure to do it.

SQL> var xnum number;
SQL> EXEC :xnum := dbms_spm.alter_sql_plan_baseline(plan_name=>'SQL_PLAN_bmkkb8jb4c4yx9671ac91',attribute_name=>'ENABLED',attribute_value=>'YES');
LATCH FREE :space background task

Latch free is a memory related specifically shared pool event which occur due to lack of space for the session to hold a latch.

~~~~~~~~~~~~~~~~~~                                                   wait   Call
Event                                            Waits    Time (s)   (ms)   Time
----------------------------------------- ------------ ----------- ------ ------
CPU time                                                     3,914          47.2
latch free                                     234,621       2,162      9   26.1

In AWR report, the top latch with high sleep activity is space background task which is a background task which manage the latch space with the slaves.

Latch Activity  DB/Inst: DB9ZX/DB9  Snaps: 14242-14243
->"Get Requests", "Pct Get Miss" and "Avg Slps/Miss" are statistics for
  willing-to-wait latch get requests
->"NoWait Requests", "Pct NoWait Miss" are for no-wait latch get requests
->"Pct Misses" for both should be very close to 0.0

                                           Pct    Avg   Wait                 Pct
                              Get          Get   Slps   Time       NoWait NoWait
Latch                       Requests      Miss  /Miss    (s)     Requests   Miss
------------------------ -------------- ------ ------ ------ ------------ ------
space background task la         37,163   20.4    0.6      2        6,132    3.4

Top sleep breakdown related to this latch is also significant

Latch Sleep breakdown  DB/Inst: DB9ZX/DB9  Snaps: 14242-14243
-> ordered by misses desc
space background task latc          37,163        7,595       4,309       3,360

Latch Miss Sources  DB/Inst: DB9ZX/DB9 Snaps: 14242-14243
-> only latches with sleeps are shown
-> ordered by name, sleeps desc

                                                     NoWait              Waiter
Latch Name               Where                       Misses     Sleeps   Sleeps
------------------------ -------------------------- ------- ---------- --------
space background task la ktsj_grab_task                   0      2,603    4,239
space background task la ktsj_detach_task                 0      1,625       69
space background task la ktsj_smco_purgeexpired           0         75        0
space background task la ktsjCreateTask                   0          6        1

Solution:

Please increase the parameter to cache the cursors for efficient parsing and also reduce the space background process slaves which spawn higher.
.
alter system set session_cached_cursors=150 scope=spfile;
alter system set "_max_spacebg_slaves"=64;

Note: Reboot is required to set the parameter.
SGA: allocation forcing component growth

This event is printed, when the SGA is not sufficient to handle the memory load. If this event is continuously printed in the database, then there may be chances of ora-04031 or ora-04036 to occur etc..

USERNAM W_CHAINS                                            TIMER_SEC CHART_WCLASS         SQL_ID         TOTAVGACT     PER%AS
------- -------------------------------------------------- ---------- -------------------- ------------- ---------- ----------
SYS     |SGA: allocation forcing component growth [|]<~~~      160626  OOOOOOOOOOOOOOOOOOO                      .42     1608.8
        SGA: allocation forcing component growth|                     OOOOOOOOOOOOOOOOOOOO
                                                                      OOOOOOOOOOOOOOOOOOOO
                                                                      OOOOOOOOOOOOOOOOOOOO
                                                                      OOOOOOOOOOOOOOOOOOOO
                                                                      OOOOOOOOOOOOOOOOOOOO
                                                                      OOOOOOOOOOOOOOOOOOOO
                                                                      OOOOOOOOOOOOOOOOOOOO
                                                                      OOOOOOOOOOOOOOOOOOOO
                                                                      OOOOOOOOOOOOOOOOOOOO
                                                                      OOOOOOOOOOOOOOOOOOOO

Solution:

This is capacity issue of SGA and the components inside SGA grows beyond current memory size either it be AMM or ASMM.

Increase SGA.

Blocking Session And Final Blocking Session In v$session Oracle

  • What is the difference between blocking session and final blocking session?
  • Can they both be same or different?
  • When do they occur?
  • How to identify them?

Blocking session means the session which blocks another session currently and acts as the parent blocker.

Final blocking session means the child blocker which blocks another session from a parent blocker. They are part of wait chains which occur on top of the chain.

If the table is locked in exclusive mode, then the consequent sessions are blocked from this session.

SQL> LOCK table dspm in exclusive mode;

Table(s) Locked.

In another session, there is another session which execute direct path insert.
SQL> INSERT /*+APPEND PARALLEL(8) */ into dspm select * from dba_source;

====>waiting in DML lock

Both blocking and final blocking sessions are same here because session 272 is both blocking and final blocking session and need to release the lock to provide access to other sessions.

SELECT blocking_session,final_blocking_session,sid,serial# from v$session;

BLOCKING_SESSION FINAL_BLOCKING_SESSION        SID    SERIAL#
---------------- ---------------------- ---------- ----------
                                                30      53527
                                                33      43650
             272                    272        255      57902

Another scenario where blocking and final blocking sessions both are totally different. Blocking sid is 10 and final blocking sid is 247.

BLOCKING_SESSION FINAL_BLOCKING_SESSION        SID    SERIAL#
---------------- ---------------------- ---------- ----------
              10                    247        255      62576
                                               257      58720
                                               258      52129
                                               259      54077
                                               261      50178
              10                    247        262      27004
                                               263       9138
                                               264      22396
              10                    247        269      62628
              10                    247        273      43140
                                               280       1236

BLOCKING_SESSION FINAL_BLOCKING_SESSION        SID    SERIAL#
---------------- ---------------------- ---------- ----------
                                               282      42139
              10                    247        286      47997

57 rows selected.

If we further check the details, they both are derived from log writer master and slave processes where slaves are the final blocker on top of the wait chains.

SQL> col EVENT for a20
SQL> SELECT sid,username,program,module,action,event from v$session where sid in (10,247);

       SID USERNAME             PROGRAM              MODULE               ACTION               EVENT
---------- -------------------- -------------------- -------------------- -------------------- --------------------
        10                      oracle@xhydra (LGWR)                                           rdbms ipc message
       247                      oracle@xhydra (LG00)                                           LGWR worker group id
                                                                                               le

Another situation where multiple blockers are having different final blocking sid.

SQL> SELECT blocking_session,final_blocking_session,sid,serial# from v$session;

BLOCKING_SESSION FINAL_BLOCKING_SESSION        SID    SERIAL#
---------------- ---------------------- ---------- ----------
                                                 1      54950
                                                 2      61194
                                                 3      43260
                                                 5      37310
                                                 6      51617
                                                 7      21945
                                                 8      35927
                                                 9      22842
                                                10       3966
                                                11      53786
             286                     10         12      15482
              10                     10         13      32839
              10                     10         15      63226
                                                17      29137
              52                     10         18      26731
                                                19      32942
                                                20      13561
                                                23      24998
                                                24      59432
                                                30       6971
              15                     10         31      56748
                                                35       7537
              10                     10         36      10042
                                                37      25337
             262                     10         38      47235
                                                46      51123
             277                     10         47      63031
              10                     10         48      41990
              10                     10         52      36831
                                               238      56860
                                               239       8282
                                               240       8263
                                               241      60647
                                               242      36474
                                               243      45151
                                               244      26719
                                               245      26867
                                               246      47090
                                               247      10706
                                               248      40117
                                               249       9474
                                               250      33411
                                               251      26321
                                               252      38322
                                               253       2770
                                               254      57166
              10                     10        255      30058
                                               257      58720
                                               258      52129
                                               259      54077
                                               261      50178
              10                     10        262      27004
                                               263       9138
              10                     10        269      62628
              10                     10        273      43140
              48                     10        277       8681
                                               280       1236
                                               282      42139
              10                     10        285      46456
              10                     10        286      47997

60 rows selected.

There are background processes which acts as blockers and final blockers. Most of the processes are blocked by a root blocker LGWR process to further not progress.

SQL> SELECT sid,username,program,module,action,event from v$session where sid in (10,247,48,286,262,15,277,52);

       SID USERNAME             PROGRAM              MODULE               ACTION               EVENT
---------- -------------------- -------------------- -------------------- -------------------- --------------------
        10                      oracle@xhydra (LGWR)                                           rdbms ipc message
        15                      oracle@xhydra (W001) KTSJ                 KTSJ Slave           log file switch (arc
                                                                                               hiving needed)

        48                      oracle@xhydra (W006) KTSJ                 KTSJ Slave           log file switch (arc
                                                                                               hiving needed)

        52                      oracle@xhydra (M000) MMON_SLAVE           Auto-Flush Slave Act log file switch (arc
                                                                          ion                  hiving needed)

       247                      oracle@xhydra (LG00)                                           LGWR worker group id
                                                                                               le

       262                      oracle@xhydra (W003) KTSJ                 KTSJ Slave           log file switch (arc
                                                                                               hiving needed)

       277                      oracle@xhydra (J000)                                           buffer busy waits
       286                      oracle@xhydra (W005) KTSJ                 KTSJ Slave           log file switch (arc
                                                                                               hiving needed)


8 rows selected.


SID 10 is the final blocker which is the LGWR culprit which causes other processes to wait on log file switch (archiving needed) , LGWR worker group idle etc..

*** 2023-11-14T21:43:46.367100+05:30 (CDB$ROOT(1))
HM: Early Warning - Session ID 254 serial# 57166 OS PID 67156 (M001)
     is waiting on 'row cache lock' for 32 seconds, wait id 8
     p1: 'cache id'=0x16, p2: 'mode'=0x0, p3: 'request'=0x3
    Blocked by Session ID 52 serial# 36831 on instance 1
     which is waiting on 'log file switch (archiving needed)' for 32 seconds
     p1: ''=0x0, p2: ''=0x0, p3: ''=0x0
    Final Blocker is Session ID 10 serial# 3966 on instance 1
     which is waiting on 'rdbms ipc message' for 0 seconds
     p1: 'timeout'=0xe1, p2: ''=0x0, p3: ''=0x0
 
                                                     IO           
 Total  Self-         Total  Total  Outlr  Outlr  Outlr           
  Hung  Rslvd  Rslvd   Wait WaitTm   Wait WaitTm   Wait           
  Sess  Hangs  Hangs  Count   Secs  Count   Secs  Count Wait Event
------ ------ ------ ------ ------ ------ ------ ------ -----------
     0      0      0      0      0      0      0      0 row cache lock
 
 
HM: Dumping Short Stack of pid[37.67156] (sid:254, ser#:57166)
Short stack dump: 
ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+200<-__sighandler()<-semtimedop()+14<-skgpwwait()+187<-ksliwat()+2218<-kslwaitctx()+188<-kqrget()+1574<-kqrLockPo()+246<-kqrpre2()+1117<-kqrpre()+35<-kewrgns_get_next_snaphdl()+115<-kerpiGetSnapshotId()+19<-kerpiSaveReport()+90<-kerpiReportFlushActionCb()+769<-kebmscw_slave_cb_wrapper()+21<-kebmiasc_invoke_action_switch_cb()+154<-kebmpsp_pdb_switch_private()+113<-kebm_slave_main()+800<-ksvrdp_int()+1941<-opirip()+583<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+243<-0x5541F689495641D7
 
HM: Current SQL: none
 

*** 2023-11-14T21:43:48.522177+05:30 (CDB$ROOT(1))
HM: Early Warning - Session ID 18 serial# 26731 OS PID 56573 (MMON)
     is waiting on 'log file switch (archiving needed)' for 32 seconds, wait id 4573
     p1: ''=0x0, p2: ''=0x0, p3: ''=0x0
    Final Blocker is Session ID 10 serial# 3966 on instance 1
     which is waiting on 'rdbms ipc message' for 0 seconds
     p1: 'timeout'=0x10b, p2: ''=0x0, p3: ''=0x0
 
                                                     IO           
 Total  Self-         Total  Total  Outlr  Outlr  Outlr           
  Hung  Rslvd  Rslvd   Wait WaitTm   Wait WaitTm   Wait           
  Sess  Hangs  Hangs  Count   Secs  Count   Secs  Count Wait Event
------ ------ ------ ------ ------ ------ ------ ------ -----------
     6      0      0     12   1344     11   1344      0 log file switch (archiving needed)

Summary:

  • Always focus on the final blocker rather than the initial blocker as they are the root blockers.