Package: sssd Version: 1.2.1-4+squeeze1 Severity: important
Sssd refuses to change user's password when ldap_pwd_policy is set to shadow and LDAP server has disabled password policies support. Changing ldap_pwd_policy to none in sssd.conf fixes the problem. Enabling ppolicy module and configuring ppolicy overlay in slapd also fixes the problem. Conditions: - sssd.conf settings: id_provider = ldap access_provider = ldap auth_provider = ldap chpass_provider = ldap ldap_pwd_policy = shadow - user has shadowAccount attributes, - slapd has ppolicy module disabled, - slapd has ppolicy overlay disabled. I'm attaching debug logs of slapd, sssd and PAM messages obtained during the password change operation: http://pastebin.com/KE9UVZKh -- System Information: Debian Release: 6.0.3 APT prefers stable APT policy: (500, 'stable') Architecture: amd64 (x86_64) Kernel: Linux 2.6.38.8-vs2.3.0.37-rc17-beng (SMP w/4 CPU cores) Locale: LANG=C, LC_CTYPE=C (charmap=ANSI_X3.4-1968) Shell: /bin/sh linked to /bin/dash Versions of packages sssd depends on: ii libc-ares2 1.7.3-1 library for asyncronous name resol ii libc6 2.11.2-10 Embedded GNU C Library: Shared lib ii libcomerr2 1.41.12-4stable1 common error description library ii libdbus-1-3 1.2.24-4+squeeze1 simple interprocess messaging syst ii libk5crypto3 1.8.3+dfsg-4squeeze2 MIT Kerberos runtime libraries - C ii libkrb5-3 1.8.3+dfsg-4squeeze2 MIT Kerberos runtime libraries ii libldap-2.4-2 2.4.23-7.2 OpenLDAP libraries ii libldb0 1:0.9.10~git20100203-1+b1 LDAP-like embedded database - shar ii libnspr4-0d 4.8.6-1 NetScape Portable Runtime Library ii libnss3-1d 3.12.8-1+squeeze3 Network Security Service libraries ii libpam0g 1.1.1-6.1 Pluggable Authentication Modules l ii libpcre3 8.12-4 Perl 5 Compatible Regular Expressi ii libpopt0 1.16-1 lib for parsing cmdline parameters ii libselinux1 2.0.96-1 SELinux runtime shared libraries ii libsemanage1 2.0.45-1 SELinux policy management library. ii libtalloc2 2.0.1-1 hierarchical pool based memory all ii libtdb1 1.2.1-2+b1 Trivial Database - shared library ii libtevent0 0.9.8-1 talloc-based event loop library - ii python 2.6.6-3+squeeze6 interactive high-level object-orie ii python-sss 1.2.1-4+squeeze1 Pam module for the System Security Versions of packages sssd recommends: ii bind9-host 1:9.7.3.dfsg-1~squeeze3 Version of 'host' bundled with BIN ii ldap-utils 2.4.23-7.2 OpenLDAP utilities Versions of packages sssd suggests: ii libnss-sss 1.2.1-4+squeeze1 Nss library for the System Securit ii libpam-sss 1.2.1-4+squeeze1 Pam module for the System Security -- no debconf information
---------------------- Debug: PHASE 1 CONSOLE: pwilk@baud:~$ passwd Current Password: SSSD: [sssd[nss]] [accept_fd_handler] (4): Client connected! [sssd[nss]] [sss_cmd_get_version] (5): Received client version [1]. [sssd[nss]] [sss_cmd_get_version] (5): Offered version [1]. [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting info for [pwilk] from [<ALL>] [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting info for [pwilk@LDAP] [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting info for [pwilk] from [<ALL>] [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting info for [pwilk@LDAP] [sssd[nss]] [accept_fd_handler] (4): Client connected! [sssd[nss]] [sss_cmd_get_version] (5): Received client version [1]. [sssd[nss]] [sss_cmd_get_version] (5): Offered version [1]. [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting info for [pwilk] from [<ALL>] [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting info for [pwilk@LDAP] [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting info for [pwilk] from [<ALL>] [sssd[nss]] [nss_cmd_getpwnam] (4): Requesting info for [pwilk@LDAP] [sssd] [service_check_alive] (4): Checking service LDAP(19723) is still alive [sssd] [service_send_ping] (4): Pinging LDAP [sssd] [service_check_alive] (4): Checking service nss(19724) is still alive [sssd] [service_send_ping] (4): Pinging nss [sssd] [service_check_alive] (4): Checking service pam(19725) is still alive [sssd] [service_send_ping] (4): Pinging pam [sssd] [ping_check] (4): Service LDAP replied to ping [sssd] [ping_check] (4): Service nss replied to ping [sssd] [ping_check] (4): Service pam replied to ping [sssd[be[LDAP]]] [fo_resolve_service_send] (4): Trying to resolve service 'LDAP' [sssd[be[LDAP]]] [resolv_gethostbyname_send] (4): Trying to resolve A record of 'ldap.myorg' [sssd[be[LDAP]]] [set_server_common_status] (4): Marking server 'ldap.myorg' as 'resolving name' [sssd[be[LDAP]]] [set_server_common_status] (4): Marking server 'ldap.myorg' as 'name resolved' [sssd[be[LDAP]]] [be_resolve_server_done] (4): Found address for server ldap.myorg: [192.168.0.2] [sssd[be[LDAP]]] [simple_bind_send] (4): Executing simple bind as: cn=NSSreader,ou=people,ou=virtual,dc=myorg,dc=org [sssd[be[LDAP]]] [simple_bind_done] (5): Server returned no controls. [sssd[be[LDAP]]] [simple_bind_done] (3): Bind result: Success(0), (null) [sssd[be[LDAP]]] [fo_set_port_status] (4): Marking port 389 of server 'ldap.myorg' as 'working' [sssd[be[LDAP]]] [set_server_common_status] (4): Marking server 'ldap.myorg' as 'working' [sssd[be[LDAP]]] [enum_users_op_done] (4): Users higher timestamp: [20111019141328Z] [sssd[be[LDAP]]] [enum_groups_op_done] (4): Groups higher timestamp: [20111017092126Z] [sssd] [service_check_alive] (4): Checking service LDAP(19723) is still alive [sssd] [service_send_ping] (4): Pinging LDAP [sssd] [service_check_alive] (4): Checking service nss(19724) is still alive [sssd] [service_send_ping] (4): Pinging nss [sssd] [service_check_alive] (4): Checking service pam(19725) is still alive [sssd] [service_send_ping] (4): Pinging pam [sssd] [ping_check] (4): Service LDAP replied to ping [sssd] [ping_check] (4): Service pam replied to ping [sssd] [ping_check] (4): Service nss replied to ping [sssd] [service_check_alive] (4): Checking service LDAP(19723) is still alive [sssd] [service_send_ping] (4): Pinging LDAP [sssd] [service_check_alive] (4): Checking service nss(19724) is still alive [sssd] [service_send_ping] (4): Pinging nss [sssd] [service_check_alive] (4): Checking service pam(19725) is still alive [sssd] [service_send_ping] (4): Pinging pam [sssd] [ping_check] (4): Service LDAP replied to ping [sssd] [ping_check] (4): Service pam replied to ping [sssd] [ping_check] (4): Service nss replied to ping [sssd] [service_check_alive] (4): Checking service LDAP(19723) is still alive [sssd] [service_send_ping] (4): Pinging LDAP [sssd] [service_check_alive] (4): Checking service nss(19724) is still alive [sssd] [service_send_ping] (4): Pinging nss [sssd] [service_check_alive] (4): Checking service pam(19725) is still alive [sssd] [service_send_ping] (4): Pinging pam [sssd] [ping_check] (4): Service LDAP replied to ping [sssd] [ping_check] (4): Service pam replied to ping [sssd] [ping_check] (4): Service nss replied to ping [sssd] [service_check_alive] (4): Checking service LDAP(19723) is still alive [sssd] [service_send_ping] (4): Pinging LDAP [sssd] [service_check_alive] (4): Checking service nss(19724) is still alive [sssd] [service_send_ping] (4): Pinging nss [sssd] [service_check_alive] (4): Checking service pam(19725) is still alive [sssd] [service_send_ping] (4): Pinging pam [sssd] [ping_check] (4): Service LDAP replied to ping [sssd] [ping_check] (4): Service pam replied to ping [sssd] [ping_check] (4): Service nss replied to ping [sssd[pam]] [accept_fd_handler] (4): Client connected! [sssd[pam]] [sss_cmd_get_version] (5): Received client version [3]. [sssd[pam]] [sss_cmd_get_version] (5): Offered version [3]. [sssd[pam]] [pam_cmd_chauthtok_prelim] (4): entering pam_cmd_chauthtok_prelim [sssd[pam]] [pam_print_data] (4): command: PAM_CHAUTHTOK_PRELIM [sssd[pam]] [pam_print_data] (4): domain: (null) [sssd[pam]] [pam_print_data] (4): user: pwilk [sssd[pam]] [pam_print_data] (4): service: passwd [sssd[pam]] [pam_print_data] (4): tty: (null) [sssd[pam]] [pam_print_data] (4): ruser: (null) [sssd[pam]] [pam_print_data] (4): rhost: (null) [sssd[pam]] [pam_print_data] (4): authtok type: 1 [sssd[pam]] [pam_print_data] (4): authtok size: 10 [sssd[pam]] [pam_print_data] (4): newauthtok type: 0 [sssd[pam]] [pam_print_data] (4): newauthtok size: 0 [sssd[pam]] [pam_print_data] (4): priv: 0 [sssd[pam]] [pam_print_data] (4): cli_pid: 19728 [sssd[pam]] [pam_dp_send_req] (4): Sending request with the following data: [sssd[pam]] [pam_print_data] (4): command: PAM_CHAUTHTOK_PRELIM [sssd[pam]] [pam_print_data] (4): domain: LDAP [sssd[pam]] [pam_print_data] (4): user: pwilk [sssd[pam]] [pam_print_data] (4): service: passwd [sssd[pam]] [pam_print_data] (4): tty: (null) [sssd[pam]] [pam_print_data] (4): ruser: (null) [sssd[pam]] [pam_print_data] (4): rhost: (null) [sssd[pam]] [pam_print_data] (4): authtok type: 1 [sssd[pam]] [pam_print_data] (4): authtok size: 10 [sssd[pam]] [pam_print_data] (4): newauthtok type: 0 [sssd[pam]] [pam_print_data] (4): newauthtok size: 0 [sssd[pam]] [pam_print_data] (4): priv: 0 [sssd[pam]] [pam_print_data] (4): cli_pid: 19728 [sssd[pam]] [pam_dom_forwarder] (4): pam_dp_send_req returned 0 [sssd[be[LDAP]]] [be_pam_handler] (4): Got request with the following data [sssd[be[LDAP]]] [pam_print_data] (4): command: PAM_CHAUTHTOK_PRELIM [sssd[be[LDAP]]] [pam_print_data] (4): domain: LDAP [sssd[be[LDAP]]] [pam_print_data] (4): user: pwilk [sssd[be[LDAP]]] [pam_print_data] (4): service: passwd [sssd[be[LDAP]]] [pam_print_data] (4): tty: [sssd[be[LDAP]]] [pam_print_data] (4): ruser: [sssd[be[LDAP]]] [pam_print_data] (4): rhost: [sssd[be[LDAP]]] [pam_print_data] (4): authtok type: 1 [sssd[be[LDAP]]] [pam_print_data] (4): authtok size: 10 [sssd[be[LDAP]]] [pam_print_data] (4): newauthtok type: 0 [sssd[be[LDAP]]] [pam_print_data] (4): newauthtok size: 0 [sssd[be[LDAP]]] [pam_print_data] (4): priv: 0 [sssd[be[LDAP]]] [pam_print_data] (4): cli_pid: 19728 [sssd[be[LDAP]]] [sdap_pam_chpass_handler] (2): starting password change request for user [pwilk]. [sssd[be[LDAP]]] [fo_resolve_service_send] (4): Trying to resolve service 'LDAP' [sssd[be[LDAP]]] [be_resolve_server_done] (4): Found address for server ldap.myorg: [192.168.0.2] [sssd[be[LDAP]]] [sdap_connect_send] (4): Executing START TLS [sssd[be[LDAP]]] [sdap_connect_done] (3): START TLS result: Success(0), (null) [sssd[be[LDAP]]] [fo_set_port_status] (4): Marking port 389 of server 'ldap.myorg' as 'working' [sssd[be[LDAP]]] [set_server_common_status] (4): Marking server 'ldap.myorg' as 'working' [sssd[be[LDAP]]] [simple_bind_send] (4): Executing simple bind as: uid=pwilk,ou=people,ou=team,dc=myorg,dc=org [sssd[be[LDAP]]] [simple_bind_done] (5): Server returned no controls. [sssd[be[LDAP]]] [simple_bind_done] (3): Bind result: Success(0), (null) [sssd[be[LDAP]]] [be_pam_handler_callback] (4): Backend returned: (3, 0, <NULL>) [Internal Error (Success)] [sssd[be[LDAP]]] [be_pam_handler_callback] (4): Sending result [0][LDAP] [sssd[be[LDAP]]] [be_pam_handler_callback] (4): Sent result [0][LDAP] [sssd[pam]] [pam_dp_process_reply] (4): received: [0][LDAP] [sssd[pam]] [pam_reply] (4): pam_reply get called. [sssd[pam]] [pam_reply] (4): blen: 21 SLAPD: slapd[13588]: conn=1011 fd=29 ACCEPT from IP=192.168.0.2:55598 (IP=192.168.0.2:389) slapd[13588]: conn=1011 op=0 EXT oid=1.3.6.1.4.1.1466.20037 slapd[13588]: conn=1011 op=0 STARTTLS slapd[13588]: conn=1011 op=0 RESULT oid= err=0 text= slapd[13588]: conn=1011 fd=29 TLS established tls_ssf=128 ssf=128 slapd[13588]: conn=1011 op=1 BIND dn="uid=pwilk,ou=people,ou=team,dc=myorg,dc=org" method=128 slapd[13588]: slap_global_control: unrecognized control: 1.3.6.1.4.1.42.2.27.8.5.1 slapd[13588]: => access_allowed: result not in cache (userPassword) slapd[13588]: => access_allowed: auth access to "uid=pwilk,ou=people,ou=team,dc=myorg,dc=org" "userPassword" requested slapd[13588]: => acl_get: [1] attr userPassword slapd[13588]: => acl_mask: access to entry "uid=pwilk,ou=people,ou=team,dc=myorg,dc=org", attr "userPassword" requested slapd[13588]: => acl_mask: to value by "", (=0) slapd[13588]: <= check a_dn_pat: anonymous slapd[13588]: <= acl_mask: [1] applying auth(=xd) (stop) slapd[13588]: <= acl_mask: [1] mask: auth(=xd) slapd[13588]: => slap_access_allowed: auth access granted by auth(=xd) slapd[13588]: => access_allowed: auth access granted by auth(=xd) slapd[13588]: conn=1011 op=1 BIND dn="uid=pwilk,ou=people,ou=team,dc=myorg,dc=org" mech=SIMPLE ssf=0 slapd[13588]: conn=1011 op=1 RESULT tag=97 err=0 text= slapd[13588]: conn=1011 op=2 UNBIND slapd[13588]: conn=1011 fd=29 closed -------------------------- PHASE 2 CONSOLE: Password: Retype new password: SSSD: [sssd[pam]] [pam_cmd_chauthtok] (4): entering pam_cmd_chauthtok [sssd[pam]] [pam_print_data] (4): command: PAM_CHAUTHTOK [sssd[pam]] [pam_print_data] (4): domain: (null) [sssd[pam]] [pam_print_data] (4): user: pwilk [sssd[pam]] [pam_print_data] (4): service: passwd [sssd[pam]] [pam_print_data] (4): tty: (null) [sssd[pam]] [pam_print_data] (4): ruser: (null) [sssd[pam]] [pam_print_data] (4): rhost: (null) [sssd[pam]] [pam_print_data] (4): authtok type: 1 [sssd[pam]] [pam_print_data] (4): authtok size: 10 [sssd[pam]] [pam_print_data] (4): newauthtok type: 1 [sssd[pam]] [pam_print_data] (4): newauthtok size: 9 [sssd[pam]] [pam_print_data] (4): priv: 0 [sssd[pam]] [pam_print_data] (4): cli_pid: 19728 [sssd[pam]] [pam_dp_send_req] (4): Sending request with the following data: [sssd[pam]] [pam_print_data] (4): command: PAM_CHAUTHTOK [sssd[pam]] [pam_print_data] (4): domain: LDAP [sssd[pam]] [pam_print_data] (4): user: pwilk [sssd[pam]] [pam_print_data] (4): service: passwd [sssd[pam]] [pam_print_data] (4): tty: (null) [sssd[pam]] [pam_print_data] (4): ruser: (null) [sssd[pam]] [pam_print_data] (4): rhost: (null) [sssd[pam]] [pam_print_data] (4): authtok type: 1 [sssd[pam]] [pam_print_data] (4): authtok size: 10 [sssd[pam]] [pam_print_data] (4): newauthtok type: 1 [sssd[pam]] [pam_print_data] (4): newauthtok size: 9 [sssd[pam]] [pam_print_data] (4): priv: 0 [sssd[pam]] [pam_print_data] (4): cli_pid: 19728 [sssd[pam]] [pam_dom_forwarder] (4): pam_dp_send_req returned 0 [sssd[be[LDAP]]] [be_pam_handler] (4): Got request with the following data [sssd[be[LDAP]]] [pam_print_data] (4): command: PAM_CHAUTHTOK [sssd[be[LDAP]]] [pam_print_data] (4): domain: LDAP [sssd[be[LDAP]]] [pam_print_data] (4): user: pwilk [sssd[be[LDAP]]] [pam_print_data] (4): service: passwd [sssd[be[LDAP]]] [pam_print_data] (4): tty: [sssd[be[LDAP]]] [pam_print_data] (4): ruser: [sssd[be[LDAP]]] [pam_print_data] (4): rhost: [sssd[be[LDAP]]] [pam_print_data] (4): authtok type: 1 [sssd[be[LDAP]]] [pam_print_data] (4): authtok size: 10 [sssd[be[LDAP]]] [pam_print_data] (4): newauthtok type: 1 [sssd[be[LDAP]]] [pam_print_data] (4): newauthtok size: 9 [sssd[be[LDAP]]] [pam_print_data] (4): priv: 0 [sssd[be[LDAP]]] [pam_print_data] (4): cli_pid: 19728 [sssd[be[LDAP]]] [sdap_pam_chpass_handler] (2): starting password change request for user [pwilk]. [sssd[be[LDAP]]] [fo_resolve_service_send] (4): Trying to resolve service 'LDAP' [sssd[be[LDAP]]] [be_resolve_server_done] (4): Found address for server ldap.myorg: [192.168.0.2] [sssd[be[LDAP]]] [sdap_connect_send] (4): Executing START TLS [sssd[be[LDAP]]] [sdap_connect_done] (3): START TLS result: Success(0), (null) [sssd[be[LDAP]]] [fo_set_port_status] (4): Marking port 389 of server 'ldap.myorg' as 'working' [sssd[be[LDAP]]] [set_server_common_status] (4): Marking server 'ldap.myorg' as 'working' [sssd[be[LDAP]]] [simple_bind_send] (4): Executing simple bind as: uid=pwilk,ou=people,ou=team,dc=myorg,dc=org [sssd[be[LDAP]]] [simple_bind_done] (5): Server returned no controls. [sssd[be[LDAP]]] [simple_bind_done] (3): Bind result: Success(0), (null) [sssd[be[LDAP]]] [sdap_auth4chpass_done] (1): Changing shadow password attributes not implemented. [sssd[be[LDAP]]] [be_pam_handler_callback] (4): Backend returned: (3, 28, <NULL>) [Internal Error (No space left on device)] [sssd[be[LDAP]]] [be_pam_handler_callback] (4): Sending result [28][LDAP] [sssd[be[LDAP]]] [be_pam_handler_callback] (4): Sent result [28][LDAP] [sssd[pam]] [pam_dp_process_reply] (4): received: [28][LDAP] [sssd[pam]] [pam_reply] (4): pam_reply get called. [sssd[pam]] [pam_reply] (4): blen: 21 [sssd[pam]] [client_recv] (5): Client disconnected! [sssd[nss]] [client_recv] (5): Client disconnected! SLAPD: slapd[13588]: conn=1012 fd=29 ACCEPT from IP=192.168.0.2:55643 (IP=192.168.0.2:389) slapd[13588]: conn=1012 op=0 EXT oid=1.3.6.1.4.1.1466.20037 slapd[13588]: conn=1012 op=0 STARTTLS slapd[13588]: conn=1012 op=0 RESULT oid= err=0 text= slapd[13588]: conn=1012 fd=29 TLS established tls_ssf=128 ssf=128 slapd[13588]: conn=1012 op=1 BIND dn="uid=pwilk,ou=people,ou=team,dc=myorg,dc=org" method=128 slapd[13588]: slap_global_control: unrecognized control: 1.3.6.1.4.1.42.2.27.8.5.1 slapd[13588]: => access_allowed: result not in cache (userPassword) slapd[13588]: => access_allowed: auth access to "uid=pwilk,ou=people,ou=team,dc=myorg,dc=org" "userPassword" requested slapd[13588]: => acl_get: [1] attr userPassword slapd[13588]: => acl_mask: access to entry "uid=pwilk,ou=people,ou=team,dc=myorg,dc=org", attr "userPassword" requested slapd[13588]: => acl_mask: to value by "", (=0) slapd[13588]: <= check a_dn_pat: anonymous slapd[13588]: <= acl_mask: [1] applying auth(=xd) (stop) slapd[13588]: <= acl_mask: [1] mask: auth(=xd) slapd[13588]: => slap_access_allowed: auth access granted by auth(=xd) slapd[13588]: => access_allowed: auth access granted by auth(=xd) slapd[13588]: conn=1012 op=1 BIND dn="uid=pwilk,ou=people,ou=team,dc=myorg,dc=org" mech=SIMPLE ssf=0 slapd[13588]: conn=1012 op=1 RESULT tag=97 err=0 text= slapd[13588]: conn=1012 op=2 UNBIND slapd[13588]: conn=1012 fd=29 closed SYSLOG: passwd[19728]: pam_sss(passwd:chauthtok): Password change failed for user pwilk: 28 (Module is unknown) CONSOLE: passwd: Authentication token manipulation error passwd: password unchanged # "No space left on device" error is probably a bad explanation of some internal error code # using errstr() or similar, but to be sure: root@baud:/# df -H /dev/hdv1 5,3G 1,2G 3,9G 24% / none 263M 33k 263M 1% /tmp
