记一次生产数据库告警日志提示TTC 协议内部错误解决过程

最近在巡检时观察告警日志发现了一个很奇怪的错误：TTC 协议内部错误，下面介绍下解决的过程，以作备忘！

环境：

操作系统:AIX 6.1系统

数据库:oracle11.2.0.1 RAC

Errors in file /u01/app/oracle/diag/rdbms/otmdb/otmdb1/trace/otmdb1_ora_3997920.trc (incident=643554):

ORA-03137: TTC 协议内部错误: [12333] [41] [103] [108] [] [] [] []

Incident details in: /u01/app/oracle/diag/rdbms/otmdb/otmdb1/incident/incdir_643554/otmdb1_ora_3997920_i643554.trc

$cp /u01/app/oracle/diag/rdbms/otmdb/otmdb1/incident/incdir_642914/otmdb1_ora_3518674_i642914.trc /home/oracle/ttc.trc

$tkprof /home/oracle/ttc.trc /home/oracle/ttc.txt aggregate=yes sys=no waits=yes sort=fchela

$tkprof /home/oracle/ttc.trc /home/oracle/ttc2.txt sys=no

解释输出文件中列的含义：CALL：每次SQL语句的处理都分成三个部分Parse：这步将SQL语句转换成执行计划，包括检查是否有正确的授权和所需要用到的表、列以及其他引用到的对象是否存在。Execute：这步是真正的由Oracle来执行语句。对于insert、update、delete操作，这步会修改数据，对于select操作，这步就只是确定选择的记录。Fetch：返回查询语句中所获得的记录，这步只有select语句会被执行。COUNT:这个语句被parse、execute、fetch的次数。CPU：这个语句对于所有的parse、execute、fetch所消耗的cpu的时间，以秒为单位。ELAPSED：这个语句所有消耗在parse、execute、fetch的总的时间。DISK：从磁盘上的数据文件中物理读取的块的数量。一般来说更想知道的是正在从缓存中读取的数据而不是从磁盘上读取的数据。QUERY：在一致性读模式下，所有parse、execute、fetch所获得的buffer的数量。一致性模式的buffer是用于给一个长时间运行的事务提供一个一致性读的快照，缓存实际上在头部存储了状态。CURRENT：在current模式下所获得的buffer的数量。一般在current模式下执行insert、update、delete操作都会获取buffer。在current模式下如果在高速缓存区发现有新的缓存足够给当前的事务使用，则这些buffer都会被读入了缓存区中。ROWS: 所有SQL语句返回的记录数目，但是不包括子查询中返回的记录数目。对于select语句，返回记录是在fetch这步，对于insert、update、delete操作，返回记录则是在execute这步。

从跟踪文件可以看到以下信息：

----- Current SQL Statement for this session (sql_id=a33v0rjbr6qm7) -----

select o.order_release_gid, o.order_release_gid from ORDER_RELEASE o, LOCATION ls, ORDER_RELEASE_TYPE ort

where (o.order_release_type_gid=ort.order_release_type_gid) and (o.order_release_gid in

(select ors1.order_release_gid from STATUS_VALUE sv1, ORDER_RELEASE_STATUS ors1 where (sv1.status_value_xid=:1)

and (ors1.status_value_gid=sv1.status_value_gid))) and (o.early_pickup_date between trunc(TO_DATE(:2,:3), :4) and

trunc(TO_DATE(:5,:6), :7)+0.99999) and (o.source_location_gid=ls.location_gid) and (ls.location_xid like :8) and

(ort.order_release_type_xid in (:9)) order by o.insert_date desc

根据报错代码，查阅MOS文档

Troubleshooting ORA-3137 [12333]

Errors Encountered When Using Oracle JDBC Driver (文档 ID 1361107.1)

此报错信息来源于11.2.0.1其中一个bug

Unpublished Bug 9703463 - ORA-3137 [12333] or ORA-600 [kpobav-1] When Using Bind Peeking

This bug affects versions 11.1.0.6, 11.1.0.7, and 11.2.0.1 of the RDBMS. It is fixed in version 11.2.0.2 of the database.

It can also occur intermittently; similarly to unpublished Bug:8625762, this is a bind peeking bug.

5.1、禁用Bind Peeking

SQL> alter system set "_optim_peek_user_binds"=false;

此参数为oracle的隐含参数

5.2、升级数据库版本

此bug已在11.2.0.3以上版本修复，可升级此版本或更高

SQL> col ksppinm for a30

SQL> col ksppstvl for a30

SQL> col ksppdesc for a30

SQL> SELECT ksppinm, ksppstvl, ksppdesc FROM x$ksppi x, x$ksppcv y WHERE x.indx = y.indx AND ksppinm = '_optim_peek_user_binds';

查看隐含参数，此参数为开启状态

这里我最终选择了禁用隐含参数，关闭特性之后，业务系统模块已恢复，告警日志也不再出现报错信息

后面会分享更多devops和DBA方面的内容，感兴趣的朋友可以关注下~