首页 » Cloud, ORACLE 9i-23ai » Oracle 12C wait ‘library cache lock’ after change password even set 28401 event 案例
Oracle 12C wait ‘library cache lock’ after change password even set 28401 event 案例
《library cache lock或row cache lock, Failed Logon Delay 因为错误的密码尝试》和《oracle 12c等待事件： Failed Logon Delay》记录过用户密码错误尝试导致数据库出现大量的library cache lock 和row cache lock。 主要是在11g引入的安全特性延迟密码认证在3-10秒，在延迟期间以X模式持有row cache lock防止同一用户的并发失败尝试。通常是配置28401 event禁用延迟认证特性,但这也不是“万能药”，像这次的案例。 除了密码延迟认证，PASSWORD_LIFE_TIME和FAILED_LOGIN_ATTEMPTS 也是用户的警惕的地方。
密码错误尝试的症状有：
1， 非常高的library cache lock(ACCOUNT)和row cache lock(dc_user)
2， v$session.username为空，因为认证还没通过
3，alter user命令会hang 等待’library cache lock’ or ‘row cache lock’，等待几分钟后最终会成功
4， 锁定用户后，等待时间消失
这是一个12C r2的数据库，通常配置28401 event消失，但这个案例并没有，下面记录一下。
修改了密码以后
SQL> alter user xx identified by xxx;
SQL>@ase.sql
USERNAME SID EVENT MACHINE MODULE STATUS LAST_CALL_ET SQL_ID WAI_SECINW ROW_WAIT_OBJ# SQLTEXT BS CH# OSUSER HEX
----------- ---------- -------------------- ---------- -------------------- -------- ------------ --------------- ---------- ------------- ------------------------------ ---------- ---- ---------- ---------
1212 row cache lock xxxxxxxxxx sqlplus ACTIVE 2 0:2 -1 : 0 redis
2874 row cache lock xxxxxxxxxx sqlplus ACTIVE 2 0:2 -1 : 0 redis
127 row cache lock xxxxxxxxxx sqlplus ACTIVE 3 0:3 -1 : 0 cbec
2615 row cache lock xxxxxxxxxx sqlplus ACTIVE 4 0:5 -1 : 0 cbec
1136 row cache lock xxxxxxxxxx sqlplus ACTIVE 6 0:6 -1 : 0 weblogic
1099 row cache lock xxxxxxxxxx sqlplus ACTIVE 6 0:6 -1 : 0 vsearch
944 row cache lock xxxxxxxxxx sqlplus ACTIVE 6 0:7 -1 : 0 vsearch
974 row cache lock xxxxxxxxxx sqlplus ACTIVE 6 0:7 -1 : 0 weblogic
845 row cache lock xxxxxxxxxx sqlplus ACTIVE 6 0:7 -1 : 0 weblogic
1037 row cache lock xxxxxxxxxx sqlplus ACTIVE 6 0:7 -1 : 0 vsearch
904 row cache lock xxxxxxxxxx sqlplus ACTIVE 6 0:7 -1 : 0 weblogic
2636 row cache lock xxxxxxxxxx python ACTIVE 6 0:7 -1 : 0 crmmon
1024 row cache lock xxxxxxxxxx sqlplus ACTIVE 6 0:7 -1 : 0 vsearch
836 row cache lock xxxxxxxxxx sqlplus ACTIVE 7 0:7 -1 : 0 vsearch
2294 row cache lock xxxxxxxxxx sqlplus ACTIVE 7 0:7 -1 : 0 cbec
1660 row cache lock xxxxxxxxxx sqlplus ACTIVE 9 0:9 -1 : 0 cbec
798 row cache lock xxxxxxxxxx sqlplus ACTIVE 9 0:9 -1 : 0 vsearch
760 row cache lock xxxxxxxxxx sqlplus ACTIVE 9 0:9 -1 : 0 vsearch
721 row cache lock xxxxxxxxxx sqlplus ACTIVE 9 0:10 -1 : 0 vsearch
2809 row cache lock xxxxxxxxxx sqlplus ACTIVE 10 0:10 -1 2:1660 0 vsearch
603 row cache lock xxxxxxxxxx sqlplus ACTIVE 10 0:10 -1 2:1660 0 vsearch
641 row cache lock xxxxxxxxxx sqlplus ACTIVE 10 0:10 -1 2:1660 0 vsearch
683 row cache lock xxxxxxxxxx sqlplus ACTIVE 10 0:10 -1 2:1660 0 vsearch
555 row cache lock xxxxxxxxxx sqlplus ACTIVE 10 0:11 -1 2:1660 0 vsearch
858 row cache lock xxxxxxxxxx sqlplus ACTIVE 11 0:11 -1 2:1660 0 vsearch
520 row cache lock xxxxxxxxxx sqlplus ACTIVE 11 0:12 -1 2:1660 0 vsearch
494 row cache lock xxxxxxxxxx sqlplus ACTIVE 12 0:12 -1 2:1660 0 taskmon
SYS 55 row cache lock xxxxxxxxxx sqlplus ACTIVE 12 5rzsj7vnvwwrq 0:12 1469878 alter user USER1 account lock 2:1660 0 oracle 2000002
2727 library cache lock xxxxxxxxxx sqlplus ACTIVE 12 0:13 -1 2:1660 0 cbea
2094 library cache lock xxxxxxxxxx sqlplus ACTIVE 13 0:13 -1 2:1660 0 cbea
2262 library cache lock xxxxxxxxxx sqlplus ACTIVE 15 0:15 -1 2:1660 0 oracle
1155 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
1181 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
608 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
638 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
665 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 tpcint
707 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
747 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
784 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 weblogic
824 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
844 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
294 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
303 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
316 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
338 library cache lock xxxxxxxxxx sqlplus ACTIVE 16 0:16 -1 2:1660 0 oracle
...
SQL> alter user xxx account lock;
如果不处理很快连接数就会耗尽。先锁定了用户，但是有部分应用还里需要这个用户，有300多台主机没有修改，即使已修改正确的应用也无法使用，这部分主机的错误密码尝试导致整个库无法使用，那有没有办法解决呢？。
尝试配置12801 event
SQL> oradebug eventdump system 10949 trace name context forever, level 1 SQL> alter system set event='10949 trace name context forever, level 1:28401 trace name context forever, level 1' scope=spfile; System altered. SQL> alter system set events '28401 trace name context forever, level 1'; System altered. SQL> oradebug eventdump system 28401 trace name context forever, level 1 10949 trace name context forever, level 1
再次尝试解锁用户。瞬间数据库会话数增加，又出现了library cache lock, row cache lock和之前的一样，此时在节点2锁用户等在那里，尝试从另一节点（节点1） 锁用户，节点1实例还意外crash,并重启了。 alert log
2020-07-09 09:21:06.197000 +08:00 Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_lmd1_81560.trc (incident=737030): ORA-00600: internal error code, arguments: [kjxscvr:lstat], [[0x534b481e][0x4b773e70],[LB][ext 0x0,0x0][domid 0x0]], [2], [3590001], [35a0000], [], [], [], [], [], [], [] Incident details in: /oracle/app/oracle/diag/rdbms/anbob/anbob1/incident/incdir_737030/anbob1_lmd1_81560_i737030.trc Use ADRCI or Support Workbench to package the incident. See Note 411.1 at My Oracle Support for error and packaging details. Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_lmd1_81560.trc: ORA-00600: internal error code, arguments: [kjxscvr:lstat], [[0x534b481e][0x4b773e70],[LB][ext 0x0,0x0][domid 0x0]], [2], [3590001], [35a0000], [], [], [], [], [], [], [] Dumping diagnostic data in directory=[cdmp_20200709092107], requested by (instance=1, osid=81560 (LMD1)), summary=[incident=737030]. 2020-07-09 09:21:07.950000 +08:00 Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_lmd1_81560.trc: ORA-00600: internal error code, arguments: [kjxscvr:lstat], [[0x534b481e][0x4b773e70],[LB][ext 0x0,0x0][domid 0x0]], [2], [3590001], [35a0000], [], [], [], [], [], [], [] Errors in file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_lmd1_81560.trc (incident=737031): ORA-482 [] [] [] [] [] [] [] [] [] [] [] [] Incident details in: /oracle/app/oracle/diag/rdbms/anbob/anbob1/incident/incdir_737031/anbob1_lmd1_81560_i737031.trc USER (ospid: 81560): terminating the instance due to error 482 opiodr aborting process unknown ospid (4511) as a result of ORA-1092 System state dump requested by (instance=1, osid=81560 (LMD1)), summary=[abnormal instance termination]. System State dumped to trace file /oracle/app/oracle/diag/rdbms/anbob/anbob1/trace/anbob1_diag_81525_20200709092108.trc 2020-07-09 09:21:10.388000 +08:00 License high water mark = 743 2020-07-09 09:21:14.935000 +08:00 Instance terminated by USER, pid = 81560 Warning: 2 processes are still attach to shmid 6782991: (size: 40960 bytes, creator pid: 79260, last attach/detach pid: 81521) ----- Call Stack Trace ----- calling call entry location type point -------------------- -------- -------------------- dbgeEndDDEInvocatio call dbgexExplicitEndInc nImpl()+658 () kjxscvr()+28666 call dbgeEndDDEInvocatio nImpl() kjmxmpm()+16387 call kjxscvr() kjmpbmsg()+6420 call kjmxmpm() kjmdmain_helper()+8 call kjmpbmsg() kjmdm()+79 call kjmdmain_helper() ksbrdp()+1079 call kjmdm() opirip()+609 call ksbrdp() opidrv()+602 call opirip()
这个ora-600 [kjxscvr:lstat] 是Bug 29392554，影响范围还挺多，直到20C BASE才修复。 在节点2继续lock 用户等了几分钟user lock 成功，library cache lock 消失。除了延迟密码认证还有另一个触发和我们手动lock用户一样的user profile FAILED_LOGIN_ATTEMPTS 自动lock用户，因为用户ACCOUNT_STATUs的改变也是要持有X模式的LIBRARY CACHE LOCK. 下面检查用户的profile.
SQL> @us user1 Show database usernames from dba_users matching %USER1% USERNAME DEFAULT_TABLESPACE TEMPORARY_TABLESPACE USER_ID CREATED PROFILE ------------------------- ------------------------- ------------------------------ ---------- ----------------- -------------------- USER1 NETM_DAT TEMP 352 20181205 14:31:09 PRO_APP SQL> select * from dba_profiles where profile='PRO_APP'; PROFILE RESOURCE_NAME RESOURCE LIMIT COM INH IMP -------------------- -------------------------------- -------- -------------------------------------------------------------------------------------------------------------------------------- --- --- --- PRO_APP COMPOSITE_LIMIT KERNEL DEFAULT NO NO NO PRO_APP SESSIONS_PER_USER KERNEL DEFAULT NO NO NO PRO_APP CPU_PER_SESSION KERNEL DEFAULT NO NO NO PRO_APP CPU_PER_CALL KERNEL DEFAULT NO NO NO PRO_APP LOGICAL_READS_PER_SESSION KERNEL DEFAULT NO NO NO PRO_APP LOGICAL_READS_PER_CALL KERNEL DEFAULT NO NO NO PRO_APP IDLE_TIME KERNEL DEFAULT NO NO NO PRO_APP CONNECT_TIME KERNEL DEFAULT NO NO NO PRO_APP PRIVATE_SGA KERNEL DEFAULT NO NO NO PRO_APP FAILED_LOGIN_ATTEMPTS PASSWORD DEFAULT NO NO NO PRO_APP PASSWORD_LIFE_TIME PASSWORD UNLIMITED NO NO NO PRO_APP PASSWORD_REUSE_TIME PASSWORD UNLIMITED NO NO NO PRO_APP PASSWORD_REUSE_MAX PASSWORD 5 NO NO NO PRO_APP PASSWORD_VERIFY_FUNCTION PASSWORD VERIFY_FUNCTION NO NO NO PRO_APP PASSWORD_LOCK_TIME PASSWORD .0004 NO NO NO PRO_APP PASSWORD_GRACE_TIME PASSWORD UNLIMITED NO NO NO PRO_APP INACTIVE_ACCOUNT_TIME PASSWORD DEFAULT NO NO NO 17 rows selected. SQL> select * from dba_profiles where profile='DEFAULT'; PROFILE RESOURCE_NAME RESOURCE LIMIT COM INH IMP -------------------- -------------------------------- -------- -------------------------------------------------------------------------------------------------------------------------------- --- --- --- DEFAULT COMPOSITE_LIMIT KERNEL UNLIMITED NO NO NO DEFAULT SESSIONS_PER_USER KERNEL UNLIMITED NO NO NO DEFAULT CPU_PER_SESSION KERNEL UNLIMITED NO NO NO DEFAULT CPU_PER_CALL KERNEL UNLIMITED NO NO NO DEFAULT LOGICAL_READS_PER_SESSION KERNEL UNLIMITED NO NO NO DEFAULT LOGICAL_READS_PER_CALL KERNEL UNLIMITED NO NO NO DEFAULT IDLE_TIME KERNEL UNLIMITED NO NO NO DEFAULT CONNECT_TIME KERNEL UNLIMITED NO NO NO DEFAULT PRIVATE_SGA KERNEL UNLIMITED NO NO NO DEFAULT FAILED_LOGIN_ATTEMPTS PASSWORD 10 NO NO NO DEFAULT PASSWORD_LIFE_TIME PASSWORD UNLIMITED NO NO NO DEFAULT PASSWORD_REUSE_TIME PASSWORD UNLIMITED NO NO NO DEFAULT PASSWORD_REUSE_MAX PASSWORD UNLIMITED NO NO NO DEFAULT PASSWORD_VERIFY_FUNCTION PASSWORD VERIFY_FUNCTION_11G NO NO NO DEFAULT PASSWORD_LOCK_TIME PASSWORD 1 NO NO NO DEFAULT PASSWORD_GRACE_TIME PASSWORD 7 NO NO NO DEFAULT INACTIVE_ACCOUNT_TIME PASSWORD UNLIMITED NO NO NO 17 rows selected.
Note:
从Profile 看出这个用户是密码连续尝试错误10次后锁住用户0.0004天，然后自动解锁。问题就在这自动lock. 既然这个用户短时间内改不完所有的错误密码配置，干脆禁用密码错误尝试记数。
SQL> create profile pfile_for_USER1 limit FAILED_LOGIN_ATTEMPTS unlimited; Profile created. SQL> alter user USER1 profile pfile_for_USER1; User altered. SQL> alter user USER1 account unlock; User altered.
Note:
之前大量的library cache lock消失， 库内的负载恢复了正常，只是因为还有大量的错误尝试还是有少量的Failed Logon Delay event等待。
微信扫一扫，打赏作者吧～
对不起，这篇文章暂时关闭评论。