Josh-Daniel S. Davis (joshdavis) wrote,
Josh-Daniel S. Davis
joshdavis

Connections To 11g TNS Listener are Slow.

GRRR. This was nowhere to be found on the public internet.
Doc ID: 	561429.1 	Type: 	PROBLEM
Modified Date: 	17-DEC-2008 	Status: PUBLISHED

In this Document
Symptoms
Cause
Solution
References

Applies to:
Oracle Net Services - Version: 11.1.0.6.0
This problem can occur on any platform.

Symptoms
Connections to 11g TNS Listener are slow and can take anywhere from 10 seconds to 2 minutes.
On connection handshake, Oracle Net client trace shows the delay between 1st Connect Packet and Resend packet
09:59:57.552261 : nttrd:entry
10:00:37.578836 : nttrd:socket 11 had bytes read=8
10:00:37.578894 : nttrd:exit
10:00:37.578918 : nsprecv:8 bytes from transport
10:00:37.578943 : nsprecv:tlen=8, plen=8, type=11
10:00:37.578966 : nsprecv:packet dump
10:00:37.578987 : nsprecv:00 08 00 00 0B 00 00 00  |........|
Oracle Net Listener trace shows the delay around the fork
09:59:57.575893 : ntpwr:exit 
09:59:57.575911 : ntprd:entry 
10:00:37.578078 : ntprd:exit 
10:00:37.578181 : ntprd:entry 
10:00:37.578482 : ntprd:exit 
10:00:37.578501 : nsbequeath:NSE=12586 
10:00:37.578520 : nsbequeath:error reading REDIR/NSE msg
Note NSE=12586 is just a complete code and not an error

Cause
Bug 6874286 Dedicate connection that use the listener take about 40 seconds to establised was logged for the issue, but confirmed as not a bug.
Strace / Truss of the TNS listener process on connection, along with TNS listener trace
strace -frT -o -p

Shows process ID of the fork as sntpcall:result string is NTP0 20742
09:59:57.575582 : sntpcall:result string is NTP0 20742
09:59:57.575610 : sntpcall:exit
09:59:57.575626 : ntpctl:exit
09:59:57.575664 : nttaddr2bnd:entry
09:59:57.575683 : snlinGetNameInfo:entry
09:59:57.575700 : snlinGetNameInfo:exit
09:59:57.575717 : nttaddr2bnd:Resolved to 192.168.132.6
09:59:57.575738 : nttaddr2bnd:exit
09:59:57.575761 : nsbequeath_stg2:doing connect handshake...
09:59:57.575779 : nsbequeath:doing connect handshake...
09:59:57.575796 : ntpwr:entry
09:59:57.575820 : ntpwr:exit
09:59:57.575838 : ntpwr:entry
09:59:57.575857 : ntpwr:exit
09:59:57.575874 : ntpwr:entry
09:59:57.575893 : ntpwr:exit
09:59:57.575911 : ntprd:entry  
10:00:37.578078 : ntprd:exit   
Process 20742 for the strace/truss shows delay between file descriptors (FD) 10 and 11
strace:20742      0.000062 poll([{fd=10, events=POLLIN}], 1, 5000) = 0 
<5.000045>
strace:20742      5.000105 socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 11 
<0.000021>
strace:20742      0.000050 connect(11, {sa_family=AF_INET, 
sin_port=htons(53), sin_addr=inet_addr("111.111.111.1")}, 28) = 0 <0.000014>
And further delays seen for file descriptors 10 & 11
strace:20742      0.000044 poll([{fd=10, events=POLLOUT, revents=POLLOUT}], 
1, 0) = 1 <0.000009>
strace:20742      0.000062 poll([{fd=10, events=POLLIN}], 1, 5000) = 0 
<5.000045>
strace:20742      0.000034 poll([{fd=11, events=POLLOUT, revents=POLLOUT}], 
1, 0) = 1 <0.000009>
File descriptors 10 and 11 show the following
connect(10, {sa_family=AF_INET, sin_port=htons(53),  
sin_addr=inet_addr("111.111.111.1") 
connect(11, {sa_family=AF_INET, sin_port=htons(53),  
sin_addr=inet_addr("222.222.222.2") 

These are the addresses of your DNS servers

Solution
Resolve underlying issues with DNS resolution. Using a local host file only is not an option as DNS is required for the function call.
References
Bug 6874286 - DEDICATED CONNECTIONS THAT USE THE LISTENER TAKES ABOUT 40 SECONDS TO ESTABLISH
Keywords
ORACLE~NET ; PERFORMANCE ;
Tags: oracle
Subscribe
  • Post a new comment

    Error

    Anonymous comments are disabled in this journal

    default userpic

    Your reply will be screened

    Your IP address will be recorded 

  • 2 comments