Question :
I am getting a very long delay (about 2 minutes) opening initial connections on my 11g2 development server. Sometimes I get ORA-28547: connection to server failed, probable Oracle Net admin error and no connection at all.
However, the problem disappears on the second attempt.
The problem occurs with multiple clients: our app under development (using occi), SQLPlus, SQLDeveloper.
Edit: Additional information. Using strace, I see the client sqlplus establish a TCP connection on the correct port of our Oracle DB server. Some data is exchanged ok and then the client hangs on a socket read.
On a hung connection:
read(6,
On a good connection:
read(6, “ 274 6 16 x86_64/Linux 2.4.xx”…, 8208) = 188
The good connection receives AUTH_SESSKEY shortly after, which is used in the authentication. So the hang occurs before password authentication completes.
Here is the output from select * from v$sgainfo:
Fixed SGA Size 2212448 No
Redo Buffers 4980736 No
Buffer Cache Size 20971520 Yes
Shared Pool Size 155189248 Yes
Large Pool Size 29360128 Yes
Java Pool Size 4194304 Yes
Streams Pool Size 4194304 Yes
Shared IO Pool Size 0 Yes
Granule Size 4194304 No
Maximum SGA Size 263049216 No
Startup overhead in Shared Pool 75497472 No
Free SGA Memory Available 41943040
Edit:
LSNRCTL for Linux: Version 11.2.0.1.0 - Production on 12-NOV-2012 23:54:07
Copyright (c) 1991, 2009, Oracle. All rights reserved.
Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=xoesrpora)(PORT=1521)))
STATUS of the LISTENER
------------------------
Alias LISTENER
Version TNSLSNR for Linux: Version 11.2.0.1.0 - Production
Start Date 12-SEP-2012 18:17:27
Uptime 61 days 5 hr. 36 min. 39 sec
Trace Level off
Security ON: Local OS Authentication
SNMP OFF
Listener Parameter File /xoesrpora/linux/app/oracle/product/11.2.0/dbhome_1/network/admin/listener.ora
Listener Log File /xoesrpora/linux/app/oracle/diag/tnslsnr/xoesrpora/listener/alert/log.xml
Listening Endpoints Summary...
(DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora)(PORT=1521)))
Services Summary...
Service "achen_l1ads.xoesr" has 1 instance(s).
Instance "achenl1ads", status READY, has 2 handler(s) for this service...
Service "anpingl1ads.xoesr" has 1 instance(s).
Instance "anpingl1ads", status READY, has 2 handler(s) for this service...
Service "bgoldl1ads.xoesr" has 1 instance(s).
Instance "bgoldl1ads", status READY, has 2 handler(s) for this service...
Service "bjodev01.xoesr" has 1 instance(s).
Instance "bjodev01", status READY, has 2 handler(s) for this service...
Service "bjodev02" has 1 instance(s).
Instance "bjodev02", status READY, has 2 handler(s) for this service...
Service "chen_l1ads.xoesr" has 1 instance(s).
Instance "chenl1ads", status READY, has 2 handler(s) for this service...
Service "gtullyl1ads.xoesr" has 1 instance(s).
Instance "gtullyl1ads", status READY, has 2 handler(s) for this service...
Service "jbentley.xoesr" has 1 instance(s).
Instance "jbentley", status READY, has 2 handler(s) for this service...
Service "jbentleyina.xoesr" has 1 instance(s).
Instance "jbentleyina", status READY, has 2 handler(s) for this service...
Service "jmiller1ads.xoesr" has 1 instance(s).
Instance "jmiller1ads", status READY, has 2 handler(s) for this service...
Service "l1ads.xoesr" has 1 instance(s).
Instance "l1ads", status READY, has 2 handler(s) for this service...
Service "l1adsSWIT.xoesr" has 1 instance(s).
Instance "l1adsSWIT", status READY, has 2 handler(s) for this service...
Service "mikedb.xoesrpora" has 1 instance(s).
Instance "mikedb", status READY, has 2 handler(s) for this service...
Service "nkovoorl1ads.xoesr" has 1 instance(s).
Instance "nkovoorl1ads", status READY, has 2 handler(s) for this service...
Service "nrekerl1ads.xoesr" has 1 instance(s).
Instance "nrekerl1ads", status READY, has 2 handler(s) for this service...
The command completed successfully
xoesrpora[51]$ lsnrctl service
LSNRCTL for Linux: Version 11.2.0.1.0 - Production on 12-NOV-2012 23:55:07
Copyright (c) 1991, 2009, Oracle. All rights reserved.
Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=xoesrpora)(PORT=1521)))
Services Summary...
Service "achen_l1ads.xoesr" has 1 instance(s).
Instance "achenl1ads", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:5 refused:0 current:0 max:1022 state:ready
DISPATCHER <machine: xoesrpora, pid: 30680>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora)(PORT=34877))
Service "anpingl1ads.xoesr" has 1 instance(s).
Instance "anpingl1ads", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:39033 refused:0 current:16 max:1022 state:ready
DISPATCHER <machine: xoesrpora, pid: 31454>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora)(PORT=13523))
Service "bgoldl1ads.xoesr" has 1 instance(s).
Instance "bgoldl1ads", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:40133 refused:5 current:17 max:1022 state:ready
DISPATCHER <machine: xoesrpora, pid: 22276>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora)(PORT=16808))
Service "bjodev01.xoesr" has 1 instance(s).
Instance "bjodev01", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:0 refused:0 current:2 max:1022 state:ready
DISPATCHER <machine: xoesrpora, pid: 1112>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora)(PORT=9362))
Service "bjodev02" has 1 instance(s).
Instance "bjodev02", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:5324 refused:0 current:7 max:1022 state:ready
DISPATCHER <machine: xoesrpora.aer.com, pid: 402>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora.aer.com)(PORT=43643))
Service "chen_l1ads.xoesr" has 1 instance(s).
Instance "chenl1ads", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:49787 refused:0 current:15 max:1022 state:ready
DISPATCHER <machine: xoesrpora, pid: 9501>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora)(PORT=57313))
Service "gtullyl1ads.xoesr" has 1 instance(s).
Instance "gtullyl1ads", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:17384 refused:0 current:20 max:1022 state:ready
DISPATCHER <machine: xoesrpora.aer.com, pid: 26905>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora.aer.com)(PORT=50258))
Service "jbentley.xoesr" has 1 instance(s).
Instance "jbentley", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:0 refused:0 current:0 max:1022 state:ready
DISPATCHER <machine: xoesrpora.aer.com, pid: 10737>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora.aer.com)(PORT=52195))
Service "jbentleyina.xoesr" has 1 instance(s).
Instance "jbentleyina", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:17 refused:0 state:ready
LOCAL SERVER
"D000" established:8993 refused:0 current:14 max:1022 state:ready
DISPATCHER <machine: xoesrpora.aer.com, pid: 18471>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora.aer.com)(PORT=28700))
Service "jmiller1ads.xoesr" has 1 instance(s).
Instance "jmiller1ads", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:25215 refused:0 current:17 max:1022 state:ready
DISPATCHER <machine: xoesrpora.aer.com, pid: 6473>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora.aer.com)(PORT=64221))
Service "l1ads.xoesr" has 1 instance(s).
Instance "l1ads", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:9049 refused:0 current:17 max:1022 state:ready
DISPATCHER <machine: xoesrpora, pid: 18150>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora)(PORT=52593))
Service "l1adsSWIT.xoesr" has 1 instance(s).
Instance "l1adsSWIT", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:4144 refused:0 current:20 max:1022 state:ready
DISPATCHER <machine: xoesrpora.aer.com, pid: 26656>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora.aer.com)(PORT=45006))
Service "mikedb.xoesrpora" has 1 instance(s).
Instance "mikedb", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:0 refused:0 current:2 max:1022 state:ready
DISPATCHER <machine: xoesrpora, pid: 17111>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora)(PORT=34540))
Service "nkovoorl1ads.xoesr" has 1 instance(s).
Instance "nkovoorl1ads", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:32557 refused:0 current:12 max:1022 state:ready
DISPATCHER <machine: xoesrpora, pid: 3601>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora)(PORT=21440))
Service "nrekerl1ads.xoesr" has 1 instance(s).
Instance "nrekerl1ads", status READY, has 2 handler(s) for this service...
Handler(s):
"DEDICATED" established:0 refused:0 state:ready
LOCAL SERVER
"D000" established:41491 refused:0 current:7 max:1022 state:ready
DISPATCHER <machine: xoesrpora, pid: 25743>
(ADDRESS=(PROTOCOL=tcp)(HOST=xoesrpora)(PORT=17368))
The command completed successfully
Answer :
The appropriate method will be sqlnet tracing. Configuration is described in Net Services Reference
the output is useful for oracle support. As far as I know it there is now documentation published but you can try to get some clues
set the following parameters in the sqlnet.ora of the client (the client must use tnsnames.ora)
DIAG_ADR_ENABLED=on trace_directory_client= trace_level_client=admin trace_uniqe_client=on trace_timestamp_client=on
if this is not a production system you should also enable tracing in the sqlnet.ora of the database server:
DIAG_ADR_ENABLED=on trace_directory_server= trace_level_server=admin trace_uniqe_server=on trace_timestamp_server=on
Using the timestamp information of each traces enables you to synchronisize the output of server and client files.
There is also a tool trcasst in the $ORACLE_HOME/bin directory that analyzes sqlnet traces (but only if you have trace_timesamp...=off). Here you can find some hints. But maybe the raw trace is of more use.
Also you can reduce the size of the trace information if you set trace_level_...=user or admin.