Hi again,

 

Here the logfile from a search process.

 

The Server find the right entry, but then search till all entries are touched….

Any ideas?

 

------------------------------------------

 

55e6fd47 daemon: activity on 1 descriptor

55e6fd47 daemon: activity on:55e6fd47  16r55e6fd47

55e6fd47 daemon: read active on 16

55e6fd47 daemon: epoll: listen=7 active_threads=0 tvp=zero

55e6fd47 daemon: epoll: listen=8 active_threads=0 tvp=zero

55e6fd47 connection_get(16)

55e6fd47 connection_get(16): got connid=1000

55e6fd47 connection_read(16): checking for input on id=1000

ber_get_next

ldap_read: want=8, got=8

  0000:  30 81 82 02 01 0d 63 7d                            0.....c}

ldap_read: want=125, got=125

  0000:  04 26 64 63 3d 6f 72 67  61 6e 69 7a 61 74 69 6f   .&dc=organizatio

  0010:  6e 73 2c 64 63 3d 76 66  6b 2c 64 63 3d 6c 64 61   ns,dc=vfk,dc=lda

  0020:  70 2c 64 63 3d 63 6f 6d  0a 01 01 0a 01 00 02 02   p,dc=com........

  0030:  03 e8 02 01 00 01 01 00  a0 34 a3 12 04 01 6f 04   .........4....o.

  0040:  0d 6f 72 67 61 6e 69 73  61 74 69 6f 6e 31 a3 1e   .organisation1..

  0050:  04 0b 6f 62 6a 65 63 74  43 6c 61 73 73 04 0f 76   ..objectClass..v

  0060:  66 6b 4f 72 67 61 6e 69  7a 61 74 69 6f 6e 30 0d   fkOrganization0.

  0070:  04 0b 6f 62 6a 65 63 74  43 6c 61 73 73            ..objectClass

ber_get_next: tag 0x30 len 130 contents:

ber_dump: buf=0x7f0fbc106140 ptr=0x7f0fbc106140 end=0x7f0fbc1061c2 len=130

  0000:  02 01 0d 63 7d 04 26 64  63 3d 6f 72 67 61 6e 69   ...c}.&dc=organi

  0010:  7a 61 74 69 6f 6e 73 2c  64 63 3d 76 66 6b 2c 64   zations,dc=vfk,d

  0020:  63 3d 6c 64 61 70 2c 64  63 3d 63 6f 6d 0a 01 01   c=ldap,dc=com...

  0030:  0a 01 00 02 02 03 e8 02  01 00 01 01 00 a0 34 a3   ..............4.

  0040:  12 04 01 6f 04 0d 6f 72  67 61 6e 69 73 61 74 69   ...o..organisati

  0050:  6f 6e 31 a3 1e 04 0b 6f  62 6a 65 63 74 43 6c 61   on1....objectCla

  0060:  73 73 04 0f 76 66 6b 4f  72 67 61 6e 69 7a 61 74   ss..vfkOrganizat

  0070:  69 6f 6e 30 0d 04 0b 6f  62 6a 65 63 74 43 6c 61   ion0...objectCla

  0080:  73 73                                              ss

55e6fd47 op tag 0x63, time 1441201479

ber_get_next

ldap_read: want=8 error=Resource temporarily unavailable

55e6fd47 daemon: activity on 1 descriptor

55e6fd47 daemon: activity on:55e6fd47

55e6fd47 daemon: epoll: listen=7 active_threads=0 tvp=zero

55e6fd47 daemon: epoll: listen=8 active_threads=0 tvp=zero

55e6fd47 conn=1000 op=12 do_search

ber_scanf fmt ({miiiib) ber:

ber_dump: buf=0x7f0fbc106140 ptr=0x7f0fbc106143 end=0x7f0fbc1061c2 len=127

  0000:  63 7d 04 26 64 63 3d 6f  72 67 61 6e 69 7a 61 74   c}.&dc=organizat

  0010:  69 6f 6e 73 2c 64 63 3d  76 66 6b 2c 64 63 3d 6c   ions,dc=vfk,dc=l

  0020:  64 61 70 2c 64 63 3d 63  6f 6d 0a 01 01 0a 01 00   dap,dc=com......

  0030:  02 02 03 e8 02 01 00 01  01 00 a0 34 a3 12 04 01   ...........4....

  0040:  6f 04 0d 6f 72 67 61 6e  69 73 61 74 69 6f 6e 31   o..organisation1

  0050:  a3 1e 04 0b 6f 62 6a 65  63 74 43 6c 61 73 73 04   ....objectClass.

  0060:  0f 76 66 6b 4f 72 67 61  6e 69 7a 61 74 69 6f 6e   .vfkOrganization

  0070:  30 0d 04 0b 6f 62 6a 65  63 74 43 6c 61 73 73      0...objectClass

55e6fd47 >>> dnPrettyNormal: <dc=organizations,dc=vfk,dc=ldap,dc=com>

=> ldap_bv2dn(dc=organizations,dc=vfk,dc=ldap,dc=com,0)

<= ldap_bv2dn(dc=organizations,dc=vfk,dc=ldap,dc=com)=0

=> ldap_dn2bv(272)

<= ldap_dn2bv(dc=organizations,dc=vfk,dc=ldap,dc=com)=0

=> ldap_dn2bv(272)

<= ldap_dn2bv(dc=organizations,dc=vfk,dc=ldap,dc=com)=0

55e6fd47 <<< dnPrettyNormal: <dc=organizations,dc=vfk,dc=ldap,dc=com>,

<dc=organizations,dc=vfk,dc=ldap,dc=com>

55e6fd47 SRCH "dc=organizations,dc=vfk,dc=ldap,dc=com" 1 055e6fd47     1000

0 0

55e6fd47 begin get_filter

55e6fd47 AND

55e6fd47 begin get_filter_list

55e6fd47 begin get_filter

55e6fd47 EQUALITY

ber_scanf fmt ({mm}) ber:

ber_dump: buf=0x7f0fbc106140 ptr=0x7f0fbc10617f end=0x7f0fbc1061c2 len=67

  0000:  a3 12 04 01 6f 04 0d 6f  72 67 61 6e 69 73 61 74   ....o..organisat

  0010:  69 6f 6e 31 a3 1e 04 0b  6f 62 6a 65 63 74 43 6c   ion1....objectCl

  0020:  61 73 73 04 0f 76 66 6b  4f 72 67 61 6e 69 7a 61   ass..vfkOrganiza

  0030:  74 69 6f 6e 30 0d 04 0b  6f 62 6a 65 63 74 43 6c   tion0...objectCl

  0040:  61 73 73                                           ass

55e6fd47 end get_filter 0

55e6fd47 begin get_filter

55e6fd47 EQUALITY

ber_scanf fmt ({mm}) ber:

ber_dump: buf=0x7f0fbc106140 ptr=0x7f0fbc106193 end=0x7f0fbc1061c2 len=47

  0000:  00 1e 04 0b 6f 62 6a 65  63 74 43 6c 61 73 73 04   ....objectClass.

  0010:  0f 76 66 6b 4f 72 67 61  6e 69 7a 61 74 69 6f 6e   .vfkOrganization

  0020:  30 0d 04 0b 6f 62 6a 65  63 74 43 6c 61 73 73      0...objectClass

55e6fd47 end get_filter 0

55e6fd47 end get_filter_list

55e6fd47 end get_filter 0

55e6fd47     filter: (&(o=organisation1)(objectClass=vfkOrganization))

ber_scanf fmt ({M}}) ber:

ber_dump: buf=0x7f0fbc106140 ptr=0x7f0fbc1061b3 end=0x7f0fbc1061c2 len=15

  0000:  00 0d 04 0b 6f 62 6a 65  63 74 43 6c 61 73 73      ....objectClass

55e6fd47     attrs:55e6fd47  objectClass55e6fd47

55e6fd47 conn=1000 op=12 SRCH base="dc=organizations,dc=vfk,dc=ldap,dc=com"

scope=1 deref=0 filter="(&(o=organisation1)(objectClass=vfkOrganization))"

55e6fd47 conn=1000 op=12 SRCH attr=objectClass

55e6fd47 => hdb_search

55e6fd47 bdb_dn2entry("dc=organizations,dc=vfk,dc=ldap,dc=com")

55e6fd47 => access_allowed: search access to

"dc=organizations,dc=vfk,dc=ldap,dc=com" "entry" requested

55e6fd47 <= root access granted

55e6fd47 => access_allowed: search access granted by manage(=mwrscxd)

55e6fd47 search_candidates: base="dc=organizations,dc=vfk,dc=ldap,dc=com"

(0x00000015) scope=1

55e6fd47 => hdb_dn2idl("dc=organizations,dc=vfk,dc=ldap,dc=com")

55e6fd47 => bdb_filter_candidates

55e6fd47        AND

55e6fd47 => bdb_list_candidates 0xa0

55e6fd47 => bdb_filter_candidates

55e6fd47        OR

55e6fd47 => bdb_list_candidates 0xa1

55e6fd47 => bdb_filter_candidates

55e6fd47        EQUALITY

55e6fd47 => bdb_equality_candidates (objectClass)

55e6fd47 => key_read

55e6fd47 bdb_idl_fetch_key: [b49d1940]

55e6fd47 <= bdb_index_read: failed (-30988)

55e6fd47 <= bdb_equality_candidates: id=0, first=0, last=0

55e6fd47 <= bdb_filter_candidates: id=0 first=0 last=0

55e6fd47 => bdb_filter_candidates

55e6fd47        AND

55e6fd47 => bdb_list_candidates 0xa0

55e6fd47 => bdb_filter_candidates

55e6fd47        EQUALITY

55e6fd47 => bdb_equality_candidates (o)

55e6fd47 <= bdb_equality_candidates: (o) not indexed

55e6fd47 <= bdb_filter_candidates: id=-1 first=1 last=130485

55e6fd47 => bdb_filter_candidates

55e6fd47        EQUALITY

55e6fd47 => bdb_equality_candidates (objectClass)

55e6fd47 => key_read

55e6fd47 bdb_idl_fetch_key: [63fb4940]

55e6fd47 <= bdb_index_read 3 candidates

55e6fd47 <= bdb_equality_candidates: id=3, first=27, last=42

55e6fd47 <= bdb_filter_candidates: id=3 first=27 last=42

55e6fd47 <= bdb_list_candidates: id=3 first=27 last=42

55e6fd47 <= bdb_filter_candidates: id=3 first=27 last=42

55e6fd47 <= bdb_list_candidates: id=3 first=27 last=42

55e6fd47 <= bdb_filter_candidates: id=3 first=27 last=42

55e6fd47 <= bdb_list_candidates: id=3 first=27 last=42

55e6fd47 <= bdb_filter_candidates: id=3 first=27 last=42

55e6fd47 bdb_search_candidates: id=3 first=27 last=42

55e6fd47 => test_filter

55e6fd47     AND

55e6fd47 => test_filter_and

55e6fd47 => test_filter

55e6fd47     EQUALITY

55e6fd47 => access_allowed: search access to

"o=organisation1,dc=organizations,dc=vfk,dc=ldap,dc=com" "o" requested

55e6fd47 <= root access granted

55e6fd47 => access_allowed: search access granted by manage(=mwrscxd)

55e6fd47 <= test_filter 6

55e6fd47 => test_filter

55e6fd47     EQUALITY

55e6fd47 => access_allowed: search access to

"o=organisation1,dc=organizations,dc=vfk,dc=ldap,dc=com" "objectClass"

requested

55e6fd47 <= root access granted

55e6fd47 => access_allowed: search access granted by manage(=mwrscxd)

55e6fd47 <= test_filter 6

55e6fd47 <= test_filter_and 6

55e6fd47 <= test_filter 6

55e6fd47 => send_search_entry: conn 1000

dn="o=organisation1,dc=organizations,dc=vfk,dc=ldap,dc=com"

55e6fd47 => access_allowed: read access to

"o=organisation1,dc=organizations,dc=vfk,dc=ldap,dc=com" "entry" requested

55e6fd47 <= root access granted

55e6fd47 => access_allowed: read access granted by manage(=mwrscxd)

55e6fd47 => access_allowed: result not in cache (objectClass)

55e6fd47 => access_allowed: read access to

"o=organisation1,dc=organizations,dc=vfk,dc=ldap,dc=com" "objectClass"

requested

55e6fd47 <= root access granted

55e6fd47 => access_allowed: read access granted by manage(=mwrscxd)

55e6fd47 => access_allowed: result was in cache (objectClass)

55e6fd47 conn=1000 op=12 ENTRY

dn="o=organisation1,dc=organizations,dc=vfk,dc=ldap,dc=com"

ber_flush2: 104 bytes to sd 16

  0000:  30 66 02 01 0d 64 61 04  36 6f 3d 6f 72 67 61 6e   0f...da.6o=organ

  0010:  69 73 61 74 69 6f 6e 31  2c 64 63 3d 6f 72 67 61   isation1,dc=orga

  0020:  6e 69 7a 61 74 69 6f 6e  73 2c 64 63 3d 76 66 6b   nizations,dc=vfk

  0030:  2c 64 63 3d 6c 64 61 70  2c 64 63 3d 63 6f 6d 30   ,dc=ldap,dc=com0

  0040:  27 30 25 04 0b 6f 62 6a  65 63 74 43 6c 61 73 73   '0%..objectClass

  0050:  31 16 04 0f 76 66 6b 4f  72 67 61 6e 69 7a 61 74   1...vfkOrganizat

  0060:  69 6f 6e 04 03 74 6f 70                            ion..top

ldap_write: want=104, written=104

  0000:  30 66 02 01 0d 64 61 04  36 6f 3d 6f 72 67 61 6e   0f...da.6o=organ

  0010:  69 73 61 74 69 6f 6e 31  2c 64 63 3d 6f 72 67 61   isation1,dc=orga

  0020:  6e 69 7a 61 74 69 6f 6e  73 2c 64 63 3d 76 66 6b   nizations,dc=vfk

  0030:  2c 64 63 3d 6c 64 61 70  2c 64 63 3d 63 6f 6d 30   ,dc=ldap,dc=com0

  0040:  27 30 25 04 0b 6f 62 6a  65 63 74 43 6c 61 73 73   '0%..objectClass

  0050:  31 16 04 0f 76 66 6b 4f  72 67 61 6e 69 7a 61 74   1...vfkOrganizat

  0060:  69 6f 6e 04 03 74 6f 70                            ion..top

55e6fd47 <= send_search_entry: conn 1000 exit.

55e6fd47 entry_decode: ""

55e6fd47 <= entry_decode()

55e6fd47 => test_filter

55e6fd47     AND

55e6fd47 => test_filter_and

55e6fd47 => test_filter

55e6fd47     EQUALITY

55e6fd47 => access_allowed: search access to

"o=organisation2,dc=organizations,dc=vfk,dc=ldap,dc=com" "o" requested

55e6fd47 <= root access granted

55e6fd47 => access_allowed: search access granted by manage(=mwrscxd)

55e6fd47 <= test_filter 5

55e6fd47 <= test_filter_and 5

55e6fd47 <= test_filter 5

55e6fd47 hdb_search: 28 does not match filter

55e6fd47 entry_decode: ""

55e6fd47 <= entry_decode()

55e6fd47 => test_filter

55e6fd47     AND

55e6fd47 => test_filter_and

55e6fd47 => test_filter

55e6fd47     EQUALITY

55e6fd47 => access_allowed: search access to

"o=testorga,dc=organizations,dc=vfk,dc=ldap,dc=com" "o" requested

55e6fd47 <= root access granted

55e6fd47 => access_allowed: search access granted by manage(=mwrscxd)

55e6fd47 <= test_filter 5

55e6fd47 <= test_filter_and 5

55e6fd47 <= test_filter 5

55e6fd47 hdb_search: 42 does not match filter

55e6fd47 send_ldap_result: conn=1000 op=12 p=3

55e6fd47 send_ldap_result: err=0 matched="" text=""

55e6fd47 send_ldap_response: msgid=13 tag=101 err=0

ber_flush2: 14 bytes to sd 16

  0000:  30 0c 02 01 0d 65 07 0a  01 00 04 00 04 00         0....e........

ldap_write: want=14, written=14

  0000:  30 0c 02 01 0d 65 07 0a  01 00 04 00 04 00         0....e........

55e6fd47 conn=1000 op=12 SEARCH RESULT tag=101 err=0 nentries=1 text=

^C55e6fd64 daemon: shutdown requested and initiated.

55e6fd64 daemon: closing 7

55e6fd64 daemon: closing 8

55e6fd64 connection_closing: readying conn=1000 sd=16 for close

55e6fd64 connection_close: conn=1000 sd=16

55e6fd64 daemon: removing 16

55e6fd64 conn=1000 fd=16 closed (slapd shutdown)

55e6fd64 slapd shutdown: waiting for 0 operations/tasks to finish

55e6fd64 slapd shutdown: initiated

55e6fd64 ====> bdb_cache_release_all

55e6fd64 slapd destroy: freeing system resources.

55e6fd64 slapd stopped.------------------------------------------

 

-----Ursprüngliche Nachricht-----
Von: openldap-technical [mailto:openldap-technical-bounces@openldap.org] Im Auftrag von Dieter Klünter
Gesendet: Dienstag, 1. September 2015 09:45
An: openldap-technical@openldap.org
Betreff: Re: Send Success with first found entry

 

Am Tue, 1 Sep 2015 06:44:08 +0000

schrieb "Fischer, Johannes" <johannes.fischer@ipa.fraunhofer.de>:

 

> Hi Dieter,

>

> I've tried it with a quite accurate filter request:

> (&

>     (cn=aaa)

>     (objectClass=vfkUser)

> )

> Scope: singleLevel

> Sizelimit: 1

> Baseobject : cn=user, ...

>

>

> The only result have been transferred from the server after 2ms, but

> the success packet still need 2-3s.

>

> Do I have to edit something on the server side?

>

> Greetings John

>

> PS. the cn's in the entry 'cn=user' are unique...

 

This is rather strange, could you run slapd in debugging mode (-d-1) in order to watch the internal process?

 

-Dieter

 

 

>

>

> -----Ursprüngliche Nachricht-----

> Von: openldap-technical

> [mailto:openldap-technical-bounces@openldap.org] Im Auftrag von Dieter

> Klünter Gesendet: Freitag, 28. August 2015 09:46 An:

> openldap-technical@openldap.org Betreff: Re: Send Success with first

> found entry

>

> Am Fri, 28 Aug 2015 05:42:37 +0000

> schrieb "Fischer, Johannes"

> <johannes.fischer@ipa.fraunhofer.de>http://ldapcon.org/2015/:

>

> > Hi again,

> >

> > more and more I get a feeling how all this work together. But often

> > you don't know what you actually need to look up...

> >

> > I've looked on the LDAP server of the Institute to get a feeling how

> > the real IT-guys managed their server... (It was a disaster from a

> > data protection perspective...) Some things were quit nice, for

> > example that the server send a "success" with the first found entry

> > in a subtree.

> >

> > On my openLDAP instance I receive a entry of a subtree after 20-30ms

> > but the success packet need 200ms. For me this behavior is not clear

> > due to the fact, that the entries in the directory need to be

> > unique.

> >

> > The Example:

> > I'm using the Spring security framework and trigger with

> > "ldapTemplate.lookup("cn=" + _name + ",dc=users");" a lookup. On

> > wireshark I see a search request with the scope "baseObject" and The

> > Filter "objectClass=*". After 33ms I receive a searchResEntry

> > packet, so the Server found something and could also stop. But I

> > think in the background all the other entries in the Subtree

> > "dc=users", are looked through also. After 230ms the success packet

> > arrive at my computer. (see also Attachment)

> >

> > My Question, is there a possibility to emit a success together with

> > the first found entry?

>

> In fact, this depends on your filter design. The rate of hits

> decreases with the degree of accuracy.

>

> -Dieter

>

>

>

> --

> Dieter Klünter | Systemberatung

> http://sys4.de

> GPG Key ID: E9ED159B

> 53°37'09,95"N

> 10°08'02,42"E

>

 

 

 

--

Dieter Klünter | Systemberatung

http://sys4.de

GPG Key ID: E9ED159B

53°37'09,95"N

10°08'02,42"E