原 Oracle解析错误的跟踪办法
简介
存储过程解析错误或某频繁SQL语句解析错误，主要发生在SQL AREA BUILD上，若频繁解析错误则会导致严重的library cache lock问题，整个数据库可能会处于hang死的状态。
问：对于一个比较复杂的存储过程来说，如何快速定位到是什么语句什么原因导致的失败解析呢？
答案：在解析SQL的过程中，若碰到SQL语法错误、访问的对象不存在或没有权限，则会导致目标SQL语句解析失败，所以，解析失败的SQL语句是不会生成执行计划的。可以通过如下几种方式找到解析失败的SQL：
① 通过关联X$KGLCURSOR和X$KGLCURSOR_CHILD_SQLID视图
② 通过使用10035事件
③ 通过Oracle systemdump
Oracle提供了一系列的跟踪事件来帮助定位各种问题，通过10035事件可以诊断解析失败的情况，如下：
1 2 | [oracle@rhel6lhr ~]$ oerr ora 10035 10035, 00000, "Write parse failures to alert log file" |
首先通过“alter system set events '10035 trace name context forever,level 5';”开启监控，然后使用tail观察告警日志，找到问题SQL之后，使用命令“alter system set events '10035 trace name context off';”关闭10035事件。
在12.2之前可以通过配置ALTER SYSTEM SET EVENTS '10035 trace name context forever, level 1';进行跟踪解析失败的SQL，从12.2开始对同一条SQL语句默认解析错误超过100（隐含参数_kks_parse_error_warning控制）的话就会在告警日志中显示，然后我们在告警日志中搜索"PARSE ERROR"、“parse errors” 就可以看到相关的SQL解析失败的语句，最后进行错误的SQL处理即可。
1 2 | [oracle@lhrora19c trace]$ grep -c "PARSE ERROR" alert_ORCLCDB.log 640 |
可以设置隐含参数_kks_parse_error_warning=0来消减警告，但不建议这样做。因为解析失败对数据库的性能是有害的，它可以引起各种 mutex/latch/library cache lock 的争用。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 | SYS@ORCLCDB> SET PAGESIZE 9999 SYS@ORCLCDB> SET LINE 9999 COL NAME FORMAT A40 SYS@ORCLCDB> COL KSPPDESC FORMAT A50 SYS@ORCLCDB> COL KSPPSTVL FORMAT A20 SYS@ORCLCDB> SELECT A.INDX, 2 A.KSPPINM NAME, 3 A.KSPPDESC, B.KSPPSTVL 5 FROM X$KSPPI A, 6 X$KSPPCV B 7 WHERE A.INDX = B.INDX 8 AND A.KSPPINM LIKE '/_%' ESCAPE '/' 9 AND LOWER(A.KSPPINM) LIKE LOWER('%_kks_parse_error_warning%'); INDX NAME KSPPDESC KSPPSTVL ---------- ---------------------------------------- -------------------------------------------------- -------------------- 3416 _kks_parse_error_warning Parse error warning 100 SYS@ORCLCDB> |
模拟该错误
环境：19c
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 | begin FOR i IN 1..300 LOOP -- alter system flush shared_pool; DECLARE N1 NUMBER := TRUNC(DBMS_RANDOM.VALUE(1, i)) ; -- N1 VARCHAR2(11) := TRUNC(DBMS_RANDOM.VALUE(1, i)) ; V1 VARCHAR2(32767) := lpad('1', i, '1'); --V1 NUMBER := lpad('1', i, '1'); --V1 NVARCHAR2(4000) := lpad('1', i, '1'); --V1 char(4000) := lpad('1', i, '1'); V2 DATE := sysdate+ DBMS_RANDOM.VALUE(-i, i) ; -- V2 TIMESTAMP := sysdate+ DBMS_RANDOM.VALUE(-i, i) ; begin EXECUTE IMMEDIATE 'INSERT INTO T_BG_20280414_LHR_88(N,V,V2) VALUES(:N1,:V1,:V2)' USING N1, V1 ,V2; exception when others then null; END; END LOOP; COMMIT; end; |
查看告警日志：
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 | 2024-04-19T17:40:12.274703+08:00 ORCLPDB1(3):WARNING: too many parse errors, count=100 SQL hash=0xc1cd5b33 ORCLPDB1(3):PARSE ERROR: ospid=747616, error=942 for statement: 2024-04-19T17:40:12.275195+08:00 ORCLPDB1(3):INSERT INTO T_BG_20280414_LHR_88(N,V,V2) VALUES(:N1,:V1,:V2) ORCLPDB1(3):Additional information: hd=0x61ca9f68 phd=0x6139b8c0 flg=0x101476 cisid=0 sid=0 ciuid=0 uid=0 sqlid=f531rdm0wuqtm ORCLPDB1(3):...Current username=SYS ORCLPDB1(3):...Application: PL/SQL Developer Action: SELECT a.INST_ID, a.WAIT_C ... 2024-04-19T17:40:12.275622+08:00 ORCLPDB1(3):----- PL/SQL Call Stack ----- object line object handle number name 0x65364870 21 anonymous block ORCLPDB1(3):WARNING: too many parse errors, count=200 SQL hash=0xc1cd5b33 ORCLPDB1(3):PARSE ERROR: ospid=747616, error=942 for statement: 2024-04-19T17:40:12.285636+08:00 ORCLPDB1(3):INSERT INTO T_BG_20280414_LHR_88(N,V,V2) VALUES(:N1,:V1,:V2) ORCLPDB1(3):Additional information: hd=0x61ca9f68 phd=0x6139b8c0 flg=0x101476 cisid=0 sid=0 ciuid=0 uid=0 sqlid=f531rdm0wuqtm ORCLPDB1(3):...Current username=SYS ORCLPDB1(3):...Application: PL/SQL Developer Action: SELECT a.INST_ID, a.WAIT_C ... 2024-04-19T17:40:12.286110+08:00 ORCLPDB1(3):----- PL/SQL Call Stack ----- object line object handle number name 0x65364870 21 anonymous block ORCLPDB1(3):WARNING: too many parse errors, count=300 SQL hash=0xc1cd5b33 ORCLPDB1(3):PARSE ERROR: ospid=747616, error=942 for statement: 2024-04-19T17:40:12.298047+08:00 ORCLPDB1(3):INSERT INTO T_BG_20280414_LHR_88(N,V,V2) VALUES(:N1,:V1,:V2) ORCLPDB1(3):Additional information: hd=0x61ca9f68 phd=0x6139b8c0 flg=0x101476 cisid=0 sid=0 ciuid=0 uid=0 sqlid=f531rdm0wuqtm ORCLPDB1(3):...Current username=SYS ORCLPDB1(3):...Application: PL/SQL Developer Action: SELECT a.INST_ID, a.WAIT_C ... 2024-04-19T17:40:12.298384+08:00 ORCLPDB1(3):----- PL/SQL Call Stack ----- object line object handle number name 0x65364870 21 anonymous block |
可以看到，每增加100解析错误，告警日志都会输出1次错误，且给出了错误的SQL语句：INSERT INTO T_BG_20280414_LHR_88(N,V,V2) VALUES(:N1,:V1,:V2) ，sqlid=f531rdm0wuqtm也给出了，而且显示是匿名块（ anonymous block）, error=942表示ora-942，表示表或视图不存在。
1 2 3 4 5 | [oracle@lhrora19c trace]$ oerr ora 942 00942, 00000, "table or view does not exist" // *Cause: // *Action: |
在 12.2 Alert.log 中"WARNING: too many parse errors" (Doc ID 2364845.1)
'WARNING: too many parse errors' in the 12.2 and above Alert.log (Doc ID 2320935.1)
症状
alert.log 中经常会生成以下消息：
WARNING: too many parse errors, count=29200 SQL hash=0x2473a808
PARSE ERROR: ospid=7013, error=942 for statement:
2017-05-30T08:19:13.196642-06:00
select col1, col2 from testtab where col1=1;“error = 942”表示 SQL 无法成功解析的根本原因。在这种情况下，error=942 意味着 ora-942：表或视图不存在。
原因
类似的问题正在下面的 Bug 中调查：
BUG 26184177 - "WARNING: TOO MANY PARSE ERRORS" IN THE ALERT.LOG <===closed as duplicate to following bug:
Bug 16945190 DIAGENH: DUMPING PARSE FAILURES AUTOMATICALLY W/O EVENT 10035
