另辟蹊径：从其他角度去解决数据库问题

数据和云 2020-12-28

1320

墨墨导读：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

于是采取了第一步的措施：

强制统计信息收集在节点1上运行
强行flush 节点2的buffer cache
altersystem flush buffer cache;

客户甚至还找停机时间，重启了节点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虽然还有少量出现，但时间都极短，并没有对业务产生影响，问题最终得以解决。

以上是罗老师本次嘉年华分享的案例的主要内容。

推荐阅读：144页！分享珍藏已久的数据库技术年刊

推荐下载：2020数据技术嘉年华PPT下载

2020数据技术嘉年华近50个PPT下载、视频回放已上传墨天轮平台，可在“数据和云”公众号回复关键词“DTC2020”获得！

视频号，新的分享时代，关注我们，看看有什么新发现？