核心系统中的ORA-1000案例

上周五,公司一套重中之重的生产系统应用大量抛出ORA-1000报错,某航司核心应用逻辑调用出现严重异常。登录数据库查看,果然有些许会话open_cursor已达到上限。

20191105-1

数据库中,open_cursor参数设置为了1000,代表着单个数据库进程允许打开的游标数目,上图显示,有许多会话open_cursor已达到999。

20191105-2

为了方便后续的根因定位,没有立即破坏故障现场,随即做了1000的errorstack与数据库的system dump确认一下进程游标open情况与会话此时在干些什么?

(1) alter system set events '1000 trace name errorstack level 3';
(2) oradebug dump systmstate 266;

保留好故障现场后,随即kill了涉及游标耗尽的会话,故障现象恢复。

(1)经过分析 1000 errorstack文件,发现上述进程确实open了将近1000个游标,并没有存在大量游标解析错误,与数据库递归SQL导致该问题发生的情况;并且应用调用已经上线多日,近期没有进行过修改。

(2)分析systemstate dump文件,抽检其中几个会话发现,进程状态正在处于SQL *NET massage from client 空闲等待中,会话并没有在处理正常干活当中。

20191105-3

再次与应用人员沟通得到了关键的信息:该应用程序逻辑为调用数据库一张表中的某几行信息(关键IP信息)进行处理,应用人员下午1点左右误操将数据表中的IP改为本机IP,导致无法调用正确IP信息,导致数据库程序无法结束,那么就解释了数据库进程为何一直处于SQL *NET massage from client 空闲等待中,数据库存储过程一直等待获取数据库某数据表中正确的IP信息进行后续调用。

但是为何会产生游标耗尽的问题呢?随后应用人员发来程序代码,真相大白,在上千行的代码中,我搜寻了close关键字,遗憾的是应用代码中并没有显示的close游标,应用程序循环启动,不断的open大量的cursor,但是一直调用不到正确的数据,导致进程游标耗尽。

该程序一直正常运行,ip信息一直获取数据正常(没有人篡改),程序正常结束,游标自然释放掉了。

20191105-4

正确的方式应为在end后添加close hostcontext_out;显示关闭游标,通过本案例我们看到系统正常不代表没有任何“坑”,在上线测试代码中,尽量想到充分的异常场景,有备无患。