lists.arthurdejong.org
RSS feed

error writing to nslcd

[Date Prev][Date Next] [Thread Prev][Thread Next]

error writing to nslcd



Hi!

I'm trying to setup ldap user database as opposed to traditional flat file one. I've successfully installed and configured test environment on virtual machine (VirtualBox) with freebsd amd64 9.0-rc3. When I repeated the same on a real machine (the same OS) I've got the next error:

Jan  8 14:09:02 devel login: error writing to nslcd: Invalid argument


My configs:

##################################################
pam.d/system:
##################################################

# auth
auth        sufficient    /usr/local/lib/pam_ldap.so    minimum_uid=10000
auth        sufficient    pam_opie.so        no_warn no_fake_prompts
auth        requisite    pam_opieaccess.so    no_warn allow_local
#auth        sufficient    pam_krb5.so        no_warn try_first_pass
#auth        sufficient    pam_ssh.so        no_warn try_first_pass
auth        required    pam_unix.so        no_warn try_first_pass nullok

# account
#account    required    pam_krb5.so
account        sufficient    /usr/local/lib/pam_ldap.so    minimum_uid=10000
account        required    pam_login_access.so
account        required    pam_unix.so

# session
#session    optional    pam_ssh.so        want_agent
session        required    pam_lastlog.so        no_fail

# password
#password    sufficient    pam_krb5.so        no_warn try_first_pass
password    sufficient    /usr/local/lib/pam_ldap.so    minimum_uid=10000
password    required    pam_unix.so        no_warn try_first_pass

##################################################
nslcd.conf:
##################################################

# The user and group nslcd should run as.
uid nslcd
gid nslcd

# The underprivileged user and group used for running the daemon.
uid nslcd
gid nslcd

uri ldap://127.0.0.1/

# The distinguished name of the search base.
base dc=muxas,dc=net
binddn uid=Administrator,ou=Users,dc=muxas,dc=net
bindpw xxx

# The distinguished name to perform password modifications by root by.
rootpwmoddn uid=Administrator,ou=Users,dc=muxas,dc=net

# Customize certain database lookups.
base   group  ou=Groups,dc=muxas,dc=net
base   passwd ou=Users,dc=muxas,dc=net
base   shadow ou=Users,dc=muxas,dc=net
scope  group  sub

##################################################
nsswitch.conf
##################################################

group: files ldap
group_compat: nis
hosts: files dns
networks: files
passwd: files ldap
passwd_compat: nis
shells: files
services: compat
services_compat: nis
protocols: files
rpc: files

##################################################
home-users.ldif
##################################################
version: 1

dn: dc=muxas,dc=net
objectClass: dcObject
objectClass: organization
dc: muxas
o: Muxas Home Office
description: My Home Office

dn: ou=Users,dc=muxas,dc=net
objectClass: organizationalUnit
ou: Users
description: Users Database

dn: ou=Groups,dc=muxas,dc=net
objectClass: organizationalUnit
ou: Groups
description: Groups Database

dn: uid=Administrator,ou=Users,dc=muxas,dc=net
objectClass: top
objectClass: posixAccount
objectClass: shadowAccount
objectClass: organizationalRole
cn: Administrator
gidNumber: 10000
homeDirectory: /nonexistent
uid: Administrator
uidNumber: 10000
description: DIT Manager

dn: cn=muxas,ou=Groups,dc=muxas,dc=net
objectClass: top
objectClass: posixGroup
cn: muxas
gidNumber: 10001
memberUid: muxas

dn: uid=muxas,ou=Users,dc=muxas,dc=net
objectClass: top
objectClass: person
objectClass: posixAccount
objectClass: shadowAccount
cn: Vetrov Maxim
gidNumber: 10001
homeDirectory: /home/muxas
sn: Vetrov
uid: muxas
uidNumber: 10001
gecos: Vetrov Maxim
loginShell: /bin/csh
shadowExpire: -1
shadowFlag: 0
shadowInactive: -1
shadowLastChange: 10877
shadowMax: 999999
shadowMin: 0
shadowWarning: 7
userPassword::  XXXX
##################################################

Output of "nslcd -d"
==================================================
nslcd -d
nslcd: DEBUG: add_uri(ldap://127.0.0.1/)
nslcd: version 0.7.15 starting
nslcd: DEBUG: setgroups(0,NULL) done
nslcd: DEBUG: setgid(928) done
nslcd: DEBUG: setuid(928) done
nslcd: accepting connections
nslcd: [0041a7] DEBUG: connection from pid=-1 uid=0 gid=0
nslcd: [0041a7] DEBUG: nslcd_passwd_byname(muxas)
nslcd: [0041a7] DEBUG: myldap_search(base="ou=Users,dc=muxas,dc=net", filter="(&(objectClass=posixAccount)(uid=muxas))")
nslcd: [d63af1] DEBUG: connection from pid=-1 uid=0 gid=0
nslcd: [0041a7] DEBUG: ldap_initialize(ldap://127.0.0.1/)
nslcd: [b7acd9] DEBUG: connection from pid=-1 uid=0 gid=0
nslcd: [b7acd9] error reading from client: No error: 0
nslcd: [d63af1] error reading from client: No error: 0
nslcd: [0041a7] DEBUG: ldap_set_rebind_proc()
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,0)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,0)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,0)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [0041a7] DEBUG: ldap_simple_bind_s("uid=Administrator,ou=Users,dc=muxas,dc=net","***") (uri="ldap://127.0.0.1/";)
nslcd: [0041a7] error writing to client: Broken pipe
nslcd: [b50c2a] DEBUG: connection from pid=-1 uid=0 gid=0
nslcd: [b50c2a] DEBUG: nslcd_pam_authc("muxas","","login","***")
nslcd: [b50c2a] DEBUG: myldap_search(base="ou=Users,dc=muxas,dc=net", filter="(&(objectClass=posixAccount)(uid=muxas))")
nslcd: [b50c2a] DEBUG: ldap_initialize(ldap://127.0.0.1/)
nslcd: [b50c2a] DEBUG: ldap_set_rebind_proc()
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [b50c2a] DEBUG: ldap_simple_bind_s("uid=Administrator,ou=Users,dc=muxas,dc=net","***") (uri="ldap://127.0.0.1/";)
nslcd: [31b782] DEBUG: connection from pid=-1 uid=0 gid=0
nslcd: [31b782] error reading from client: No error: 0
nslcd: [06dac8] DEBUG: connection from pid=-1 uid=0 gid=0
nslcd: [06dac8] error reading from client: No error: 0
nslcd: [b50c2a] DEBUG: myldap_search(base="uid=muxas,ou=Users,dc=muxas,dc=net", filter="(objectClass=posixAccount)")
nslcd: [b50c2a] DEBUG: ldap_initialize(ldap://127.0.0.1/)
nslcd: [b50c2a] DEBUG: ldap_set_rebind_proc()
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [b50c2a] DEBUG: ldap_simple_bind_s("uid=muxas,ou=Users,dc=muxas,dc=net","***") (uri="ldap://127.0.0.1/";)
nslcd: [b50c2a] DEBUG: ldap_unbind()
nslcd: [b50c2a] DEBUG: bind successful
nslcd: [b50c2a] error writing to client: Broken pipe
^Cnslcd: [b50c2a] DEBUG: ldap_unbind()
nslcd: [0041a7] DEBUG: ldap_unbind()
nslcd: caught signal SIGINT (2), shutting down
nslcd: DEBUG: unlink() of /var/run/nslcd.ctl failed (ignored): Permission denied nslcd: DEBUG: unlink() of /var/run/nslcd.pid failed (ignored): Permission denied
nslcd: version 0.7.15 bailing out

Output of "nslcd -dd"
==================================================
nslcd -dd
nslcd: DEBUG: ber_set_option(LBER_OPT_LOG_PRINT_FILE)
nslcd: DEBUG: ldap_set_option(LDAP_OPT_DEBUG_LEVEL,-1)
nslcd: DEBUG: add_uri(ldap://127.0.0.1/)
nslcd: version 0.7.15 starting
nslcd: DEBUG: setgroups(0,NULL) done
nslcd: DEBUG: setgid(928) done
nslcd: DEBUG: setuid(928) done
nslcd: accepting connections
nslcd: [0041a7] DEBUG: connection from pid=-1 uid=0 gid=5
nslcd: [0041a7] DEBUG: nslcd_group_bymember(operator)
nslcd: [0041a7] DEBUG: myldap_search(base="ou=Users,dc=muxas,dc=net", filter="(&(objectClass=posixAccount)(uid=operator))")
nslcd: [0041a7] DEBUG: ldap_initialize(ldap://127.0.0.1/)
ldap_create
ldap_url_parse_ext(ldap://127.0.0.1/)
nslcd: [0041a7] DEBUG: ldap_set_rebind_proc()
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,0)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,0)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,0)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [0041a7] DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [0041a7] DEBUG: ldap_simple_bind_s("uid=Administrator,ou=Users,dc=muxas,dc=net","***") (uri="ldap://127.0.0.1/";)
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_new_connection 1 1 0
ldap_int_open_connection
ldap_connect_to_host: TCP 127.0.0.1:389
ldap_new_socket: 10
ldap_prepare_socket: 10
ldap_connect_to_host: Trying 127.0.0.1:389
ldap_pvt_connect: fd: 10 tm: 10 async: 0
ldap_ndelay_on: 10
ldap_int_poll: fd: 10 tm: 10
ldap_is_sock_ready: 10
ldap_ndelay_off: 10
ldap_pvt_connect: 0
ldap_open_defconn: successful
ldap_send_server_request
ldap_result ld 0x801cab0d0 msgid 1
wait4msg ld 0x801cab0d0 msgid 1 (timeout 10000000 usec)
wait4msg continue ld 0x801cab0d0 msgid 1 all 1
** ld 0x801cab0d0 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:00 2012


** ld 0x801cab0d0 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x801cab0d0 request count 1 (abandoned 0)
** ld 0x801cab0d0 Response Queue:
   Empty
  ld 0x801cab0d0 response count 0
ldap_chkResponseList ld 0x801cab0d0 msgid 1 all 1
ldap_chkResponseList returns ld 0x801cab0d0 NULL
ldap_int_select
read1msg: ld 0x801cab0d0 msgid 1 all 1
read1msg: ld 0x801cab0d0 msgid 1 message type bind
read1msg: ld 0x801cab0d0 0 new referrals
read1msg:  mark request completed, ld 0x801cab0d0 msgid 1
request done: ld 0x801cab0d0 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_result
ldap_msgfree
ldap_search_ext
put_filter: "(&(objectClass=posixAccount)(uid=operator))"
put_filter: AND
put_filter_list "(objectClass=posixAccount)(uid=operator)"
put_filter: "(objectClass=posixAccount)"
put_filter: simple
put_simple_filter: "objectClass=posixAccount"
put_filter: "(uid=operator)"
put_filter: simple
put_simple_filter: "uid=operator"
ldap_build_search_req ATTRS: uid
ldap_send_initial_request
ldap_send_server_request
ldap_result ld 0x801cab0d0 msgid 2
wait4msg ld 0x801cab0d0 msgid 2 (timeout 10000000 usec)
wait4msg continue ld 0x801cab0d0 msgid 2 all 0
** ld 0x801cab0d0 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:00 2012


** ld 0x801cab0d0 Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x801cab0d0 request count 1 (abandoned 0)
** ld 0x801cab0d0 Response Queue:
   Empty
  ld 0x801cab0d0 response count 0
ldap_chkResponseList ld 0x801cab0d0 msgid 2 all 0
ldap_chkResponseList returns ld 0x801cab0d0 NULL
ldap_int_select
read1msg: ld 0x801cab0d0 msgid 2 all 0
read1msg: ld 0x801cab0d0 msgid 2 message type search-result
read1msg: ld 0x801cab0d0 0 new referrals
read1msg:  mark request completed, ld 0x801cab0d0 msgid 2
request done: ld 0x801cab0d0 msgid 2
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 2, msgid 2)
ldap_parse_result
ldap_msgfree
nslcd: [0041a7] DEBUG: ldap_result(): end of results
nslcd: [0041a7] DEBUG: myldap_search(base="ou=Groups,dc=muxas,dc=net", filter="(&(objectClass=posixGroup)(memberUid=operator))")
ldap_search_ext
put_filter: "(&(objectClass=posixGroup)(memberUid=operator))"
put_filter: AND
put_filter_list "(objectClass=posixGroup)(memberUid=operator)"
put_filter: "(objectClass=posixGroup)"
put_filter: simple
put_simple_filter: "objectClass=posixGroup"
put_filter: "(memberUid=operator)"
put_filter: simple
put_simple_filter: "memberUid=operator"
ldap_build_search_req ATTRS: cn userPassword memberUid gidNumber uniqueMember
ldap_send_initial_request
ldap_send_server_request
ldap_result ld 0x801cab0d0 msgid 3
wait4msg ld 0x801cab0d0 msgid 3 (timeout 10000000 usec)
wait4msg continue ld 0x801cab0d0 msgid 3 all 0
** ld 0x801cab0d0 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:00 2012


** ld 0x801cab0d0 Outstanding Requests:
 * msgid 3,  origid 3, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x801cab0d0 request count 1 (abandoned 0)
** ld 0x801cab0d0 Response Queue:
   Empty
  ld 0x801cab0d0 response count 0
ldap_chkResponseList ld 0x801cab0d0 msgid 3 all 0
ldap_chkResponseList returns ld 0x801cab0d0 NULL
ldap_int_select
read1msg: ld 0x801cab0d0 msgid 3 all 0
read1msg: ld 0x801cab0d0 msgid 3 message type search-result
read1msg: ld 0x801cab0d0 0 new referrals
read1msg:  mark request completed, ld 0x801cab0d0 msgid 3
request done: ld 0x801cab0d0 msgid 3
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 3, msgid 3)
ldap_parse_result
ldap_msgfree
nslcd: [0041a7] DEBUG: ldap_result(): end of results
nslcd: [d63af1] DEBUG: connection from pid=-1 uid=0 gid=0
nslcd: [d63af1] DEBUG: nslcd_passwd_byname(muxas)
nslcd: [b7acd9] DEBUG: connection from pid=-1 uid=0 gid=0
nslcd: [d63af1] DEBUG: myldap_search(base="ou=Users,dc=muxas,dc=net", filter="(&(objectClass=posixAccount)(uid=muxas))")
nslcd: [d63af1] DEBUG: ldap_initialize(ldap://127.0.0.1/)
ldap_create
nslcd: [b7acd9] DEBUG: nslcd_passwd_byname(muxas)
nslcd: [b7acd9] DEBUG: myldap_search(base="ou=Users,dc=muxas,dc=net", filter="(&(objectClass=posixAccount)(uid=muxas))")
nslcd: [b7acd9] DEBUG: ldap_initialize(ldap://127.0.0.1/)
ldap_create
ldap_url_parse_ext(ldap://127.0.0.1/)
nslcd: [d63af1] DEBUG: ldap_set_rebind_proc()
nslcd: [d63af1] DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [d63af1] DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [d63af1] DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,0)
nslcd: [d63af1] DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,0)
nslcd: [d63af1] DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,0)
nslcd: [d63af1] DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [d63af1] DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
ldap_url_parse_ext(ldap://127.0.0.1/)
nslcd: [d63af1] DEBUG: ldap_simple_bind_s("uid=Administrator,ou=Users,dc=muxas,dc=net","***") (uri="ldap://127.0.0.1/";)
ldap_simple_bind_s
ldap_sasl_bind_s
nslcd: [b50c2a] DEBUG: connection from pid=-1 uid=0 gid=0
nslcd: [b7acd9] DEBUG: ldap_set_rebind_proc()
nslcd: [b7acd9] DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [b7acd9] DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [b7acd9] DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,0)
nslcd: [b7acd9] DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,0)
nslcd: [b7acd9] DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,0)
nslcd: [b7acd9] DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [b50c2a] DEBUG: nslcd_passwd_byname(muxas)
nslcd: [b50c2a] DEBUG: myldap_search(base="ou=Users,dc=muxas,dc=net", filter="(&(objectClass=posixAccount)(uid=muxas))")
nslcd: [b7acd9] DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
ldap_sasl_bind
nslcd: [b7acd9] DEBUG: ldap_simple_bind_s("uid=Administrator,ou=Users,dc=muxas,dc=net","***") (uri="ldap://127.0.0.1/";)
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
nslcd: [b50c2a] DEBUG: ldap_initialize(ldap://127.0.0.1/)
ldap_create
ldap_new_connection 1 1 0
ldap_send_initial_request
ldap_int_open_connection
ldap_new_connection 1 1 0
ldap_connect_to_host: TCP 127.0.0.1:389
ldap_new_socket: 11
ldap_int_open_connection
ldap_prepare_socket: 11
ldap_url_parse_ext(ldap://127.0.0.1/)
ldap_connect_to_host: Trying 127.0.0.1:389
ldap_pvt_connect: fd: 11 tm: 10 async: 0
ldap_ndelay_on: 11
ldap_connect_to_host: TCP 127.0.0.1:389
nslcd: [b50c2a] DEBUG: ldap_set_rebind_proc()
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,0)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,0)
ldap_int_poll: fd: 11 tm: 10
ldap_new_socket: 12
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [b50c2a] DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [b50c2a] DEBUG: ldap_simple_bind_s("uid=Administrator,ou=Users,dc=muxas,dc=net","***") (uri="ldap://127.0.0.1/";)
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_is_sock_ready: 11
ldap_ndelay_off: 11
ldap_pvt_connect: 0
ldap_send_initial_request
ldap_open_defconn: successful
ldap_new_connection 1 1 0
ldap_prepare_socket: 12
ldap_int_open_connection
ldap_connect_to_host: Trying 127.0.0.1:389
ldap_send_server_request
ldap_connect_to_host: TCP 127.0.0.1:389
ldap_new_socket: 13
ldap_prepare_socket: 13
ldap_connect_to_host: Trying 127.0.0.1:389
ldap_result ld 0x802435040 msgid 1
ldap_pvt_connect: fd: 13 tm: 10 async: 0
ldap_pvt_connect: fd: 12 tm: 10 async: 0
ldap_ndelay_on: 12
ldap_int_poll: fd: 12 tm: 10
ldap_is_sock_ready: 12
ldap_ndelay_off: 12
ldap_pvt_connect: 0
ldap_open_defconn: successful
ldap_send_server_request
ldap_ndelay_on: 13
ldap_result ld 0x802835040 msgid 1
wait4msg ld 0x802835040 msgid 1 (timeout 10000000 usec)
wait4msg continue ld 0x802835040 msgid 1 all 1
** ld 0x802835040 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:05 2012


** ld 0x802835040 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x802835040 request count 1 (abandoned 0)
** ld 0x802835040 Response Queue:
   Empty
  ld 0x802835040 response count 0
ldap_int_poll: fd: 13 tm: 10
ldap_is_sock_ready: 13
ldap_ndelay_off: 13
ldap_pvt_connect: 0
ldap_open_defconn: successful
ldap_send_server_request
ldap_result ld 0x802c35040 msgid 1
wait4msg ld 0x802c35040 msgid 1 (timeout 10000000 usec)
wait4msg continue ld 0x802c35040 msgid 1 all 1
** ld 0x802c35040 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:05 2012


** ld 0x802c35040 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x802c35040 request count 1 (abandoned 0)
** ld 0x802c35040 Response Queue:
   Empty
  ld 0x802c35040 response count 0
ldap_chkResponseList ld 0x802c35040 msgid 1 all 1
ldap_chkResponseList returns ld 0x802c35040 NULL
ldap_int_select
ldap_chkResponseList ld 0x802835040 msgid 1 all 1
ldap_chkResponseList returns ld 0x802835040 NULL
ldap_int_select
wait4msg ld 0x802435040 msgid 1 (timeout 10000000 usec)
wait4msg continue ld 0x802435040 msgid 1 all 1
** ld 0x802435040 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:05 2012


** ld 0x802435040 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x802435040 request count 1 (abandoned 0)
** ld 0x802435040 Response Queue:
   Empty
  ld 0x802435040 response count 0
ldap_chkResponseList ld 0x802435040 msgid 1 all 1
ldap_chkResponseList returns ld 0x802435040 NULL
ldap_int_select
read1msg: ld 0x802435040 msgid 1 all 1
read1msg: ld 0x802435040 msgid 1 message type bind
read1msg: ld 0x802435040 0 new referrals
read1msg:  mark request completed, ld 0x802435040 msgid 1
request done: ld 0x802435040 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_result
ldap_msgfree
ldap_search_ext
put_filter: "(&(objectClass=posixAccount)(uid=muxas))"
put_filter: AND
put_filter_list "(objectClass=posixAccount)(uid=muxas)"
put_filter: "(objectClass=posixAccount)"
put_filter: simple
put_simple_filter: "objectClass=posixAccount"
put_filter: "(uid=muxas)"
put_filter: simple
put_simple_filter: "uid=muxas"
ldap_build_search_req ATTRS: userPassword cn gidNumber uidNumber loginShell objectClass gecos uid homeDirectory
ldap_send_initial_request
ldap_send_server_request
ldap_result ld 0x802435040 msgid 2
wait4msg ld 0x802435040 msgid 2 (timeout 10000000 usec)
wait4msg continue ld 0x802435040 msgid 2 all 0
** ld 0x802435040 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:05 2012


** ld 0x802435040 Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x802435040 request count 1 (abandoned 0)
** ld 0x802435040 Response Queue:
   Empty
  ld 0x802435040 response count 0
ldap_chkResponseList ld 0x802435040 msgid 2 all 0
ldap_chkResponseList returns ld 0x802435040 NULL
ldap_int_select
read1msg: ld 0x802835040 msgid 1 all 1
read1msg: ld 0x802835040 msgid 1 message type bind
read1msg: ld 0x802835040 0 new referrals
read1msg:  mark request completed, ld 0x802835040 msgid 1
read1msg: ld 0x802c35040 msgid 1 all 1
read1msg: ld 0x802c35040 msgid 1 message type bind
read1msg: ld 0x802c35040 0 new referrals
read1msg:  mark request completed, ld 0x802c35040 msgid 1
request done: ld 0x802c35040 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_result
ldap_msgfree
request done: ld 0x802835040 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_result
ldap_msgfree
ldap_search_ext
put_filter: "(&(objectClass=posixAccount)(uid=muxas))"
put_filter: AND
put_filter_list "(objectClass=posixAccount)(uid=muxas)"
put_filter: "(objectClass=posixAccount)"
put_filter: simple
put_simple_filter: "objectClass=posixAccount"
put_filter: "(uid=muxas)"
put_filter: simple
put_simple_filter: "uid=muxas"
ldap_build_search_req ATTRS: userPassword cn gidNumber uidNumber loginShell objectClass gecos uid homeDirectory
ldap_send_initial_request
ldap_send_server_request
ldap_search_ext
ldap_result ld 0x802835040 msgid 2
wait4msg ld 0x802835040 msgid 2 (timeout 10000000 usec)
wait4msg continue ld 0x802835040 msgid 2 all 0
** ld 0x802835040 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:05 2012


** ld 0x802835040 Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x802835040 request count 1 (abandoned 0)
** ld 0x802835040 Response Queue:
   Empty
  ld 0x802835040 response count 0
ldap_chkResponseList ld 0x802835040 msgid 2 all 0
ldap_chkResponseList returns ld 0x802835040 NULL
ldap_int_select
read1msg: ld 0x802435040 msgid 2 all 0
read1msg: ld 0x802435040 msgid 2 message type search-entry
ldap_get_values
put_filter: "(&(objectClass=posixAccount)(uid=muxas))"
put_filter: AND
put_filter_list "(objectClass=posixAccount)(uid=muxas)"
put_filter: "(objectClass=posixAccount)"
put_filter: simple
put_simple_filter: "objectClass=posixAccount"
put_filter: "(uid=muxas)"
put_filter: simple
put_simple_filter: "uid=muxas"
ldap_get_values
ldap_build_search_req ATTRS: userPassword cn gidNumber uidNumber loginShell objectClass gecos uid homeDirectory
ldap_send_initial_request
ldap_send_server_request
ldap_result ld 0x802c35040 msgid 2
wait4msg ld 0x802c35040 msgid 2 (timeout 10000000 usec)
wait4msg continue ld 0x802c35040 msgid 2 all 0
** ld 0x802c35040 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:05 2012


** ld 0x802c35040 Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x802c35040 request count 1 (abandoned 0)
** ld 0x802c35040 Response Queue:
   Empty
  ld 0x802c35040 response count 0
ldap_chkResponseList ld 0x802c35040 msgid 2 all 0
ldap_chkResponseList returns ld 0x802c35040 NULL
ldap_int_select
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
nslcd: [d63af1] error writing to client: Broken pipe
ldap_msgfree
ldap_abandon 2
ldap_abandon_ext 2
do_abandon origid 2, msgid 2
ldap_msgdelete ld=0x802435040 msgid=2
read1msg: ld 0x802835040 msgid 2 all 0
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_free_request (origid 2, msgid 2)
read1msg: ld 0x802835040 msgid 2 message type search-entry
ldap_get_values
ldap_msgfree
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
nslcd: [b7acd9] error writing to client: Broken pipe
ldap_msgfree
ldap_abandon 2
ldap_abandon_ext 2
do_abandon origid 2, msgid 2
ldap_msgdelete ld=0x802835040 msgid=2
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_free_request (origid 2, msgid 2)
ldap_msgfree
read1msg: ld 0x802c35040 msgid 2 all 0
read1msg: ld 0x802c35040 msgid 2 message type search-entry
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
nslcd: [b50c2a] error writing to client: Broken pipe
ldap_msgfree
ldap_abandon 2
ldap_abandon_ext 2
do_abandon origid 2, msgid 2
ldap_msgdelete ld=0x802c35040 msgid=2
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_free_request (origid 2, msgid 2)
ldap_msgfree
nslcd: [31b782] DEBUG: connection from pid=-1 uid=0 gid=0
nslcd: [31b782] DEBUG: nslcd_pam_authc("muxas","","login","***")
nslcd: [31b782] DEBUG: myldap_search(base="ou=Users,dc=muxas,dc=net", filter="(&(objectClass=posixAccount)(uid=muxas))")
nslcd: [31b782] DEBUG: ldap_initialize(ldap://127.0.0.1/)
ldap_create
ldap_url_parse_ext(ldap://127.0.0.1/)
nslcd: [31b782] DEBUG: ldap_set_rebind_proc()
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,0)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,0)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,0)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [31b782] DEBUG: ldap_simple_bind_s("uid=Administrator,ou=Users,dc=muxas,dc=net","***") (uri="ldap://127.0.0.1/";)
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
nslcd: [06dac8] DEBUG: connection from pid=-1 uid=0 gid=0
ldap_send_initial_request
ldap_new_connection 1 1 0
nslcd: [06dac8] DEBUG: nslcd_passwd_byname(muxas)
ldap_int_open_connection
ldap_connect_to_host: TCP 127.0.0.1:389
nslcd: [06dac8] DEBUG: myldap_search(base="ou=Users,dc=muxas,dc=net", filter="(&(objectClass=posixAccount)(uid=muxas))")
ldap_search_ext
ldap_new_socket: 14
ldap_prepare_socket: 14
ldap_connect_to_host: Trying 127.0.0.1:389
nslcd: [058ed8] DEBUG: connection from pid=-1 uid=0 gid=0
put_filter: "(&(objectClass=posixAccount)(uid=muxas))"
put_filter: AND
put_filter_list "(objectClass=posixAccount)(uid=muxas)"
nslcd: [058ed8] error reading from client: Invalid argument
ldap_pvt_connect: fd: 14 tm: 10 async: 0
ldap_ndelay_on: 14
put_filter: "(objectClass=posixAccount)"
put_filter: simple
put_simple_filter: "objectClass=posixAccount"
put_filter: "(uid=muxas)"
put_filter: simple
put_simple_filter: "uid=muxas"
ldap_build_search_req ATTRS: userPassword cn gidNumber uidNumber loginShell objectClass gecos uid homeDirectory
ldap_send_initial_request
ldap_send_server_request
ldap_result ld 0x801cab0d0 msgid 4
ldap_int_poll: fd: 14 tm: 10
ldap_is_sock_ready: 14
ldap_ndelay_off: 14
ldap_pvt_connect: 0
ldap_open_defconn: successful
ldap_send_server_request
ldap_result ld 0x803031040 msgid 1
wait4msg ld 0x803031040 msgid 1 (timeout 10000000 usec)
wait4msg continue ld 0x803031040 msgid 1 all 1
** ld 0x803031040 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:07 2012


** ld 0x803031040 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x803031040 request count 1 (abandoned 0)
** ld 0x803031040 Response Queue:
   Empty
  ld 0x803031040 response count 0
ldap_chkResponseList ld 0x803031040 msgid 1 all 1
ldap_chkResponseList returns ld 0x803031040 NULL
ldap_int_select
wait4msg ld 0x801cab0d0 msgid 4 (timeout 10000000 usec)
wait4msg continue ld 0x801cab0d0 msgid 4 all 0
** ld 0x801cab0d0 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:07 2012


** ld 0x801cab0d0 Outstanding Requests:
 * msgid 4,  origid 4, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x801cab0d0 request count 1 (abandoned 0)
** ld 0x801cab0d0 Response Queue:
   Empty
  ld 0x801cab0d0 response count 0
ldap_chkResponseList ld 0x801cab0d0 msgid 4 all 0
ldap_chkResponseList returns ld 0x801cab0d0 NULL
ldap_int_select
read1msg: ld 0x803031040 msgid 1 all 1
read1msg: ld 0x803031040 msgid 1 message type bind
read1msg: ld 0x803031040 0 new referrals
read1msg:  mark request completed, ld 0x803031040 msgid 1
request done: ld 0x803031040 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_result
ldap_msgfree
ldap_search_ext
put_filter: "(&(objectClass=posixAccount)(uid=muxas))"
put_filter: AND
put_filter_list "(objectClass=posixAccount)(uid=muxas)"
put_filter: "(objectClass=posixAccount)"
put_filter: simple
put_simple_filter: "objectClass=posixAccount"
put_filter: "(uid=muxas)"
put_filter: simple
put_simple_filter: "uid=muxas"
ldap_build_search_req ATTRS: uid
ldap_send_initial_request
ldap_send_server_request
read1msg: ld 0x801cab0d0 msgid 4 all 0
read1msg: ld 0x801cab0d0 msgid 4 message type search-entry
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
ldap_get_values
nslcd: [06dac8] error writing to client: Broken pipe
ldap_msgfree
ldap_result ld 0x803031040 msgid 2
wait4msg ld 0x803031040 msgid 2 (timeout 10000000 usec)
wait4msg continue ld 0x803031040 msgid 2 all 0
** ld 0x803031040 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:07 2012


** ld 0x803031040 Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x803031040 request count 1 (abandoned 0)
** ld 0x803031040 Response Queue:
   Empty
  ld 0x803031040 response count 0
ldap_chkResponseList ld 0x803031040 msgid 2 all 0
ldap_chkResponseList returns ld 0x803031040 NULL
ldap_int_select
ldap_abandon 4
ldap_abandon_ext 4
do_abandon origid 4, msgid 4
ldap_msgdelete ld=0x801cab0d0 msgid=4
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_free_request (origid 4, msgid 4)
ldap_msgfree
read1msg: ld 0x803031040 msgid 2 all 0
read1msg: ld 0x803031040 msgid 2 message type search-entry
ldap_get_dn
ldap_explode_dn
=> ldap_bv2dn(uid=muxas,ou=Users,dc=muxas,dc=net,0)
<= ldap_bv2dn(uid=muxas,ou=Users,dc=muxas,dc=net)=0
ldap_explode_rdn
nslcd: [31b782] DEBUG: myldap_search(base="uid=muxas,ou=Users,dc=muxas,dc=net", filter="(objectClass=posixAccount)")
nslcd: [31b782] DEBUG: ldap_initialize(ldap://127.0.0.1/)
ldap_create
ldap_url_parse_ext(ldap://127.0.0.1/)
nslcd: [31b782] DEBUG: ldap_set_rebind_proc()
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_PROTOCOL_VERSION,3)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_DEREF,0)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_TIMELIMIT,0)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_TIMEOUT,0)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_NETWORK_TIMEOUT,0)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_REFERRALS,LDAP_OPT_ON)
nslcd: [31b782] DEBUG: ldap_set_option(LDAP_OPT_RESTART,LDAP_OPT_ON)
nslcd: [31b782] DEBUG: ldap_simple_bind_s("uid=muxas,ou=Users,dc=muxas,dc=net","***") (uri="ldap://127.0.0.1/";)
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_new_connection 1 1 0
ldap_int_open_connection
ldap_connect_to_host: TCP 127.0.0.1:389
ldap_new_socket: 15
ldap_prepare_socket: 15
ldap_connect_to_host: Trying 127.0.0.1:389
ldap_pvt_connect: fd: 15 tm: 10 async: 0
ldap_ndelay_on: 15
ldap_int_poll: fd: 15 tm: 10
ldap_is_sock_ready: 15
ldap_ndelay_off: 15
ldap_pvt_connect: 0
ldap_open_defconn: successful
ldap_send_server_request
ldap_result ld 0x803031190 msgid 1
wait4msg ld 0x803031190 msgid 1 (timeout 10000000 usec)
wait4msg continue ld 0x803031190 msgid 1 all 1
** ld 0x803031190 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:07 2012


** ld 0x803031190 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x803031190 request count 1 (abandoned 0)
** ld 0x803031190 Response Queue:
   Empty
  ld 0x803031190 response count 0
ldap_chkResponseList ld 0x803031190 msgid 1 all 1
ldap_chkResponseList returns ld 0x803031190 NULL
ldap_int_select
read1msg: ld 0x803031190 msgid 1 all 1
read1msg: ld 0x803031190 msgid 1 message type bind
read1msg: ld 0x803031190 0 new referrals
read1msg:  mark request completed, ld 0x803031190 msgid 1
request done: ld 0x803031190 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_result
ldap_msgfree
ldap_search_ext
put_filter: "(objectClass=posixAccount)"
put_filter: simple
put_simple_filter: "objectClass=posixAccount"
ldap_build_search_req ATTRS: uid
ldap_send_initial_request
ldap_send_server_request
ldap_result ld 0x803031190 msgid 2
wait4msg ld 0x803031190 msgid 2 (timeout 10000000 usec)
wait4msg continue ld 0x803031190 msgid 2 all 0
** ld 0x803031190 Connections:
* host: 127.0.0.1  port: 389  (default)
  refcnt: 2  status: Connected
  last used: Sun Jan  8 14:11:07 2012


** ld 0x803031190 Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x803031190 request count 1 (abandoned 0)
** ld 0x803031190 Response Queue:
   Empty
  ld 0x803031190 response count 0
ldap_chkResponseList ld 0x803031190 msgid 2 all 0
ldap_chkResponseList returns ld 0x803031190 NULL
ldap_int_select
read1msg: ld 0x803031190 msgid 2 all 0
read1msg: ld 0x803031190 msgid 2 message type search-entry
ldap_get_values
ldap_msgfree
ldap_abandon 2
ldap_abandon_ext 2
do_abandon origid 2, msgid 2
ldap_msgdelete ld=0x803031190 msgid=2
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_free_request (origid 2, msgid 2)
ldap_msgfree
nslcd: [31b782] DEBUG: ldap_unbind()
ldap_unbind
ldap_free_connection 1 1
ldap_send_unbind
ldap_free_connection: actually freed
nslcd: [31b782] DEBUG: bind successful
nslcd: [31b782] error writing to client: Broken pipe
ldap_msgfree
ldap_abandon 2
ldap_abandon_ext 2
do_abandon origid 2, msgid 2
ldap_msgdelete ld=0x803031040 msgid=2
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_free_request (origid 2, msgid 2)
ldap_msgfree
^Cnslcd: [31b782] DEBUG: ldap_unbind()
nslcd: [058ed8] DEBUG: ldap_unbind()
ldap_unbind
ldap_unbind
ldap_free_connection 1 1
ldap_free_connection 1 1
nslcd: [b7acd9] DEBUG: ldap_unbind()
ldap_unbind
nslcd: [b50c2a] DEBUG: ldap_unbind()
ldap_unbind
ldap_send_unbind
ldap_free_connection 1 1
ldap_free_connection 1 1
ldap_send_unbind
ldap_send_unbind
nslcd: [06dac8] DEBUG: ldap_unbind()
ldap_free_connection: actually freed
ldap_free_connection: actually freed
ldap_free_connection: actually freed
ldap_unbind
ldap_free_connection 1 1
ldap_send_unbind
ldap_send_unbind
ldap_free_connection: actually freed
ldap_free_connection: actually freed
nslcd: caught signal SIGINT (2), shutting down
nslcd: DEBUG: unlink() of /var/run/nslcd.ctl failed (ignored): Permission denied nslcd: DEBUG: unlink() of /var/run/nslcd.pid failed (ignored): Permission denied
nslcd: version 0.7.15 bailing out

I think the line with string "error writing to client: Broken pipe" is somehow connected to the error but I do not know how. Any help would be appreciated. I used the same configs in the virtual and real installation(I just copied them).

Thanks,
Maxim
--
To unsubscribe send an email to
nss-pam-ldapd-users-unsubscribe@lists.arthurdejong.org or see
http://lists.arthurdejong.org/nss-pam-ldapd-users/