[sssd PR#347][opened] Fixes related to negative cache and "root" user/group

[fidencio]

   URL: https://github.com/SSSD/sssd/pull/347
Author: fidencio
 Title: #347: Fixes related to negative cache and "root" user/group
Action: opened

PR body:
"""
This patch set contains a bunch of fixes in the negative cache code.

The patches were tested in an AD-trust environment and more specific instructions/details
can be found below:
- **NEGCACHE: Add some comments about each step of sss_ncache_prepopulate()**
  Just verified the comments make sense.

- **NEGCACHE: Always add "root" to the negative cache**:
  - Add `filter_users = foo` and `filter_groups = foo` under `[nss]` section;
  - Restart SSSD (`systemctl restart sssd`) and run `id root`;
  - Inspect sssd_nss.log, checking for the second time the users and groups are added to
the negative cache;

    - Without this patch:
      ```
      (Mon Aug 14 17:09:50 2017) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'foo' matched without domain, user is foo
      (Mon Aug 14 17:09:50 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/USER/indirect.ipa.ff/foo(a)indirect.ipa.ff] to negative cache permanently
      (Mon Aug 14 17:09:50 2017) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'bar' matched without domain, user is bar
      (Mon Aug 14 17:09:50 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/GROUP/indirect.ipa.ff/bar(a)indirect.ipa.ff] to negative cache permanently
      ```
    - With this patch:
      ```
      (Mon Aug 14 17:13:31 2017) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'foo' matched without domain, user is foo
      (Mon Aug 14 17:13:31 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/USER/indirect.ipa.ff/foo(a)indirect.ipa.ff] to negative cache permanently
      (Mon Aug 14 17:13:31 2017) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'bar' matched without domain, user is bar
      (Mon Aug 14 17:13:31 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/GROUP/indirect.ipa.ff/bar(a)indirect.ipa.ff] to negative cache permanently
      (Mon Aug 14 17:13:31 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/USER/indirect.ipa.ff/root(a)indirect.ipa.ff] to negative cache permanently
      (Mon Aug 14 17:13:31 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/GROUP/indirect.ipa.ff/root(a)indirect.ipa.ff] to negative cache permanently
      (Mon Aug 14 17:13:31 2017) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain
indirect.ad.ff is Active
      (Mon Aug 14 17:13:31 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/USER/indirect.ad.ff/root(a)indirect.ad.ff] to negative cache permanently
      (Mon Aug 14 17:13:31 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/GROUP/indirect.ad.ff/root(a)indirect.ad.ff] to negative cache permanently
      ```

- **NEGCACHE: Add "0" to the negative cache**:
  - Considering the very same environment where the previous patch was applied, do:
    - `id 0`;
    - Inspect sssd_nss.log, checking for the cache req call triggered by the command
above;
      - Without this patch:
      ```
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [nss_getby_name] (0x0400): Input name: 0
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #0:
Setting "User by name" plugin
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_send] (0x0400): CR #0: New request
'User by name'
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_process_input] (0x0400): CR #0:
Parsing input name [0]
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'0' matched without domain, user is 0
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_set_name] (0x0400): CR #0: Setting
name [0]
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #0:
Performing a multi-domain search
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #0:
Search will check the cache and check the data provider
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_validate_domain_type] (0x2000):
Request type POSIX-only for domain indirect.ipa.ff type POSIX is valid
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #0: Using
domain [indirect.ipa.ff]
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR
#0: Preparing input data for domain [indirect.ipa.ff] rules
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_search_send] (0x0400): CR #0:
Looking up 0(a)indirect.ipa.ff
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #0:
Checking negative cache for [0(a)indirect.ipa.ff]
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking
negative cache for [NCE/USER/indirect.ipa.ff/0(a)indirect.ipa.ff]
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #0:
[0(a)indirect.ipa.ff] is not present in negative cache
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #0:
Looking up [0(a)indirect.ipa.ff] in cache
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x669120
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x6691e0
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [ldb] (0x4000): Running timer event 0x669120
"ltdb_callback"
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [ldb] (0x4000): Destroying timer event
0x6691e0 "ltdb_timeout"
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [ldb] (0x4000): Ending timer event 0x669120
"ltdb_callback"
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #0:
Object [0(a)indirect.ipa.ff] was not found in cache
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #0:
Looking up [0(a)indirect.ipa.ff] in data provider
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing
request for [0x416010:1:[e-mail]@indirect.ipa.ff]
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating
request for [indirect.ipa.ff][0x1][BE_REQ_USER][name=[e-mail]:-]
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x65db60
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering
request [0x416010:1:[e-mail]@indirect.ipa.ff]
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x65db60
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [sbus_dispatch] (0x4000): dbus conn:
0x65c8c0
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [sbus_dispatch] (0x4000): Dispatching.
      (Mon Aug 14 17:19:52 2017) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from
Data Provider - DP error code: 0 errno: 0 error message: Success
      ```
      - With this patch:
      ```
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [nss_getby_name] (0x0400): Input name: 0
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #0:
Setting "User by name" plugin
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_send] (0x0400): CR #0: New request
'User by name'
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_process_input] (0x0400): CR #0:
Parsing input name [0]
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'0' matched without domain, user is 0
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_set_name] (0x0400): CR #0: Setting
name [0]
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #0:
Performing a multi-domain search
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #0:
Search will check the cache and check the data provider
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_validate_domain_type] (0x2000):
Request type POSIX-only for domain indirect.ipa.ff type POSIX is valid
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #0: Using
domain [indirect.ipa.ff]
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_prepare_domain_data] (0x0400): CR
#0: Preparing input data for domain [indirect.ipa.ff] rules
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_search_send] (0x0400): CR #0:
Looking up 0(a)indirect.ipa.ff
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #0:
Checking negative cache for [0(a)indirect.ipa.ff]
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking
negative cache for [NCE/USER/indirect.ipa.ff/0(a)indirect.ipa.ff]
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #0:
[0(a)indirect.ipa.ff] does not exist (negative cache)
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_validate_domain_type] (0x2000):
Request type POSIX-only for domain indirect.ad.ff type POSIX is valid
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [cache_req_process_result] (0x0400): CR #0:
Finished: Not found

      ```

- **NEGCACHE: Descend to subdomains when adding user/groups**:
  - Considering the very same environment where the previous patch was applied, do:
    - `id root`;
    - Inspect sssd_nss.log, looking for when the user `foo` and group `bar` are added to
the negative cache;
      - Without this patch:
      ```
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'foo' matched without domain, user is foo
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/USER/indirect.ipa.ff/foo(a)indirect.ipa.ff] to negative cache permanently
      (Mon Aug 14 17:26:17 2017) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'bar' matched without domain, user is bar
      ```
      - With this patch:
      ```
      (Mon Aug 14 17:31:54 2017) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'foo' matched without domain, user is foo
      (Mon Aug 14 17:31:54 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/USER/indirect.ipa.ff/foo(a)indirect.ipa.ff] to negative cache permanently
      (Mon Aug 14 17:31:54 2017) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain
indirect.ad.ff is Active
      (Mon Aug 14 17:31:54 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/USER/indirect.ad.ff/foo(a)indirect.ad.ff] to negative cache permanently
      (Mon Aug 14 17:31:54 2017) [sssd[nss]] [sss_parse_name_for_domains] (0x0200): name
'bar' matched without domain, user is bar
      (Mon Aug 14 17:31:54 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/GROUP/indirect.ipa.ff/bar(a)indirect.ipa.ff] to negative cache permanently
      (Mon Aug 14 17:31:54 2017) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain
indirect.ad.ff is Active
      (Mon Aug 14 17:31:54 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/GROUP/indirect.ad.ff/bar(a)indirect.ad.ff] to negative cache permanently
      ```
- **CACHE_REQ: Don't error out when searching by id = 0**:
  - With the very same environment, just do:
    - `id root`;
    - Inspect the sssd_nss.log, taking a look after the first cache req request;
      - Without this patch:
        ```
        (Mon Aug 14 19:21:59 2017) [sssd[nss]] [sss_domain_get_state] (0x1000): Domain
indirect.ad.ff is Active
        (Mon Aug 14 19:21:59 2017) [sssd[nss]] [nss_protocol_done] (0x4000): Sending
reply: not found
        (Mon Aug 14 19:21:59 2017) [sssd[nss]] [nss_getby_id] (0x0400): Input ID: 0
        (Mon Aug 14 19:21:59 2017) [sssd[nss]] [cache_req_data_create] (0x0020): Bug: id
cannot be 0!
        (Mon Aug 14 19:21:59 2017) [sssd[nss]] [cache_req_data_create] (0x0020): Unable to
create cache_req data [1432158209]: Internal Error
        (Mon Aug 14 19:21:59 2017) [sssd[nss]] [nss_getby_id] (0x0020): Unable to set
cache request data!
        (Mon Aug 14 19:21:59 2017) [sssd[nss]] [nss_protocol_done] (0x4000): Sending
reply: error [12]: Cannot allocate memory
        ```
      - With this patch:
        ```
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [nss_getby_id] (0x0400): Input ID: 0
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #1:
Setting "User by ID" plugin
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_send] (0x0400): CR #1: New
request 'User by ID'
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #1:
Performing a multi-domain search
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #1:
Search will check the cache and check the data provider
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_validate_domain_type] (0x2000):
Request type POSIX-only for domain indirect.ipa.ff type POSIX is valid
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #1:
Using domain [indirect.ipa.ff]
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_send] (0x0400): CR #1:
Looking up UID:[e-mail]
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
Checking negative cache for [UID:[e-mail]]
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking
negative cache for [NCE/UID/0]
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
[UID:[e-mail]] is not present in negative cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #1:
Looking up [UID:[e-mail]] in cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x252fa20
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x2532bc0
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [ldb] (0x4000): Running timer event
0x252fa20 "ltdb_callback"
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [ldb] (0x4000): Destroying timer event
0x2532bc0 "ltdb_timeout"
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [ldb] (0x4000): Ending timer event
0x252fa20 "ltdb_callback"
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #1:
Object [UID:[e-mail]] was not found in cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #1:
Looking up [UID:[e-mail]] in data provider
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing
request for [0x416030:1:*@indirect.ipa.ff]
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating
request for [indirect.ipa.ff][0x1][BE_REQ_USER][*:-]
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x252a330
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sss_dp_internal_get_send] (0x0400):
Entering request [0x416030:1:*@indirect.ipa.ff]
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x252a330
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sbus_dispatch] (0x4000): dbus conn:
0x25238c0
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sbus_dispatch] (0x4000): Dispatching.
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from
Data Provider - DP error code: 0 errno: 0 error message: Success
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #1:
Looking up [UID:[e-mail]] in cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x252f960
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x2534150
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [ldb] (0x4000): Running timer event
0x252f960 "ltdb_callback"
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [ldb] (0x4000): Destroying timer event
0x2534150 "ltdb_timeout"
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [ldb] (0x4000): Ending timer event
0x252f960 "ltdb_callback"
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #1:
Object [UID:[e-mail]] was not found in cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_ncache_add] (0x2000): CR
#1: This request type does not support negative cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_global_ncache_add] (0x0400): CR
#1: Adding [UID:[e-mail]] to global negative cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/UID/0] to negative cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_process_result] (0x0400): CR #1:
Finished: Not found
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [memcache_delete_entry] (0x0040): Bug:
invalid input!
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [nss_protocol_done] (0x4000): Sending
reply: not found
        ```

- **NSS: Don't error out when deleting an entry which has id = 0 from the
memcache**:
  - Considering the very same environment, just do:
    - `id root`;
    - Inspect sssd_nss.log, looking for "Bug: invalid input!" from
memcache_delete_entry;
      - Without this patch:
        ```
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #1:
Object [UID:[e-mail]] was not found in cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_ncache_add] (0x2000): CR
#1: This request type does not support negative cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_global_ncache_add] (0x0400): CR
#1: Adding [UID:[e-mail]] to global negative cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/UID/0] to negative cache
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_process_result] (0x0400): CR #1:
Finished: Not found
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [memcache_delete_entry] (0x0040): Bug:
invalid input!
        (Mon Aug 14 19:26:11 2017) [sssd[nss]] [nss_protocol_done] (0x4000): Sending
reply: not found
        ```
      - With this patch:
        ```
        (Mon Aug 14 19:34:08 2017) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #1:
Object [UID:[e-mail]] was not found in cache
        (Mon Aug 14 19:34:08 2017) [sssd[nss]] [cache_req_search_ncache_add] (0x2000): CR
#1: This request type does not support negative cache
        (Mon Aug 14 19:34:08 2017) [sssd[nss]] [cache_req_global_ncache_add] (0x0400): CR
#1: Adding [UID:[e-mail]] to global negative cache
        (Mon Aug 14 19:34:08 2017) [sssd[nss]] [sss_ncache_set_str] (0x0400): Adding
[NCE/UID/0] to negative cache
        (Mon Aug 14 19:34:08 2017) [sssd[nss]] [cache_req_process_result] (0x0400): CR #1:
Finished: Not found
        (Mon Aug 14 19:34:08 2017) [sssd[nss]] [nss_protocol_done] (0x4000): Sending
reply: not found
        ```

- **NEGCACHE: Add root's uid/gid to ncache**:
  - Considering the very same environment, just do:
    - `id root`;
    - Inspect sssd_nss.log, looking for a lookup in the data provider;
      - Without this patch:
        ```
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [nss_getby_id] (0x0400): Input ID: 0
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #1:
Setting "User by ID" plugin
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_send] (0x0400): CR #1: New
request 'User by ID'
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #1:
Performing a multi-domain search
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #1:
Search will check the cache and check the data provider
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_validate_domain_type] (0x2000):
Request type POSIX-only for domain indirect.ipa.ff type POSIX is valid
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #1:
Using domain [indirect.ipa.ff]
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_search_send] (0x0400): CR #1:
Looking up UID:[e-mail]
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
Checking negative cache for [UID:[e-mail]]
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking
negative cache for [NCE/UID/0]
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
[UID:[e-mail]] is not present in negative cache
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #1:
Looking up [UID:[e-mail]] in cache
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [ldb] (0x4000): Added timed event
"ltdb_callback": 0x82b230
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [ldb] (0x4000): Added timed event
"ltdb_timeout": 0x825100
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [ldb] (0x4000): Running timer event
0x82b230 "ltdb_callback"
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [ldb] (0x4000): Destroying timer event
0x825100 "ltdb_timeout"
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [ldb] (0x4000): Ending timer event 0x82b230
"ltdb_callback"
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #1:
Object [UID:[e-mail]] was not found in cache
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #1:
Looking up [UID:[e-mail]] in data provider
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing
request for [0x415ff0:1:*@indirect.ipa.ff]
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating
request for [indirect.ipa.ff][0x1][BE_REQ_USER][*:-]
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x825330
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [sss_dp_internal_get_send] (0x0400):
Entering request [0x415ff0:1:*@indirect.ipa.ff]
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x825330
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [sbus_dispatch] (0x4000): dbus conn:
0x81e8c0
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [sbus_dispatch] (0x4000): Dispatching.
        (Mon Aug 14 19:39:17 2017) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from
Data Provider - DP error code: 0 errno: 0 error message: Success
        ```
      - With this patch:
        ```
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [nss_getby_id] (0x0400): Input ID: 0
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_set_plugin] (0x2000): CR #1:
Setting "User by ID" plugin
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_send] (0x0400): CR #1: New
request 'User by ID'
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #1:
Performing a multi-domain search
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #1:
Search will check the cache and check the data provider
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_validate_domain_type] (0x2000):
Request type POSIX-only for domain indirect.ipa.ff type POSIX is valid
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #1:
Using domain [indirect.ipa.ff]
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_search_send] (0x0400): CR #1:
Looking up UID:[e-mail]
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
Checking negative cache for [UID:[e-mail]]
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking
negative cache for [NCE/UID/0]
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
[UID:[e-mail]] does not exist (negative cache)
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_validate_domain_type] (0x2000):
Request type POSIX-only for domain indirect.ad.ff type POSIX is valid
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #1:
Using domain [indirect.ad.ff]
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_search_send] (0x0400): CR #1:
Looking up UID:[e-mail]
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
Checking negative cache for [UID:[e-mail]]
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking
negative cache for [NCE/UID/0]
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
[UID:[e-mail]] does not exist (negative cache)
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_process_result] (0x0400): CR #1:
Finished: Not found
        (Mon Aug 14 19:41:29 2017) [sssd[nss]] [nss_protocol_done] (0x4000): Sending
reply: not found
        ```




"""

To pull the PR as Git branch:
git remote add ghsssd https://github.com/SSSD/sssd
git fetch ghsssd pull/347/head:pr347
git checkout pr347