RE: [nssldap] pam_ldap and nss_ldap can't connect to LDAP server(s)

[Aaron Hicks <HicksA [at] landcareresearch.co.nz>]

Hmm, getent passwd ldapuser and id ldapuser now produce these debug messages, 
and not find the LDAP user (even though it is exactly the same user it's 
binding with)

ldap_create
ldap_url_parse_ext(ldap://ldap.our.long.domain.co.nz)
ldap_create
ldap_url_parse_ext(ldap://ldap.our.long.domain.co.nz)
ldap_simple_bind
ldap_sasl_bind
ldap_send_initial_request
ldap_new_connection 1 1 0
ldap_int_open_connection
ldap_connect_to_host: TCP ldap.our.long.domain.co.nz:389
ldap_new_socket: 3
ldap_prepare_socket: 3
ldap_connect_to_host: Trying 202.27.242.229:389
ldap_connect_timeout: fd: 3 tm: 120 async: 0
ldap_ndelay_on: 3
ldap_is_sock_ready: 3
ldap_ndelay_off: 3
ldap_open_defconn: successful
ldap_send_server_request
ber_scanf fmt ({it) ber:
ber_scanf fmt ({i) ber:
ber_flush: 119 bytes to sd 3
ldap_result ld 0x2b37070 msgid 1
ldap_chkResponseList ld 0x2b37070 msgid 1 all 0
ldap_chkResponseList returns ld 0x2b37070 NULL
wait4msg ld 0x2b37070 msgid 1 (timeout 120000000 usec)
wait4msg continue ld 0x2b37070 msgid 1 all 0
** ld 0x2b37070 Connections:
* host: ldap.our.long.domain.co.nz  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Fri Jun 26 11:51:12 2009

** ld 0x2b37070 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
** ld 0x2b37070 Response Queue:
   Empty
ldap_chkResponseList ld 0x2b37070 msgid 1 all 0
ldap_chkResponseList returns ld 0x2b37070 NULL
ldap_int_select
read1msg: ld 0x2b37070 msgid 1 all 0
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
read1msg: ld 0x2b37070 msgid 1 message type bind
ber_scanf fmt ({eaa) ber:
ber_scanf fmt ({eaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg: ld 0x2b37070 0 new referrals
read1msg:  mark request completed, ld 0x2b37070 msgid 1
request done: ld 0x2b37070 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
ldap_search
put_filter: "(&(objectClass=user)(sAMAccountName=ldapuser))"
put_filter: AND
put_filter_list "(objectClass=user)(sAMAccountName=ldapuser)"
put_filter: "(objectClass=user)"
put_filter: simple
put_simple_filter: "objectClass=user"
put_filter: "(sAMAccountName=ldapuser)"
put_filter: simple
put_simple_filter: "sAMAccountName=ldapuser"
ldap_send_initial_request
ldap_send_server_request
ber_scanf fmt ({it) ber:
ber_scanf fmt ({) ber:
ber_flush: 242 bytes to sd 3
ldap_result ld 0x2b37070 msgid 2
ldap_chkResponseList ld 0x2b37070 msgid 2 all 1
ldap_chkResponseList returns ld 0x2b37070 NULL
wait4msg ld 0x2b37070 msgid 2 (timeout 30000000 usec)
wait4msg continue ld 0x2b37070 msgid 2 all 1
** ld 0x2b37070 Connections:
* host: ldap.our.long.domain.co.nz  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Fri Jun 26 11:51:12 2009

** ld 0x2b37070 Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
** ld 0x2b37070 Response Queue:
   Empty
ldap_chkResponseList ld 0x2b37070 msgid 2 all 1
ldap_chkResponseList returns ld 0x2b37070 NULL
ldap_int_select
read1msg: ld 0x2b37070 msgid 2 all 1
ber_get_next
ber_get_next: tag 0x30 len 245 contents:
read1msg: ld 0x2b37070 msgid 2 message type search-entry
wait4msg ld 0x2b37070 30 secs to go
wait4msg continue ld 0x2b37070 msgid 2 all 1
** ld 0x2b37070 Connections:
* host: ldap.our.long.domain.co.nz  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Fri Jun 26 11:51:12 2009

** ld 0x2b37070 Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
** ld 0x2b37070 Response Queue:
 * msgid 2,  type 100
ldap_chkResponseList ld 0x2b37070 msgid 2 all 1
ldap_chkResponseList returns ld 0x2b37070 NULL
ldap_int_select
read1msg: ld 0x2b37070 msgid 2 all 1
ber_get_next
ber_get_next: tag 0x30 len 135 contents:
read1msg: ld 0x2b37070 msgid 2 message type search-reference
ber_scanf fmt ({v}) ber:
ldap_chase_v3referrals
ldap_url_parse_ext(ldap://DomainDnsZones.our.long.domain.co.nz/DC=DomainDnsZones,DC=landcare,DC=ad,DC=landcareresearch,DC=co,DC=nz)
re_encode_request: new msgid 3, new dn 
<DC=DomainDnsZones,DC=landcare,DC=ad,DC=landcareresearch,DC=co,DC=nz>
ber_scanf fmt ({it) ber:
ber_scanf fmt ({me) ber:
ldap_chase_v3referral: msgid 2, url 
"ldap://DomainDnsZones.our.long.domain.co.nz/DC=DomainDnsZones,DC=landcare,DC=ad,DC=landcareresearch,DC=co,DC=nz"
ldap_send_server_request
ldap_new_connection 0 1 1
ldap_int_open_connection
ldap_connect_to_host: TCP DomainDnsZones.our.long.domain.co.nz:389
ldap_new_socket: 4
ldap_prepare_socket: 4
ldap_connect_to_host: Trying 202.27.242.229:389
ldap_connect_timeout: fd: 4 tm: 120 async: 0
ldap_ndelay_on: 4
ldap_is_sock_ready: 4
ldap_ndelay_off: 4
Call application rebind_proc
ldap_simple_bind
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ber_scanf fmt ({it) ber:
ber_scanf fmt ({i) ber:
ber_flush: 119 bytes to sd 4
ldap_result ld 0x2b37070 msgid 4
ldap_chkResponseList ld 0x2b37070 msgid 4 all 0
ldap_chkResponseList returns ld 0x2b37070 NULL
wait4msg ld 0x2b37070 msgid 4 (timeout 120000000 usec)
wait4msg continue ld 0x2b37070 msgid 4 all 0
** ld 0x2b37070 Connections:
* host: DomainDnsZones.our.long.domain.co.nz  port: 0
  refcnt: 2  status: Connected
  last used: Fri Jun 26 11:51:12 2009
  rebind in progress
    queue is empty

* host: ldap.our.long.domain.co.nz  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Fri Jun 26 11:51:12 2009

** ld 0x2b37070 Outstanding Requests:
 * msgid 4,  origid 4, status InProgress
   outstanding referrals 0, parent count 0
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 1, parent count 0
** ld 0x2b37070 Response Queue:
 * msgid 2,  type 100
ldap_chkResponseList ld 0x2b37070 msgid 4 all 0
ldap_chkResponseList returns ld 0x2b37070 NULL
ldap_int_select
read1msg: ld 0x2b37070 msgid 4 all 0
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
read1msg: ld 0x2b37070 msgid 2 message type search-result
ber_scanf fmt ({eaa) ber:
ber_scanf fmt ({eaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg: ld 0x2b37070 0 new referrals
read1msg:  mark request completed, ld 0x2b37070 msgid 2
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
wait4msg ld 0x2b37070 120 secs to go
wait4msg continue ld 0x2b37070 msgid 4 all 0
** ld 0x2b37070 Connections:
* host: DomainDnsZones.our.long.domain.co.nz  port: 0
  refcnt: 2  status: Connected
  last used: Fri Jun 26 11:51:12 2009
  rebind in progress
    queue is empty

* host: ldap.our.long.domain.co.nz  port: 389  (default)
  refcnt: 1  status: Connected
  last used: Fri Jun 26 11:51:12 2009

** ld 0x2b37070 Outstanding Requests:
 * msgid 4,  origid 4, status InProgress
   outstanding referrals 0, parent count 0
 * msgid 2,  origid 2, status RequestCompleted
   outstanding referrals 1, parent count 0
** ld 0x2b37070 Response Queue:
 * msgid 2,  type 100
ldap_chkResponseList ld 0x2b37070 msgid 4 all 0
ldap_chkResponseList returns ld 0x2b37070 NULL
ldap_int_select
read1msg: ld 0x2b37070 msgid 4 all 0
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
read1msg: ld 0x2b37070 msgid 4 message type bind
ber_scanf fmt ({eaa) ber:
ber_scanf fmt ({eaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg: ld 0x2b37070 0 new referrals
read1msg:  mark request completed, ld 0x2b37070 msgid 4
request done: ld 0x2b37070 msgid 4
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 4, msgid 4)
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
ber_scanf fmt ({it) ber:
ber_scanf fmt ({) ber:
ber_flush: 261 bytes to sd 4
adding response ld 0x2b37070 msgid 2 type 115:
wait4msg ld 0x2b37070 30 secs to go
wait4msg continue ld 0x2b37070 msgid 2 all 1
** ld 0x2b37070 Connections:
* host: DomainDnsZones.our.long.domain.co.nz  port: 0
  refcnt: 1  status: Connected
  last used: Fri Jun 26 11:51:12 2009

* host: ldap.our.long.domain.co.nz  port: 389  (default)
  refcnt: 1  status: Connected
  last used: Fri Jun 26 11:51:12 2009

** ld 0x2b37070 Outstanding Requests:
 * msgid 3,  origid 2, status InProgress
   outstanding referrals 0, parent count 1
 * msgid 2,  origid 2, status RequestCompleted
   outstanding referrals 1, parent count 1
** ld 0x2b37070 Response Queue:
 * msgid 2,  type 100
   chained responses:
  * msgid 2,  type 115
ldap_chkResponseList ld 0x2b37070 msgid 2 all 1
ldap_chkResponseList returns ld 0x2b37070 NULL
ldap_int_select
read1msg: ld 0x2b37070 msgid 2 all 1
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
read1msg: ld 0x2b37070 msgid 3 message type search-result
ber_scanf fmt ({eaa) ber:
ber_scanf fmt ({eaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg: ld 0x2b37070 0 new referrals
read1msg:  mark request completed, ld 0x2b37070 msgid 3
merged parent (id 2) error info:  result errno 0, error <>, matched <>
request done: ld 0x2b37070 msgid 2
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 2, msgid 2)
ldap_free_request (origid 2, msgid 3)
ldap_free_connection 0 1
ldap_send_unbind
ber_flush: 7 bytes to sd 4
ldap_free_connection: actually freed
adding response ld 0x2b37070 msgid 2 type 101:
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt ([v]) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([v]) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ldap_msgfree
ldap_unbind
ldap_free_connection 1 1
ldap_send_unbind
ber_flush: 7 bytes to sd 3
ldap_free_connection: actually freed

> -----Original Message-----
> From: owner-nssldap@padl.com [owner-nssldap [at] padl.com] On Behalf
> Of Aaron Hicks
> Sent: Friday, 26 June 2009 11:25 a.m.
> To: pamldap@padl.com; nssldap@padl.com
> Subject: RE: [nssldap] pam_ldap and nss_ldap can't connect to LDAP
> server(s)
>
> Ok, some progress.
>
> This error:
>
> new result:  res_errno: 49, res_error: <80090308: LdapErr: DSID-
>  0C090334, comment: AcceptSecurityContext error, data 525, vece>,
>
> According to this page: http://www-
> 01.ibm.com/support/docview.wss?rs=688&uid=swg21290631
>
> Told me that the username was not correct. Some mucking about revealed
> that the quote marks around "User Name" were unecessary. nns_ldap is
> now binding to the domain server
>
> id usr and getent passwd user are still unable to find usernames, so
> I'll look at the base DN used for searches and any filters in place.
>
> Regards,
>
> Aaron Hicks
>
> > -----Original Message-----
> > From: owner-nssldap@padl.com [owner-nssldap [at] padl.com] On
> Behalf
> > Of Aaron Hicks
> > Sent: Friday, 26 June 2009 10:23 a.m.
> > To: pamldap@padl.com; nssldap@padl.com
> > Subject: RE: [nssldap] pam_ldap and nss_ldap can't connect to LDAP
> > server(s)
> >
> > Thanks Buchan.
> >
> > The bits I've snipped out of ldap.conf were all commented out, and
> the
> > errors pointed out were due to me manually mangling the parts that
> > violate our policies for submitting to public lists. I'll be more
> > careful.
> >
> > I've made a couple of changes which deal with the exessive delays on
> > failed connections in ldap.conf:
> >
> > debug 1
> > bind_policy soft
> > tls_checkpeer no
> > nss_connect_policy oneshot
> >
> > Looking at the debug messages it looks a lot like nss_ldap is failing
> > to bind to LDAP on the AD server. I've requested a user account for
> > searching the domain which doesn't have a space in its name.
> >
> > And here's the debugging info from getent
> >
> > [root@centos ~]# getent passwd user
> > ldap_create
> > ldap_url_parse_ext(ldap://ldap.our.long.domain.co.nz)
> > ldap_create
> > ldap_url_parse_ext(ldap://ldap.our.long.domain.co.nz)
> > ldap_simple_bind
> > ldap_sasl_bind
> > ldap_send_initial_request
> > ldap_new_connection 1 1 0
> > ldap_int_open_connection
> > ldap_connect_to_host: TCP ldap.our.long.domain.co.nz:389
> > ldap_new_socket: 3
> > ldap_prepare_socket: 3
> > ldap_connect_to_host: Trying x.x.x.x:389
> > ldap_connect_timeout: fd: 3 tm: 10 async: 0
> > ldap_ndelay_on: 3
> > ldap_is_sock_ready: 3
> > ldap_ndelay_off: 3
> > ldap_open_defconn: successful
> > ldap_send_server_request
> > ber_scanf fmt ({it) ber:
> > ber_scanf fmt ({i) ber:
> > ber_flush: 121 bytes to sd 3
> > ldap_result ld 0x49d1310 msgid 1
> > ldap_chkResponseList ld 0x49d1310 msgid 1 all 0
> > ldap_chkResponseList returns ld 0x49d1310 NULL
> > wait4msg ld 0x49d1310 msgid 1 (timeout 10000000 usec)
> > wait4msg continue ld 0x49d1310 msgid 1 all 0
> > ** ld 0x49d1310 Connections:
> > * host: ldap.our.long.domain.co.nz  port: 389  (default)
> >   refcnt: 2  status: Connected
> >   last used: Fri Jun 26 10:11:04 2009
> >
> > ** ld 0x49d1310 Outstanding Requests:
> >  * msgid 1,  origid 1, status InProgress
> >    outstanding referrals 0, parent count 0
> > ** ld 0x49d1310 Response Queue:
> >    Empty
> > ldap_chkResponseList ld 0x49d1310 msgid 1 all 0
> > ldap_chkResponseList returns ld 0x49d1310 NULL
> > ldap_int_select
> > read1msg: ld 0x49d1310 msgid 1 all 0
> > ber_get_next
> > ber_get_next: tag 0x30 len 103 contents:
> > read1msg: ld 0x49d1310 msgid 1 message type bind
> > ber_scanf fmt ({eaa) ber:
> > ber_scanf fmt ({eaa}) ber:
> > ldap_chase_referrals
> > read1msg:  V2 referral chased, mark request completed, id = 1
> > new result:  res_errno: 49, res_error: <80090308: LdapErr: DSID-
> > 0C090334, comment: AcceptSecurityContext error, data 525, vece>,
> > res_matched: <>
> > read1msg: ld 0x49d1310 0 new referrals
> > read1msg:  mark request completed, ld 0x49d1310 msgid 1
> > request done: ld 0x49d1310 msgid 1
> > res_errno: 49, res_error: <80090308: LdapErr: DSID-0C090334, comment:
> > AcceptSecurityContext error, data 525, vece>, res_matched: <>
> > ldap_free_request (origid 1, msgid 1)
> > ldap_free_connection 0 1
> > ldap_free_connection: refcnt 1
> > ldap_parse_result
> > ber_scanf fmt ({iaa) ber:
> > ber_scanf fmt (}) ber:
> > ldap_msgfree
> > ldap_err2string
> > ldap_unbind
> > ldap_free_connection 1 1
> > ldap_send_unbind
> > ber_flush: 7 bytes to sd 3
> > ldap_free_connection: actually freed
> > ldap_err2string
> >
> >
> > > -----Original Message-----
> > > From: owner-nssldap@padl.com [owner-nssldap [at] padl.com] On
> > Behalf
> > > Of Buchan Milne
> > > Sent: Friday, 26 June 2009 1:30 a.m.
> > > To: Guillaume Rousse
> > > Cc: pamldap@padl.com; nssldap@padl.com
> > > Subject: Re: [nssldap] pam_ldap and nss_ldap can't connect to LDAP
> > > server(s)
> > >
> > > On Thursday 25 June 2009 11:11:35 Guillaume Rousse wrote:
> > > > Aaron Hicks a écrit :
> > > > > Hope someone here can help.
> > > >
> > > > You'd better test nss first, and pam second. As long as 'getent
> > > > password' doesn't list you all known users, that's no use to try
> to
> > > > autenticate them.
> > > >
> > > > Various hints:
> > > > - use 'debug 1' in your nss_ldap configuration file.
> > > > - check if there is any difference using anonymous or
> authenticated
> > > binding
> > > > - check if there any difference between tls (port 389), ssl (port
> > > 636),
> > > > and unencrypted connection (warning, unspecified configuration
> > values
> > > in
> > > > nss_ldap configuration, such as tls_checkpeer, will usually use
> > > nss_ldap
> > > > default values, not use openldap library values, such as
> > TLS_REQCERT
> > > > never in your case)
> > > > - check your ldap server logs
> > > >
> > > > I have no clue what eDirectory is, but if it is just a branding
> > name
> > > > over openldap, you can perfectly tune its access policy as
> needed.
> > I
> > > > doubt it really enforce the use of encryption for connection,
> > rather
> > > for
> > > > autentication only.
> > >
> > > eDirectory is Novell's directory server (historically, NDS), which
> > > later
> > > (after the bindery days) got an LDAP interface.
> > >
> > > The error message provided however looks very much like MS Active
> > > Directory.
> > >
> > > > Also, take care than ubuntu (Debian, actually) doesn't use a
> unique
> > > > configuration file for nss_ldap and pam_ldap (/etc/ldap.conf),
> but
> > > two
> > > > distinct ones (/etc/libnss_ldap and /etc/libpam_ldap, from
> memory).
> > > > [..]
> > >
> > > AFAIR, modern releases of Ubuntu have reverted to a single
> > > /etc/ldap.conf.
> > >
> > > >
> > > > > ===========Config files from here on========
> > > > >
> > > > > My /etc/ldap.conf looks like (omitting sections left as
> default):
> > > > >
> > > > > <defaults omitted>
> > > > > # The distinguished name of the search base.
> > > > > base
> > > >
> > > > An empty base will not help. maybe nss_ldap use openldap default
> > > > configuration in this case, but I would not rely on it.
> > >
> > > I would also prefer to see the entire ldap.conf without comments
> > (but,
> > > including any "defaults"), rather than missing some potentially
> > > important
> > > values that are maybe at incorrect defaults. Also, please do
> > consistent
> > > (e.g.
> > > perl -pe 's/dc=myrealdomain,dc=com/dc=example,dc=com') mangling of
> > your
> > > configuration file, as this looks suspect:
> > >
> > > binddn "cn=User
> > >
> >
> Name,ou=internal,ou=users,ou=accounts,cn=,dc=our,dc=long,dc=domain,dc=c
> > > o,dc=nz"
> > >
> > > (this is not a valid DN, as there is an attribute without a value)
> > >
> > > Now, I am unsure if your original value is correct or not.
> > >
> > > Regardless, if there is not some simple mistake like the above,
> > running
> > > 'getent passwd user_in_ldap' (where user_in_ldap is the samAccount
> > > value of a
> > > user in AD) with debugging enabled in nss_ldap would be more
> > > enlightening.
> > >
> > > Regards,
> > > Buchan
> >
> > Please consider the environment before printing this email
> > Warning:  This electronic message together with any attachments is
> > confidential. If you receive it in error: (i) you must not read, use,
> > disclose, copy or retain it; (ii) please contact the sender
> immediately
> > by reply email and then delete the emails.
> > The views expressed in this email may not be those of Landcare
> Research
> > New Zealand Limited. http://www.landcareresearch.co.nz
>
> Please consider the environment before printing this email
> Warning:  This electronic message together with any attachments is
> confidential. If you receive it in error: (i) you must not read, use,
> disclose, copy or retain it; (ii) please contact the sender immediately
> by reply email and then delete the emails.
> The views expressed in this email may not be those of Landcare Research
> New Zealand Limited. http://www.landcareresearch.co.nz

Please consider the environment before printing this email
Warning:  This electronic message together with any attachments is 
confidential. If you receive it in error: (i) you must not read, use, disclose, 
copy or retain it; (ii) please contact the sender immediately by reply email 
and then delete the emails.
The views expressed in this email may not be those of Landcare Research New 
Zealand Limited. http://www.landcareresearch.co.nz