一次数据库无法登陆的问题及排查 (r3笔记第99天)

今天在中午的时候，收到客户的邮件，说数据库访问有问题了，赶紧连到生产环境查看。结果在尝试登录的时候报了listener的错误，感觉像是listener停了一样。

>  sqlplus n1/n1@xxxx
SQL*Plus: Release 11.2.0.2.0 Production on Mon Dec 29  12:33:23 2014
Copyright (c) 1982, 2010, Oracle.  All rights  reserved.
ERROR:
ORA-12541: TNS:no  listener

Enter user-name: 
ERROR:
ORA-12536: TNS:operation would  block

当我再次登录数据库服务器的时候突然看到报了一行错误。提示系统资源的问题。 Last login: Mon Dec 29 12:33:55 2014 from xxxxxxx -bash: fork: Resource temporarily unavailable 等我重新登录的时候，没有使用tns连接的时候还是报错。

> sqlplus  n1/n1
SQL*Plus: Release 11.2.0.2.0 Production on Mon Dec 29 12:38:11  2014
Copyright (c) 1982, 2010, Oracle.  All rights  reserved.
ERROR:
ORA-12536:  TNS:operation would  block

根据以往碰到的问题情况，是session满了，这个库目前设置的session数支持近10000个session。连接暂时出现问题，赶紧先查看下系统级的进程情况。

-bash-3.2$  ps -ef|wc -l
9513

-bash-3.2$ ps -ef|grep oracle|wc  -l
8103

在稍等待了几秒，再次尝试终于连进数据库了，我使用如下的sql语句定位了基本的问题情况。

set feed  off
set verify off
set line 132
set pages 200

col username  format a15
col sql_id format a20
col sql_address format a20
col machine  format a30
col osuser format a15
col logon_time format a10
col program  format a35
break on report
compute sum of  cnt  on report
select  status,count(*) cnt from v$session group by status;
select  USERNAME,OSUSER,machine, program,status,count(*) cnt from v$session group by  status,USERNAME,OSUSER,machine, program  having count(*)>2 order by cnt  desc;
select USERNAME,OSUSER,machine,  program,status,to_char(logon_time,'yyyy-mm-dd')logon_date,count(*) cnt from  v$session group by status,USERNAME,OSUSER,machine,  program,to_char(logon_time,'yyyy-mm-dd') order by username,osuser,cnt desc;

语句运行的结果如下，结果做了一些修改。

STATUS           CNT
-------- ----------
ACTIVE           90
INACTIVE        8985
         ----------
sum            9075

USERNAME        OSUSER           MACHINE                        PROGRAM                              STATUS          CNT
--------------- ---------------  ------------------------------ ----------------------------------- --------  ----------
 DAPPC           mwrk01        client1                       JDBC  Thin Client                    INACTIVE       6215
 DAPPC           rwrk01         client1                       JDBC Thin Client                    INACTIVE         126
 CCCBSCUST01     pggate        client3                        extract@xxxxxxxx (TNS V1-V3)        INACTIVE         90
 DAPPC            uwl45         client4                       JDBC Thin Client                     INACTIVE         84
 DAPPC           uwl15         client1                        JDBC Thin Client                    INACTIVE         83
                                                                                                              ----------
sum                                                                                                                6598

COUNT(*)  OSUSER                            PREV_HASH_VALUE      PREV_SQL_ID
----------  --------------- -------------------- --------------- -------------
      1326  mwrk01                        201716277               dqaf35060bwjp
       1972 arwrk01                        2096946154              f41ncsxygtqza
        534 mwrk01                         3203606695               dm03006zg6a57

可以看到在mwrk01这个用户上已经有好几千个session运行着同样的sql语句。查看这些session的登录时间还是能发现一些潜在的问题。

USERNAME         OSUSER          MACHINE                        PROGRAM                              STATUS   LOGON_DATE        CNT
--------------- ---------------  ------------------------------ ----------------------------------- --------  ---------- ----------
 DAPPC           mwrk01        client1                        JDBC Thin Client                    INACTIVE 2014-12-29        1206
 DAPPC           mwrk01        client1                       JDBC Thin  Client                    INACTIVE 2014-12-27        990
 DAPPC            mwrk01        client1                       JDBC Thin Client                     INACTIVE 2014-12-28        664
 DAPPC           mwrk01        client1                        JDBC Thin Client                    INACTIVE 2014-12-26         498
 DAPPC           mwrk01        client1                       JDBC Thin  Client                    INACTIVE 2014-12-24        168
 DAPPC            mwrk01        client1                       JDBC Thin Client                     INACTIVE 2014-12-22         99
 DAPPC           mwrk01        client1                        JDBC Thin Client                    INACTIVE 2014-12-23          38

对应的sql语句都是同一个Insert操作。这是一个每天都需要运行的job，但是根据开发的反馈这些job运行完就会停掉。从上面的情况来看似乎没有按照预期的方式来运行。这种问题按照以往的思路都是已经基本定论，配合开发来做进一步的排查了。发现很多问题再深入一点，还是会有一些收获，对于这个问题开发主动找到我，我们大概聊了下，他们反馈说这个job运行的频率并不高。每天一次，他们也很纳闷为什么还存在着几天前的session,问题又回归到我这了，不过也是可以理解，我和他们解释说，如果一个job从客户端断开后，是会被数据库的后台进程清理掉的，如果一直没有释放session就很可能是一直存在着未完成的事务，从这个思路来考虑，有大量的session都在运行同样的insert操作，从业务上讲也是存在问题的，他们解释说根据新的业务处理，每处理一个外部文件，都会有一个单独的session在处理。我就追问那是都处理完成之后是等待都处理完了再commit还是每处理一个就commit,他们就有些支支吾吾了,说在这块没做过变化，都是处理完成再提交。这样问题就比较明朗了。我建议他们再确认一下事务结束的处理，以前是一个session处理多个文件，都是每处理一个文件commit一次，最后考虑到性能是在处理完成后再commit,这次的变更使用了多个session处理，把事务的处理部分再做变更，很可能就忽略了那个部分。如果是那种情况的话，很可能就会导致大量的session占用。最后他们反馈说这个地方确实存在着一定的问题，问题的处理就进入开发修复的阶段了。