library cache lock caused by wrong password login

Well mostly when DBA’s got called, conversation start with “everything is running slow”. Sometime back got same type of call from client that, we are not able to login to the system and calls are not processed.  Well started investigation and found that lot’s of session are waiting for library cache lock wait and here is ASH report which pretty much gives the reason for this locks


          Analysis Begin Time:   08-Jun-15 09:00:00
            Analysis End Time:   08-Jun-15 09:22:00
                 Elapsed Time:        22.0 (mins)
            Begin Data Source:   V$ACTIVE_SESSION_HISTORY
              End Data Source:   V$ACTIVE_SESSION_HISTORY
                 Sample Count:     206,434
      Average Active Sessions:      156.39
  Avg. Active Session per CPU:        6.52
                Report Target:   None specified

                                                               Avg Active
Event                               Event Class        % Event   Sessions
----------------------------------- --------------- ---------- ----------
library cache lock                  Concurrency          99.36     155.39

Top Event P1/P2/P3 Values     DB/Inst: PCHGCH/PCHGCH1  (Jun 08 09:00 to 09:22)

Event                          % Event  P1 Value, P2 Value, P3 Value % Activity
------------------------------ ------- ----------------------------- ----------
Parameter 1                Parameter 2                Parameter 3
-------------------------- -------------------------- --------------------------
library cache lock               99.36 "33699225536","3006886000","5       0.43
handle address             lock address               100*mode+namespace

Top Phases of Execution       DB/Inst: PCHGCH/PCHGCH1  (Jun 08 09:00 to 09:22)

                                          Avg Active
Phase of Execution             % Activity   Sessions
------------------------------ ---------- ----------
Connection Management               99.57     155.71

Top Call Types                DB/Inst: PCHGCH/PCHGCH1  (Jun 08 09:00 to 09:22)

Call Type                                     Count % Activity Avg Active
---------------------------------------- ---------- ---------- ----------
OAUTH                                       205,543      99.57     155.71

                         Slot                                   Event
Slot Time (Duration)    Count Event                             Count % Event
-------------------- -------- ------------------------------ -------- -------
09:00:00   (2.0 min)   18,508 library cache lock               18,290    8.86
                              CPU + Wait for CPU                  123    0.06
                              enq: JS - queue lock                 65    0.03
09:02:00   (2.0 min)   18,934 library cache lock               18,768    9.09
                              CPU + Wait for CPU                  107    0.05
                              row cache lock                       21    0.01
09:04:00   (2.0 min)   18,105 library cache lock               18,001    8.72
                              CPU + Wait for CPU                   96    0.05
                              library cache pin                     3    0.00
09:06:00   (2.0 min)   16,978 library cache lock               16,853    8.16
                              CPU + Wait for CPU                  118    0.06
                              Disk file Mirror Read                 3    0.00
09:08:00   (2.0 min)   19,685 library cache lock               19,591    9.49
                              CPU + Wait for CPU                   88    0.04
                              ADR block file read                   1    0.00
09:10:00   (2.0 min)   20,215 library cache lock               20,088    9.73
                              CPU + Wait for CPU                  111    0.05
                              Streams AQ: qmn coordinator wa        6    0.00
09:12:00   (2.0 min)   19,816 library cache lock               19,696    9.54
                              CPU + Wait for CPU                  120    0.06
09:14:00   (2.0 min)   17,866 library cache lock               17,812    8.63
                              CPU + Wait for CPU                   49    0.02
                              reliable message                      4    0.00
09:16:00   (2.0 min)   17,419 library cache lock               17,318    8.39
                              CPU + Wait for CPU                   85    0.04
                              control file sequential read          6    0.00
09:18:00   (2.0 min)   19,683 library cache lock               19,582    9.49
                              CPU + Wait for CPU                  100    0.05
                              ADR block file read                   1    0.00
09:20:00   (2.0 min)   19,225 library cache lock               19,117    9.26
                              CPU + Wait for CPU                   92    0.04
                              direct path read                      6    0.00

So, as you can see from above output 155 AAS was waiting for this lock which explains why call are not completing and from line 30 and 36 we can say that something is going wrong with the authentication. Well further we can see something same in AWR also.


                                                           Avg
                                                          wait   % DB
Event                                 Waits     Time(s)   (ms)   time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
library cache lock                    3,158     751,422 2.E+05   99.6 Concurrenc
DB CPU                                            1,735            .2
inactive session                         60          57    951     .0 Other
control file sequential read         73,205          34      0     .0 System I/O
enq: PS - contention                 21,631          30      1     .0 Other

Statistic Name                                       Time (s) % of DB Time
------------------------------------------ ------------------ ------------
connection management call elapsed time             752,541.7         99.7
sql execute elapsed time                              1,814.3           .2
DB CPU                                                1,734.6           .2
PL/SQL execution elapsed time                           266.5           .0
parse time elapsed                                        8.7           .0

So, connection management was consuming majority of DB time. Unfortunately we haven’t enabled auditing due to some other issues. But, here is output from Tanel’s awesome tool.

dashtop

Well further investigating found out that this may caused because of

High “Library Cache Locks” Wait Time Due to Invalid Login Attempts (Doc ID 1309738.1)

Bug 19637855 : LIBRARY CACHE LOCK CAUSED BY WRONG PASSWORD LOGIN

About Taral
I am Rookie to Oracle Technology so let's see where it goes

Leave a comment