Oracle 12.2 DB alert show “WARNING: too many parse errors” or “__Oracle_JDBC_internal_ROWID__” in sql
朋友一套12.2的RAC一节点CRASH, 发我一份alert log让帮着看看,crash的原因以后有时间再写,但是alert log中出现了大量的”WARNING: too many parse errors”,是以前的版本中从未见过,这也是12.2的新特性,自动生成解析失败的信息写入db alert log, 即使没有在数据库启用event 10035, 以前版本可以通过启用10035 event分析解决失败信息写入alert log.
db alert log
2017-11-21T04:22:55.526449+08:00 XXHCPDB(12):WARNING: too many parse errors, count=2996 SQL hash=0x117d3781 XXHCPDB(12):PARSE ERROR: ospid=56905, error=1446 for statement: 2017-11-21T04:22:55.526595+08:00 XXHCPDB(12):select rowid as "__Oracle_JDBC_internal_ROWID__", inv_objs from (select count(*) as inv_objs from dba_objects where status='INVALID') XXHCPDB(12):Additional information: hd=0x43f493be0 phd=0x4368401a0 flg=0x20 cisid=0 sid=0 ciuid=0 uid=0 XXHCPDB(12):WARNING: too many parse errors, count=2996 SQL hash=0x92a117b7 XXHCPDB(12):PARSE ERROR: ospid=56905, error=918 for statement: 2017-11-21T04:22:55.563449+08:00 XXHCPDB(12):select rowid as "__Oracle_JDBC_internal_ROWID__", ses,ac_ses,waits,ofn_files,fai_jobs,inv_objs,lck_objs from (select count(*) as ses from v$session),(select count(*) as ac_ses from v$session where status='ACTIVE'),(select count(*) as waits from v$session_wait),(select count(*) as ofn_files from v$datafile where status = 'OFFLINE'),(select count(*) as fai_jobs from dba_jobs where failures > 0),(select count(*) as lck_objs from v$locked_object),(select count(*) as inv_objs from dba_objects where status='INVALID') XXHCPDB(12):Additional information: hd=0x479b14608 phd=0xfc3e4728 flg=0x20 cisid=0 sid=0 ciuid=0 uid=0
Note:
从以上信息中可以看到的信息:
1, WARNING: too many parse errors
2, SQL HASH
3, SQL TEXT
4, SQL ERROR CODE
5, __Oracle_JDBC_internal_ROWID__
[oracle@anbob ~]$ oerr ora 1446 01446, 00000, "cannot select ROWID from, or sample, a view with DISTINCT, GROUP BY, etc." // *Cause: // *Action: [oracle@anbob ~]$ oerr ora 918 00918, 00000, "column ambiguously defined" // *Cause:
SQL解析失败是一种常见现象,但是同一SQL频繁的解析失败会给数据库带来性能问题, 从AWR中的时间模型中同样可以发现parse, failed parse 占用较高的DB TIME, 以上DB Alert log中的输出是一种诊断信息的增强,可以默认把经常解决失败的信息写入db alert, 多数都是应用程序问题,解决方法自然是调整应用或SQL.
WARNING: too many parse errors 并不是每次解析都提示,默认是在同一SQL在60分钟内每出现100次就会提示一次worning到DB ALERT LOG. 对于这个阀值应该是有隐藏参数”_kks_parse_error_warning” 控制的。
SQL> @pd parse_error
Show all parameters and session values from x$ksppi/x$ksppcv...
NUM N_HEX NAME VALUE DESCRIPTION
---------- ----- ---------------------------- ------------- -------------------------
3080 C08 _kks_cached_parse_errors 0 KKS cached parse errors
3082 C0A _kks_parse_error_warning 100 Parse error warning
对于SQL文本是可以手动执行还原问题,ERROR 就是解析的错误ORACE的提示编号,这里的1446 是提示rowid 不能用于count这类汇总操作中。
对于SQL文本中的ROWID 和“__Oracle_JDBC_internal_ROWID__”应该不是程序员人为加入,ALERT中提示中出现了大量__Oracle_JDBC_internal_ROWID__字样,判断应该是ORACLE JDBC驱动自动附加的。
当JDBC 中scroll sensitive resultset 启用时,JDBC驱动就会在用户SQL中自动增加ROWID ,但是并不是所有的查询都适合附加rowid, 该功能是JDBC中对于结果集是否在数据改变后自动刷新,有TYPE_SCROLL_SENSITIVE和TYPE_SCROLL_INSENSITIVE两种,区别可以看这里。
–JAVA CODE Demo
try { Class.forName(driverName).newInstance(); connection = DriverManager.getConnection(url+dbName, userName, password); Statement stmt = connection.createStatement( ResultSet.TYPE_SCROLL_SENSITIVE, ResultSet.CONCUR_READ_ONLY); ... if (res.getType() == ResultSet.TYPE_SCROLL_SENSITIVE) { System.out.println("ResultSet TYPE_SCROLL_SENSITIVE."); } ''' }
解决该类问题需要程序员了解TYPE_SCROLL_SENSITIVE的限制,修改SQL解析失败处代码ResultSet型的类
AWK 提取 db alert中的 parse error信息
定期的提取一下parse error 如语法错误的或权限错误的SQL, 有必要提供给前端修正。从多到少的修复。
-- DB ALERT LOG
WARNING: too many parse errors, count=650096763 SQL hash=0xa101d379
PARSE ERROR: ospid=2526, error=911 for statement:
2021-01-19T13:10:00.717433+08:00
SELECT 1 FROM TAB_ANBOB_COM WHERE REGION= 313 AND STATUS= :STATUS AND CREATEDATE <= SYSDATE - :DATACYCLE/24 AND ROWNUM < 2
Additional information: hd=c0000001cd576b28 phd=c0000001cd576f50 flg=0x28 cisid=52 sid=52 ciuid=52 uid=52
2021-01-19T13:10:01.827376+08:00
WARNING: too many parse errors, count=650096863 SQL hash=0xa101d379
PARSE ERROR: ospid=2496, error=911 for statement:
2021-01-19T13:10:01.828177+08:00
SELECT 1 FROM TAB_ANBOB_COM WHERE REGION= 313 AND STATUS= :STATUS AND CREATEDATE <= SYSDATE - :DATACYCLE/24 AND ROWNUM < 2
Additional information: hd=c0000001cd576b28 phd=c0000001cd576f50 flg=0x28 cisid=52 sid=52 ciuid=52 uid=52
2021-01-19T13:10:03.047922+08:00
WARNING: too many parse errors, count=650096963 SQL hash=0xa101d379
PARSE ERROR: ospid=2514, error=911 for statement:
2021-01-19T13:10:03.049293+08:00
SELEC
WARNING: too many parse errors, count=650096763 SQL hash=0xa101d379
PARSE ERROR: ospid=2526, error=911 for statement:
2021-01-19T13:10:00.717433+08:00
SELECT 1 FROM TAB_ANBOB_COM WHERE REGION= 313 AND STATUS= :STATUS AND CREATEDATE <= SYSDATE - :DATACYCLE/24 AND ROWNUM < 2
Additional information: hd=c0000001cd576b28 phd=c0000001cd576f50 flg=0x28 cisid=52 sid=52 ciuid=52 uid=52
2021-01-19T13:10:01.827376+08:00
WARNING: too many parse errors, count=650096863 SQL hash=0xa101d379
PARSE ERROR: ospid=2496, error=911 for statement:
2021-01-19T13:10:01.828177+08:00
SELECT 1 FROM TAB_ANBOB_COM WHERE REGION= 313 AND STATUS= :STATUS AND CREATEDATE <= SYSDATE - :DATACYCLE/24 AND ROWNUM < 2
Additional information: hd=c0000001cd576b28 phd=c0000001cd576f50 flg=0x28 cisid=52 sid=52 ciuid=52 uid=52
2021-01-19T13:10:03.047922+08:00
WARNING: too many parse errors, count=650096963 SQL hash=0xa101d379
PARSE ERROR: ospid=2514, error=911 for statement:
2021-01-19T13:10:03.049293+08:00
SELEC
-- 记算不同sql hash出次的次数
# cat alert\ parse\ error.sql |awk '/parse error/ { H=$8 ;next;}; /PARSE ERROR/ { E= $4 ;print H " " E}' |sort |uniq -c|sort -n
1 hash=0xa101d300 error=904
1 hash=0xa101d379 error=905
1 hash=0xa101d379 error=912
3 hash=0xa101d379 error=911
-- 报错明细时间
# cat alert\ parse\ error.sql|awk '/parse error/ { H=$8 ; next;};/PARSE ERROR/{R=NR;E= $4 }NR==R+1{ D=$0; print "****" H " " E " " D};'
****hash=0xa101d379 error=911 2021-01-19T13:10:00.717433+08:00
****hash=0xa101d379 error=911 2021-01-19T13:10:01.828177+08:00
****hash=0xa101d300 error=904 2021-01-19T13:10:03.049293+08:00
****hash=0xa101d379 error=911 2021-01-19T13:10:00.717433+08:00
****hash=0xa101d379 error=905 2021-01-19T13:10:01.828177+08:00
****hash=0xa101d379 error=912 2021-01-19T13:10:03.049293+08:00
-- 报错明细SQL
# cat alert\ parse\ error.sql|awk '/parse error/ { H=$8 ; next;};/PARSE ERROR/{R=NR;E= $4 }NR==R+2{ D=$0; print "****" H " " E " " D};'
****hash=0xa101d379 error=911 SELECT 1 FROM GROUP_MEMBER_CONFRIM WHERE REGION= 313 AND STATUS= :STATUS AND CREATEDATE <= SYSDATE - :DATACYCLE/24 AND ROWNUM < 2
****hash=0xa101d379 error=911 SELECT 1 FROM GROUP_MEMBER_CONFRIM WHERE REGION= 313 AND STATUS= :STATUS AND CREATEDATE <= SYSDATE - :DATACYCLE/24 AND ROWNUM < 2
****hash=0xa101d300 error=904 SELECt 1
****hash=0xa101d379 error=911 SELECT 1 FROM GROUP_MEMBER_CONFRIM WHERE REGION= 313 AND STATUS= :STATUS AND CREATEDATE <= SYSDATE - :DATACYCLE/24 AND ROWNUM < 2
****hash=0xa101d379 error=905 SELECT 1 FROM GROUP_MEMBER_CONFRIM WHERE REGION= 313 AND STATUS= :STATUS AND CREATEDATE <= SYSDATE - :DATACYCLE/24 AND ROWNUM < 2
****hash=0xa101d379 error=912 SELECt 1
Known Issue
— update 2024/9/25 —
在oracle 19.19 RU中存在一个bug 导致db alert log中的parse error 并不输出SQL TEXT文本
alert_v1919.log
2023-10-17T21:28:26.828730+00:00
OS Pid: 4070331 executed alter system set events ‘10035 trace name context forever, level 1’ <<######### 即使配置 event 10035 configured..
2023-10-17T21:28:35.250854+00:00
PARSE ERROR: ospid=4070331, error=942 for statement:
Additional information: hd=0x66afde50 phd=0x66aff5a8 flg=0x20 cisid=0 sid=0 ciuid=0 uid=0 sqlid=g9b7tgg6dm018 <<######### no SQL TEXT is seen ..
…Current username=SYS
…Application: sqlplus@perf-adat-instance (TNS V1-V3) Action:
原因
BUG 35888571 – NEED TO RECORD SQL THAT HITS PARSE ERRORS (Status=80)
修复
fixed in 23.4 或安装one-off patch。
— enjoy —
对不起,这篇文章暂时关闭评论。