Hide Forgot
Description of problem: While verifying bug #1370300, I encountered misleading error messages. DS error log shows "error 49 invalid credentials, as well error 0, success" for passing invalid credentials to nsDS5ReplicaBindDN and nsDS5ReplicaCredentials Version-Release number of selected component (if applicable): 389-ds-base-1.3.5.10-10 How reproducible: Consistently when passing invalid credentials to Replication agreement. Steps to Reproduce: 1. Setup 2 way MMR. 2. Check the entries are synced across masters. 3. Change the credentials for replication agreement. [root@ratangad MMR_WINSYNC]# PORT=1189 ; /usr/bin/ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 << EOF dn: cn=1189_to_2626_on_ratangad.eng.blr.redhat.com,cn=replica,cn=dc\3Dpasssync\2Cdc\3Dcom,cn=mapping tree,cn=config replace: nsDS5ReplicaCredentials nsDS5ReplicaCredentials: InvalidPW123 EOF modifying entry "cn=1189_to_2626_on_ratangad.eng.blr.redhat.com,cn=replica,cn=dc\3Dpasssync\2Cdc\3Dcom,cn=mapping tree,cn=config" [root@ratangad MMR_WINSYNC]# PORT=1189 ; /usr/bin/ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 << EOF dn: cn=1189_to_14089_on_ratangad.eng.blr.redhat.com,cn=replica,cn=dc\3Dpasssync\2Cdc\3Dcom,cn=mapping tree,cn=config replace: nsDS5ReplicaBindDN nsDS5ReplicaBindDN: cn=WrongDN_Repl,cn=config EOF modifying entry "cn=1189_to_14089_on_ratangad.eng.blr.redhat.com,cn=replica,cn=dc\3Dpasssync\2Cdc\3Dcom,cn=mapping tree,cn=config" Initialize the replica again to check if error logs print error 49(Invalid credentials) or error 32(Entry doesn't exist). Actual results: Error log prints "error 0 success" along with the relevant error message. This is misleading whether the replica initialization is successful or not. Expected results: Error log prints only relevant messages. It should avoid printing irrelevant messages. Additional info: [14/Sep/2016:16:43:47.323809796 +051800] slapi_ldap_bind - Error: could not bind id [cn=SyncManager,cn=config] authentication mechanism [SIMPLE]: error 49 (Invalid credentials) errno 0 (Success) [14/Sep/2016:16:43:47.359207135 +051800] slapi_ldap_bind - Error: could not send bind request for id [cn=SyncManager,cn=config] authentication mechanism [SIMPLE]: error -1 (Can't contact LDAP server), system error -5987 (Invalid function argument.), network error 107 (Transport endpoint is not connected, host "ratangad.eng.blr.redhat.com:9989") [14/Sep/2016:16:43:47.467012608 +051800] slapi_ldap_bind - Error: could not bind id [cn=SyncManagerNN,cn=config] authentication mechanism [SIMPLE]: error 32 (No such object) errno 0 (Success) [14/Sep/2016:16:43:47.625316253 +051800] slapi_ldap_bind - Error: could not bind id [cn=SyncManager,cn=config] authentication mechanism [SIMPLE]: error 49 (Invalid credentials) errno 0 (Success)
Indeed, it could be misleading: > [14/Sep/2016:16:43:47.323809796 +051800] slapi_ldap_bind - Error: could not bind id [cn=SyncManager,cn=config] authentication mechanism [SIMPLE]: error 49 (Invalid credentials) errno 0 (Success) The issue is, the error 49 is from the Directory server's level (ACL), not from the system level (errno). In the system level, there is no problem. 1223 slapi_log_error(SLAPI_LOG_FATAL, LOG_ERR, "slapi_ldap_bind", 1224 "Error: could not bind id " 1225 "[%s] authentication mechanism [%s]: error %d (%s) errno %d (%s)\n", 1226 bindid ? bindid : "(anon)", 1227 mech ? mech : "SIMPLE", 1228 rc, ldap_err2string(rc), errno, slapd_system_strerror(errno)); For instance, we could replace "errno" with "system error". Or even we could suppress "errno %d (%s)" part if errno is 0. But I believe this is not a new issue and this is not a blocker bug. Plus there are more places having the similar log messages. I propose to push this to 7.5.
^7.5^7.4^ :p
(In reply to Noriko Hosoi from comment #2) > Indeed, it could be misleading: > > > [14/Sep/2016:16:43:47.323809796 +051800] slapi_ldap_bind - Error: could not bind id [cn=SyncManager,cn=config] authentication mechanism [SIMPLE]: error 49 (Invalid credentials) errno 0 (Success) > > The issue is, the error 49 is from the Directory server's level (ACL), not > from the system level (errno). In the system level, there is no problem. > > 1223 slapi_log_error(SLAPI_LOG_FATAL, LOG_ERR, "slapi_ldap_bind", > 1224 "Error: could not bind id " > 1225 "[%s] authentication mechanism [%s]: error %d (%s) errno %d > (%s)\n", > 1226 bindid ? bindid : "(anon)", > 1227 mech ? mech : "SIMPLE", > 1228 rc, ldap_err2string(rc), errno, slapd_system_strerror(errno)); > > For instance, we could replace "errno" with "system error". Or even we > could suppress "errno %d (%s)" part if errno is 0. > > But I believe this is not a new issue and this is not a blocker bug. Plus > there are more places having the similar log messages. I agree with your Noriko. > > I propose to push this to 7.5.
This was fixed upstream via: https://fedorahosted.org/389/ticket/48978 and will be included in 7.4 (389-ds-base-1.3.6)