Cryptic messages in SQL*Net trace file

  • From: "William Wagman" <wjwagman@xxxxxxxxxxx>
  • To: <oracle-l@xxxxxxxxxxxxx>
  • Date: Tue, 24 Apr 2007 17:30:55 -0700

Greetings,

I'm running a two node RAC cluster using Oracle 10.2.0.3.0 Enterprise
Edition on RHEL4. I am trying to resolve an issue with a database link.
I am using a local tnsnames.ora on each node. I have created the
database link...

create database link <link> connect to <user> identified by <password>
using '<connect string>'; 

And it functions on one node but on the second node I get an ORA-12154
error. I can resolve the error on the second node by creating the link
as follows...

create database link <link> connect to <user> identified by <password>
using '(DESCRIPTION =(ADDRESS = (COMMUNITY = TCP.ucdavis.edu)(PROTOCOL =
TCP) (host = veni.ucdavis.edu)(port = 1521)) (connect_data = (sid =
academic)(GLOBAL_NAME = 
academic.ucdavis.edu)))'; 

Which is kind of a pain. The interesting thing is that this only occurs
when I am using a database link. 

sqlplus user/password@remote database

works fin. So I turned on tracing and in the trace file on the
misbehaving node I see the following (apologies for the long segment)...

[24-APR-2007 14:24:31:417] nttrd: socket 9 had bytes read=22
[24-APR-2007 14:24:31:417] nttrd: exit
[24-APR-2007 14:24:31:417] nsprecv: 22 bytes from transport
[24-APR-2007 14:24:31:417] nsprecv: tlen=22, plen=11, type=12
[24-APR-2007 14:24:31:417] nsprecv: 11 bytes to leftover
[24-APR-2007 14:24:31:417] nsprecv: packet dump
[24-APR-2007 14:24:31:417] nsprecv: 00 0B 00 00 0C 00 00 00  |........|
[24-APR-2007 14:24:31:417] nsprecv: 01 00 03                 |...     |
[24-APR-2007 14:24:31:417] nsprecv: normal exit
[24-APR-2007 14:24:31:417] nsrdr: got NSPTMK packet
[24-APR-2007 14:24:31:417] nsrdr: normal exit
[24-APR-2007 14:24:31:417] nsdo: *what=17, *bl=1
[24-APR-2007 14:24:31:417] nsdo: nsctxrnk=0
[24-APR-2007 14:24:31:417] nsdo: normal exit
[24-APR-2007 14:24:31:417] nioqrc:  found a interrupt marker...
[24-APR-2007 14:24:31:417] nioqrc:  Recieve: returning error: 3111
[24-APR-2007 14:24:31:418] nioqrc: exit
[24-APR-2007 14:24:31:418] nioqrs: entry
[24-APR-2007 14:24:31:418] nioqrs:  state = interrupted (1)
[24-APR-2007 14:24:31:418] nioqrs:  state = interrupted (1)
[24-APR-2007 14:24:31:418] nioqrs: nioqrs: sending reset marker...
[24-APR-2007 14:24:31:418] nioqsm: entry
[24-APR-2007 14:24:31:418] nioqsm:  Sending reset packet (2)...
[24-APR-2007 14:24:31:418] nsdo: entry
[24-APR-2007 14:24:31:418] nsdo: cid=0, opcode=67, *bl=1, *what=17,
uflgs=0x0, cflgs=0x3
[24-APR-2007 14:24:31:418] nsdo: rank=64, nsctxrnk=0
[24-APR-2007 14:24:31:418] nsdo: nsctx: state=8, flg=0x400d, mvd=0
[24-APR-2007 14:24:31:418] nsdo: gtn=127, gtc=127, ptn=10, ptc=2011
[24-APR-2007 14:24:31:418] nsdofls: entry
[24-APR-2007 14:24:31:418] nsdofls: DATA flags: 0x0
[24-APR-2007 14:24:31:418] nsdofls: normal exit
[24-APR-2007 14:24:31:418] nsdo: sending NSPTMK packet
[24-APR-2007 14:24:31:418] nspsend: entry
[24-APR-2007 14:24:31:418] nspsend: plen=11, type=12
[24-APR-2007 14:24:31:418] nttwr: entry
[24-APR-2007 14:24:31:418] nttwr: socket 9 had bytes written=11
[24-APR-2007 14:24:31:418] nttwr: exit
[24-APR-2007 14:24:31:418] nspsend: packet dump
[24-APR-2007 14:24:31:418] nspsend: 00 0B 00 00 0C 00 00 00  |........|
[24-APR-2007 14:24:31:418] nspsend: 01 00 02                 |...     |
[24-APR-2007 14:24:31:418] nspsend: 11 bytes to transport
[24-APR-2007 14:24:31:418] nspsend: normal exit
[24-APR-2007 14:24:31:418] nsdoacts: entry
[24-APR-2007 14:24:31:418] nsdofls: entry
[24-APR-2007 14:24:31:418] nsdofls: DATA flags: 0x0
[24-APR-2007 14:24:31:418] nsdofls: normal exit
[24-APR-2007 14:24:31:418] nsdoacts: flushing transport
[24-APR-2007 14:24:31:418] nttctl: entry
[24-APR-2007 14:24:31:418] nsdoacts: normal exit
[24-APR-2007 14:24:31:418] nsdo: nsctxrnk=0
[24-APR-2007 14:24:31:418] nsdo: normal exit
[24-APR-2007 14:24:31:418] nioqsm: exit
[24-APR-2007 14:24:31:418] nioqrs: nioqrs: sucking for reset marker...
[24-APR-2007 14:24:31:418] nioqar: entry
[24-APR-2007 14:24:31:418] nioqar: nioqar: suck pipe til I get a
reset...
[24-APR-2007 14:24:31:419] nscontrol: entry
[24-APR-2007 14:24:31:419] nscontrol: cmd=1, lcl=0x0
[24-APR-2007 14:24:31:419] nscontrol: normal exit

The first difference I see when comparing this with the same trace file
on the functioning node is on the first line. On the functioning node
bytes read=367. I don't understand the meaning of all these messages but
from what I have found it appears there is some sort of networking issue
In-band and Out-of-band Breaks (which I don't understand but will ask
the sysadmin about) or something but I can't find anything more about
it. It isn't a firewall issue as it works on one node but not the other.

Has anyone ever seen something like this before or have any insight as
to what might be happening?

Thanks.

Bill Wagman
Univ. of California at Davis
IET Campus Data Center
wjwagman@xxxxxxxxxxx
(530) 754-6208
--
//www.freelists.org/webpage/oracle-l


Other related posts:

  • » Cryptic messages in SQL*Net trace file