Re: HELP! SQLNET problem in Distributed System

Joe <joetin_at_netvigator.com> wrote:

>Our system runs on distributed system with two databases on two separate
>machines. The ProC program written by us will read the transaction data
>from Database A (dbname=sail), process and write to Database B
>(dbname=acct) through sqlnet. However a trace file (in
>?/network/trace/client) in Database A continued to grow up to several
>hundred mega bytes when the program ran. The program ended successfully.
>There is no corresponding trace file in Database B and there is also no
>special records in alert_log files in both databases.

Joe,

With trace enabled you will get very large trace fioles as every packet sent on the network is traced. Unless you have a problem then swith off tracing on all machines, edit the sqlnet.ora files and set all tracing off (Refer to the asqlnet manual for dertails)

In production environments you should not have trace on, it's a diagnosis tool for resolving problems ony.
>
>We want to know why there is a trace file generated and how to solve the
>problem because the trace file is too large and is going to make the
>filesystem space full. We have attached a porton of the trace file.

You will note that trace level is set to 16 and trace_client is set true, comment these out of sqlnet.ora and tracing will stop

>
>Other information:
>OS: AIX 4.1.4 on RS/6000 J40
>Oracle: 7.2.3 (with patch reqarding AIX J40 machine)
>ProC: 2.1.6
>
>Thank you.
>
>Joe Tin
>joetin_at_netvigator.com
>
>----------------------------
>Part of the trace file (From the begining)
>
>
>--- TRACE CONFIGURATION INFORMATION FOLLOWS ---
>New trace stream is "/oracle72/network/trace/client/sqlnet_17912.trc"
>New trace level is 16
>--- TRACE CONFIGURATION INFORMATION ENDS ---
>
>--- PARAMETER SOURCE INFORMATION FOLLOWS ---
>Attempted load of system pfile source /oracle72/network/admin/sqlnet.ora
>Parameter source loaded successfully
>
>Attempted load of local pfile source /home/tkctl/.sqlnet.ora
>Parameter source was not loaded
>
> -> PARAMETER TABLE LOAD RESULTS FOLLOW <-
>Successful parameter table load
> -> PARAMETER TABLE HAS THE FOLLOWING CONTENTS <-
> automatic_ipc = off
> trace_directory_client = /oracle72/network/trace/client
> sqlnet.expire_time = 10
> trace_file_client = sqlnet.trc
> log_file_client = sqlnet.log
> log_directory_client = /oracle72/network/log/client
> trace_unique_client = ON
> use_dedicated_server = off
> trace_level_client = 16
>--- PARAMETER SOURCE INFORMATION ENDS ---
>
>--- LOG CONFIGURATION INFORMATION FOLLOWS ---
>Log stream will be "/oracle72/network/log/client/sqlnet.log"
>Log stream validation not requested
>--- LOG CONFIGURATION INFORMATION ENDS ---
>
>osnqig: entry
>osnqig: Count in the NL global area is now 1
>osnqig: Count in OSN global area now: 1
>nrigbi: entry
>nrigbni: entry
>nrigbni: Unable to get data from navigation file tnsnav.ora
>nrigbni: exit
>nrigbi: exit
>osnqig: exit
>nnfsinit: entry
>nnfsinit: Obtaining native use parameter native_names.use_native
>nnfsinit: Using Oracle naming
>nncpmlf_make_local_addrfile: construction of local names file failed
>nncpmsf_make_sys_addrfile: system names file is
>/oracle72/network/admin/tnsnames.ora
>nncpcin_maybe_init: first request sent to name server will have ID 63597
>nncpcin_maybe_init: initial retry timeout for all name servers is 500
>csecs
>nncpcin_maybe_init: max request retries per name server is 2
>nngsini_init_streams: initializing stream subsystem, cache size is 10
>nngtini_init_msg: initializing PDU subsystem, initial pool size is 2
>nncpcin_maybe_init: default name server domain is [root]
>osnqrn: Using nnfsn2a() to build connect descriptor for (possibly
>remote) database.
>nncpldf_load_addrfile: initial load of names file
>/oracle72/network/admin/tnsnames.ora
>nncpldf_load_addrfile: success
>--- /oracle72/network/admin/tnsnames.ora TABLE HAS THE FOLLOWING
>CONTENTS ---
>sail = (DESCRIPTION= (ADDRESS_LIST= (ADDRESS= (PROTOCOL=TCP)
>(HOST=9.192.34.210) (PORT=1521))) (CONNECT_DATA= (SID=sail)))
>acct = (DESCRIPTION= (ADDRESS_LIST= (ADDRESS= (PROTOCOL=TCP)
>(HOST=9.192.34.230) (PORT=1521))) (CONNECT_DATA= (SID=acct)))
>--- END /oracle72/network/admin/tnsnames.ora TABLE ---
>nncin2a: System table translated "acct" to (DESCRIPTION= (ADDRESS_LIST=
>(ADDRESS= (PROTOCOL=TCP) (HOST=9.192.34.230) (PORT=1521)))
>(CONNECT_DATA= (SID=acct)))
>nngsdei_deinit_streams: deinit
>nngscls_close_stream: UID 0 not established, ignored
>nngscls_close_stream: UID 0 not established, ignored
>nngscls_close_stream: UID 0 not established, ignored
>nngscls_close_stream: UID 0 not established, ignored
>nngscls_close_stream: UID 0 not established, ignored
>nngscls_close_stream: UID 0 not established, ignored
>nngscls_close_stream: UID 0 not established, ignored
>nngscls_close_stream: UID 0 not established, ignored
>nngscls_close_stream: UID 0 not established, ignored
>nngscls_close_stream: UID 0 not established, ignored
>nrigbd: entry
>nrigbd: exit
>osntns: entry
>osntns: Not trying to enable dead connection detection.
>osntns: Calling address:
>(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=9.192.34.230)(PORT=1521)))(CONNECT_DATA=(SID=acct)(CID=(PROGRAM=)(HOST=ctsvenus_stdby)(USER=tkctl))))
>nricall: entry
>nrigbi: entry
>nrigbni: entry
>nrigbni: Unable to get data from navigation file tnsnav.ora
>nrigbni: exit
>nrigbi: exit
>nric2a: entry
>nric2a: Getting local community information
>nriglp: entry
>nriglp: Looking for local addresses setup by nrigla
>nriglp: No addresses in the preferred address list
>nriglp: exit
>nric2a: TNSNAV.ORA is not present. No local communities entry.
>nrigla: entry
>nrigla: Getting local address information
>nrigla: Address list being processed...
>nrigla: No community information so all addresses are "local"
>nrigla: exit
>nridst: entry
>nridst: Resolving address to use to call destination or next hop
>nridst: Processing address list...
>nridst: No community entries so iterate over address list
>nridst: exit
>nric2a: This is a local community access
>nric2a: exit
>nricall: Got routable address information
>nricall: Making call with following address information:
>(DESCRIPTION=(CONNECT_DATA=(SID=acct)(CID=(PROGRAM=)(HOST=ctsvenus_stdby)(USER=tkctl)))(ADDRESS=(PROTOCOL=TCP)(HOST=9.192.34.230)(PORT=1521)))
>nricdt: entry
>nricdt: Calling with outgoing connect data
>(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=9.192.34.230)(PORT=1521)))(CONNECT_DATA=(SID=acct)(CID=(PROGRAM=)(HOST=ctsvenus_stdby)(USER=tkctl))))
>nscall: entry
>nscall: connecting...
>nsc2addr: entry
>nsc2addr:
>(DESCRIPTION=(CONNECT_DATA=(SID=acct)(CID=(PROGRAM=)(HOST=ctsvenus_stdby)(USER=tkctl)))(ADDRESS=(PROTOCOL=TCP)(HOST=9.192.34.230)(PORT=1521)))
>nttbnd2addr: entry
>nttbnd2addr: port resolved to 1521
>nttbnd2addr: using host IP address: 9.192.34.230
>nttbnd2addr: exit
>nsc2addr: normal exit
>nsopen: entry
>nsmal: 436 bytes at 0x200a55e8
>nsopen: opening transport...
>nttcon: entry
>nttcon: toc = 1
>nttcnp: entry
>nttcnp: creating a socket.
>nttcnp: exit
>nttcni: entry
>nttcni: trying to connect to socket 14.
>nttcni: exit
>nttcon: NT layer TCP/IP connection has been established.
>nttcon: exit
>nsopen: transport is open
>nsnainit: entry
>nsnainit: call
>nsnadct: entry
>nsnadct: normal exit
>nsnasvnainfo: entry
>nsnasvnainfo: normal exit
>nainit: entry
>nagblini: entry
>nau_gin: entry
>nau_gparams: entry
>nau_gslf: entry
>nam_gic: entry
>nam_gic: exit
>nau_gslf: exit
>nau_gparams: exit
>nau_gin: exit
>nagblini: exit
>na_saveprot: entry
>na_saveprot: exit
>nacomin: entry
>nas_init: entry
>nas_init: exit
>nau_ini: entry
>nau_gettab: entry
>nau_gettab: using authentication adapter table "nautab"
>nau_gettab: adapter table is empty
>nau_gettab: exit
>nau_sini: entry
>nau_sini: exit
>nau_ini: connection type: "standard"
>nau_ini: exit
>naeeinit: entry
>naeshow: entry
>naeshow: These are the encryption algorithms that the client will
>accept:
>naeshow: Choice 0: no algorithm; encryption inactive
>naeshow: exit
>naeeinit: exit
>naecinit: entry
>naeshow: entry
>naeshow: These are the checksumming algorithms that the client will
>accept:
>naeshow: Choice 0: no algorithm; checksumming inactive
>naeshow: exit
>naecinit: exit
>nainit: exit
>nsnainit: NS Connection version: 308
>nsnainit: setting "no services" flag
>nsnainit: native service(s) is (are) wanted
>nsnainit: inf->nsinfflg[0]: 0x9 inf->nsinfflg[1]: 0x9
>nsnainit: normal exit
>nsoptions: lcl[0]=0x0, lcl[1]=0x0, gbl[0]=0x0, gbl[1]=0xa01, cha=0x0
>nsoptions: lcl[0]=0xe9ff, lcl[1]=0x0, gbl[0]=0x983f, gbl[1]=0x801
>nsopen: global context check-in (to slot 0) complete
>nsopen: lcl[0]=0xe9ff, lcl[1]=0x0, gbl[0]=0x983f, gbl[1]=0x801,
>tdu=32767, sdu=2048
>nsdo: entry
>nsdo: cid=0, opcode=65, *bl=0, *what=0, uflgs=0x0, cflgs=0x2
>nsdo: nsctx: state=7, flg=0x4201, mvd=0
>nsmal: 2094 bytes at 0x200a65a8
>nsmal: 2094 bytes at 0x200a6de8
>nsdo: normal exit
>nsopen: normal exit
>nsdo: entry
>nsdo: cid=0, opcode=67, *bl=157, *what=8, uflgs=0x0, cflgs=0x3
>nsdo: nsctx: state=14, flg=0x4205, mvd=0
>nsdo: gtn=0, gtc=0, ptn=10, ptc=2048
>nscon: entry
>nscon: doing connect handshake...
>nscon: sending NSPTCN packet
>nspsend: entry
>nspsend: plen=191, type=1
>nttwr: entry
>nttwr: socket 14 had bytes written=191
>nttwr: exit
>nspsend: 191 bytes to transport
>nspsend:packet dump
>nspsend:00 BF 00 00 01 00 00 00 |........|
>nspsend:01 34 01 2C 08 01 08 00 |.4.,....|
>nspsend:7F FF 7B 08 00 00 00 01 |..{.....|
>nspsend:00 9D 00 22 00 00 08 00 |..."....|
>nspsend:09 09 28 44 45 53 43 52 |..(DESCR|
>nspsend:49 50 54 49 4F 4E 3D 28 |IPTION=(|
>nspsend:41 44 44 52 45 53 53 5F |ADDRESS_|
>nspsend:4C 49 53 54 3D 28 41 44 |LIST=(AD|
>nspsend:44 52 45 53 53 3D 28 50 |DRESS=(P|
>nspsend:52 4F 54 4F 43 4F 4C 3D |ROTOCOL=|
>nspsend:54 43 50 29 28 48 4F 53 |TCP)(HOS|
>nspsend:54 3D 39 2E 31 39 32 2E |T=9.192.|
>nspsend:33 34 2E 32 33 30 29 28 |34.230)(|
>nspsend:50 4F 52 54 3D 31 35 32 |PORT=152|
>nspsend:31 29 29 29 28 43 4F 4E |1)))(CON|
>nspsend:4E 45 43 54 5F 44 41 54 |NECT_DAT|
>nspsend:41 3D 28 53 49 44 3D 61 |A=(SID=a|
>nspsend:63 63 74 29 28 43 49 44 |cct)(CID|
>nspsend:3D 28 50 52 4F 47 52 41 |=(PROGRA|
>nspsend:4D 3D 29 28 48 4F 53 54 |M=)(HOST|
>nspsend:3D 63 74 73 76 65 6E 75 |=ctsvenu|
>nspsend:73 5F 73 74 64 62 79 29 |s_stdby)|
>nspsend:28 55 53 45 52 3D 74 6B |(USER=tk|
>nspsend:63 74 6C 29 29 29 29 00 |ctl)))).|
>nspsend: normal exit
>nscon: exit (0)
>nsdo: normal exit
>nsmal: 2048 bytes at 0x200a7628
>nsdo: entry
>nsdo: cid=0, opcode=68, *bl=2048, *what=9, uflgs=0x0, cflgs=0x3
>nsdo: nsctx: state=2, flg=0x4205, mvd=0
>nsdo: gtn=0, gtc=0, ptn=10, ptc=2048
>nscon: entry
>nscon: recving a packet
>nsprecv: entry
>nsprecv: reading from transport...
>nttrd: entry
>nttrd: socket 14 had bytes read=8
>nttrd: exit
>nsprecv: 8 bytes from transport
>nsprecv: tlen=8, plen=8, type=11
>nsprecv:packet dump
>nsprecv:00 08 00 00 0B 00 00 00 |........|
>nsprecv: normal exit
>nscon: got NSPTRS packet
>nscon: no connect data
>nscon: exit (0)
>nsdo: normal exit
>nsmfr: 2048 bytes at 0x200a7628
>nsdo: entry
>nsdo: cid=0, opcode=67, *bl=157, *what=8, uflgs=0x0, cflgs=0x3
>nsdo: nsctx: state=2, flg=0x4205, mvd=0
>nsdo: gtn=0, gtc=0, ptn=10, ptc=2048
>nscon: entry
>nscon: sending NSPTCN packet
>nspsend: entry
>nspsend: plen=191, type=1
>nttwr: entry
>nttwr: socket 14 had bytes written=191
>nttwr: exit
>nspsend: 191 bytes to transport
>nspsend:packet dump
>nspsend:00 BF 00 00 01 00 00 00 |........|
>nspsend:01 34 01 2C 08 01 08 00 |.4.,....|
>nspsend:7F FF 7B 08 00 00 00 01 |..{.....|
>nspsend:00 9D 00 22 00 00 08 00 |..."....|
>nspsend:09 09 28 44 45 53 43 52 |..(DESCR|
>nspsend:49 50 54 49 4F 4E 3D 28 |IPTION=(|
>nspsend:41 44 44 52 45 53 53 5F |ADDRESS_|
>nspsend:4C 49 53 54 3D 28 41 44 |LIST=(AD|
>nspsend:44 52 45 53 53 3D 28 50 |DRESS=(P|
>nspsend:52 4F 54 4F 43 4F 4C 3D |ROTOCOL=|
>nspsend:54 43 50 29 28 48 4F 53 |TCP)(HOS|
>nspsend:54 3D 39 2E 31 39 32 2E |T=9.192.|
>nspsend:33 34 2E 32 33 30 29 28 |34.230)(|
>nspsend:50 4F 52 54 3D 31 35 32 |PORT=152|
>nspsend:31 29 29 29 28 43 4F 4E |1)))(CON|
>nspsend:4E 45 43 54 5F 44 41 54 |NECT_DAT|
>nspsend:41 3D 28 53 49 44 3D 61 |A=(SID=a|
>nspsend:63 63 74 29 28 43 49 44 |cct)(CID|
>nspsend:3D 28 50 52 4F 47 52 41 |=(PROGRA|
>nspsend:4D 3D 29 28 48 4F 53 54 |M=)(HOST|
>nspsend:3D 63 74 73 76 65 6E 75 |=ctsvenu|
>nspsend:73 5F 73 74 64 62 79 29 |s_stdby)|
>nspsend:28 55 53 45 52 3D 74 6B |(USER=tk|
>nspsend:63 74 6C 29 29 29 29 00 |ctl)))).|
>nspsend: normal exit
>nscon: exit (0)
>nsdo: normal exit
>nsmal: 2048 bytes at 0x200a7628
>nsdo: entry
>nsdo: cid=0, opcode=68, *bl=2048, *what=9, uflgs=0x0, cflgs=0x3
>nsdo: nsctx: state=2, flg=0x4205, mvd=0
>nsdo: gtn=0, gtc=0, ptn=10, ptc=2048
>nscon: entry
>nscon: recving a packet
>nsprecv: entry
>nsprecv: reading from transport...
>nttrd: entry
>nttrd: socket 14 had bytes read=24
>nttrd: exit
>nsprecv: 24 bytes from transport
>nsprecv: tlen=24, plen=24, type=2
>nsprecv:packet dump
>nsprecv:00 18 00 00 02 00 00 00 |........|
>nsprecv:01 34 08 01 08 00 7F FF |.4......|
>nsprecv:00 01 00 00 00 18 09 08 |........|
>nsprecv: normal exit
>nscon: got NSPTAC packet
>nsconneg: entry
>nsconneg: vsn=308, gbl=0x801, sdu=2048, tdu=32767
>nsconneg: normal exit
>nscon: no connect data
>nscon: connect handshake is complete
>nscon: nsctxinf[0]=0x9, [1]=0x8
>nscon: normal exit
>nsdo: normal exit
>nsmfr: 2048 bytes at 0x200a7628
>nsnaconn: entry
>nsnaconn: inf->nsinfflg[0]: 0x9 inf->nsinfflg[1]: 0x8
>nsnaconn: NA services unavailable on both processes - negotiation not
>needed
>nscall: normal exit
>nricdt: Call successful: returned data
>nricdt: exit
>nricall: Failed to copy originating community name value binding
>nricall: Exiting NRICALL with following termination result 0
>nricall: exit
>osntns: osntns: passing ns handle back up...
>osntns: exit
>osnqsn: entry
>osnqsn: exit
>osnqrc: entry
>nsdo: entry
>nsdo: cid=0, opcode=84, *bl=0, *what=1, uflgs=0x20, cflgs=0x3
>nsdo: nsctx: state=8, flg=0x420d, mvd=0
>nsdo: gtn=24, gtc=24, ptn=10, ptc=2048
>nsdofls: entry
>nsdofls: DATA flags: 0x0
>nsdofls: sending NSPTDA packet
>nspsend: entry
>nspsend: plen=41, type=6
>nttwr: entry
>nttwr: socket 14 had bytes written=41
>nttwr: exit
>nspsend: 41 bytes to transport
>nspsend:packet dump
>nspsend:00 29 00 00 06 00 00 00 |.)......|
>nspsend:00 00 01 04 03 02 01 00 |........|
>nspsend:49 42 4D 20 41 49 58 2F |IBM AIX/|
>nspsend:52 53 36 30 30 30 20 33 |RS6000 3|
>nspsend:2E 32 2D 37 2E 30 2E 30 |.2-7.0.0|
>nspsend:00 00 00 00 00 00 00 00 |........|
>nspsend: normal exit
>nsdofls: exit (0)
>nsdo: normal exit
>nsdo: entry
>nsdo: cid=0, opcode=85, *bl=0, *what=0, uflgs=0x0, cflgs=0x3
>nsdo: nsctx: state=8, flg=0x420d, mvd=0
>nsdo: gtn=24, gtc=24, ptn=10, ptc=2048
>nsdo: switching to application buffer
>nsrdr: entry
>nsrdr: recving a packet
>nsprecv: entry
>nsprecv: reading from transport...
>nttrd: entry
>nttrd: socket 14 had bytes read=143
>nttrd: exit
>nsprecv: 143 bytes from transport
>nsprecv: tlen=143, plen=143, type=6
>nsprecv:packet dump
>nsprecv:00 8F 00 00 06 00 00 00 |........|
>nsprecv:00 00 01 04 00 49 42 4D |.....IBM|
>nsprecv:20 41 49 58 2F 52 53 36 | AIX/RS6|
>nsprecv:30 30 30 20 33 2E 32 2D |000 3.2-|
>nsprecv:37 2E 30 2E 30 00 61 03 |7.0.0.a.|
>nsprecv:01 14 00 01 00 5C 03 01 |.....\..|
>nsprecv:5C 03 01 00 0A 61 03 01 |\....a..|
>nsprecv:00 0A 01 00 61 03 01 5C |....a..\|
>nsprecv:03 61 03 07 61 03 5C 03 |.a..a.\.|
>nsprecv:02 01 00 5F 03 01 5F 03 |..._.._.|
>nsprecv:01 00 0A 01 00 5D 03 01 |.....]..|
>nsprecv:5D 03 01 00 0A 01 00 5E |]......^|
>nsprecv:03 01 5E 03 01 00 0A 66 |..^....f|
>nsprecv:03 61 03 01 61 03 66 03 |.a..a.f.|
>nsprecv:01 62 03 61 03 0A 61 03 |.b.a..a.|
>nsprecv:62 03 0A 60 03 61 03 03 |b..`.a..|
>nsprecv:61 03 60 03 04 60 03 5C |a.`..`.\|
>nsprecv:03 04 5C 03 60 03 07 00 |..\.`...|
>nsprecv: normal exit
>nsrdr: got NSPTDA packet
>nsrdr: NSPTDA flags: 0x0
>nsrdr: normal exit
>nsdo: *what=1, *bl=2038
>nsdo: normal exit
>osnqrc: exit
>osnqsn: entry
>osnqsn: exit
>osnqrc: entry
>nsdo: entry
>nsdo: cid=0, opcode=84, *bl=0, *what=1, uflgs=0x20, cflgs=0x3
>nsdo: nsctx: state=8, flg=0x420d, mvd=0
>nsdo: gtn=24, gtc=24, ptn=10, ptc=2048
>nsdofls: entry
>nsdofls: DATA flags: 0x0
>nsdofls: sending NSPTDA packet
>nspsend: entry
>nspsend: plen=16, type=6
>nttwr: entry
>nttwr: socket 14 had bytes written=16
>nttwr: exit
>nspsend: 16 bytes to transport
>nspsend:packet dump
>nspsend:00 10 00 00 06 00 00 00 |........|
>nspsend:00 00 02 61 03 61 03 01 |...a.a..|
>nspsend: normal exit
>nsdofls: exit (0)
>nsdo: normal exit
>nsdo: entry
>nsdo: cid=0, opcode=85, *bl=0, *what=0, uflgs=0x0, cflgs=0x3
>nsdo: nsctx: state=8, flg=0x420d, mvd=0
>nsdo: gtn=24, gtc=24, ptn=10, ptc=2048
>nsdo: switching to application buffer
>nsrdr: entry
>nsrdr: recving a packet
>nsprecv: entry
>nsprecv: reading from transport...
>nttrd: entry
>nttrd: socket 14 had bytes read=11
>nttrd: exit
>nsprecv: 11 bytes from transport
>nsprecv: tlen=11, plen=11, type=6
>nsprecv:packet dump
>nsprecv:00 0B 00 00 06 00 00 00 |........|
>nsprecv:00 00 02 00 00 00 00 00 |........|
>nsprecv: normal exit
>
>---------------------

Willias

If you go with the flow you will probably drown ! Received on Mon Jun 02 1997 - 00:00:00 CEST