墨墨导读:2020数据技术嘉年华于11月21日落下帷幕,大会历时两天,来自全国各地的数据领域学术精英、领袖人物、技术专家、从业者和技术爱好者相聚北京,见证了个人的快速成长、技术的迭代进步、行业的蓬勃发展、生态的融合共赢,以及市场的风云变迁。
2020数据技术嘉年华近50个PPT下载、视频回放已上传墨天轮平台,可在“数据和云”公众号回复关键词“DTC2020”获得!
本文根据 罗海雄 老师在 2020数据技术嘉年华 分享的主题《另辟蹊径 -- 从其他角度去解决数据库问题》整理而成。
罗老师是一名 Oracle ACE-A,还是ITPUB论坛数据库管理版版主,2012 ITPUB全国SQL大赛冠军得主;资深的架构师和性能优化专家,对 SQL 优化和理解尤其深入;作为业内知名的技术传播者之一,经常出席各类技术分享活动;从开发到性能管理,有着超过10年的企业级系统设计和优化经验;曾服务于甲骨文公司,组织和主讲过多次《甲骨文技术开发人员日》和《Oracle圆桌会议》,在任职甲骨文公司之前,还曾经服务于大型制造企业中芯国际,具备丰富的制造行业系统架构经验。
接下来,我们跟随罗老师的文字,一同回顾属于他的嘉年华瞬间。
作为开场白,罗老师说:
我小孩经常问我,你做的什么工作? 我回答,数据库服务? 小孩又问,什么是数据库服务? 我说,数据库服务就是数据库的医生啊,数据库生了病,爸爸帮它治。
上面这个图,是一张数据库的DB Time的图,下面这一张,是一张心电图。
作为一个医生,如果看到心电图突然异常波动,肯定会特紧张;同样,一个DBA, 看到自己管理的数据的DB Time异常跳高,估计也会很紧张的。
从医院这,联想到一个“笑话”:
一个医院,在重症监护室,死亡率从某个时候起突然高起来,而经过医生的分析,每天早上8点的死亡率,比其他时间段高很多…
下面的故障,和这个“笑话”有异曲同工之妙:
客户系统某天告警,15:10-15:25 系统卡顿
语句都是最简单的insert相关 :
insert into xxx values(…,…)
从等待事件看,最严重的是gc current multi block request.
GC等待,本质上就是节点间的交互
gc主要的等待有三类
current请求就是访问数据块本身, 发生于DML
cr请求就是根据不同情况访问数据块本身或者前镜像(undo),主要发生于查询。
对于GC等待,主要有3种方法:
而这个客户的情况是这样的:
检查x$bh/v$bh, 发现部分块在节点2也存在,怀疑是统计信息收集导致部分块在节点2的buffer cache里也存在
select count(*),owner
from x$bh h ,dba_objects o
where o.data_object_id = h.obj
于是采取了第一步的措施:
客户甚至还找停机时间,重启了节点2。
结果第二第三天,问题还是持续发生,而且,时间点都还在差不多的15:00附近。
这时候,想起了重症监护室的“笑话”。
一个医院,在重症监护室,死亡率从某个时候起突然高起来,而经过医生的分析,每天早上8点的死亡率,比其他时间段高很多… 原来,每天8点清洁阿姨拔掉呼吸机的电源,开始打扫卫生
于是,开始去找时间规律背后的原因。
先从lms进程开始入手,检查故障期间的Lms进程日志,发现如下日志:
2020-09-26 15:31:30.766 === Twoconsecutive receive calls took in 5945 ms ==
2020-09-26 15:31:30.767 === Twoconsecutive receive calls took in 7274 ms ==
2020-09-26 15:31:30.807 === Twoconsecutive receive calls took in 8494 ms ==
2020-09-26 15:31:30.835 === Twoconsecutive receive calls took in 6355 ms ==
分析日志中出现这一类报错的时间规律
awk '/Two consecutive receivecalls took/{
t=substr($2,1,5);wait=$(NF-2)/1000;
if( wait>=3;cnt3[t]++);
if( wait>=2;cnt2[t]++);
if( wait>=1;cnt1[t]++);}
END{for (i in cnt1)
print i,cnt1[i],cnt2[i],cnt3[i]}'*lms*.trc
把结果做成图表:
发现时间规律非常明显,基本都是每6个小时出现一次日志高峰。
那么,数据库里有哪个清洁阿姨每六个小时打扫一次卫生?
在各种信息中,找到crs日志,发现crs日志产生时间也有这个规律,每6个小时产生大量日志文件。
分析15:00-16:00期间的进程信息
发现了可疑对象,一个java .. OraJavaAgentDriver进程,每6个小时调用一批crs的命令,并产生了相关的日志文件。
调用关系如下:
那么,这个java … OraJavaAgentDriver的进程是干什么的?又是哪个功能调用的呢?
搜索Oracle官网,发现OraJavaAgentDriver对应的是Oracle的cvu组件,全称是ClusterVerification Utility, 是Oracle CRS健康检查的一个工具,在CRS作为资源存在,名字是ora.cvu。
那cvu会是那个打扫卫生的阿姨吗?首先,来确认一下它的工作时间:
crsctl stat res ora.cvu -p
看到了check_interval属性,21600正好就是6*3600, 也就说,这个进程的确是每6个小时调用一次。
由于Oracle CVU主要是初始安装时用来检查系统状况是否符合安装标准,如果后续整个集群没有硬件和操作系统变更,理论上来说,不会有变化,因此,该组件可以禁用。
禁用方法如下:
crsctl stop ora.cvucrsctl disable ora.cvu
关闭cvu后,对系统继续观察,首先,crs日志不会再出现那么多日志,lms日志里的Two consecutive receive calls信息也基本不再出现,系统中的gc current multi block request虽然还有少量出现,但时间都极短,并没有对业务产生影响,问题最终得以解决。
以上是罗老师本次嘉年华分享的案例的主要内容。