#2877 LDAP ID provider corrupts db-cache and causes sssd to fail on restart
Closed: Invalid None Opened 8 years ago by nandersson.

Problem surfaces when sudo_provider = ldap is enabled in sssd.conf. When commented out it works.

First run works, but when sssd is stopped and then restarted the process fails. And in the error logs there is a "[sssm_ldap_sudo_init] (0x0020): Cannot init LDAP ID provider [5]: Input/output error".

When I delete /var/lib/sss/db/cache_openforce.org.ldb I am able to start the service again, but once again when the service is restarted it breaks.


Trace (-d 9) of the first run that works.
1-first-run-this-works

2:nd run after the process is restarted. Trace with -d 9
2-second-run-after-sssd-restart-this-breaks

The probably corrupt database file that includes the breaking issue.
cache_openforce.org.ldb

This is the sssd.conf

[sssd]
domains = openforce.org
config_file_version = 2
services = nss, pam, ssh, sudo
#reconnection_retries = 7

[ssh]

[sudo]
debug_level = 4

[pam]
offline_credentials_expiration = 60
pam_pwd_expiration_warning = 14

[nss]
#filter_groups = root
#filter_users = root

[domain/openforce.org]
id_provider = ad
#auth_provider = ad
#chpass_provider = ad
#access_provider = permit
sudo_provider = ldap
ignore_group_members = true
#enumerature = false
dyndns_update = false
use_fully_qualified_names = False
lookup_family_order = ipv4_only
cache_credentials = True
fallback_homedir = /home/%u
create_homedir = True
override_shell = /bin/bash
#
# Sudo
#
ldap_uri = ldap://srv11.openforce.org
ldap_sudo_search_base = ou=SUDOers,dc=openforce,dc=org
ldap_default_bind_dn = cn=admin,dc=openforce,dc=org
ldap_default_authtok = Abc123!
#debug_level = 5

_comment0: This is the sssd.conf

[sssd]
domains = openforce.org
config_file_version = 2
services = nss, pam, ssh, sudo

reconnection_retries = 7

[ssh]

[sudo]
debug_level = 4

[pam]
offline_credentials_expiration = 60
pam_pwd_expiration_warning = 14

[nss]

filter_groups = root

filter_users = root

[domain/openforce.org]
id_provider = ad

auth_provider = ad

chpass_provider = ad

access_provider = permit

sudo_provider = ldap
ignore_group_members = true

enumerature = false

dyndns_update = false
use_fully_qualified_names = False
lookup_family_order = ipv4_only
cache_credentials = True
fallback_homedir = /home/%u
create_homedir = True
override_shell = /bin/bash

Sudo

ldap_uri = ldap://srv11.openforce.org
ldap_sudo_search_base = ou=SUDOers,dc=openforce,dc=org
ldap_default_bind_dn = cn=admin,dc=openforce,dc=org
ldap_default_authtok = Abc123!

debug_level = 5

=> 1448015919523259

I had a check on the corrupt cache-file with tdbdump, and it is clear that the sudo-rules are fetched from the ldap-database and then stored in cache.

So, it looks like the problem might arise when the rules are then fetched from the cache on the 2:nd run, or with the sync between the cache and the ldap-storage.

It's not a database corruption, it's something with ID mapping. I was unable to reproduce the issue locally against AD 2012R2. You're using Samba, though, right?

Would using:

sudo_provider=ad

fix the issue for you? You'd drop the last section completely, then.

Alternatively, would it help if you added the domain SID with ldap_idmap_default_domain_sid explicitly?

I am using Samba4 instead of AD because it is easier to setup. In the corporate environment we have AD and I can't extend that schema to include Sudo-rules, so we must use a separate LDAP-database unfortunately.

I'll give ldap_idmap_default_domain_sid a look! Thanks!

Aaah, it's a separate LDAP tree. That might be the difference in my testing. Then I don't think it makes sense to add the default_domain_sid and I will run another test.

That is correct.

When I look at the cache-file it seems to me that the Sudo-rules aren't correct. They don't point to the original ldap-source. Seems that they now point to some internal database? :-/

Edit: (Well, after posting I realized that that might be the purpose for the cache. I.e that they now reference to the internal cache-file instead of being fetched? I see there is a key DN=@INDEX:ORIGINALDN:CN=DEFAULTS,OU=SUDOERS,DC=OPENFORCE,DC=ORG that indeed is correct)

DN=@INDEX:DATAEXPIRETIMESTAMP:1447948439
DN=@INDEX:NAME:openforce.org
DN=NAME=candersson,CN=USERS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@MODULES
DN=@INDEX:NAME:defaults
DN=@INDEX:OBJECTCLASS:USER
DN=@INDEX:ORIGINALDN:CN=CANDERSSON,CN=USERS,DC=OPENFORCE,DC=ORG
DN=NAME=nandersson,CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:@IDXONE:
DN=@INDEX:SUDOUSER:nandersson
DN=@INDEX:NAMEALIAS:candersson
DN=@INDEX:ORIGINALDN:CN=NANDERSSON,OU=SUDOERS,DC=OPENFORCE,DC=ORG
DN=@ATTRIBUTES
DN=CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:CN:NANDERSSON
DN=@INDEX:CN:USERS
DN=@INDEX:NAME:candersson
DN=CN=RANGES,CN=SYSDB
DN=CN=USERS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:@IDXONE:CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:CN:SUDORULES
DN=@INDEX:CN:SYSDB
DN=@INDEX:GIDNUMBER:700400513
DN=@INDEX:UIDNUMBER:700401104
DN=@INDEX:CN:GROUPS
DN=@BASEINFO
DN=@INDEX:@IDXONE:CN=USERS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:ORIGINALDN:CN=DEFAULTS,OU=SUDOERS,DC=OPENFORCE,DC=ORG
DN=@INDEX:OBJECTCLASS:ID_MAPPING
DN=@INDEX:SUDOUSER:candersson
DN=CN=GROUPS,CN=OPENFORCE.ORG,CN=SYSDB
DN=NAME=candersson,CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:ORIGINALDN:CN=CANDERSSON,OU=SUDOERS,DC=OPENFORCE,DC=ORG
DN=@INDEX:NAME:nandersson
DN=CN=SYSDB
DN=@INDEX:DATAEXPIRETIMESTAMP:1447948420
DN=@INDEX:@IDXONE:CN=ID_MAPPINGS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:LASTUPDATE:1447943039
DN=@INDEX:OBJECTCLASS:SUDORULE
DN=@INDEX:CN:RANGES
DN=@INDEX:@IDXONE:CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=NAME=defaults,CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:CN:OPENFORCE.ORG
DN=@INDEX:@IDXONE:CN=SYSDB
DN=@INDEX:CN:DEFAULTS
DN=@INDEX:CN:CANDERSSON
DN=@INDEXLIST
DN=CN=OPENFORCE.ORG,CN=SYSDB
DN=OBJECTSID=S-1-5-21-3065846811-936052125-3479462643,CN=ID_MAPPINGS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:@IDXONE:CN=OPENFORCE.ORG,CN=SYSDB

_comment0: That is correct.

When I look at the cache-file it seems to me that the Sudo-rules isn't correct. They don't point to the original ldap-source. Seems that they now point to some internal database? :-/

DN=@INDEX:DATAEXPIRETIMESTAMP:1447948439
DN=@INDEX:NAME:openforce.org
DN=NAME=candersson,CN=USERS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@MODULES
DN=@INDEX:NAME:defaults
DN=@INDEX:OBJECTCLASS:USER
DN=@INDEX:ORIGINALDN:CN=CANDERSSON,CN=USERS,DC=OPENFORCE,DC=ORG
DN=NAME=nandersson,CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:@IDXONE:
DN=@INDEX:SUDOUSER:nandersson
DN=@INDEX:NAMEALIAS:candersson
DN=@INDEX:ORIGINALDN:CN=NANDERSSON,OU=SUDOERS,DC=OPENFORCE,DC=ORG
DN=@ATTRIBUTES
DN=CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:CN:NANDERSSON
DN=@INDEX:CN:USERS
DN=@INDEX:NAME:candersson
DN=CN=RANGES,CN=SYSDB
DN=CN=USERS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:@IDXONE:CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:CN:SUDORULES
DN=@INDEX:CN:SYSDB
DN=@INDEX:GIDNUMBER:700400513
DN=@INDEX:UIDNUMBER:700401104
DN=@INDEX:CN:GROUPS
DN=@BASEINFO
DN=@INDEX:@IDXONE:CN=USERS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:ORIGINALDN:CN=DEFAULTS,OU=SUDOERS,DC=OPENFORCE,DC=ORG
DN=@INDEX:OBJECTCLASS:ID_MAPPING
DN=@INDEX:SUDOUSER:candersson
DN=CN=GROUPS,CN=OPENFORCE.ORG,CN=SYSDB
DN=NAME=candersson,CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:ORIGINALDN:CN=CANDERSSON,OU=SUDOERS,DC=OPENFORCE,DC=ORG
DN=@INDEX:NAME:nandersson
DN=CN=SYSDB
DN=@INDEX:DATAEXPIRETIMESTAMP:1447948420
DN=@INDEX:@IDXONE:CN=ID_MAPPINGS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:LASTUPDATE:1447943039
DN=@INDEX:OBJECTCLASS:SUDORULE
DN=@INDEX:CN:RANGES
DN=@INDEX:@IDXONE:CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=NAME=defaults,CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:CN:OPENFORCE.ORG
DN=@INDEX:@IDXONE:CN=SYSDB
DN=@INDEX:CN:DEFAULTS
DN=@INDEX:CN:CANDERSSON
DN=@INDEXLIST
DN=CN=OPENFORCE.ORG,CN=SYSDB
DN=OBJECTSID=S-1-5-21-3065846811-936052125-3479462643,CN=ID_MAPPINGS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:@IDXONE:CN=OPENFORCE.ORG,CN=SYSDB
=> 1448028967295553
_comment1: That is correct.

When I look at the cache-file it seems to me that the Sudo-rules aren't correct. They don't point to the original ldap-source. Seems that they now point to some internal database? :-/

Edit: (Well, after posting I realized that that might be the purpose for the cache. I.e that they now reference to the internal cache-file instead of being fetched?)

DN=@INDEX:DATAEXPIRETIMESTAMP:1447948439
DN=@INDEX:NAME:openforce.org
DN=NAME=candersson,CN=USERS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@MODULES
DN=@INDEX:NAME:defaults
DN=@INDEX:OBJECTCLASS:USER
DN=@INDEX:ORIGINALDN:CN=CANDERSSON,CN=USERS,DC=OPENFORCE,DC=ORG
DN=NAME=nandersson,CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:@IDXONE:
DN=@INDEX:SUDOUSER:nandersson
DN=@INDEX:NAMEALIAS:candersson
DN=@INDEX:ORIGINALDN:CN=NANDERSSON,OU=SUDOERS,DC=OPENFORCE,DC=ORG
DN=@ATTRIBUTES
DN=CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:CN:NANDERSSON
DN=@INDEX:CN:USERS
DN=@INDEX:NAME:candersson
DN=CN=RANGES,CN=SYSDB
DN=CN=USERS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:@IDXONE:CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:CN:SUDORULES
DN=@INDEX:CN:SYSDB
DN=@INDEX:GIDNUMBER:700400513
DN=@INDEX:UIDNUMBER:700401104
DN=@INDEX:CN:GROUPS
DN=@BASEINFO
DN=@INDEX:@IDXONE:CN=USERS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:ORIGINALDN:CN=DEFAULTS,OU=SUDOERS,DC=OPENFORCE,DC=ORG
DN=@INDEX:OBJECTCLASS:ID_MAPPING
DN=@INDEX:SUDOUSER:candersson
DN=CN=GROUPS,CN=OPENFORCE.ORG,CN=SYSDB
DN=NAME=candersson,CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:ORIGINALDN:CN=CANDERSSON,OU=SUDOERS,DC=OPENFORCE,DC=ORG
DN=@INDEX:NAME:nandersson
DN=CN=SYSDB
DN=@INDEX:DATAEXPIRETIMESTAMP:1447948420
DN=@INDEX:@IDXONE:CN=ID_MAPPINGS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:LASTUPDATE:1447943039
DN=@INDEX:OBJECTCLASS:SUDORULE
DN=@INDEX:CN:RANGES
DN=@INDEX:@IDXONE:CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=NAME=defaults,CN=SUDORULES,CN=CUSTOM,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:CN:OPENFORCE.ORG
DN=@INDEX:@IDXONE:CN=SYSDB
DN=@INDEX:CN:DEFAULTS
DN=@INDEX:CN:CANDERSSON
DN=@INDEXLIST
DN=CN=OPENFORCE.ORG,CN=SYSDB
DN=OBJECTSID=S-1-5-21-3065846811-936052125-3479462643,CN=ID_MAPPINGS,CN=OPENFORCE.ORG,CN=SYSDB
DN=@INDEX:@IDXONE:CN=OPENFORCE.ORG,CN=SYSDB
=> 1448029929813418

Hi,

I just thought of, that the problem might be that I am having the same basedn dc=openforce,dc=org in both Samba4 and in the 2:nd OpenLDAP?

Perhaps I should try and rename the LDAP-one and see if that might be the issue here?

Maybe, worth a shot.

About the cache dump, it's more convenient to use ldbsearch from the ldb-tools package than tdbdump. Your dump shows a lot of internal data (indexes) and in general there is no guarantee that the ldb database would be powered by tdb, especially in the future.

I changed the domain for the sudo server to a different TLD.

Same issue unfortunately :(

These are error messages from sssd_sudo

(Fri Nov 20 16:27:33 2015) [sssd[sudo]] [confdb_get_domain_internal] (0x0100): Setting domain password expiration warning to 14 days
(Fri Nov 20 16:27:33 2015) [sssd[sudo]] [monitor_common_send_id] (0x0100): Sending ID: (sudo,1)
(Fri Nov 20 16:27:33 2015) [sssd[sudo]] [sss_names_init_from_args] (0x0100): Using re [(((?P<domain>[^\]+)\(?P<name>.+$))|((?P<name>[^@]+)@(?P<domain>.+$))|(^(?P<name>[^@\]+)$))].
(Fri Nov 20 16:27:33 2015) [sssd[sudo]] [sss_fqnames_init] (0x0100): Using fq format [%1$s@%2$s].
(Fri Nov 20 16:27:33 2015) [sssd[sudo]] [dp_common_send_id] (0x0100): Sending ID to DP: (1,SUDO)
(Fri Nov 20 16:27:33 2015) [sssd[sudo]] [dp_id_callback] (0x0100): Got id ack and version (1) from DP
(Fri Nov 20 16:27:33 2015) [sssd[sudo]] [id_callback] (0x0100): Got id ack and version (1) from Monitor
(Fri Nov 20 16:27:44 2015) [sssd[sudo]] [confdb_get_domain_internal] (0x0100): Setting domain password expiration warning to 14 days
(Fri Nov 20 16:27:44 2015) [sssd[sudo]] [monitor_common_send_id] (0x0100): Sending ID: (sudo,1)
(Fri Nov 20 16:27:44 2015) [sssd[sudo]] [sss_names_init_from_args] (0x0100): Using re [(((?P<domain>[^\]+)\(?P<name>.+$))|((?P<name>[^@]+)@(?P<domain>.+$))|(^(?P<name>[^@\]+)$))].
(Fri Nov 20 16:27:44 2015) [sssd[sudo]] [sss_fqnames_init] (0x0100): Using fq format [%1$s@%2$s].
(Fri Nov 20 16:27:44 2015) [sssd[sudo]] [sbus_client_init] (0x0020): check_file failed for [/var/lib/sss/pipes/private/sbus-dp_openforce.org].
(Fri Nov 20 16:27:44 2015) [sssd[sudo]] [sss_dp_init] (0x0010): Failed to connect to monitor services.
(Fri Nov 20 16:27:44 2015) [sssd[sudo]] [sss_process_init] (0x0010): fatal error setting up backend connector
(Fri Nov 20 16:27:44 2015) [sssd[sudo]] [sudo_process_init] (0x0010): sss_process_init() failed

Seems to be a problem with /var/lib/sss/pipes/private/sbus-dp_openforce.org ?

It is a symbolic link that points to /var/lib/sss/pipes/private/sbus-dp_openforce.org.13800

ls -l /var/lib/sss/pipes/private/sbus-dp_openforce.org
lrwxrwxrwx 1 root root 54 nov 20 16:34 /var/lib/sss/pipes/private/sbus-dp_openforce.org -> /var/lib/sss/pipes/private/sbus-dp_openforce.org.13800
root@ows-d1b929e3:/var/log/sssd# ls -l /var/lib/sss/pipes/private/sbus-dp_openforce.org.13800
srw------- 1 root root 0 nov 20 16:34 /var/lib/sss/pipes/private/sbus-dp_openforce.org.13800

When I do the failed run, both sssd_nss.log, sssd_pam.log, sssd_ssh.log and sssd_sudo.log reports:

(Sat Nov 21 00:35:27 2015) [sssd[sudo]] [sss_dp_init] (0x0010): Failed to connect to monitor services.
(Sat Nov 21 00:35:27 2015) [sssd[sudo]] [sss_process_init] (0x0010): fatal error setting up backend connector
(Sat Nov 21 00:35:27 2015) [sssd[sudo]] [sudo_process_init] (0x0010): sss_process_init() failed
(Sat Nov 21 00:35:27 2015) [sssd[sudo]] [sss_dp_init] (0x0010): Failed to connect to monitor services.
(Sat Nov 21 00:35:27 2015) [sssd[sudo]] [sss_process_init] (0x0010): fatal error setting up backend connector
(Sat Nov 21 00:35:27 2015) [sssd[sudo]] [sudo_process_init] (0x0010): sss_process_init() failed

sssd_openforce.org.log reports:

(Sat Nov 21 00:35:22 2015) [sssd[be[openforce.org]]] [load_backend_module] (0x0010): Error (5) in module (ldap) initialization (sssm_ldap_sudo_init)!
(Sat Nov 21 00:35:22 2015) [sssd[be[openforce.org]]] [be_process_init] (0x0010): fatal error initializing data providers
(Sat Nov 21 00:35:22 2015) [sssd[be[openforce.org]]] [main] (0x0010): Could not initialize backend [5]

...and this message is repeated 4 times.

Hi, I think I have tracked down the error to sdap_idmap_init.

[sdap_idmap_init] (0x0020): Could not add domain [openforce.org][S-1-5-21-3065846811-936052125-3479462643][3501] to ID map: [Input/output error]

This error occurs when the cache file is used. If it is not present, it is initialized correctly. It is also here where the /var/lib/sss/pipes/private/sbus-dp_openforce.org.14310 is teared down, and becuase if this the error in the other modules occurs (I think)

This is the log when it does not work:

(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [ldap_id_init_internal] (0x0100): Service name for discovery set to ldap
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [fo_new_service] (0x0400): Creating new service 'LDAP'
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [_sdap_urls_init] (0x0400): Added URI ldap://srv11.openforce.org
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'srv11.openforce.org:389' to service 'LDAP'
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [sysdb_idmap_get_mappings] (0x4000): cn=id_mappings,cn=openforce.org,cn=sysdb
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1771a30

(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1771b60

(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [ldb] (0x4000): Running timer event 0x1771a30 "ltdb_callback"

(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [ldb] (0x4000): Destroying timer event 0x1771b60 "ltdb_timeout"

(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [ldb] (0x4000): Ending timer event 0x1771a30 "ltdb_callback"

(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [sdap_idmap_init] (0x0100): Initializing [1] domains for ID-mapping
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [sdap_idmap_add_domain] (0x0020): Could not add domain [openforce.org] to the map: [11]
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [sdap_idmap_init] (0x0020): Could not add domain [openforce.org][S-1-5-21-3065846811-936052125-3479462643][3501] to ID map: [Input/output error]
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [sssm_ldap_sudo_init] (0x0020): Cannot init LDAP ID provider [5]: Input/output error
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [load_backend_module] (0x0010): Error (5) in module (ldap) initialization (sssm_ldap_sudo_init)!
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [be_process_init] (0x0010): fatal error initializing data providers
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [be_ptask_destructor] (0x0400): Terminating periodic task [Cleanup of openforce.org]
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [sbus_remove_watch] (0x2000): 0x17539d0/0x1754590
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [remove_socket_symlink] (0x4000): The symlink points to [/var/lib/sss/pipes/private/sbus-dp_openforce.org.14310]
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [remove_socket_symlink] (0x4000): The path including our pid is [/var/lib/sss/pipes/private/sbus-dp_openforce.org.14310]
(Sat Nov 21 00:47:30 2015) [sssd[be[openforce.org]]] [remove_socket_symlink] (0x4000): Removed the symlink

Here is the same section when it does work: (with linenumbers)

461 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [fo_new_service] (0x0400): Creating new service 'LDAP'
 462 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [_sdap_urls_init] (0x0400): Added URI ldap://srv11.openforce.org
 463 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [fo_add_server_to_list] (0x0400): Inserted primary server 'srv11.openforce.org:389' to service 'LDAP'
 464 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [sysdb_idmap_get_mappings] (0x4000): cn=id_mappings,cn=openforce.org,cn=sysdb
 465 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x25b6160
 466 
 467 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x25b6290
 468 
 469 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [ldb] (0x4000): Running timer event 0x25b6160 "ltdb_callback"
 470 
 471 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [ldb] (0x4000): Destroying timer event 0x25b6290 "ltdb_timeout"
 472 
 473 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [ldb] (0x4000): Ending timer event 0x25b6160 "ltdb_callback"
 474 
 475 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [sysdb_idmap_get_mappings] (0x0080): Could not locate ID mappings: [No such file or directory]
 476 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [be_fo_set_srv_lookup_plugin] (0x0400): Trying to set SRV lookup plugin to DNS
 477 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [fo_set_srv_lookup_plugin] (0x0080): SRV lookup plugin is already set
 478 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [be_fo_set_srv_lookup_plugin] (0x0080): Unable to set SRV lookup plugin, another plugin may be already in place
 479 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [sdap_sudo_init] (0x2000): Initializing sudo LDAP back end
 480 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [ldap_get_sudo_options] (0x0400): Search base not set, trying to discover it later connecting to the LDAP server.
 481 (Sat Nov 21 01:11:31 2015) [sssd[be[openforce.org]]] [common_parse_search_base] (0x0100): Search base added: [SUDO][ou=SUDOers,dc=openforce,dc=se][SUBTREE][]

Here is the area in the log when it breaks by adding sudo_provider = ldap when the cache-file is present. I am positive :)

[monitor_service_init] (0x0400): Initializing D-BUS Service
[sbus_conn_add_interface] (0x1000): Will register path /org/freedesktop/sssd/monitor without fallback
[sbus_dispatch] (0x4000): dbus conn: 0x721470
[sbus_toggle_watch] (0x4000): 0x714010/0x70fd50 (16), R/- (disabled)
[sbus_toggle_watch] (0x4000): 0x714010/0x710680 (16), -/W (enabled)
[sbus_toggle_watch] (0x4000): 0x714010/0x70fd50 (16), R/- (enabled)
[sbus_toggle_watch] (0x4000): 0x714010/0x710680 (16), -/W (disabled)
[sbus_remove_watch] (0x2000): 0x714010/0x70fd50
[sbus_remove_watch] (0x2000): 0x714010/0x710680
[sbus_dispatch] (0x4000): dbus conn: 0x721470
[sbus_dispatch] (0x0080): Connection is not open for dispatching.

I don't know how to debug this further. If this could be debugged even further with gdb or something, just give me som guide lines and I'll try and track it down.

We resolved this ticket by explicitly adding:

ldap_id_mapping = true

to the domain section.

resolution: => worksforme
status: new => closed

Metadata Update from @nandersson:
- Issue set to the milestone: NEEDS_TRIAGE

7 years ago

SSSD is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in SSSD's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/SSSD/sssd/issues/3918

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.

Login to comment on this ticket.

Metadata