避坑:一次离奇性能故障的排查与反思
错乱的系统
某客户反馈生产库ETL及报表类SQL全部运行不出来,监控告警近期大量SQL语句执行计划发生变更。客户DBA通过对比新旧执行计划发现执行计划变更的SQL大部分都变成了走索引加上NL的方式,而且不止一个SQL出现这种问题,该生产库上几乎所有的AP类型SQL都出现了该问题。问题到我们这边前,客户已经花了数周时间做了好几轮排查,均没有效果。
历史的诊断
全库统计信息排查
DBA排查过历史的统计信息,并重新收集了对应schema的统计信息,重新收集相关表、索引的直方图统计信息,部分SQL增加了多列统计信息。每次操作完成后的验证均无效果,之后回退了以上无效操作。
绑定部分SQL执行计划
部分业务过于紧急,约10条SQL临时使用SQLPROFILE绑定了执行计划,针对绑定的SQL有效,然而执行计划发生变更SQL语句数量过多,针对每个SQL分析执行计划并绑定,这完全不现实。
参数排查
排查了系统参数optimizer_index_*相关参数,均为默认值,优化器模式为默认ALL_ROWS,db_file_multiblock_read_count参数设置128,参数无异常变更,后检查包括触发器层面、进程级别,均为无异常参数调整。
故障重现
由于客户生产上的案例文章中不方便使用真实数据,模拟了以下数据:
create user test identified by test;grant dba to test;conn test/testcreate table t1 as select * from dba_objects;create index test.idx1 on test.t1(OBJECT_ID);execute dbms_stats.gather_table_stats(ownname => 'TEST',tabname => 'T1' ,cascade => true,method_opt => 'for all columns size auto');update test.t1 set OBJECT_ID=1 where rownum <40000; commit;
查询数据如下,T1表上有8.7W数据:
SQL>
select count(*) from test.t1 SQL> ;
COUNT(*)
87629
简单模拟的SQL如下,查询OBJECT_ID=1的数据,数据量有4W,差不多一半的数据量,正常情况肯定走全表了,实际情况却走索引。
SQL> set autot tracealter system flush shared_pool;select * from test.t1 t where OBJECT_ID=1;SQL>System altered.SQL>39999 rows selected.Execution Plan----------------------------------------------------------Plan hash value: 1483979983------------------------------------------------------------------------------------| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time|------------------------------------------------------------------------------------| 0 | SELECT STATEMENT | | 38294 | 3627K| 747 (2)| 00:00:01 || 1 | TABLE ACCESS BY INDEX ROWID| T1 | 38294 | 3627K| 747 (2)| 00:00:01 ||* 2 | INDEX RANGE SCAN | IDX1 | 38294 | | 112 (4)| 00:00:01 |------------------------------------------------------------------------------------Predicate Information (identified by operation id):---------------------------------------------------2 - access("OBJECT_ID"=1)Statistics----------------------------------------------------------133 recursive calls0 db block gets6227 consistent gets0 physical reads0 redo size4468586 bytes sent via SQL*Net to client29845 bytes received via SQL*Net from client2668 SQL*Net roundtrips to/from client27 sorts (memory)0 sorts (disk)39999 rows processed
逐层分析
真实情况中,客户发来了监视报告,10053trace文件,SQLT报告。因为监视报告这里用处不大,没做模拟。
10053trace信息
参数方面确认没什么问题跳过,快速定位到单表访问路径那部分,如下所示,单表路径选择的时候对比了访问索引(cost :746.93),以及访问全表的方式(cost :10050.77),(注:这里人为造出来的数据cost值差异较大,真实场景中相差不是特别大)那么问题在于为什么会有这么大的差异,Card: 38294.13,即预估返回结果集38294,对比实际值39999,可以发现统计信息这块儿,基本准确。
SINGLE TABLE ACCESS PATHSingle Table Cardinality Estimation for T1[T]Column (#4):NewDensity:0.000012, OldDensity:0.000012 BktCnt:254, PopBktCnt:111, PopValCnt:1, NDV:47788Column (#4): OBJECT_ID(AvgLen: 5 NDV: 47788 Nulls: 1 Density: 0.000012 Min: 1 Max: 190751Histogram: HtBal #Bkts: 254 UncompBkts: 254 EndPtVals: 144Table: T1 Alias: TCard: Original: 87629.000000 Rounded: 38294 Computed: 38294.13 Non Adjusted: 38294.13Access Path: TableScanCost: 10050.77 Resp: 10050.77 Degree: 0Cost_io: 10033.00 Cost_cpu: 40345028Resp_io: 10033.00 Resp_cpu: 40345028Access Path: index (AllEqRange)Index: IDX1resc_io: 734.00 resc_cpu: 29353837ix_sel: 0.437008 ix_sel_with_filters: 0.437008Cost: 746.93 Resp: 746.93 Degree: 1Best:: AccessPath: IndexRangeIndex: IDX1Cost: 746.93 Degree: 1 Resp: 746.93 Card: 38294.13 Bytes: 0
线索到这里时,同事考虑到全表扫描COST值基本来源于IO,冒出一个大胆的想法:是否可能数据块儿碎片严重化,极端情况下比如所有不需要的数据分布为每条数据均存于不同的块儿中,而需要的数据则集中于几个需要的块儿。这个脑洞大开的想法马上被他自己的查询证伪了。
SQL> select BLOCKS from dba_segments where segment_name='T1' and owner='TEST';BLOCKS----------1281
SQLT中发现关键信息
基于以往故障经验的猜想都不成立,而现象看上去是Oracle CBO计算执行计划时出了问题,有DBA已经开始认为是Oracle BUG了(当然没找到对应的BUG编号)。在看客户DBA发来的SQLT的报告时,终于在报告中找到了问题的突破口。
上图可以发现客户的系统是收集过系统统计信息的(报告为测试环境抓取的),再看单块读、多块读,MBRC(注测试环境模拟时,单块读、多块读数值差别较大,真实环境差别为十多倍,MBRC为3)均有统计信息,这点很是异常,毕竟看过的绝大部分系统都是没收集过系统统计信息的。
当然其实10053 trace文件中也有系统统计信息,只是这块儿相对关注较少。
问题分析
详细分析前,先回顾下COST算法,参考support oracle文档:How To Calculate CPU Cost(文档 ID 457228.1)。
Cost = (#SRds * sreadtim +#MRds * mreadtim +#CPUCycles / cpuspeed) / sreadtim#SRDs - number of single block reads#MRDs - number of multi block reads#CPUCycles - number of CPU Cyclessreadtim - single block read timemreadtim - multi block read timecpuspeed - CPU cycles per second
公式总结起来可以归结为cost本质为单块读,获取数据途径为磁盘或内存,内存中的逻辑读取消耗CPU时间除以单块读后,折算成以单位读为单位,磁盘中获取分为单块读(大部分索引访问)或多块读(全表或部分索引访问),多块读时间折算成单块读时间时,需要考虑每次读取块数(优先参考参数_db_file_optimizer_read_count,该隐含参数未设置情况下取db_file_multiblock_read_count,默认配置为8)。
可以验算一下,全表扫描时COST值10033粗略计算方式:1281/128*1000。
而sreadtim,mreadtim在没收集过系统统计信息时是通过公式计算得来的。
SREADTIM = IOSEEKTIM + db_block_size / IOTFRSPEEDMREADTIM = IOSEEKTIM + db_block_size * MBRC / IOTFRSPEED
IOSEEKTIM默认10ms,IOTFRSPEED默认4096字节/ms,推算可得默认值:SREADTIM 12ms, MREADTIM 26ms
回顾过COST相关的知识后,再来看当前的系统信息SREADTIM 1ms, MREADTIM 1000ms MBRC 128,即:通过单块读的方式读取128个块也只需要128ms,远远小于直接多块读128个块的成本(1000ms),CBO当然会选错。
故障处理
故障处理起来很简单,运行以下语句,清除掉收集的系统统计信息就可以了。
exec dbms_stats.delete_system_stats;
清除完统计信息后,再清除下shared pool中的执行计划,再次解析时,系统正常运行,至此困扰许久的问题终于解决。
追根溯源
为什么收集系统统计信息会产生错误的单块读、多块读值?
这个主要是由于部分物理IO命中存储/操作系统文件缓存引起,如果收集时间短,或是系统空闲可能导致信息非常不准确。
为什么会收集系统统计信息?
默认收集全库统计信息并不会收集系统统计信息,只能运行DBMS_STATS.gather_system_stats手工触发,最终客户DBA通过堡垒机排查发现运维人员存在违规操作,问题源头得以查清。
是否应该收集系统统计信息?
这是一个非常有争议的话题,甚至官方文档的建议随着不同的Oracle版本也在变化。无论参考Oracle的官方文档,还是对比实际值( 实际awr报告中db file sequential read db file scattered read等待事件,大部分值都小于5ms的真实情景),或是参考Exadata以及各种国产一体机出色IO性能的大背景,单块读12ms,多块读26ms这个系统默认值都似乎过时了,应该调整。
事实上影响Oracle优化器的因素非常多,搜集统计信息会引入一个额外的因素,导致系统性能波动。系统性能和扩展性问题更多是因为糟糕的schema设计和schema统计信息没有维护好导致的。在现实情况中,我们没有遇到过通过搜集系统统计信息解决SQL性能问题,倒是遇到过多个案例因为搜集系统统计信息,替换了默认的系统统计信息,从而导致执行计划变差的案例。建议生产中不更新系统统计信息,使用默认的系统统计信息。
性能故障时的排查思路:
决定SQL性能的主要因素为以下四条,SQL性能问题时的排查可做参考:
统计信息;
schema访问路径;
SQL写法;
Oracle版本补丁情况。
能否直接调整系统信息?
附上测试脚本,开始测试时,直接调整SREADTIM、MREADTIM、MBRC值,并不能达到效果,必须有个收集的过程,哪怕如脚本所示实际没采集到数据(注:flush shared pool为危险操作,测试脚本内容不要在生产库使用)。
为什么收集系统统计信息不生效?
收集系统统计信息分为NOWORKLOAD及WORKLOAD两种模式,脚本中gather_system_stats('start')方式为workload模式,该模式下大表读取如果使用直接路径读方式,则无法采集到MBRC值。因为MBRC值必须读进buffer cache中,才会被统计(alter session set “_serial_direct_read”=never; 关闭后测试可获取)。SREADTIM、MREADTIM、MBRC值三个缺少任意一个,收集的系统统计信息均不会生效。
SQL> exec dbms_stats.delete_system_stats;EXEC DBMS_STATS.gather_system_stats('start');EXEC DBMS_STATS.gather_system_stats('stop');EXEC DBMS_STATS.set_system_stats('SREADTIM', 1);EXEC DBMS_STATS.set_system_stats('MREADTIM', 1000);--exec dbms_stats.set_system_stats('MBRC',128);SELECT pname, pval1 FROM sys.aux_stats$ WHERE sname = 'SYSSTATS_MAIN';set autot tracealter system flush shared_pool;select * from test.t1 t where OBJECT_ID=1;PL/SQL procedure successfully completed.SQL>PL/SQL procedure successfully completed.SQL>PL/SQL procedure successfully completed.SQL>PL/SQL procedure successfully completed.SQL>PL/SQL procedure successfully completed.SQL> SQL>PNAME PVAL1------------------------------ ----------CPUSPEED 2270CPUSPEEDNW 2270IOSEEKTIM 10IOTFRSPEED 4096MAXTHRMBRCMREADTIM 1000SLAVETHRSREADTIM 19 rows selected.SQL> SQL>System altered.SQL>39999 rows selected.Execution Plan----------------------------------------------------------Plan hash value: 3617692013--------------------------------------------------------------------------| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |--------------------------------------------------------------------------| 0 | SELECT STATEMENT | | 38294 | 3627K| 350 (1)| 00:00:05 ||* 1 | TABLE ACCESS FULL| T1 | 38294 | 3627K| 350 (1)| 00:00:05 |--------------------------------------------------------------------------Predicate Information (identified by operation id):---------------------------------------------------1 - filter("OBJECT_ID"=1)Statistics----------------------------------------------------------42 recursive calls0 db block gets3903 consistent gets1253 physical reads0 redo size1852399 bytes sent via SQL*Net to client29845 bytes received via SQL*Net from client2668 SQL*Net roundtrips to/from client6 sorts (memory)0 sorts (disk)39999 rows processed
附执行操作脚本:
exec dbms_stats.delete_system_stats;EXEC DBMS_STATS.gather_system_stats('start');EXEC DBMS_STATS.gather_system_stats('stop');EXEC DBMS_STATS.set_system_stats('SREADTIM', 1);EXEC DBMS_STATS.set_system_stats('MREADTIM', 1000);exec dbms_stats.set_system_stats('MBRC',128);SELECT pname, pval1 FROM sys.aux_stats$ WHERE sname = 'SYSSTATS_MAIN';set autot trace alter system flush shared_pool;select * from test.t1 t where OBJECT_ID=1;select /*+ full(t ) */ * from test.t1 t where OBJECT_ID=1;select /*+ index(t idx1) */ * from test.t1 t where OBJECT_ID=1;select count(*) from test.t1 t where OBJECT_ID=1;alter system flush shared_pool;oradebug setmypid oradebug unlimitoradebug event 10053 trace name context forever,level 1select * from test.t1 t where OBJECT_ID=1;oradebug event 10053 trace name context offoradebug tracefile_name
参考文档
http://www.oracle.com/technetwork/database/bi-datawarehousing/twp-bp-for-stats-gather-12c-1967354.pdf
https://blogs.oracle.com/optimizer/should-you-gather-system-statistics
原文发布时间为:2018-07-03
本文作者:蒋健
本文来自云栖社区合作伙伴“ DBAplus社群”,了解相关信息可以关注“ DBAplus社群”。
避坑:一次离奇性能故障的排查与反思相关推荐
- 17条避坑指南:一份来自谷歌的数据库经验贴
点击上方蓝色"程序猿DD",选择"设为星标" 回复"资源"获取独家整理的学习资料! 来源 | https://medium.com/@rak ...
- MongoDB 应用场景、避坑事项与最佳实践
MongoDB 是一个高性能,开源,无模式的文档型数据库,是当前 NoSQL 数据库产品中最热门的一种.它在许多场景下可用于替代传统的关系型数据库或键/值存储方式,MongoDB 使用 C++开发. ...
- 完美避坑!记一次Elasticsearch集群迁移架构实战
作者介绍 李猛(ynuosoft),Elastic-stack产品深度用户,ES认证工程师,2012年接触Elasticsearch,对Elastic-Stack开发.架构.运维等方面有深入体验,实践 ...
- 工业级光纤收发器使用“避坑”指南
工业级光纤收发器在使用中有很多的注意事项,往往这些注意事项经常被忽略.下面飞畅科技就整理了一些工业级光纤收发器使用"避坑"指南,大家可以仔细看看,引起重视. 使用工业级光纤收发器连 ...
- 项目从0到1避坑指南
背景: 物流行业,老板信息化意识弱,不是现有的TMS而是一个新的方向,目前市场上竞品较少 前言: 一个项目从0到1,有相关的固定的考虑事项.然而,由于公司环境.项目涉及的行业等一些实际条件的约束,会在 ...
- 0基础自学Python,有哪些避坑经验?
回顾自己近 2 年的Python 自学经历,有一些学习心得和避坑经验分享给大家,让大家在学习 Python 的过程中少走一些弯路!减少遇到不必要的学习困难! 首先,最开始最大的困难应该就是对编程的抵触 ...
- dubbo日志关闭_不可忽视的Dubbo线程池避坑指南
推荐阅读: 阿里巴巴4面Java岗位:算法+性能调优+并发+多线程+数据库 Dubbo+Kafka+MyBatis+reids+Spring+多线程等,学完就去面试BAT 问题描述 线上突然出现Dub ...
- @程序员,区块链开发平台避坑指南!
来源 | Michiel Mulders 译者 | 火火酱 责编 | Carol 出品 | 区块链大本营(blockchain_camp) 市面上有很多不同的区块链网络,就可扩展性和功能而言,每个区块 ...
- h5 nan_易企秀资深前端架构师袁飞:移动H5开发如何避坑
2020年10月24日,正值程序员节,第二届全球移动开发技术峰会在北京隆重举行.易企秀资深前端架构师袁飞应邀出席峰会,并分享了移动H5开发技术要点和避坑指南. 本次峰会,来自微软.阿里巴巴.小米.腾讯 ...
最新文章
- numpy 中的 squeeze() 函数
- keras构建卷积神经网络(CNN(Convolutional Neural Networks))进行图像分类模型构建和学习
- get 和post 方式请求数据
- 第12周学习进度总结
- MiniGUI细节处理(转)
- 迪米特法则(Law of Demeter) 简介
- 这些实验好习惯科研小白一定要先养成!
- 电脑打字手指正确姿势_正确的投篮姿势教学,许多人都忽略的细节,学会变投篮神射手...
- P3335-[ZJOI2013]蚂蚁寻路【dp】
- 发送结构化数据Client端
- 从零开始学Pytorch(五)之欠拟合和过拟合
- stm32串口接收不定长数据_基于STM32之UART串口通信协议--接收
- php 织梦模板 防盗,织梦DedeCMS模板怎么防盗
- 【Spring第七篇】Java配置类:JavaConfig
- 中国计算机管理软件学院,中国管理软件学院官方网站
- Html和css算是编程语言吗,不被承认的编程语言
- html制作问卷调查,如何通过jQuery制作一个在线问卷调查
- 网站技术分析报告之——开心网_转载
- 【Unity3D】AudioSource组件
- 关于行人检测中的常用数据集