Re: Slow connection to Oracle 10

From: Michael Austin <maustin_at_firstdbasource.com>
Date: Thu, 04 Sep 2008 21:48:56 -0500
Message-ID: <%81wk.8594$np7.1442@flpi149.ffdc.sbc.com>

Michael D O'Shea wrote:

> On Sep 2, 11:34 am, "Shakespeare" <what..._at_xs4all.nl> wrote:

>> "Michael D O'Shea" <michael.os..._at_tessella.com> schreef in berichtnews:0232f938-805d-4d51-95df-90534d19fb1f_at_k30g2000hse.googlegroups.com...
>>
>>
>>
>>
>>
>>> All, my problem is one of a "slow connection to Oracle".
>>> The box is Windows 2K SP4 with Oracle version. Oracle has been
>>> installed as part of a third party application validated with this OS.
>>> SQL> SELECT * FROM V$VERSION;
>>> BANNER
>>> ----------------------------------------------------------------
>>> Oracle Database 10g Enterprise Edition Release 10.1.0.4.0 - Prod
>>> PL/SQL Release 10.1.0.4.0 - Production
>>> CORE 10.1.0.4.0 Production
>>> TNS for 32-bit Windows: Version 10.1.0.4.0 - Production
>>> NLSRTL Version 10.1.0.4.0 - Production
>>> SQL>
>>> To aid in support for my usenet query, my sqlnet.ora file contains
>>> SQLNET.AUTHENTICATION_SERVICES = (NTS)
>>> TRACE_DIRECTORY_CLIENT=c:\temp
>>> TRACE_LEVEL_CLIENT=SUPPORT
>>> The trace file produced shows connect delay in excess of 30 seconds.
>>> The server is idle and there are no real competing CPU processes.
>>> I have included part of the trace file below.
>>> The full unadulterated trace file can be viewed at
>>> http://www.strychnine.co.uk/cdos/cli_736_1.txt
>>> Any ideas on where I should look next or what might be the cause of
>>> the underlying problem would be most welcome.
>>> Thank you in advance
>>> TESSELLA Michael.OS..._at_tessella.com
>>> __/__/__/ Tessella Support Services plc
>>> __/__/__/ 3 Vineyard Chambers, ABINGDON, OX14 3PX, England
>>> __/__/__/ Tel: (44)(0)1235-555511 Fax: (44)(0)1235-553301
>>> www.tessella.com Registered in England No. 1466429
>>> [02-SEP-2008 10:30:20:281] --- TRACE CONFIGURATION INFORMATION FOLLOWS
>>> ---
>>> [02-SEP-2008 10:30:20:281] New trace stream is c:\temp\cli_736_1.trc
>>> [02-SEP-2008 10:30:20:281] New trace level is 16
>>> [02-SEP-2008 10:30:20:281] --- TRACE CONFIGURATION INFORMATION ENDS
>>> ---
>>> [02-SEP-2008 10:30:20:281] --- PARAMETER SOURCE INFORMATION FOLLOWS
>>> ---
>>> [02-SEP-2008 10:30:20:281] Attempted load of system pfile source C:
>>> \3RDPARTYPRODUCT\Oracle\Oracle10g\network\admin\sqlnet.ora
>>> [02-SEP-2008 10:30:20:281] Parameter source loaded successfully
>>> [02-SEP-2008 10:30:20:281]
>>> [02-SEP-2008 10:30:20:281] Attempted load of local pfile source C:
>>> \Documents and Settings\TESTX\sqlnet.ora
>>> [02-SEP-2008 10:30:20:281] Parameter source was not loaded
>>> [02-SEP-2008 10:30:20:281]
>>> [02-SEP-2008 10:30:20:281] -> PARAMETER TABLE LOAD RESULTS FOLLOW <-
>>> [02-SEP-2008 10:30:20:281] Successful parameter table load
>>> [02-SEP-2008 10:30:20:281] -> PARAMETER TABLE HAS THE FOLLOWING
>>> CONTENTS <-
>>> [02-SEP-2008 10:30:20:281] TRACE_DIRECTORY_CLIENT = c:\temp
>>> [02-SEP-2008 10:30:20:281] SQLNET.AUTHENTICATION_SERVICES = (NTS)
>>> [02-SEP-2008 10:30:20:281] TRACE_LEVEL_CLIENT = SUPPORT
>>> [02-SEP-2008 10:30:20:281] --- PARAMETER SOURCE INFORMATION ENDS ---
>>> [02-SEP-2008 10:30:20:281] --- LOG CONFIGURATION INFORMATION FOLLOWS
>>> ---
>>> [02-SEP-2008 10:30:20:281] Log stream will be "C:\Documents and
>>> Settings\TESTX\sqlnet.log"
>>> [02-SEP-2008 10:30:20:281] Log stream validation not requested
>>> [02-SEP-2008 10:30:20:281] --- LOG CONFIGURATION INFORMATION ENDS ---
>>> [02-SEP-2008 10:30:20:281] nigini: entry
>>> [02-SEP-2008 10:30:20:281] nigini: Count in the NL global area is now
>>> 1
>>> [02-SEP-2008 10:30:20:281] nigini: Count in NI global area now: 1
>>> [02-SEP-2008 10:30:20:281] nrigbi: entry
>>> [02-SEP-2008 10:30:20:281] nrigbni: entry
>>> //lots of stuff deleted
>>> [02-SEP-2008 10:30:20:640] nsdo: cid=0, opcode=68, *bl=2048, *what=0,
>>> uflgs=0x0, cflgs=0x3
>>> [02-SEP-2008 10:30:20:640] nsdo: rank=64, nsctxrnk=0
>>> [02-SEP-2008 10:30:20:640] nsdo: nsctx: state=8, flg=0x102400d, mvd=0
>>> [02-SEP-2008 10:30:20:640] nsdo: gtn=32, gtc=32, ptn=10, ptc=2011
>>> [02-SEP-2008 10:30:20:640] nsrdr: entry
>>> [02-SEP-2008 10:30:20:640] nsrdr: recving a packet
>>> [02-SEP-2008 10:30:20:640] nsprecv: entry
>>> [02-SEP-2008 10:30:20:640] nsprecv: reading from transport...
>>> [02-SEP-2008 10:30:20:640] nttrd: entry
>>> [02-SEP-2008 10:30:35:640] nttrd: socket 668 had bytes read=163
>>> [02-SEP-2008 10:30:35:640] nttrd: exit
>>> [02-SEP-2008 10:30:35:640] nsprecv: 163 bytes from transport
>>> [02-SEP-2008 10:30:35:640] nsprecv: tlen=163, plen=163, type=6
>>> [02-SEP-2008 10:30:35:640] nsprecv: packet dump
>>> [02-SEP-2008 10:30:35:640] nsprecv: 00 A3 00 00 06 04 00 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 00 00 DE AD BE EF 00 99
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 0A 10 04 00 00 04 00 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 04 00 03 00 00 00 00 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 04 00 05 0A 10 04 00 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 02 00 06 00 1F 00 0E 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 01 DE AD BE EF 00 03 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 00 00 02 00 04 00 01 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 01 00 07 00 00 00 00 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 04 00 05 0A 10 04 00 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 02 00 06 FA FF 00 01 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 02 01 00 03 00 00 4E 54
>>> |......NT|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 53 00 04 00 05 02 00 00 |
>>> S.......|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 00 00 04 00 04 00 00 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 00 00 04 00 04 00 00 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 02 00 02 00 02 00 00 00
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 00 00 04 00 05 0A 10 04
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 00 00 01 00 02 00 00 03
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 00 02 00 00 00 00 00 04
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 00 05 0A 10 04 00 00 01
>>> |........|
>>> [02-SEP-2008 10:30:35:640] nsprecv: 00 02 00 |...
>>> |
>>> [02-SEP-2008 10:30:35:640] nsprecv: normal exit
>>> [02-SEP-2008 10:30:35:640] nsrdr: got NSPTDA packet
>>> [02-SEP-2008 10:30:35:640] nsrdr: NSPTDA flags: 0x0
>>> //lots of stuff deleted
>>> [02-SEP-2008 10:30:35:640] nacomrp: exit
>>> [02-SEP-2008 10:30:35:656] nau_rpv: Version received for 32-bit
>>> Windows: Version 10.1.0.4.0 - UNKNOWN
>>> [02-SEP-2008 10:30:35:656] nau_rpv: Connection version for 32-bit
>>> Windows: Version 10.1.0.4.0 - UNKNOWN
>>> [02-SEP-2008 10:30:35:656] nau_rpv: adapter version communication is
>>> supported by other process
>>> [02-SEP-2008 10:30:35:656] nau_rpv: exit
>>> [02-SEP-2008 10:30:35:656] nau_cga: entry
>>> [02-SEP-2008 10:30:35:656] nacomrp: entry
>>> [02-SEP-2008 10:30:35:656] nacomrp: exit
>>> [02-SEP-2008 10:30:35:656] nacomrp: entry
>>> [02-SEP-2008 10:30:35:656] nacomrp: exit
>>> [02-SEP-2008 10:30:35:656] nacomrp: entry
>>> [02-SEP-2008 10:30:35:656] nacomrp: exit
>>> [02-SEP-2008 10:30:35:656] nau_cga: client received negotiated adapter
>>> - type: auth. service name: NTS
>>> [02-SEP-2008 10:30:35:656] nau_gse: entry
>>> [02-SEP-2008 10:30:35:656] nau_fad: entry
>>> [02-SEP-2008 10:30:35:656] nau_fad: searching for "NTS" adapter
>>> [02-SEP-2008 10:30:35:656] nau_fad: supported adapter: "KERBEROS5"
>>> [02-SEP-2008 10:30:35:656] nau_fad: supported adapter: "NTS"
>>> [02-SEP-2008 10:30:35:656] nau_fad: exit
>>> [02-SEP-2008 10:30:35:656] naunts: entry
>>> [02-SEP-2008 10:30:35:656] naunts5: entry
>>> [02-SEP-2008 10:30:50:656] naunts5: exit
>>> [02-SEP-2008 10:30:50:656] naunts: exit
>>> [02-SEP-2008 10:30:50:656] nauninit: entry
>>> [02-SEP-2008 10:30:50:656] naun5init: entry
>>> [02-SEP-2008 10:30:50:656] naun5init: Connection type is: 0
>>> [02-SEP-2008 10:30:50:671] naun5init: exit
>>> [02-SEP-2008 10:30:50:671] nauninit: exit
>>> [02-SEP-2008 10:30:50:671] nau1saai_adapter_info: exit
>>> [02-SEP-2008 10:30:50:671] nam_gnsp: Reading parameter
>>> "sqlnet.server_authentication" from parameter file
>>> [02-SEP-2008 10:30:50:671] nam_gnsp: Parameter not found
>>> [02-SEP-2008 10:30:50:671] nau1saai_adapter_info: Using default value
>>> "OFF"
>>> [02-SEP-2008 10:30:50:671] nau1saai_adapter_info: Adapter does not
>>> support SA, because there is no control function
>>> [02-SEP-2008 10:30:50:671] nau1saai_adapter_info: exit
>>> [02-SEP-2008 10:30:50:671] nau_gse: exit
>>> [02-SEP-2008 10:30:50:671] nau_cga: exit
>>> [02-SEP-2008 10:30:50:671] nau_rai: entry
>> Does SQLNET.AUTHENTICATION_SERVICES = (NONE) speed up the process?
>>
>> Shakespeare- Hide quoted text -
>>
>> - Show quoted text -

> 
> Shakespeare - spot on!
> Many thanks
> Mike
> 
> TESSELLA   Michael.OS..._at_tessella.com
>  __/__/__/  Tessella Support Services plc
>  __/__/__/  3 Vineyard Chambers, ABINGDON, OX14 3PX, England
>  __/__/__/  Tel: (44)(0)1235-555511  Fax: (44)(0)1235-553301
> www.tessella.com   Registered in England No. 1466429
>

Also, make sure you in your BIOS that you have hyperthreading turned OFF. As of 10.2.0.2, it was almost twice as fast turning this off. Not sure why this occurred, but it was consistent on more than 15 different x86 servers (HP, Dell, Compaq (it was ~2 years ago) NT2000/2003/XP) Received on Thu Sep 04 2008 - 21:48:56 CDT

This message: [ Message body ]
Next message: DG problem: "Finding a SQL bug in 9.2.0.8"
Previous message: phil_herring_at_yahoo.com.au: "Re: displaying clob in sqlplus/toad"
In reply to: Michael D O'Shea: "Re: Slow connection to Oracle 10"
Next in thread: joel garry: "Re: Slow connection to Oracle 10"
Reply: joel garry: "Re: Slow connection to Oracle 10"

Contemporary messages sorted: [ by date ] [ by thread ] [ by subject ] [ by author ]

Original text of this message