cpu 频繁冲高100%持续1秒

概述：
最近新接手一套新系统，在对该系统进行短信监控部署后，发现CPU频繁的告警且CPU利率高达100%. 通过分析发现同一时间内存在大量短连接进程连接数据库。由于并发进程数多，导致CPU利用率冲高.

1.CPU正常时的进程情况：
Topas Monitor for host:    tdx1b                EVENTS/QUEUES    FILE/TTY
Sat Oct 11 11:49:49 2014   Interval:  2         Cswitch    6076  Readch   476.2K
                                                Syscall   20827  Writech   29010
CPU  User%  Kern%  Wait%  Idle%                 Reads       197  Rawin         0
ALL    2.4    1.9    0.1   95.7                 Writes       37  Ttyout      279
                                                Forks         6  Igets         0
Network  KBPS   I-Pack  O-Pack   KB-In  KB-Out  Execs         7  Namei       457
en4     126.1     96.5   151.0    22.1   104.0  Runqueue    0.0  Dirblk        0
en5       1.3      6.5     3.5     0.5     0.8  Waitqueue   0.0
lo0       0.1      1.0     1.0     0.0     0.0
                                                PAGING           MEMORY
Disk    Busy%     KBPS     TPS KB-Read KB-Writ  Faults     2011  Real,MB   41984
hdisk2    0.0    12.5      2.0   12.0     0.5   Steals        0  % Comp     54
hdisk1    1.0    12.0      3.0    0.0    12.0   PgspIn        0  % Noncomp   9
hdisk0    0.0    12.0      3.0    0.0    12.0   PgspOut       0  % Client    9
hdisk16   0.0     4.5      1.0    4.0     0.5   PageIn        0
hdisk20   0.0     0.5      1.0    0.0     0.5   PageOut       0  PAGING SPACE
hdisk21   0.0     0.0      0.0    0.0     0.0   Sios          0  Size,MB   32768
                                                                 % Used      0
Name            PID  CPU%  PgSp Owner           NFS (calls/sec)  % Free    100
oraroota    1216620   0.5  29.1 root            ServerV2       0
ocssd.bi     376860   0.4  97.5 oracle          ClientV2       0   Press:
ohasd.bi     336048   0.4  55.2 root            ServerV3       0   "h" for help
crsd.bin     843944   0.3  72.2 root            ClientV3       0   "q" to quit
gipcd.bi     839918   0.3  25.4 oracle
evmd.bin    1036398   0.2  42.6 oracle
octssd.b     835588   0.2  16.5 root  
oraagent    1224808   0.2  51.9 oracle
oracle       880766   0.1  29.7 oracle
oracle      1253444   0.1  34.1 oracle
Signal 2 received

2.CPU告警时的进程使用情况：

Topas Monitor for host:    tdx1b                EVENTS/QUEUES    FILE/TTY
Wed Oct  8 15:35:06 2014   Interval:  2         Cswitch    8887  Readch    38.1M
                                                Syscall  132.0K  Writech  223.0K
CPU  User%  Kern%  Wait%  Idle%                 Reads     11850  Rawin         0
ALL   84.4   14.5    0.0    1.1                 Writes     1167  Ttyout      428                   ==============>通过Idle 1.1%  可以看出CPU利率几乎耗尽 
                                                Forks       146  Igets         0
Network  KBPS   I-Pack  O-Pack   KB-In  KB-Out  Execs        88  Namei     28715
lo0    3564.8    120.2   119.2  1790.3  1774.5  Runqueue   18.2  Dirblk        0
en5     459.6   1096.1   896.1   255.2   204.4  Waitqueue   0.0
en4      66.7    129.6   129.1    31.7    35.1
                                                PAGING           MEMORY
Disk    Busy%     KBPS     TPS KB-Read KB-Writ  Faults    193.9K Real,MB   41984
hdisk0   35.0   644.9    161.0    0.0   644.9   Steals        0  % Comp     56
hdisk1   43.0   642.9    160.0    0.0   642.9   PgspIn        0  % Noncomp   9
hdisk20   0.0    27.9      1.0    0.0    27.9   PgspOut       0  % Client    9
hdisk22   0.0    21.0     16.0    0.0    21.0   PageIn        0
hdisk16   0.0    16.5      3.0   11.8     4.7   PageOut       0  PAGING SPACE
hdisk8    0.0    16.3     12.0    0.0    16.3   Sios          0  Size,MB   32768
                                                                 % Used      0
Name            PID  CPU%  PgSp Owner           NFS (calls/sec)  % Free    100
tnslsnr     1274058   3.9  14.1 oracle          ServerV2       0                       ＝＝＝＝＝＝＝＝＝＝＝＝＝＝》每次CPU 告警时，发现占用CPU最高的进程为tnslsnr            
oracle      2179082   0.9  10.9 oracle          ClientV2       0   Press:
oracle       770080   0.8  10.9 oracle          ServerV3       0   "h" for help    ================>每次CPU告警时，对应的下面oracle进程数据利用率会增加。并采用ps -ef |grep 查看对应的进程时发现该进程不存。 因此判断该类进程为短连接进程。
oracle      2310278   0.8  10.9 oracle          ClientV3       0   "q" to quit
oracle      1495072   0.8  10.9 oracle
oracle      2437344   0.8  10.9 oracle
oracle      1568812   0.8  10.9 oracle
oracle      1523958   0.8  10.9 oracle
oracle      1958070   0.8  10.9 oracle
oracle      1933320   0.8  10.9 oracle

Topas Monitor for host:    tdx1b                EVENTS/QUEUES    FILE/TTY
Wed Oct  8 15:33:13 2014   Interval:  2         Cswitch    8202  Readch    39.7M
                                                Syscall  138.7K  Writech  291.8K
CPU  User%  Kern%  Wait%  Idle%                 Reads     12490  Rawin         0
ALL   84.5   15.0    0.0    0.5                 Writes     1213  Ttyout      448
                                                Forks       168  Igets         0
Network  KBPS   I-Pack  O-Pack   KB-In  KB-Out  Execs       112  Namei     30083
lo0    3654.7    116.4   114.9  1839.4  1815.2  Runqueue   24.4  Dirblk        0
en5     491.0   1057.2   898.5   254.6   236.4  Waitqueue   0.0
en4      34.1     61.2    63.2    15.7    18.4
                                                PAGING           MEMORY
Disk    Busy%     KBPS     TPS KB-Read KB-Writ  Faults    197.3K Real,MB   41984
hdisk1   47.0   670.6    167.0    0.0   670.6   Steals        0  % Comp     56
hdisk0   30.0   670.6    167.0    0.0   670.6   PgspIn        0  % Noncomp   9
hdisk2    0.0    28.6      4.0   15.9    12.7   PgspOut       0  % Client    9
hdisk4    0.0    23.9      2.0    0.0    23.9   PageIn        0
hdisk17   0.0    19.9      2.0    0.0    19.9   PageOut       0  PAGING SPACE
hdisk25   0.0    19.9      1.0    0.0    19.9   Sios          0  Size,MB   32768
                                                                 % Used      0
Name            PID  CPU%  PgSp Owner           NFS (calls/sec)  % Free    100
tnslsnr     1274058   4.4   3.3 oracle          ServerV2       0
oracle      1069068   0.8  10.9 oracle          ClientV2       0   Press:
oracle      2318508   0.8  11.0 oracle          ServerV3       0   "h" for help
oracle      2453518   0.8  10.9 oracle          ClientV3       0   "q" to quit
oracle      1704058   0.8  10.9 oracle
oracle      1392652   0.8  10.8 oracle
oracle      2367526   0.8  10.9 oracle
oracle      1159362   0.8  10.9 oracle
oracle      1581306   0.8  10.9 oracle
oracle      2478110   0.8  10.9 oracle

3.监听日志分析：
由于TOP进程为tnslsnr因此判断可能跟监听有关系。 根据监听日志我们进一步发现，在同一秒中由tm34连接到数据库进程 PROGRAM=UnifyFileDeal 约50－100左右。根据日志情况结合上TOPAS高CPU oracle 短连接进程。可以判断出每次CPU冲高的原因是由于短连接程序同一时间连接数据太高导致。
)(HOST=tm3e)(USER=root))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.19.244.44)(PORT=38032)) * establish * oradx1 * 0
10-OCT-2014 18:23:07 * (CONNECT_DATA=(SERVICE_NAME=oradx1)(INSTANCE_NAME=odx1b)(server=dedicated)(FAILOVER_MODE=(BACKUP=odx1a)(TYPE=SESSION))(CID=(PROGRAM=UnifyFileDeal
)(HOST=tm3e)(USER=root))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.19.244.44)(PORT=38030)) * establish * oradx1 * 0
10-OCT-2014 18:23:07 * (CONNECT_DATA=(SERVICE_NAME=oradx1)(INSTANCE_NAME=odx1b)(server=dedicated)(FAILOVER_MODE
=(BACKUP=odx1a)(TYPE=SESSION))(CID=(PROGRAM=UnifyFileDeal
)(HOST=tm3e)(USER=root))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.19.244.44)(PORT=38031)) * establish * oradx1 * 0
10-OCT-2014 18:23:07 * (CONNECT_DATA=(SERVICE_NAME=oradx1)(INSTANCE_NAME=odx1b)(server=dedicated)(FAILOVER_MODE=(BACKUP=odx1a)(TYPE=SESSION))(CID=(PROGRAM=UnifyFileDeal
)(HOST=tm3e)(USER=root))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.19.244.44)(PORT=38034)) * establish * oradx1 * 0
10-OCT-2014 18:23:07 * (CONNECT_DATA=(SERVICE_NAME=or
adx1)(INSTANCE_NAME=odx1b)(server=dedicated)(FAILOVER_MODE=(BACKUP=odx1a)(TYPE=SESSION))(CID=(PROGRAM=UnifyFileDeal
)(HOST=tm3e)(USER=root))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.19.244.44)(PORT=38033)) * establish * oradx1 * 0
10-OCT-2014 18:23:07 * (CONNECT_DATA=(SERVICE_NAME=oradx1)(INSTANCE_NAME=odx1b)(server=dedicated)(FAILOVER_MODE=(BACKUP=odx1a)(TYPE=SESSION))(CID=(PROGRAM=UnifyFileDeal
)(HOST=tm3e)(USER=root))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.19.244.44)(PORT=38036)) * establish * oradx1
 * 0
10-OCT-2014 18:23:07 * (CONNECT_DATA=(SERVICE_NAME=oradx1)(INSTANCE_NAME=odx1b)(server=dedicated)(FAILOVER_MODE=(BACKUP=odx1a)(TYPE=SESSION))(CID=(PROGRAM=UnifyFileDeal
)(HOST=tm3e)(USER=root))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.19.244.44)(PORT=38035)) * establish * oradx1 * 0
10-OCT-2014 18:23:07 * (CONNECT_DATA=(SERVICE_NAME=oradx1)(INSTANCE_NAME=odx1b)(server=dedicated)(FAILOVER_MODE=(BACKUP=odx1a)(TYPE=SESSION))(CID=(PROGRAM=UnifyFileDeal
)(HOST=tm3e)(USER=root))) * (ADDRESS=(PROTOCOL
=tcp)(HOST=10.19.244.44)(PORT=38037)) * establish * oradx1 * 0
10-OCT-2014 18:23:07 * (CONNECT_DATA=(SERVICE_NAME=oradx1)(INSTANCE_NAME=odx1b)(server=dedicated)(FAILOVER_MODE=(BACKUP=odx1a)(TYPE=SESSION))(CID=(PROGRAM=UnifyFileDeal
)(HOST=tm3e)(USER=root))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.19.244.44)(PORT=38038)) * establish * oradx1 * 0
10-OCT-2014 18:23:07 * (CONNECT_DATA=(SERVICE_NAME=oradx1)(INSTANCE_NAME=odx1b)(server=dedicated)(FAILOVER_MODE=(BACKUP=odx1a)(TYPE=SESSION))(CID=(PROGRAM=Un
ifyFileDeal
)(HOST=tm3e)(USER=root))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.19.244.44)(PORT=38040)) * establish * oradx1 * 0
10-OCT-2014 18:23:07 * (CONNECT_DATA=(SERVICE_NAME=oradx1)(INSTANCE_NAME=odx1b)(server=dedicated)(FAILOVER_MODE=(BACKUP=odx1a)(TYPE=SESSION))(CID=(PROGRAM=UnifyFileD

4.结果：
经研发人员对 PROGRAM=UnifyFileDeal 进行确认，该类程序是“局数据处理文件平台” 。最好通过把进程均分，确保同一时刻只启动 15个来解决此类问题。

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/29446986/viewspace-1295118/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/29446986/viewspace-1295118/