ORA-03137 TTC protocol internal error

Recently received this error on one of our 11.1.0.7 Database. Here is the description from alert log

Errors in file /...../1.trc:
ORA-03137: TTC protocol internal error : [12333] [5] [196] [2] [] [] [] []
----- Error Stack Dump -----
ORA-03137: TTC protocol internal error : [12333] [5] [196] [2] [] [] [] []
----- Current SQL Statement for this session (sql_id=xyzxxxxxxxxxxx) -----
UPDATE test stage_table SET ..... :BIND1 ... :BIND2 ... :BIND3 ........

Well, so what does it mean. After further investigation it’s a bug regarding bind peeking.

Here is what oracle workaround for same.

Bug 8625762 ORA-3137 [12333] due to bind data not read from wire

eg: Typically the trace file will show a PROTOCOL VIOLATION with Page before data showing a SQL statement (or request to execute a statement), the last 3 bytes of which are a bind length and the start of bind data, and then will show “Current Page” with the rest of thebind data.

Workaround
Setting “_optim_peek_user_binds”=false avoids this problem but use this with caution as it can affect execution plans chosen by CBO.

Not so clear. Let’s look into some details. First part of trace

--- PROTOCOL VIOLATION DETECTED ---
----- Dump Cursor sql_id=xyzxxxxxxxxxxx xsc=0x2b99f42bc148 cur=0x2b99f3d01d40 -----
Dump Parent Cursor sql_id=xyzxxxxxxxxxxx phd=0xcccccccc plk=0xyyyyyyyyy
 sqltxt(0xcccccccc)=UPDATE test stage_table SET ..... :BIND1 ... :BIND2 ... :BIND3 ........
  hash=xxxxxxxxxxxxx
  parent=0xYYYYYY maxchild=07 plk=0xyyyyyyyyy ppn=n
.......................
.......................
.......................

  sharing failure(s)=800000040000
----- Bind Info (kkscoacd) -----
 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000000 frm=00 csi=00 siz=2096 off=0
  kxsbbbfp=2b99f4241e10  bln=22  avl=00  flg=05
 Bind#1
  oacdty=01 mxl=2000(132) mxlc=33 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000010 frm=01 csi=873 siz=0 off=24
  kxsbbbfp=2b99f4241e28  bln=2000  avl=00  flg=01
 Bind#2
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000000 frm=00 csi=00 siz=0 off=2024
  kxsbbbfp=2b99f42425f8  bln=22  avl=00  flg=01
 Bind#3
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000000 frm=00 csi=00 siz=0 off=2048
  kxsbbbfp=2b99f4242610  bln=22  avl=00  flg=01
 Bind#4
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000000 frm=00 csi=00 siz=0 off=2072
  kxsbbbfp=2b99f4242628  bln=22  avl=00  flg=01
 Frames pfr 0x2b99f40af0b0 siz=20744 efr 0x2b99f40aefd8 siz=20720
 kxscphp=0x2b99f4633808 siz=1992 inu=1616 nps=1504
 kxscbhp=0x2b99f4633e98 siz=3104 inu=2368 nps=2120
Starting SQL statement dump

As, you can see from this avl=00 so bind length is Zero and sharing failure(s)=800000040000 which corrospond to USER_BIND_PEEK_MISMATCH + BIND_EQUIV_FAILURE. So, this is related to bind peeking.

Further there is an another section in trace that is

-----Page before-----
XXXXXXXXX 03 5E 19 29 80 00 00 00 00 00 00 01 CC 03 00 00  [.^.)............]
XXXXXXXXX 01 0D 00 00 00 01 01 00 00 00 00 01 00 00 00 00  [................]
..................................
..................................
..................................
..................................
..................................
XXXXXXXXX 00 00 00 00 00 00 00 00 00 00 02 03 00 00 15 00  [................]
XXXXXXXXX 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  [................]
XXXXXXXXX 00 00 00 00 00 00 00 07 05 C4 02                 [...........]
-----Current Page-----
nsbfdbpt 0x1b74mmmm
ifccrcp = 0x1b74mmm, ifccrcl = 0x1b74emmm
buffer length = 56
XXXXXXXXX                                  01 02 1C 21 54             [...!T]
..................................
..................................
XXXXXXXXX 04 C3 47 51 57 06 C5 04 41 64 58 51 06 C5 04 42  [..GQW...AdXQ...B]
XXXXXXXXX 01 58 51                                         [.XQ]

03 5E – The Page before shows we have an OALL8 packet and it looks like bind data has been left on the wire. As you can see last three bytes of bind data is left and read as new packet also they matches our error.

Also, in that last three bytes length of first bind data is 5 second is 21 and so on.

I have change some names of files and other stuff but data which i want to show are same from trace.

RMAN-03002-06571

We are using 11.1.0.7 Database with standby. This issue happend while applying incremental backup to DR site.

RMAN>
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of switch to copy command at 01/24/2012 19:24:02
RMAN-06571: datafile 104 does not have recoverable copy

When you issue RMAN > report schema command. One of the datafile shows Zero bytes

104 0 USERS *** +DATA/taral/datafile/users.600.7510420000

While this was in alertlog

Managed Standby Recovery not using Real Time Apply
Errors in file /u01/app/oracle/diag/rdbms/taral/taral1/trace/taral1_mrp0_22065.trc:
ORA-01110: data file 104: '+DATA/taral/datafile/users.600.7510420000'
ORA-01157: cannot identify/lock data file 104 - see DBWR trace file
ORA-01110: data file 104: '+DATA/taral/datafile/users.600.7510420000'

To resolve this issue copy that data file through RMAN and ship to remote location

copy datafile '+DATA/primary/datafile/users.600.7510420000' to '/backup/taral/users.600.7510420000';
scp /backup/taral/users.600.7510420000 oracle@remot:/backup/taral

Now in mount mode on DR site issue this commands in RMAN

catalog datafilecopy '/backup/taral/users.600.7510420000';
switch datafile 104 to copy;
backup as copy datafile 104 format '+DATA';
switch datafile 104 to copy;

Now when you run report schema it will report correct size.