On Jun 9, 2010, at 12:37 PM, Russ Allbery wrote:
I can tell you in general why a PAM module would do that. One of the .... much faster than the first. This information disclosure vulnerability could then be used to further target brute-force password attacks and
I understand that. I believe that my complaint about the logging problem is valid. If you look at the log excepts below, it appears that in one scenario no BIND attempt occurred. Logging it for success but not for failure in the logs (see where it skips right to send-ldap_result without logging the BIND attempt) tends to lead someone down the wrong road when debugging the problem.
Jun 4 14:58:52 ldap-server slapd[5158]: => dn: [1] Jun 4 14:58:52 ldap-server slapd[5158]: => acl_get: [2] attr userPassword Jun 4 14:58:52 ldap-server slapd[5158]: access_allowed: no res from state (userPassword) Jun 4 14:58:52 ldap-server slapd[5158]: => acl_mask: access to entry "uid=jrhett,ou=Users,dc=equinix,dc=com", attr "userPassword" requested Jun 4 14:58:52 ldap-server slapd[5158]: => acl_mask: to value by "", (=0) Jun 4 14:58:52 ldap-server slapd[5158]: <= check a_dn_pat: anonymous Jun 4 14:58:52 ldap-server slapd[5158]: <= acl_mask: [1] applying auth(=xd) (stop) Jun 4 14:58:52 ldap-server slapd[5158]: <= acl_mask: [1] mask: auth(=xd) Jun 4 14:58:52 ldap-server slapd[5158]: => access_allowed: auth access granted by auth(=xd) Jun 4 14:58:52 ldap-server slapd[5158]: send_ldap_result: conn=75 op=2 p=3 Jun 4 14:58:52 ldap-server slapd[5158]: send_ldap_result: err=49 matched="" text="" Jun 4 14:58:52 ldap-server slapd[5158]: send_ldap_response: msgid=3 tag=97 err=49 Jun 4 14:58:52 ldap-server slapd[5158]: conn=75 op=2 RESULT tag=97 err=49 text=
Jun 4 15:02:54 ldap-server slapd[5158]: => acl_get: [2] attr userPassword Jun 4 15:02:54 ldap-server slapd[5158]: access_allowed: no res from state (userPassword) Jun 4 15:02:54 ldap-server slapd[5158]: => acl_mask: access to entry "uid=jrhett,ou=Users,dc=equinix,dc=com", attr "userPassword" requested Jun 4 15:02:54 ldap-server slapd[5158]: => acl_mask: to value by "", (=0) Jun 4 15:02:54 ldap-server slapd[5158]: <= check a_dn_pat: anonymous Jun 4 15:02:54 ldap-server slapd[5158]: <= acl_mask: [1] applying auth(=xd) (stop) Jun 4 15:02:54 ldap-server slapd[5158]: <= acl_mask: [1] mask: auth(=xd) Jun 4 15:02:54 ldap-server slapd[5158]: => access_allowed: auth access granted by auth(=xd) Jun 4 15:02:54 ldap-server slapd[5158]: conn=83 op=0 BIND dn="uid=jrhett,ou=Users,dc=equinix,dc=com" mech=SIMPLE ssf=0 Jun 4 15:02:54 ldap-server slapd[5158]: do_bind: v3 bind: "uid=jrhett,ou=Users,dc=equinix,dc=com" to "uid=jrhett,ou=Users,dc=equinix,dc=com" Jun 4 15:02:54 ldap-server slapd[5158]: send_ldap_result: conn=83 op=0 p=3 Jun 4 15:02:54 ldap-server slapd[5158]: send_ldap_result: err=0 matched="" text="" Jun 4 15:02:54 ldap-server slapd[5158]: send_ldap_response: msgid=1 tag=97 err=0 Jun 4 15:02:54 ldap-server slapd[5158]: conn=83 op=0 RESULT tag=97 err=0 text= Jun 4 15:02:54 ldap-server slapd[5158]: daemon: activity on 1 descriptor Jun 4 15:02:54 ldap-server slapd[5158]: daemon: activity on: