当前位置：首页 > news >正文

Oracle AWR案例分析：精准定位SQL执行计划切换的时间点

news 2025/11/5 8:39:03

全网最全面的Oracle AWR 专栏，持续更新中…
有一天，我的一个用户突然发现Oracle数据库变得非常慢，但他们无法确定性能下降究竟是从什么时候开始的。

问题SQL

下面是最近一次AWR快照生成的“SQL statistics”部分：
在这里插入图片描述

在这份报告中，排名第一的SQL消耗了超过99%的Total DB Time。它共执行了19次，平均每次耗时高达66秒。紧随其后的两个PL/SQL过程也表现出较差的性能，分别执行了18次和1次，平均执行时间几乎与该SQL一致。显然，这两个PL/SQL过程调用了这个SQL，这个SQL就是性能下降的主要原因。

下面查询在AWR中保存的这个SQL的执行计划：

SQL> select * from table(dbms_xplan.display_awr('g81cbrq5yamf5'));PLAN_TABLE_OUTPUT
___________________________________________________________________________________________________________
SQL_ID g81cbrq5yamf5
--------------------
SELECT ADDRESS_ID, CUSTOMER_ID, DATE_CREATED, HOUSE_NO_OR_NAME,
STREET_NAME, TOWN, COUNTY, COUNTRY, POST_CODE, ZIP_CODE FROM ADDRESSES
WHERE CUSTOMER_ID = :B2 AND ROWNUM < :B1Plan hash value: 1286489376--------------------------------------------------------------------------------
| Id  | Operation          | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |           |       |       |  2681K(100)|          |
|*  1 |  COUNT STOPKEY     |           |       |       |            |          |
|*  2 |   TABLE ACCESS FULL| ADDRESSES |     2 |   154 |  2681K  (1)| 00:01:45 |
--------------------------------------------------------------------------------Predicate Information (identified by operation id):
---------------------------------------------------1 - filter(ROWNUM<:B1)2 - filter("CUSTOMER_ID"=:B2)SQL_ID g81cbrq5yamf5
--------------------
SELECT ADDRESS_ID, CUSTOMER_ID, DATE_CREATED, HOUSE_NO_OR_NAME,
STREET_NAME, TOWN, COUNTY, COUNTRY, POST_CODE, ZIP_CODE FROM ADDRESSES
WHERE CUSTOMER_ID = :B2 AND ROWNUM < :B1Plan hash value: 2480532011--------------------------------------------------------------------------------------------------------
| Id  | Operation                            | Name            | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                     |                 |       |       |     6 (100)|          |
|*  1 |  COUNT STOPKEY                       |                 |       |       |            |          |
|   2 |   TABLE ACCESS BY INDEX ROWID BATCHED| ADDRESSES       |     2 |   154 |     6   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN                  | ADDRESS_CUST_IX |     2 |       |     4   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------Predicate Information (identified by operation id):
---------------------------------------------------1 - filter(ROWNUM<:B1)3 - access("CUSTOMER_ID"=:B2)PLAN_TABLE_OUTPUT
____________________45 rows selected.

该SQL在AWR中有两种执行计划。

Plan 2 使用了索引“ADDRESS_CUST_IX”进行快速访问，成本仅为6，执行时间约1秒。

而Plan 1则跳过索引，对表“ADDRESSES”执行全表扫描，成本高达268万，执行时间达到1分45秒。

两者的“Plan hash value”不同，表明执行计划确实发生了变化。

问题在于：为什么Plan 1会选择全表扫描而不是使用ADDRESS_CUST_IX索引？

让我们查看表ADDRESSES当前的索引元数据：

SELECT index_name, index_type, uniqueness
FROM user_indexes
WHERE table_name = 'ADDRESSES';INDEX_NAME    INDEX_TYPE    UNIQUENESS
__________________ _____________ _____________
ADDRESS_PK         NORMAL/REV    UNIQUE

输出结果表明，当前“ADDRESSES”表只存在一个索引“ADDRESS_PK”，而“ADDRESS_CUST_IX”已不存在。

也就是说，Plan 2中引用的索引消失了。是有人误删了索引，还是该索引从未存在？我们需要进一步调查。

SQL执行计划时间线

既然今天SQL性能变差，我们需要确定高效的Plan 2在什么时候切换成低效的Plan 1。
可以通过AWR中的DBA_HIST_SQLSTAT视图追踪执行计划的变化。该视图存储了SQL在各个AWR快照间的历史统计信息，包括plan hash value和平均执行时间。

以下SQL可构建一条时间线，精确定位性能下降的时间点：

set veri off
define top_sql_id='g81cbrq5yamf5'SELECT b.snap_id,TO_CHAR(b.end_interval_time, 'HH24:MI') AS snap_time,a.plan_hash_value,TRUNC(a.elapsed_time_delta / 1000000 / NULLIF(a.executions_delta, 0), 5) AS avg_elapsed_second
FROM dba_hist_sqlstat a,dba_hist_snapshot b
WHERE sql_id = '&top_sql_id'AND a.snap_id (+) = b.snap_idAND b.begin_interval_time > TRUNC(SYSDATE)
ORDER BY a.snap_id;

输出结果如下：

SNAP_ID    SNAP_TIME    PLAN_HASH_VALUE    AVG_ELAPSED_SECOND
__________ ____________ __________________ _____________________2932 06:00                2480532011               0.000342933 06:30                2480532011               0.001212934 07:00                2480532011               0.001242935 07:30                2480532011               0.001242936 08:00                2480532011               0.001192937 08:30                2480532011               0.001122938 09:00                2480532011               0.001142939 09:30                2480532011               0.001152940 10:00                2480532011                0.00112941 10:30                1286489376              64.993512942 11:00                1286489376              63.295272943 11:30                1286489376              64.502862944 12:00                1286489376              63.360642945 12:30                1286489376              63.421922946 13:00                1286489376              64.472892947 13:30                1286489376              64.5258816 rows selected.

从结果可以看出，Plan 2（2480532011）在06:00到10:00期间运行高效；
到了10:30（快照ID 2941），SQL切换为Plan 1（1286489376），平均执行时间飙升到63秒以上，性能明显崩溃。
这说明在10:00到10:30之间，执行计划发生了切换，极可能由于索引的丢失导致。

进一步缩小时间窗口：ASH视角

接下来，我们可以借助DBA_HIST_ACTIVE_SESS_HISTORY视图进一步缩小时间范围。
该视图每10秒采样一次活动会话，能帮助我们定位更精确的时间点。

DEFINE top_sql_id='g81cbrq5yamf5'
SELECT sql_id,sql_child_number,TO_CHAR(sample_time, 'HH24:MI:SS') AS track_time,sql_plan_hash_value AS curr_sql_plan
FROM dba_hist_active_sess_history
WHERE snap_id = 2941AND sql_id = '&top_sql_id'
ORDER BY sample_time;

输出结果：

SQL_ID    SQL_CHILD_NUMBER    TRACK_TIME    CURR_SQL_PLAN
________________ ___________________ _____________ ________________
...
g81cbrq5yamf5                      0 10:12:22            2480532011
g81cbrq5yamf5                      0 10:12:32            2480532011
g81cbrq5yamf5                      0 10:14:25            2480532011
g81cbrq5yamf5                      1 10:15:26            1286489376
g81cbrq5yamf5                      1 10:15:26            1286489376
g81cbrq5yamf5                      1 10:15:26            1286489376
...

从输出中可以看到，Plan 2（2480532011）一直运行到10:14:25；

到了10:15:26，Plan 1（1286489376）开始被使用。

这意味着执行计划的切换大约发生在10:15左右——这正是性能骤降的精确时间点。