?

Log in

No account? Create an account

Josh-D. S. Davis

Xaminmo / Omnimax / Max Omni / Mad Scientist / Midnight Shadow / Radiation Master

Previous Entry Share Next Entry
Connections To 11g TNS Listener are Slow.
Josh 201604 KWP
joshdavis
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:


  • 1
(Deleted comment)
Because Oracle is SNEAKY!

  • 1