ttc error oracle,ORA-03137: TTC protocol internal error : [12333]錯誤

admin wrote:

Hdr: 7445550 11.1.0.6.0 RDBMS 11.1.0.6.0 PRG INTERFACE PRODID-5 PORTID-226 ORA-3137 7390077

Abstract: ORA-3137: TTC PROTO INTERNAL ERROR : [12333] [21] [106] [110] [] [] [] []

PROBLEM:

Customer is in database 11.1.0.6 and JDBC Thin driver 11.1.0.6 and is getting

error :

ORA-3137: TTC proto internal error : [12333] [21] [106] [110] [] [] []

[]

There was originally bug 7148457 filed for the same customer but was closed

as it it could not be reproduced.

The problem still does not seem reproducable in the customers environment as

the error occurs intermittently.

The violations that are causing the application to fail.

Customer is using three tier architecture.

1 db server 11.1.0.6, 19 middle tier servers running 11.1.0.6 JDBC driver,

and many browser clients.

=========================

Environment Information:

Database: Oracle DB 11.1.0.6 – 64 bit Oracle software on 64 bit operating

system

JDBC Driver: Thin 11.1.0.6

OS: x86_64 x86_64 GNU/Linux – Red Hat Enterprise Linux Server release 5

(Tikanga)

=========================

RELATED BUGS:

7148457 – same customer

=========================

REPRODUCIBILITY:

No – error occurs intermittently.

=========================

TESTCASE:

N/A

=========================

URL:

All stack traces can be uploaded

========================

WORKAROUND:

N/A

=========================

STACK TRACE:

File = XACTLY01_ora_13733.trc

— PROTOCOL VIOLATION DETECTED —

—– Dump Cursor sql_id=6naatzxy9kh1a xsc=0x2aaaac4af2f0 cur=0x2aaaabd41c90

—–

Dump Parent Cursor sql_id=6naatzxy9kh1a phd=0x44637cab8 plk=0x429f05928

sqltxt(0x44637cab8)=select position0_.POSITION_ID as POSITION1_13_,

position0_.VERSION as VERSION13_, position0_.NAME as NAME13_,

position0_.DESCR as DESCR13_, position0_.INCENT_ST_DATE as INCENT5_13_,

position0_.INCENT_END_DATE as INCENT6_13_, position0_.EFFECTIVE_START_DATE as

EFFECTIVE7_13_, position0_.EFFECTIVE_END_DATE as EFFECTIVE8_13_,

position0_.IS_MASTER as IS9_13_, position0_.MASTER_POSITION_ID as

MASTER10_13_, position0_.IS_ACTIVE as IS11_13_, position0_.CREATED_DATE as

CREATED12_13_, position0_.CREATED_BY_ID as CREATED13_13_,

position0_.CREATED_BY_NAME as CREATED14_13_, position0_.MODIFIED_DATE as

MODIFIED15_13_, position0_.MODIFIED_BY_ID as MODIFIED16_13_,

position0_.MODIFIED_BY_NAME as MODIFIED17_13_, position0_.BUSINESS_ID as

BUSINESS18_13_ from XC_POSITION position0_ where position0_.BUSINESS_ID=:1

hash=dbb804768d9c25ae6a2959ff7c99402a

parent=0x446379dc0 maxchild=12 plk=0x429f05928 ppn=n

cursor instantiation=0x2aaaac4af2f0 used=1222720227 exec_id=16804067 exec=2

child#10(0x42ee8a6c0) pcs=0x42e4f0e48

clk=0x429f05830 ci=0x42f679438 pn=0x422ea67e8 ctx=0x43624a188

kgsccflg=1 llk[0x2aaaac4af2f8,0x2aaaac4af2f8] idx=2b

xscflg=c0110676 fl2=5d000009 fl3=52222008 fl4=180

sharing failure(s)=100000000

—– Bind Info (kkscoacd) —–

Bind#0

oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

kxsbbbfp=2aaaacb55820 bln=22 avl=00 flg=05

Frames pfr 0x2aaaacb55be0 siz=25528 efr 0x2aaaacb55b10 siz=25512

kxscphp=0x2aaaabd4b900 siz=984 inu=392 nps=344

kxscbhp=0x2aaaacb6d298 siz=984 inu=168 nps=48

Starting SQL statement dump

SQL Information

user_id=30 user_name=INCENT module=JDBC Thin Client action=

sql_id=6naatzxy9kh1a plan_hash_value=-1268437987 problem_type=4

—– Current SQL Statement for this session (sql_id=6naatzxy9kh1a) —–

select position0_.POSITION_ID as POSITION1_13_, position0_.VERSION as

VERSION13_, position0_.NAME as NAME13_, position0_.DESCR as DESCR13_,

position0_.INCENT_ST_DATE as INCENT5_13_, position0_.INCENT_END_DATE as

INCENT6_13_, position0_.EFFECTIVE_START_DATE as EFFECTIVE7_13_,

position0_.EFFECTIVE_END_DATE as EFFECTIVE8_13_, position0_.IS_MASTER as

IS9_13_, position0_.MASTER_POSITION_ID as MASTER10_13_, position0_.IS_ACTIVE

as IS11_13_, position0_.CREATED_DATE as CREATED12_13_,

position0_.CREATED_BY_ID as CREATED13_13_, position0_.CREATED_BY_NAME as

CREATED14_13_, position0_.MODIFIED_DATE as MODIFIED15_13_,

position0_.MODIFIED_BY_ID as MODIFIED16_13_, position0_.MODIFIED_BY_NAME as

MODIFIED17_13_, position0_.BUSINESS_ID as BUSINESS18_13_ from XC_POSITION

position0_ where position0_.BUSINESS_ID=:1

sql_text_length=806

sql=select position0_.POSITION_ID as POSITION1_13_, position0_.VERSION as

VERSION13_, position0_.NAME as NAME13_, position0_.DESCR as DESCR13_,

position0_.INCENT_ST_DATE as INCENT5_13_, position0_.INCENT_END_DATE as

INCENT6_13_, position0_.EFFECTIVE_START_DATE

sql= as EFFECTIVE7_13_, position0_.EFFECTIVE_END_DATE as EFFECTIVE8_13_,

position0_.IS_MASTER as IS9_13_, position0_.MASTER_POSITION_ID as

MASTER10_13_, position0_.IS_ACTIVE as IS11_13_, position0_.CREATED_DATE as

CREATED12_13_, position0_.CREATED_BY_ID as CRE

sql=ATED13_13_, position0_.CREATED_BY_NAME as CREATED14_13_,

position0_.MODIFIED_DATE as MODIFIED15_13_, position0_.MODIFIED_BY_ID as

MODIFIED16_13_, position0_.MODIFIED_BY_NAME as MODIFIED17_13_,

position0_.BUSINESS_ID as BUSINESS18_13_ from XC_POSITION posit

sql=ion0_ where position0_.BUSINESS_ID=:1

====================== END SQL Statement Dump ======================

*** 13:30:27.416

—– Error Stack Dump —–

ORA-3137: TTC protocol internal error : [1010] [] [] [] [] [] [] []

—– Current SQL Statement for this session (sql_id=6naatzxy9kh1a) —–

select position0_.POSITION_ID as POSITION1_13_, position0_.VERSION as

VERSION13_, position0_.NAME as NAME13_, position0_.DESCR as DESCR13_,

position0_.INCENT_ST_DATE as INCENT5_13_, position0_.INCENT_END_DATE as

INCENT6_13_, position0_.EFFECTIVE_START_DATE as EFFECTIVE7_13_,

position0_.EFFECTIVE_END_DATE as EFFECTIVE8_13_, position0_.IS_MASTER as

IS9_13_, position0_.MASTER_POSITION_ID as MASTER10_13_, position0_.IS_ACTIVE

as IS11_13_, position0_.CREATED_DATE as CREATED12_13_,

position0_.CREATED_BY_ID as CREATED13_13_, position0_.CREATED_BY_NAME as

CREATED14_13_, position0_.MODIFIED_DATE as MODIFIED15_13_,

position0_.MODIFIED_BY_ID as MODIFIED16_13_, position0_.MODIFIED_BY_NAME as

MODIFIED17_13_, position0_.BUSINESS_ID as BUSINESS18_13_ from XC_POSITION

position0_ where position0_.BUSINESS_ID=:1

—– Call Stack Trace —–

calling call entry argument values in hex

location type point (? means dubious value)

——————– ——– ——————–

—————————-

skdstdst()+41 call kgdsdst() 000000000 ? 000000001 ?

7FFF9F580088 ?

7FFF9F57EB70 ?

000000000 ? 000000002 ?

ksedst1()+103 call skdstdst() 000000000 ? 000000001 ?

7FFF9F580088 ?

7FFF9F57EB70 ?

000000001 ? 000000002 ?

ksedst()+39 call ksedst1() 000000000 ? 000000001 ?

7FFF9F580088 ?

7FFF9F57EB70 ?

000000001 ? 000000002 ?

dbkedDefDump()+1076 call ksedst() 000000000 ? 000000001 ?

7FFF9F580088 ?

7FFF9F57EB70 ?

000000001 ? 000000002 ?

ksedmp()+41 call dbkedDefDump() 000000003 ? 000000000 ?

7FFF9F580088 ?

7FFF9F57EB70 ?

000000001 ? 000000002 ?

opiierr()+411 call ksedmp() 000000003 ? 000000000 ?

7FFF9F580088 ?

7FFF9F57EB70 ?

000000001 ? 000000002 ?

opitsk()+5353 call opiierr() 000000003 ? 000000000 ?

7FFF9F580088 ? 000000000 ?

0000003F2 ? 000000001 ?

opiino()+1026 call opitsk() 000000001 ? 000000000 ?

000000001 ? 000000000 ?

0000003F2 ? 000000001 ?

opiodr()+1178 call opiino() 00000003C ? 000000004 ?

7FFF9F587308 ? 000000000 ?

0000003F2 ? 000000001 ?

opidrv()+580 call opiodr() 00000003C ? 000000004 ?

7FFF9F587308 ? 000000000 ?

008202E40 ? 000000001 ?

sou2o()+90 call opidrv() 00000003C ? 000000004 ?

7FFF9F587308 ? 000000000 ?

008202E40 ? 000000001 ?

opimai_real()+145 call sou2o() 7FFF9F5872E0 ? 00000003C ?

000000004 ? 7FFF9F587308 ?

008202E40 ? 000000001 ?

ssthrdmain()+177 call opimai_real() 000000002 ? 7FFF9F587480 ?

000000004 ? 7FFF9F587308 ?

008202E40 ? 000000001 ?

main()+215 call ssthrdmain() 000000002 ? 7FFF9F587480 ?

000000004 ? 000000000 ?

008202E40 ? 000000001 ?

__libc_start_main() call main() 000000002 ? 7FFF9F5875E8 ?

[phone] ? 000000000 ?

008202E40 ? 000000001 ?

_start()+41 call __libc_start_main() 000935D68 ? 000000002 ?

7FFF9F5875E8 ? 000000000 ?

008202E40 ? 000000002 ?

There are two errors reported above:

ORA-3137: TTC protocol internal error : [12333] [21] [106] [110] []

ORA-3137: TTC protocol internal error : [1010] [] [] [] [] [] [] []

The stacks are the same for both:

skdstdst, ksedst1, ksedst, dbkedDefDump, ksedmp, opiierr,

opitsk, opiino, opiodr, opidrv, sou2o, opimai_real, ssthrdmain,

main, __libc_start_main, _start

According to the TAR, the error the client application sees is:

Exception Message : PreparedStatementCallback; uncategorized

SQLException for SQL []; SQL state [72000];

error code [1010]; ORA-1010: invalid OCI operation

even though this is thin.

Hunting for the error with opiierr finds numerous reports vs 11g. Bug

6741577 says the ORA-3137 with [1010] happens when oracle can’t consume all

the bytes received on the wire. This sounds to me like more data is being

sent than expected. In that bug it suggested adding:

event=”1010 trace name errorstack level 2″

to the init.ora to try and get a trace from the 1010.

Note 35928.1 says 12333 followed by 3 parameters means a request is being

received from a network packet and the request code in the packet is not

recognized. The three additional values report the invalid request values

received.

Both these issues seem to indicate some sort of corruption in the data being

sent to the d/b, possibly because JDBC is sending bad info or there is a

problem on the network itself. We ideally need to see a corresponding client

and server side net trace in order to determine where the problem is

occurring.

There is a similar 11g bug, bug 7238542. In that bug they believe the

problem may occur when the cursor is reloaded into the shared pool. A

protocol violation occurs on the server but is not signalled to the client so

the next request from the client also causes a violation which results in the

server side aborting. Bug 7446725 was raised from this and is currently

assigned to SE as the conclusion was a diagnostics patch would probably be

required to resolve this.

If the same is happening here then a workaround may be to pin the failing

selects in the shared pool.