[Date Prev][Date Next] [Chronological] [Thread] [Top]
OpenLDAP 2.0.11 SASL/ACL Problem

To: openldap-software@OpenLDAP.org
Subject: OpenLDAP 2.0.11 SASL/ACL Problem
From: Fred Ollermann <Fred.Ollermann@fh-stralsund.de>
Date: Wed, 10 Apr 2002 12:10:58 +0200
Hi everybody,

we are trying to setup OpenLDAP with SASL DIGEST-MD5 authentication several 
hours now.  SASL works well with the testsuite of cyrus-sasl. 

Also Slurpd binds via SASL to the slave LDAP-server which is to be updated, 
so replication from master to slave works fine. The problem occurs if a user 
wants to bind to a server using SASL. 

SASL authentication for the user seems to be working. 

	athene:~ # ldapmodify -H ldap://athene -U foller -f mod.ldif
	SASL/DIGEST-MD5 authentication started
	Please enter your password:
	SASL username: foller
	SASL realm: athene
	SASL SSF: 112
	SASL installing layers
	modifying entry "uid=foller,dc=fh-stralsund,dc=de"
	ldap_modify: Insufficient access

	ldif_record() = 50

but modifying of an entry fails. This might be a problem with ACL's.
We have added the following lines on top of our ACL file, included by 
slapd.conf.

	access to dn="uid=(.*),dc=fh-stralsund,dc=de"  
  		by dn="UID=$1\+REALM=ATHENE" write
  		by self write
  		by * none

The LDIF file looks like follows.

	dn: uid=foller,dc=fh-stralsund,dc=de
	changetype: modify
	replace: l
	l: Stralsund

The whole log is attached, but the relevant lines should be.

Apr 10 11:38:27 athene slapd[13596]: => access_allowed: write access to 
"uid=foller,dc=fh-stralsund,dc=de" "l" requested 
Apr 10 11:38:27 athene slapd[13596]: => dnpat: [1] 
uid=(.*),dc=fh-stralsund,dc=de nsub: 1 
Apr 10 11:38:27 athene slapd[13596]: => acl_get: [1] matched 
Apr 10 11:38:27 athene slapd[13596]: => acl_get: [1] check attr l 
Apr 10 11:38:27 athene slapd[13596]: <= acl_get: [1] acl 
uid=foller,dc=fh-stralsund,dc=de attr: l 
Apr 10 11:38:27 athene slapd[13596]: => acl_mask: access to entry 
"uid=foller,dc=fh-stralsund,dc=de", attr "l" requested 
Apr 10 11:38:27 athene slapd[13596]: => acl_mask: to value by 
"UID=FOLLER+REALM=ATHENE", (=n)  
Apr 10 11:38:27 athene slapd[13596]: <= check a_dn_pat: UID=$1+REALM=ATHENE 
Apr 10 11:38:27 athene slapd[13596]: => string_expand: pattern:  
UID=$1+REALM=ATHENE 
Apr 10 11:38:27 athene slapd[13596]: => string_expand: expanded: 
UID=FOLLER+REALM=ATHENE 
Apr 10 11:38:27 athene slapd[13596]: => regex_matches: string:   
UID=FOLLER+REALM=ATHENE 
Apr 10 11:38:27 athene slapd[13596]: => regex_matches: rc: 1 no matches 
Apr 10 11:38:27 athene slapd[13596]: <= check a_dn_pat: self 
Apr 10 11:38:27 athene slapd[13596]: <= check a_dn_pat: * 
Apr 10 11:38:27 athene slapd[13596]: <= acl_mask: [3] applying none (=n) 
(stop) 
Apr 10 11:38:27 athene slapd[13596]: <= acl_mask: [3] mask: none (=n) 
Apr 10 11:38:27 athene slapd[13596]: => access_allowed: write access denied 
by none (=n) 


The question is why do the expanded string and regex string dont match. 

Any suggestion will be quite helpfull.

Thanks in advance.

Marcus Linke & Fred Ollermann

University of Applied Sciences Stralsund
Germany

---

The whole log:

Apr 10 11:38:27 athene slapd[13596]: do_bind 
Apr 10 11:38:27 athene slapd[13596]: do_sasl_bind: dn () mech DIGEST-MD5 
Apr 10 11:38:27 athene slapd[13596]: conn=0 op=3 BIND dn="" method=163 
Apr 10 11:38:27 athene slapd[13596]: SASL Authorize [conn=0]: "foller" as  
"u:foller" 
Apr 10 11:38:27 athene slapd[13596]: slap_sasl_bind: username="u:foller" 
realm="athene" ssf=112 
Apr 10 11:38:27 athene slapd[13596]: <== slap_sasl_bind: authzdn: "uid=foller 
+ realm=athene" 
Apr 10 11:38:27 athene slapd[13596]: send_ldap_sasl: err=0 len=-1 
Apr 10 11:38:27 athene slapd[13596]: send_ldap_response: msgid=4 tag=97 err=0 
Apr 10 11:38:27 athene slapd[13596]: <== slap_sasl_bind: rc=0 
Apr 10 11:38:27 athene slapd[13581]: connection_get(12): got connid=0 
Apr 10 11:38:27 athene slapd[13581]: connection_read(12): checking for input 
on id=0 
Apr 10 11:38:27 athene slapd[13581]: ber_get_next on fd 12 failed errno=11 
(Resource temporarily unavailable) 
Apr 10 11:38:27 athene slapd[13596]: do_modify 
Apr 10 11:38:27 athene slapd[13596]: conn=0 op=4 MOD 
dn="uid=foller,dc=fh-stralsund,dc=de" 
Apr 10 11:38:27 athene slapd[13596]: dn2entry_r: dn: 
"UID=FOLLER,DC=FH-STRALSUND,DC=DE" 
Apr 10 11:38:27 athene slapd[13596]: => dn2id( 
"UID=FOLLER,DC=FH-STRALSUND,DC=DE" ) 
Apr 10 11:38:27 athene slapd[13596]: => ldbm_cache_open( "dn2id.dbb", 7, 600 
) 
Apr 10 11:38:27 athene slapd[13596]: <= ldbm_cache_open (opened 0) 
Apr 10 11:38:27 athene slapd[13596]: <= dn2id 50 
Apr 10 11:38:27 athene slapd[13596]: => id2entry_r( 50 ) 
Apr 10 11:38:27 athene slapd[13596]: => ldbm_cache_open( "id2entry.dbb", 7, 
600 ) 
Apr 10 11:38:27 athene slapd[13596]: <= ldbm_cache_open (opened 1) 
Apr 10 11:38:27 athene slapd[13596]: => str2entry 
Apr 10 11:38:27 athene slapd[13596]: <= 
str2entry(uid=foller,dc=fh-stralsund,dc=de) -> -1 (0x80e1930) 
Apr 10 11:38:27 athene slapd[13596]: <= id2entry_r( 50 ) 0x80e1930 (disk) 
Apr 10 11:38:27 athene slapd[13596]: ====> cache_return_entry_r( 50 ): 
created (0) 
Apr 10 11:38:27 athene slapd[13596]: dn2entry_w: dn: 
"UID=FOLLER,DC=FH-STRALSUND,DC=DE" 
Apr 10 11:38:27 athene slapd[13596]: => dn2id( 
"UID=FOLLER,DC=FH-STRALSUND,DC=DE" ) 
Apr 10 11:38:27 athene slapd[13596]: ====> 
cache_find_entry_dn2id("UID=FOLLER,DC=FH-STRALSUND,DC=DE"): 50 (1 tries) 
Apr 10 11:38:27 athene slapd[13596]: <= dn2id 50 (in cache) 
Apr 10 11:38:27 athene slapd[13596]: => id2entry_w( 50 ) 
Apr 10 11:38:27 athene slapd[13596]: ====> cache_find_entry_id( 50 ) 
"uid=foller,dc=fh-stralsund,dc=de" (found) (1 tries) 
Apr 10 11:38:27 athene slapd[13596]: <= id2entry_w( 50 ) 0x80e1930 (cache) 
Apr 10 11:38:27 athene slapd[13596]: ldbm_modify_internal: 
Apr 10 11:38:27 athene slapd[13596]: => access_allowed: write access to 
"uid=foller,dc=fh-stralsund,dc=de" "l" requested 
Apr 10 11:38:27 athene slapd[13596]: => dnpat: [1] 
uid=(.*),dc=fh-stralsund,dc=de nsub: 1 
Apr 10 11:38:27 athene slapd[13596]: => acl_get: [1] matched 
Apr 10 11:38:27 athene slapd[13596]: => acl_get: [1] check attr l 
Apr 10 11:38:27 athene slapd[13596]: <= acl_get: [1] acl 
uid=foller,dc=fh-stralsund,dc=de attr: l 
Apr 10 11:38:27 athene slapd[13596]: => acl_mask: access to entry 
"uid=foller,dc=fh-stralsund,dc=de", attr "l" requested 
Apr 10 11:38:27 athene slapd[13596]: => acl_mask: to value by 
"UID=FOLLER+REALM=ATHENE", (=n)  
Apr 10 11:38:27 athene slapd[13596]: <= check a_dn_pat: UID=$1+REALM=ATHENE 
Apr 10 11:38:27 athene slapd[13596]: => string_expand: pattern:  
UID=$1+REALM=ATHENE 
Apr 10 11:38:27 athene slapd[13596]: => string_expand: expanded: 
UID=FOLLER+REALM=ATHENE 
Apr 10 11:38:27 athene slapd[13596]: => regex_matches: string:   
UID=FOLLER+REALM=ATHENE 
Apr 10 11:38:27 athene slapd[13596]: => regex_matches: rc: 1 no matches 
Apr 10 11:38:27 athene slapd[13596]: <= check a_dn_pat: self 
Apr 10 11:38:27 athene slapd[13596]: <= check a_dn_pat: * 
Apr 10 11:38:27 athene slapd[13596]: <= acl_mask: [3] applying none (=n) 
(stop) 
Apr 10 11:38:27 athene slapd[13596]: <= acl_mask: [3] mask: none (=n) 
Apr 10 11:38:27 athene slapd[13596]: => access_allowed: write access denied 
by none (=n) 
Apr 10 11:38:27 athene slapd[13596]: send_ldap_result: conn=0 op=4 p=3 
Apr 10 11:38:27 athene slapd[13596]: send_ldap_response: msgid=5 tag=103 
err=50 
Apr 10 11:38:27 athene slapd[13596]: conn=0 op=4 RESULT tag=103 err=50 text= 
Apr 10 11:38:27 athene slapd[13581]: connection_get(12): got connid=0 
Apr 10 11:38:27 athene slapd[13581]: connection_read(12): checking for input 
on id=0 
Apr 10 11:38:27 athene slapd[13581]: ber_get_next on fd 12 failed errno=0 
(Success) 
Apr 10 11:38:27 athene slapd[13581]: connection_read(12): input error=-2 
id=0, closing. 
Apr 10 11:38:27 athene slapd[13581]: connection_closing: readying conn=0 
sd=12 for close 
Apr 10 11:38:27 athene slapd[13581]: connection_close: deferring conn=0 sd=12 
Apr 10 11:38:27 athene slapd[13596]: ====> cache_return_entry_w( 50 ): 
returned (0) 
Apr 10 11:38:27 athene slapd[13596]: connection_resched: attempting closing 
conn=0 sd=12 
Apr 10 11:38:27 athene slapd[13596]: connection_close: deferring conn=0 sd=12 
Apr 10 11:38:27 athene slapd[13597]: do_unbind 
Apr 10 11:38:27 athene slapd[13597]: conn=0 op=5 UNBIND 
Apr 10 11:38:27 athene slapd[13597]: connection_resched: attempting closing 
conn=0 sd=12 
Apr 10 11:38:27 athene slapd[13597]: connection_close: conn=0 sd=12 
Apr 10 11:38:27 athene slapd[13597]: conn=-1 fd=12 closed
Prev by Date: Re: A Few Questions (LDAP failover)
Next by Date: Replication with LDAP - newbie
Index(es):
- Chronological
- Thread