On 22 August 2017 at 08:33, Lachlan Musicman <datakid@gmail.com> wrote:
On 22 August 2017 at 00:46, Jakub Hrozek <jhrozek@redhat.com> wrote:
On Mon, Aug 21, 2017 at 10:24:50AM +1000, Lachlan Musicman wrote:
> On 18 August 2017 at 17:33, Jakub Hrozek <jhrozek@redhat.com> wrote:
>
> Hmmm. Weird. We are still seeing the "AD group not reflected in cache"
> problem and am not seeing evidence of SSSD updating from the IPA server on
> request (via login from other machine, via id command).



Just to follow up on this, I've done a comparative test.

On a machine in which <user> comes up correctly (all groups, properly over-written by ipa's idview) and one in which the same <user> does not. Note that both machines are on the same network, run the same OS and SSSD versions.

When I run the following on both servers:

sss_cache -u <user>
'id <user>’

On the sssd client that returns the correct data, sssd_<domain>.log shows:

....
(Tue Aug 22 13:13:17 2017) [sssd[be[sub.domain.com]]] [sss_domain_get_state] (0x1000): Domain sub.domain.com is Active
(Tue Aug 22 13:13:17 2017) [sssd[be[sub.domain.com]]] [sss_domain_get_state] (0x1000): Domain sub.domain.com is Active
(Tue Aug 22 13:13:17 2017) [sssd[be[sub.domain.com]]] [sysdb_set_entry_attr] (0x0200): Entry [name=<user>,cn=users,cn=domain.com,cn=sysdb] has set [ts_cache] attrs.
(Tue Aug 22 13:13:17 2017) [sssd[be[sub.domain.com]]] [dp_req_done] (0x0400): DP Request [Account #5760]: Request handler finished [0]: Success
(Tue Aug 22 13:13:17 2017) [sssd[be[sub.domain.com]]] [_dp_req_recv] (0x0400): DP Request [Account #5760]: Receiving request data.
....


On the sssd client which does *not* return the correct data, sssd_<domain>.log shows:

....
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [sss_domain_get_state] (0x1000): Domain sub.domain.com is Active
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [sss_domain_get_state] (0x1000): Domain sub.domain.com is Active
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [sysdb_set_cache_entry_attr] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait: No such object (32)]
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [sysdb_set_cache_entry_attr] (0x0400): No such entry
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [sysdb_set_entry_attr] (0x0080): Cannot set attrs for name=<user>,cn=users,cn=domain.com,cn=sysdb, 2 [No such file or directory]
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [sysdb_store_user] (0x0040): Cache update failed: 2
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [sysdb_store_user] (0x0400): Error: 2 (No such file or directory)
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [ipa_s2n_save_objects] (0x0040): sysdb_store_user failed [2]: No such file or directory
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [ipa_s2n_get_user_done] (0x0040): ipa_s2n_save_objects failed.
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [dp_req_done] (0x0400): DP Request [Account #400]: Request handler finished [0]: Success
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [_dp_req_recv] (0x0400): DP Request [Account #400]: Receiving request data.
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #400]: Finished. Success.
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [dp_req_reply_std] (0x1000): DP Request [Account #400]: Returning [Success]: 0,0,Success
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:1::domain.com:name=<user>] from reply table
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [dp_req_destructor] (0x0400): DP Request [Account #400]: Request removed.
(Tue Aug 22 12:54:25 2017) [sssd[be[sub.domain.com]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
....


The difference is

[sysdb_set_cache_entry_attr] (0x0080): ldb_modify failed: [No such object](32)[ldb_wait: No such object (32)]

What is that? Why is that failing?

Is it because <user> is already cached against the AD UID instead of the IPA UID so the command isn't finding <user> in the ldb?

Cheers
L.