Hello Readers,

Trust you are doing well.

Today, I am going to discuss an interesting issue we encountered in one of our 4-node RAC production databases. We observed a session spike that lasted for a couple of minutes and then resolved itself automatically. As this incident only caused brief disruption in a few application services, our customer requested a Root Cause Analysis for the event.

Our initial analysis revealed that multiple sessions were executing a particular INSERT statement on a table, contributing significantly to the session spike. These sessions were experiencing various types of waits, primarily related to cluster and index contentions.

Further investigation into the session history showed that one specific session, running an INSERT on the same table on one of the instances, was waiting for a “gc current request.” This wait state blocked all other sessions, leading to the observed session spike.

The same information was also evident in the database trace files:

*** 2024-06-12T21:33:33.906816+05:30
HM: Early Warning - Session ID 11772 serial# 60905 OS PID 60330 (FG)
     is waiting on 'gc current request' for 32 seconds, wait id 6642466
     p1: 'file#'=0x1066, p2: 'block#'=0x17080d, p3: 'id#'=0x1000001
    Session ID 11772 is blocking 40 sessions
    Blocking Session ID 3564 serial# 4067 on instance 1
     which is waiting on 'gc buffer busy acquire' for 0 seconds
     p1: 'file#'=0x1066, p2: 'block#'=0x17080d, p3: 'class#'=0x1

                                                     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 gc current request

The hanganalyze trace also revealed that the same session was the final blocker during the session spike in the initial hang chain:

-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
    Oracle session identified by:
    {
                instance: 1 (testsrv.testserver1)
                   os id: 80098
              process id: 1153, oracle@testserver1
              session id: 83
        session serial #: 5659
             module name: 0 (JDBC Thin Clientb4 (TNS V1-V3))
    }
    is waiting for 'gc buffer busy acquire' with wait info:
    {
                      p1: 'file#'=0x1066
                      p2: 'block#'=0x17080d
                      p3: 'class#'=0x1
            time in wait: 0.690331 sec
      heur. time in wait: 1 min 11 sec
           timeout after: never
                 wait id: 121
                blocking: 0 sessions
          current sql_id: 4260916539
            wait history:
              * time between current wait and wait #1: 0.000091 sec
              1.       event: 'gc buffer busy acquire'
                 time waited: 1.000067 sec
                     wait id: 120              p1: 'file#'=0x1066
                                               p2: 'block#'=0x17080d
                                               p3: 'class#'=0x1
              * time between wait #1 and #2: 0.000177 sec
              2.       event: 'gc buffer busy acquire'
                 time waited: 1.000076 sec
                     wait id: 119              p1: 'file#'=0x1066
                                               p2: 'block#'=0x17080d
                                               p3: 'class#'=0x1
              * time between wait #2 and #3: 0.000086 sec
              3.       event: 'gc buffer busy acquire'


                 time waited: 1.000069 sec
                     wait id: 118              p1: 'file#'=0x1066
                                               p2: 'block#'=0x17080d
                                               p3: 'class#'=0x1
    }
    and is blocked by
 => Oracle session identified by:
    {
                instance: 1 (testsrv.testserver1)
                   os id: 60330
              process id: 533, oracle@testserver1
              session id: 11772
        session serial #: 60905
             module name: 0 (TESTAPI:APIS V1-V3))
    }
    which is waiting for 'gc current request' with wait info:
    {
                      p1: 'file#'=0x1066
                      p2: 'block#'=0x17080d
                      p3: 'id#'=0x1000001
            time in wait: 1 min 26 sec
           timeout after: never
                 wait id: 6642466
                blocking: 116 sessions
          current sql_id: 2068535322
            wait history:
              * time between current wait and wait #1: 0.001604 sec
              1.       event: 'SQL*Net message from client'
                 time waited: 0.001287 sec
                     wait id: 6642465          p1: 'driver id'=0x28444553
                                               p2: '#bytes'=0x1
              * time between wait #1 and #2: 0.000056 sec
              2.       event: 'SQL*Net message to client'
                 time waited: 0.000001 sec
                     wait id: 6642464          p1: 'driver id'=0x28444553
                                               p2: '#bytes'=0x1
              * time between wait #2 and #3: 0.000186 sec
              3.       event: 'SQL*Net message from client'
                 time waited: 0.023844 sec
                     wait id: 6642463          p1: 'driver id'=0x28444553
                                               p2: '#bytes'=0x1
    }

Chain 1 Signature: 'gc current request'<='gc buffer busy acquire'
Chain 1 Signature Hash: 0x8823aa2a	 

From the available data, it was evident that a session running a DML statement was waiting for a “gc current request” for over 85 seconds, which is abnormal.

This issue corresponded precisely with the bug described below, for which the recommended workaround is to issue a local checkpoint at the exclusive holder instance.

Bug 34871935 [RAC] Queue Buildup – Sessions Spike With ‘gc current request’. This bug is affected on all versions below 19.19, you may request backport on top of versions below 19.19.

You can also implement a workaround by setting up a cron or scheduled job to check for any sessions waiting for a “gc current request” for more than 10 seconds and then issue a local checkpoint on the blocker instance.

It is crucial to include the following fixes in your inventory to prevent session pileups caused by GC waits.

• Bug 34871935 [RAC] QUEUE BUILDUP – SESSIONS SPIKE WITH ‘GC CURRENT REQUEST’
• Bug 34377917 [RAC] DML statement is blocked by gc current request
• Bug 34310304 [RAC] 3 Sessions Waiting for ‘gc current request’ For Long Time

Let me know for any questions and any further information in comments or LinkedIn.

Regards
Adityanath.