[Date Prev][Date Next] [Chronological] [Thread] [Top]

OpenLDAP -> Active Directory occasionally takes 60 seconds to return query results??



Apologies if this is a duplicate post.  I never saw it on the
list and it's not in the list archive at openldap.org.
-------------------------------------------------------------

I have an interesting problem and before I go over to the Microsoft
Active Directory groups I want to eliminate OpenLDAP as the culprit.

I have Postfix configured to verify recipients in Active Directory
using OpenLDAP (Postfix and OpenLDAP running on Fedora Core 2).
99.5% of the time, the Active Directory server responds to LDAP
Search Requests within 1 millisecond (based on an Ethereal trace).

Every once in a while, the response takes 60-70 seconds.  What I
see in the Ethereal trace then is a series of TCP-level retransmissions
followed by an LDAP "Abandon Request" packet.  This is followed by
two more TCP-level retransmissions of the search request.  Fifteen
seconds after the LDAP "Abandon Request", the client receives a
TCP ACK packet for the Abandon, followed immediately by the response
(with ACK) to the original Search Request.  The client (OpenLDAP)
then RSTs the connection.  PostFix treats all this as a "temporary
lookup failure".  The symptoms point to something causing a long
delay in packet transmission (without actual packet loss) since the
retransmission is happening in the TCP layer and the A/D server
eventually responds to the original Search Request.

Questions:

1) Has anyone seen this behavior?

2) I seriously doubt OpenLDAP has anything to do with the problem.
    Anyone believe otherwise, and if so, why?

I've attached a short text file with the packet summary from Ethereal.

--
James Garrison                                Athens Group, Inc.
mailto:jhg@athensgroup.com                    5608 Parkcrest Dr
http://www.athensgroup.com                    Austin, TX 78731
PGP: RSA=0x92E90A3B DH/DSS=0x498D331C         (512) 345-0600 x150


No.     Time            Source                Destination           Protocol Info
  10712 01:27:24.962048 10.10.236.238         10.56.8.232           LDAP     MsgId=44 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10713 01:27:24.962659 10.56.8.232           10.10.236.238         LDAP     MsgId=44 Search Result
  10714 01:27:25.001793 10.10.236.238         10.56.8.232           TCP      43225 > ldap [ACK] Seq=4856 Ack=1076 Win=6912 Len=0 TSV=3942818843 TSER=39426459
  10715 01:27:45.750293 10.56.8.232           10.56.8.255           BROWSER  Local Master Announcement TRITON, Workstation, Server, Domain Controller, Time Source, NT Workstation, Master Browser, Unknown server type:23
  10716 01:30:02.633475 10.10.236.238         10.56.8.232           LDAP     MsgId=45 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10717 01:30:02.634271 10.56.8.232           10.10.236.238         LDAP     MsgId=45 Search Entry, 1 result
  10718 01:30:02.634349 10.10.236.238         10.56.8.232           TCP      43225 > ldap [ACK] Seq=4972 Ack=1203 Win=6912 Len=0 TSV=3942976499 TSER=39428036
  10719 01:30:25.178621 10.10.236.238         10.56.8.232           TCP      33976 > ldap [SYN] Seq=0 Ack=0 Win=5840 Len=0 MSS=1460 TSV=3942999047 TSER=0 WS=2
  10720 01:30:25.179219 10.56.8.232           10.10.236.238         TCP      ldap > 33976 [SYN, ACK] Seq=0 Ack=1 Win=65535 Len=0 MSS=1460 WS=0 TSV=0 TSER=0
  10721 01:30:25.179285 10.10.236.238         10.56.8.232           TCP      33976 > ldap [ACK] Seq=1 Ack=1 Win=5840 Len=0 TSV=3942999047 TSER=0
  10722 01:30:25.179399 10.10.236.238         10.56.8.232           LDAP     MsgId=1 Bind Request, DN=cn=ldapQuery,cn=Users,dc=athens,dc=int
  10723 01:30:25.181041 10.56.8.232           10.10.236.238         LDAP     MsgId=1 Bind Result
  10724 01:30:25.181092 10.10.236.238         10.56.8.232           TCP      33976 > ldap [ACK] Seq=62 Ack=23 Win=5840 Len=0 TSV=3942999049 TSER=39428262
  10725 01:30:25.181305 10.10.236.238         10.56.8.232           LDAP     MsgId=2 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10726 01:30:25.182260 10.56.8.232           10.10.236.238         LDAP     MsgId=2 Search Entry, 1 result
  10727 01:30:25.221381 10.10.236.238         10.56.8.232           TCP      33976 > ldap [ACK] Seq=173 Ack=150 Win=5840 Len=0 TSV=3942999090 TSER=39428262
  10728 01:30:25.717614 10.10.236.238         10.56.8.232           LDAP     MsgId=46 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10729 01:30:25.718358 10.56.8.232           10.10.236.238         LDAP     MsgId=46 Search Entry, 1 result
  10730 01:30:25.718440 10.10.236.238         10.56.8.232           TCP      43225 > ldap [ACK] Seq=5095 Ack=1341 Win=6912 Len=0 TSV=3942999587 TSER=39428267
  10731 01:31:13.148468 10.10.236.238         10.56.8.232           LDAP     MsgId=47 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10732 01:31:13.349050 10.10.236.238         10.56.8.232           LDAP     [TCP Retransmission] MsgId=47 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10733 01:31:13.751035 10.10.236.238         10.56.8.232           LDAP     [TCP Retransmission] MsgId=47 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10734 01:31:14.554909 10.10.236.238         10.56.8.232           LDAP     [TCP Retransmission] MsgId=47 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10735 01:31:16.162669 10.10.236.238         10.56.8.232           LDAP     [TCP Retransmission] MsgId=47 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10736 01:31:19.378191 10.10.236.238         10.56.8.232           LDAP     [TCP Retransmission] MsgId=47 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10737 01:31:23.146890 10.10.236.238         10.56.8.232           LDAP     MsgId=48 Abandon Request
  10738 01:31:25.809196 10.10.236.238         10.56.8.232           LDAP     [TCP Retransmission] MsgId=47 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10739 01:31:38.671239 10.10.236.238         10.56.8.232           LDAP     [TCP Retransmission] MsgId=47 Search Request, Base DN=cn=Users,dc=athens,dc=int
  10740 01:31:38.671681 10.56.8.232           10.10.236.238         TCP      ldap > 43225 [ACK] Seq=1341 Ack=5222 Win=64840 Len=0 TSV=39428997 TSER=3943072551
  10741 01:31:38.672015 10.56.8.232           10.10.236.238         LDAP     MsgId=47 Search Entry, 1 result
  10742 01:31:38.672074 10.10.236.238         10.56.8.232           TCP      43225 > ldap [RST] Seq=5222 Ack=1537925965 Win=0 Len=0
  10743 01:31:38.672020 10.56.8.232           10.10.236.238         TCP      ldap > 43225 [FIN, ACK] Seq=1468 Ack=5222 Win=64840 Len=0 TSV=39428997 TSER=3943072551
  10744 01:31:38.672115 10.10.236.238         10.56.8.232           TCP      43225 > ldap [RST] Seq=5222 Ack=1537925965 Win=0 Len=0