Hi folks,
Thanks to Pierangelo's last reply, I now know what I suspected: that my consumer servers are configured to authenticate to their providers using SASL/GSSAPI, but that sometimes they don't do this, especially with proxy authorization. I've documented the entire install process:
* OpenLDAP provider with MIT Kerberos V on Debian squeeze http://www.rjsystems.nl/en/2100-d6-openldap-provider-kerberos.php
* OpenLDAP consumer with MIT Kerberos V on Debian squeeze http://www.rjsystems.nl/en/2100-d6-openldap-consumer-kerberos.php
The last time I followed these instructions to the letter, proxy authorization worked. Now I've booted up the same machines again a few days later and it no longer works: the consumer still uses SASL to bind with the provider for replication, but it uses a SIMPLE bind for proxy authorization. Of course that results in an error. Yet, the configuration seems unchanged.
Has anyone else experienced this problem?
Thanks,
Jaap
PS -- If anyone is interested, I can supply plenty of details. See also my post of 12/24/2010 03:25:51 AM CET with subject "No ProxyAuthz with SASL-GSSAPI?"
Quoting Jaap Winius jwinius@umrk.nl:
... The last time I followed these instructions to the letter, proxy authorization worked. Now I've booted up the same machines again a few days later and it no longer works: the consumer still uses SASL to bind with the provider for replication, but it uses a SIMPLE bind for proxy authorization. ...
Okay, I think this is a bug.
It occurs on the consumer server when, logged in as the admin user, I try to add a new group, cn=bbeamon, to the DIT. After setting the olcLogLevel to -1, I found this:
slapd[2112]: <= hdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found (-30988)
It looks similar to this earlier bug report, which contains the same error:
http://www.openldap.org/its/index.cgi/Software%20Bugs?id=6472
Below is a larger section of the log from the consumer, ldapks2, that contains the above log entry (ldapks is an alias for the provider, ldapks1):
================================================= Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=8 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=9 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=10 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: SASL proxy authorize [conn=1000]: authcid="admin@EXAMPLE.COM" authzid="admin@EXAMPLE.COM" Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=2 BIND authcid="admin@EXAMPLE.COM" authzid="admin@EXAMPLE.COM" Jan 2 02:56:12 ldapks2 slapd[2112]: SASL Authorize [conn=1000]: proxy authorization allowed authzDN="" Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_sasl: err=0 len=-1 Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=2 BIND dn="uid=admin,ou=people,dc=example,dc=com" mech=GSSAPI sasl_ssf=56 ssf=56 Jan 2 02:56:12 ldapks2 slapd[2112]: do_bind: SASL/GSSAPI bind: dn="uid=admin,ou=people,dc=example,dc=com" sasl_ssf=56 Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_response: msgid=3 tag=97 err=0 Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=2 RESULT tag=97 err=0 text= Jan 2 02:56:12 ldapks2 slapd[2112]: <== slap_sasl_bind: rc=0 Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: activity on 1 descriptor Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: activity on: Jan 2 02:56:12 ldapks2 slapd[2112]: 16r Jan 2 02:56:12 ldapks2 slapd[2112]: Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: read active on 16 Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=8 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=9 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=10 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: connection_get(16) Jan 2 02:56:12 ldapks2 slapd[2112]: connection_get(16): got connid=1000 Jan 2 02:56:12 ldapks2 slapd[2112]: connection_read(16): checking for input on id=1000 Jan 2 02:56:12 ldapks2 slapd[2112]: op tag 0x68, time 1293933372 Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: activity on 1 descriptor Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: activity on: Jan 2 02:56:12 ldapks2 slapd[2112]: Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=8 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=9 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=10 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=3 do_add Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=3 do_add: dn (cn=bbeamon,ou=groups,dc=example,dc=com) Jan 2 02:56:12 ldapks2 slapd[2112]: >>> dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com> Jan 2 02:56:12 ldapks2 slapd[2112]: <<< dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com>, <cn=bbeamon,ou=groups,dc=example,dc=com> Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=3 ADD dn="cn=bbeamon,ou=groups,dc=example,dc=com" Jan 2 02:56:12 ldapks2 slapd[2112]: bdb_dn2entry("cn=bbeamon,ou=groups,dc=example,dc=com") Jan 2 02:56:12 ldapks2 slapd[2112]: => hdb_dn2id("ou=groups,dc=example,dc=com") Jan 2 02:56:12 ldapks2 slapd[2112]: <= hdb_dn2id: got id=0x3 Jan 2 02:56:12 ldapks2 slapd[2112]: => hdb_dn2id("cn=bbeamon,ou=groups,dc=example,dc=com") Jan 2 02:56:12 ldapks2 slapd[2112]: <= hdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found (-30988) Jan 2 02:56:12 ldapks2 slapd[2112]: entry_decode: "" Jan 2 02:56:12 ldapks2 slapd[2112]: <= entry_decode() Jan 2 02:56:12 ldapks2 slapd[2112]: hdb_referrals: tag=104 target="cn=bbeamon,ou=groups,dc=example,dc=com" matched="ou=groups,dc=example,dc=com" Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: conn=1000 op=3 p=3 Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: err=10 matched="" text="" Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: referral="ldap://ldapks.example.com:389/cn=bbeamon,ou=groups,dc=example,dc=com" Jan 2 02:56:12 ldapks2 slapd[2112]: >>> dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com> Jan 2 02:56:12 ldapks2 slapd[2112]: <<< dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com>, <cn=bbeamon,ou=groups,dc=example,dc=com> Jan 2 02:56:12 ldapks2 slapd[2112]: ldap_back_db_open: URI=ldap://ldapks.example.com:389 Jan 2 02:56:12 ldapks2 slapd[2112]: ==> ldap_back_add("cn=bbeamon,ou=groups,dc=example,dc=com") Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: conn=1000 op=3 p=3 Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: err=8 matched="" text="modifications require authentication" Jan 2 02:56:12 ldapks2 slapd[2112]: <== ldap_back_add("cn=bbeamon,ou=groups,dc=example,dc=com"): 8 Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: conn=1000 op=3 p=3 Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: err=8 matched="" text="" Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_response: msgid=4 tag=105 err=8 Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: activity on 1 descriptor Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: activity on:
=================================================
Quoting Jaap Winius jwinius@umrk.nl:
... The last time I followed these instructions to the letter, proxy authorization worked. Now I've booted up the same machines again a few days later and it no longer works: the consumer still uses SASL to bind with the provider for replication, but it uses a SIMPLE bind for proxy authorization. ...
Okay, I think this is a bug.
It occurs on the consumer server when, logged in as the admin user, I try to add a new group, cn=bbeamon, to the DIT. After setting the olcLogLevel to -1, I found this:
slapd[2112]: <= hdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found (-30988)
It looks similar to this earlier bug report, which contains the same error:
http://www.openldap.org/its/index.cgi/Software%20Bugs?id=6472
I don't think they're related.
Below is a larger section of the log from the consumer, ldapks2, that contains the above log entry (ldapks is an alias for the provider, ldapks1):
================================================= Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=8 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=9 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=10 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: SASL proxy authorize [conn=1000]: authcid="admin@EXAMPLE.COM" authzid="admin@EXAMPLE.COM" Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=2 BIND authcid="admin@EXAMPLE.COM" authzid="admin@EXAMPLE.COM" Jan 2 02:56:12 ldapks2 slapd[2112]: SASL Authorize [conn=1000]: proxy authorization allowed authzDN=""
^^^ here we're within slap_sasl_authorize() (slapd/sasl.c); prop_getnames() was called to collect information about the authenticated identity, including authzDN. This appears to be empty.
Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_sasl: err=0 len=-1 Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=2 BIND dn="uid=admin,ou=people,dc=example,dc=com" mech=GSSAPI sasl_ssf=56 ssf=56 Jan 2 02:56:12 ldapks2 slapd[2112]: do_bind: SASL/GSSAPI bind: dn="uid=admin,ou=people,dc=example,dc=com" sasl_ssf=56 Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_response: msgid=3 tag=97 err=0 Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=2 RESULT tag=97 err=0 text= Jan 2 02:56:12 ldapks2 slapd[2112]: <== slap_sasl_bind: rc=0 Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: activity on 1 descriptor Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: activity on: Jan 2 02:56:12 ldapks2 slapd[2112]: 16r Jan 2 02:56:12 ldapks2 slapd[2112]: Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: read active on 16 Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=8 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=9 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=10 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: connection_get(16) Jan 2 02:56:12 ldapks2 slapd[2112]: connection_get(16): got connid=1000 Jan 2 02:56:12 ldapks2 slapd[2112]: connection_read(16): checking for input on id=1000 Jan 2 02:56:12 ldapks2 slapd[2112]: op tag 0x68, time 1293933372 Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: activity on 1 descriptor Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: activity on: Jan 2 02:56:12 ldapks2 slapd[2112]: Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=8 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=9 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: daemon: epoll: listen=10 active_threads=0 tvp=zero Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=3 do_add Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=3 do_add: dn (cn=bbeamon,ou=groups,dc=example,dc=com)
^^^ here slapd receives a request to add the entry "cn=bbeamon,ou=groups,dc=example,dc=com"
Jan 2 02:56:12 ldapks2 slapd[2112]: >>> dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com> Jan 2 02:56:12 ldapks2 slapd[2112]: <<< dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com>, <cn=bbeamon,ou=groups,dc=example,dc=com> Jan 2 02:56:12 ldapks2 slapd[2112]: conn=1000 op=3 ADD dn="cn=bbeamon,ou=groups,dc=example,dc=com" Jan 2 02:56:12 ldapks2 slapd[2112]: bdb_dn2entry("cn=bbeamon,ou=groups,dc=example,dc=com") Jan 2 02:56:12 ldapks2 slapd[2112]: => hdb_dn2id("ou=groups,dc=example,dc=com") Jan 2 02:56:12 ldapks2 slapd[2112]: <= hdb_dn2id: got id=0x3
^^^ here back-hdb gets the parent of the entry that's being added
Jan 2 02:56:12 ldapks2 slapd[2112]: => hdb_dn2id("cn=bbeamon,ou=groups,dc=example,dc=com") Jan 2 02:56:12 ldapks2 slapd[2112]: <= hdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found (-30988)
^^^ here back-hdb verifies that the entry "cn=bbeamon,ou=groups,dc=example,dc=com" does not exist yet. This is why you see this error, but no error is logged, because it is expected.
Jan 2 02:56:12 ldapks2 slapd[2112]: entry_decode: "" Jan 2 02:56:12 ldapks2 slapd[2112]: <= entry_decode() Jan 2 02:56:12 ldapks2 slapd[2112]: hdb_referrals: tag=104 target="cn=bbeamon,ou=groups,dc=example,dc=com" matched="ou=groups,dc=example,dc=com"
^^^ a referral is generated because the server is a consumer
Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: conn=1000 op=3 p=3 Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: err=10 matched="" text=""
^^^ here you get a referral response code (err=10).
Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: referral="ldap://ldapks.example.com:389/cn=bbeamon,ou=groups,dc=example,dc=com" Jan 2 02:56:12 ldapks2 slapd[2112]: >>> dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com> Jan 2 02:56:12 ldapks2 slapd[2112]: <<< dnPrettyNormal: <cn=bbeamon,ou=groups,dc=example,dc=com>, <cn=bbeamon,ou=groups,dc=example,dc=com> Jan 2 02:56:12 ldapks2 slapd[2112]: ldap_back_db_open: URI=ldap://ldapks.example.com:389 Jan 2 02:56:12 ldapks2 slapd[2112]: ==> ldap_back_add("cn=bbeamon,ou=groups,dc=example,dc=com")
^^^ here slapo-chain(5) tries to chase the referral
Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: conn=1000 op=3 p=3 Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: err=8 matched="" text="modifications require authentication"
^^^ You get an error because the referral was chased anonymously.
Jan 2 02:56:12 ldapks2 slapd[2112]: <== ldap_back_add("cn=bbeamon,ou=groups,dc=example,dc=com"): 8 Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: conn=1000 op=3 p=3 Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_result: err=8 matched="" text="" Jan 2 02:56:12 ldapks2 slapd[2112]: send_ldap_response: msgid=4 tag=105 err=8
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)
--- dn: olcOverlay={0}chain,olcDatabase={-1}frontend,cn=config objectClass: olcOverlayConfig objectClass: olcChainConfig olcOverlay: {0}chain olcChainReturnError: TRUE
dn: olcDatabase={0}ldap,olcOverlay={0}chain,olcDatabase={-1}frontend,cn=config objectClass: olcLDAPConfig objectClass: olcChainDatabase olcDatabase: {0}ldap olcDbURI: "ldap://ldapks.example.com:389/"; olcDbIDAssertBind: bindmethod=sasl saslmech=gssapi mode=self olcDbRebindAsUser: TRUE ---
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.
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.
p.
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
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
^^^ this call shouldn't be here; on the contrary, this should result in calling ldap_sasl_interactive_bind_s() from within back-ldap's ldap_back_proxy_authz_bind(). I have no clue about why this is happening since I've never tested this with GSSAPI (and I can't do it now). However I've tested it with other SASL mechs (including DIGEST-MD5 and EXTERNAL) and it worked as expected.
p.
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
Quoting masarati@aero.polimi.it:
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
^^^ this call shouldn't be here; on the contrary, this should result in calling ldap_sasl_interactive_bind_s() from within back-ldap's ldap_back_proxy_authz_bind(). I have no clue about why this is happening since I've never tested this with GSSAPI (and I can't do it now). However I've tested it with other SASL mechs (including DIGEST-MD5 and EXTERNAL) and it worked as expected.
Then I suppose it's a good thing I ran into it. ;-)
Shall I file a bug report? If so, I would prefer to do it via Debian's bug reporting system, since that's what I'm using (along with your 2010-04-29 patch for that error regarding the olcDbURI attribute).
Thanks,
Jaap
Quoting masarati@aero.polimi.it:
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
^^^ this call shouldn't be here; on the contrary, this should result in calling ldap_sasl_interactive_bind_s() from within back-ldap's ldap_back_proxy_authz_bind(). I have no clue about why this is happening since I've never tested this with GSSAPI (and I can't do it now). However I've tested it with other SASL mechs (including DIGEST-MD5 and EXTERNAL) and it worked as expected.
Then I suppose it's a good thing I ran into it. ;-)
As I said, I have no clue.
Shall I file a bug report?
Yes, if you like. Hopefully someone can test your scenario with GSSAPI.
If so, I would prefer to do it via Debian's bug reporting system, since that's what I'm using
If you use Debian's bug reporting, you implicitly assume Debian maintainers will address the issue. If you want OpenLDAP developers to address it, you need to use OpenLDAP's tracker.
p.
openldap-technical@openldap.org
-
Jaap Winius -
masarati＠aero.polimi.it