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 anything in 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 admin from 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 name uid=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_apply rule='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=56 do_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