If I'm understanding this log correctly, what is happening is that the attempt to bind as the user to the slave server, which then issues a referral to the master LDAP server. When we rebind to the master server, it's not accepting the bind credentials. This is due to (what we consider to be) a bug in the openldap client libraries. Due to a poorly-written mutex, the openldap client library was sometimes hanging if it attempted to automatically follow a referral during a bind.

Instead of fixing the mutex (as we requested), they instead opted not to invoke the rebind procedure when following referrals on bind. We are still working with openldap upstream to correct this behavior.

However, in your particular case, it would be best for you to specify the following additional option in sssd.conf:

ldap_chpass_uri = master-ldap.domain.local

This will cause SSSD to always use the specified URI (or list of URIs) for performing password changes, instead of trying to use the regular {{{ldap_uri}}} list which may include read-only replicas like your {{{slave-ldap.domain.local}}}.

I'm leaving this ticket open to track the rebind bug.

description: Trying to change user password with 'passwd' command fails when the first uri in ldap_uri is set to a slave ldap server:

''Changement de mot de passe pour l'utilisateur frobin.[[BR]]
Current Password: [[BR]]
Nouveau mot de passe : [[BR]]
Retapez le nouveau mot de passe : [[BR]]
passwd: Erreur de manipulation du jeton d'authentification''

The current sssd.conf:[[BR]]
''
[domain/default][[BR]]
...[[BR]]
ldap_uri slave-ldap.domain.local master-ldap.domain.local[[BR]]
...[[BR]]
''

When modifying sssd.conf ldap_uri to refer only to the master ldap server, the password change is successfull.
''
[domain/default][[BR]]
...[[BR]]
ldap_uri master-ldap.domain.local[[BR]]
...[[BR]]
''

Modifying the password with the "classic" nss_ldap system (sssd disabled) always work.

Looking to the log files on the client, the sssd client tries to connect to both ldap servers but fails:[[BR]]
''(Mon May 23 17:41:16 2011) [sssd[be[default]]] [get_server_status] (7): Status of server 'slave-ldap.domain.local' is 'working'[BR] [sssd[be[default]]] [get_port_status] (7): Port status of port 389 for server 'slave-ldap.domain.local' is 'working'[BR] [sssd[be[default]]] [get_server_status] (7): Status of server 'slave-ldap.domain.local' is 'working'[BR] [sssd[be[default]]] [be_resolve_server_done] (4): Found address for server slave-ldap.domain.local: [192.168.101.4][BR] [sssd[be[default]]] [sdap_uri_callback] (6): Constructed uri ldap://slave-ldap.domain.local/ [BR] [sssd[be[default]]] [sdap_connect_send] (4): Executing START TLS[BR] [sssd[be[default]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://slave-ldap.domain.local:389] with fd [25].[BR] [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xacc700], ldap[0xacc360][BR] [sssd[be[default]]] [sdap_connect_done] (3): START TLS result: Success(0), (null)[BR] [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'slave-ldap.domain.local' as 'working'[BR] [sssd[be[default]]] [set_server_common_status] (4): Marking server 'slave-ldap.domain.local' as 'working'[BR] [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xacc7c0[BR] [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xacc870[BR] [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0xacc870 "ltdb_timeout"[BR] [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0xacc7c0 "ltdb_callback"[BR] [sssd[be[default]]] [find_password_expiration_attributes] (9): No password policy requested.[BR] [sssd[be[default]]] [sdap_control_create] (3): Server does not support the requested control [1.3.6.1.4.1.42.2.27.8.5.1].[BR] [sssd[be[default]]] [simple_bind_send] (4): Executing simple bind as: uid=frobin,ou=people,dc=domain,dc=local[BR] [sssd[be[default]]] [simple_bind_send] (8): ldap simple bind sent, msgid = 2[BR] [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xacb8f0], ldap[0xacc360][BR] [sssd[be[default]]] [sdap_process_result] (8): Trace: ldap_result found nothing![[BR]](Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xacb8f0], ldap[0xacc360][BR] [sssd[be[default]]] [simple_bind_done] (5): Server returned no controls.[BR] [sssd[be[default]]] [simple_bind_done] (3): Bind result: Success(0), (null)[BR] [sssd[be[default]]] [sdap_auth4chpass_done] (7): user [uid=frobin,ou=people,dc=domain,dc=local] successfully authenticated.[BR] [sssd[be[default]]] [sdap_control_create] (3): Server does not support the requested control [1.3.6.1.4.1.42.2.27.8.5.1].[BR] [sssd[be[default]]] [sdap_exop_modify_passwd_send] (4): Executing extended operation[BR] [sssd[be[default]]] [sdap_exop_modify_passwd_send] (8): ldap_extended_operation sent, msgid = 3[BR] [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xa28210], ldap[0xacc360][BR] [sssd[be[default]]] [sdap_process_result] (8): Trace: ldap_result found nothing![[BR]](Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xa28210], ldap[0xacc360][BR] [sssd[be[default]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://ldap.domain.local] with fd [27].[BR] [sssd[be[default]]] [synchronous_tls_setup] (4): Executing START TLS[BR] [sssd[be[default]]] [synchronous_tls_setup] (3): START TLS result: Success(0), (null)[BR] [sssd[be[default]]] [sdap_control_create] (3): Server does not support the requested control [1.3.6.1.4.1.42.2.27.8.5.1].[BR] [sssd[be[default]]] [sdap_rebind_proc] (7): Successfully bind to [ldap://master-ldap.domain.local].[BR] [sssd[be[default]]] [sdap_process_result] (8): Trace: ldap_result found nothing![[BR]](Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xa28210], ldap[0xacc360][BR] [sssd[be[default]]] [sdap_ldap_connect_callback_del] (9): Closing LDAP connection with fd [27].[BR] [sssd[be[default]]] [sdap_exop_modify_passwd_done] (5): Server returned no controls.[BR] [sssd[be[default]]] [sdap_exop_modify_passwd_done] (3): ldap_extended_operation result: Strong(er) authentication required(8), only authenticated users may change passwords[BR] [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (3, 4, <NULL>) [Internal Error (Erreur système)][BR] [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [4][default][BR] [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [4][default][BR] [sssd[be[default]]] [sdap_handle_release] (8): Trace: sh[0xacb580], connected[1], ops[(nil)], ldap[0xacc360], destructor_lock[0], release_memory[0][BR] [sssd[be[default]]] [remove_connection_callback] (9): Successfully removed connection callback.[[BR]]
''

=> Trying to change user password with 'passwd' command fails when the first uri in ldap_uri is set to a slave ldap server:
{{{
Changement de mot de passe pour l'utilisateur frobin.
Current Password: [[BR]]
Nouveau mot de passe : [[BR]]
Retapez le nouveau mot de passe : [[BR]]
passwd: Erreur de manipulation du jeton d'authentification''
}}}
The current sssd.conf:
{{{
[domain/default]
...
ldap_uri slave-ldap.domain.local master-ldap.domain.local
...
}}}

When modifying sssd.conf ldap_uri to refer only to the master ldap server, the password change is successfull.
{{{
[domain/default][[BR]]
...
ldap_uri master-ldap.domain.local
...
}}}

Modifying the password with the "classic" nss_ldap system (sssd disabled) always work.

Looking to the log files on the client, the sssd client tries to connect to both ldap servers but fails:
{{{
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [get_server_status] (7): Status of server 'slave-ldap.domain.local' is 'working'
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [get_port_status] (7): Port status of port 389 for server 'slave-ldap.domain.local' is 'working'
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [get_server_status] (7): Status of server 'slave-ldap.domain.local' is 'working'
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [be_resolve_server_done] (4): Found address for server slave-ldap.domain.local: [192.168.101.4]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_uri_callback] (6): Constructed uri ldap://slave-ldap.domain.local/
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_connect_send] (4): Executing START TLS
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://slave-ldap.domain.local:389] with fd [25].
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xacc700], ldap[0xacc360]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_connect_done] (3): START TLS result: Success(0), (null)
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [fo_set_port_status] (4): Marking port 389 of server 'slave-ldap.domain.local' as 'working'
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [set_server_common_status] (4): Marking server 'slave-ldap.domain.local' as 'working'
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_callback": 0xacc7c0
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [ldb] (9): tevent: Added timed event "ltdb_timeout": 0xacc870
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [ldb] (9): tevent: Destroying timer event 0xacc870 "ltdb_timeout"
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [ldb] (9): tevent: Ending timer event 0xacc7c0 "ltdb_callback"
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [find_password_expiration_attributes] (9): No password policy requested.
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_control_create] (3): Server does not support the requested control [1.3.6.1.4.1.42.2.27.8.5.1].
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [simple_bind_send] (4): Executing simple bind as: uid=frobin,ou=people,dc=domain,dc=local
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [simple_bind_send] (8): ldap simple bind sent, msgid = 2
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xacb8f0], ldap[0xacc360]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xacb8f0], ldap[0xacc360]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [simple_bind_done] (5): Server returned no controls.
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [simple_bind_done] (3): Bind result: Success(0), (null)
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_auth4chpass_done] (7): user [uid=frobin,ou=people,dc=domain,dc=local] successfully authenticated.
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_control_create] (3): Server does not support the requested control [1.3.6.1.4.1.42.2.27.8.5.1].
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_exop_modify_passwd_send] (4): Executing extended operation
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_exop_modify_passwd_send] (8): ldap_extended_operation sent, msgid = 3
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xa28210], ldap[0xacc360]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xa28210], ldap[0xacc360]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://ldap.domain.local] with fd [27].
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [synchronous_tls_setup] (4): Executing START TLS
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [synchronous_tls_setup] (3): START TLS result: Success(0), (null)
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_control_create] (3): Server does not support the requested control [1.3.6.1.4.1.42.2.27.8.5.1].
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_rebind_proc] (7): Successfully bind to [ldap://master-ldap.domain.local].
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_process_result] (8): Trace: sh[0xacb580], connected[1], ops[0xa28210], ldap[0xacc360]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_ldap_connect_callback_del] (9): Closing LDAP connection with fd [27].
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_exop_modify_passwd_done] (5): Server returned no controls.
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_exop_modify_passwd_done] (3): ldap_extended_operation result: Strong(er) authentication required(8), only authenticated users may change passwords
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Backend returned: (3, 4, <NULL>) [Internal Error (Erreur système)]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sending result [4][default]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [be_pam_handler_callback] (4): Sent result [4][default]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [sdap_handle_release] (8): Trace: sh[0xacb580], connected[1], ops[(nil)], ldap[0xacc360], destructor_lock[0], release_memory[0]
(Mon May 23 17:41:16 2011) [sssd[be[default]]] [remove_connection_callback] (9): Successfully removed connection callback.
}}}

Replying to [comment:1 sgallagh]:

If I'm understanding this log correctly, what is happening is that the attempt to bind as the user to the slave server, which then issues a referral to the master LDAP server. When we rebind to the master server, it's not accepting the bind credentials. This is due to (what we consider to be) a bug in the openldap client libraries. Due to a poorly-written mutex, the openldap client library was sometimes hanging if it attempted to automatically follow a referral during a bind.

Instead of fixing the mutex (as we requested), they instead opted not to invoke the rebind procedure when following referrals on bind. We are still working with openldap upstream to correct this behavior.

However, in your particular case, it would be best for you to specify the following additional option in sssd.conf:
{{{
ldap_chpass_uri = master-ldap.domain.local
}}}

This will cause SSSD to always use the specified URI (or list of URIs) for performing password changes, instead of trying to use the regular {{{ldap_uri}}} list which may include read-only replicas like your {{{slave-ldap.domain.local}}}.

I'm leaving this ticket open to track the rebind bug.

Thank you very much for this answer. The option "ldap_chpass_uri" actually works. Is it documented somewhere ? I could not find it except in other issues listed in this bug tracker.

It's documented in the manpage {{{sssd-ldap(5)}}}:

       ldap_chpass_uri (string)
           Specifies the list of URIs of the LDAP servers to which SSSD should
           connect in the order of preference to change the password of a
           user. Refer to the “FAILOVER” section for more information on
           failover and server redundancy.

           To enable service discovery ldap_chpass_dns_service_name must be
           set.

           Default: empty, i.e. ldap_uri is used.

Related to #860. This is kept open to track specific customer request. The core of the problem is covered in #860.

milestone: NEEDS_TRIAGE => SSSD 1.7.0

Fields changed

milestone: SSSD 1.8.0 => SSSD 1.7.0

Fields changed

owner: somebody => sgallagh
rhbz: =>

Fields changed

milestone: SSSD 1.7.0 => Referrals

Fields changed

rhbz: => 0

Fields changed

blockedby: =>
blocking: =>
cc: => jkt@flaska.net
changelog: =>
design: =>
design_review: => 0
feature_milestone: =>
fedora_test_page: =>
review: => 0
selected: =>

Thank you for taking time to submit this request for SSSD. Unfortunately this issue was not given priority and the team lacks the capacity to work on it at this time.

Given that we are unable to fulfill this request I am closing the issue as wontfix.

If the issue still persist on recent SSSD you can request re-consideration of this decision by reopening this issue. Please provide additional technical details about its importance to you.

Thank you for understanding.

SSSD is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in SSSD's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/SSSD/sssd/issues/1917

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.