某客户一个新环境主机solaris 11上的Oracle 11.2.0.4.4的RAC系统，查询dba_segments视图的时候，如果只返回几条数据时是正常的。但是如果查询整个dba_segments视图的时候，就异常缓慢，需要近20分钟才能完成。
最开始怀疑是数据字典的统计信息出现问题，但是重新收集统计信息后，问题依然存在，而且不管执行几次，查询时间并不会减少。
用10046事件跟踪查询过程，用tkprof格式化后可以看到如下部分：
TRACE FILE
————–
Filename=dss1_ora_41051.log
SQL ID: g0xs2m5bxb2hx Plan Hash: 3858284383
select *
from
dba_segments
call count cpu elapsed disk query current rows
——- —— ——– ———- ———- ———- ———- ———-
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 22805 154.72 693.95 480324 532323 207 342047
——- —— ——– ———- ———- ———- ———- ———-
total 22807 154.72 693.95 480324 532323 207 342047
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
———- ———- ———- —————————————————
342047 342047 342047 VIEW SYS_DBA_SEGS (cr=40926 pr=0 pw=0 time=8480798 us cost=8817 size=49541676 card=123238)
342047 342047 342047 UNION-ALL (cr=40926 pr=0 pw=0 time=8198476 us)
341913 341913 341913 HASH JOIN (cr=37726 pr=0 pw=0 time=6126968 us cost=7869 size=26356965 card=109365)
907 907 907 TABLE ACCESS FULL FILE$ (cr=5 pr=0 pw=0 time=431 us cost=3 size=9977 card=907)
341913 341913 341913 HASH JOIN RIGHT OUTER (cr=37721 pr=0 pw=0 time=5567805 us cost=7866 size=25153950 card=109365)
133 133 133 TABLE ACCESS CLUSTER USER$ (cr=136 pr=0 pw=0 time=995 us cost=3 size=1995 card=133)
135 135 135 INDEX FULL SCAN I_USER# (cr=1 pr=0 pw=0 time=183 us cost=1 size=0 card=1)(object id 11)
341913 341913 341913 HASH JOIN (cr=37585 pr=0 pw=0 time=4982638 us cost=7863 size=23513475 card=109365)
48 48 48 TABLE ACCESS FULL TS$ (cr=54 pr=0 pw=0 time=500 us cost=18 size=1200 card=48)
341913 341913 341913 HASH JOIN (cr=37531 pr=0 pw=0 time=4427336 us cost=7844 size=20779350 card=109365)
341913 341913 341913 HASH JOIN (cr=11942 pr=0 pw=0 time=1657429 us cost=5591 size=15092370 card=109365)
342047 342047 342047 TABLE ACCESS FULL SEG$ (cr=2387 pr=0 pw=0 time=132351 us cost=765 size=23639469 card=342601)
686468 686468 686468 VIEW SYS_OBJECTS (cr=9555 pr=0 pw=0 time=655078 us cost=3124 size=47404656 card=687024)
686468 686468 686468 UNION-ALL (cr=9555 pr=0 pw=0 time=445322 us)
49322 49322 49322 TABLE ACCESS FULL TAB$ (cr=2254 pr=0 pw=0 time=62300 us cost=721 size=1085040 card=49320)
426767 426767 426767 TABLE ACCESS FULL TABPART$ (cr=1883 pr=0 pw=0 time=91690 us cost=601 size=7691850 card=427325)
11 11 11 TABLE ACCESS FULL CLU$ (cr=2253 pr=0 pw=0 time=99 us cost=720 size=154 card=11)
11485 11485 11485 TABLE ACCESS FULL IND$ (cr=2253 pr=0 pw=0 time=5807 us cost=720 size=195245 card=11485)
10128 10128 10128 TABLE ACCESS FULL INDPART$ (cr=59 pr=0 pw=0 time=4228 us cost=19 size=182304 card=10128)
459 459 459 TABLE ACCESS BY INDEX ROWID LOB$ (cr=99 pr=0 pw=0 time=1232 us cost=99 size=8721 card=459)
459 459 459 INDEX FULL SCAN I_LOB1 (cr=1 pr=0 pw=0 time=390 us cost=1 size=0 card=459)(object id 81)
177035 177035 177035 TABLE ACCESS FULL TABSUBPART$ (cr=713 pr=0 pw=0 time=35355 us cost=229 size=2655525 card=177035)
11260 11260 11260 TABLE ACCESS FULL INDSUBPART$ (cr=39 pr=0 pw=0 time=1978 us cost=13 size=168900 card=11260)
1 1 1 TABLE ACCESS FULL LOBFRAG$ (cr=2 pr=0 pw=0 time=24 us cost=2 size=17 card=1)
774481 774481 774481 TABLE ACCESS FULL OBJ$ (cr=25589 pr=0 pw=0 time=563643 us cost=905 size=40302236 card=775043)
134 134 134 HASH JOIN (cr=350 pr=0 pw=0 time=3253 us cost=160 size=3542 card=22)
134 134 134 HASH JOIN OUTER (cr=336 pr=0 pw=0 time=2209 us cost=157 size=3300 card=22)
134 134 134 HASH JOIN (cr=200 pr=0 pw=0 time=2488 us cost=154 size=2970 card=22)
134 134 134 NESTED LOOPS (cr=146 pr=0 pw=0 time=3579 us cost=136 size=2420 card=22)
134 134 134 TABLE ACCESS FULL UNDO$ (cr=2 pr=0 pw=0 time=387 us cost=2 size=5494 card=134)
134 134 134 TABLE ACCESS CLUSTER SEG$ (cr=144 pr=0 pw=0 time=995 us cost=1 size=69 card=1)
134 134 134 INDEX UNIQUE SCAN I_FILE#_BLOCK# (cr=10 pr=0 pw=0 time=254 us cost=0 size=0 card=1)(object id 9)
48 48 48 TABLE ACCESS FULL TS$ (cr=54 pr=0 pw=0 time=309 us cost=18 size=1200 card=48)
133 133 133 TABLE ACCESS CLUSTER USER$ (cr=136 pr=0 pw=0 time=754 us cost=3 size=1995 card=133)
135 135 135 INDEX FULL SCAN I_USER# (cr=1 pr=0 pw=0 time=156 us cost=1 size=0 card=1)(object id 11)
907 907 907 TABLE ACCESS FULL FILE$ (cr=14 pr=0 pw=0 time=247 us cost=3 size=9977 card=907)
0 0 0 HASH JOIN (cr=2850 pr=0 pw=0 time=85058 us cost=788 size=1662120 card=13851)
907 907 907 TABLE ACCESS FULL FILE$ (cr=5 pr=0 pw=0 time=42 us cost=3 size=9977 card=907)
0 0 0 HASH JOIN RIGHT OUTER (cr=2845 pr=0 pw=0 time=84210 us cost=785 size=1509759 card=13851)
133 133 133 TABLE ACCESS CLUSTER USER$ (cr=136 pr=0 pw=0 time=783 us cost=3 size=1995 card=133)
135 135 135 INDEX FULL SCAN I_USER# (cr=1 pr=0 pw=0 time=173 us cost=1 size=0 card=1)(object id 11)
0 0 0 HASH JOIN (cr=2709 pr=0 pw=0 time=82717 us cost=782 size=1301994 card=13851)
48 48 48 TABLE ACCESS FULL TS$ (cr=54 pr=0 pw=0 time=450 us cost=18 size=1200 card=48)
0 0 0 TABLE ACCESS FULL SEG$ (cr=2655 pr=0 pw=0 time=80981 us cost=764 size=955719 card=13851)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
—————————————- Waited ———- ————
SQL*Net message to client 22805 0.00 0.02
Disk file operations I/O 575 0.00 0.01
gc current block 2-way 7 0.00 0.00
SQL*Net message from client 22805 0.00 9.09
db file sequential read 480324 0.03 526.91
gc cr disk read 240465 0.00 49.50
KJC: Wait for msg sends to complete 2 0.00 0.00
latch free 1 0.01 0.01
gc cr block 2-way 68 0.00 0.03
gc current block congested 1 0.00 0.00
********************************************************************************
可以看到，该查询有大量的物理读。查看原始的trc文件，能够看到：
TRACE
====================
filename=dss1_ora_41051.trc
WAIT #18446744071511115840: nam=’gc cr disk read’ ela= 179 p1=85 p2=1474 p3=4 obj#=-1 tim=7277328785184
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 293 file#=85 block#=1474 blocks=1 obj#=-1 tim=7277328785552
WAIT #18446744071511115840: nam=’SQL*Net message to client’ ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=7277328785660
WAIT #18446744071511115840: nam=’gc cr disk read’ ela= 437 p1=85 p2=1506 p3=4 obj#=-1 tim=7277328786267
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 4151 file#=85 block#=1506 blocks=1 obj#=-1 tim=7277328790498
WAIT #18446744071511115840: nam=’gc cr disk read’ ela= 242 p1=85 p2=1506 p3=4 obj#=-1 tim=7277328791523
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 428 file#=85 block#=1506 blocks=1 obj#=-1 tim=7277328792216
WAIT #18446744071511115840: nam=’gc cr disk read’ ela= 211 p1=85 p2=1506 p3=4 obj#=-1 tim=7277328793014
……
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 295 file#=87 block#=934626 blocks=1 obj#=-1 tim=7277891694056
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 6119 file#=87 block#=934626 blocks=1 obj#=-1 tim=7277891700329
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 295 file#=87 block#=934626 blocks=1 obj#=-1 tim=7277891700806
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 302 file#=87 block#=934530 blocks=1 obj#=-1 tim=7277891701284
……
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 4206 file#=87 block#=884930 blocks=1 obj#=-1 tim=7277949460424
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 296 file#=87 block#=884930 blocks=1 obj#=-1 tim=7277949460864
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 309 file#=87 block#=884930 blocks=1 obj#=-1 tim=7277949461301
WAIT #18446744071511115840: nam=’db file sequential read’ ela= 305 file#=87 block#=884834 blocks=1 obj#=-1 tim=7277949461782
从这些诊断文件中，发现执行计划都是走的full table scan。但是等待事件却是单块读的等待事件。
怀疑在访问dba_segments视图的时候，去访问每一个segment的head file中的bitmap， 由于这些bitmap没有cache到内存中，引起的单块物理读操作。从dba_segments视图中验证这些数据块的内容。
select a.owner,a.segment_name,a.partition_name,a.segment_type,a.segment_subtype,a.tablespace_name,a.header_file,a.header_block from dba_segments a
where a.header_file in(85,87,92)
and a.header_block in(1474,1506,934626,934530,884834,469826,469762)
1 BONC_PURE SYS_IL0000102023C00007$$ LOBINDEX ASSM TBS_DM_SMALL 87 1474
2 BONC_PURE VBAP_LOG TABLE ASSM TBS_DM_SMALL 87 1506
3 DP_REPO BEAF_SCHEMA TABLE ASSM TBS_DM_SMALL 85 1474
4 DP_REPO BEAF_SCHEMA_HELP TABLE ASSM TBS_DM_SMALL 85 1506
5 DM DM_3G_D_DEV_BUSINESS_A PART20130212 TABLE PARTITION ASSM TBS_DM_SMALL 92 469826
6 DM DM_3G_D_DEV_BUSINESS_A PART20130211 TABLE PARTITION ASSM TBS_DM_SMALL 92 469762
7 DM DM_3G_CHANNELUSER_DEV PART20121117 TABLE PARTITION ASSM TBS_DM_SMALL 92 884834
8 DM DM_D_GSM_USER_DEVELOP PART20120312 TABLE PARTITION ASSM TBS_DM_SMALL 87 469826
9 DM DM_3G_DEV_INCR PART20120401 TABLE PARTITION ASSM TBS_DM_SMALL 92 934530
10 DM DM_CHNL_D_TWOCHNLDEV_HB PART20130331 TABLE PARTITION ASSM TBS_DM_SMALL 87 934626
11 DM DM_CHNL_D_TWOCHNLDEV_HB PART20130330 TABLE PARTITION ASSM TBS_DM_SMALL 87 934530
12 DM DM_D_3G_ACCEPT PART20140914 TABLE PARTITION ASSM TBS_DM_SMALL 87 884834
在MOS上查询后，怀疑是Oracle的bug 16820228引发的。
Bug 16820228 : SLOW QUERY PERFORMANCE ON USER_SEGMENTS DUE TO SLOW SEGMENTS
可以通过以下测试方式确认该问题。
具体步骤：
1. 建立测试表1000个。
=============================================
declare i Number(10);
str_create varchar2(100);
Begin
i := 1;
execute immediate ’set role all’;
for i in 1..1000 loop
str_create:=’create table test_’||to_char(i)|| ‘ (a char(100))’ ;
execute immediate str_create;
end loop;
End ;
2.插入数据
==============================================
declare i Number(10);
str_create varchar2(100);
Begin
i := 1;
execute immediate ’set role all’;
for i in 1..1000 loop
str_create:=’insert into test_’||to_char(i)||’ select ”test” from user_tables’;
execute immediate str_create;
commit;
end loop;
End ;
3. 观察blocks和extexts的更新情况
===============================================
select bitand(segment_flags, 131073),count(*)
from sys.sys_dba_segs
where owner = ‘WP’ –<<你的用户
group by bitand(segment_flags, 131073)
不停观察这个查询结果。等待超过5分钟。
如果撞到这个bug，最终的结果，应该类似如下：
BITAND(SEGMENT_FLAGS,131073) COUNT(*)
1 950
131073 50
这个说明1000这个表，其中只有50个正确更新了数据到seg$,有950个没有正确更新。
这个bug会引起访问user_tables 和dba_tables 性能慢。
4. 删除测试表
================================================
declare i Number(10);
str_create varchar2(100);
Begin
i := 1;
execute immediate ’set role all’;
for i in 1..1000 loop
str_create:=’drop table test_’||to_char(i);
execute immediate str_create;
end loop;
End ;
这个bug在solaris系统上目前还没有补丁，但是可以通过一些方式临时解决。即对该数据库中所有的ASSM的表空间执行如下语句
dbms_space_admin.tablespace_fix_segment_extblks(‘FMTALM_DATA’); – 说明，FMTALM-DATA为表空间名称。
但是随着数据修改和空间分配的变化， 相同的问题还将继续产生，所以该语句需要经常执行，只是一个临时解决方案。
在我的这个系统中，将几十个是表空间跑完该命令共花费73分钟，然后执行对dba_segments的全表查询，时间降到20秒左右。
