某银行的某系统rac数据库版本19.6,二节点的mmon slave进程一直在报ORA-01000,导致awr、ash等等很多MMON的功能收到了影响。
1 2 3 4 5 6 7 8 9 10 11 |
2021-11-05T14:38:50.244256+08:00 Errors in file /u01/app/oracle/diag/rdbms/rcg02/rcg022/trace/rcg022_m002_65032.trc: ORA-00604: error occurred at recursive SQL level 1 ORA-01000: maximum open cursors exceeded ORA-00604: error occurred at recursive SQL level 1 ORA-01000: maximum open cursors exceeded 2021-11-05T14:53:51.739041+08:00 Errors in file /u01/app/oracle/diag/rdbms/rcg02/rcg022/trace/rcg022_m000_64999.trc: ORA-00604: error occurred at recursive SQL level 1 ORA-01000: maximum open cursors exceeded ORA-00604: error occurred at recursive SQL level 1 |
查询v$open_cursor,发现每个m00n的session都open了很多同一个递归sql,cursor type为OPEN-RECURSIVE:
1 |
select ts# from ts$ where bitmapped <> 0 and contents$ <> 1 and online$=1 and ts# >= :1 order by ts# asc |
并且发现rac的所有节点,就只有2节点的异常
1 2 3 4 5 6 7 8 9 10 11 12 |
SQL> select a.inst_id,program,ADDRESS,CHILD_ADDRESS,a.sql_id,count(*) from gv$open_cursor a,gv$session b 2 where a.inst_id=b.inst_id and a.sid=b.sid and b.program like '%M00%' 3 group by a.inst_id,program,ADDRESS,CHILD_ADDRESS,a.sql_id having count(*)>10; INST_ID PROGRAM ADDRESS CHILD_ADDRESS SQL_ID COUNT(*) ---------- ------------------------------------------------ ---------------- ---------------- --------------- ---------- 2 oracle@mgmrcgarac02 (M004) 000000063F2A95B0 000000063F2A8188 38hpmnhjywkz4 995 2 oracle@mgmrcgarac02 (M005) 000000063F2A95B0 000000063F2A8188 38hpmnhjywkz4 995 2 oracle@mgmrcgarac02 (M002) 000000063F2A95B0 000000063F2A8188 38hpmnhjywkz4 995 2 oracle@mgmrcgarac02 (M000) 000000063F2A95B0 000000063F2A8188 38hpmnhjywkz4 994 2 oracle@mgmrcgarac02 (M003) 000000063F2A95B0 000000063F2A8188 38hpmnhjywkz4 998 2 oracle@mgmrcgarac02 (M001) 000000063F2A95B0 000000063F2A8188 38hpmnhjywkz4 995 |
这非常不正常,通常每个session不会一直open同一个递归cursor,怀疑是这些递归sql在运行结束都没有关闭游标。为了更好的分析问题,对M000进程做了一个processstate dump
1 2 3 4 5 6 |
SQL> oradebug setospid 64999; Oracle pid: 74, Unix process pid: 64999, image: oracle@mgmrcgarac02 (M000) SQL> oradebug dump processstate 266; Statement processed. SQL> oradebug tracefile_name /u01/app/oracle/diag/rdbms/rcg02/rcg022/trace/rcg022_m000_64999.trc |
从dump中发现确实同时打开了多个该cursor,单对某个LIBRARY CACHE LOCK进行分析,发现session以NULL模式持有该sql父游标handle的library cache lock,说明已经打开了游标。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 |
SO: 0x61a4b63a8, type: LIBRARY OBJECT LOCK (118), map: 0x448394090 state: LIVE (0x4532), flags: 0x1 owner: 0x86ffdc2f8, proc: 0x86fef8078 link: 0x61a4b63c8[0x61e0f7ae8, 0x61e0ef1e8] child list count: 0, link: 0x61a4b6418[0x61a4b6418, 0x61a4b6418] conid: 1, conuid: 1, SGA version=(1,0), pg: 0 SOC: 0x448394090, type: LIBRARY OBJECT LOCK (118), map: 0x61a4b63a8 state: LIVE (0x99fc), flags: INIT (0x1) LibraryObjectLock: Address=0x448394090 Handle=0x63f2a95b0 Mode=N CanBeBrokenCount=1 Incarnation=1 ExecutionCount=1 User=0x863b17220 Session=0x863b19a08 ReferenceCount=1 Flags=CNB/[0001] SavepointNum=c21c50 Time=09/02/2021 03:04:59 LibraryHandle: Address=0x63f2a95b0 Hash=23ee4be4 LockMode=N PinMode=0 LoadLockMode=0 Status=VALD ObjectName: Name=select ts# from ts$ where bitmapped <> 0 and contents$ <> 1 and online$=1 and ts# >= :1 order by ts# asc |
游标打开时间09/02/2021 03:04:59,两个月前。。。。,并且对应的子游标handle的状态已经失效了
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
SO: 0x61e0ef1c8, type: LIBRARY OBJECT LOCK (118), map: 0x44b1ca9b0 state: LIVE (0x4532), flags: 0x1 owner: 0x86ffdc2f8, proc: 0x86fef8078 link: 0x61e0ef1e8[0x61a4b63c8, 0x86ffdc368] child list count: 0, link: 0x61e0ef238[0x61e0ef238, 0x61e0ef238] conid: 1, conuid: 1, SGA version=(1,0), pg: 0 SOC: 0x44b1ca9b0, type: LIBRARY OBJECT LOCK (118), map: 0x61e0ef1c8 state: LIVE (0x99fc), flags: INIT (0x1) LibraryObjectLock: Address=0x44b1ca9b0 Handle=0x63f2a8188 Mode=N CanBeBrokenCount=1 Incarnation=1 ExecutionCount=33565358 Context=0x7f44760c4f80 User=0x863b17220 Session=0x863b19a08 ReferenceCount=1 Flags=BRO/CBK/[0020] SavepointNum=0 Time=09/02/2021 03:04:59 LibraryHandle: Address=0x63f2a8188 Hash=0 LockMode=N PinMode=S LoadLockMode=0 Status=INVL |
说明sql早已执行完成,但是游标并未关闭。
解决该问题的方法很简单,就是关闭session,由于m00n进程是mmon的slave进程,可以随便kill,kill之后问题解决。但是并没有找到该问题的原因,MOS上也没有查到相关的案例,个人怀疑是在关闭递归游标的时候出现了异常,导致反复的打开该游标。