|
在生产环境中，我们可能会经常遇到CPU过度使用而影响系统性能或正常运行的问题。大多数情况下，系统的性能问题都是由不良SQL代码引起的，那么作为DBA，怎样发现和解决这些SQL问题就显得尤为重要。
本文通过一个生产系统中的案例分析和处理过程分享，希望能够给大家带来一点借鉴作用。
问题描述:
业务及开发人员报告系统运行缓慢，已经影响业务系统正常使用。请求协助诊断。
1．使用vmstat检查系统当前情况
首先登陆数据库主机，检查当前系统状况。
使用vmstat检查，发现CPU资源已经耗尽，大量任务位于运行队列：
bash-2.03$ vmstat 3
procs memory page disk faults cpu
r b w swap free re mf pi po fr de sr s6 s9 s1 sd in sy cs us sy id
0 0 0 5504232 1464112 0 0 0 0 0 0 0 0 1 1 0 4294967196 0 0 -84 -5 -145
131 0 0 5368072 1518360 56 691 0 2 2 0 0 0 1 0 0 3011 7918 2795 97 3 0
131 0 0 5377328 1522464 81 719 0 2 2 0 0 0 1 0 0 2766 8019 2577 96 4 0
130 0 0 5382400 1524776 67 682 0 0 0 0 0 0 0 0 0 3570 8534 3316 97 3 0
134 0 0 5373616 1520512 127 1078 0 2 2 0 0 0 1 0 0 3838 9584 3623 96 4 0
136 0 0 5369392 1518496 107 924 0 5 5 0 0 0 0 0 0 2920 8573 2639 97 3 0
132 0 0 5364912 1516224 63 578 0 0 0 0 0 0 0 0 0 3358 7944 3119 97 3 0
129 0 0 5358648 1511712 189 1236 0 0 0 0 0 0 0 0 0 3366 10365 3135 95 5 0
129 0 0 5354528 1511304 120 1194 0 0 0 0 0 0 0 4 0 3235 8864 2911 96 4 0
本案例当时，系统CPU资源已经耗尽，Idle为0，并且运行队列大量进程排队等待。
2．使用Top工具辅助诊断
通过Top工具，我们可以查看进程CPU耗用情况，如果存在进程异常，可以通过Top定位，为进一步诊断提供依据。
对于本案例，观察进程CPU耗用，发现没有明显过高CPU使用的进程。
$ top
last pid: 28313; load averages: 99.90, 117.54, 125.71 23:28:38
296 processes: 186 sleeping, 99 running, 2 zombie, 9 on cpu
CPU states: 0.0% idle, 96.5% user, 3.5% kernel, 0.0% iowait, 0.0% swap
Memory: 4096M real, 1404M free, 2185M swap in use, 5114M swap free
PID USERNAME THR PRI NICE SIZE RES STATE TIME CPU COMMAND
27082 oracle8i 1 33 0 1328M 1309M run 0:17 1.29% oracle
26719 oracle8i 1 55 0 1327M 1306M sleep 0:29 1.11% oracle
28103 oracle8i 1 35 0 1327M 1304M run 0:06 1.10% oracle
28161 oracle8i 1 25 0 1327M 1305M run 0:04 1.10% oracle
26199 oracle8i 1 45 0 1328M 1309M run 0:42 1.10% oracle
26892 oracle8i 1 33 0 1328M 1310M run 0:24 1.09% oracle
27805 oracle8i 1 45 0 1327M 1306M cpu/1 0:10 1.04% oracle
23800 oracle8i 1 23 0 1327M 1306M run 1:28 1.03% oracle
25197 oracle8i 1 34 0 1328M 1309M run 0:57 1.03% oracle
21593 oracle8i 1 33 0 1327M 1306M run 2:12 1.01% oracle
从Top的输出中我们发现有大量进程处于running的运行状态，CPU消耗很平均，单进程消耗大约在1%左右，我们基本可以排除个别进程异常导致CPU问题的可能。
3、检查进程数量
对于一个生产数据库系统，稳定运行的进程数量通常是可知的。
提示:对于稳定运行的生产系统，数据库的运行状况通常是稳定的，如果你绘制出性能曲线，你会发现每个星期的曲线几乎是可以重合的，对数据库系统的运行状况及性能指标具有充分认识和了解是必须的。
我们看一下当前系统的进程数量，从而进行比较判断：
bash-2.03$ ps -ef|grep ora|wc -l
258
bash-2.03$ ps -ef|grep ora|wc -l
275
bash-2.03$ ps -ef|grep ora|wc -l
274
bash-2.03$ ps -ef|grep ora|wc -l
278
bash-2.03$ ps -ef|grep ora|wc -l
277
bash-2.03$ ps -ef|grep ora|wc -l
366
发现此时系统存在大量Oracle进程,大约在300左右，大量进程消耗了几乎所有CPU资源,而正常情况下Oracle连接数应该在100左右。
由此，我们可以基本判断，是数据库或应用出现问题，导致进程任务无法完成，不断累积，从而出现大量队列等待。
这些等待在数据库中应该有具体的体现，接下来需要登陆数据库进行检查了。
4、登陆数据库
我们判断数据库可能经历了等待，那么Oracle数据库提供了相关视图供我们查询和发现问题，v$session_wait是首先值得我们关注的。
查询v$session_wait获取各进程等待事件：
SQL> select sid,event,p1,p1text from v$session_wait;
SID EVENT P1 P1TEXT
---------- ------------------------------ ---------- ----------------------------------------------------------------
124 latch free 1.6144E+10 address
1 pmon timer 300 duration
2 rdbms ipc message 300 timeout
。。。。。。
140 buffer busy waits 17 file#
66 buffer busy waits 17 file#
10 db file sequential read 17 file#
18 db file sequential read 17 file#
54 db file sequential read 17 file#
49 db file sequential read 17 file#
48 db file sequential read 17 file#
46 db file sequential read 17 file#
45 db file sequential read 17 file#
。。。。。。
234 db file sequential read 17 file#
233 db file sequential read 17 file#
230 db file sequential read 17 file#
333 db file sequential read 17 file#
330 db file scattered read 17 file#
310 db file scattered read 17 file#
。。。。。。。
244 rows selected.
对于本案例，我们发现存在大量db file scattered read及db file sequential read等待。显然全表扫描等操作成为系统最严重的性能影响因素。
5、捕获相关SQL
确定这些进程因为数据访问产生了等待，我们考虑捕获这些SQL以发现问题。
这里用到了我的以下脚本getsqlbysid.sql，该脚本通过已知session的sid，联合v$session、v$sqltext视图，获得相关session正在执行的完整的SQL语句。
SELECT sql_text
FROM v$sqltext a
WHERE a.hash_value = (SELECT sql_hash_value
FROM v$session b
WHERE b.SID = '&sid')
ORDER BY piece ASC
/
使用该脚本,通过从v$session_wait中获得的等待全表或索引扫描的进程SID，可以捕获可能存在问题的sql语句:
SQL> @getsqlbysid
Enter value for sid: 18
old 5: where b.sid='&sid'
new 5: where b.sid='18'
SQL_TEXT
----------------------------------------------------------------
select i.vc2title,i.numinfoguid from hs_info i where i.intenab
ledflag = 1 and i.intpublishstate = 1 and i.datpublishdate <=
sysdate and i.numcatalogguid = 2047 order by i.datpublishdate d
esc, i.numorder desc
SQL> /
Enter value for sid: 54
old 5: where b.sid='&sid'
new 5: where b.sid='54'
SQL_TEXT
----------------------------------------------------------------
select i.vc2title,i.numinfoguid from hs_info i where i.intenab
ledflag = 1 and i.intpublishstate = 1 and i.datpublishdate <=
sysdate and i.numcatalogguid = 33 order by i.datpublishdate des
c, i.numorder desc
。。。。。。。。
对几个进程进行跟踪,分别得到以上SQL语句，这些SQL可能就是问题产生的根源。
使用该应用用户连接，通过autotrace功能检查以上SQL的执行计划:
SQL> set autotrace trace explain
SQL> select i.vc2title,i.numinfoguid
2 from hs_info i where i.intenabledflag = 1
3 and i.intpublishstate = 1 and i.datpublishdate <=sysdate
4 and i.numcatalogguid = 3475
5 order by i.datpublishdate desc, i.numorder desc ;
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE (Cost=228 Card=1 Bytes=106)
1 0 SORT (ORDER BY) (Cost=228 Card=1 Bytes=106)
2 1 TABLE ACCESS (FULL) OF 'HS_INFO' (Cost=218 Card=1 Bytes=106)
SQL> select count(*) from hs_info;
COUNT(*)
----------
227404
通过执行计划，我们看到以上查询使用了全表扫描，而该表这里有22万记录，全表扫描已经不再适合。
我们检查全表扫描的数据表，发现存在以下索引:
SQL> select index_name,index_type from user_indexes where table_name='HS_INFO';
INDEX_NAME INDEX_TYPE
------------------------------ ---------------------------
HSIDX_INFO1 FUNCTION-BASED NORMAL
HSIDX_INFO_SEARCHKEY DOMAIN
PK_HS_INFO NORMAL
检查索引键值：
SQL> select index_name,column_name
2 from user_ind_columns where table_name ='HS_INFO';
INDEX_NAME COLUMN_NAME
------------------------------ --------------------
HSIDX_INFO1 NUMORDER
HSIDX_INFO1 SYS_NC00024$
HSIDX_INFO_SEARCHKEY VC2INDEXWORDS
PK_HS_INFO NUMINFOGUID
SQL> desc hs_info
Name Null? Type
--------------------------------- -------- --------------------------------------------
NUMINFOGUID NOT NULL NUMBER(15)
NUMCATALOGGUID NOT NULL NUMBER(15)
INTTEXTTYPE NOT NULL NUMBER(38)
VC2TITLE NOT NULL VARCHAR2(60)
VC2AUTHOR VARCHAR2(100)
NUMPREVINFOGUID NUMBER(15)
NUMNEXTINFOGUID NUMBER(15)
NUMORDER NOT NULL NUMBER(15)
。。。。。
6、创建新的索引以消除全表扫描
检查发现在numcatalogguid字段上并没有索引,该字段具有很好的区分度，考虑在该字段创建索引以消除全表扫描。
SQL> create index hs_info_NUMCATALOGGUID on hs_info(NUMCATALOGGUID);
Index created.
SQL> set autotrace trace explain
SQL> select i.vc2title,i.numinfoguid
2 from hs_info i where i.intenabledflag = 1
3 and i.intpublishstate = 1 and i.datpublishdate <=sysdate
4 and i.numcatalogguid = 3475
5 order by i.datpublishdate desc, i.numorder desc ;
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE (Cost=12 Card=1 Bytes=106)
1 0 SORT (ORDER BY) (Cost=12 Card=1 Bytes=106)
2 1 TABLE ACCESS (BY INDEX ROWID) OF 'HS_INFO' (Cost=2 Card=1 Bytes=106)
3 2 INDEX (RANGE SCAN) OF 'HS_INFO_NUMCATALOGGUID' (NON-UNIQUE) (Cost=1 Card=1)
7、观察系统状况
原大量等待消失
SQL> select sid,event,p1,p1text from v$session_wait where event not like 'SQL%';
SID EVENT P1 P1TEXT
---------- ------------------------------ ---------- ----------------------------------------------------------------
1 pmon timer 300 duration
2 rdbms ipc message 300 timeout
3 rdbms ipc message 300 timeout
6 rdbms ipc message 180000 timeout
59 rdbms ipc message 6000 timeout
118 rdbms ipc message 6000 timeout
275 rdbms ipc message 30000 timeout
147 rdbms ipc message 6000 timeout
62 rdbms ipc message 6000 timeout
11 rdbms ipc message 30000 timeout
4 rdbms ipc message 300 timeout
305 db file sequential read 17 file#
356 db file sequential read 17 file#
19 db file scattered read 17 file#
5 smon timer 300 sleep time
15 rows selected.
在另外的session里，持续观察的CPU使用情况：
bash-2.03$ vmstat 3
procs memory page disk faults cpu
r b w swap free re mf pi po fr de sr s6 s9 s1 sd in sy cs us sy id
34 0 0 5343016 1465416 44 386 77 0 0 0 0 0 0 0 0 3197 8486 2902 92 8 0
31 0 0 5331568 1459696 178 1491 122 0 0 0 0 0 0 3 0 3237 9461 3005 89 11 0
31 0 0 5317792 1453008 76 719 80 0 0 0 0 0 0 0 0 3292 8736 3025 93 7 0
31 2 0 5311144 1449552 235 1263 69 2 2 0 0 0 1 0 0 3473 9535 3357 88 12 0
25 0 0 5300240 1443920 108 757 18 2 2 0 0 0 1 1 0 2377 7876 2274 95 5 0
19 0 0 5295904 1441840 50 377 0 0 0 0 0 0 0 1 0 1915 6598 1599 98 1 0
----以上为创建索引之前部分
----以下为创建索引之后部分，CPU使用率恢复正常
procs memory page disk faults cpu
r b w swap free re mf pi po fr de sr s6 s9 s1 sd in sy cs us sy id
0 0 0 4955872 1287136 737 6258 16 0 0 0 0 0 0 3 0 2890 11777 4432 44 12 44
1 0 0 4887888 1256464 809 6234 8 2 2 0 0 0 0 2 0 2809 12066 4247 45 12 43
0 0 0 4828912 1228200 312 2364 13 5 5 0 0 0 2 1 0 2410 6816 3492 38 6 57
0 0 0 4856816 1240168 8 138 0 0 0 0 0 0 1 0 0 2314 4026 3232 34 4 62
0 0 0 4874176 1247712 0 86 0 0 0 0 0 0 0 0 0 2298 3930 3324 35 2 63
2 0 0 4926088 1270824 34 560 0 0 0 0 0 0 0 0 0 2192 4694 2612 29 16 55
0 0 0 5427320 1512952 53 694 0 0 0 0 0 0 3 2 0 2443 5085 3340 33 12 55
0 0 0 5509120 1553136 0 37 0 0 0 0 0 0 0 0 0 2309 3908 3321 35 1 64
至此，此问题得以解决。
8、性能何以提高
回答这个问题似乎是多余的,我只想重申一点:
有效的降低SQL的逻辑读是SQL优化的基本原则之一。
我们来比较一下前后两种执行方式的逻辑读取及性能差异。
a. 全表扫描的性能
SQL> select i.vc2title,i.numinfoguid
2 from hs_info i where i.intenabledflag = 1
3 and i.intpublishstate = 1 and i.datpublishdate <=sysdate
4 and i.numcatalogguid = 3475
5 order by i.datpublishdate desc, i.numorder desc ;
352 rows selected.
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE (Cost=541 Card=1 Bytes=106)
1 0 SORT (ORDER BY) (Cost=541 Card=1 Bytes=106)
2 1 TABLE ACCESS (FULL) OF 'HS_INFO' (Cost=531 Card=1 Bytes=106)
Statistics
----------------------------------------------------------
0 recursive calls
25 db block gets
3499 consistent gets
258 physical reads
0 redo size
…..
2 sorts (memory)
0 sorts (disk)
352 rows processed
b. 使用索引的性能
SQL> select i.vc2title,i.numinfoguid
2 from hs_info i where i.intenabledflag = 1
3 and i.intpublishstate = 1 and i.datpublishdate <=sysdate
4 and i.numcatalogguid = 3475
5 order by i.datpublishdate desc, i.numorder desc;
352 rows selected.
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE (Cost=12 Card=1 Bytes=106)
1 0 SORT (ORDER BY) (Cost=12 Card=1 Bytes=106)
2 1 TABLE ACCESS (BY INDEX ROWID) OF 'HS_INFO' (Cost=2 Card=1 Bytes=106)
3 2 INDEX (RANGE SCAN) OF 'HS_INFO_NUMCATALOGGUID' (NON-UNIQUE) (Cost=1 Card=1)
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
89 consistent gets
0 physical reads
0 redo size
….
1 sorts (memory)
0 sorts (disk)
352 rows processed
consistent gets从3499 到89,我们看到性能得到了巨大的提高.
结语
通常,开发人员很少注意SQL代码的效率,他们更着眼于功能的实现。
至于性能问题通常被认为是次要的,而且在应用系统开发初期,由于数据库数据量较少,对于查询SQL语句等,不容易体会出各种SQL句法的性能差异。
但是一旦这些应用作为生产系统上线运行,随着数据库中数据量的增加,大量并发访问,系统的响应速度可能就会成为系统需要解决的最主要的问题之一。
在少量用户下性能可以接受的SQL，可能在大量用户并发的条件下就会成为性能瓶颈。
在我这个案例中，开发人员很难相信仅只一条SQL语句就导致了整个数据库的性能下降。然而事实就是如此，一条低效的SQL语句就可能毁掉你的数据库，所以在系统设计及开发过程中，你必须考虑到诸多细节，严格的测试也是提早发现问题的有效方法。
如果不幸以上环节都被忽略，那么，DBA(也许就是你)就是最后的一环，你必须能够快速的诊断并解决各种复杂问题。
| 