OpenLDAP
Up to top level
Build   Contrib   Development   Documentation   Historical   Incoming   Software Bugs   Software Enhancements   Web  

Logged in as guest

Viewing Incoming/6383
Full headers

From: whm@stanford.edu
Subject: Very Slow Query Response
Compose comment
Download message
State:
0 replies:
6 followups: 1 2 3 4 5 6

Major security issue: yes  no

Notes:

Notification:


Date: Mon, 16 Nov 2009 20:27:21 +0000
From: whm@stanford.edu
To: openldap-its@OpenLDAP.org
Subject: Very Slow Query Response
Full_Name: Bill MacAllister
Version: 2.4.19+
OS: Debian 5
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (171.64.19.165)


On a system where slapd is the top CPU process and is consuming 4% of the CPU
simple queries are taking ten of seconds to complete.  Here is an example
query:

% time ldapsearch -x -h ldap1.stanford.edu -b dc=stanford,dc=edu uid=whm 
# extended LDIF
#
# LDAPv3
# base <dc=stanford,dc=edu> with scope subtree
# filter: uid=whm
# requesting: ALL
#
...data...
# search result
search: 2
result: 0 Success

# numResponses: 2
# numEntries: 1
0.001u 0.000s 0:18.13 0.0%      0+0k 0+0io 0pf+0w

Here is a backtrace:

ldap1:/var/log# gdb slapd 24029
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu"...
Attaching to program: /usr/sbin/slapd, process 24029
Reading symbols from /usr/lib/libtcmalloc_minimal.so.0...done.
Loaded symbols for /usr/lib/libtcmalloc_minimal.so.0
Reading symbols from /usr/lib/libldap_r-2.4.so.2...Reading symbols from
/usr/lib/debug/usr/lib/libldap_r-2.4.so.2.5.2...done.
done.
Loaded symbols for /usr/lib/libldap_r-2.4.so.2
Reading symbols from /usr/lib/liblber-2.4.so.2...Reading symbols from
/usr/lib/debug/usr/lib/liblber-2.4.so.2.5.2...done.
done.
Loaded symbols for /usr/lib/liblber-2.4.so.2
Reading symbols from /usr/lib/libdb-4.8.so...Reading symbols from
/usr/lib/debug/usr/lib/libdb-4.8.so.debug...done.
done.
Loaded symbols for /usr/lib/libdb-4.8.so
Reading symbols from /usr/lib/libodbc.so.1...done.
Loaded symbols for /usr/lib/libodbc.so.1
Reading symbols from /usr/lib/libslp.so.1...done.
Loaded symbols for /usr/lib/libslp.so.1
Reading symbols from /usr/lib/libsasl2.so.2...done.
Loaded symbols for /usr/lib/libsasl2.so.2
Reading symbols from /usr/lib/libssl.so.0.9.8...done.
Loaded symbols for /usr/lib/libssl.so.0.9.8
Reading symbols from /usr/lib/libcrypto.so.0.9.8...done.
Loaded symbols for /usr/lib/libcrypto.so.0.9.8
Reading symbols from /lib/libcrypt.so.1...done.
Loaded symbols for /lib/libcrypt.so.1
Reading symbols from /lib/libresolv.so.2...done.
Loaded symbols for /lib/libresolv.so.2
Reading symbols from /usr/lib/libltdl.so.3...done.
Loaded symbols for /usr/lib/libltdl.so.3
Reading symbols from /lib/libpthread.so.0...done.
[Thread debugging using libthread_db enabled]
[New Thread 0x7f89261b86f0 (LWP 24029)]
[New Thread 0x44bef950 (LWP 24047)]
[New Thread 0x443ee950 (LWP 24046)]
[New Thread 0x40a74950 (LWP 24045)]
[New Thread 0x43bed950 (LWP 24044)]
[New Thread 0x433ec950 (LWP 24043)]
[New Thread 0x42beb950 (LWP 24042)]
[New Thread 0x423ea950 (LWP 24041)]
[New Thread 0x41be9950 (LWP 24040)]
[New Thread 0x413e8950 (LWP 24039)]
Loaded symbols for /lib/libpthread.so.0
Reading symbols from /lib/libc.so.6...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /usr/lib/libstdc++.so.6...done.
Loaded symbols for /usr/lib/libstdc++.so.6
Reading symbols from /lib/libm.so.6...done.
Loaded symbols for /lib/libm.so.6
Reading symbols from /lib/libgcc_s.so.1...done.
Loaded symbols for /lib/libgcc_s.so.1
Reading symbols from /lib/libnsl.so.1...done.
Loaded symbols for /lib/libnsl.so.1
Reading symbols from /lib/libdl.so.2...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /usr/lib/libz.so.1...done.
Loaded symbols for /usr/lib/libz.so.1
Reading symbols from /lib/ld-linux-x86-64.so.2...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
Reading symbols from /lib/libnss_files.so.2...done.
Loaded symbols for /lib/libnss_files.so.2
Reading symbols from /usr/lib/sasl2/libntlm.so.2...done.
Loaded symbols for /usr/lib/sasl2/libntlm.so.2
Reading symbols from /usr/lib/sasl2/libcrammd5.so.2...done.
Loaded symbols for /usr/lib/sasl2/libcrammd5.so.2
Reading symbols from /usr/lib/sasl2/liblogin.so.2...done.
Loaded symbols for /usr/lib/sasl2/liblogin.so.2
Reading symbols from /usr/lib/sasl2/libsasldb.so.2...done.
Loaded symbols for /usr/lib/sasl2/libsasldb.so.2
Reading symbols from /usr/lib/libdb-4.6.so...done.
Loaded symbols for /usr/lib/libdb-4.6.so
Reading symbols from /usr/lib/sasl2/libdigestmd5.so.2...done.
Loaded symbols for /usr/lib/sasl2/libdigestmd5.so.2
Reading symbols from /usr/lib/sasl2/libgssapiv2.so.2...done.
Loaded symbols for /usr/lib/sasl2/libgssapiv2.so.2
Reading symbols from /usr/lib/libgssapi.so.2...done.
Loaded symbols for /usr/lib/libgssapi.so.2
Reading symbols from /usr/lib/libkrb5.so.25...done.
Loaded symbols for /usr/lib/libkrb5.so.25
Reading symbols from /usr/lib/libasn1.so.8...done.
Loaded symbols for /usr/lib/libasn1.so.8
Reading symbols from /usr/lib/libroken.so.18...done.
Loaded symbols for /usr/lib/libroken.s

Message of length 27066 truncated

Followup 1

Download message
Date: Mon, 16 Nov 2009 19:37:49 -0800
From: Quanah Gibson-Mount <quanah@zimbra.com>
To: whm@stanford.edu, openldap-its@openldap.org
Subject: Re: (ITS#6383) Very Slow Query Response

--On November 16, 2009 8:27:21 PM +0000 whm@stanford.edu wrote:

> Full_Name: Bill MacAllister
> Version: 2.4.19+
> OS: Debian 5
> URL: ftp://ftp.openldap.org/incoming/
> Submission from: (NULL) (171.64.19.165)
>
>
> On a system where slapd is the top CPU process and is consuming 4% of the
> CPU simple queries are taking ten of seconds to complete.  Here is an
> example query:

Last time we saw this it appeared that it might be related to DNS.  How 
long does a netstat -a take on the affected systems when the LDAP queries 
are slow?

--Quanah

--

Quanah Gibson-Mount
Principal Software Engineer
Zimbra, Inc
--------------------
Zimbra ::  the leader in open source messaging and collaboration



Followup 2

Download message
Date: Tue, 17 Nov 2009 05:03:38 +0000
From: Bill MacAllister <whm@stanford.edu>
Subject: Re: (ITS#6383) Very Slow Query Response
To: Quanah Gibson-Mount <quanah@zimbra.com>, openldap-its@openldap.org
Cc: unix-systems@mailman.stanford.edu

--On Monday, November 16, 2009 07:37:49 PM -0800 Quanah Gibson-Mount
<quanah@zimbra.com> wrote:

>
>
> --On November 16, 2009 8:27:21 PM +0000 whm@stanford.edu wrote:
>
>> Full_Name: Bill MacAllister
>> Version: 2.4.19+
>> OS: Debian 5
>> URL: ftp://ftp.openldap.org/incoming/
>> Submission from: (NULL) (171.64.19.165)
>>
>>
>> On a system where slapd is the top CPU process and is consuming 4% of
the
>> CPU simple queries are taking ten of seconds to complete.  Here is an
>> example query:
>
> Last time we saw this it appeared that it might be related to DNS.
> How long does a netstat -a take on the affected systems when the
> LDAP queries are slow?

I don't have that number.  I have only see it once in the test
environment I am not sure how long it will take me to get it.  Since
this plastered the production service today, I will have to reproduce
it though before we attempt another production upgrade.

Not clear to me why a DNS issue would appear only under load and not
at other times.  And it seems strange that it appears in
lenny/openldap-2.4 and not in etch/openldap-2.3.

Bill

-- 
Bill MacAllister, System Software Programmer
Unix Systems Group, Stanford University



Followup 3

Download message
From: Quanah Gibson-Mount <quanah@zimbra.com>
To: Bill MacAllister <whm@stanford.edu>
Subject: Re: (ITS#6383) Very Slow Query Response
Date: Tue, 17 Nov 2009 21:11:23 -0800
Cc: "openldap-its@openldap.org" <openldap-its@openldap.org>,
        "unix-systems@lists.stanford.edu" <unix-systems@mailman.stanford.edu>

On Nov 16, 2009, at 9:03 PM, Bill MacAllister <whm@stanford.edu> wrote:

>
>
> --On Monday, November 16, 2009 07:37:49 PM -0800 Quanah Gibson-Mount  
> <quanah@zimbra.com> wrote:
>
>>
>>
>> --On November 16, 2009 8:27:21 PM +0000 whm@stanford.edu wrote:
>>
>>> Full_Name: Bill MacAllister
>>> Version: 2.4.19+
>>> OS: Debian 5
>>> URL: ftp://ftp.openldap.org/incoming/
>>> Submission from: (NULL) (171.64.19.165)
>>>
>>>
>>> On a system where slapd is the top CPU process and is consuming 4% 

>>> of the
>>> CPU simple queries are taking ten of seconds to complete.  Here is 

>>> an
>>> example query:
>>
>> Last time we saw this it appeared that it might be related to DNS.
>> How long does a netstat -a take on the affected systems when the
>> LDAP queries are slow?
>
> I don't have that number.  I have only see it once in the test
> environment I am not sure how long it will take me to get it.  Since
> this plastered the production service today, I will have to reproduce
> it though before we attempt another production upgrade.
>
> Not clear to me why a DNS issue would appear only under load and not
> at other times.  And it seems strange that it appears in
> lenny/openldap-2.4 and not in etch/openldap-2.3.
>
> Bill
>
> -- 
> Bill MacAllister, System Software Programmer
> Unix Systems Group, Stanford University

For historical note this was caused by Cyrus-sasl being built  
incorrectly by the debian packagers when heimdal is used.

--Quanah



Followup 4

Download message
From: Russ Allbery <rra@stanford.edu>
To: openldap-its@openldap.org
Subject: Re: (ITS#6383) Very Slow Query Response
Date: Tue, 17 Nov 2009 21:21:17 -0800
quanah@zimbra.com writes:

> For historical note this was caused by Cyrus-sasl being built
> incorrectly by the debian packagers when heimdal is used.

Well, rather, that's a theory which currently looks good.  It definitely
hasn't been proven yet.

-- 
Russ Allbery (rra@stanford.edu)             <http://www.eyrie.org/~eagle/>



Followup 5

Download message
Date: Wed, 18 Nov 2009 09:39:02 +0000
From: Bill MacAllister <whm@stanford.edu>
Subject: Re: (ITS#6383) Very Slow Query Response
To: Quanah Gibson-Mount <quanah@zimbra.com>
Cc: openldap-its@openldap.org, unix-systems@mailman.stanford.edu

--On Tuesday, November 17, 2009 09:11:23 PM -0800 Quanah Gibson-Mount
<quanah@zimbra.com> wrote:

>
>
> On Nov 16, 2009, at 9:03 PM, Bill MacAllister <whm@stanford.edu>
wrote:
>
>>
>>
>> --On Monday, November 16, 2009 07:37:49 PM -0800 Quanah Gibson-Mount
>> <quanah@zimbra.com> wrote:
>>
>>>
>>>
>>> --On November 16, 2009 8:27:21 PM +0000 whm@stanford.edu wrote:
>>>
>>>> Full_Name: Bill MacAllister
>>>> Version: 2.4.19+
>>>> OS: Debian 5
>>>> URL: ftp://ftp.openldap.org/incoming/
>>>> Submission from: (NULL) (171.64.19.165)
>>>>
>>>>
>>>> On a system where slapd is the top CPU process and is consuming
4%
>>>> of the
>>>> CPU simple queries are taking ten of seconds to complete.  Here
is
>>>> an
>>>> example query:
>>>
>>> Last time we saw this it appeared that it might be related to DNS.
>>> How long does a netstat -a take on the affected systems when the
>>> LDAP queries are slow?
>>
>> I don't have that number.  I have only see it once in the test
>> environment I am not sure how long it will take me to get it.  Since
>> this plastered the production service today, I will have to reproduce
>> it though before we attempt another production upgrade.
>>
>> Not clear to me why a DNS issue would appear only under load and not
>> at other times.  And it seems strange that it appears in
>> lenny/openldap-2.4 and not in etch/openldap-2.3.
>>
>> Bill
>>
>> --
>> Bill MacAllister, System Software Programmer
>> Unix Systems Group, Stanford University
>
> For historical note this was caused by Cyrus-sasl being built
> incorrectly by the debian packagers when heimdal is used.
>
> --Quanah

I don't understand why you refer to this finding as historical.  If I
am reading this correctly you and Howard have found the underlying
cause.  Now that the problem is understood can you suggest a way for
us to cause the problem in our test environments?  At this point we
will really need to convince ourselves that the problem is indeed fixed
before we try to deploy 2.4 in our production environment again.

Bill

-- 
Bill MacAllister, System Software Programmer
Unix Systems Group, Stanford University



Followup 6

Download message
Date: Wed, 18 Nov 2009 09:20:32 -0800
From: Quanah Gibson-Mount <quanah@zimbra.com>
To: Bill MacAllister <whm@stanford.edu>
cc: openldap-its@openldap.org, unix-systems@mailman.stanford.edu
Subject: Re: (ITS#6383) Very Slow Query Response

--On November 18, 2009 9:39:02 AM +0000 Bill MacAllister
<whm@stanford.edu> 
wrote:

>> For historical note this was caused by Cyrus-sasl being built
>> incorrectly by the debian packagers when heimdal is used.
>>
>
> I don't understand why you refer to this finding as historical.

Not a historical finding. As a record for anyone who comes across this ITS 
and wants to know what was found.

> If I
> am reading this correctly you and Howard have found the underlying
> cause.  Now that the problem is understood can you suggest a way for
> us to cause the problem in our test environments?  At this point we
> will really need to convince ourselves that the problem is indeed fixed
> before we try to deploy 2.4 in our production environment again.

To note, first off, this issue was not a bug in OpenLDAP, and the project 
went beyond its scope in tracking down why cyrus-sasl was behaving the way 
it was.  Finding out test cases for you to explore is also beyond the scope 
of the OpenLDAP project when dealing with non-OpenLDAP issues.

However, given what is known, i.e., that the NTLM code path was being 
called during SASL/GSSAPI binds, I would suggest you either set up a number 
of windows boxes that try and do SASL/GSSAPI auth with NTLM to a test 
server, or write a script that does that and run it from multiple systems.

Some reference points:

<http://www.netid.washington.edu/documentation/ldapAuth.aspx>

It also seems it may be possible to use python-ldap to do this.  I don't 
know if it is possible with Net::LDAP or Net::LDAPapi

--Quanah

--

Quanah Gibson-Mount
Principal Software Engineer
Zimbra, Inc
--------------------
Zimbra ::  the leader in open source messaging and collaboration


Up to top level
Build   Contrib   Development   Documentation   Historical   Incoming   Software Bugs   Software Enhancements   Web  

Logged in as guest


The OpenLDAP Issue Tracking System uses a hacked version of JitterBug

______________
© Copyright 2013, OpenLDAP Foundation, info@OpenLDAP.org