从一次小故障引发的思考之应用到数据库的连接数管控

一个周末的早上,接到某运营商客户消息,某数据库出现问题,已经影响到了业务,请尽快排查。立即上线,vpn远程检查,几分钟很快定位出故障原因,并建议了临时解决方案,先消除影响,同时建议客户与应用厂商协作,从根源上消除问题。虽然故障原因很简单,但是从这次小故障,反映出一个非常重要但是很多人并没有认真考虑过的问题,这里和大家交流探讨下,欢迎大家分享自己的心得和经验。

首先补充下环境情况,10g的两节点集群:

SQL> select * from v$version;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bi
PL/SQL Release 10.2.0.4.0 - Production
CORE    10.2.0.4.0      Production
TNS for IBM/AIX RISC System/6000: Version 10.2.0.4.0 - Productio
NLSRTL Version 10.2.0.4.0 - Production

接到消息时只是说数据库有问题,影响业务,具体什么问题需要排查,所以快速检查(仅以节点1为例,其它节点不再赘述),先看看数据库后台进程是否存在:

# ps -ef | grep ora_
  oracle  282706       1   0   Jun 04      -  0:00 ora_q000_nxuamdb1 
  oracle  549034       1   0   Jun 04      -  0:53 ora_mman_nxuamdb1 
  oracle  557072       1   0   Jun 04      - 13:54 ora_diag_nxuamdb1 
  oracle  569380       1   0   Jun 04      - 442:47 ora_lms0_nxuamdb1 
  oracle  626706       1   0   Jun 04      -  1:44 ora_qmnc_nxuamdb1 
  oracle  630784       1   0   Jun 04      -  9:40 ora_dbw0_nxuamdb1 
  oracle  659546       1   0   Jun 04      - 137:12 ora_lgwr_nxuamdb1 
  oracle  667666       1   0   Jun 04      - 127:04 ora_lmon_nxuamdb1 
  oracle  721012       1   0   Jun 04      -  1:58 ora_psp0_nxuamdb1 
  oracle  770150       1   0   Jun 04      -  0:01 ora_reco_nxuamdb1 
  oracle  835682       1   0   Jun 04      -  4:00 ora_smon_nxuamdb1 
  oracle 1011766       1   0   Jun 04      - 19:24 ora_ckpt_nxuamdb1 
  oracle 1216740       1   0   Jun 04      - 13:04 ora_cjq0_nxuamdb1 
  oracle 1277980       1   0   Jun 04      -  3:46 ora_mmon_nxuamdb1 
  oracle 1310854       1   0   Jun 04      - 12:35 ora_pmon_nxuamdb1 
  oracle 1327308       1   0   Jun 04      - 446:28 ora_lms1_nxuamdb1 
  oracle 3031190       1   0 07:20:04      -  0:00 ora_j000_nxuamdb1 
  oracle 4149452       1   0 07:10:20      -  0:00 ora_pz99_nxuamdb1 
  oracle 4481080       1   0   Jun 04      - 13:21 ora_lck0_nxuamdb1 
  oracle 6234354       1   0   Jun 04      - 95:44 ora_mmnl_nxuamdb1 
    root 6832318 1257514   0 07:20:14  pts/1  0:00 grep ora_ 
  oracle 8990948       1   0   Jun 04      -  0:16 ora_q001_nxuamdb1 
  oracle 9023616       1   0   Jun 04      - 39:15 ora_lmd0_nxuamdb1

从os看后台进程正常,进入数据库中看看:

SQL> select inst_id,status from gv$instance order by inst_id;

   INST_ID STATUS
---------- ------------
         1 OPEN
         2 OPEN

实例的状态也正常,会不会是因某个sql引发拥堵造成问题(这个在运营商这种高负荷高压力且持续优化已经较少存在硬伤的环境里是比较常见的问题来源),继续检查:

SQL> col username format a10
SQL> col program format a25
SQL> col event format a30
SQL> col osuser format a12
SQL> col machine format a12
SQL> col spid format a10
SQL> col client_info format a16
SQL> col sid format 99999
SQL> col last_call_et format 9999999
SQL> select s.sid,
  2         s.serial#,
  3         s.username,
  4         s.machine,
  5         s.program,
  6         s.event,
  7         s.last_call_et,
  8         s.osuser,
  9         p.spid,
 10         s.sql_id,
 11         s.client_info
 12    from v$session s, v$process p
 13   where s.paddr = p.addr
 14     and s.status = 'ACTIVE'
 15     and s.username is not null
 16   order by s.last_call_et;
   SID    SERIAL# USERNAME   MACHINE      PROGRAM                   EVENT                          LAST_CALL_ET OSUSER       SPID       SQL_ID        CLIENT_INFO
------ ---------- ---------- ------------ ------------------------- ------------------------------ ------------ ------------ ---------- ------------- ----------------
  3217      65184 SYS        nxuam2       sqlplus@nxuam2 (TNS V1-V3 SQL*Net message to client)                 1 oracle       6033474    3qxcsyqgjuptp
  1572        375 CTSW       nxuam2       oracle@nxuam2 (J003)      db file scattered read                 2761 oracle       6217890    3cabpdhtkgcq8
  1672      64552 WSKFZX     nxuam2       oracle@nxuam2 (J001)      db file sequential read                4437 oracle       6959352    3fzyc0wdq5mn7
  3204      37750 CTSW       nxuam2       oracle@nxuam2 (J000)      single-task message                ######## oracle       8503462    3q1zc0zz8rb59

SQL>

可以看到,除了一些后台job,并没有拥堵的sql和会话。好吧,那就赶紧去看看alert日志,在日志中发现如下错误:

Sat Jul  9 08:09:06 2016
Process startup failed, error stack:
Sat Jul  9 08:09:06 2016
Errors in file /oracle/admin/nxuamdb/bdump/nxuamdb1_psp0_721012.trc:
ORA-27300: OS system dependent operation:fork failed with status: 11
ORA-27301: OS failure message: Resource temporarily unavailable
ORA-27302: failure occurred at: skgpspawn5
ORA-27303: additional information: skgpspawn5
Sat Jul  9 08:09:07 2016
Process m001 died, see its trace file
Sat Jul  9 08:09:07 2016
ksvcreate: Process(m001) creation failed

很明显啊,报错是因为系统资源不够,当前没有消耗资源的大sql,为啥会资源不够,先去topas观察下资源使用情况:

Topas Monitor for host:    nxuam2               EVENTS/QUEUES    FILE/TTY
Sat Jul 9 08:13:41 2016   Interval:  2         Cswitch    6389  Readch    18.1M
                                                Syscall   24387  Writech    4069
CPU  User%  Kern%  Wait%  Idle%                 Reads       171  Rawin         0
ALL   22.0    5.1    9.1   63.8                 Writes       13  Ttyout      399
                                                Forks         0  Igets         0
Network  KBPS   I-Pack  O-Pack   KB-In  KB-Out  Execs         0  Namei        45
Total  2082.4   1077.3  1355.5   702.5  1379.9  Runqueue    1.5  Dirblk        0
                                                Waitqueue   0.5
Disk    Busy%     KBPS     TPS KB-Read KB-Writ                   MEMORY
Total    57.0     19.8K  213.0    19.7K  102.5  PAGING           Real,MB   15679
                                                Faults      193  % Comp     99  <--'内存耗尽'
FileSystem        KBPS     TPS KB-Read KB-Writ  Steals        0  % Noncomp   1
Total              6.8    16.4    6.1    0.7    PgspIn        0  % Client    0
                                                PgspOut       0
Name            PID  CPU%  PgSp Owner           PageIn        0  PAGING SPACE
oracle      5672970  19.9   6.1 oracle          PageOut       4  Size,MB   16384
oracle      9015412   1.5  18.7 oracle          Sios          4  % Used     30
oracle       733352   1.3  18.8 oracle                           % Free     70
luax.3.2    5255272   0.8   1.5 bossnm          NFS (calls/sec)
java         364724   0.7  71.7 root            SerV2         0  WPAR Activ    0
topas       1978418   0.2   2.2 oracle          CliV2         0  WPAR Total    0
oracle      9011450   0.2  13.5 oracle          SerV3         0  Press: "h"-help
oracle      6959352   0.1  11.8 oracle          CliV3         0         "q"-quit
dtgreet      151646   0.1   1.3 root  
oracle      8683592   0.1   5.7 oracle
java        8343658   0.1  69.3 bossnm
oracle      8941806   0.1  11.1 oracle
oracle      1200372   0.1  18.6 oracle
sshd        7512240   0.0   0.8 root  
gil           65568   0.0   0.9 root  
ocssd.bi     987148   0.0  33.4 oracle
oracle      7315598   0.0  14.7 oracle
oracle      8716378   0.0  18.7 oracle
oracle       999444   0.0   9.4 oracle
oracle      4460626   0.0   7.1 oracle

一看吓一跳,物理内存耗尽,并且swap使用了30%多,同时从数据库里和os中检查连接资源消耗情况:

SQL> select inst_id,username,count(*) from gv$session where type='USER' group by inst_id,username order by count(*) desc

   INST_ID USERNAME     COUNT(*)
---------- ---------- ----------
         2 CTSW             1948    <--'连接数主要消耗者'
         1 CTSW             1919    <--'连接数主要消耗者'
         1 UAM                43
         2 UAM                40
         1 WSKFZX             16
         1 NX_SURFING         10
         1 SMSLOG_SEA          8
           RCH

         2 BOSSNM              7
         1 BOSSNM              6
         2                     5
         1 SYS                 5
         2 SMCDMA              4
         2 SYS                 3
         2 FSWPM               1
         2 WSKFZX              1
         1 FSWPM               1

16 rows selected.
SQL> show parameter process

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
aq_tm_processes                      integer     0
db_writer_processes                  integer     1
gcs_server_processes                 integer     2
job_queue_processes                  integer     10
log_archive_max_processes            integer     2
processes                            integer     3000
nxuam1$ulimit -a
time(seconds)        unlimited
file(blocks)         unlimited
data(kbytes)         unlimited
stack(kbytes)        4194304
memory(kbytes)       unlimited
coredump(blocks)     unlimited
nofiles(descriptors) 2000       <--'进程中打开文件的最大数量'
threads(per process) unlimited
processes(per user)  unlimited

可以看到两个节点均连了2000来个连接,没有达到数据库的限制,但是达到了os对oracle用户的资源限制。同时库里绝大多数连接资源都是被CTSW用户消耗了,合理吗?跟客户沟通排查后确认,这个用户是掌上营业厅模块的用户,不应该有这么多连接,因为其它原因中间件连接池暴涨,最终导致问题出现。现在问题根源真相大白,先紧急配合客户创建了个profile,对这个用户的连接数进行了限制(最多1000),杀掉多余的非活动会话。同时建议客户与应用厂商协作,从根源上消除问题。

SQL> select * from dba_profiles where profile='MONITORING_PROFILE';

PROFILE                        RESOURCE_NAME                    RESOURCE LIMIT
------------------------------ -------------------------------- -------- ----------------------------------------
MONITORING_PROFILE             COMPOSITE_LIMIT                  KERNEL   UNLIMITED
MONITORING_PROFILE             SESSIONS_PER_USER                KERNEL   1000       <--'限制连接数'
MONITORING_PROFILE             CPU_PER_SESSION                  KERNEL   UNLIMITED
MONITORING_PROFILE             CPU_PER_CALL                     KERNEL   UNLIMITED
MONITORING_PROFILE             LOGICAL_READS_PER_SESSION        KERNEL   UNLIMITED
MONITORING_PROFILE             LOGICAL_READS_PER_CALL           KERNEL   UNLIMITED
MONITORING_PROFILE             IDLE_TIME                        KERNEL   UNLIMITED
MONITORING_PROFILE             CONNECT_TIME                     KERNEL   UNLIMITED
MONITORING_PROFILE             PRIVATE_SGA                      KERNEL   UNLIMITED
MONITORING_PROFILE             FAILED_LOGIN_ATTEMPTS            PASSWORD UNLIMITED
MONITORING_PROFILE             PASSWORD_LIFE_TIME               PASSWORD UNLIMITED
MONITORING_PROFILE             PASSWORD_REUSE_TIME              PASSWORD UNLIMITED
MONITORING_PROFILE             PASSWORD_REUSE_MAX               PASSWORD UNLIMITED
MONITORING_PROFILE             PASSWORD_VERIFY_FUNCTION         PASSWORD NULL
MONITORING_PROFILE             PASSWORD_LOCK_TIME               PASSWORD UNLIMITED
MONITORING_PROFILE             PASSWORD_GRACE_TIME              PASSWORD UNLIMITED

16 rows selected.
SQL> select username,profile from dba_users where profile='MONITORING_PROFILE';

USERNAME                       PROFILE
------------------------------ ------------------------------
CTSW                           MONITORING_PROFILE

问题虽然解决了,但是开篇提到的问题才是我们想进行探讨的核心,即从应用到数据库的连接数该如何设计?这一条线上需要考虑的环节不少,应用对连接数的需求->应用服务器os配置->连接池配置->数据库服务器os配置->oracle参数配置->oracle资源管理配置,加之很多数据库是被多个应用或者多个模块共用,又导致了这个问题的复杂化。

我个人的看法是:

1,在系统建设初期,就应该进行系统负荷定量分析,全方面的分析系统各个方面的负荷,并针对性的设计解决方案,在其中包含对数据库连接数管控的考虑。

2,在系统运维期,每一个数据库用户的增加,均和应用等沟通清楚对连接数等资源需求,再结合硬件状况/配置现状等,制定调整方案,比较全面的将从应用到数据库整条线上所有环节配套修改。

3,在系统运维期,应该建立一种手段或者机制,能够持续的管控数据库连接数变化趋势,并能进行相应的统计汇总分析,必要时报警。

第1、2条建议里,需要大家结合自己单位部门岗位分工,因地制宜的推动落实,第3条属于比较纯粹的技术性功能,可以稍作展开。

数据库连接数限制,可以通过上面讲的profile实现,那么监控呢?不外乎自己动手开发或者利用第三方软件。

自己开发,无论是java类的开发语言,还是存储过程开发,思路均是,一份job周期性的对v$session视图进行抽取,将信息适当处理后另外存储起来,一份job周期性的对另外存储的信息进行统计/分析,根据结果与报警要求比对,针对隐患性的趋势调用报警接口报警。
利用第三方软件,针对数据库的监控软件非常多,如oem、spotlight等等,基本都含有活动连接、总连接数的监控,但是含有连接数变化趋势以及连接数按应用服务器/用户等不同纬度下钻分析/预警/报警功能的却很少,目前我知道有zone、ignite、zabbix。其中zone具有完整的功能模块,可以直接使用,ignite和zabbix均有接口支持自定义监控项目,可以通过此二次开发实现。
你的单位是如何解决和应对这个问题的呢?我这里抛砖引玉,欢迎大家探讨:)

发表评论

电子邮件地址不会被公开。 必填项已用*标注