一条SQL让20个CPU都50% Busy

一条SQL让20个CPU都50% Busy

一、概述

GOTOTOP有两年多没有冲锋在技术第一线了，所以这篇文章也只是个没营养的案例而已，有经验的你完全可以跳过:)
硬件：20个CPU×2+128GB MEM×2
软件：AIX5.3+HACMP5.2+Oracle10g RAC
这段时间一直在做压力测试，昨晚客户通知昨天压力测试的结果不理想，今天开会分析结果，希望我们参加，客户的希望对我们就是命令，何况现在项目关键阶段，我高度重视，带工程师准时参加了今天的会议。

二、现象

接下来继续测试现场观察测试情况，监控结果发现一个节点的CPU整体消耗了50%多，可是20个CPU哦，而I/O不足10%，检查Oracle数据库监控结果发现如下现象：

SQL ordered by Elapsed Time
Elapsed Time (s) CPU Time (s) Executions Elap per Exec (s) % Total DB Time SQL Id SQL Text
3,469 105 7,036 0.49 8.63 67vjwqswg2zvy
SELECT formatid, globalid, b…
1,725 485 286,314 0.01 4.29 ddvghnq8kypm4
select SUBSID, REGION, CUSTID,…
1,142 1,052 15,685,884 0.00 2.84 0mbs4b6ujgmrn
select RTFEEID, SUBSID, ACCTID…

SQL ordered by CPU Time
CPU Time (s) Elapsed Time (s) Executions CPU per Exec (s) % Total DB Time SQL Id SQL Text
1,052 1,142 15,685,884 0.00 2.84 0mbs4b6ujgmrn
select RTFEEID, SUBSID, ACCTID…
485 1,725 286,314 0.00 4.29 ddvghnq8kypm4
select SUBSID, REGION, CUSTID,…

SQL ordered by Gets
Buffer Gets Executions Gets per Exec %Total CPU Time (s) Elapsed Time (s) SQL Id SQL Text
46,623,132 15,685,884 2.97 48.53 1052.44 1141.87 0mbs4b6ujgmrn
select RTFEEID, SUBSID, ACCTID…
10,673,101 118,925 89.75 11.11 196.59 200.56 3q32j6tdu8×3f
select VALIDBILLCYC, BILLMODEI…

SQL ordered by Executions
Executions Rows Processed Rows per Exec CPU per Exec (s) Elap per Exec (s) SQL Id SQL Text
15,685,884 0 0.00 0.00 0.00 0mbs4b6ujgmrn
select RTFEEID, SUBSID, ACCTID…
1,504,975 1,386,411 0.92 0.00 0.00 743vt34540cs0
select RTFEEID, SUBSID, ACCTID…

SQL ordered by Parse Calls
Parse Calls Executions % Total Parses SQL Id SQL Text
15,686,218 15,685,884 76.82 0mbs4b6ujgmrn
select RTFEEID, SUBSID, ACCTID…
1,504,983 1,504,975 7.37 743vt34540cs0
select RTFEEID, SUBSID, ACCTID…

三、分析结果

结果表明ID为0mbs4b6ujgmrn的SQL在处理变量解析时可能有问题，原因在于：
1、该SQL执行次数很多，而且解析次数基本和执行次数相同，解析该SQL占据所有SQL解析消耗CPU的76.8%；
2、该SQL读取数据量非常大，占所有SQL数据读的48.5%，但没有数据量返回
3、单独执行该SQL响应很快

下面是完整SQL语句：
select RTFEEID, SUBSID, ACCTID, VALIDBILLCYC, F_ACCTAMT, LASTUPDATETIME, F_LASTUPDATEAMT, DISCMINUTE, STATE from IB_CB_REALTIMEFEE where SUBSID=:1 and STATE=:2 and ACCTID=:3

SQL> select count(*) from IB_CB_REALTIMEFEE;

COUNT(*)
———-
248953


dido
Quote Monday, October 16th, 2006 at 11:43
看的不太清楚，是不是执行次数太多了点？
还有空回技术第一线体验一把？

boypoo1
Quote Monday, October 16th, 2006 at 12:51
既然是压力测试阶段,执行次数或许是要求的
该SQL已经使用了bind var,建议考虑下SESSION_CACHED_CURSORS
oracle documents对这个参数的解释是:
SESSION_CACHED_CURSORS specifies the number of session cursors to cache. Repeated parse calls of the same SQL statement cause the session cursor for that statement to be moved into the session cursor cache. Subsequent parse calls will find the cursor in the cache and do not need to reopen the cursor. Oracle uses a least recently used algorithm to remove entries in the session cursor cache to make room for new entries when needed.
This parameter also constrains the size of the PL/SQL cursor cache which PL/SQL uses to avoid having to reparse as statements are re-executed by a user.
我的建议是先看看这个值目前大小,把它设置为300看看,减少频繁open cursor带来的CPU 消耗

tommy
Quote Monday, October 16th, 2006 at 13:12
to dido：都是别人监控的，我只是看看结果，觉得这是个消耗CPU的典型案例就放上来了，呵呵
boypoo大师给的建议和Oracle一样，NB

wangxin
Quote Thursday, March 8th, 2007 at 00:23
1. 怀疑您截取的SQL语句来自工具（如trace）而非程序代码，原代码恐怕还是使用了literal sql。每秒执行15,685,884/（1052.44+1141.87 ）/20=357 exections/second/avg_cpu, 不然我只能说IBM的cpu太慢了。
3. 虽然使用fast soft parse是比soft parse快点，但是空转（没有执行结果的操作）一样大量消耗cpu.
solution:
相信这是个多线程（并发）式的访问，只要控制线程数量，如并发执行该语句的线程（进程）为5个，那cpu资源就大大释放了。
不知道这个应用是什么行业的那类业务系统。