This discussion is archived
1 2 Previous Next 18 Replies Latest reply: Nov 13, 2012 1:06 PM by Colin'tHart RSS

Long delay on initial connection.

973867 Newbie
Currently Being Moderated
I am getting a very long delay (about 2 minutes) opening initial connections on my 11g2 development server. Sometimes I get "ORA-28547" and no connection at all. However, the problem disappears on the second attempt.

The problem occurs with multiple clients: our app under development (which uses occi), SQLPlus, SQLDeveloper.

I am looking for debugging instructions, or information on how to setup the appropriate trace, etc.

Additional Information:
Using strace on Linux, 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.
  • 1. Re: Long delay on initial connection.
    sb92075 Guru
    Currently Being Moderated
    970864 wrote:
    I am getting a very long delay (about 2 minutes) opening initial connections on my 11g2 development server. Sometimes I get "ORA-28547" and no connection at all. However, the problem disappears on the second attempt.
    28547, 0000, "connection to server failed, probable Oracle Net admin error"
    // *Cause:   A failure occurred during initialization of a network connection
    //           from a client process to the Oracle server.  The connection
    //           was completed but a disconnect occurred while trying to
    //           perform protocol-specific initialization, usually due to
    //           use of different network protocols by opposite sides
    //           of the connection.  This usually is caused by incorrect
    //           Oracle Net administrative setup for database links or external
    //           procedure calls.   The most frequent specific causes are:
    //           --  The connection uses a connect string which refers
    //               to a Heterogeneous Services agent instead of
    //               an Oracle server.
    //           --  The connection uses a connect string which includes
    //               an (HS=) specification.
    //           --  Hitting Ctrl+C before connection initialization is
    //               complete.
    //           --  Using DRCP on Windows with SQLNET.AUTHENTICATION_SERVICES
    //               set to NTS.
    //           --  Connection timeout due to SQLNET.INBOUND_CONNECT_TIMEOUT
    //               parameter when all shared servers are busy in
    //               shared server configuration.
    // *Action:  Check Oracle Net administration in the following ways:
    //           --  When using TNSNAMES.ORA or an Oracle Names server, make sure
    //               that the client connection to the Oracle server uses
    //               the correct service name or SID.
    //           --  Check LISTENER.ORA on the connection end point's host machine
    //               to assure that this service name or SID refers
    //               to the correct server.
    //           --  Confirm in TNSNAMES.ORA or the equivalent service definition
    //               that the connect string does not contain (HS=).
    //           --  Set SQLNET.AUTHENTICATION_SERVICES to NONE when using DRCP
    //               on Windows.
    //
    post results from following OS commands below

    lsnrctl status
    lsnrctl service
  • 2. Re: Long delay on initial connection.
    973867 Newbie
    Currently Being Moderated
    Yes, we have taken all of those steps and no progress. It is worth noting that occi instant client does not use tnsnames infrastructure.
  • 3. Re: Long delay on initial connection.
    sb92075 Guru
    Currently Being Moderated
    How do I ask a question on the forums?
    SQL and PL/SQL FAQ

    see we don't even know OS name or version or which version of Oracle is involved.
    970864 wrote:
    Yes, we have taken all of those steps and no progress. It is worth noting that occi instant client does not use tnsnames infrastructure.
    since you choose to purposefully disregard a polite request for details,
    I choose to waste no more of my time trying to assist.

    You're On Your Own (YOYO)!

    enjoy your mystery
  • 4. Re: Long delay on initial connection.
    973867 Newbie
    Currently Being Moderated
    @sb92075, have a nice life.
  • 5. Re: Long delay on initial connection.
    973867 Newbie
    Currently Being Moderated
    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
  • 6. Re: Long delay on initial connection.
    jgarry Guru
    Currently Being Moderated
    17 instances on a server is rarely a good sign. It could simply mean you are running out of some OS resource.

    Do a netstat -a and see if you have a lot of WAIT statuses - that could mean you have a lot of things dying and using some tcp timeout to clean up, rather than a quicker proper close protocol.

    Check if you OCCI is opening a new connection each time, that would be a bad thing.

    Check for OCCI bugs fixed in the later patch sets than you have, like MOS Using setPrefetchRowCount in OCCI causes application to dump on closeResultSet [ID 8645094.8]

    Listen to SB, he is (or was) trying to help you. Surround your output with
     tags to make it legible, use the Preview tab to check.                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        
  • 7. Re: Long delay on initial connection.
    973867 Newbie
    Currently Being Moderated
    @jgarry, thanks. The instances are nearly all inactive most of the time, and our instance is the only one experiencing this problem.
    There are no WAIT states on netstat -a.
    Occi, is opening and closing connections in rapid succession. (That's a choice of our testing framework, not ours.) This is a dev environment, not production. The delay occurs with SQLPlus and SQLDev as well, which leads me to believe it's not occi.
  • 8. Re: Long delay on initial connection.
    Osama_Mustafa Oracle ACE
    Currently Being Moderated
    970864 wrote:
    @jgarry, thanks. The instances are nearly all inactive most of the time, and our instance is the only one experiencing this problem.
    There are no WAIT states on netstat -a.
    Occi, is opening and closing connections in rapid succession. (That's a choice of our testing framework, not ours.) This is a dev environment, not production. The delay occurs with SQLPlus and SQLDev as well, which leads me to believe it's not occi.
    How can they been inactive !!!

    you use 17 instance on same server , What server resource you have ?
  • 9. Re: Long delay on initial connection.
    Osama_Mustafa Oracle ACE
    Currently Being Moderated
    Check MOS :
    Isolating Connection Delays [ID 1359821.1]


    Post sqlnet.ora
  • 10. Re: Long delay on initial connection.
    jgarry Guru
    Currently Being Moderated
    Well, if your OCCI is using up all the resources, that would affect sqlplus too. Unless you are saying you aren't doing OCCI when you see it in sqlplus.

    I wonder if this is one of those odd situations where you do want to use multiple listeners. Maybe all those instances sending heartbeats are causing issues. Do you still see the problem when you shut down the "inactive" instances? Something is always happening, even when your database is bored. Tell us the physical characteristics of your server, are you using large pages, etc.
  • 11. Re: Long delay on initial connection.
    973867 Newbie
    Currently Being Moderated
    @Osama, they are inactive in the sense that there are no open sessions. It's a Dell i7 quad-core server with 8GB ram. It's not RAIDed though.

    Edited by: 970864 on Nov 13, 2012 9:18 AM
  • 12. Re: Long delay on initial connection.
    jgarry Guru
    Currently Being Moderated
    That is one informative paper. Did you notice the reference to the dns bug?
  • 13. Re: Long delay on initial connection.
    973867 Newbie
    Currently Being Moderated
    @Osama, there no Sqlnet.ora file in $ORACLE_HOME/network/admin directory.
  • 14. Re: Long delay on initial connection.
    KeenOnOracle Explorer
    Currently Being Moderated
    I had similar issue resolved after setting the sqlnet.ora parameter

    from SQLNET.AUTHENTICATION_SERVICES= (NTS)

    to SQLNET.AUTHENTICATION_SERVICES= (NONE)
1 2 Previous Next

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points