这是我见过最奇怪的数据库问题了
这是坚持走路上下班的第三周,终于还是坚持了下来。我发现走路,居然可以缓解菊花的疼痛,医药费都省了,真是绝了。希望自己能继续坚持下去!
早上到公司刚开完会,一个多年老客户就电话过来了。用户说其一个重要的库有点问题,其核心数据库环境最近备份出现了异常,发现每次备份到某个数据文件都卡住了。奇怪的是,数据库运行正常,无任何报错。业务运行也是正常的。客户使用了大名鼎鼎的NBU备份软件(本质上也是调用Oracle RMAN),据说找了备份厂商看了,也没问题;客户自己的数据库维保厂商看了很久也是没头绪。
由于客户的这套核心ERP环境运行在我司zData 分布式存储一体机环境上,从用户的截图来看,该环境自从2020年上线至今没有出过任何问题了,rac集群没有异常,计算节点,存储节点都没有出现过重启现象,感觉还是非常的稳啊。。。这里我不得不给大家科普一下zData分布式存储一体机的基本架构,本质上是一种存算分离架构。如下是我们从2014年开始做的zdata分布式存储的架构:
以前zData的架构只能支持Oracle,分布式存储管理软件本身负责磁盘映射管理工作,当然除了支持IB交换机之外,其实也支持RoCE 交换机。随着近几年国产化的发展,我们在2023年对zData进行了升级换代,重新自研了一套分布式存储管理软件zStorage。依托于zStorage形成了新的zData X 全栈国产化一体机的解决方案;操作系统支持国产麒麟、银河麒麟等;数据库支持MySQL、达梦、KingBase等。
新的zData X一体机已经在超过30家客户生产环境中运行,其中有很多创新的技术,这里我就不展开了,基于分布式协议支持三副本,两副本 保证数据库的绝对高可用,同时还能支持底层快照。
同时当有存储节点异常时,底层重构速度也是非常迅速的(类似Oracle 以前ASM reblanace)。
好了,这里我不是来给大家打广告的;更多信息大家可以到https://enmotech.com/products/zDataX了解或者找我们市场部 marketing@enmotech.com 获取详细的技术白皮书。
回到我们的案例上来,既然客户使用了我们的产品,备份软件和数据库都检查了,那么一体机肯定也需要检查,确认是否正常。虽然客户这套zdata一体机已经过保了,本着为用户负责的角度,我们工程师也给客户做了诊断,认为一体机是正常的,无任何告警。
那么问题来了,问题就是在哪里呢?难道这是一个悬案?
等客户发来了toDesk,我远程登录看了几分钟。首先给大家分享一下我的诊断思路。
首先既然备份卡住,那我需要重新这个现象,很久没有用NBU了,不太熟了,既然NBU是调用rman,那么我们直接rman就好了,操作时发现确实卡住了,等了2分钟没反应。
之前由于已经让客户做过了dbv等检查,确认文件是正常的,因此这里我就直接校验该文件即可,既然这个会话2分钟没反应,那么我们是不是应该到数据库中看看该会话在数据库中的表现?在等待什么,或者有没有被阻塞?
查询gv$session我发现,我们的rman进程正在等待enq: TC - contention,同时该进程正在被节点2的 2401会话所阻塞(这里要说明一点,final_blocking_session/final_blocking_instance是oracle 11203之后引入的新字段,对于分析锁问题,可以直接用来定位阻塞源头)。
到这里,我们自然应该去看看这个等待事件的含义是什么?其次这个blocking session是什么进程,同时它在干什么。
首先我们来说说这个等待事件,tc 应该是指的tablespace checkpoint。那么这个等待事件势必是跟表空间检查点有关,也就是说rman的备份或者validate 操作会触发表空间级别的检查点。当然到这里,其实我们还可以思考一下oracle中的哪些操作也会触发tbs checkpoint,比如direct path read。
所以到这里,我们猜测2401 会话应该就是checkpoint进程了,查一下gv$session视图便知。
果然不出我们所料,2401这个session是节点2的ckpt进程,而该进程的event是rdbms ipc message,这是一个空闲等待。
这里我们要验证该节点ckpt进程是否正常,我尝试手工执行了alter system checkpoint操作,发现5秒左右就返回了,说明该节点是"正常"的,这也难怪业务没有受到任何影响。
会话被进程阻塞,而该进程等待事件又是空闲等待,这说明了什么呢?说明该进程可能已经hung或者说stuck了。本来想strace 该进程的,结果发现我们的这套zdata老环境,居然没有安装strace命令。好吧。
我们就利用Oracle oradebug hanganalyze来看看该进程的状态吧。
此时分析这个diag trace就是关键了。揭开谜底就靠这个文件了。
-------------------------------------------------------------------------------
Chain 1:
-------------------------------------------------------------------------------
Oracle session identified by:
{
instance: 1 (prod.prod1)
os id: 58008
process id: 480, oracle@erp01 (TNS V1-V3)
session id: 2
session serial #: 42926
}
is waiting for 'enq: TC - contention' with wait info:
{
p1: 'name|mode'=0x54430006
p2: 'checkpoint ID'=0x101e0
p3: '0'=0x0
time in wait: 25330 min 46 sec
timeout after: never
wait id: 7019456
blocking: 0 sessions
current sql:
short stack: ksedsts()+244