[Date Prev][Date Next] [Chronological] [Thread] [Top]
(ITS#4289) probably component matching filter issue

To: openldap-its@OpenLDAP.org
Subject: (ITS#4289) probably component matching filter issue
From: vadim.tarassov@swissonline.ch
Date: Wed, 28 Dec 2005 23:36:19 GMT
Full_Name: vadim tarassov
Version: 2.3.14
OS: solaris 8
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (84.74.60.254)


Hallo everybody,

as I am not familiar with openldap code and can not yet identify source of the
problem, I decided to submit this issue. When using search filter:

"(userCertificate:componentFilterMatch:=item:{ component  
\"toBeSigned.serialNumber\", rule integerMatch, value 1768 })"

slapd performes the search operation and quits with return code 1.

Here is debug output of slapd:

Dec 28 23:58:04 c003998 slapd[8210]: [ID 601841 local4.debug] daemon: activity
on 1 descriptor
Dec 28 23:58:04 c003998 slapd[8210]: [ID 300852 local4.debug] daemon: listen=7,
new connection on 11
Dec 28 23:58:04 c003998 slapd[8210]: [ID 624067 local4.debug] daemon: added 11r
Dec 28 23:58:04 c003998 slapd[8210]: [ID 848112 local4.debug] conn=0 fd=11
ACCEPT from IP=166.9.94.147:60408 (IP=0.0.0.0:10389)
Dec 28 23:58:04 c003998 slapd[8210]: [ID 538834 local4.debug] daemon: select:
listen=7 active_threads=0 tvp=zero
Dec 28 23:58:04 c003998 slapd[8210]: [ID 601841 local4.debug] daemon: activity
on 1 descriptor
Dec 28 23:58:04 c003998 slapd[8210]: [ID 802679 local4.debug] daemon: activity
on:
Dec 28 23:58:04 c003998 slapd[8210]: [ID 522297 local4.debug]  11r
Dec 28 23:58:04 c003998 slapd[8210]: [ID 100000 local4.debug]
Dec 28 23:58:04 c003998 slapd[8210]: [ID 694296 local4.debug] daemon: read
activity on 11
Dec 28 23:58:04 c003998 slapd[8210]: [ID 525477 local4.debug]
connection_get(11)
Dec 28 23:58:04 c003998 slapd[8210]: [ID 611214 local4.debug]
connection_get(11): got connid=0
Dec 28 23:58:04 c003998 slapd[8210]: [ID 138202 local4.debug]
connection_read(11): checking for input on id=0
Dec 28 23:58:04 c003998 slapd[8210]: [ID 812316 local4.debug] ber_get_next on fd
11 failed errno=11 (Resource temporarily unavailable)
Dec 28 23:58:04 c003998 slapd[8210]: [ID 538834 local4.debug] daemon: select:
listen=7 active_threads=0 tvp=zero
Dec 28 23:58:04 c003998 slapd[8210]: [ID 948228 local4.debug] do_bind
Dec 28 23:58:04 c003998 slapd[8210]: [ID 198467 local4.debug] >>>
dnPrettyNormal: <cn=manager,ou=alcatraz,o=winterthur,c=ch>
Dec 28 23:58:04 c003998 slapd[8210]: [ID 147344 local4.debug] <<<
dnPrettyNormal: <cn=manager,ou=alcatraz,o=winterthur,c=ch>,
<cn=manager,ou=alcatraz,o=winterthur,c=ch>
Dec 28 23:58:04 c003998 slapd[8210]: [ID 286280 local4.debug] do_bind: version=3
dn="cn=manager,ou=alcatraz,o=winterthur,c=ch" method=128
Dec 28 23:58:04 c003998 slapd[8210]: [ID 215403 local4.debug] conn=0 op=0 BIND
dn="cn=manager,ou=alcatraz,o=winterthur,c=ch" method=128
Dec 28 23:58:04 c003998 slapd[8210]: [ID 121414 local4.debug] ==> bdb_bind: dn:
cn=manager,ou=alcatraz,o=winterthur,c=ch
Dec 28 23:58:04 c003998 slapd[8210]: [ID 600343 local4.debug] conn=0 op=0 BIND
dn="cn=Manager,ou=Alcatraz,o=winterthur,c=ch" mech=SIMPLE ssf=0
Dec 28 23:58:04 c003998 slapd[8210]: [ID 469106 local4.debug] do_bind: v3 bind:
"cn=manager,ou=alcatraz,o=winterthur,c=ch" to
"cn=Manager,ou=Alcatraz,o=winterthur,c=ch"
Dec 28 23:58:04 c003998 slapd[8210]: [ID 131099 local4.debug] send_ldap_result:
conn=0 op=0 p=3
Dec 28 23:58:04 c003998 slapd[8210]: [ID 291653 local4.debug] send_ldap_result:
err=0 matched="" text=""
Dec 28 23:58:04 c003998 slapd[8210]: [ID 324658 local4.debug]
send_ldap_response: msgid=1 tag=97 err=0
Dec 28 23:58:04 c003998 slapd[8210]: [ID 601841 local4.debug] daemon: activity
on 1 descriptor
Dec 28 23:58:04 c003998 slapd[8210]: [ID 802679 local4.debug] daemon: activity
on:
Dec 28 23:58:04 c003998 slapd[8210]: [ID 522297 local4.debug]  11r
Dec 28 23:58:04 c003998 slapd[8210]: [ID 100000 local4.debug]
Dec 28 23:58:04 c003998 slapd[8210]: [ID 694296 local4.debug] daemon: read
activity on 11
Dec 28 23:58:04 c003998 slapd[8210]: [ID 525477 local4.debug]
connection_get(11)
Dec 28 23:58:04 c003998 slapd[8210]: [ID 611214 local4.debug]
connection_get(11): got connid=0
Dec 28 23:58:04 c003998 slapd[8210]: [ID 138202 local4.debug]
connection_read(11): checking for input on id=0
Dec 28 23:58:04 c003998 slapd[8210]: [ID 812316 local4.debug] ber_get_next on fd
11 failed errno=11 (Resource temporarily unavailable)
Dec 28 23:58:04 c003998 slapd[8210]: [ID 538834 local4.debug] daemon: select:
listen=7 active_threads=0 tvp=zero
Dec 28 23:58:04 c003998 slapd[8210]: [ID 940369 local4.debug] do_search
Dec 28 23:58:04 c003998 slapd[8210]: [ID 198467 local4.debug] >>>
dnPrettyNormal: <roId=1000090,ou=alcatraz,o=winterthur,c=ch>
Dec 28 23:58:04 c003998 slapd[8210]: [ID 147344 local4.debug] <<<
dnPrettyNormal: <roId=1000090,ou=alcatraz,o=winterthur,c=ch>,
<roId=1000090,ou=alcatraz,o=winterthur,c=ch>
Dec 28 23:58:04 c003998 slapd[8210]: [ID 829381 local4.debug] SRCH
"roId=1000090,ou=alcatraz,o=winterthur,c=ch" 0 0
Dec 28 23:58:04 c003998 slapd[8210]: [ID 998714 local4.debug]     0 0 0
Dec 28 23:58:04 c003998 slapd[8210]: [ID 119476 local4.debug] begin get_filter
Dec 28 23:58:04 c003998 slapd[8210]: [ID 769236 local4.debug] EXTENSIBLE
Dec 28 23:58:04 c003998 slapd[8210]: [ID 948969 local4.debug] get_comp_filter
Dec 28 23:58:04 c003998 slapd[8210]: [ID 562317 local4.debug]
LDAP_COMP_FILTER_ITEM
Dec 28 23:58:04 c003998 slapd[8210]: [ID 391367 local4.debug] get_item
Dec 28 23:58:04 c003998 slapd[8210]: [ID 676560 local4.debug] get_compId [128]
Dec 28 23:58:04 c003998 last message repeated 1 time
Dec 28 23:58:04 c003998 slapd[8210]: [ID 957352 local4.debug] get_matching_rule:
2.5.13.14Dec 28 23:58:04 c003998 slapd[8210]: [ID 274773 local4.debug] end
get_filter 0
Dec 28 23:58:04 c003998 slapd[8210]: [ID 141783 local4.debug]     filter:
(userCertificate:componentFilterMatch:=\00\00\00\00$\00J\0E|\00\00\00\01\00\29\CC0\00\00\00\04\00J\0EI\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00,\00J\0E\AC\00J\0E\AC\00\00\00\19\00J\0E\15\00\00\00\02\00\00\00\00\00\00\00\00\00\00)
Dec 28 23:58:04 c003998 slapd[8210]: [ID 503656 local4.debug]     attrs:
Dec 28 23:58:04 c003998 slapd[8210]: [ID 100000 local4.debug]
Dec 28 23:58:04 c003998 slapd[8210]: [ID 469902 local4.debug] conn=0 op=1 SRCH
base="roId=1000090,ou=alcatraz,o=winterthur,c=ch" scope=0 deref=0
filter="(userCertificate:componentFilterMatch:=\00\00\00\00$\00J\0E|\00\00\00\01\00\29\CC0\00\00\00\04\00J\0EI\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00\00,\00J\0E\AC\00J\0E\AC\00\00\00\19\00J\0E\15\00\00\00\02\00\00\00\00\00\00\00\00\00\00)"
Dec 28 23:58:04 c003998 slapd[8210]: [ID 325447 local4.debug] => bdb_search
Dec 28 23:58:04 c003998 slapd[8210]: [ID 449132 local4.debug]
bdb_dn2entry("roId=1000090,ou=alcatraz,o=winterthur,c=ch")
Dec 28 23:58:04 c003998 slapd[8210]: [ID 603319 local4.debug] =>
bdb_dn2id("ou=alcatraz,o=winterthur,c=ch")
Dec 28 23:58:04 c003998 slapd[8210]: [ID 697587 local4.debug] <= bdb_dn2id: got
id=0x00000001
Dec 28 23:58:04 c003998 slapd[8210]: [ID 603319 local4.debug] =>
bdb_dn2id("roId=1000090,ou=alcatraz,o=winterthur,c=ch")
Dec 28 23:58:04 c003998 slapd[8210]: [ID 697587 local4.debug] <= bdb_dn2id: got
id=0x00000021
Dec 28 23:58:04 c003998 slapd[8210]: [ID 548982 local4.debug] entry_decode:
"roId=1000090,ou=Alcatraz,o=winterthur,c=ch"
Dec 28 23:58:04 c003998 slapd[8210]: [ID 184541 local4.debug] <=
entry_decode(roId=1000090,ou=Alcatraz,o=winterthur,c=ch)
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923460 local4.debug] base_candidates:
base: "roId=1000090,ou=alcatraz,o=winterthur,c=ch" (0x00000021)
Dec 28 23:58:04 c003998 slapd[8210]: [ID 344839 local4.debug] => test_filter
Dec 28 23:58:04 c003998 slapd[8210]: [ID 636329 local4.debug]     EXT
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
search access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "userCertificate"
requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 203198 local4.debug] test_comp_filter
Dec 28 23:58:04 c003998 slapd[8210]: [ID 791166 local4.debug] <= test_filter 6
Dec 28 23:58:04 c003998 slapd[8210]: [ID 359377 local4.debug] =>
send_search_entry: conn 0 dn="roId=1000090,ou=Alcatraz,o=winterthur,c=ch"
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "entry" requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "sn" requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "roType" requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "objectClass"
requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "mail" requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "updateTime"
requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "roId" requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "cn" requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "updater" requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch" "birthday"
requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 923158 local4.debug] => access_allowed:
read access to "roId=1000090,ou=Alcatraz,o=winterthur,c=ch"
"userCertificate;binary" requested
Dec 28 23:58:04 c003998 slapd[8210]: [ID 592946 local4.debug] <= root access
granted
Dec 28 23:58:04 c003998 slapd[8210]: [ID 580335 local4.debug] conn=0 op=1 ENTRY
dn="roId=1000090,ou=alcatraz,o=winterthur,c=ch"
Dec 28 23:58:04 c003998 slapd[8210]: [ID 223968 local4.debug] <=
send_search_entry: conn 0 exit.
Dec 28 23:58:04 c003998 slapd[8210]: [ID 131099 local4.debug] send_ldap_result:
conn=0 op=1 p=3
Dec 28 23:58:04 c003998 slapd[8210]: [ID 291653 local4.debug] send_ldap_result:
err=0 matched="" text=""
Dec 28 23:58:04 c003998 slapd[8210]: [ID 324658 local4.debug]
send_ldap_response: msgid=2 tag=101 err=0
Dec 28 23:58:04 c003998 slapd[8210]: [ID 167594 local4.debug] conn=0 op=1 SEARCH
RESULT tag=101 err=0 nentries=1 text=

Could you please suggest me what I could do to identify problem?

Thanx a lot and best regards, vadim tarassov
Prev by Date: Re: can not compile comp_match module (ITS#4270)
Next by Date: Re: (ITS#4276) Password policy history and complexity ignored with exop pwd change
Index(es):
- Chronological
- Thread