寻找锁定数据库用户的真凶

前几天,一位兄弟部门的同事,提过来一个问题,有一台开发Oracle数据库服务器,修改了一个应用用户的密码,然后就发现这个账户隔几分钟就会被锁,需要手工unlock解锁才行,但没过一会又被锁了,问了一圈开发人员,基本都说使用这个账户的应用要么停了,要么跟着改了密码。很是挠人。

从现象看,推测可能还是有未修改用户密码的应用仍在运行中,接下来就按照当时探究的过程复盘。

1.首先看下这个环境。 11.2.0.4版本:

SQL> select * from v$version where rownum=1;
BANNER
---------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production

双节点的RAC:

[oracle@db1 ~]$ cat /etc/hosts
# Do not remove the following line, or various programs
# that require network functionality will fail.
127.0.0.1       localhost
#Public
x.x.x.11   db1
x.x.x.12   db2
#Private
x.x.x.1   db1-priv
x.x.x.2   db2-priv
#Virtual
x.x.x.13   db1-vip
x.x.x.14   db2-vip
#SCAN
x.x.x.15   db-cluster

2.现象是用户隔几分钟就会被锁定,从用户profile的角度确认是否设置了密码尝试错误次数的参数。

假设这用户名是USER,首先查询到其使用的profile是默认的DEFAULT

SQL> select username, profile from dba_users where username='USER';

USERNAME                   PROFILE
------------------------- --------------------------
USER                       DEFAULT

再查询出DEFAULT这个profile的FAILED_LOGIN_ATTEMPTS参数值是10:

SQL> select resource_name, limit from dba_profiles where profile='DEFAULT';

RESOURCE_NAME                    LIMIT
-------------------------------- ------------------------
COMPOSITE_LIMIT                  UNLIMITED
SESSIONS_PER_USER                UNLIMITED
CPU_PER_SESSION                  UNLIMITED
CPU_PER_CALL                     UNLIMITED
LOGICAL_READS_PER_SESSION        UNLIMITED
LOGICAL_READS_PER_CALL           UNLIMITED
IDLE_TIME                        UNLIMITED
CONNECT_TIME                     UNLIMITED
PRIVATE_SGA                      UNLIMITED
FAILED_LOGIN_ATTEMPTS            10
PASSWORD_LIFE_TIME               180
PASSWORD_REUSE_TIME              UNLIMITED
PASSWORD_REUSE_MAX               UNLIMITED
PASSWORD_VERIFY_FUNCTION         NULL
PASSWORD_LOCK_TIME               1
PASSWORD_GRACE_TIME              7

16 rows selected.

首先,这就能解释为什么USER用户unlock解锁后,隔几分钟就又会被锁,就是由这个参数决定的,至于Oracle如何统计登录失败次数,可以参考eygle很久前写过的一篇短文,介绍的很清楚: http://www.eygle.com/archives/2009/07/profile_failed_login_attempts.html

3.从以上现象来推断,还是有未修改用户密码的应用在运行,接下来看看监听的信息:

[oracle@db1 ~]$ lsnrctl status

LSNRCTL for Linux: Version 11.2.0.4.0 - Production on 25-MAR-2016 18:38:31

Copyright (c) 1991, 2013, Oracle.  All rights reserved.

Connecting to (ADDRESS=(PROTOCOL=tcp)(HOST=)(PORT=1521))
STATUS of the LISTENER
------------------------
Alias                     LISTENER
Version                   TNSLSNR for Linux: Version 11.2.0.4.0 - Production
Start Date                04-FEB-2015 10:05:52
Uptime                    415 days 8 hr. 32 min. 39 sec
Trace Level               off
Security                  ON: Local OS Authentication
SNMP                      OFF
Listener Parameter File   /oracle/app/11.2.0/grid/network/admin/listener.ora
Listener Log File         /oracle/app/grid/diag/tnslsnr/db1/listener/alert/log.xml
Listening Endpoints Summary...
  (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=LISTENER)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=x.x.x.11)(PORT=1521)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=x.x.x.13)(PORT=1521)))
Services Summary...
Service "+ASM" has 1 instance(s).
  Instance "+ASM1", status READY, has 1 handler(s) for this service...
Service "DB" has 1 instance(s).
  Instance "DB1", status READY, has 1 handler(s) for this service...
Service "DBXDB" has 1 instance(s).
  Instance "DB1", status READY, has 1 handler(s) for this service...
The command completed successfully

我们得知监听日志位置: /oracle/app/grid/diag/tnslsnr/db1/listener/alert/log.xml

看到有一些令人兴奋的记录:

<msg time='2016-03-10T13:11:17.467+08:00' org_id='oracle' comp_id='tnslsnr'
 type='UNKNOWN' level='16' host_id='db2'
 host_addr='x.x.x.12'>
 <txt>10-MAR-2016 13:11:17 * (CONNECT_DATA=(SID=db2)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=))) 
 * (ADDRESS=(PROTOCOL=tcp)(HOST=x.x.x.24)(PORT=43428)) * establish * db2 * 0
 </txt>
</msg>

我们可以清楚的看到有一个x.x.x.24的IP,使用jdbc连接方式连接到这台数据库服务器,准确的说是db2,即RAC的第二个节点。而且这个信息是有时几乎1秒钟就会记录一次。

说到这,有个细节,就是dbsnake提醒,由于这是一套RAC环境,因此监听日志不是一份,而是每一个节点都有,开始我碰巧看的是没有x.x.x.24连接记录节点的日志,还怀疑自己之前的判断,后来到另外一个节点就发现了这个IP。

这里端口PORT是43428,会发现每次记录的端口是变化的,即应用连接监听listener经历的两次握手过程。

4.找到了这个IP,是不是就完事儿了?反馈给同事,广播开发人员,但无人有印象在这台机器上有部署过应用。。。

没办法,就自己来呗。

登录这台x.x.x.24机器,root的home目录下就有一个晃眼的dataSync.jar文件。数据同步? 解压这文件,搜索数据库IP,幸运的发现com/xxx/xxx/xxx/datasync/config/jdbc.properties这个文件,打开看看,有一段正是连接这个RAC节点的配置:

jdbc.jdbcUrl=jdbc:oracle:thin:@x.x.x.14:1521:db2

再看看,这个目录下还有一个go的脚本,内容是:

java -Xms1024m -Xmx1024m -XX:MaxPermSize=256m -jar dataSync.jar xx  10 &

感觉越来越接近真相,从这推测,是后台调用dataSync.jar,而且有一个参数10,有可能就是时间间隔。

再找一找,发现有log文件夹,里面有日志,打开看:

2016-03-11 00:04:07,881 - ... While trying to acquire a needed new resource, we failed to succeed more than the maximum number of allowed acquisition attempts (30). Last acquisition attempt exception: 
java.sql.SQLException: ORA-28000: the account is locked

at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:111)

(1).这个日志当前还在不停滚动。 (2).日志中已经明确写出ORA-28000,提示当前用户被锁定了。

基于以上所有线索,百分百确认x.x.x.24的dataSync.jar应用就是因库用户密码变更,其未改变,导致用户频繁被锁的真凶!

5.接下来的工作,就是“找到部署这个应用的人,打一顿”(开玩笑:))。可能有几种方法:

(1) 后台kill这个进程,删除go脚本的可执行权限,或移动位置。

(2) 修改dataSync配置中用户错误的密码。

6.在上面监听日志中,除了x.x.x.24的IP外,还有一条记录:

<msg time='2016-03-10T13:11:17.467+08:00' org_id='oracle' comp_id='tnslsnr'
 type='UNKNOWN' level='16' host_id='db2'
 host_addr='x.x.x.12'>

这条记录也是频繁出现,他是做什么用?dbsnake指点,“这个应该是OHASD定期(每隔1分钟)去连一下本机的listener,目的可能是为了监控本机 listener的健康状况—— Oracle11gR2 Grid Control Oracle High Availability Services OHASD Oracle Agent, (ora_agent) manages the TNS Listener(s) when the ‘ENABLE_GLOBAL_DYNAMIC_ENDPOINT_LISTENER = ON’ parameter is set in the listener.ora file for the Grid Control configuration. ”

7.lsnrctl status:

Trace Level   off
Security  ON: Local OS Authentication
SNMP  OFF
Listener Parameter File   /oracle/app/11.2.0/grid/network/admin/listener.ora
Listener Log File /oracle/app/grid/diag/tnslsnr/db1/listener/alert/log.xml

这块显示的Listener Log File是默认开启的更宏观的连接信息,使用log_status。

另外的Trace Level=off应该表示的是更细粒度的信息,默认关闭,可以在sqlnet.ora配置:

TRACE_LEVEL_CLIENT=16
TRACE_FILE_CLIENT=CLIENT
TRACE_TIMESTAMP_CLIENT=OFF
trace_directory_client=/u01/app/oracle/11.2.0.4/dbhome_1/network/admin

总结

1.无论应用大小,都应该有比较完善的维护机制,至少有一个简易文档,不至于移交工作之后,这个应用成为黑洞,造成不必要的麻烦。

2.Oracle中每个现象是都会有其相应的原因,正所谓因果联系,更不要轻易放过任何一个细节,比如之前要找两个节点的监听日志,比如检索dataSync中有没有文件制定了数据库IP信息。

3.Oracle很多知识点都是相互串联的,监听、监听日志、监听trace日志、profile等等,很多的小点汇聚为了一个庞大的系统,同样,对于这么个问题也是,需要抽丝拨茧般排查每个问题,研究每一个现象后,才能得出最后的结论,往往是更有说服力的。Oracle的魅力就在于此。

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

发表于

我来说两句

0 条评论
登录 后参与评论

扫码关注云+社区

领取腾讯云代金券