In a Fedora 27 FreeIPA-4.6 domain with the following sssd.conf, I regularly get the followin error:
sssd_nss[2603]: The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal]
Increasing the sssd debug level reveals that the fatal error seems to be raised by the lookup in the implicit_files domain which doesn't contain this GID.
While this happens on all my FreeIPA clients, this particular host is a mailserver postfix and cyrus-imap with saslsuthd/pam authentication so the number of user lookups is far higher and the error occurs with considerable frequency.
Do I have a misconfiguration here or is there a problem with implicit_domain and GID lookups? It doesn't seem like this should be a fatal error when the GID exists in the example.com FreeIPA/SSSD domain.
# /etc/nsswitch.conf (snippet) passwd: sss files mymachines systemd shadow: files sss group: sss files mymachines systemd
# /etc/sssd/sssd.conf [domain/example.com] cache_credentials = True krb5_store_password_if_offline = True ipa_domain = example.com id_provider = ipa auth_provider = ipa access_provider = ipa ipa_hostname = host.example.com chpass_provider = ipa ipa_server = _srv_, ipa-master.ipa.example.com ldap_tls_cacert = /etc/ipa/ca.crt [sssd] services = nss, sudo, pam, ssh, ifp
domains = example.com [nss] homedir_substring = /home
[pam]
[sudo]
[autofs]
[ssh]
[pac]
[ifp] allowed_uids = apache, root
[secrets]
# Relevant sssd_nss debug logs Jan 30 18:22:48 sssd_nss[2603]: Input ID: 1111100001 Jan 30 18:22:48 sssd_nss[2603]: CR #134773: New request 'Group by ID' Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Performing a multi-domain search Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Search will check the cache and check the data provider Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Using domain [implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up GID:1111100001@implicit_files Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Checking negative cache for [GID:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: [GID:1111100001@implicit_files] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in data provider Jan 30 18:22:48 sssd_nss[2603]: Issuing request for [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: Creating request for [implicit_files][0x2][BE_REQ_GROUP][idnumber=1111100001:-] Jan 30 18:22:48 sssd_nss[2603]: Entering request [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: Input ID: 1111100001 Jan 30 18:22:48 sssd_nss[2603]: CR #134774: New request 'Group by ID' Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Performing a multi-domain search Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Search will check the cache and check the data provider Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Using domain [implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up GID:1111100001@implicit_files Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Checking negative cache for [GID:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: [GID:1111100001@implicit_files] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@implicit_files] in data provider Jan 30 18:22:48 sssd_nss[2603]: Issuing request for [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: Identical request in progress: [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Data Provider Error: 3, 5, Failed to get reply from Data Provider Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Due to an error we will return cached data Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Using domain [example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up GID:1111100001@example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Checking negative cache for [GID:1111100001@example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: [GID:1111100001@example.com] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@example.com] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Returning [GID:1111100001@example.com] from cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Filtering out results by negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Data Provider Error: 3, 5, Failed to get reply from Data Provider Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Due to an error we will return cached data Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Using domain [example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up GID:1111100001@example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Checking negative cache for [GID:1111100001@example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: [GID:1111100001@example.com] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@example.com] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Returning [GID:1111100001@example.com] from cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Filtering out results by negative cache Jan 30 18:22:48 sssd_nss[2603]: Deleting request: [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Found 1 entries in domain example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Found 1 entries in domain example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Finished: Success Jan 30 18:22:48 sssd_nss[2603]: Domain example.com is Active Jan 30 18:22:48 sssd_nss[2603]: Domain implicit_files is Active Jan 30 18:22:48 sssd_nss[2603]: Domain example.com is Active Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Finished: Success
On Wed, Jan 31, 2018 at 12:32:28PM -0600, Anthony Joseph Messina wrote:
In a Fedora 27 FreeIPA-4.6 domain with the following sssd.conf, I regularly get the followin error:
sssd_nss[2603]: The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal]
Increasing the sssd debug level reveals that the fatal error seems to be raised by the lookup in the implicit_files domain which doesn't contain this GID.
While this happens on all my FreeIPA clients, this particular host is a mailserver postfix and cyrus-imap with saslsuthd/pam authentication so the number of user lookups is far higher and the error occurs with considerable frequency.
Do I have a misconfiguration here or is there a problem with implicit_domain and GID lookups? It doesn't seem like this should be a fatal error when the GID exists in the example.com FreeIPA/SSSD domain.
# /etc/nsswitch.conf (snippet) passwd: sss files mymachines systemd shadow: files sss group: sss files mymachines systemd
# /etc/sssd/sssd.conf [domain/example.com] cache_credentials = True krb5_store_password_if_offline = True ipa_domain = example.com id_provider = ipa auth_provider = ipa access_provider = ipa ipa_hostname = host.example.com chpass_provider = ipa ipa_server = _srv_, ipa-master.ipa.example.com ldap_tls_cacert = /etc/ipa/ca.crt [sssd] services = nss, sudo, pam, ssh, ifp
domains = example.com [nss] homedir_substring = /home
[pam]
[sudo]
[autofs]
[ssh]
[pac]
[ifp] allowed_uids = apache, root
[secrets]
# Relevant sssd_nss debug logs Jan 30 18:22:48 sssd_nss[2603]: Input ID: 1111100001 Jan 30 18:22:48 sssd_nss[2603]: CR #134773: New request 'Group by ID' Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Performing a multi-domain search Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Search will check the cache and check the data provider Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Using domain [implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up GID:1111100001@implicit_files Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Checking negative cache for [GID:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: [GID:1111100001@implicit_files] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in data provider Jan 30 18:22:48 sssd_nss[2603]: Issuing request for [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: Creating request for [implicit_files][0x2][BE_REQ_GROUP][idnumber=1111100001:-] Jan 30 18:22:48 sssd_nss[2603]: Entering request [0x56200cc04250:2:1111100001@implicit_files]
I think it's probably https://pagure.io/SSSD/sssd/issue/3520. In general the files provider shouldn't be calling the Data Provider at all, because all users should be always cached.
Could you open a bug against Fedora so we can link it with the upstream ticket and you can test the fix when it's ready?
btw the implicit files domain can be disabled, I think that would be the best workaround in the meantime.
Jan 30 18:22:48 sssd_nss[2603]: Input ID: 1111100001 Jan 30 18:22:48 sssd_nss[2603]: CR #134774: New request 'Group by ID' Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Performing a multi-domain search Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Search will check the cache and check the data provider Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Using domain [implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up GID:1111100001@implicit_files Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Checking negative cache for [GID:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: [GID:1111100001@implicit_files] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@implicit_files] in data provider Jan 30 18:22:48 sssd_nss[2603]: Issuing request for [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: Identical request in progress: [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Data Provider Error: 3, 5, Failed to get reply from Data Provider Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Due to an error we will return cached data Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Using domain [example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up GID:1111100001@example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Checking negative cache for [GID:1111100001@example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: [GID:1111100001@example.com] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@example.com] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Returning [GID:1111100001@example.com] from cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Filtering out results by negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Data Provider Error: 3, 5, Failed to get reply from Data Provider Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Due to an error we will return cached data Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Using domain [example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up GID:1111100001@example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Checking negative cache for [GID:1111100001@example.com] Jan 30 18:22:48 sssd_nss[2603]: CR #134774: [GID:1111100001@example.com] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Looking up [GID:1111100001@example.com] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Returning [GID:1111100001@example.com] from cache Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Filtering out results by negative cache Jan 30 18:22:48 sssd_nss[2603]: Deleting request: [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Found 1 entries in domain example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Found 1 entries in domain example.com Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Finished: Success Jan 30 18:22:48 sssd_nss[2603]: Domain example.com is Active Jan 30 18:22:48 sssd_nss[2603]: Domain implicit_files is Active Jan 30 18:22:48 sssd_nss[2603]: Domain example.com is Active Jan 30 18:22:48 sssd_nss[2603]: CR #134774: Finished: Success
-- Anthony - https://messinet.com/ - https://messinet.com/~amessina/gallery F9B6 560E 68EA 037D 8C3D D1C9 FF31 3BDB D9D8 99B6
sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
On Wednesday, January 31, 2018 1:45:27 PM CST Jakub Hrozek wrote:
On Wed, Jan 31, 2018 at 12:32:28PM -0600, Anthony Joseph Messina wrote:
In a Fedora 27 FreeIPA-4.6 domain with the following sssd.conf, I regularly get the followin error:
sssd_nss[2603]: The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal]
Increasing the sssd debug level reveals that the fatal error seems to be raised by the lookup in the implicit_files domain which doesn't contain this GID.
While this happens on all my FreeIPA clients, this particular host is a mailserver postfix and cyrus-imap with saslsuthd/pam authentication so the number of user lookups is far higher and the error occurs with considerable frequency.
Do I have a misconfiguration here or is there a problem with implicit_domain and GID lookups? It doesn't seem like this should be a fatal error when the GID exists in the example.com FreeIPA/SSSD domain.
# /etc/nsswitch.conf (snippet) passwd: sss files mymachines systemd shadow: files sss group: sss files mymachines systemd
# /etc/sssd/sssd.conf [domain/example.com] cache_credentials = True krb5_store_password_if_offline = True ipa_domain = example.com id_provider = ipa auth_provider = ipa access_provider = ipa ipa_hostname = host.example.com chpass_provider = ipa ipa_server = _srv_, ipa-master.ipa.example.com ldap_tls_cacert = /etc/ipa/ca.crt [sssd] services = nss, sudo, pam, ssh, ifp
domains = example.com [nss] homedir_substring = /home
[pam]
[sudo]
[autofs]
[ssh]
[pac]
[ifp] allowed_uids = apache, root
[secrets]
# Relevant sssd_nss debug logs Jan 30 18:22:48 sssd_nss[2603]: Input ID: 1111100001 Jan 30 18:22:48 sssd_nss[2603]: CR #134773: New request 'Group by ID' Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Performing a multi-domain search Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Search will check the cache and check the data provider Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Using domain [implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up GID:1111100001@implicit_files Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Checking negative cache for [GID:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: [GID:1111100001@implicit_files] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in data provider Jan 30 18:22:48 sssd_nss[2603]: Issuing request for [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: Creating request for [implicit_files][0x2][BE_REQ_GROUP][idnumber=1111100001:-] Jan 30 18:22:48 sssd_nss[2603]: Entering request [0x56200cc04250:2:1111100001@implicit_files]
I think it's probably https://pagure.io/SSSD/sssd/issue/3520. In general the files provider shouldn't be calling the Data Provider at all, because all users should be always cached.
Could you open a bug against Fedora so we can link it with the upstream ticket and you can test the fix when it's ready?
Fedora Bug filed: https://bugzilla.redhat.com/show_bug.cgi?id=1540703
btw the implicit files domain can be disabled, I think that would be the best workaround in the meantime.
Thanks Jakub. If I disable the implicit_files domain, I need to revert the nsswitch configuration to list files before sss, correct?
On Wed, Jan 31, 2018 at 01:56:56PM -0600, Anthony Joseph Messina wrote:
On Wednesday, January 31, 2018 1:45:27 PM CST Jakub Hrozek wrote:
On Wed, Jan 31, 2018 at 12:32:28PM -0600, Anthony Joseph Messina wrote:
In a Fedora 27 FreeIPA-4.6 domain with the following sssd.conf, I regularly get the followin error:
sssd_nss[2603]: The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal]
Increasing the sssd debug level reveals that the fatal error seems to be raised by the lookup in the implicit_files domain which doesn't contain this GID.
While this happens on all my FreeIPA clients, this particular host is a mailserver postfix and cyrus-imap with saslsuthd/pam authentication so the number of user lookups is far higher and the error occurs with considerable frequency.
Do I have a misconfiguration here or is there a problem with implicit_domain and GID lookups? It doesn't seem like this should be a fatal error when the GID exists in the example.com FreeIPA/SSSD domain.
# /etc/nsswitch.conf (snippet) passwd: sss files mymachines systemd shadow: files sss group: sss files mymachines systemd
# /etc/sssd/sssd.conf [domain/example.com] cache_credentials = True krb5_store_password_if_offline = True ipa_domain = example.com id_provider = ipa auth_provider = ipa access_provider = ipa ipa_hostname = host.example.com chpass_provider = ipa ipa_server = _srv_, ipa-master.ipa.example.com ldap_tls_cacert = /etc/ipa/ca.crt [sssd] services = nss, sudo, pam, ssh, ifp
domains = example.com [nss] homedir_substring = /home
[pam]
[sudo]
[autofs]
[ssh]
[pac]
[ifp] allowed_uids = apache, root
[secrets]
# Relevant sssd_nss debug logs Jan 30 18:22:48 sssd_nss[2603]: Input ID: 1111100001 Jan 30 18:22:48 sssd_nss[2603]: CR #134773: New request 'Group by ID' Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Performing a multi-domain search Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Search will check the cache and check the data provider Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Using domain [implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up GID:1111100001@implicit_files Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Checking negative cache for [GID:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: CR #134773: [GID:1111100001@implicit_files] is not present in negative cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Object [GID:1111100001@implicit_files] was not found in cache Jan 30 18:22:48 sssd_nss[2603]: CR #134773: Looking up [GID:1111100001@implicit_files] in data provider Jan 30 18:22:48 sssd_nss[2603]: Issuing request for [0x56200cc04250:2:1111100001@implicit_files] Jan 30 18:22:48 sssd_nss[2603]: Creating request for [implicit_files][0x2][BE_REQ_GROUP][idnumber=1111100001:-] Jan 30 18:22:48 sssd_nss[2603]: Entering request [0x56200cc04250:2:1111100001@implicit_files]
I think it's probably https://pagure.io/SSSD/sssd/issue/3520. In general the files provider shouldn't be calling the Data Provider at all, because all users should be always cached.
Could you open a bug against Fedora so we can link it with the upstream ticket and you can test the fix when it's ready?
Fedora Bug filed: https://bugzilla.redhat.com/show_bug.cgi?id=1540703
Thanks, linked to the upstream bug.
btw the implicit files domain can be disabled, I think that would be the best workaround in the meantime.
Thanks Jakub. If I disable the implicit_files domain, I need to revert the nsswitch configuration to list files before sss, correct?
You don't need to, but you should, because without the files domain, every program falls back from libnss_sss to libsss_files at least once per runtime and without the files domain there is no benefit anymore in having the sss module precede the files module.
sssd-users@lists.fedorahosted.org