systemd doesn't successfully enforce RuntimeMaxSec for gnome session

Bug #2015126 reported by Steve Langasek
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
systemd (Ubuntu)
Triaged
Low
Unassigned
Jammy
Triaged
Low
Unassigned
Kinetic
Triaged
Low
Unassigned

Bug Description

On Jammy, I have configured systemd to set RuntimeMaxSec on certain user sessions:

# cat /run/systemd/transient/session-43.scope
# This is a transient unit file, created programmatically via the systemd API. Do not edit.
[Scope]
Slice=user-1000.slice

[Unit]
Description=Session 43 of User xavier
Wants=user-runtime-dir@1000.service
Wants=user@1000.service
After=systemd-logind.service
After=systemd-user-sessions.service
After=user-runtime-dir@1000.service
After=user@1000.service
RequiresMountsFor=/home/xavier

[Scope]
SendSIGHUP=yes
TasksMax=infinity
RuntimeMaxSec=2h
#

I have verified that this does what's expected on an ssh session, and kills the session when the runtime max has been reached.

But on a GNOME login session (using X), this apparently doesn't work: the session is still running 17 hours after it should have been terminated.

My guess is that systemd is ending the session by sending a signal that is being ignored by the GNOME login session?

RuntimeMaxSec is not very useful if it's advisory...

ProblemType: Bug
DistroRelease: Ubuntu 22.04
Package: systemd 249.11-0ubuntu3.7
ProcVersionSignature: Ubuntu 5.19.0-38.39~22.04.1-generic 5.19.17
Uname: Linux 5.19.0-38-generic x86_64
ApportVersion: 2.20.11-0ubuntu82.3
Architecture: amd64
CasperMD5CheckResult: pass
CurrentDesktop: ubuntu:GNOME
Date: Mon Apr 3 12:20:22 2023
InstallationDate: Installed on 2023-01-22 (70 days ago)
InstallationMedia: Ubuntu 22.04.1 LTS "Jammy Jellyfish" - Release amd64 (20220809.1)
MachineType: LENOVO 2306CTO
ProcEnviron:
 TERM=xterm-256color
 PATH=(custom, no user)
 XDG_RUNTIME_DIR=<set>
 LANG=en_US.UTF-8
 SHELL=/bin/bash
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-5.19.0-38-generic root=UUID=c415e6a8-5cd2-4d08-913d-14c00b792374 ro quiet splash vt.handoff=7
SourcePackage: systemd
UpgradeStatus: No upgrade log present (probably fresh install)
dmi.bios.date: 10/25/2013
dmi.bios.release: 2.57
dmi.bios.vendor: LENOVO
dmi.bios.version: G2ET97WW (2.57 )
dmi.board.asset.tag: Not Available
dmi.board.name: 2306CTO
dmi.board.vendor: LENOVO
dmi.board.version: Not Defined
dmi.chassis.asset.tag: No Asset Information
dmi.chassis.type: 10
dmi.chassis.vendor: LENOVO
dmi.chassis.version: Not Available
dmi.ec.firmware.release: 1.13
dmi.modalias: dmi:bvnLENOVO:bvrG2ET97WW(2.57):bd10/25/2013:br2.57:efr1.13:svnLENOVO:pn2306CTO:pvrThinkPadX230:rvnLENOVO:rn2306CTO:rvrNotDefined:cvnLENOVO:ct10:cvrNotAvailable:skuLENOVO_MT_2306:
dmi.product.family: ThinkPad X230
dmi.product.name: 2306CTO
dmi.product.sku: LENOVO_MT_2306
dmi.product.version: ThinkPad X230
dmi.sys.vendor: LENOVO

Revision history for this message
Steve Langasek (vorlon) wrote :
Revision history for this message
Steve Langasek (vorlon) wrote :

For reference, populating RuntimeMaxSec is done via https://github.com/vorlonofportland/pam_session_timelimit; there is no existing support for this in Ubuntu today.

Revision history for this message
Nick Rosbrook (enr0n) wrote :

I was able to re-produce this in a different way, but I'm pretty sure it's the same bug that affects you. For scope units in particular, the RuntimeMaxSec property is not applied correctly when systemd is reloaded. E.g., if I run:

$ systemd-run --scope -u foo-1.scope /usr/bin/foo
$ mkdir -p /etc/systemd/system/foo-.scope.d/
$ cat > /etc/systemd/system/foo-.scope.d/override.conf << EOF
[Scope]
RuntimeMaxSec=10s
$ systemctl daemon-reload

Then foo-1.scope just keeps running. The setting is applied correctly if I restart foo-1.scope, however. Running the same test for a service unit results in the RuntimeMaxSec value being applied correctly, and the unit is terminated.

I have built and tested a fix in ppa:enr0n/systemd-251. Does that fix your issue?

Changed in systemd (Ubuntu):
importance: Undecided → Low
Revision history for this message
Nick Rosbrook (enr0n) wrote :

Er, I built and tested on kinetic, but I can build the fix for jammy too.

Revision history for this message
Nick Rosbrook (enr0n) wrote :

Jammy version with my fix is in ppa:enr0n/systemd-249.

Changed in systemd (Ubuntu):
status: New → Triaged
Revision history for this message
Steve Langasek (vorlon) wrote :

Thanks, I've confirmed the fix on jammy here.

Revision history for this message
Nick Rosbrook (enr0n) wrote :

Thanks for testing!

Changed in systemd (Ubuntu Jammy):
status: New → Triaged
Changed in systemd (Ubuntu Kinetic):
status: New → Triaged
Changed in systemd (Ubuntu Jammy):
importance: Undecided → Low
Changed in systemd (Ubuntu Kinetic):
importance: Undecided → Low
Revision history for this message
Steve Langasek (vorlon) wrote :

Although this was working with the ppa package, enforcement is failing again.

# apt policy systemd
systemd:
  Installed: 249.11-0ubuntu3.10~debug1
  Candidate: 249.11-0ubuntu3.10~debug1
  Version table:
 *** 249.11-0ubuntu3.10~debug1 500
        500 https://ppa.launchpadcontent.net/enr0n/systemd-249/ubuntu jammy/main amd64 Packages
        100 /var/lib/dpkg/status
     249.11-0ubuntu3.9 500
        500 http://us.archive.ubuntu.com/ubuntu jammy-updates/main amd64 Packages
     249.11-0ubuntu3.7 500
        500 http://security.ubuntu.com/ubuntu jammy-security/main amd64 Packages
     249.11-0ubuntu3 500
        500 http://us.archive.ubuntu.com/ubuntu jammy/main amd64 Packages
#

# grep Runtime /run/systemd/transient/session-2.scope
RuntimeMaxSec=2h
# ls -l /run/systemd/transient/session-2.scope
-rw-r--r-- 1 root root 442 Apr 15 13:43 /run/systemd/transient/session-2.scope
# date
Sat Apr 15 16:17:15 PDT 2023
#

So the session has been open for over 2 hours.

Revision history for this message
Nick Rosbrook (enr0n) wrote :

Odd. Does `systemctl show --propoerty=RuntimeMaxUSec session-2.scope` show the same thing, or something different?

Revision history for this message
Steve Langasek (vorlon) wrote : Re: [Bug 2015126] Re: systemd doesn't successfully enforce RuntimeMaxSec for gnome session

On Mon, Apr 17, 2023 at 01:30:11PM -0000, Nick Rosbrook wrote:
> Odd. Does `systemctl show --propoerty=RuntimeMaxUSec session-2.scope`
> show the same thing, or something different?

For a current session, which is session-93.scope, I see in the file:

RuntimeMaxSec=1h 38min 56s

And from systemctl:

# systemctl show --property=RuntimeMaxUSec session-93.scope
RuntimeMaxUSec=1h 38min 56s
#

So these match.

Revision history for this message
Nick Rosbrook (enr0n) wrote :

Okay. I'm curious what the output is when RuntimeMaxSec does not seem to be enforced. Does this fail consistently again or is it irregular?

Revision history for this message
Nick Rosbrook (enr0n) wrote (last edit ):

Also, to check the active runtime, can you use `systemctl show --property=ActiveEnterTimestamp session-X.scope`? Or just show the full output of systemctl status session-X.scope. It should inform us if it is counting up to RuntimeMaxSec.

Revision history for this message
Steve Langasek (vorlon) wrote :

On Fri, Apr 21, 2023 at 03:57:58PM -0000, Nick Rosbrook wrote:
> Also, to check the active runtime, can you use `systemctl show
> --property=ActiveEnterTimestamp session-X.scope`? Or just show the full
> output of systemctl status session-X.scope. It should inform us if it is
> counting up to RuntimeMaxSec.

A test session with a 5-minute limit:

# systemctl status session-35.scope --no-pager -l | sed -e's/User .*/User foo/'
● session-35.scope - Session 35 of User foo
     Loaded: loaded (/run/systemd/transient/session-35.scope; transient)
  Transient: yes
     Active: active (running) since Fri 2023-04-21 10:42:20 PDT; 2min 15s ago
      Tasks: 18
     Memory: 56.8M
        CPU: 2.325s
     CGroup: /user.slice/user-1000.slice/session-35.scope
             ├─15573 "gdm-session-worker [pam/gdm-password]"
             ├─15745 /usr/bin/gnome-keyring-daemon --daemonize --login
             ├─15749 /usr/libexec/gdm-x-session --run-script "env GNOME_SHELL_SESSION_MODE=ubuntu /usr/bin/gnome-session --session=ubuntu"
             ├─15751 /usr/lib/xorg/Xorg vt3 -displayfd 3 -auth /run/user/1000/gdm/Xauthority -nolisten tcp -background none -noreset -keeptty -novtswitch -verbose 3
             └─15762 /usr/libexec/gnome-session-binary --session=ubuntu

Apr 21 10:42:21 virgil /usr/libexec/gdm-x-session[15799]: dbus-update-activation-environment: setting QT_ACCESSIBILITY=1
Apr 21 10:42:21 virgil gnome-keyring-daemon[15745]: The Secret Service was already initialized
Apr 21 10:42:21 virgil gnome-keyring-daemon[15745]: The PKCS#11 component was already initialized
Apr 21 10:42:21 virgil gnome-keyring-daemon[15745]: The SSH agent was already initialized
Apr 21 10:42:21 virgil /usr/libexec/gdm-x-session[15751]: (II) modeset(0): EDID vendor "AUO", prod id 4204
Apr 21 10:42:21 virgil /usr/libexec/gdm-x-session[15751]: (II) modeset(0): Printing DDC gathered Modelines:
Apr 21 10:42:21 virgil /usr/libexec/gdm-x-session[15751]: (II) modeset(0): Modeline "1366x768"x0.0 69.30 1366 1414 1446 1454 768 771 777 793 -hsync -vsync (47.7 kHz eP)
Apr 21 10:42:25 virgil /usr/libexec/gdm-x-session[15751]: (II) modeset(0): EDID vendor "AUO", prod id 4204
Apr 21 10:42:25 virgil /usr/libexec/gdm-x-session[15751]: (II) modeset(0): Printing DDC gathered Modelines:
Apr 21 10:42:25 virgil /usr/libexec/gdm-x-session[15751]: (II) modeset(0): Modeline "1366x768"x0.0 69.30 1366 1414 1446 1454 768 771 777 793 -hsync -vsync (47.7 kHz eP)
# systemctl show --property=ActiveEnterTimestamp session-35.scope
ActiveEnterTimestamp=Fri 2023-04-21 10:42:20 PDT
# systemctl show --property=RuntimeMaxUSec session-35.scope
RuntimeMaxUSec=5min
#

# date
Fri Apr 21 10:52:23 PDT 2023
#

Still running past the limit.

--
Steve Langasek Give me a lever long enough and a Free OS
Debian Developer to set it on, and I can move the world.
Ubuntu Developer https://www.debian.org/
<email address hidden> <email address hidden>

Revision history for this message
Steve Langasek (vorlon) wrote :

Ah, now, rechecking, it appears the gdm session is mostly dead:

$ systemctl status session-35.scope --no-pager -l | sed -e's/User .*/User foo/'
× session-35.scope - Session 35 of User foo
     Loaded: loaded (/run/systemd/transient/session-35.scope; transient)
  Transient: yes
     Active: failed (Result: timeout) since Fri 2023-04-21 10:47:20 PDT; 18min ago
        CPU: 2.916s

Apr 21 10:47:20 virgil /usr/libexec/gdm-x-session[15751]: (II) systemd-logind: releasing fd for 13:65
Apr 21 10:47:20 virgil /usr/libexec/gdm-x-session[15751]: (II) UnloadModule: "libinput"
Apr 21 10:47:20 virgil /usr/libexec/gdm-x-session[15751]: (II) systemd-logind: releasing fd for 13:74
Apr 21 10:47:20 virgil /usr/libexec/gdm-x-session[15751]: (II) UnloadModule: "libinput"
Apr 21 10:47:20 virgil /usr/libexec/gdm-x-session[15751]: (II) systemd-logind: releasing fd for 13:66
Apr 21 10:47:20 virgil /usr/libexec/gdm-x-session[15751]: (WW) xf86CloseConsole: KDSETMODE failed: Input/output error
Apr 21 10:47:20 virgil /usr/libexec/gdm-x-session[15751]: (WW) xf86CloseConsole: VT_GETMODE failed: Input/output error
Apr 21 10:47:20 virgil /usr/libexec/gdm-x-session[15751]: (II) Server terminated successfully (0). Closing log file.
Apr 21 10:47:20 virgil systemd[1]: session-35.scope: Failed with result 'timeout'.
Apr 21 10:47:20 virgil systemd[1]: session-35.scope: Consumed 2.916s CPU time.
$

But there are still some processes owned by the user lingering:

$ ps awxfu|grep ^x | cut -f2- -d' '
     9185 0.0 0.0 18152 10956 ? Ss 09:40 0:04 /lib/systemd/systemd --user
     9186 0.0 0.0 170764 4508 ? S 09:40 0:00 \_ (sd-pam)
     9192 0.0 0.0 48216 6756 ? S<sl 09:40 0:00 \_ /usr/bin/pipewire
     9193 0.0 0.0 32256 6428 ? Ssl 09:40 0:00 \_ /usr/bin/pipewire-media-session
    17778 0.0 0.0 8436 4124 ? Ss 10:47 0:00 \_ /usr/bin/dbus-daemon --session --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only
    17779 0.0 0.0 471820 7440 ? Ssl 10:47 0:00 \_ /usr/libexec/xdg-document-portal
    17782 0.0 0.0 244796 5416 ? Ssl 10:47 0:00 \_ /usr/libexec/xdg-permission-store
$

Seems like a bug in the session management of those processes? But the actual gdm process is dead, as is gnome-shell.

Could it be an issue of the timer not triggering if the system is suspended when the timeout is reached, and then resumed after?

Revision history for this message
Steve Langasek (vorlon) wrote :

ok, reproduced the failure - if the system is suspended at the session expiry, the session apparently is never closed.

     Active: active (running) since Fri 2023-04-21 11:13:02 PDT; 7min ago

RuntimeMaxUSec=5min

Revision history for this message
Steve Langasek (vorlon) wrote :

The session did eventually exit:

     Active: failed (Result: timeout) since Fri 2023-04-21 11:24:31 PDT; 2min 48s ago

However, the time while the system was suspended didn't count towards the session limit.

This kind of makes sense, but is also at odds with my goal of also using pam_time to enforce specific bedtime limits.

Revision history for this message
Nick Rosbrook (enr0n) wrote :

Thanks, that is very helpful. I tested this for service units too, and got the same result:

$ systemd-run -u test-1.service -p RuntimeMaxSec=1m /usr/bin/bash -c 'while true; do sleep 1; done'
$ systemctl suspend # Waited a bit...

After resume:

$ systemctl status test-1.service
● test-1.service - /usr/bin/bash -c while true; do sleep 1; done
     Loaded: loaded (/run/systemd/transient/test-1.service; transient)
  Transient: yes
     Active: active (running) since Fri 2023-04-21 15:35:17 EDT; 2min 15s ago
      Until: Fri 2023-04-21 15:36:17 EDT; 1min 15s ago
   Main PID: 61473 (bash)
      Tasks: 2 (limit: 18896)
     Memory: 572.0K
        CPU: 138ms
     CGroup: /system.slice/test-1.service
             ├─61473 /usr/bin/bash -c "while true; do sleep 1; done"
             └─62087 sleep 1

Apr 21 15:35:17 six systemd[1]: Started test-1.service - /usr/bin/bash -c while true; do sleep 1; done.
$ systemctl status test-1.service
× test-1.service - /usr/bin/bash -c while true; do sleep 1; done
     Loaded: loaded (/run/systemd/transient/test-1.service; transient)
  Transient: yes
     Active: failed (Result: timeout) since Fri 2023-04-21 15:37:35 EDT; 1s ago
   Duration: 2min 18.274s
    Process: 61473 ExecStart=/usr/bin/bash -c while true; do sleep 1; done (code=killed, signal=TERM)
   Main PID: 61473 (code=killed, signal=TERM)
        CPU: 145ms

Apr 21 15:35:17 six systemd[1]: Started test-1.service - /usr/bin/bash -c while true; do sleep 1; done.
Apr 21 15:37:35 six systemd[1]: test-1.service: Service reached runtime time limit. Stopping.
Apr 21 15:37:35 six systemd[1]: test-1.service: Failed with result 'timeout'.

I am not sure if this is the intended behavior, so I will look into it further. The fact that the "Until: " line shows a time in the past makes me think this is not the intended behavior, and that timers should be restarted on suspend (which will immediately timeout if the time is in the past).

Revision history for this message
Nick Rosbrook (enr0n) wrote (last edit ):

Okay, so internally systemd is using CLOCK_MONOTONIC for the event source that counts up to RuntimeMaxSec, and CLOCK_MONOTONIC does not count the time when the system is suspended. Your use case wants CLOCK_BOOTTIME, which does count time when the system is suspended. I will work on a fix for this.

[1] https://man7.org/linux/man-pages/man3/clock_gettime.3.html

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.