2

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, "\0\274\0\0\6\0\0\0\0\0\1\6\0x86_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
Improve this question
15
  • See stackoverflow.com/questions/10353869/…
    – ali köksal
    Nov 8, 2012 at 20:30
  • @alikox, I saw that. As I said, I am seeing the problem also using occi, which bypasses tnsnames.ora entirely.
    – ThomasMcLeod
    Nov 8, 2012 at 20:35
  • 1
    Sounds like a reverse dns lookup problem, or something similar
    – Philᵀᴹ
    Nov 8, 2012 at 21:58
  • @Phil, pings to the server are fast.
    – ThomasMcLeod
    Nov 8, 2012 at 22:10
  • I'm not asking anyone to guess. I want to know how to run the appropriate trace or turn on the appropriate debug logging for this problem.
    – ThomasMcLeod
    Nov 8, 2012 at 22:12

1 Answer 1

Reset to default
1
+50

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.

Improve this answer

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.