ORA-12539 and ORA-12630 errors in SQLNET trace file

[zxmgh]

Hi, all,

I have a C++ application that connecting to a Oracle9i RAC (two nodes) system running on Linux IA64 platform, the version of DB is 9.2.0.5.0. Each time the application gets a request from client, it opens a connection to the DB and insert/update/delete data and then close this connection. This application gets many requests each day. In the log files of this application, we found the following Oracle errors:

ORA-12539: TNS:buffer or under-flow
ORA-12630: Native service operation not supported

It happens several times per day, it happens exactly before the application tries to connect the DB.

I checked the server side trace files under udump directory; listener.log file, nothing is special there at the time this problem happened; then I turn on the client side tracing by adding the following entries to sqlnet.ora of the client machine:

TRACE_LEVEL_CLIENT=16
TRACE_DIRECTORY_CLIENT=c:\temp
TRACE_FILE_CLIENT=client_trace.trc

Here is the part of the sqlnet trace files that caught these errors:

(2824) [000001 13-APR-2005 15:24:23:120] nscon: got NSPTRD packet
(2824) [000001 13-APR-2005 15:24:23:120] nsmal: entry
(2824) [000001 13-APR-2005 15:24:23:120] nsmal: 524 bytes at 0x13f1bc8
(2824) [000001 13-APR-2005 15:24:23:120] nsmal: normal exit
(2824) [000001 13-APR-2005 15:24:23:120] nscon: recving connect data
(2824) [000001 13-APR-2005 15:24:23:120] nsdo: entry
(2824) [000001 13-APR-2005 15:24:23:120] nsdo: cid=0, opcode=68, *bl=524, *what=1, uflgs=0x4001, cflgs=0x0
(2824) [000001 13-APR-2005 15:24:23:120] nsdo: nsctx: state=2, flg=0x804205, mvd=0
(2824) [000001 13-APR-2005 15:24:23:120] nsdo: gtn=10, gtc=10, ptn=10, ptc=2047
(2824) [000001 13-APR-2005 15:24:23:120] nsrdr: entry
(2824) [000001 13-APR-2005 15:24:23:120] nsrdr: recving a packet
(2824) [000001 13-APR-2005 15:24:23:120] nsprecv: entry
(2824) [000001 13-APR-2005 15:24:23:120] nsprecv: 534 bytes from leftover
(2824) [000001 13-APR-2005 15:24:23:120] nsprecv: tlen=534, plen=534, type=6
(2824) [000001 13-APR-2005 15:24:23:120] nsprecv: packet dump

...

(2824) [000001 13-APR-2005 15:24:23:120] nsprecv: normal exit
(2824) [000001 13-APR-2005 15:24:23:120] nsrdr: got NSPTDA packet
(2824) [000001 13-APR-2005 15:24:23:120] nsrdr: NSPTDA flags: 0x40
(2824) [000001 13-APR-2005 15:24:23:120] nsrdr: normal exit
(2824) [000001 13-APR-2005 15:24:23:120] nsdo: *what=1, *bl=524
(2824) [000001 13-APR-2005 15:24:23:120] nsdo: 524 bytes from NS buffer
(2824) [000001 13-APR-2005 15:24:23:120] nsdo: normal exit
(2824) [000001 13-APR-2005 15:24:23:120] nscon: got 524 bytes connect data
(2824) [000001 13-APR-2005 15:24:23:120] nsmfr: entry
(2824) [000001 13-APR-2005 15:24:23:120] nsmfr: 524 bytes at 0x13f1bc8
(2824) [000001 13-APR-2005 15:24:23:120] nsmfr: normal exit
(2824) [000001 13-APR-2005 15:24:23:120] nscon: connect data overflow
(2824) [000001 13-APR-2005 15:24:23:120] nserror: entry
(2824) [000001 13-APR-2005 15:24:23:120] nserror: nsres: id=0, op=77, ns=12539, ns2=0; nt[0]=0, nt[1]=0, nt[2]=0; ora[0]=0, ora[1]=0, ora[2]=0
(2824) [000001 13-APR-2005 15:24:23:120] nscon: error exit
(2824) [000001 13-APR-2005 15:24:23:120] snsbitts_ts: entry
(2824) [000001 13-APR-2005 15:24:23:120] snsbitts_ts: acquired the bit
(2824) [000001 13-APR-2005 15:24:23:120] snsbitts_ts: normal exit
(2824) [000001 13-APR-2005 15:24:23:120] nsdo: nsctxrnk=0
(2824) [000001 13-APR-2005 15:24:23:120] snsbitcl_ts: entry
(2824) [000001 13-APR-2005 15:24:23:120] snsbitcl_ts: normal exit
(2824) [000001 13-APR-2005 15:24:23:120] nsdo: error exit
(2824) [000001 13-APR-2005 15:24:23:120] nscall: unexpected response

[zxmgh]

One thing I found after analyzing the sqlnet trace file is when this ORA-12539 happens, the pattern is:

(280) [000007 13-APR-2005 07:26:17:803] nsrdr: recving a packet
(280) [000007 13-APR-2005 07:26:17:803] nsprecv: reading from transport...
(280) [000007 13-APR-2005 07:26:17:803] nttrd: entry
(280) [000007 13-APR-2005 07:26:17:803] nttrd: socket 772 had bytes read=530
(280) [000007 13-APR-2005 07:26:17:803] nttrd: exit
(280) [000007 13-APR-2005 07:26:17:803] nsprecv: 530 bytes from transport
(280) [000007 13-APR-2005 07:26:17:803] nsprecv: tlen=530, plen=530, type=6
(280) [000007 13-APR-2005 07:26:17:803] nsrdr: got NSPTDA packet
(280) [000007 13-APR-2005 07:26:17:803] nsrdr: NSPTDA flags: 0x40
(280) [000007 13-APR-2005 07:26:17:803] nsdo: *what=1, *bl=520
(280) [000007 13-APR-2005 07:26:17:803] nsdo: 520 bytes from NS buffer
(280) [000007 13-APR-2005 07:26:17:803] nscon: got 520 bytes connect data
(280) [000007 13-APR-2005 07:26:17:803] nsmfr: 520 bytes at 0x165ac18
(280) [000007 13-APR-2005 07:26:17:803] nscon: connect data overflow
(280) [000007 13-APR-2005 07:26:17:803] nserror: nsres: id=0, op=77, ns=12539, ns2=0; nt[0]=0, nt[1]=0, nt[2]=0; ora[0]=0, ora[1]=0, ora[2]=0
(280) [000007 13-APR-2005 07:26:17:803] snsbitts_ts: acquired the bit
(280) [000007 13-APR-2005 07:26:17:803] nsdo: nsctxrnk=0
(280) [000007 13-APR-2005 07:26:17:803] nscall: unexpected response
(280) [000007 13-APR-2005 07:26:17:803] nstimarmed: no timer allocated
(280) [000007 13-APR-2005 07:26:17:803] snsbitts_ts: acquired the bit
(280) [000007 13-APR-2005 07:26:17:803] nsdo: cid=0, opcode=98, *bl=0, *what=0, uflgs=0x440, cflgs=0x2
(280) [000007 13-APR-2005 07:26:17:803] snsbitts_ts: acquired the bit
(280) [000007 13-APR-2005 07:26:17:803] nsdo: rank=64, nsctxrnk=0
(280) [000007 13-APR-2005 07:26:17:803] nsdo: nsctx: state=6, flg=0x804201, mvd=0
(280) [000007 13-APR-2005 07:26:17:803] snsbitts_ts: acquired the bit
(280) [000007 13-APR-2005 07:26:17:803] nsdo: nsctxrnk=0
(280) [000007 13-APR-2005 07:26:17:803] nsclose: closing transport
(280) [000007 13-APR-2005 07:26:17:803] nttdisc: entry
(280) [000007 13-APR-2005 07:26:17:803] nttdisc: Closed socket 772
(280) [000007 13-APR-2005 07:26:17:803] nttdisc: exit

It seems that Net8 get 530 bytes from transport but the NS buffer is only 520 bytes, it this the reason why? In another case I found Net8 get 544 bytes from transport but the NS buffer is only 534 bytes.

[zxmgh]

The rmem_default value of both servers has been set to 65535 and rmem_max set to 131071, but in the "RAC on Linux Best Practices" (Metalink Note: 240575.1) article, Oracle strongly recommend to adjust the send and receive buffer size to 256K.

#The default setting in bytes of the socket receive buffer
/proc/sys/net/core/rmem_default = 65535

#The maximum socket receive buffer size in bytes
/proc/sys/net/core/rmem_max = 131071

#he default setting in bytes of the socket send buffer
/proc/sys/net/core/wmem_default = 262144

#The maximum socket send buffer size in bytes
/proc/sys/net/core/wmem_max = 262144

Do you think this may cause the error?

I also found a Bug: 2642168 - Buffer overflow vulnerability with CREATE DATABASE LINK, but Oracle claims that this bug is fixed in 9.2.0.3.0.

[zxmgh]

Anyone has any idea please help

[DaPi]

SORRY!

Net problems are hard to diagnose at a distance and almost impossible if they are intermittant. Would have liked to help but . . . . . can only suggest Oracle support.

[tamilselvan]

Check the Network cable using analyzer. There may be some "bend".

Tamil

[zxmgh]

What kind of network cable analyzer? please clarify

Thanks

[zxmgh]

In the SQLNET.log file, I saw the following error message:

Fatal NI connect error 12560, connecting to:

(DESCRIPTION=(ADDRESS=(PROTOL=BEQ)(PROGRAM=oracle)(ARGV0=oracleORCL)(ARGS='(DSCRIPTION=(LOCAL=YES)(A DDRESS=(PROTO =beq)))'))(CONNECT_DATA=(SID=ORCL)(CID=(PROGRAM=C:\xxx.exe)(HOST=zzzz)(USER=SYSTEM))))

Fatal NI connect error 12539, connecting to:

(DESCRIPTION=(LOAD_BALANCE=ON)(FAILOVER=ON)(ADDRESS=(PROTOL=TCP)(HOST=yyyy)(PORT=1521))(CONNECT_DATA =(SERVER=DEDICATED)(SERVICE_NAME=oraprod)(FAILOVER_MODE=(TYPE=select)(METHOD=basic))(CID=(PROGRAM=C: \xxx.exe)(HOST=zzzz)(USER=SYSTEM))))

VERSION INFORMATION:
TNS for 32-bit Windows: Version 9.2.0.5.0 - Production
Windows NT TCP/IP NT Proto Adapter for 32-bit Windows: Version 9.2.0.5.0 - Production
Time: 04-MAY-2005 13:59:11
Tns error struct:
nr err code: 0
ns main err code: 12560
TNS-12560: TNSroto adapter error
ns secondary err code: 0
Tns error struct:
nt main err code: 530
nr err code: 0
ns main err code: 12539
TNS-00530: Proto adapter error
nt secondary err code: 126
nt OS err code: 0
TNS-12539: TNS:buffer over- or under-flow
ns secondary err code: 0
nt main err code: 0
nt secondary err code: 0
nt OS err code: 0