Bug 2221337
| Summary: | Nightly error on systemd restart... (sd-pam): pam_systemd(login:session): Failed to release session: Access denied | ||
|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | John Dodson <jwadodson> |
| Component: | systemd | Assignee: | systemd-maint |
| Status: | NEW --- | QA Contact: | Fedora Extras Quality Assurance <extras-qa> |
| Severity: | medium | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 38 | CC: | dtardon, fedoraproject, filbranden, fsumsal, lnykryn, msekleta, ryncsn, systemd-maint, yuwatana, zbyszek |
| Target Milestone: | --- | Keywords: | Triaged |
| Target Release: | --- | ||
| Hardware: | Unspecified | ||
| OS: | Linux | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | Type: | --- | |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
Please attach the log from around the time (journalctl -b).
Jul 09 01:00:01 HOSTNAME-DELETED audit[274313]: USER_ACCT pid=274313 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:accounting grantors=pam_access,pam_unix,pam_localuser acct="USENAME-DELETED" exe="/usr/sbin/crond" hostname=? addr=? terminal=cron res=success'
Jul 09 01:00:01 HOSTNAME-DELETED audit[274313]: CRED_ACQ pid=274313 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="USENAME-DELETED" exe="/usr/sbin/crond" hostname=? addr=? terminal=cron res=success'
Jul 09 01:00:01 HOSTNAME-DELETED systemd[1]: Starting sysstat-collect.service - system activity accounting tool...
Jul 09 01:00:01 HOSTNAME-DELETED systemd[1]: Starting dnf-automatic.service - dnf automatic...
Jul 09 01:00:01 HOSTNAME-DELETED systemd[1]: sysstat-collect.service: Deactivated successfully.
Jul 09 01:00:01 HOSTNAME-DELETED systemd[1]: Finished sysstat-collect.service - system activity accounting tool.
Jul 09 01:00:01 HOSTNAME-DELETED audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sysstat-collect comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:01 HOSTNAME-DELETED audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sysstat-collect comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:01 HOSTNAME-DELETED systemd[1]: Started session-28.scope - Session 28 of User USENAME-DELETED.
Jul 09 01:00:01 HOSTNAME-DELETED audit[274313]: USER_START pid=274313 uid=0 auid=1000 ses=28 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:session_open grantors=pam_loginuid,pam_keyinit,pam_limits,pam_systemd acct="USENAME-DELETED" exe="/usr/sbin/crond" hostname=? addr=? terminal=cron res=success'
Jul 09 01:00:01 HOSTNAME-DELETED audit[274313]: CRED_REFR pid=274313 uid=0 auid=1000 ses=28 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="USENAME-DELETED" exe="/usr/sbin/crond" hostname=? addr=? terminal=cron res=success'
Jul 09 01:00:01 HOSTNAME-DELETED CROND[274320]: (USENAME-DELETED) CMD (/usr/local/etc/monitor/checkset)
Jul 09 01:00:01 HOSTNAME-DELETED CROND[274313]: (USENAME-DELETED) CMDEND (/usr/local/etc/monitor/checkset)
Jul 09 01:00:01 HOSTNAME-DELETED audit[274313]: CRED_DISP pid=274313 uid=0 auid=1000 ses=28 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="USENAME-DELETED" exe="/usr/sbin/crond" hostname=? addr=? terminal=cron res=success'
Jul 09 01:00:01 HOSTNAME-DELETED audit[274313]: USER_END pid=274313 uid=0 auid=1000 ses=28 subj=system_u:system_r:crond_t:s0-s0:c0.c1023 msg='op=PAM:session_close grantors=pam_loginuid,pam_keyinit,pam_limits,pam_systemd acct="USENAME-DELETED" exe="/usr/sbin/crond" hostname=? addr=? terminal=cron res=success'
Jul 09 01:00:01 HOSTNAME-DELETED systemd[1]: session-28.scope: Deactivated successfully.
Jul 09 01:00:02 HOSTNAME-DELETED dnf-automatic[274315]: Last metadata expiration check: 1:31:47 ago on Sat 08 Jul 2023 23:28:15.
Jul 09 01:00:12 HOSTNAME-DELETED dnf-automatic[274315]: Delta RPMs reduced 7.8 MB of updates to 4.9 MB (38.0% saved)
Jul 09 01:00:12 HOSTNAME-DELETED dnf-automatic[274315]: Running transaction check
Jul 09 01:00:12 HOSTNAME-DELETED dnf-automatic[274315]: Transaction check succeeded.
Jul 09 01:00:12 HOSTNAME-DELETED dnf-automatic[274315]: Running transaction test
Jul 09 01:00:12 HOSTNAME-DELETED dnf-automatic[274315]: Transaction test succeeded.
Jul 09 01:00:12 HOSTNAME-DELETED dnf-automatic[274315]: Running transaction
Jul 09 01:00:16 HOSTNAME-DELETED systemd[1]: Started run-r2f40afd8532944e7946b8dcf5f8a8632.service - /usr/bin/systemctl start man-db-cache-update.
Jul 09 01:00:16 HOSTNAME-DELETED audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-r2f40afd8532944e7946b8dcf5f8a8632 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:16 HOSTNAME-DELETED systemd[1]: Starting man-db-cache-update.service...
Jul 09 01:00:16 HOSTNAME-DELETED systemd[1]: Reloading requested from client PID 274419 (unit dnf-automatic.service)...
Jul 09 01:00:16 HOSTNAME-DELETED systemd[1]: Reloading...
Jul 09 01:00:16 HOSTNAME-DELETED (sd-execu[274423]: /usr/lib/systemd/system-generators/ostree-system-generator failed with exit status 1.
Jul 09 01:00:16 HOSTNAME-DELETED systemd[1]: Reloading finished in 445 ms.
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=105 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=106 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=82 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=83 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=107 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=84 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=108 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=85 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=109 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=110 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=86 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=87 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=111 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=88 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=112 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=113 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=89 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=90 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=114 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=91 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=115 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=92 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=116 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=93 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=117 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=118 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=94 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=95 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=119 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=96 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=120 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=97 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=121 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=122 op=LOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=98 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED audit: BPF prog-id=99 op=UNLOAD
Jul 09 01:00:16 HOSTNAME-DELETED systemd[1]: Queuing reload/restart jobs for marked units…
Jul 09 01:00:16 HOSTNAME-DELETED systemd[1]: Started run-u159.service - systemd-stdio-bridge -punix:path=${XDG_RUNTIME_DIR}/bus.
Jul 09 01:00:16 HOSTNAME-DELETED audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-u159 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:16 HOSTNAME-DELETED systemd[1]: Started run-u160.service - systemd-stdio-bridge :1
-punix:path=${XDG_RUNTIME_DIR}/bus.
Jul 09 01:00:16 HOSTNAME-DELETED audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-u160 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:16 HOSTNAME-DELETED audit[274473]: USER_ACCT pid=274473 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:accounting grantors=pam_unix,pam_localuser acct="gdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:16 HOSTNAME-DELETED audit[274473]: CRED_ACQ pid=274473 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="gdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:16 HOSTNAME-DELETED audit[274473]: USER_ROLE_CHANGE pid=274473 uid=0 auid=42 ses=29 subj=system_u:system_r:init_t:s0 msg='pam: default-context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 selected-context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED audit[274474]: USER_ACCT pid=274474 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:accounting grantors=pam_unix,pam_localuser acct="USENAME-DELETED" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED audit[274474]: CRED_ACQ pid=274474 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="USENAME-DELETED" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED audit[274474]: USER_ROLE_CHANGE pid=274474 uid=0 auid=1000 ses=30 subj=system_u:system_r:init_t:s0 msg='pam: default-context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 selected-context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: Started session-29.scope - Session 29 of User gdm.
Jul 09 01:00:17 HOSTNAME-DELETED (o-bridge)[274473]: pam_unix(login:session): session opened for user gdm(uid=42) by (uid=0)
Jul 09 01:00:17 HOSTNAME-DELETED audit[274473]: USER_START pid=274473 uid=0 auid=42 ses=29 subj=system_u:system_r:init_t:s0 msg='op=PAM:session_open grantors=pam_selinux,pam_loginuid,pam_selinux,pam_namespace,pam_keyinit,pam_keyinit,pam_limits,pam_systemd,pam_unix,pam_umask,pam_lastlog acct="gdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1071]: Reloading requested from client PID 274473 ('systemd-stdio-b')...
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1071]: Reloading...
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: Started session-30.scope - Session 30 of User USENAME-DELETED.
Jul 09 01:00:17 HOSTNAME-DELETED (o-bridge)[274474]: pam_unix(login:session): session opened for user USENAME-DELETED(uid=1000) by (uid=0)
Jul 09 01:00:17 HOSTNAME-DELETED audit[274474]: USER_START pid=274474 uid=0 auid=1000 ses=30 subj=system_u:system_r:init_t:s0 msg='op=PAM:session_open grantors=pam_selinux,pam_loginuid,pam_selinux,pam_namespace,pam_keyinit,pam_keyinit,pam_limits,pam_systemd,pam_unix,pam_umask,pam_lastlog acct="USENAME-DELETED" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1989]: Created slice session.slice - User Core Session Slice.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1989]: Starting dbus-broker.service - D-Bus User Message Bus...
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker-launch[274490]: Service file '/usr/share//dbus-1/services/org.xfce.Tumbler.Cache1.service' is not named after the D-Bus name 'org.freedesktop.thumbnails.Cache1'.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker-launch[274490]: Policy to allow eavesdropping in /usr/share/dbus-1/session.conf +31: Eavesdropping is deprecated and ignored
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker-launch[274490]: Policy to allow eavesdropping in /usr/share/dbus-1/session.conf +33: Eavesdropping is deprecated and ignored
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker-launch[274490]: Service file '/usr/share//dbus-1/services/imsettings-daemon.service' is not named after the D-Bus name 'com.redhat.imsettings'.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker-launch[274490]: Service file '/usr/share//dbus-1/services/org.xfce.Thunar.FileManager1.service' is not named after the D-Bus name 'org.freedesktop.FileManager1'.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker-launch[274490]: Ignoring duplicate name 'org.freedesktop.FileManager1' in service file '/usr/share//dbus-1/services/org.xfce.Thunar.FileManager1.service'
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker-launch[274490]: Service file '/usr/share//dbus-1/services/org.xfce.Tumbler.Manager1.service' is not named after the D-Bus name 'org.freedesktop.thumbnails.Manager1'.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker-launch[274490]: Service file '/usr/share//dbus-1/services/org.xfce.Tumbler.Thumbnailer1.service' is not named after the D-Bus name 'org.freedesktop.thumbnails.Thumbnailer1'.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1989]: Started dbus-broker.service - D-Bus User Message Bus.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker-launch[274490]: Ready
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1989]: Reloading requested from client PID 274474 ('systemd-stdio-b')...
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1989]: Reloading...
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1071]: Reloading finished in 272 ms.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker[1152]: Peer :1.9 is being disconnected as it sent a message with an invalid header.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: run-u159.service: Deactivated successfully.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker[934]: A security policy denied :1.163 to send method call /org/freedesktop/login1:org.freedesktop.login1.Manager.ReleaseSession to org.freedesktop.login1.
Jul 09 01:00:17 HOSTNAME-DELETED (sd-pam)[274480]: pam_systemd(login:session): Failed to release session: Access denied
Jul 09 01:00:17 HOSTNAME-DELETED (sd-pam)[274480]: pam_unix(login:session): session closed for user gdm
Jul 09 01:00:17 HOSTNAME-DELETED audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-u159 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: session-29.scope: Deactivated successfully.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1989]: Reloading finished in 297 ms.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker[274495]: Peer :1.0 is being disconnected as it sent a message with an invalid header.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: run-u160.service: Deactivated successfully.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker[934]: A security policy denied :1.164 to send method call /org/freedesktop/login1:org.freedesktop.login1.Manager.ReleaseSession to org.freedesktop.login1.
Jul 09 01:00:17 HOSTNAME-DELETED (sd-pam)[274486]: pam_systemd(login:session): Failed to release session: Access denied
Jul 09 01:00:17 HOSTNAME-DELETED (sd-pam)[274486]: pam_unix(login:session): session closed for user USENAME-DELETED
Jul 09 01:00:17 HOSTNAME-DELETED audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-u160 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: session-30.scope: Deactivated successfully.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: Started run-u165.service - systemd-stdio-bridge -punix:path=${XDG_RUNTIME_DIR}/bus.
Jul 09 01:00:17 HOSTNAME-DELETED audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-u165 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: Started run-u166.service - systemd-stdio-bridge -punix:path=${XDG_RUNTIME_DIR}/bus.
Jul 09 01:00:17 HOSTNAME-DELETED audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-u166 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED audit[274581]: USER_ACCT pid=274581 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:accounting grantors=pam_unix,pam_localuser acct="gdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED audit[274581]: CRED_ACQ pid=274581 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="gdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED audit[274580]: USER_ACCT pid=274580 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:accounting grantors=pam_unix,pam_localuser acct="USENAME-DELETED" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED audit[274580]: CRED_ACQ pid=274580 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='op=PAM:setcred grantors=pam_env,pam_fprintd acct="USENAME-DELETED" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED audit[274581]: USER_ROLE_CHANGE pid=274581 uid=0 auid=42 ses=31 subj=system_u:system_r:init_t:s0 msg='pam: default-context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 selected-context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED audit[274580]: USER_ROLE_CHANGE pid=274580 uid=0 auid=1000 ses=32 subj=system_u:system_r:init_t:s0 msg='pam: default-context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 selected-context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: Started session-32.scope - Session 32 of User USENAME-DELETED.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: Started session-31.scope - Session 31 of User gdm.
Jul 09 01:00:17 HOSTNAME-DELETED (o-bridge)[274580]: pam_unix(login:session): session opened for user USENAME-DELETED(uid=1000) by (uid=0)
Jul 09 01:00:17 HOSTNAME-DELETED audit[274580]: USER_START pid=274580 uid=0 auid=1000 ses=32 subj=system_u:system_r:init_t:s0 msg='op=PAM:session_open grantors=pam_selinux,pam_loginuid,pam_selinux,pam_namespace,pam_keyinit,pam_keyinit,pam_limits,pam_systemd,pam_unix,pam_umask,pam_lastlog acct="USENAME-DELETED" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED (o-bridge)[274581]: pam_unix(login:session): session opened for user gdm(uid=42) by (uid=0)
Jul 09 01:00:17 HOSTNAME-DELETED audit[274581]: USER_START pid=274581 uid=0 auid=42 ses=31 subj=system_u:system_r:init_t:s0 msg='op=PAM:session_open grantors=pam_selinux,pam_loginuid,pam_selinux,pam_namespace,pam_keyinit,pam_keyinit,pam_limits,pam_systemd,pam_unix,pam_umask,pam_lastlog acct="gdm" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1989]: Queuing reload/restart jobs for marked units…
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: run-u165.service: Deactivated successfully.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker[274495]: Peer :1.3 is being disconnected as it sent a message with an invalid header.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker[934]: A security policy denied :1.169 to send method call /org/freedesktop/login1:org.freedesktop.login1.Manager.ReleaseSession to org.freedesktop.login1.
Jul 09 01:00:17 HOSTNAME-DELETED (sd-pam)[274593]: pam_systemd(login:session): Failed to release session: Access denied
Jul 09 01:00:17 HOSTNAME-DELETED (sd-pam)[274593]: pam_unix(login:session): session closed for user USENAME-DELETED
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1071]: Queuing reload/restart jobs for marked units…
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker[1152]: Peer :1.10 is being disconnected as it sent a message with an invalid header.
Jul 09 01:00:17 HOSTNAME-DELETED dbus-broker[934]: A security policy denied :1.170 to send method call /org/freedesktop/login1:org.freedesktop.login1.Manager.ReleaseSession to org.freedesktop.login1.
Jul 09 01:00:17 HOSTNAME-DELETED (sd-pam)[274596]: pam_systemd(login:session): Failed to release session: Access denied
Jul 09 01:00:17 HOSTNAME-DELETED (sd-pam)[274596]: pam_unix(login:session): session closed for user gdm
Jul 09 01:00:17 HOSTNAME-DELETED audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-u165 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: run-u166.service: Deactivated successfully.
Jul 09 01:00:17 HOSTNAME-DELETED audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-u166 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: session-31.scope: Deactivated successfully.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: session-32.scope: Deactivated successfully.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: Started run-r8b0e5467a09c4de68d6a0d85d9aa7e1d.service - /usr/bin/systemctl start man-db-cache-update.
Jul 09 01:00:17 HOSTNAME-DELETED audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-r8b0e5467a09c4de68d6a0d85d9aa7e1d comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: man-db-cache-update.service: Deactivated successfully.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: Finished man-db-cache-update.service.
Jul 09 01:00:17 HOSTNAME-DELETED audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=man-db-cache-update comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=man-db-cache-update comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: man-db-cache-update.service: Consumed 1.538s CPU time.
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: run-r2f40afd8532944e7946b8dcf5f8a8632.service: Deactivated successfully.
Jul 09 01:00:17 HOSTNAME-DELETED audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-r2f40afd8532944e7946b8dcf5f8a8632 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:17 HOSTNAME-DELETED systemd[1]: run-r8b0e5467a09c4de68d6a0d85d9aa7e1d.service: Deactivated successfully.
Jul 09 01:00:18 HOSTNAME-DELETED audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=run-r8b0e5467a09c4de68d6a0d85d9aa7e1d comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:18 HOSTNAME-DELETED systemd[1]: Starting packagekit.service - PackageKit Daemon...
Jul 09 01:00:18 HOSTNAME-DELETED PackageKit[274627]: daemon start
Jul 09 01:00:18 HOSTNAME-DELETED systemd[1]: Started packagekit.service - PackageKit Daemon.
Jul 09 01:00:18 HOSTNAME-DELETED audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=packagekit comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: The following updates have been applied on 'HOSTNAME-DELETED':
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: ================================================================================
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: Package Arch Version Repo Size
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: ================================================================================
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: Upgrading:
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: aardvark-dns x86_64 1.7.0-1.fc38 updates 907 k
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: eog x86_64 44.3-1.fc38 updates 1.6 M
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: netavark x86_64 1.7.0-1.fc38 updates 3.0 M
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: pipewire x86_64 0.3.73-1.fc38 updates 107 k
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: pipewire-alsa x86_64 0.3.73-1.fc38 updates 63 k
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: pipewire-gstreamer x86_64 0.3.73-1.fc38 updates 64 k
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: pipewire-jack-audio-connection-kit x86_64 0.3.73-1.fc38 updates 16 k
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: pipewire-jack-audio-connection-kit-libs x86_64 0.3.73-1.fc38 updates 139 k
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: pipewire-libs x86_64 0.3.73-1.fc38 updates 1.8 M
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: pipewire-pulseaudio x86_64 0.3.73-1.fc38 updates 172 k
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: Transaction Summary
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: ================================================================================
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: Upgrade 10 Packages
Jul 09 01:00:18 HOSTNAME-DELETED dnf-automatic[274315]: Updates completed at Sun 09 Jul 2023 01:00:18
Jul 09 01:00:18 HOSTNAME-DELETED systemd[1]: dnf-automatic.service: Deactivated successfully.
Jul 09 01:00:18 HOSTNAME-DELETED systemd[1]: Finished dnf-automatic.service - dnf automatic.
Jul 09 01:00:18 HOSTNAME-DELETED audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=dnf-automatic comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:18 HOSTNAME-DELETED audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=dnf-automatic comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 09 01:00:18 HOSTNAME-DELETED systemd[1]: dnf-automatic.service: Consumed 13.006s CPU time.
Jul 09 01:01:01 HOSTNAME-DELETED CROND[274634]: (root) CMD (run-parts /etc/cron.hourly)
Jul 09 01:01:01 HOSTNAME-DELETED run-parts[274637]: (/etc/cron.hourly) starting 0anacron
Jul 09 01:01:01 HOSTNAME-DELETED anacron[274645]: Anacron started on 2023-07-09
Jul 09 01:01:01 HOSTNAME-DELETED anacron[274645]: Normal exit (0 jobs run)
Jul 09 01:01:01 HOSTNAME-DELETED run-parts[274647]: (/etc/cron.hourly) finished 0anacron
Jul 09 01:01:01 HOSTNAME-DELETED CROND[274633]: (root) CMDEND (run-parts /etc/cron.hourly)
See log above... The /usr/local/etc/monitor/checkset script run at 1am does a "shell set command" & compares it with that obtained last night. Note that there is only one user that is also logged in through ssh (4 windows) at that time. (I wish I knew what the systemd-stdio-bridge things were actually doing) The hostname is replaced with HOSTNAME-DELETED & the "user" is relaced with USERNAME-DELETED |
Nightly error on systemd restart... (sd-pam): pam_systemd(login:session): Failed to release session: Access denied Each night just after 1am systemd seems to do a "restart" which results in the "error"... (sd-pam): pam_systemd(login:session): Failed to release session: Access denied a number of times in quick succession (4 each night on some machines & only 2 on another) There are no selinux errors at this time. Reproducible: Always Steps to Reproduce: 1. Watch the systemd/secure logs 2. 3. Actual Results: The above unexplained error. Expected Results: Either no error or a detailed understanding of why it is occurring.