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

Re: SASL proxy auth problem -- looks like a bug

To: openldap-technical@openldap.org
Subject: Re: SASL proxy auth problem -- looks like a bug
From: Jaap Winius <jwinius@umrk.nl>
Date: Sun, 02 Jan 2011 14:17:22 +0100
Content-disposition: inline
In-reply-to: <9f99a6e0f6955e466f96d90f2fb8a7b1.squirrel@www.aero.polimi.it>
References: <20110101200248.14724kb8t7f9ddic@bitis.umrk.nl> <20110102040251.151873lg8yll7gws@bitis.umrk.nl> <9f99a6e0f6955e466f96d90f2fb8a7b1.squirrel@www.aero.polimi.it>
User-agent: Internet Messaging Program (IMP) H3 (4.3.8)

Quoting masarati@aero.polimi.it:

To determine why the referral was chased anonymously we need to know the
configuration of your slapo-chain(5).  I assume the configuration you
posted in an earlier message
<http://www.openldap.org/lists/openldap-technical/201012/msg00209.html> is
still valid (reported below)


Yes, it's still exactly the same.

Assuming you did not mask hostnames and you did not make any mistake in
masking them, this configuration should be fine, AFAIK, since the URI in
olcDbURI matches that of the referral, "ldap://ldapks.example.com:389";,
and authenticated referral chasing is based on the referral URI's
host:port part.

Checked it again. I can ssh from ldapks2 to ldapks.example.com and,indeed, end up on ldapks1 as expected. There's no firewall or anythingin between. If I use nmap on ldapks2 to check TCP port 389 on ldapks,it's open.

I haven't checked the specific case of SASL-GSSAPI but authenticated
referral chasing works as expected; perhaps you can provide a few more
details about what's actually happening inside slapo-chain?  For example,
if you run the consumer from command line with -dstats,trace,args we can
also get the logging from libldap, which may allow to understand what
slapo-chain(5) is actually doing.

Okay, here's the output from slapd again, to add cn=bbeamon as adminfrom the consumer (same result), but with the -dstats,trace,args:


=======================================
slap_listener_activate(7):

slap_listener(ldap:///)

conn=1001 fd=14 ACCEPT from IP=127.0.1.1:41637 (IP=0.0.0.0:389)
connection_get(14)
connection_get(14): got connid=1001
connection_read(14): checking for input on id=1001
ber_get_next
ber_get_next: tag 0x30 len 632 contents:
op tag 0x60, time 1293973781
ber_get_next
conn=1001 op=0 do_bind
ber_scanf fmt ({imt) ber:
ber_scanf fmt ({m) ber:
ber_scanf fmt (m) ber:
ber_scanf fmt (}}) ber:

dnPrettyNormal: <>

<<< dnPrettyNormal: <>, <>
conn=1001 op=0 BIND dn="" method=163
do_bind: dn () SASL mech GSSAPI
==> sasl_bind: dn="" mech=GSSAPI datalen=604
send_ldap_sasl: err=14 len=156
send_ldap_response: msgid=1 tag=97 err=14
ber_flush2: 203 bytes to sd 14
conn=1001 op=0 RESULT tag=97 err=14 text=SASL(0): successful result:
<== slap_sasl_bind: rc=14
connection_get(14)
connection_get(14): got connid=1001
connection_read(14): checking for input on id=1001
ber_get_next
ber_get_next: tag 0x30 len 20 contents:
op tag 0x60, time 1293973781
ber_get_next
conn=1001 op=1 do_bind
ber_scanf fmt ({imt) ber:
ber_scanf fmt ({m) ber:
ber_scanf fmt (}}) ber:

dnPrettyNormal: <>

<<< dnPrettyNormal: <>, <>
conn=1001 op=1 BIND dn="" method=163
do_bind: dn () SASL mech GSSAPI
==> sasl_bind: dn="" mech=<continuing> datalen=0
send_ldap_sasl: err=14 len=32
send_ldap_response: msgid=2 tag=97 err=14
ber_flush2: 76 bytes to sd 14
conn=1001 op=1 RESULT tag=97 err=14 text=SASL(0): successful result:
connection_get(14)
connection_get(14): got connid=1001
connection_read(14): checking for input on id=1001
ber_get_next
ber_get_next: tag 0x30 len 54 contents:
op tag 0x60, time 1293973781
connection_input: conn=1001 deferring operation: binding
ber_get_next
<== slap_sasl_bind: rc=14
conn=1001 op=2 do_bind
ber_scanf fmt ({imt) ber:
ber_scanf fmt ({m) ber:
ber_scanf fmt (m) ber:
ber_scanf fmt (}}) ber:

dnPrettyNormal: <>

<<< dnPrettyNormal: <>, <>
conn=1001 op=2 BIND dn="" method=163
do_bind: dn () SASL mech GSSAPI
==> sasl_bind: dn="" mech=<continuing> datalen=32
SASL Canonicalize [conn=1001]: authcid="admin"
slap_sasl_getdn: conn 1001 id=admin [len=5]
=> ldap_dn2bv(16)
<= ldap_dn2bv(uid=admin,cn=EXAMPLE.COM,cn=GSSAPI,cn=auth)=0
slap_sasl_getdn: u:id converted to uid=admin,cn=EXAMPLE.COM,cn=GSSAPI,cn=auth

dnNormalize: <uid=admin,cn=EXAMPLE.COM,cn=GSSAPI,cn=auth>

=> ldap_bv2dn(uid=admin,cn=EXAMPLE.COM,cn=GSSAPI,cn=auth,0)
<= ldap_bv2dn(uid=admin,cn=EXAMPLE.COM,cn=GSSAPI,cn=auth)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=admin,cn=example.com,cn=gssapi,cn=auth)=0
<<< dnNormalize: <uid=admin,cn=example.com,cn=gssapi,cn=auth>

==>slap_sasl2dn: converting SASL nameuid=admin,cn=example.com,cn=gssapi,cn=auth to a DN==> rewrite_context_apply [depth=1]string='uid=admin,cn=example.com,cn=gssapi,cn=auth'==> rewrite_rule_applyrule='uid=([^,]+),cn=example.com,cn=gssapi,cn=auth'string='uid=admin,cn=example.com,cn=gssapi,cn=auth' [1 pass(es)]==> rewrite_context_apply [depth=1]res={0,'uid=admin,ou=people,dc=example,dc=com'}[rw] authid: "uid=admin,cn=example.com,cn=gssapi,cn=auth" ->"uid=admin,ou=people,dc=example,dc=com"

slap_parseURI: parsing uid=admin,ou=people,dc=example,dc=com
ldap_url_parse_ext(uid=admin,ou=people,dc=example,dc=com)

dnNormalize: <uid=admin,ou=people,dc=example,dc=com>

=> ldap_bv2dn(uid=admin,ou=people,dc=example,dc=com,0)
<= ldap_bv2dn(uid=admin,ou=people,dc=example,dc=com)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=admin,ou=people,dc=example,dc=com)=0
<<< dnNormalize: <uid=admin,ou=people,dc=example,dc=com>
<==slap_sasl2dn: Converted SASL name to uid=admin,ou=people,dc=example,dc=com
slap_sasl_getdn: dn:id converted to uid=admin,ou=people,dc=example,dc=com

SASL Canonicalize [conn=1001]:slapAuthcDN="uid=admin,ou=people,dc=example,dc=com"SASL proxy authorize [conn=1001]: authcid="admin@EXAMPLE.COM"authzid="admin@EXAMPLE.COM"

conn=1001 op=2 BIND authcid="admin@EXAMPLE.COM" authzid="admin@EXAMPLE.COM"
SASL Authorize [conn=1001]:  proxy authorization allowed authzDN=""
send_ldap_sasl: err=0 len=-1

conn=1001 op=2 BIND dn="uid=admin,ou=people,dc=example,dc=com"mech=GSSAPI sasl_ssf=56 ssf=56do_bind: SASL/GSSAPI bind: dn="uid=admin,ou=people,dc=example,dc=com"sasl_ssf=56

send_ldap_response: msgid=3 tag=97 err=0
ber_flush2: 14 bytes to sd 14
conn=1001 op=2 RESULT tag=97 err=0 text=
<== slap_sasl_bind: rc=0
connection_get(14)
connection_get(14): got connid=1001
connection_read(14): checking for input on id=1001
ldap_pvt_sasl_generic_install
ber_get_next
ber_get_next: tag 0x30 len 120 contents:
op tag 0x68, time 1293973781
ber_get_next
conn=1001 op=3 do_add
ber_scanf fmt ({m) ber:
conn=1001 op=3 do_add: dn (cn=bbeamon,ou=groups,dc=example,dc=com)
ber_scanf fmt ({m{W}}) ber:
ber_scanf fmt ({m{W}}) ber:
ber_scanf fmt ({m{W}}) ber:
ber_scanf fmt (}) ber:

dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com>

=> ldap_bv2dn(cn=bbeamon,ou=groups,dc=example,dc=com,0)
<= ldap_bv2dn(cn=bbeamon,ou=groups,dc=example,dc=com)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(cn=bbeamon,ou=groups,dc=example,dc=com)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(cn=bbeamon,ou=groups,dc=example,dc=com)=0

<<< dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com>,<cn=bbeamon,ou=groups,dc=example,dc=com>

conn=1001 op=3 ADD dn="cn=bbeamon,ou=groups,dc=example,dc=com"
bdb_dn2entry("cn=bbeamon,ou=groups,dc=example,dc=com")
=> hdb_dn2id("cn=bbeamon,ou=groups,dc=example,dc=com")

<= hdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found(-30988)hdb_referrals: tag=104 target="cn=bbeamon,ou=groups,dc=example,dc=com"matched="ou=groups,dc=example,dc=com"

ldap_url_parse_ext(ldap://ldapks.example.com:389/)
send_ldap_result: conn=1001 op=3 p=3
send_ldap_result: err=10 matched="" text=""

send_ldap_result:referral="ldap://ldapks.example.com:389/cn=bbeamon,ou=groups,dc=example,dc=com";

ldap_url_parse_ext(ldap://ldapks.example.com:389/cn=bbeamon,ou=groups,dc=example,dc=com)

dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com>

=> ldap_bv2dn(cn=bbeamon,ou=groups,dc=example,dc=com,0)
<= ldap_bv2dn(cn=bbeamon,ou=groups,dc=example,dc=com)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(cn=bbeamon,ou=groups,dc=example,dc=com)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(cn=bbeamon,ou=groups,dc=example,dc=com)=0

<<< dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com>,<cn=bbeamon,ou=groups,dc=example,dc=com>

ldap_back_db_open: URI=ldap://ldapks.example.com:389
==> ldap_back_add("cn=bbeamon,ou=groups,dc=example,dc=com")
ldap_create
ldap_url_parse_ext(ldap://ldapks.example.com:389)
=>ldap_back_getconn: conn=1001 op=3: lc=0x960e6f8 inserted refcnt=1 rc=0
ldap_sasl_bind
ldap_send_initial_request
ldap_new_connection 1 1 0
ldap_int_open_connection
ldap_connect_to_host: TCP ldapks.example.com:389
ldap_new_socket: 16
ldap_prepare_socket: 16
ldap_connect_to_host: Trying 192.168.2.53:389
ldap_pvt_connect: fd: 16 tm: -1 async: 0
ldap_open_defconn: successful
ldap_send_server_request
ber_scanf fmt ({it) ber:
ber_scanf fmt ({i) ber:
ber_flush2: 14 bytes to sd 16
ldap_result ld 0x962a208 msgid 1
wait4msg ld 0x962a208 msgid 1 (timeout 100000 usec)
wait4msg continue ld 0x962a208 msgid 1 all 1
** ld 0x962a208 Connections:
* host: ldapks.example.com  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  2 14:09:41 2011


** ld 0x962a208 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x962a208 request count 1 (abandoned 0)
** ld 0x962a208 Response Queue:
   Empty
  ld 0x962a208 response count 0
ldap_chkResponseList ld 0x962a208 msgid 1 all 1
ldap_chkResponseList returns ld 0x962a208 NULL
ldap_int_select
read1msg: ld 0x962a208 msgid 1 all 1
ber_get_next
ber_get_next: tag 0x30 len 12 contents:
read1msg: ld 0x962a208 msgid 1 message type bind
ber_scanf fmt ({eAA) ber:
read1msg: ld 0x962a208 0 new referrals
read1msg:  mark request completed, ld 0x962a208 msgid 1
request done: ld 0x962a208 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_result
ber_scanf fmt ({iAA) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
ldap_add_ext
ldap_send_initial_request
ldap_send_server_request
ber_scanf fmt ({it) ber:
ber_scanf fmt ({) ber:
ber_flush2: 122 bytes to sd 16
ldap_result ld 0x962a208 msgid 2
wait4msg ld 0x962a208 msgid 2 (timeout 100000 usec)
wait4msg continue ld 0x962a208 msgid 2 all 1
** ld 0x962a208 Connections:
* host: ldapks.example.com  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  2 14:09:41 2011


** ld 0x962a208 Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x962a208 request count 1 (abandoned 0)
** ld 0x962a208 Response Queue:
   Empty
  ld 0x962a208 response count 0
ldap_chkResponseList ld 0x962a208 msgid 2 all 1
ldap_chkResponseList returns ld 0x962a208 NULL
ldap_int_select
read1msg: ld 0x962a208 msgid 2 all 1
ber_get_next
ber_get_next: tag 0x30 len 48 contents:
read1msg: ld 0x962a208 msgid 2 message type add
ber_scanf fmt ({eAA) ber:
ldap_chase_referrals
read1msg:  V2 referral chased, mark request completed, id = 2
read1msg: ld 0x962a208 0 new referrals
read1msg:  mark request completed, ld 0x962a208 msgid 2
request done: ld 0x962a208 msgid 2

res_errno: 8, res_error: <modifications require authentication>,res_matched: <>

ldap_free_request (origid 2, msgid 2)
ldap_parse_result
ber_scanf fmt ({iAA) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
send_ldap_result: conn=1001 op=3 p=3
send_ldap_result: err=8 matched="" text="modifications require authentication"
<== ldap_back_add("cn=bbeamon,ou=groups,dc=example,dc=com"): 8
ldap_free_connection 1 1
ldap_send_unbind
ber_flush2: 7 bytes to sd 16
ldap_free_connection: actually freed
send_ldap_result: conn=1001 op=3 p=3
send_ldap_result: err=8 matched="" text=""
send_ldap_response: msgid=4 tag=105 err=8
ber_flush2: 14 bytes to sd 14
connection_get(14)
connection_get(14): got connid=1001
connection_read(14): checking for input on id=1001
ber_get_next
ber_get_next: tag 0x30 len 5 contents:
op tag 0x42, time 1293973781
ber_get_next
ber_get_next on fd 14 failed errno=0 (Success)
conn=1001 op=4 do_unbind
conn=1001 op=4 UNBIND
conn=1001 op=3 RESULT tag=105 err=8 text=
connection_close: conn=1001 sd=14
conn=1001 fd=14 closed

=======================================

Thanks,

Jaap

Follow-Ups:
- Re: SASL proxy auth problem -- looks like a bug
  - From: masarati@aero.polimi.it

References:
- SASL proxy auth problem
  - From: Jaap Winius <jwinius@umrk.nl>
- Re: SASL proxy auth problem -- looks like a bug
  - From: Jaap Winius <jwinius@umrk.nl>
- Re: SASL proxy auth problem -- looks like a bug
  - From: masarati@aero.polimi.it

Prev by Date: Re: Windows ldp.exe kills openldap 2.4.23
Next by Date: Re: SASL proxy auth problem -- looks like a bug
Index(es):
- Chronological
- Thread