极限优化：从75到2000,由技能到性能提升岂止20倍

崔华，网名 dbsnake

Oracle ACE Director，ACOUG 核心专家

编辑手记：感谢崔华授权我们独家转载其精品文章，也欢迎大家向“Oracle”社区投稿。

崔华手记：这篇文章的标题颇有些标题党的味道，但这不是我的初衷。其实我想表达的是，基于RDBMS的应用系统的性能问题绝大多数都是和SQL直接相关，而基于Oracle数据库的SQL优化能否奏效、效果的好与坏归根结底比拼的还是对CBO和执行计划的理解程度，这也正是我在《基于Oracle的SQL优化》一书中提出来的SQL优化方法论的第一点——Oracle里SQL优化的本质是基于对CBO和执行计划的深刻理解。

整个事情是这样的……

快下班的时候去打卡，兄弟部门的同事拦住了我，说他们有一个测试系统，性能一直上不去，现在每分钟仅能跑75个Job，想让我帮忙看一下。

简单的用TOP和VMSTAT看了一下，发现在他们并发跑Job的时候，CPU占用率接近100%，IDLE值接近零，看上去瓶颈像是在CPU上。

我让他们将事发时间段的AWR报告发给我，然后我就回家了。

第二天早上来到公司，我打开了这份AWR报告。

如下是这份AWR报告的部分内容：

Top 5 Timed Foreground Events

从上述显示内容中我们可以看出，上述数据库在上述采样时间段是非常繁忙的，Cache Buffers Chains有894797次等待，平均等待时间25毫秒，占了26.07%的DB time。

Cache Buffers Chains等待通常说明存在热点块，这可能是由于Oracle自身的Bug（例如“Bug 10396041 – ‘cache buffers chains’ latch contention [ID 10396041.8]”），当然更多的情形是由于应用的某些SQL不恰当的多读了一些本不应该它们读的数据块。所以通常情况下缓解Cache Buffers Chains的方法就是调整SQL，缩减目标SQL所需要读的数据块的数量，这样Cache Buffers Chains等待的数量自然就下去了。

从上述AWR报告中SQL ordered by Gets部分我们可以很轻易的定位出待调整的目标SQL为SQL ID为“73qyztauub2a1”和“74hnt3vjjm85a”的这两条SQL：

SQL ID为“73qyztauub2a1”的SQL文本为如下所示：

SELECT s.LOCATOR_ID, s.segment_ID, n.en_name

FROM ANA_SEG_CLASS S, ana_segment a, ana_name n

where A.SEGMENT_ID = S.SEGMENT_ID

and s.locator_id = n.locator_id

and n.en_name = :1

and ((a.orgn_city = :2 and a.start_time > :3 and a.start_time < :4) or

(a.dstn_city = :5 and a.end_time > :6 and a.end_time < :7))

and n.person_id_count > 0

从同样采样时间段的AWR SQL Report中我们可以看出SQL ID为“73qyztauub2a1”的目标SQL的资源消耗和执行计划为如下所示：

从上述显示内容中我们可以看出，SQL ID为“73qyztauub2a1”的目标SQL在采样时间段每次执行平均只返回0.1行记录，但平均每次执行需要耗时1009秒，平均每次执行所消耗的逻辑读为25407585。

从该SQL的执行计划我们可以看出，CBO评估出来执行该SQL所对应的成本值为2，这是一个明显异常的值，假如成本值真的像CBO评估的那样为2的话，那么该SQL就不可能平均每次执行需要消耗超过2500万的逻辑读。

很明显，这里很可能是上述SQL所涉及到的对象的统计信息出现了问题，我们现在来检查一下：

表ANA_NAME的统计信息为如下所示：

从上述显示内容中我们可以看出，表ANA_NAME的相关统计信息值全部为0，但实际上表ANA_NAME是一个有300多万数据量的大表：

SQL> select count(*) from ana_name;

COUNT(*)

———-

3180474

所以很明显这里是由于表ANA_NAME的统计信息严重不准而导致CBO选错了执行计划。分析清楚了问题的原因，解决起来就很简单了，我们只需要重新对上述SQL所涉及到的表用如下命令重新收集一下统计信息就好了：

SQL> exec dbms_stats.gather_table_stats(ownname => ‘GALT’,tabname => ‘ANA_NAME’,cascade => true,no_invalidate => false);

PL/SQL procedure successfully completed

SQL> exec dbms_stats.gather_table_stats(ownname => ‘GALT’,tabname => ‘ANA_SEGMENT’,cascade => true,no_invalidate => false);

PL/SQL procedure successfully completed

SQL> exec dbms_stats.gather_table_stats(ownname => ‘GALT’,tabname => ‘ANA_SEG_CLASS’,cascade => true,no_invalidate => false);

PL/SQL procedure successfully completed

重新收集完统计信息后表ANA_NAME的相关统计信息已经有了值：

同时，上述SQL ID为“73qyztauub2a1”的目标SQL的执行计划也已经恢复了正常：

SQL> explain plan for SELECT s.LOCATOR_ID, s.segment_ID, n.en_name FROM ANA_SEG_CLASS S, ana_segment a , ana_name n where A.SEGMENT_ID = S.SEGMENT_ID and s.locator_id = n.locator_id and n.en_name = :1 and ( ( a.orgn_city = :2 and a.start_time > :3 and a.start_time < :4 ) or ( a.dstn_city=:5 and a.end_time> :6 and a.end_time < :7 ) ) and n.person_id_count > 0;

Explained

SQL> col plan_table_output for a200

SQL> select * from table(dbms_xplan.display);

是不是这就完事了？——事情没有这么简单。

表ANA_NAME的那300多万的数据早就存在了，并不是今天早上才导入的，为什么经过了昨晚的自动收集统计信息作业，其各项统计信息的值还是为0？

是不是因为这个库的自动统计信息收集作业被禁掉了？

我们来检查一下：

SQL> select client_name,status from dba_autotask_task;

CLIENT_NAME STATUS

—————————————————————- ——–

sql tuning advisor ENABLED

auto optimizer stats collection ENABLED

auto space advisor ENABLED

SQL> select window_name,autotask_status from dba_autotask_window_clients;

WINDOW_NAME AUTOTASK_STATUS

—————————— —————

MONDAY_WINDOW ENABLED

TUESDAY_WINDOW ENABLED

WEDNESDAY_WINDOW ENABLED

THURSDAY_WINDOW ENABLED

FRIDAY_WINDOW ENABLED

SATURDAY_WINDOW ENABLED

SUNDAY_WINDOW ENABLED

7 rows selected

SQL> select window_name,repeat_interval from dba_scheduler_windows where enabled=’TRUE’;

WINDOW_NAME REPEAT_INTERVAL

—————- ——————————————————

MONDAY_WINDOW freq=daily;byday=MON;byhour=22;byminute=0; bysecond=0

TUESDAY_WINDOW freq=daily;byday=TUE;byhour=22;byminute=0; bysecond=0

WEDNESDAY_WINDOW freq=daily;byday=WED;byhour=22;byminute=0; bysecond=0

THURSDAY_WINDOW freq=daily;byday=THU;byhour=22;byminute=0; bysecond=0

FRIDAY_WINDOW freq=daily;byday=FRI;byhour=22;byminute=0; bysecond=0

SATURDAY_WINDOW freq=daily;byday=SAT;byhour=6;byminute=0; bysecond=0

SUNDAY_WINDOW freq=daily;byday=SUN;byhour=6;byminute=0; bysecond=0

7 rows selected

SQL> select window_name, job_name, job_start_time from (select * from dba_autotask_job_history where client_name=’auto optimizer stats collection’ order by window_start_time desc) where rownum<4;

WINDOW_NAME JOB_NAME JOB_START_TIME

————— ——————— ————————————

TUESDAY_WINDOW ORA$AT_OS_OPT_SY_1 09-4月 -13 10.00.00.825901 下午 PRC

SQL> select window_name,window_next_time from dba_autotask_window_clients;

WINDOW_NAME WINDOW_NEXT_TIME

—————————— ————————————-

MONDAY_WINDOW 15-4月 -13 10.00.00.000000 下午 PRC

TUESDAY_WINDOW 16-4月 -13 10.00.00.000000 下午 PRC

WEDNESDAY_WINDOW 10-4月 -13 10.00.00.000000 下午 PRC

THURSDAY_WINDOW 11-4月 -13 10.00.00.000000 下午 PRC

FRIDAY_WINDOW 12-4月 -13 10.00.00.000000 下午 PRC

SATURDAY_WINDOW 13-4月 -13 06.00.00.000000 上午 PRC

SUNDAY_WINDOW 14-4月 -13 06.00.00.000000 上午 PRC

7 rows selected

从上述显示内容中我们可以看出，上述库的自动统计信息收集作业并没有被禁掉，只是出于某种原因，自4月9日晚上10点最后一次运行完后就再没有被执行过。

Oracle 11g里的自动统计信息收集作业每次运行时会先生成名为ORA$AT_OS_OPT_XXX的Job，然后再执行这个Job。所以有一种可能就是虽然自动统计信息收集作业没有被禁掉，但Oracle在生成Job的时候碰到了问题，比如参数job_queue_processes的值被设成了0。

从如下查询结果中我们可以看到，上述库的job_queue_processes的值果然是0：

SQL> show parameter job;

NAME TYPE VALUE

———————————— ———– ——————————

job_queue_processes integer 0

从上述库的alert log里我们看到了如下内容：

Wed Apr 10 14:09:50 2013

ALTER SYSTEM SET job_queue_processes=0 SCOPE=BOTH;

Wed Apr 10 14:10:26 2013

ALTER SYSTEM SET aq_tm_processes=0 SCOPE=BOTH;

ALTER DATABASE OPEN

Wed Apr 10 14:10:35 2013

这说明上述库的参数job_queue_processes和aq_tm_processes在4月10日下午2点多的时候被修改成了0，难怪上述库的自动统计信息收集作业自4月9日晚上10点最后一次运行完后就再没有被成功执行过。

我们将上述两个参数的值给改回来：

SQL> alter system set job_queue_processes = 1000 scope=both;

System altered

SQL> alter system set aq_tm_processes = 1 scope=both;

System altered

SQL> show parameter job_queue_processes;

NAME TYPE VALUE

———————————— ———– ——————————

job_queue_processes integer 1000

SQL> show paramete aq_tm_processes;

NAME TYPE VALUE

———————————— ———– ——————————

aq_tm_processes integer 1

从如下查询结果中我们可以看到，参数job_queue_processes恢复成大于0的值后，上述库的自动统计信息收集作业的各个窗口所对应的WINDOW_NEXT_TIME的值也随之恢复了正常：

SQL> select window_name,window_next_time from dba_autotask_window_clients;

WINDOW_NAME WINDOW_NEXT_TIME

—————————— ————————————

MONDAY_WINDOW 29-4月 -13 10.00.00.000000 下午 PRC

TUESDAY_WINDOW 23-4月 -13 10.00.00.000000 下午 PRC

WEDNESDAY_WINDOW 24-4月 -13 10.00.00.000000 下午 PRC

THURSDAY_WINDOW 25-4月 -13 10.00.00.000000 下午 PRC

FRIDAY_WINDOW 26-4月 -13 10.00.00.000000 下午 PRC

SATURDAY_WINDOW 27-4月 -13 06.00.00.000000 上午 PRC

SUNDAY_WINDOW 28-4月 -13 06.00.00.000000 上午 PRC

7 rows selected

接下来，我们对上述SQL所涉及到的schema重新收集了一下统计信息（以避免再次出现有目标表的统计信息严重不准的情形）：

SQL> EXEC DBMS_STATS.GATHER_SCHEMA_STATS(OWNNAME => ‘GALT’,ESTIMATE_PERCENT => DBMS_STATS.AUTO_SAMPLE_SIZE,CASCADE => TRUE,METHOD_OPT => ‘FOR ALL COLUMNS SIZE REPEAT’,no_invalidate => false);

PL/SQL procedure successfully completed

此时第一阶段的调整就结束了，根据同事的反馈，现在每分钟能跑的Job的数量已经从之前的75上升到了现在的2000 。