Bug 1540703 - FreeIPA/SSSD implicit_file sssd_nss error: The Data Provider returned an error [org.freedesktop.sssd.Error.DataProvider.Fatal]
Summary: FreeIPA/SSSD implicit_file sssd_nss error: The Data Provider returned an erro...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: sssd
Version: 27
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: ---
Assignee: Jakub Hrozek
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-01-31 19:50 UTC by Anthony Messina
Modified: 2018-05-01 13:41 UTC (History)
11 users (show)

Fixed In Version: sssd-1.16.1-3.fc28 sssd-1.16.1-3.fc26 sssd-1.16.1-3.fc27
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-05-01 07:42:53 UTC


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
FedoraHosted SSSD 3520 None None None 2018-01-31 19:50:36 UTC

Description Anthony Messina 2018-01-31 19:50:36 UTC
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

Comment 1 Jakub Hrozek 2018-01-31 20:16:21 UTC
Upstream ticket:
https://pagure.io/SSSD/sssd/issue/3520

Comment 2 Fabiano Fidêncio 2018-04-27 12:04:33 UTC
master:
 d69e1da
 1f8bfb6
 81f1699
 c1bce7d
 77d63f5

Comment 3 Fedora Update System 2018-04-27 21:02:36 UTC
sssd-1.16.1-3.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2018-e0662375ce

Comment 4 Fedora Update System 2018-04-27 21:03:27 UTC
sssd-1.16.1-3.fc26 has been submitted as an update to Fedora 26. https://bodhi.fedoraproject.org/updates/FEDORA-2018-33ce52aa2d

Comment 5 Fedora Update System 2018-04-27 21:09:00 UTC
sssd-1.16.1-3.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2018-2f11593fb0

Comment 6 Fedora Update System 2018-04-29 09:41:25 UTC
sssd-1.16.1-3.fc28 has been pushed to the Fedora 28 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-e0662375ce

Comment 7 Fedora Update System 2018-04-29 14:29:25 UTC
sssd-1.16.1-3.fc27 has been pushed to the Fedora 27 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-2f11593fb0

Comment 8 Fedora Update System 2018-05-01 07:42:53 UTC
sssd-1.16.1-3.fc28 has been pushed to the Fedora 28 stable repository. If problems still persist, please make note of it in this bug report.

Comment 9 Fedora Update System 2018-05-01 13:18:20 UTC
sssd-1.16.1-3.fc26 has been pushed to the Fedora 26 stable repository. If problems still persist, please make note of it in this bug report.

Comment 10 Fedora Update System 2018-05-01 13:41:26 UTC
sssd-1.16.1-3.fc27 has been pushed to the Fedora 27 stable repository. If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.