一次奇葩问题的解决-技术人生系列第三十二期-我和数据中心的故事

来源:这里教程网 时间:2026-03-03 12:35:22 作者:

前言:

我们曾经在 17 期,发布了 看中国最美女 DBA 的一次价值连城的系统优化 的文章 , 大家表示很 好看 。很多网友对什么时候可以再看到最美女 DBA 的文章表示严重的关注,为此,我们在 32 期再度邀请到中亦科技的小仙女为大家分享她的第二篇技术文章。

客户删除大量历史分区,越删越慢,同时系统出现性能问题,请求协助分析和解决。

如下图所示 , 红色底线表示执行时间 :

删除分区的时间从 1 秒钟变为 2 分钟,再到 5 分钟

如果是你,不妨停下来思考一下,你会怎么来分析这个问题呢?

同时看中亦最美女 DBA 又是如何分析和解决的 (思考过后,下方有福利 照片?嘻嘻

问题来了

电话响了,“我们的系统好像出问题了,快帮我们看看吧。”

来电的客户是某大型央企政府机构,系统遍布全国各省,每天需要处理的 case 不断。

放下电话,远程连上,一切都是那么熟练和自然。

客户提到系统有问题,那就先收个 AWR 报告来看看吧。

看完吓一跳,确实如客户所说,系统出问题了!

对,性能问题。不过看上去好像问题不难。

估计是 DDL 语句引起的,难道这么简单就被判断出来了 ?... 嘻嘻

 

 “ 你们是不是在做什么特殊的操作呀?   先简单了解一下。

我们没做什么特殊的操作呀,我们就是在 做分区表历史分区的清理而已,前面删的好好的,突然系统就这样了 ,肯定跟我的删除没有关系! 客户答到。

这还叫没做什么操作啊

开始分析之旅

首先从 AWR 报告搜索 drop/truncate 关键字,

可以看到大量的 drop partition 操作,验证过了客户所说的删除历史分区操作的动作。

如下图所示,

脑子里立刻闪现出这么一个过程:

    删除一个分区,相当于对表做了 DDL 操作;

    对表做了 DDL 操作之后,与表相关的语句需要重新硬解析,解析过程中需要对相关表持有 S 模式的 library cache lock

    删完一个分区紧接着删下一个分区,又要对表请求 X 模式的 library cache lock

    后续再有语句又需要重新硬解析,这时请求不到 S 模式的 library cache lock 了;

    往复循环,会导致等待越来越严重。因为不断 DDL ,不断有 SQL 需要硬解析, DDL SQL 硬解析分别持有 X S 模式的 library cache lock, 二者不兼容, S 阻塞 X,X 又阻塞了后续需要执行的 SQL 所需要的 S ,于是就出现了大量的 library cache lock 等待;对于日常业务需要执行的 SQL 语句而言,出现 LIBRARY CACHE LOCK 等待则会导致响应时间变慢,也就是客户所说的系统出问题了 ..

    cursor:pin S wait on X 等待则表示多个会话同一时刻执行一个 SQL ,发现需要做硬解析,则由其中一个会话负责硬解析,其他会话等待硬解析的结果,坐享其成就好了,不需要再做硬解析。也就是说,有多个会话再并发的执行同样的 SQL.

大概理清了这个过程之后,解决问题的思路就出来了:

再重复一下关键点:

不断 DDL 删除历史分区,不断有 SQL 需要硬解析; DDL SQL 硬解析分别持有 X S 模式的 librarycache lock, 二者不兼容, S 阻塞 X,X 又阻塞了后续需要执行的一堆 SQL 所需要的 S 这一堆 S 势必会导致再接下来的 DDL 所需要的 X 的被阻塞的更久,于是就出现了大量的 library cache lock 等待。

需要说明的是,硬解析应该是很快的一个动作, 只要不是删完一个分区再立刻删除一个分区 ,业务的影响就可以基本忽略不计了;

谁说女子不如男,被自己的聪明感动到了,嘻嘻

于是我乐颠乐颠地跟客户说道: 你可以在删除分区的过程中加一个 sleep 操作,不要这么连续地删除分区!应该可以解决这个问题!

 

客户试了试,很快给了答复, 删除分区是变快了,但现在是系统出问题了,肯定不是我删分区造成的!你快查查是不是系统有问题了。

谁在无理取闹

显然,系统出现的这些问题和之前清理历史分区操作有关。

和客户耐心解释后,客户还是有疑问:

Q:“如果真的跟删除分区有关,为什么我前面那些表删除分区的时候那么快 ? 的确,很尖锐的一个问题。

A:“可能是前面删除历史分区的时候,业务上没有什么其他 SQL 在执行吧。”

Q:“那为什么删除第一个分区的时候还好好的,到了后面就慢了呢?”

A:“因为删第一个分区的时候,还没有会话在做硬解析嘛。”

为了让客户信服,我从 AWR 报告里摘取下图

可以看到,和平时相比,出现了大量的硬解析 , Invali-dations Reloads

思考片刻后,我再次提出我的建议:

那要不咱们换个时间来删除,找个闲一点的时候,避免业务高峰,速度肯定能加快!

这是一个放之四海都适用的运维原则,没想到,客户似乎有些不耐烦了:

我们这个系统是 24 小时都很忙,没有所谓闲的时候!如果是像你说的问题,那你有没有办法帮我们解决现在删除分区慢的问题,还有很多分区需要删除呢; 可否在业务不停的情况下,我们可不可以让它优先删除分区,再做硬解析?

听到这话,我的内心是奔溃的 ……(此处不用图是不能表达作者的心情的!)

然而,客户是上帝啊,有问题自然需要快速解决,才能显示我们服务的价值。

那么,我们不妨试试看, 可否在业务不停的情况下,我们可不可以让它优先删除分区,再做硬解析呢?

真以为有啊,逗你玩呢 .. 嘻嘻

于是,我跟客户要了一份他们删分区的命令,准备自己执行试试看。

这次错怪了客户

拿着客户的删除命令, 我就开始执行:

第一个分区的删除操作还是挺快的,不到一秒的时间就完事了;

随后第二个分区的删除就慢了,和我预想的一样,是在等待 library cache lock   事件,

估计一小会儿就完,只要我不立刻就继续执行删除分区的操作应该就问题不大,先等着吧。

。。。。。。

然而,等了有好几分钟,这个分区的删除操作才完成,这 什么情况?

读者到这里不妨停下来,思考一下,如果是您,你会怎么继续分析

 

为什么解析要那么久-抓取元凶

看起来,问题还真不一定是想象的那样 :

可以判断删除分区的操作是被解析阻塞了,

但是真的需要阻塞那么久吗?

接下来我通过 gv$session 视图的 blocking_session 字段和 sid 字段的迭代跟进,

终于找到了阻塞的源头,是一个 select 语句 , 脱敏后如下所示:

这个会话阻塞 DDL 语句,显然这个语句正在做解析操作;正常解析应该是非常快的动作,然而这个解析却一直在做,而且从 gv$session.event 不断刷等待事件上看一直在等待不同的 IO ,那它到底在做什么呢?

我这个时候想起了平日里师父们培训时讲的递归 SQL 这回事,在解析的时候,它实际上在底层调用的是递归 SQL ,那现在就需要将它抓出来!

于是,我抓了一个 process dump ,相关的递归 SQL 现出了原型:

没错,当前实际上执行的 SQL 130dvvr5s8bgn

再通过抓取这个 SQL 10046 可以看到其等待情况类似如下:

大多数等待事件均为数据文件顺序读;

看起来就是这个 SQL 的执行时间太长,导致的解析时间过长!

具体的 SQL 文本如下:

select obj#,dataobj#, part#, hiboundlen, hiboundval, ts#, file#, block#, pctfree$,pctused$, initrans, maxtrans, flags, analyzetime, samplesize, rowcnt, blkcnt,empcnt, avgspc, chncnt, avgrln, length(bhiboundval), bhiboundval from tabpart$ where bo# = :1order by part#;

诡异的递归SQL

那么这个 SQL 为什么执行的这么慢呢?立刻来做个 SQLRPT 看看:

SQLRPT 可以看到, SQL 语句似乎没有那么复杂,但是 SQL 语句平均单次执行时间需要超过 60 秒,其中物理读的个数为 7664 个,而 IO 等待事件达到了 126 秒!由于执行计划走索引范围扫描,等待事件是单块读,相当于每个 IO 需要 16ms ,这个 IO 性能本身不太好啊!

这个系统性能本身就差,再系统上做这种影响生产的动作,那不就更慢了吗?

问题到这里就算结束了么?

正准备跟客户汇报这一重大发现,

但是一想到这个过程还是难以解释清楚客户的疑问,我隐约觉得我还是应该再做点什么;

这里,看起来语句的执行计划不错,但是真的要那么多物理读吗?

而且每次都需要做那么多物理读吗?数据怎么就不缓存到 SGA 里呢?

于是,我就在刚刚的 10046 trace 文件中找到这里 bo# 对应的绑定变量值,自己手动执行:

哇,这速度简直快的不要不要的!

怎么到了硬解析那里就要做那么多物理读然后就变的慢了呢?

IO 你慢就慢吧,怎么我的递归 SQL 还要经常做那么多物理读呢?

越往下查,就有太多的问题需要解释了 … 

细节,细节!又一毁三观的情况出现

先后继续删了好几个分区,还都是这样的情况!

SQL 的硬解析真是慢到不可接受。但是我继续看 SQL 解析过程的等待时发现其发生 IO 等待时所等待的对象(v$session.row_wait_obj#)正是我删除的那个分区表!

如此下来,更是诡异了,语句在做硬解析执行 130dvvr5s8bgn 访问的是 TABPART$ 及其表上的索引, 怎么会去访问根本就不在执行计划中的对象呢?

逼我出大招

气死本姑娘了!今天怎么回事,这么多奇葩请出现呢。告诉自己,不能乱,不能乱。再静下心来仔细研究了一刻钟后,我使出了大招:

altersystem set events '14534 trace name context forever, level 1';

接下来,我再次开始删除分区;这个时候,奇迹出现了:

删除操作异常顺利,平均每个分区 1 秒左右就删除完了;

这时,终于可以理直气壮地向客户好好解释此中的问题,接下来的工作就继续甩给客户了;

 

真相大白

看到这里,很多读者蒙圈了。

怎么你就出了这么个大招了呢?姑娘,中间到底经历了什么..

公司平日里各位师父们的培训,不断强调过,如果你觉得不合理的地方,想破脑袋也想不明白的,那么就有可能是不合理的地方,可能就是oracle的缺陷。所以,期间我只是登录MOS网站,以 TABPART$ 作为搜索的关键字,简单一搜索,搜到如下 bug

bug文档中提到,出现这种情况是因为表没有收集统计信息,导致解析时需要扫描extent map(非动态采样);而使用14534事件来跳过extent map,避免load library cache data的时间过长,避免解析时间过长;

要匹配这个 bug ,我还需要核对:

1. 删除的分区表上是否有统计信息?

2. 数据库的版本是不是一致的?

首先,查看表的信息发现这个分区表从未收集过统计信息,符合!

然而,   bug 提到的数据库版本是 10g ,而我们这里的数据库版本是 11.2.0.3, 为什么会出现这个情况呢?

这里,小亦姑娘教大家一招(不用谢哈)...

不妨看看上面 BUG 的描述,细节,注意细节。

“Thisfix is disable by default” 。一切尽在不言中了吧

相关推荐

热文推荐