« DBA手记:SQL_TRACE跟踪与诊断案例 | Blog首页 | DBA手记:X$KTUXE与Oracle的死事务恢复 »
DBA手记:临时表空间组导致递归SQL高度解析
链接:https://www.eygle.com/archives/2011/03/temporary_tablespace_group.html
在2009年的一次客户现场服务中,很惊奇地再次看到了熟悉的表名和用户,这套系统(如图1-13)就是1.7我写到过的那个发布系统,作为一个DBA,多年以后看到似曾相识的数据库,是多么令人感慨。
图1-13 AWR中采样的部分SQL
从图1-13中摘录的是AWR中采样的一些SQL,这些SQL没有绑定变量,是性能影响的一个因素。
客户反映这个系统的主要问题是CPU消耗很高,经常处于90%以上运行。我们对数据库AWR采样生成了一个10小时的采样报告(如图1-14所示),这是一个运行于IBM P595之上的Oracle 10.2.0.2版本的RAC集群数据库:
图1-14 AWR生成的10小时采样报告
从图1-14报告的DB Time/Elapsed = 8.6,可以获得的整体印象是,数据库处于相当繁忙的运行状态。
如图1-15的负载概要信息(Load Profile)进一步显示,数据库每秒的逻辑读高达857 104.76次,SQL Parses每秒为750.16次,频繁的SQL解析和User Calls是CPU消耗的另外一方面的体现:
图1-15 负载概要信息
为了了解SQL分析调用的信息,我们可以进一步来查看SQL Statistics 部分的Parse Calls模块内容(如图1-16所示),在这部分信息中,发现了一条可疑的高解析执行的SQL:
图1-16 Parse Calls的输出
排在第一位的这条SQL占据了78.62%的解析比重,在10小时的AWR报告采样中,共执行了两千多万次,平均每秒解析执行约600次,这个高解析执行的SQL以超乎寻常的频率解析执行引起了我们的注意,其SQL的完整文本为:
select min(bitmapped) from ts$ where dflmaxext =:1 and bitand(flags, 1024) =1024
直观判断这条SQL是和系统递归调用相关的,查询了底层的ts$视图,其调用如此频繁必然和大多数查询有关,尝试跟踪一下普通查询,我们发现这个SQL有很高的解析度。比如跟踪如下的SQL:
SQL> alter session set events '10046 trace name context forever,level 12';
Session altered.
SQL> select count(*) from dba_indexes;
COUNT(*)
----------
5890
tkprof格式化后台跟踪文件可以发现,在这个查询中,后台ts$递归查询高达3305次,并且逻辑读很高:
select min(bitmapped) from
ts$ where dflmaxext =:1 and bitand(flags,1024) =1024
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3305 0.02 0.04 0 0 0 0
Execute 3305 0.24 0.30 0 0 0 0
Fetch 6610 0.90 1.05 0 317280 0 3305
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 13220 1.16 1.39 0 317280 0 3305
这使得我怀疑可能是某个Bug在作祟,检索Metalink,马上发现了相关Bug,Bug号为:5455880。该Bug的影响版本如图1-17所示:
Product (Component) |
Oracle Server (Rdbms) |
Range of versions believed to be affected |
Versions < 11 |
Versions confirmed as being affected |
|
Platforms affected |
Generic (all / most platforms affected) |
图1-17 Bug号为5455880的影响版本
客户的数据库版本为10.2.0.2,正好在受影响之列,这个Bug是说,当使用了Oracle 10g的临时表空间组特性时,后台的递归SQL可能会发生高昂的解析及执行:
When using a tablespace group as the temporary tablespace
excessive recursive queried against TS$ can impact performance.
The offending SQL is of the form:
"select min(bitmapped) from ts$ where dflmaxext =:1 and bitand(flags,1024)=1024"
这个Bug在10.2.0.4之后修正,暂时的解决方案是停用临时表空间组。用户调整了临时表空间组的使用之后,这个SQL立即消失了,系统的解析等负载概要信息也发生了较大变化(使用$ORACLE_HOME/rdbms/admin/awrddrpt.sql可以生成两个时段的AWR比较报告),如图1-18所示:
|
1st Per Sec |
2nd Per Sec |
%Diff |
1st Per Txn |
2nd Per Txn |
%Diff |
Parses: |
743.69 |
145.64 |
-80.42 |
22.40 |
5.78 |
-74.20 |
Sorts: |
4,534.49 |
2,670.65 |
-41.10 |
136.60 |
106.02 |
-22.39 |
Executes: |
1,032.02 |
425.26 |
-58.79 |
31.09 |
16.88 |
-45.71 |
图1-18两个时段的AWR比较报告
在使用Oracle的一些新特性时,一定要注意观察,看是否会引发一些新的问题,而DBA应该对系统中的一些异常SQL具有一定的敏锐性,要认真细致及时审查确认,才能保障数据库的持续稳定运行。历史上的今天...
>> 2010-03-04文章:
>> 2008-03-04文章:
>> 2007-03-04文章:
>> 2005-03-04文章:
By eygle on 2011-03-04 08:38 | Comments (5) | Case | 2740 |
我们数据仓库11.1.0.7的MV刷新时,也碰到一个硬解析, 忘了详细场景了, 跟Flashback query有关.
幸好每天只刷新一次. 等下一版本修复它.
MV 10g里边有个Latch free的bug,11.1,准备升级了没有?
估计是递归调用时候有许多冗余计算
估计是这个查询写在Loop里面了,导致过度解析。放外面就好了!
现在是11.1.0.7, 暂时还没有打算升级或者打补丁11.1.0.7.4 (Patch Set Update).
select a.* from v$sql a, (
SELECT hash_value, COUNT(*)
FROM v$sql
GROUP BY hash_value
HAVING COUNT(*) > 1000 ) b
where a.hash_value = b.hash_value
... results show 1000s of versions of this sql:
update sys.sumdelta$ s set s.timestamp = :1, s.scn = :2 where rowid in
(select rowid from sys.sumdelta$ AS OF SNAPSHOT (:3) s1
where s1.tableobj# = :4 and s1.timestamp >= to_date('4000-01-01:00:00:00','YYYY-MM-DD:HH24:MI:SS')
);
Bug 8865718 Recursive cursors for MV refresh not shared.