Oracle 11g業務使用者更改密碼後產生大量library cache lock等待

531968912發表於2016-07-04
Oracle密碼
DB Version:11.2.0.4+RAC
OS Version:Oracle Linux Server 6.7

在我的一個兩節點RAC資料庫上，alert日誌中平均每3秒左右就會產生一條連線超時錯誤，如下：
  1. ***********************************************************************
  2. Fatal NI connect error 12170.
  3. VERSION INFORMATION:
  4. TNS for Linux: Version 11.2.0.4.0 - Production
  5. Oracle Bequeath NT Protocol Adapter for Linux: Version 11.2.0.4.0 - Production
  6. TCP/IP NT Protocol Adapter for Linux: Version 11.2.0.4.0 - Production
  7. Time: 29-APR-2016 15:29:47
  8. Tracing not turned on.
  9. Tns error struct:
  10. ns main err code: 12535

  12. TNS-12535: TNS:operation timed out
  13. ns secondary err code: 12606
  14. nt main err code: 0
  15. nt secondary err code: 0
  16. nt OS err code: 0
  17. Client address: (ADDRESS=(PROTOCOL=tcp)(HOST=10.xxx.xx.xx)(PORT=39766))
  18. WARNING: inbound connection timed out (ORA-3136)
登入資料庫之後，檢查會話的等待事件，發現很多會話的event為library cache lock，並且發現由於library cache lock造成鎖阻塞的會話也很多，如下：

點選(此處)摺疊或開啟

  1. SYS@xxxxxxx(dmxxxxx)> select sid,event,SECONDS_IN_WAIT from v$session where state='WAITING' and event not like 'SQL%' and event not like 'rdbms%' order by SECONDS_IN_WAIT;

  3.        SID EVENT SECONDS_IN_WAIT
  4. ---------- ---------------------------------------- ---------------
  5.        921 PING 7
  6.       1382 library cache lock 10
  7.       2417 Streams AQ: qmn coordinator idle wait 21
  8.        692 library cache lock 35
  9.        349 library cache lock 35
  10.       2189 library cache lock 36
  11.       2419 library cache lock 46
  12.        235 library cache lock 46
  13.       2305 library cache lock 46
  14.       1613 library cache lock 51
  15.       1271 library cache lock 58
  16.       2303 library cache lock 74
  17.       1962 library cache lock 74
  18.       1732 library cache lock 79
  19.        468 library cache lock 95
  20.        926 library cache lock 95
  21.          6 library cache lock 106
  22.        812 library cache lock 108
  23.        348 library cache lock 118
  24.       1617 library cache lock 139
  25.        237 library cache lock 153
  26.        120 library cache lock 155
  27.       2534 library cache lock 166
  28.        469 library cache lock 171
  29.       2077 library cache lock 173
  30.       1501 library cache lock 173
  31.        696 library cache lock 173
  32.        583 library cache lock 173
  33.       2648 library cache lock 173
  34.          5 library cache lock 173
  35.       2647 library cache lock 173
  36.       2533 library cache lock 173
  37.       2422 library cache lock 173
  38.          1 smon timer 209
  39.       2532 Streams AQ: waiting for time management 1050393
  40.            or cleanup tasks

  42.        461 VKTM Logical Idle Wait 2260216

  44. --鎖阻塞查詢結果
  45.   INSTANCE SES             SESS_SERIAL# BLOCKER_INSTANCE BLOCKER_SID BLOCKER_SESS_SERIAL#
    ---------- --------------- ------------ ---------------- ----------- --------------------
             2 1729                   22581
             1   3                    14009                2        1729                22581
             1   4                     9749                2        1729                22581
             2   4                    22677                2        1729                22581
             1   119                   6855                2        1729                22581
             2   120                  11049                2        1729                22581
             1   237                   1639                2        1729                22581
             2   237                  51763                2        1729                22581
             1   349                   5499                2        1729                22581
             2   350                  18479                2        1729                22581
             1   351                   6311                2        1729                22581
             2   351                  20871                2        1729                22581
             1   464                  21611                2        1729                22581
             1   465                   7039                2        1729                22581
             1   466                   8357                2        1729                22581
             2   469                   6163                2        1729                22581
             1   580                   7181                2        1729                22581
             1   582                   7545                2        1729                22581
             2   583                  15015                2        1729                22581
             2   692                  45275                2        1729                22581
             1   694                   6941                2        1729                22581
             2   696                  15463                2        1729                22581
             1   810                  28941                2        1729                22581
             2   812                  18891                2        1729                22581
             2   926                   8275                2        1729                22581
             1   1155                  5669                2        1729                22581
             1   1270                  5621                2        1729                22581
             1   1385                  9857                2        1729                22581
             1   1501                  3555                2        1729                22581
             2   1501                 21727                2        1729                22581
             1   1617                  1515                2        1729                22581
             2   1617                 14759                2        1729                22581
             2   1728                 43225                2        1729                22581
             1   1846                  3393                2        1729                22581
             1   1961                  5643                2        1729                22581
             1   2077                  4889                2        1729                22581
             2   2077                 20353                2        1729                22581
             1   2191                  5141                2        1729                22581
             2   2303                 21061                2        1729                22581
             1   2306                  5609                2        1729                22581
             1   2419                  5091                2        1729                22581
             1   2421                  7683                2        1729                22581
             2   2422                 17493                2        1729                22581
             2   2533                 15515                2        1729                22581
             2   2534                 19505                2        1729                22581
             1   2536                  6187                2        1729                22581
             1   2647                 25537                2        1729                22581
             2   2647                 41505                2        1729                22581
             1   2649                  7135                2        1729                22581
             2   2650                 21481                2        1729                22581


    50 rows selected.

從AWR報告的Time Model Statistics部分可以看到，connection management call 消耗的時間佔整個DB Time的99.95%，記得以前好象看到過由於11g的新特性密碼錯誤可能造成大量library cache lock的文章，於是上MOS也查了查相關的文件，結合dba_audit_trail檢視發現，從4月7日起到現在，平均每天約有九千多次的登入失敗記錄，那麼是不是4月7日對PAMPAS_W使用者更改密碼了呢？ 透過查詢sys.user$也得到了驗證，使用者在4月7日9點31分更改過密碼。到此問題查清了，解決方案也很簡單，通知負責應用的工程師來改正密碼。在資料庫層面也可透過設定28401事件來遮蔽密碼錯誤驗證延遲功能。
alter system set event ="28401 TRACE NAME CONTEXT FOREVER, LEVEL 1" scope=spfile;
oracle採用的這種密碼延時登入機制主要是為了防止口令猜測攻擊，我們也可以透過profile，設定密碼登入錯誤幾次後被鎖定的方式。不過不管怎樣，都應該避免應用程式源源不斷的向資料庫傳送無效的密碼。

Time Model Statistics

  • Total time in database user-calls (DB Time): 86942.6s
  • Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic
  • Ordered by % or DB time desc, Statistic name
Statistic Name Time (s) % of DB Time
connection management call elapsed time 86,899.87 99.95
DB CPU 39.93 0.05
sql execute elapsed time 26.45 0.03
parse time elapsed 8.23 0.01
hard parse elapsed time 7.58 0.01
PL/SQL execution elapsed time 0.70 0.00
PL/SQL compilation elapsed time 0.27 0.00
RMAN cpu time (backup/restore) 0.17 0.00
failed parse elapsed time 0.09 0.00
hard parse (sharing criteria) elapsed time 0.07 0.00
inbound PL/SQL rpc elapsed time 0.01 0.00
repeated bind elapsed time 0.00 0.00
DB time 86,942.64  
background elapsed time 117.33  
background cpu time 52.15


  1. SYS@xxxndbx(dmxxxx2)> select os_username,USERNAME,userhost,to_char(TIMESTAMP,'yyyy-mm-dd') qq,count(*) from dba_audit_trail
  2.   2 where timestamp > '2016-01-01 12:00:00'
  3.   3 and returncode=1017 group by os_username,username,userhost,to_char(TIMESTAMP,'yyyy-mm-dd') order by 4;

  5. OS_USERNAME USERNAME USERHOST QQ COUNT(*)
  6. --------------- ------------------------------ -------------------- ---------- ----------
  7. qqpamp0 PAMPAS_R ltxshe0kqal2 2016-04-06 3
  8. qqpamp0 PAMPAS_W ltxshe0kqal2 2016-04-06 2
  9. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-07 5495
  10. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-08 9099
  11. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-09 9105
  12. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-10 9098
  13. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-11 9070
  14. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-12 9085
  15. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-13 9088
  16. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-14 9093
  17. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-15 9117
  18. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-16 9096
  19. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-17 9099
  20. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-18 9072
  21. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-19 9121
  22. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-20 9114
  23. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-21 9118
  24. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-22 9070
  25. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-23 9112
  26. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-24 9112
  27. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-25 9091
  28. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-26 9081
  29. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-27 9105
  30. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-28 9077
  31. qqpamp0 PAMPAS_W ltxshe0ipso2 2016-04-29 5306

  33. 26 rows selected.

SYS@xxxndbx(dmxxxx2)> select ptime , ctime from sys.user$ where name='PAMPAS_W';

PTIME               CTIME
------------------- -------------------
2016-04-07 09:31:32 2015-02-09 14:01:28
Oracle 11g下要注意的幾個關於密碼方面問題：
1. 11g預設開始密碼區分大小寫，可以透過把引數設定為SEC_CASE_SENSITIVE_LOGON =FALSE 遮蔽
2. 11g密碼預設有效期180天，可以透過修改ALTER PROFILE DEFAULT[根據實際的profile] LIMIT PASSWORD_LIFE_TIME UNLIMITED;   注意需要修改密碼生效
3. 密碼錯誤驗證延遲，可以透過設定EVENT="28401 TRACE NAME CONTEXT FOREVER, LEVEL 1" 遮蔽


MOS上的相關文件：
(1309738.1)
 - LOTS OF 'LIBRARY CACHE LOCK' DURING USER LOGON AUTHENTICATION
NOTE:7715339.8 - Bug 7715339 - Logon failures causes "row cache lock" waits - Allow disable of logon delay
 - LIBRARY CACHE LOCK CAUSED BY WRONG PASSWORD LOGIN
(1620409.1)




來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/25462274/viewspace-2121465/，如需轉載，請註明出處，否則將追究法律責任。

相關文章