July 3, 2012

MMAN in idle state but blocking other sessions which waiting 'SGA: allocation forcing component growth'

Find many blocking in one instance of an three nodes Rac DB.
Most sessions are either hang or running slow, after tracing found the blocker is MMAN process.

Below is from the trace:

Chain 1:
-------------------------------------------------------------------------------
    Oracle session identified by:
    {
                instance: 1 (apccfp1.apccfp11)
                   os id: 15557
              process id: 64, oracle@alpcispdb604 (J001)
              session id: 2
        session serial #: 23481
    }
    is waiting for 'latch free' with wait info:
    {
                      p1: 'address'=0x6003f518
                      p2: 'number'=0x189
                      p3: 'tries'=0x0
            time in wait: 22.106728 sec
           timeout after: never
                 wait id: 3995
                blocking: 0 sessions
             current sql: UPDATE T_XXXX HSC SET (HSC.HOSTAPP_STATE_ID, HSC..................
            wait history:
              * time between current wait and wait #1: 0.023292 sec
              1.       event: 'gc current block 2-way'
                 time waited: 0.000410 sec
                     wait id: 3994            p1: ''=0x1
                                              p2: ''=0x1a32e
                                              p3: ''=0x1
              * time between wait #1 and #2: 0.000438 sec
              2.       event: 'library cache pin'
                 time waited: 0.000327 sec
                     wait id: 3993            p1: 'handle address'=0x1b7e8b1f0
                                              p2: 'pin address'=0x13b609ef0
                                              p3: '100*mode+namespace'=0xffffffff00160002
              * time between wait #2 and #3: 0.000158 sec
              3.       event: 'library cache lock'
                 time waited: 0.000374 sec
                     wait id: 3992            p1: 'handle address'=0x1b7e8b1f0
                                              p2: 'lock address'=0x172458968
                                              p3: '100*mode+namespace'=0xffffffff00160002
    }
    and is blocked by
 => Oracle session identified by:
    {
                instance: 1 (apccfp1.apccfp11)
                   os id: 15454
              process id: 65, oracle@alpcispdb604
              session id: 28
        session serial #: 33079
    }
    which is waiting for 'SGA: allocation forcing component growth' with wait info:
    {
            time in wait: 0.047688 sec (last interval)
            time in wait: 4.538964 sec (total)
      heur. time in wait: 4.539095 sec
           timeout after: never
                 wait id: 44447
                blocking: 17 sessions
             current sql: 
            wait history:
              * time between current wait and wait #1: 0.000000 sec
              1.       event: 'SGA: allocation forcing component growth'
                 time waited: 0.000053 sec
                     wait id: 44535
              * time between wait #1 and #2: 0.000000 sec
              2.       event: 'SGA: allocation forcing component growth'
                 time waited: 0.050851 sec (last interval)
                 time waited: 4.491223 sec (total)
                     wait id: 44447
              * time between wait #2 and #3: 0.000000 sec
              3.       event: 'SGA: allocation forcing component growth'
                 time waited: 0.000122 sec
                     wait id: 44534
    }
    and is blocked by
 => Oracle session identified by:
    {
                instance: 1 (apccfp1.apccfp11)
                   os id: 25858
              process id: 18, oracle@alpcispdb604 (MMAN)
              session id: 451
        session serial #: 1
    }
    which is waiting for 'rdbms ipc message' with wait info:
    {
                      p1: 'timeout'=0x1f
            time in wait: 0.047679 sec
           timeout after: 0.262321 sec
                 wait id: 3739777
                blocking: 18 sessions
             current sql: 
            wait history:
              * time between current wait and wait #1: 0.000060 sec
              1.       event: 'rdbms ipc message'
                 time waited: 0.050904 sec
                     wait id: 3739776         p1: 'timeout'=0x24
              * time between wait #1 and #2: 0.000067 sec
              2.       event: 'rdbms ipc message'
                 time waited: 0.050946 sec
                     wait id: 3739775         p1: 'timeout'=0x29
              * time between wait #2 and #3: 0.000055 sec
              3.       event: 'rdbms ipc message'
                 time waited: 0.050844 sec
                     wait id: 3739774         p1: 'timeout'=0x2e
    }

Chain 1 Signature: 'rdbms ipc message'<='SGA: allocation forcing component growth'<='latch free'
Chain 1 Signature Hash: 0xd39c75b6
-------------------------------------------------------------------------------

There are mutiple other chains, but all chains' root is MMAN.

From above we can see some sessions were facing suffcient memory issue, hence waiting MMAN to turn memory for them.

These blocked sessions were also hodling some resouces, as a result they were blocking more sessions.

And during the whole time, MMAN is idle and do nothing.
We tried to flush shared_pool but also hang, also blocked by MMAN. Since MMAN is critical background process, we can't kill it. Therefore we had to bounce the first instance at last.

0 Comments:

Post a Comment