[Date Prev][Date Next] [Chronological] [Thread] [Top]

RE: Problems Enabling Authentication using Cyrus SASL



Hi all
Thanks for all your suggestions

   I tried the suggested command (thanks Moorthi):
                  ldapwhoami -U proxyuser -X u:test -Y digest-md5 -I
with no success. I got this error:

firewall:~ # ldapwhoami -U proxyuser -X u:test -Y digest-md5 -I
SASL/DIGEST-MD5 authentication started
SASL Interaction
Default: u:test
Please enter your authorization name: test
Default: proxyuser
Please enter your authentication name: proxyuser
Please enter your password:
ldap_sasl_interactive_bind_s: Insufficient access (50)
        additional info: SASL(-14): authorization failure: unable authorization ID

(Logs are at the bottom of this mail for details)

I also realized that the logs changed almost nothing either the command below is running or not:

            saslauthd -d -V -a ldap -r -O /etc/saslauthd.conf

so I can say that unfortunately there's no comunication between SASLAUTHD and LDAP.

Now I will try the suggestion to separate saslauthd and ldapdb (thanks Dieter)

But I'm still wondering if there's a way to work ldap server and cyrus-sasl together. Let's be more accuratte

1.-  Connect to ldap server throught cyrus-sasl (let's say authenticated/authorized proxyuser connected to ldap server)
2.-  Once connected to the ldap server, authenticate/authorize other user (or any object ) saved on ldap server using previous connection done in step 1

Is that posible? Or, Am I driving crazy for nothing?

Thanks in advance

   Fernando Torrez

     LDAP LOGS
Nov 17 10:10:44 firewall slapd[2901]: daemon: activity on 1 descriptor
Nov 17 10:10:44 firewall slapd[2901]: daemon: activity on:
Nov 17 10:10:44 firewall slapd[2901]:
Nov 17 10:10:44 firewall slapd[2901]: slap_listener_activate(8):
Nov 17 10:10:44 firewall slapd[2901]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Nov 17 10:10:44 firewall slapd[2901]: daemon: epoll: listen=8 busy
Nov 17 10:10:44 firewall slapd[2901]: >>> slap_listener(ldap://)
Nov 17 10:10:44 firewall slapd[2901]: daemon: listen=8, new connection on 13
Nov 17 10:10:44 firewall slapd[2901]: daemon: added 13r (active) listener=(nil)
Nov 17 10:10:44 firewall slapd[2901]: conn=1002 fd=13 ACCEPT from IP=[::1]:39399 (IP=[::]:389)
Nov 17 10:10:44 firewall slapd[2901]: daemon: activity on 1 descriptor
Nov 17 10:10:44 firewall slapd[2901]: daemon: activity on:
Nov 17 10:10:44 firewall slapd[2901]:
Nov 17 10:10:44 firewall slapd[2901]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Nov 17 10:10:44 firewall slapd[2901]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Nov 17 10:10:44 firewall slapd[2901]: daemon: activity on 1 descriptor
Nov 17 10:10:44 firewall slapd[2901]: daemon: activity on:
Nov 17 10:10:44 firewall slapd[2901]:  13r
Nov 17 10:10:44 firewall slapd[2901]:
Nov 17 10:10:44 firewall slapd[2901]: daemon: read active on 13
Nov 17 10:10:44 firewall slapd[2901]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Nov 17 10:10:44 firewall slapd[2901]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Nov 17 10:10:44 firewall slapd[2901]: connection_get(13)
Nov 17 10:10:44 firewall slapd[2901]: connection_get(13): got connid=1002
Nov 17 10:10:44 firewall slapd[2901]: connection_read(13): checking for input on id=1002
Nov 17 10:10:44 firewall slapd[2901]: op tag 0x60, time 1290003044
Nov 17 10:10:44 firewall slapd[2901]: conn=1002 op=0 do_bind
Nov 17 10:10:44 firewall slapd[2901]: >>> dnPrettyNormal: <>
Nov 17 10:10:44 firewall slapd[2901]: <<< dnPrettyNormal: <>, <>
Nov 17 10:10:44 firewall slapd[2901]: conn=1002 op=0 BIND dn="" method=163
Nov 17 10:10:44 firewall slapd[2901]: do_bind: dn () SASL mech DIGEST-MD5
Nov 17 10:10:44 firewall slapd[2901]: ==> sasl_bind: dn="" mech=DIGEST-MD5 datalen=0
Nov 17 10:10:44 firewall slapd[2901]: SASL [conn=1002] Debug: DIGEST-MD5 server step 1
Nov 17 10:10:44 firewall slapd[2901]: send_ldap_sasl: err=14 len=182
Nov 17 10:10:44 firewall slapd[2901]: send_ldap_response: msgid=1 tag=97 err=14
Nov 17 10:10:44 firewall slapd[2901]: conn=1002 op=0 RESULT tag=97 err=14 text=SASL(0): successful result:
Nov 17 10:10:44 firewall slapd[2901]: <== slap_sasl_bind: rc=14
Nov 17 10:10:44 firewall slapd[2901]: daemon: activity on 1 descriptor
Nov 17 10:10:44 firewall slapd[2901]: daemon: activity on:
Nov 17 10:10:44 firewall slapd[2901]:
Nov 17 10:10:44 firewall slapd[2901]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Nov 17 10:10:44 firewall slapd[2901]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Nov 17 10:10:44 firewall ldapwhoami: DIGEST-MD5 client step 2
Nov 17 10:11:02 firewall ldapwhoami: DIGEST-MD5 client step 2
Nov 17 10:11:02 firewall slapd[2901]: daemon: activity on 1 descriptor
Nov 17 10:11:02 firewall slapd[2901]: daemon: activity on:
Nov 17 10:11:02 firewall slapd[2901]:  13r
Nov 17 10:11:02 firewall slapd[2901]:
Nov 17 10:11:02 firewall slapd[2901]: daemon: read active on 13
Nov 17 10:11:02 firewall slapd[2901]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Nov 17 10:11:02 firewall slapd[2901]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Nov 17 10:11:02 firewall slapd[2901]: connection_get(13)
Nov 17 10:11:02 firewall slapd[2901]: connection_get(13): got connid=1002
Nov 17 10:11:02 firewall slapd[2901]: connection_read(13): checking for input on id=1002
Nov 17 10:11:02 firewall slapd[2901]: op tag 0x60, time 1290003062
Nov 17 10:11:02 firewall slapd[2901]: conn=1002 op=1 do_bind
Nov 17 10:11:02 firewall slapd[2901]: >>> dnPrettyNormal: <>
Nov 17 10:11:02 firewall slapd[2901]: <<< dnPrettyNormal: <>, <>
Nov 17 10:11:02 firewall slapd[2901]: conn=1002 op=1 BIND dn="" method=163
Nov 17 10:11:02 firewall slapd[2901]: do_bind: dn () SASL mech DIGEST-MD5
Nov 17 10:11:02 firewall slapd[2901]: ==> sasl_bind: dn="" mech=<continuing> datalen=294
Nov 17 10:11:02 firewall slapd[2901]: SASL [conn=1002] Debug: DIGEST-MD5 server step 2
Nov 17 10:11:02 firewall slapd[2901]: SASL Canonicalize [conn=1002]: authcid="proxyuser"
Nov 17 10:11:02 firewall slapd[2901]: slap_sasl_getdn: conn 1002 id=proxyuser [len=9]
Nov 17 10:11:02 firewall slapd[2901]: slap_sasl_getdn: u:id converted to uid=proxyuser,cn=DIGEST-MD5,cn=auth
Nov 17 10:11:02 firewall slapd[2901]: >>> dnNormalize: <uid=proxyuser,cn=DIGEST-MD5,cn=auth>
Nov 17 10:11:02 firewall slapd[2901]: <<< dnNormalize: <uid=proxyuser,cn=digest-md5,cn=auth>
Nov 17 10:11:02 firewall slapd[2901]: ==>slap_sasl2dn: converting SASL name uid=proxyuser,cn=digest-md5,cn=auth to a DN
Nov 17 10:11:02 firewall slapd[2901]: [rw] authid: "uid=proxyuser,cn=digest-md5,cn=auth" -> "uid=proxyuser,ou=people,dc=plainjoe,dc=org"
Nov 17 10:11:02 firewall slapd[2901]: slap_parseURI: parsing uid=proxyuser,ou=people,dc=plainjoe,dc=org
Nov 17 10:11:02 firewall slapd[2901]: >>> dnNormalize: <uid=proxyuser,ou=people,dc=plainjoe,dc=org>
Nov 17 10:11:02 firewall slapd[2901]: <<< dnNormalize: <uid=proxyuser,ou=people,dc=plainjoe,dc=org>
Nov 17 10:11:02 firewall slapd[2901]: <==slap_sasl2dn: Converted SASL name to uid=proxyuser,ou=people,dc=plainjoe,dc=org
Nov 17 10:11:02 firewall slapd[2901]: slap_sasl_getdn: dn:id converted to uid=proxyuser,ou=people,dc=plainjoe,dc=org
Nov 17 10:11:02 firewall slapd[2901]: SASL Canonicalize [conn=1002]: slapAuthcDN="uid=proxyuser,ou=people,dc=plainjoe,dc=org"
Nov 17 10:11:02 firewall slapd[2901]: => bdb_search
Nov 17 10:11:02 firewall slapd[2901]: bdb_dn2entry("uid=proxyuser,ou=people,dc=plainjoe,dc=org")
Nov 17 10:11:02 firewall slapd[2901]: => access_allowed: auth access to "uid=proxyuser,ou=people,dc=plainjoe,dc=org" "entry" requested
Nov 17 10:11:02 firewall slapd[2901]: daemon: activity on 1 descriptor
Nov 17 10:11:02 firewall slapd[2901]: daemon: activity on:
Nov 17 10:11:02 firewall slapd[2901]:
Nov 17 10:11:02 firewall slapd[2901]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Nov 17 10:11:02 firewall slapd[2901]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Nov 17 10:11:02 firewall slapd[2901]: => acl_get: [2] attr entry
Nov 17 10:11:02 firewall slapd[2901]: => acl_mask: access to entry "uid=proxyuser,ou=people,dc=plainjoe,dc=org", attr "entry" requested
Nov 17 10:11:02 firewall slapd[2901]: => acl_mask: to all values by "", (=0)
Nov 17 10:11:02 firewall slapd[2901]: <= check a_dn_pat: *
Nov 17 10:11:02 firewall slapd[2901]: <= acl_mask: [1] applying read(=rscxd) (stop)
Nov 17 10:11:02 firewall slapd[2901]: <= acl_mask: [1] mask: read(=rscxd)
Nov 17 10:11:02 firewall slapd[2901]: => slap_access_allowed: auth access granted by read(=rscxd)
Nov 17 10:11:02 firewall slapd[2901]: => access_allowed: auth access granted by read(=rscxd)
Nov 17 10:11:02 firewall slapd[2901]: base_candidates: base: "uid=proxyuser,ou=people,dc=plainjoe,dc=org" (0x00000011)
Nov 17 10:11:02 firewall slapd[2901]: => test_filter
Nov 17 10:11:02 firewall slapd[2901]:     PRESENT
Nov 17 10:11:02 firewall slapd[2901]: => access_allowed: auth access to "uid=proxyuser,ou=people,dc=plainjoe,dc=org" "objectClass" requested
Nov 17 10:11:02 firewall slapd[2901]: => acl_get: [2] attr objectClass
Nov 17 10:11:02 firewall slapd[2901]: => acl_mask: access to entry "uid=proxyuser,ou=people,dc=plainjoe,dc=org", attr "objectClass" requested
Nov 17 10:11:02 firewall slapd[2901]: => acl_mask: to all values by "", (=0)
Nov 17 10:11:02 firewall slapd[2901]: <= check a_dn_pat: *
Nov 17 10:11:02 firewall slapd[2901]: <= acl_mask: [1] applying read(=rscxd) (stop)
Nov 17 10:11:02 firewall slapd[2901]: <= acl_mask: [1] mask: read(=rscxd)
Nov 17 10:11:02 firewall slapd[2901]: => slap_access_allowed: auth access granted by read(=rscxd)
Nov 17 10:11:02 firewall slapd[2901]: => access_allowed: auth access granted by read(=rscxd)
Nov 17 10:11:02 firewall slapd[2901]: <= test_filter 6
Nov 17 10:11:02 firewall slapd[2901]: => access_allowed: auth access to "uid=proxyuser,ou=people,dc=plainjoe,dc=org" "userPassword" requested
Nov 17 10:11:02 firewall slapd[2901]: => acl_get: [1] attr userPassword
Nov 17 10:11:02 firewall slapd[2901]: => acl_mask: access to entry "uid=proxyuser,ou=people,dc=plainjoe,dc=org", attr "userPassword" requested
Nov 17 10:11:02 firewall slapd[2901]: => acl_mask: to all values by "", (=0)
Nov 17 10:11:02 firewall slapd[2901]: <= check a_dn_pat: self
Nov 17 10:11:02 firewall slapd[2901]: <= check a_dn_pat: anonymous
Nov 17 10:11:02 firewall slapd[2901]: <= acl_mask: [2] applying auth(=xd) (stop)
Nov 17 10:11:02 firewall slapd[2901]: <= acl_mask: [2] mask: auth(=xd)
Nov 17 10:11:02 firewall slapd[2901]: => slap_access_allowed: auth access granted by auth(=xd)
Nov 17 10:11:02 firewall slapd[2901]: => access_allowed: auth access granted by auth(=xd)
Nov 17 10:11:02 firewall slapd[2901]: slap_ap_lookup: str2ad(cmusaslsecretDIGEST-MD5): attribute type undefined
Nov 17 10:11:02 firewall slapd[2901]: send_ldap_result: conn=1002 op=1 p=3
Nov 17 10:11:02 firewall slapd[2901]: send_ldap_result: err=0 matched="" text=""
Nov 17 10:11:02 firewall slapd[2901]: SASL Canonicalize [conn=1002]: authzid="test"
Nov 17 10:11:02 firewall slapd[2901]: slap_sasl_getdn: conn 1002 id=test [len=4]
Nov 17 10:11:02 firewall slapd[2901]: SASL [conn=1002] Failure: Inappropriate authentication
Nov 17 10:11:02 firewall slapd[2901]: SASL [conn=1002] Failure: unable authorization ID
Nov 17 10:11:02 firewall slapd[2901]: send_ldap_result: conn=1002 op=1 p=3
Nov 17 10:11:02 firewall slapd[2901]: send_ldap_result: err=50 matched="" text="SASL(-14): authorization failure: unable authorization ID"
Nov 17 10:11:02 firewall slapd[2901]: send_ldap_response: msgid=2 tag=97 err=50
Nov 17 10:11:02 firewall slapd[2901]: daemon: activity on 1 descriptor
Nov 17 10:11:02 firewall slapd[2901]: daemon: activity on:
Nov 17 10:11:02 firewall slapd[2901]:  13r
Nov 17 10:11:02 firewall slapd[2901]:
Nov 17 10:11:02 firewall slapd[2901]: daemon: read active on 13
Nov 17 10:11:02 firewall slapd[2901]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Nov 17 10:11:02 firewall slapd[2901]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Nov 17 10:11:02 firewall slapd[2901]: connection_get(13)
Nov 17 10:11:02 firewall slapd[2901]: connection_get(13): got connid=1002
Nov 17 10:11:02 firewall slapd[2901]: connection_read(13): checking for input on id=1002
Nov 17 10:11:02 firewall slapd[2901]: ber_get_next on fd 13 failed errno=0 (Success)
Nov 17 10:11:02 firewall slapd[2901]: connection_read(13): input error=-2 id=1002, closing.
Nov 17 10:11:02 firewall slapd[2901]: connection_closing: readying conn=1002 sd=13 for close
Nov 17 10:11:02 firewall slapd[2901]: connection_close: deferring conn=1002 sd=13
Nov 17 10:11:02 firewall slapd[2901]: daemon: activity on 1 descriptor
Nov 17 10:11:02 firewall slapd[2901]: daemon: activity on:
Nov 17 10:11:02 firewall slapd[2901]:
Nov 17 10:11:02 firewall slapd[2901]: daemon: epoll: listen=7 active_threads=0 tvp=zero
Nov 17 10:11:02 firewall slapd[2901]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Nov 17 10:11:02 firewall slapd[2901]: conn=1002 op=1 RESULT tag=97 err=50 text=SASL(-14): authorization failure: unable authorization ID
Nov 17 10:11:02 firewall slapd[2901]: <== slap_sasl_bind: rc=50
Nov 17 10:11:02 firewall slapd[2901]: connection_resched: attempting closing conn=1002 sd=13
Nov 17 10:11:02 firewall slapd[2901]: connection_close: conn=1002 sd=13
Nov 17 10:11:02 firewall slapd[2901]: daemon: removing 13
Nov 17 10:11:02 firewall slapd[2901]: conn=1002 fd=13 closed (connection lost)
Nov 17 10:11:13 firewall sshd[2983]: Accepted keyboard-interactive/pam for root from 192.168.0.2 port 1622 ssh2
Nov 17 10:11:13 firewall sshd[2983]: subsystem request for sftp