Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Inadvertent sssd related calls in Leap 15.4 #2429

Closed
phillxnet opened this issue Nov 15, 2022 · 6 comments
Closed

Inadvertent sssd related calls in Leap 15.4 #2429

phillxnet opened this issue Nov 15, 2022 · 6 comments
Assignees

Comments

@phillxnet
Copy link
Member

During experimental preparation for our re-basing on openSUSE Leap 15.4 via pending pr #2427 for issue #2424, it was discovered that we appear, in 15.4 only, to be calling on sssd inadvertently, prior to its configuration for AD/LDAP function, resulting in massive slow-downs in group and some deeper user page views:
Reproducer - visit/refresh groups page:

Nov 15 16:06:23 rleap15-4 [RPM][21426]: install sssd-dbus-2.5.2-150400.4.11.1.x86_64: success
Nov 15 16:06:23 rleap15-4 [RPM][21426]: install sssd-dbus-2.5.2-150400.4.11.1.x86_64: success
Nov 15 16:06:23 rleap15-4 [RPM][21426]: Transaction ID 6373b8fe finished: 0
Nov 15 16:06:45 rleap15-4 dbus-daemon[656]: [system] Activating via systemd: service name='org.freedesktop.sssd.infopipe' unit='sssd-ifp.service' requested by ':1.33' (uid=0 pid=13385 comm="/usr/bin/python2 /opt/rockstor-dev/bin/gunicorn --")
Nov 15 16:06:45 rleap15-4 systemd[1]: Starting System Security Services Daemon...
Nov 15 16:06:45 rleap15-4 sssd[22235]: SSSD couldn't load the configuration database [2]: No such file or directory.
Nov 15 16:06:45 rleap15-4 systemd[1]: sssd.service: Main process exited, code=exited, status=4/NOPERMISSION
Nov 15 16:06:45 rleap15-4 systemd[1]: sssd.service: Failed with result 'exit-code'.
Nov 15 16:06:45 rleap15-4 systemd[1]: Failed to start System Security Services Daemon.
Nov 15 16:06:45 rleap15-4 systemd[1]: Dependency failed for SSSD IFP Service responder.
Nov 15 16:06:45 rleap15-4 systemd[1]: sssd-ifp.service: Job sssd-ifp.service/start failed with result 'dependency'.
Nov 15 16:06:45 rleap15-4 systemd[1]: Reached target User and Group Name Lookups.
Nov 15 16:06:45 rleap15-4 systemd[1]: sssd.service: Scheduled restart job, restart counter is at 1.
Nov 15 16:06:45 rleap15-4 systemd[1]: Stopped System Security Services Daemon.
Nov 15 16:06:45 rleap15-4 systemd[1]: Starting System Security Services Daemon...
Nov 15 16:06:45 rleap15-4 sssd[22240]: SSSD couldn't load the configuration database [2]: No such file or directory.
Nov 15 16:06:45 rleap15-4 systemd[1]: sssd.service: Main process exited, code=exited, status=4/NOPERMISSION

In the above we see that, as part of the initial diagnosis, we ended up installing the last of our sssd related dependencies before this issue was triggerable, the so-called InfoPipe, from:

zypper info sssd-dbus

Description :
Provides the D-Bus responder of sssd, called InfoPipe, which allows
information from sssd to be transmitted over the system bus.

unit='sssd-ifp.service' requested by ':1.33' (uid=0 pid=13385 comm="/usr/bin/python2 /opt/rockstor-dev/bin/gunicorn --")

which in turn finds our sssd not working, because there is no AD setup. Hence a suspected failing check on if AD / sssd is enabled.

Thanks to @FroggyFlox for assistance in the initial diagnosis of what might be going awry here.

@FroggyFlox
Copy link
Member

Thanks @phillxnet !
The culprit might lie in #2279, for reference.

@phillxnet
Copy link
Member Author

OK, so it looks like 'just-asking' dbus InfoPipe for group info via sssd results in the exact same sssd initialisation and consequent slowdown/timeout (but only in 15.4):

On command line we do:

rleap15-4:~ # dbus-send --print-reply --system --dest=org.freedesktop.sssd.infopipe /org/freedesktop/sssd/infopipe org.freedesktop.sssd.infopipe.GetUserGroups
Error org.freedesktop.DBus.Error.TimedOut: Failed to activate service 'org.freedesktop.sssd.infopipe': timed out (service_start_timeout=25000ms)

And experience a delay for our response (second line above).
Via:

journalctl -f

We receive the, as per groups page visit of:

Nov 15 18:08:01 rleap15-4 dbus-daemon[656]: [system] Activating via systemd: service name='org.freedesktop.sssd.infopipe' unit='sssd-ifp.service' requested by ':1.99' (uid=0 pid=11436 comm="dbus-send --print-reply --system --dest=org.freede")
Nov 15 18:08:01 rleap15-4 systemd[1]: Starting System Security Services Daemon...
Nov 15 18:08:01 rleap15-4 sssd[11437]: SSSD couldn't load the configuration database [2]: No such file or directory.
Nov 15 18:08:01 rleap15-4 systemd[1]: sssd.service: Main process exited, code=exited, status=4/NOPERMISSION
Nov 15 18:08:01 rleap15-4 systemd[1]: sssd.service: Failed with result 'exit-code'.
Nov 15 18:08:01 rleap15-4 systemd[1]: Failed to start System Security Services Daemon.
Nov 15 18:08:01 rleap15-4 systemd[1]: Dependency failed for SSSD IFP Service responder.
Nov 15 18:08:01 rleap15-4 systemd[1]: sssd-ifp.service: Job sssd-ifp.service/start failed with result 'dependency'.
Nov 15 18:08:01 rleap15-4 systemd[1]: sssd.service: Scheduled restart job, restart counter is at 1.
...
Nov 15 18:08:02 rleap15-4 systemd[1]: sssd.service: Scheduled restart job, restart counter is at 5.
Nov 15 18:08:02 rleap15-4 systemd[1]: Stopped System Security Services Daemon.
Nov 15 18:08:02 rleap15-4 systemd[1]: sssd.service: Start request repeated too quickly.
Nov 15 18:08:02 rleap15-4 systemd[1]: sssd.service: Failed with result 'exit-code'.
Nov 15 18:08:02 rleap15-4 systemd[1]: Failed to start System Security Services Daemon.
Nov 15 18:08:26 rleap15-4 dbus-daemon[656]: [system] Failed to activate service 'org.freedesktop.sssd.infopipe': timed out (service_start_timeout=25000ms)

Where-as with our prior older InfoPipe etc in Leap 15.3 we have the following behaviour:

rleap15-3:~ # dbus-send --print-reply --system --dest=org.freedesktop.sssd.infopipe /org/freedesktop/sssd/infopipe org.freedesktop.sssd.infopipe.GetUserGroups
Error org.freedesktop.DBus.Error.Spawn.ChildExited: Launch helper exited with unknown return code 1

Where the above fails imidiately and doesn't try to start the related services.
And we have the immidiate response in logs also of:

Nov 15 18:13:56 rleap15-3 dbus-daemon[560]: [system] Activating service name='org.freedesktop.sssd.infopipe' requested by ':1.42' (uid=0 pid=15708 comm="dbus-send --print-reply --system --dest=org.freede") (using servicehelper)
Nov 15 18:13:56 rleap15-3 org.freedesktop.sssd.infopipe[15711]: Could not signal SSSD. Is SSSD running?
Nov 15 18:13:56 rleap15-3 dbus-daemon[560]: [system] Activated service 'org.freedesktop.sssd.infopipe' failed: Launch helper exited with unknown return code 1

So in Leap 15.3 we have an instant fail / return when we 'ask' for sssd stuff as sssd is not running (in both OS's above) but in Leap 15.4 we have a timeout and a resulting attempt to start the sssd service which, as it's not configured yet, fails.

@phillxnet
Copy link
Member Author

I think what we are seeing here is a difference in the systemd setup of InfoPipe between 15.3 and 15.4:

rleap15-3:~ # zypper info sssd-dbus | grep "Version"
Version : 1.16.1-150300.23.34.1
rleap15-3:~ # rpm -ql sssd-dbus | grep service
/usr/share/dbus-1/system-services/org.freedesktop.sssd.infopipe.service


rleap15-4:~ # zypper info sssd-dbus | grep "Version"
Version : 2.5.2-150400.4.11.1
rleap15-4:~ # rpm -ql sssd-dbus | grep service
/usr/lib/systemd/system/sssd-ifp.service
/usr/share/dbus-1/system-services/org.freedesktop.sssd.infopipe.service

@phillxnet
Copy link
Member Author

Where the new sssd-ifp.service associated with the newer 15.4 sssd-dbus package has an invocation thus:

[Unit]
Description=SSSD IFP Service responder
Documentation=man:sssd-ifp(5)
After=sssd.service
BindsTo=sssd.service

[Service]
Environment=DEBUG_LOGGER=--logger=files
EnvironmentFile=-/etc/sysconfig/sssd
Type=dbus
BusName=org.freedesktop.sssd.infopipe
ExecStart=/usr/lib/sssd/sssd_ifp --uid 0 --gid 0 --dbus-activated ${DEBUG_LOGGER}
CapabilityBoundingSet=  CAP_IPC_LOCK CAP_CHOWN CAP_DAC_READ_SEARCH CAP_FOWNER CAP_SETGID CAP_SETUID
Restart=on-failure
/usr/lib/systemd/system/sssd-ifp.service lines 1-14/14 (END)

@phillxnet
Copy link
Member Author

Interestingly when we remove the pivital app in this case:

rleap15-4:~ # zypper remove sssd-dbus 
...
The following package is going to be REMOVED:
  sssd-dbus
...
rm: cannot remove '/var/lib/systemd/migrated/sssd-ifp': No such file or directory

And then re-run our cli reproducer for our observed delay in groups page visit:

rleap15-4:~ # dbus-send --print-reply --system --dest=org.freedesktop.sssd.infopipe /org/freedesktop/sssd/infopipe org.freedesktop.sssd.infopipe.GetUserGroups
Error org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.sssd.infopipe was not provided by any .service files

Re-indicating such a call does in fact now invoke our .service in a way it did not in Leap 15.3.

@phillxnet phillxnet self-assigned this Nov 15, 2022
phillxnet added a commit to phillxnet/rockstor-core that referenced this issue Nov 16, 2022
Add simple sssd service running checks to avoid
inadvertent slow-downs in Leap 15.4 where our
InfoPipe requests initiated a previously not
observed, in earlier Leap versions, sssd service
start.

Includes additional comments and TODO in services
concerning speed-ups/simplifications regarding
simple/fast service status enquiry.
phillxnet added a commit that referenced this issue Nov 18, 2022
…_calls_in_Leap_15.4

Inadvertent sssd related calls in Leap 15.4 #2429
@phillxnet
Copy link
Member Author

Closing as:
Fixed by #2430

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants