客户的11.2.0.2 RAC for Linux X86-64环境的数据库在登录时,发现出现长时间等待。
这一篇描述问题的现象的诊断。
出问题的时候我正好在客户现场,于是当时诊断了一下。
客户反映,问题发生在一个用户上,使用这个用户登录需要等待很长时间,而使用其他的用户登录则不存在问题。
首先检查了DBA_PROFILES,确认和密码以及登录有关的PROFILE是否存在限制,当前数据库已经都设置为UNLIMITED,那么问题应该和PROFILE无关。
检查出现问题的用户,也未发现任何特别之处。
在sqlplus上使用这个用户登录,经历了将近10秒左右的等待,终于成功登录。同时检查到会话当时出现library cache lock等待事件。
当再次尝试重现问题时,却已发现问题无法重现了,现在即使使用刚才的问题用户,也可以很快登录成功,并不会出现明显的登录等待。莫非一次成功的登录,就可以解决这个问题。
不过很快,问题再次出现,为了检查会话执行的具体操作,对这个问题用户创建了一个登录触发器,在登录触发器中设置会话的TRACE:
SQL> CREATE OR REPLACE TRIGGER T_AFTER_LOGON AFTER LOGON ON DATABASE 2 BEGIN 3 IF USER = 'GJT' THEN 4 DBMS_SESSION.SESSION_TRACE_ENABLE(TRUE, TRUE); 5 END IF; 6 END; 7 / TRIGGER created. |
虽然问题重现了,但是找到会话的TRACE信息,却没有发现任何异常之处,甚至在TRACE信息中都找不到任何library cache lock等待事件的信息。
而且此时还发现一个现象,就是利用这个用户登录时,即使用户名的密码输入错误,sqlplus也会等待很长时间,然后才会返回错误信息。而这个长时间的等待从V$SESSION视图中查询,恰恰就是library cache lock等待事件。
上面的两个现象说明,library cache lock的等待实际上是发生在用户登录之前的。其实从数据库V$SESSION视图中也可以看出这个问题:
SQL> SELECT sid, username, event, p1text, p1, p2text, p2, p3text, p3, seconds_in_wait 2 FROM gv$session 3 WHERE event = 'library cache lock'; SID USERNAME EVENT SECONDS_IN_WAIT ----------- ------------------------------ ------------------ --------------- 19 library cache LOCK 21 2017 library cache LOCK 20 2062 library cache LOCK 0 2147 library cache LOCK 10 2210 library cache LOCK 21 |
可以看到,所有出现library cache lock等待的会话用户名都是空。这些会话并不是Oracle后台进程,而是刚才提到的问题用户,这同样说明当方式这个library cache lock等待时,会话还没有成功的登录到数据库中。
那么现在问题有点棘手,如果会话没有登录,则没有办法检查会话执行了哪些操作,Oracle的文档中也没有提到过,会话登录之前会进行哪些操作,经历哪些等待。
分析一下这个问题,整个数据库目前只有这个用户出现了library cache lock的等待,而其他用户没有出现,说明问题肯定和这个用户的自身特点有关。而数据库中只存在默认的DEFAULT PROFILE,且所有限制都设置为UNLIMITED,那么问题应该和PROFILE没有关系。通过登录触发器设置TRACE后发现,会话登录后并无任何异常操作,且TRACE文件中看不到library cache lock等待信息。而且即使用户名密码错误,也会出现这个等待事件。这说明等待发生在登录之前,与用户登录后的行为无关。
简单总结一下,问题和当前用户的自身特性有关,且与DBA_PROFILE无关,也与用户登录后的行为无关。如果不考虑PROFILE,那么用户特有的属性恐怕就剩下了用户名和密码了。而且在一次成功的登录数据库后,这个现象曾短时间消失,这说明问题可能确实和密码有关系。
在11g中,Oracle的密码策略确实出现了一些改变,比如密码变成大小写敏感。这个问题很可能导致老的程序来连接数据库时出现密码错误的现象。此外,11g还新增了一个密码相关的特性——密码错误延迟验证:当用户连续的输入错误的密码,Oracle所需要的密码验证时间会逐步增加,这可以有效的避免有人试图通过暴力方式来破解密码。关于11g新增密码错误延迟验证的详细内容,可以参考:http://yangtingkun.itpub.net/post/468/505041
那么当前的问题和这个密码延迟验证有关系吗,如果是密码延迟验证的问题,那么至少要多次重复输入错误的密码。不过从刚才的V$SESSION视图中可以看到,问题用户存在多个会话在登录数据库,如果是程序连接数据库,且配置了错误的密码,那么基本上就可以确定问题了。
询问了相关程序人员,发现一个测试程序的密码确实配置错误,且这个程序目前仍然在后台不断的尝试连接数据库。
现在所有的疑问都解开了,用户程序已错误的密码不断登录,在加上11g的密码延迟验证,使得用户的验证等待时间不断加长。这也解释了为什么输入正确的密码登录后,这个现象曾短暂消失,因为用户成功登录,密码延迟验证的时间归零。
找到问题的原因后,在客户的数据库上以其他的用户尝试模拟这个现象,测试发现,如果一个会话登录数据库,即使每次密码都不正确使得延迟验证时间不断变长,也不会引发library cache lock的等待时间,但是只要该用户存在第二个登录会话,这时library cache lock会在两个会话同时出现,而且即使这个会话尝试使用正确的密码登录,在成功登录之前,也要等待library cache lock事件。
根据这个现象,个人推测Oracle为了实现延迟验证,必然需要在共享池中保存一个类似计数器的对象。这个计数器记录用户登录连续密码错误次数,从而确定延迟验证的等待时间。当用户成功登录,计数器清零。如果是一个会话,那么只需要独占这个计数器就可以了,当存在两个以上的会话,且两个会话都试图修改计数器的内容,那么资源竞争就出现了,而体现在数据库中的等待事件就是library cache lock。当然这只是个人的猜测而已,还没有看到Oracle官方对这种情况的说明。
Pingback: 11.2数据库登录出现library cache lock等待(二) | yangtingkun