Created attachment 1201545
Proposed patch
+++ This bug was initially created as a clone of Bug #1376666 +++
Description of problem:
There is a minor bug in the nss_cmd_getpwuid_search code where it logs the
error in Summary after the done: block, which means that the message is logged
even if a matching domain was found for the id.
Code excerpt:
~~~
        ret = EOK;
        goto done;
    }
    /* All domains were tried and none had the entry. */
    ret = ENOENT;
done:
    if (ret == ENOENT) {
        /* The entry was not found, need to set result in negative cache */
        err = sss_ncache_set_uid(nctx->rctx->ncache, false, NULL, cmdctx->id);
        if (err != EOK) {
            DEBUG(SSSDBG_MINOR_FAILURE,
                "Cannot set negative cache for UID %"PRIu32"\n", cmdctx->id);
        }
        DEBUG(SSSDBG_MINOR_FAILURE,
              "No matching domain found for [%"PRIu32"]\n", cmdctx->id);
    }
    return ret;
}
~~~
Version-Release number of selected component (if applicable):
The customer has reported this on sssd-1.13.3-22.el6.x86_64
However the bug is present in all new versions of sssd and the latest upstream
repo as well.
How reproducible:
Always (with debug logging enabled)
Steps to Reproduce:
1. Enable debug logging and run an id lookup for a known good gid.
2.
3.
Actual results:
Log excerpt:
~~~
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [nss_cmd_getbyid] (0x0400): Running
command [18][SSS_NSS_GETPWUID] with id [9309087].
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [sss_ncache_check_str] (0x2000):
Checking negative cache for [NCE/UID/9309087]
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [nss_cmd_getpwuid_search] (0x0100):
Requesting info for [9309087@INT.CORP.SUN]
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x25dcf80
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x25de210
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [ldb] (0x4000): Running timer event
0x25dcf80 "ltdb_callback"
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [ldb] (0x4000): Destroying timer event
0x25de210 "ltdb_timeout"
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [ldb] (0x4000): Ending timer event
0x25dcf80 "ltdb_callback"
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [get_dp_name_and_id] (0x0400): Not a
LOCAL view, continuing with provided values.
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [check_cache] (0x0400): Cached entry is
valid, returning..
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [nss_cmd_getpwuid_search] (0x0400):
Returning info for uid [9309087@INT.CORP.SUN]
(Mon Sep 12 16:59:04 2016) [sssd[nss]] [nss_cmd_getpwuid_search] (0x0080): No
matching domain found for [9309087]
~~~
Expected results:
The last log entry "No matching domain found for [9309087]" should not be
present.
Additional info:
Proposed patch attached.