[20180828]exadata–豆腐渣系统的保护神.txt
–//昨天看awr报表发现如下,时间8-9点报表,这个时间病房业务很少,主要门诊的业务:
1.awr报表情况:
top 10 foreground events by total wait time
event waits total wait time (sec) wait avg(ms) % db time wait class
db cpu 10.7k 77.9
direct path read 1,206,717 1745.2 1 12.8 user i/o
cell single block physical read 371,283 901.5 2 6.6 user i/o
log file sync 382,715 626.8 2 4.6 commit
–//exadata机器什么会存在这么大direct path read呢?难道不出现cell smart table scan.
–//1745.2*1000/1206717 = 1.44623801603855750768ms
segments by direct physical reads
total direct physical reads: 210,215,077
captured segments account for 100.0% of total
owner tablespace name object name subobject name obj. type direct reads %total
xxxxxx_yyy xxxxxx_yyy emr_bl03 table 201,275,448 95.75
xxxxxx_zzz xxxxxx_zzz ms_cf01 table 7,072,230 3.36
–//201275448*8192/1024/1024/1024/1024 = 1.49961894750595092773,与iostat by function/filetype summary看到的统计一致.
–//查看io统计:
iostat by function/filetype summary
‘data’ columns suffixed with m,g,t,p are in multiples of 1024 other columns suffixed with k,m,g,t,p are in multiples of 1000
ordered by (data read + write) desc for each function
function/file name reads: data reqs per sec data per sec writes: data reqs per sec data per sec waits: count avg tm(ms)
direct reads 1.5t 436.59 434.062 0m 0.00 0m 0
direct reads (data file) 1.5t 436.59 434.062 0m 0.00 0m 0
smart scan 68.5g 20.03 19.37m 0m 0.00 0m 0
smart scan (data file) 68.5g 20.03 19.37m 0m 0.00 0m 0
buffer cache reads 5.3g 125.81 1.491m 0m 0.00 0m 382.1k 2.19
buffer cache reads (data file)5.3g 125.81 1.491m 0m 0.00 0m 382.1k 2.19
–//direct reads到达1.5t.
–//应该与表emr_bl03,查询awr报表,找到如下sql语句:
sql_id=’crzs1c9pnjqg2′
select xxxxxx_yyy.emr_bl03.*, xxxxxx_yyy.emr_bl_bl01.blmc
from xxxxxx_yyy.emr_bl03
left join xxxxxx_yyy.emr_bl_bl01
on xxxxxx_yyy.emr_bl03.blbh = xxxxxx_yyy.emr_bl_bl01.blbh
where xxxxxx_yyy.emr_bl_bl01.brbh = ‘00366441’;
sql ordered by user i/o wait time
resources reported for pl/sql code includes the resources used by all sql statements called by the code.
%total – user i/o time as a percentage of total user i/o wait time
%cpu – cpu time as a percentage of elapsed time
%io – user i/o time as a percentage of elapsed time
captured sql account for 9.4% of total user i/o wait time (s): 2,775
captured pl/sql account for 0.0% of total user i/o wait time (s): 2,775
user i/o time (s) executions uio per exec (s) %total elapsed time (s) %cpu %io sql id sql module sql text
…
49.51 1 49.51 1.78 54.27 9.63 91.22 crzs1c9pnjqg2 select xxxxxx_yyy.emr_bl03.*, …
–//仅仅看到1条.为什么?另外的实例也没有执行类似的语句.我估计没有使用绑定变量,在生成awr报表时漏掉这些类似的sql语句.
–//参考链接:http://blog.itpub.net/267265/viewspace-1749265/
–//实际上开发没有使用绑定变量,为什么不使用绑定变量….xxx.
–//消耗时间49秒.
2.分析:
–//首先看看执行计划:
zzzzz> @ &r/dpcawr crzs1c9pnjqg2 ”
plan_table_output
——————–
sql_id crzs1c9pnjqg2
——————–
select xxxxxx_yyy.emr_bl03.*,xxxxxx_yyy.emr_bl_bl01.blmc from
xxxxxx_yyy.emr_bl03 left join xxxxxx_yyy.emr_bl_bl01 on
xxxxxx_yyy.emr_bl03.blbh=xxxxxx_yyy.emr_bl_bl01.blbh where
xxxxxx_yyy.emr_bl_bl01.brbh = ‘00366441’
plan hash value: 40434530
———————————————————————————————————-
| id | operation | name | e-rows |e-bytes| cost (%cpu)| e-time |
———————————————————————————————————-
| 0 | select statement | | | | 215k(100)| |
| 1 | hash join | | 19 | 27645 | 215k (1)| 00:43:02 |
| 2 | join filter create | :bf0000 | 19 | 817 | 16 (0)| 00:00:01 |
| 3 | table access by index rowid| emr_bl_bl01 | 19 | 817 | 16 (0)| 00:00:01 |
| 4 | index range scan | i_emr_bl_bl01_brbh_cjsj | 19 | | 3 (0)| 00:00:01 |
| 5 | join filter use | :bf0000 | 3968k| 5343m| 215k (1)| 00:43:01 |
| 6 | table access storage full | emr_bl03 | 3968k| 5343m| 215k (1)| 00:43:01 |
———————————————————————————————————-
query block name / object alias (identified by operation id):
————————————————————-
1 – sel$c8875fe2
3 – sel$c8875fe2 / emr_bl_bl01@sel$1
4 – sel$c8875fe2 / emr_bl_bl01@sel$1
6 – sel$c8875fe2 / emr_bl03@sel$2
note
—–
– warning: basic plan statistics not available. these are only collected when:
* hint ‘gather_plan_statistics’ is used for the statement or
* parameter ‘statistics_level’ is set to ‘all’, at session or system level
35 rows selected.
zzzzz> @ &r/desc xxxxxx_yyy.emr_bl03
name null? type
—– ——– —————————-
wdbh not null number(18)
zymz not null number(2)
blbh not null number(18)
wdlx not null number(4)
wdnr blob
zzzzz> select segment_name,bytes/1024/1024/1024 gb from dba_segments where segment_name=’emr_bl03′;
segment_name gb
——————– ———-
emr_bl03 12.2724609
zzzzz> select segment_name,bytes/1024/1024/1024 gb from dba_segments where segment_name in
(select segment_name from dba_lobs where table_name=’emr_bl03′);
segment_name gb
—————————— ———-
sys_lob0000087717c00005$$ 102.436523
–//我以前大概测试过我们现在使用的exadata,select /*+ full(a) */ count(*) from big_table a;io最大吞吐量大约2.5gb/s.
–//(102.436523+12.2724609)/2.5 = 45.88359356,这样非常接近.
–//可以发现这个表存在blob字段,读取数据时访问blob字段时选择直接路径读.而不会出现cell smart table scan等待事件.
–//真不知道awr报表提示直接路径读1.5t如何得来的,估计像我前面提到那样漏掉类似的sql语句.
–//emr_bl03存在索引idx_emr_bl03_blbh.字段包括zymz, blbh, wdlx.不知道为什么没有选择index skip scan.
3.看看direct path read设计那些数据段:
zzzzz> select event,count(*) from dba_hist_active_sess_history where sql_id=’crzs1c9pnjqg2′ group by event;
event count(*)
—————————————- ———-
direct path read 5
–//5次,取样10秒1次,需要50秒.这样与前面的执行时间基本对上.主要等待事件就是direct path read.
zzzzz> @ &r/ev_name.sql ‘direct path read’
event# event_id name parameter1 parameter2 parameter3 wait_class_id wait_class# wait_class
———- ———- —————————————- ——————– ——————– ——————– ————- ———– ——————–
198 3926164927 direct path read file number first dba block cnt 1740759767 8 user i/o
199 861319509 direct path read temp file number first dba block cnt 1740759767 8 user i/o
zzzzz> select event,p1,p2,p3,p1text,p2text,p3text from dba_hist_active_sess_history where sql_id=’crzs1c9pnjqg2′ ;
event p1 p2 p3 p1text p2text p3text
—————- — ——– —- ———– ——— ———
direct path read 56 2562432 128 file number first dba block cnt
direct path read 59 3122176 128 file number first dba block cnt
direct path read 59 3729536 128 file number first dba block cnt
direct path read 60 287744 128 file number first dba block cnt
direct path read 63 43392 128 file number first dba block cnt
–//看看对应那些段.
zzzzz> column partition_name noprint
zzzzz> @ &r/which_obj 56 2562432
owner segment_name segment_type tablespace_name extent_id file_id block_id bytes blocks relative_fno
———- ——————– —————— —————————— ———- ———- ———- ———- ———- ————
xxxxxx_yyy emr_bl03 table xxxxxx_yyy 151 56 2556416 67108864 8192 56
zzzzz> @ &r/which_obj 59 3122176
owner segment_name segment_type tablespace_name extent_id file_id block_id bytes blocks relative_fno
———- ——————– —————— —————————— ———- ———- ———- ———- ———- ————
xxxxxx_yyy emr_bl03 table xxxxxx_yyy 162 59 3121664 67108864 8192 59
–//有点小小吃惊,抓取对应的都是表段,没有lob段.有点奇怪.应该有一些lob段.不理解…..
4.问题解决:
–//加入提示很快执行完成:
select /*+ index_ss(emr_bl03 ) */ xxxxxx_yyy.emr_bl03.*, xxxxxx_yyy.emr_bl_bl01.blmc
from xxxxxx_yyy.emr_bl03
left join xxxxxx_yyy.emr_bl_bl01
on xxxxxx_yyy.emr_bl03.blbh = xxxxxx_yyy.emr_bl_bl01.blbh
where xxxxxx_yyy.emr_bl_bl01.brbh = ‘00366441’;
sql_id 175cc74hfsn7k, child number 0
————————————-
select /*+ index_ss(emr_bl03 ) */ xxxxxx_yyy.emr_bl03.*,
xxxxxx_yyy.emr_bl_bl01.blmc from xxxxxx_yyy.emr_bl03 left join
xxxxxx_yyy.emr_bl_bl01 on xxxxxx_yyy.emr_bl03.blbh =
xxxxxx_yyy.emr_bl_bl01.blbh where xxxxxx_yyy.emr_bl_bl01.brbh =
‘00366441’
plan hash value: 2710181240
——————————————————————————————————–
| id | operation | name | rows | bytes | cost (%cpu)| time |
——————————————————————————————————–
| 0 | select statement | | | | 130 (100)| |
| 1 | nested loops | | 19 | 27645 | 130 (0)| 00:00:02 |
| 2 | table access by index rowid| emr_bl_bl01 | 19 | 817 | 16 (0)| 00:00:01 |
|* 3 | index range scan | i_emr_bl_bl01_brbh_cjsj | 19 | | 3 (0)| 00:00:01 |
| 4 | table access by index rowid| emr_bl03 | 1 | 1412 | 6 (0)| 00:00:01 |
|* 5 | index skip scan | idx_emr_bl03_blbh | 1 | | 5 (0)| 00:00:01 |
——————————————————————————————————–
predicate information (identified by operation id):
—————————————————
3 – access(“emr_bl_bl01”.”brbh”=’00366441′)
5 – access(“emr_bl03″.”blbh”=”emr_bl_bl01″.”blbh”)
filter(“emr_bl03″.”blbh”=”emr_bl_bl01″.”blbh”)
–//感觉很奇怪为什么oracle不选择index skip scan.而且走index skip scan 的cost的成本更低.
–//我发现zymz字段仅仅存在3个值1,2,3.没有直方图信息,会是这个原因吗?感觉不对,还是重新分析看看:
begin
sys.dbms_stats.gather_table_stats (
ownname => ‘xxxxxx_yyy’
,tabname => ’emr_bl03′
,estimate_percent => sys.dbms_stats.auto_sample_size
,method_opt => ‘for all columns size repeat for colunms zymz size 254’
,degree => 4
,cascade => true
,no_invalidate => false);
end;
/
–//依旧不行.先设置索引idx_emr_bl03_blbh属性invisible,建立新索引如下:
create index xxxxxx_yyy.i_emr_bl03_blbh on xxxxxx_yyy.emr_bl03
(blbh)
logging
tablespace xxxxxx_yyy
pctfree 10
initrans 2
maxtrans 255
storage (
initial 64k
next 1m
maxsize unlimited
minextents 1
maxextents unlimited
pctincrease 0
buffer_pool default
flash_cache default
cell_flash_cache default
)
noparallel;
–//测试ok,执行计划不在贴出.
–//感觉index skip scan的行为难以控制.
–//alter index xxxxxx_yyy.i_emr_bl03_blbh invisible;
–//alter index xxxxxx_yyy.xxxxxx_yyy.i_emr_bl03_blbh visible;
select /*+ cardinality(emr_bl_bl01 1) */ xxxxxx_yyy.emr_bl03.*, xxxxxx_yyy.emr_bl_bl01.blmc
from xxxxxx_yyy.emr_bl03
left join xxxxxx_yyy.emr_bl_bl01
on xxxxxx_yyy.emr_bl03.blbh = xxxxxx_yyy.emr_bl_bl01.blbh
where xxxxxx_yyy.emr_bl_bl01.brbh = ‘00366441’;
–//问题依旧不会选择跳跃索引,放弃探究…
总结:
–//实际上我想说的是正是exadata强有力的io处理能力,导致前台用户对于出现的问题根本没有反映.
–//如果是别的系统,整个io消耗殆尽.根本跑不起来….
–//最让我吃惊的是执行需要49秒,前台用户对此却毫无反应,很无语….
–//如果表存在lob类型,exadata不会出现cell smart table scan等待事件,而是走direct path read.关于这点有时间我再验证看看.
–//附上使用的测试脚本:
$ cat which_obj.sql
define __file = &1
define __block = &2
set verify off
select * –owner,segment_name
from dba_extents
where file_id = &__file
and &__block between block_id and block_id + blocks – 1
— and rownum = 1
;
$ cat ev_name.sql
column name format a40
select * from v$event_name where lower(name) like lower(‘%&&1%’);
# cat dpcawr.sql
set verify off
select * from table(dbms_xplan.display_awr(nvl(‘&1′,null),null,null,’all allstats last peeked_binds &2 cost partition -projection -outline’));