1、CPU接近100% nmon数据 8月5日在9:209:40之间,出现CPU接近100%的情况,特点表现为9:20左右CPU急剧攀升,在9:45左右又快速下降 2、原因分析结果总述 2.1 持续时间与恢复方式 此次CPU攀高时间持续约20分钟,在无人工干预的情况下自动恢复 2.2 原因分析
1、CPU接近100% nmon数据
8月5日在9:20—9:40之间,出现CPU接近100%的情况,特点表现为9:20左右CPU急剧攀升,在9:45左右又快速下降
2、原因分析结果总述
2.1 持续时间与恢复方式
此次CPU攀高时间持续约20分钟,在无人工干预的情况下自动恢复
2.2 原因分析总述:
经过分析,原因为:4条SQL语句ORACLE优化器对LB_T_XXXVIDER视图、LB_T_XXXJECT_PROVIDER表、LA_XXCKAGE表的基数数据评估发生了巨大的差错,导致选择了错误的执行计划,消耗大量的CPU资源
2.3 错误执行计划估算数据与正确执行计划估算数据对比
此处为选择一条最严重的SQL语句为例,其它语句原因相同
错误执行计划基数估算值 |
Execution Plan
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
正确执行计划基数估算值 |
Execution Plan
|
说明上面统计信息与实际数据存在非常大的差异,是引起执行计划错误的真正原因
2.4 错误执行计划与正确执行计划CPU资源消耗差异巨大对比
此处为选择一条最严重的SQL语句为例,其它语句比例相近
SQL ID: bj75p9188y410
# |
Plan Hash Value |
Total Elapsed Time(ms) |
Executions |
1st Capture Snap ID |
Last Capture Snap ID |
1 |
3990363694 |
4,585,425 |
9 |
33676 |
33677 |
2 |
6178145 |
2,838 |
2 |
33677 |
33677 |
3 |
2354817963 |
1,461 |
1 |
33677 |
33677 |
错误执行计划CPU消耗是最优执行计划CPU消耗的348倍
2.5 问题自动修复原因
ORACLE11G 的新功能cardinality feedback可以在上次运行完成后,得到上一次运行的基数真正结果,智能的调整后面语句运行时的执行计划,通过cardinality feedback功能得到准确基数数据后调整的执行计划,会给出下面提示:
cardinality feedback used for this statement
3、数据库时间与AWR快照对应信息
此在列出时间与AWR快照对应信息的原因为后续分析依赖时间与快照的关系,展示阶段性数据
序号 |
snap_id |
BEGIN_INTERVAL_TIME |
END_INTERVAL_TIME |
1 |
33675 |
05-8月 -13 08.30.41.054 |
05-8月 -13 09.00.09.786 |
2 |
33676 |
05-8月 -13 09.00.09.786 |
05-8月 -13 09.30.10.502 |
3 |
33677 |
05-8月 -13 09.30.10.502 |
05-8月 -13 10.00.26.364 |
4 |
33678 |
05-8月 -13 10.00.26.364 |
05-8月 -13 10.30.18.791 |
5 |
33679 |
05-8月 -13 10.30.18.791 |
05-8月 -13 11.00.24.540 |
4、总体原因具体分析
8月5日9:00—10:00AWR报告分析
SQL ordered by CPU Time
|
分析:
(1) 上述标红色语句共四条,其中第4条和第10条其实为同一条SQL语句
(2) 上述四条标红色SQL语句分析为最消耗CPU资源的语句
(3) 上述四条标红色SQL语句在出问题前都没有运行,基本都集中在9:00以后开始运行
(4) 上述标红色语句的问题有共同特性,都调用了LB_T_XXXVIDER视图、LB_T_XXXJECT_PROVIDER表、LA_XXCKAGE
(5) 上述标红色语句都是因为优化器对LB_T_XXXVIDER视图、LB_T_XXXJECT_PROVIDER表、LA_XXCKAGE表的基数数据评估发生了巨大的差错,导致选择了错误的执行计划,消耗大量的CPU资源,导致CPU接近100%
(6) 上述标红色语句都是在几次错误选择后有效的利用了ORACLE11g的新特性cardinalityfeedback功能,最终得到准确的基数数据,自行修正了执行计划
5、问题语句逐条剖析
5.1 第一条:SQL_ID:bj75p9188y410
SQL ID: bj75p9188y410
# |
Plan Hash Value |
Total Elapsed Time(ms) |
Executions |
1st Capture Snap ID |
Last Capture Snap ID |
1 |
3990363694 |
4,585,425 |
9 |
33676 |
33677 |
2 |
6178145 |
2,838 |
2 |
33677 |
33677 |
3 |
2354817963 |
1,461 |
1 |
33677 |
33677 |
分析:
(1)标红色的为错误的执行计划及其统计信息
(2)9:00—10:00之间,共发生9次错误的执行计划
(3)在前面发生9次错误的执行计划之后,由于ORACLE 11G的cardinality feedback新功能,最终得到准确的基数,在9:30-10:00之间,自动纠正了执行计划
5.2 第二条:SQL_ID:gmfktzfsd6hj3
SQL ID: gmfktzfsd6hj3
# |
Plan Hash Value |
Total Elapsed Time(ms) |
Executions |
1st Capture Snap ID |
Last Capture Snap ID |
1 |
617277444 |
2,602,874 |
6 |
33677 |
33678 |
2 |
2335536944 |
2,725 |
2 |
33678 |
33678 |
3 |
687995303 |
1,437 |
1 |
33678 |
33678 |
分析:
(1)标红色的为错误的执行计划及其统计信息
(2)9:30—10:30之间,共发生6次错误的执行计划
(3)在前面发生6次错误的执行计划之后,由于ORACLE 11G的cardinality feedback新功能,最终得到准确的基数,在10:00-10:30之间,自动纠正了执行计划
5.3 第三条:SQL_ID:1d44jc4at7xt6
SQL ID: 1d44jc4at7xt6
# |
Plan Hash Value |
Total Elapsed Time(ms) |
Executions |
1st Capture Snap ID |
Last Capture Snap ID |
1 |
3265929876 |
2,029,525 |
4 |
33676 |
33677 |
2 |
2949667951 |
19,116 |
13 |
33676 |
33677 |
3 |
1227972422 |
1,761 |
1 |
33676 |
33677 |
分析:
(1)标红色的为错误的执行计划及其统计信息
(2)9:00—10:00之间,共发生4次错误的执行计划,其中
(3)在前面发生4次错误的执行计划之后,由于ORACLE 11G的cardinality feedback新功能,最终得到准确的基数,在9:30-10:00之间,自动纠正了执行计划
5.4 第四条:SQL_ID:fh86uz0ch9z9w
SQL ID: fh86uz0ch9z9w
# |
Plan Hash Value |
Total Elapsed Time(ms) |
Executions |
1st Capture Snap ID |
Last Capture Snap ID |
1 |
3265929876 |
1,247,089 |
4 |
33676 |
33681 |
2 |
2949667951 |
2,624 |
2 |
33681 |
33681 |
3 |
1227972422 |
1,291 |
1 |
33681 |
33681 |
分析:
(1)标红色的为错误的执行计划及其统计信息
(2)9:00—11:30之间,共发生4次错误的执行计划,其中两次发生在9:00-9:30间
(3)在前面发生4次错误的执行计划之后,由于ORACLE 11G的cardinality feedback新功能,最终得到准确的基数,在11:00-11:30之间,自动纠正了执行计划
6、引发执行计划错误原因分析
6.1 表统计信息统计历史
6.1.1 LB_T_XXXJECT_PROVIDER
序号 |
用户名 |
表名 |
分析历史时间 |
1 |
BIDPRO |
LB_T_XXXJECT_PROVIDER |
11-8月 -13 20.06.16.630512 |
2 |
BIDPRO |
LB_T_XXXJECT_PROVIDER |
03-8月 -13 20.22.23.332654 |
3 |
BIDPRO |
LB_T_XXXJECT_PROVIDER |
26-7月 -13 22.18.08.386638 |
在8月5日开标前,该表已经有10天未统计
6.1.2 LA_XXCKAGE
序号 |
用户名 |
表名 |
分析历史时间 |
1 |
BIDPRO |
LA_XXCKAGE |
15-8月 -13 20.01.28.232128 |
2 |
BIDPRO |
LA_XXCKAGE |
09-8月 -13 20.04.35.224700 |
3 |
BIDPRO |
LA_XXCKAGE |
26-7月 -13 20.08.49.666682 |
在8月5日开标前,该表已经有10天未统计
6.1.3 XXCC_SUPPLIER
序号 |
用户名 |
表名 |
分析历史时间 |
1 |
BIDPRO |
XXCC_SUPPLIER |
18-8月 -13 20.13.21.031834 |
2 |
BIDPRO |
XXCC_SUPPLIER |
10-8月 -13 20.07.04.740643 |
3 |
BIDPRO |
XXCC_SUPPLIER |
31-7月 -13 22.00.39.107474 |
4 |
BIDPRO |
XXCC_SUPPLIER |
22-7月 -13 22.01.26.170018 |
在8月5日开标前,该表已经有5天未统计
6.1.4 XXCC_SUPPLIER_CONTACT
序号 |
用户名 |
表名 |
分析历史时间 |
1 |
BIDPRO |
XXCC_SUPPLIER_CONTACT |
17-8月 -13 20.03.30.834585 |
2 |
BIDPRO |
XXCC_SUPPLIER_CONTACT |
09-8月 -13 22.03.30.402420 |
3 |
BIDPRO |
XXCC_SUPPLIER_CONTACT |
26-7月 -13 22.07.06.696581 |
在8月5日开标前,该表已经有10天未统计
6.2 表数据变化分析
6.2.1 8月5日前最后一次统计时间至8月5日时的block_changes数量
序号 |
表名 |
最后一次统计时间 |
block_changes |
1 |
LB_T_XXXJECT_PROVIDER |
26-7月 -13 22.18 |
158560 |
2 |
LA_XXCKAGE |
26-7月 -13 20.08 |
168224 |
3 |
XXCC_SUPPLIER |
31-7月 -13 22.00 |
608 |
4 |
XXCC_SUPPLIER_CONTACT |
26-7月 -13 22.07 |
576 |
6.3 错误执行计划预估数据量与真正数据量差异对比
SQL_ID |
执行计划对错区分 |
对表的ROWS评估数 |
|||
XXCC_SUPPLIER_CONTACT |
XXCC_SUPPLIER |
LA_XXCKAGE |
LB_T_XXXJECT_PROVIDER |
||
bj75p9188y410 |
错误执行计划 |
30058 |
1 |
1 |
1 |
正确执行计划 |
10M |
26139 |
1 |
347 |
|
gmfktzfsd6hj3 |
错误执行计划 |
30058 |
1 |
1 |
1 |
正确执行计划 |
10M |
26139 |
1 |
347 |
|
1d44jc4at7xt6 |
错误执行计划 |
30058 |
1 |
1 |
1 |
正确执行计划 |
10M |
26139 |
1 |
347 |
|
fh86uz0ch9z9w |
错误执行计划 |
30058 |
1 |
1 |
1 |
正确执行计划 |
7763K |
26139 |
1 |
347 |
7、解决方案建议
建议对上述四条发生执行计划错误的SQL语句,采用SQL_PROFILE对执行计划进行固定,可以避免下次开标时出现同样的问题