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
> GPG Key ID: E9ED159B
> 53°37'09,95"N
> 10°08'02,42"E
>
--
Dieter Klünter | Systemberatung
GPG Key ID: E9ED159B
53°37'09,95"N
10°08'02,42"E