Oracle 19c alert log 大量 WARNING too many parse errors 告警分析过程
1 问题现象
虽然 19c 已经出来了很多年,但主要还是玩 11g 多一些,而且 19 年以后主要精力也是在研究国产数据库上。
下午业务说新部署的一个业务连不上12c 的RAC 集群,就看了下日志,发现里面有很多的WARNING: too many parse errors,如下:
[dave@www.cndba.cn ~]# orz log 20
BEGIN P_SMON_ISDBNORMAL(); END;
Additional information: hd=0x2deb5d8c8 phd=0x2deb5ecf0 flg=0x20 cisid=107 sid=107 ciuid=107 uid=107
2024-01-16T22:45:02.170323+08:00
WARNING: too many parse errors, count=604700 SQL hash=0x756778a4
PARSE ERROR: ospid=18060, error=6550 for statement:
2024-01-16T22:45:02.170584+08:00
BEGIN P_SMON_ISDBNORMAL(); END;
Additional information: hd=0x2deb5d8c8 phd=0x2deb5ecf0 flg=0x20 cisid=107 sid=107 ciuid=107 uid=107
2024-01-16T22:50:02.347459+08:00
WARNING: too many parse errors, count=604800 SQL hash=0x756778a4
PARSE ERROR: ospid=18060, error=6550 for statement:
2024-01-16T22:50:02.347717+08:00
BEGIN P_SMON_ISDBNORMAL(); END;
Additional information: hd=0x2deb5d8c8 phd=0x2deb5ecf0 flg=0x20 cisid=107 sid=107 ciuid=107 uid=107
2024-01-16T22:55:02.517434+08:00
WARNING: too many parse errors, count=604900 SQL hash=0x756778a4
PARSE ERROR: ospid=18060, error=6550 for statement:
2024-01-16T22:55:02.517694+08:00
BEGIN P_SMON_ISDBNORMAL(); END;
Additional information: hd=0x2deb5d8c8 phd=0x2deb5ecf0 flg=0x20 cisid=107 sid=107 ciuid=107 uid=107
[dave@www.cndba.cn ~]#
2 问题说明
这里其实有 2 个问题。
2.1 告警提示问题
在Oracle 12.2版本之前, SQL 的解析错误默认不记录到alert log中,但可以通过event 10035实现类似功能,如下:
SQL> ALTER SYSTEM SET EVENTS '10035 trace name context forever, level 1';
SQL> SELECT * FROM CNDBA;
SQL> ALTER SYSTEM SET EVENTS '10035 trace name context off';
Oracle从12.2开始, 默认就启用了解析错误记录,当sql解析失败超过一定次数,会在alert日志中记录类似警告信息,也就是我们之前 log 日志看到的问题。
这里的解析次数由隐含参数_kks_parse_error_warning控制,默认每100次解析失败写入alert日志一次。
SQL> col PARAMNAME for a50
SQL> col SESSIONVALUE for a15
SQL> col INSTANCEVALUE for a15
SQL> set lines 190
SQL> select paramName,SessionValue,InstanceValue from hparams where paramname='_kks_parse_error_warning';
PARAMNAME SESSIONVALUE INSTANCEVALUE
-------------------------------------------------- --------------- ---------------
_kks_parse_error_warning 100 100
SQL>
所以我们可以看到日志中count=604800 到 count=604900,按 100 递增。
我们可以通过修改该隐含参数,控制 log 的显示,比如 200 记录一次:
SQL> alter system set "_kks_parse_error_warning"=200 scope=both;
或者直接该值为0,不记录在alert日志中。
SQL> alter system set "_kks_parse_error_warning"=0 scope=both;
隐含参数的查看,参考我之前的博客,如下:
Oracle 19c 查看隐含参数视图
以上综述,就是在 12.2 之后的版本,alert log 里出现解析错误是正常的现象,不正常的是为啥解析失败。
2.2 触发解析失败的原因
首先,目前已知有多种原因可能会触发这种错误,比如:
JDBC driver when using JDBC “ResultSet.TYPE_SCROLL_SENSITIVE.
WARNING: Too Many Parse Errors And error=937 In Database Alert Log (Doc ID 2590218.1)
从日志看,但我们这里明显不是这种情况:
WARNING: too many parse errors, count=604900 SQL hash=0x756778a4
PARSE ERROR: ospid=18060, error=6550 for statement:
2024-01-16T22:55:02.517694+08:00
BEGIN P_SMON_ISDBNORMAL(); END;
Additional information: hd=0x2deb5d8c8 phd=0x2deb5ecf0 flg=0x20 cisid=107 sid=107
这个对象:P_SMON_ISDBNORMAL() 非常像系统对象,但是并没有看到这个对象:
SQL> select owner,object_name,object_type,status from dba_objects where object_name like '%P_SMON_ISDBNORMAL%';
no rows selected
SQL> select owner,object_name,object_type,status from dba_objects where object_name like '%ISDBNORMAL%';
no rows selected
查看了一下进程,又是一个非本地的进程:
[dave@www.cndba.cn trace]$ ps -ef|grep 18060
oracle 8617 4882 0 23:18 pts/2 00:00:00 grep 18060
oracle 18060 1 0 2023 ? 00:09:01 oracledave1 (LOCAL=NO)
[dave@www.cndba.cn trace]$
然后查了一下会话,果然是业务的SQL,但是对象的名字取的太有误导性了,一度以为是系统对象,触发了 12c 的 bug 导致的问题,在 MOS 上搜了半天,并没有搜到P_SMON_ISDBNORMAL()这个对象。
SQL> select b.spid,a.sid,a.username,a.program,a.machine,a.sql_id from v$session a,v$process b where a.paddr=b.addr and b.spid=18060;
SPID SID USERNAME PROGRAM MACHINE SQL_ID
------------------------ ---------- ---------- ------------------------- --------------- -------------
18060 1834 ICD JDBC Thin Client emp-cti2
然后扫了一下日志,应该是系统上线之后就一直存在这个问题,我接手这个系统时间也不长,系统一直很稳定,也没有怎么关注,一步小心还挖到雷了。
[dave@www.cndba.cn trace]$ grep -5 P_SMON_ISDBNORMAL alert_dave1.log |more
Clearing Resource Manager plan via parameter
2018-04-08T05:17:04.108900+08:00
WARNING: too many parse errors, count=100 SQL hash=0x756778a4
PARSE ERROR: ospid=30573, error=6550 for statement:
2018-04-08T05:17:04.109148+08:00
BEGIN P_SMON_ISDBNORMAL(); END;
Additional information: hd=0x11d1dac90 phd=0x11d1daec0 flg=0x20 cisid=107 sid=107 ciuid=107 uid=107
2018-04-08T05:22:04.297726+08:00
WARNING: too many parse errors, count=200 SQL hash=0x756778a4
PARSE ERROR: ospid=30573, error=6550 for statement:
2018-04-08T05:22:04.297987+08:00
BEGIN P_SMON_ISDBNORMAL(); END;
Additional information: hd=0x11d1dac90 phd=0x11d1daec0 flg=0x20 cisid=107 sid=107 ciuid=107 uid=107
2018-04-08T05:27:04.480892+08:00
WARNING: too many parse errors, count=300 SQL hash=0x756778a4
PARSE ERROR: ospid=30573, error=6550 for statement:
2018-04-08T05:27:04.481136+08:00
BEGIN P_SMON_ISDBNORMAL(); END;
Additional information: hd=0x11d1dac90 phd=0x11d1daec0 flg=0x20 cisid=107 sid=107 ciuid=107 uid=107
2018-04-08T05:32:04.665790+08:00
WARNING: too many parse errors, count=400 SQL hash=0x756778a4
PARSE ERROR: ospid=30573, error=6550 for statement:
2018-04-08T05:32:04.666031+08:00
BEGIN P_SMON_ISDBNORMAL(); END;
版权声明:本文为博主原创文章,未经博主允许不得转载。