Bug 1376057 - Misleading error messages for wrong replica credentials
Summary: Misleading error messages for wrong replica credentials
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: 389-ds-base
Version: 7.4
Hardware: x86_64
OS: Linux
medium
medium
Target Milestone: rc
: ---
Assignee: Noriko Hosoi
QA Contact: Viktor Ashirov
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-09-14 14:35 UTC by Sankar Ramalingam
Modified: 2016-12-07 18:06 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-12-07 18:06:50 UTC
Target Upstream Version:


Attachments (Terms of Use)

Description Sankar Ramalingam 2016-09-14 14:35:09 UTC
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)

Comment 2 Noriko Hosoi 2016-09-14 16:09:13 UTC
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.

Comment 3 Noriko Hosoi 2016-09-14 16:10:12 UTC
^7.5^7.4^ :p

Comment 4 Sankar Ramalingam 2016-10-11 10:09:09 UTC
(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.

Comment 5 mreynolds 2016-12-07 18:06:50 UTC
This was fixed upstream via: https://fedorahosted.org/389/ticket/48978 and will be included in 7.4 (389-ds-base-1.3.6)


Note You need to log in before you can comment on or make changes to this bug.