Rick, for now I am not too much concerned about the initial search (although, I want to get to the bottom of this as well), but the skipping of this one search. Actually on the client side, the request (which is the skipped op), times out! -Reinhard ________________________________________ From: 389-users-bounces at lists.fedoraproject.org [389-users-bounces at lists.fedoraproject.org] On Behalf Of Rich Megginson [rmeggins at redhat.com] Sent: Tuesday, May 11, 2010 2:20 PM To: General discussion list for the 389 Directory server project. Subject: Re: Skipped request ... Reinhard Nappert wrote: > Hi all, > > I have seen a weird behavior of my DS (1.1.2). It has a very small > database (only about 2300 objects). A client performed a one-level > search retrieving the children. The server find 114 objects, but the > search was very slow: > > [06/May/2010:12:23:11 +0000] conn=127 op=149 SRCH base=<base> scope=1 > filter="(&(&(objectClass=<xyz>)(<att1>=value))(!(<att2>=TRUE)))" > > yes, the filter is a bit complex, but both attribute types <att1> and > <att2> are indexed. This search usually is fast. It looks to me that > the server is already in a funny state. > ... > [06/May/2010:12:23:17 +0000] conn=127 op=149 RESULT err=3 tag=101 > nentries=114 etime=7 err=3 is TIMELIMIT_EXCEEDED - that's probably why you aren't getting all of the results you expect, and could be why it's skipping the op. > > When the client gets the results, it iterates over those and gets its > children, like: > > [06/May/2010:12:23:17 +0000] conn=127 op=150 SRCH base=<dn of result > from previous SRCH> scope=1 > filter="(&(&(objectClass=<uvw>)(<attr3>=*))(!(<attr2>=TRUE)))" attrs=ALL. > Those searches are quick: > [06/May/2010:12:23:17 +0000] conn=127 op=150 RESULT err=0 tag=101 > nentries=1 etime=0 > > but somehow the server does not process on of the requests, when the > client iterates over the results: > > [06/May/2010:12:23:18 +0000] conn=127 op=263 SRCH base=<dn of result > from previous SRCH> scope=1 > filter="(&(&(objectClass=<uvw>)(<attr3>=*))(!(<attr2>=TRUE)))" attrs=ALL. > [06/May/2010:12:23:18 +0000] conn=127 op=263 RESULT err=0 tag=101 > nentries=1 etime=0 > [06/May/2010:12:23:26 +0000] conn=127 op=265 SRCH base=<dn of result > from previous SRCH> scope=1 > filter="(&(&(objectClass=<uvw>)(<attr3>=*))(!(<attr2>=TRUE)))" attrs=ALL. > [06/May/2010:12:23:26 +0000] conn=127 op=265 RESULT err=0 tag=101 > nentries=0 etime=0 > You can see that the server skipped op=264. It looks to me that the > request came in, but somehow the server joked up, before it could log > the request in access. > > Has anybody seen such a behavior before? > > Thanks, > -Reinhard > > > ------------------------------------------------------------------------ > > -- > 389 users mailing list > 389-users at lists.fedoraproject.org > https://admin.fedoraproject.org/mailman/listinfo/389-users -- 389 users mailing list 389-users at lists.fedoraproject.org https://admin.fedoraproject.org/mailman/listinfo/389-users
