Logged in as guest
Viewing Incoming/6383 Full headers
Major security issue: yes no
Notes: most likely not ours 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
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
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
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
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/>
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
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
______________ © Copyright 2013, OpenLDAP Foundation, info@OpenLDAP.org
