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:0@indirect.ipa.ff@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=0@indirect.ipa.ff:-]
(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:0@indirect.ipa.ff@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:0@indirect.ipa.ff
(Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
Checking negative cache for [UID:0@indirect.ipa.ff]
(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:0@indirect.ipa.ff] 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:0@indirect.ipa.ff] 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:0@indirect.ipa.ff] was not found in cache
(Mon Aug 14 19:26:11 2017) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #1:
Looking up [UID:0@indirect.ipa.ff] 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:0@indirect.ad.ff] 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:0@indirect.ad.ff] 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:0@indirect.ad.ff] 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:0@indirect.ad.ff] 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:0@indirect.ad.ff] 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:0@indirect.ad.ff] 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:0@indirect.ad.ff] 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:0@indirect.ipa.ff
(Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
Checking negative cache for [UID:0@indirect.ipa.ff]
(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:0@indirect.ipa.ff] 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:0@indirect.ipa.ff] 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:0@indirect.ipa.ff] was not found in cache
(Mon Aug 14 19:39:17 2017) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #1:
Looking up [UID:0@indirect.ipa.ff] 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:0@indirect.ipa.ff
(Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
Checking negative cache for [UID:0@indirect.ipa.ff]
(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:0@indirect.ipa.ff] 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:0@indirect.ad.ff
(Mon Aug 14 19:41:29 2017) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #1:
Checking negative cache for [UID:0@indirect.ad.ff]
(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:0@indirect.ad.ff] 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