黄远邦小y
作者黄远邦小y2017-04-25 13:56
技术总监, 中亦科技

橙色预警:Oracle游标泄露(open_cursor耗尽)

字数 3289阅读 3708评论 0赞 0

作者:老猫

1前言

很早就想把ORA-1000的问题,总结成一个话题。机缘巧合,最近恰好遇上几个此类问题,特分享分析过程出来供大家参考。

首先,ORA-1000报错是什么意思呢?我们来看看官方的解释:
微信图片_20170425133021.jpg

微信图片_20170425133021.jpg

非常简单,单个进程打开的游标数超过了最大值,也就是超过了数据库设置的open_cursos参数的值;面对这样的情况,不同的DBA会有不同的解决方案:调整open_cursors参数?还是直接把问题抛给开发人员?

今天老猫就来给大家分享一个处理ORA-1000的经典案例,看看大家的处理方式和我们的处理方式有什么不一样?在处理过程中老猫又用到了什么不一样的处理技巧?处理完能收获什么样的心得体会?

2来活啦

客户来电求助,系统周期性地报ORA-1000的错误,之前客户已经多次调整open_cursors参数,目前已经调整到了2000了,难道还是接着一直往上调?open_cursors是针对一个单个进程打开cursor数的限制,对于一般应用来说,如果能及时关闭cursor,2000个已经足够使用,那么这里是客户没有正确关闭游标还是其本身就需要同时打开大量游标抑或是其他原因呢,这已经极大地勾起了我的兴趣!找出根因,并提供解决方案,是我们在服务客户过程中的一贯态度。

3捕捉信息

面对ORA-1000这种应用级的错误,我们一般可以通过设置errorstack时收集报错进程的process dump来进行分析;而如果报错没那么容易出现,我们就会选择在之前抛错业务频繁执行的时段做个systemstate dump,主要目的是可以看看这类业务执行时server process中都open了哪些cursor,然后根据现象进行进一步的分析,判断问题的原因;

这里客户系统是周期性的报ORA-1000错误,于是建议客户开errorstack,收集trace文件进行分析。

4开始分析

首先是设置1000的errorstack;
微信图片_20170425134335.jpg

微信图片_20170425134335.jpg

ORA-1000错误发生时,会生成一个trace,通过观察trace发现在,确实打开了2000个cursor,在trace中搜索cursor#可以看到,发现cursor都是打开的同一个SQL:SELECT activityno,ruleno FROM T_RM_COUPONINF;
微信图片_20170425134640.jpg

微信图片_20170425134640.jpg

那么问题来了,为什么对同一个SQL会打开这么多cursor呢?仔细观察一下我们就会发现这个SQL的特别之处,Excutioncount=0&LoadCount=299&InvalidationCount=300,还记得老猫分享的第十二期的故事么,这是典型的解析错误的问题!
微信图片_20170425134930.jpg
微信图片_20170425134930.jpg

不过这里我们就不用设置10035事件去确认了,我们试图来解析SQL:SELECT activityno,ruleno FROM T_RM_COUPONINF;很快我们就发现了问题,T_RM_COUPONINF这个对象根本就不存在!

到这里,看起来我们发现了两个问题:

  1. 进程中打开了一条错误SQL的cursor;
  2. 在遇到编译错误后,进程没有及时关闭cursor,似乎对这段代码的处理过程没有加catchexecption或者finally的过程;

那么是谁发起了这条SQL,在没有编译成功的情况下,没有关闭cursor呢?模拟这样的代码一点都不难,脑子里闪过无数个草泥马…骂谁还不好说,先冷静,由于这个问题可以在测试环境重现。

5定位来源

通常来说,数据库中运行的SQL可以分为两种,普通SQL和递归SQL;由于这里,sql本身存在错误,所以我们无法直接定位SQL到底是来自外部(普通SQL)还是数据库(递归SQL);这时,我们就可以使用10046事件来帮忙了;
微信图片_20170425135146.jpg

微信图片_20170425135146.jpg

可以看到10046的trace中有如上一条解析错误的记录,err=942即抛错ORA-942,意味着表或视图不存在;同时还有另一关键的点:dep=0,即SQL的递归深度为0,也就是非递归SQL!所以,只能找开发来确认了,开发给出明确的答复却让人沮丧:这条SQL不是应用发出来的!

不是应用写的,也不是数据库自己产生的,那么这SQL来自于哪里呢?我再仔细捋了捋思路,发现我们在日常处理问题的过程中,经常忽略的一个环节,那就是JDBC包;一般认为,JDBC主要是为了维护应用与数据库的连接的,但实际上,JDBC在这个过程中也是有可能执行一些SQL的,甚至可以通过一些配置重新封装应用程序发到数据库服务器的SQL语句,在这个过程中,出现一些问题也是可能的。

至此,我们暂时将问题定位到JDBC上;查看JDBC版本,是12.1.0.2数据库自带的。OK,范围缩小到JDBC。下一步debug JDBC。

6不一样的trace

前面初步怀疑到了JDBC上,接下来需要做的就是通过在应用代码中打开JDBC的trace即可,增加的代码如下:
微信图片_20170425135231.jpg

微信图片_20170425135231.jpg

观察结果JDBC trace文件:
微信图片_20170425135317.jpg
微信图片_20170425135317.jpg

没错,我们看到了那条SQL的身影,看来错误SQL确实是来自于JDBC;

7原因确认

原来,应用持久化框架里为了取得SQL的绑定变量信息,调用Oracle JDBC的PreparedStatement.getParameterMetaData()函数, 在这个方法里,JDBC取得parameter metadata的方法是:生成一条SQL:SELECT activityno, ruleno FROM T_RM_COUPONINFO,通过编译这条SQL,取得activityno, ruleno两个列的metadata信息,然后返回给客户应用。

不幸的是:在生成这条SQL时,出现了错误----丢掉了一个字母O,导致ORA-942的错误。错就错了吧,你至少要关掉cursor呀。JDBC的开发疏忽了。
正确sql:
SELECT activityno, ruleno FROM T_RM_COUPONINFO
目前解析成的sql:
SELECT activityno, ruleno FROM T_RM_COUPONINF

这是JDBC递归SQL引发的一个问题,其实是JDBC12.1.0.2的一个BUG。

8解决问题

将收集的errorstack和JDBC trace提交到oracle support;GCS还是蛮给力的,不长时间就提供了一个patch。

9老猫小提示

大家可能会疑惑,为什么老猫开的SR反馈这么快,我开的SR却迟迟没有进展呢?
其实,老猫作为从原厂出来的老司机,就这个CASE而言,你要了解下面两点:

  1. JDBC在Oracle内部是个很跨界的产品,它的support其实是负责中间件的工程师,而不是Oracle Database工程师。当你开一个ORA-1000的问题给Database工程师时,你实在不能指望他会java;当你开给中间件工程师,又不能指望他对Database有多深的了解,势必扯皮。老猫在原厂时,遇上这类问题,通常是在五楼阳台抽烟时,互相沟通一小会儿的。大家工作压力都很大,还没到自己手里的问题,没人真的上心。
  2. 能重现的问题,尽量作一个test case给Oracle support,把能提供的信息提供好。在这个案例中,我们把现象,问题发生的函数,trace证据全都提供给support,减少了交互,减少了扯皮。所以,问题解决得很快。

总而言之,对于每个自己的SR,我们尽量提供自己所了解的所有信息,SR的进展就会更顺利。

10问题总结

这个问题,我们看到,作为一个好的DBA,绝对不能只是改改参数,或者是将看起来与数据库无关的问题一手推给开发人员;我们可以做的是,把问题定位到最小范围内,至于确确实实涉及到数据库内层不公开的部分,只要提供足够的信息,我们相信SR也能帮助我们定位到数据库底层的问题。

如果觉得我的文章对您有用,请点赞。您的支持将鼓励我继续创作!

0

添加新评论0 条评论

Ctrl+Enter 发表

作者其他文章

相关文章

相关问题

相关资料

X社区推广