Bug 1734831 - SELinux is preventing (modprobe) from create access on the directory linger
Summary: SELinux is preventing (modprobe) from create access on the directory linger
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: selinux-policy
Version: rawhide
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ---
Assignee: Lukas Vrabec
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 1735481 1737188 1737189 1737193 1737886 (view as bug list)
Depends On:
Blocks: BetaBlocker, F31BetaBlocker
TreeView+ depends on / blocked
 
Reported: 2019-07-31 14:50 UTC by Lukas Slebodnik
Modified: 2019-08-08 21:48 UTC (History)
17 users (show)

Fixed In Version: selinux-policy-3.14.4-28.fc31
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-08-08 11:45:36 UTC


Attachments (Terms of Use)

Description Lukas Slebodnik 2019-07-31 14:50:47 UTC
*****  Plugin catchall (100. confidence) suggests   **************************

If you believe that (modprobe) should be allowed create access on the linger directory by default.
Then you should report this as a bug.
You can generate a local policy module to allow this access.
Do
allow this access for now by executing:
# ausearch -c '(modprobe)' --raw | audit2allow -M my-modprobe
# semodule -X 300 -i my-modprobe.pp


Additional Information:
Source Context                system_u:system_r:init_t:s0
Target Context                system_u:object_r:systemd_logind_var_lib_t:s0
Target Objects                linger [ dir ]
Source                        (modprobe)
Source Path                   (modprobe)
Port                          <Unknown>
Host                          host.example.com
Source RPM Packages           
Target RPM Packages           
Policy RPM                    selinux-policy-3.14.4-26.fc31.noarch
Selinux Enabled               True
Policy Type                   targeted
Enforcing Mode                Permissive
Host Name                     host.example.com
Platform                      Linux host.example.com
                              5.3.0-0.rc2.git1.1.fc31.x86_64 #1 SMP Tue Jul 30
                              12:35:29 UTC 2019 x86_64 x86_64
Alert Count                   1
First Seen                    2019-07-31 13:20:10 CEST
Last Seen                     2019-07-31 13:20:10 CEST
Local ID                      2b81fad4-dd97-42e1-894f-4f9a1fa48cb6

Raw Audit Messages
type=AVC msg=audit(1564572010.976:83): avc:  denied  { create } for  pid=705 comm="(modprobe)" name="linger" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=1


Hash: (modprobe),init_t,systemd_logind_var_lib_t,dir,create

Comment 1 Lukas Slebodnik 2019-07-31 14:54:27 UTC
All AVCs in permissive mode

Jul 31 13:20:10 host.example.com systemd[1]: Starting Login Service...
Jul 31 13:20:10 host.example.com audit[705]: AVC avc:  denied  { create } for  pid=705 comm="(modprobe)" name="linger" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=1
Jul 31 13:20:10 host.example.com audit[705]: AVC avc:  denied  { read } for  pid=705 comm="(modprobe)" name="linger" dev="dm-0" ino=8642970 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=1
Jul 31 13:20:10 host.example.com systemd[1]: Starting Permit User Sessions...
Jul 31 13:20:11 host.example.com audit[705]: AVC avc:  denied  { mounton } for  pid=705 comm="(modprobe)" path="/run/systemd/unit-root/var/lib/systemd/linger" dev="dm-0" ino=8642970 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=1
Jul 31 13:20:11 host.example.com systemd[1]: Started Permit User Sessions.
Jul 31 13:20:11 host.example.com audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-user-sessions comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'

Comment 2 Lukas Slebodnik 2019-07-31 14:57:59 UTC
Guys,
could you explain what systemd is trying to do here?

Comment 3 Zbigniew Jędrzejewski-Szmek 2019-07-31 15:53:00 UTC
systemd-logind.service runs in a private mount namespace with certain things bind-mounted into its root to make them read-write.
Paths are first arranged under /run/systemd/unit-root/ and then moved over /.
This is done by a forked-off child of PID1 before execve into the target daemon.

$ grep linger /proc/$(systemctl show --value -p MainPID systemd-logind)/mountinfo
635 592 253:1 /var/lib/systemd/linger /var/lib/systemd/linger rw,relatime shared:357 master:1 - ext4 /dev/mapper/fedora_krowka-root rw,seclabel

I don't know why comm="(modprobe)" is shown. This doesn't make much sense.

Comment 4 Zbigniew Jędrzejewski-Szmek 2019-08-01 06:06:21 UTC
*** Bug 1735481 has been marked as a duplicate of this bug. ***

Comment 5 Lukas Vrabec 2019-08-01 15:37:33 UTC
Hi Michal,
Could you please take a look on this issue? We need to understand what's going on systemd side. 

Thanks,
Lukas.

Comment 6 Zbigniew Jędrzejewski-Szmek 2019-08-01 16:14:45 UTC
I'm not the addressee, but I don't quite grok the question. What is unclear on the systemd side?

Comment 7 Lukas Slebodnik 2019-08-01 19:15:07 UTC
Here is a debug log in permissive mode

Aug 01 18:58:27 host.example.com systemd[1]: systemd-logind.service: About to execute: /sbin/modprobe -abq drm
Aug 01 18:58:27 host.example.com systemd[1]: systemd-logind.service: Forked /sbin/modprobe as 702
Aug 01 18:58:27 host.example.com systemd[1]: systemd-logind.service: Changed dead -> start-pre
Aug 01 18:58:27 host.example.com systemd[1]: Starting Login Service...
Aug 01 18:58:27 host.example.com systemd[1]: systemd-user-sessions.service: Passing 0 fds to service
Aug 01 18:58:27 host.example.com systemd[1]: systemd-user-sessions.service: About to execute: /usr/lib/systemd/systemd-user-sessions start
Aug 01 18:58:27 host.example.com systemd[1]: systemd-user-sessions.service: Forked /usr/lib/systemd/systemd-user-sessions as 703
Aug 01 18:58:27 host.example.com systemd[1]: systemd-user-sessions.service: Changed dead -> start
Aug 01 18:58:27 host.example.com systemd[1]: Starting Permit User Sessions...
Aug 01 18:58:27 host.example.com audit[702]: AVC avc:  denied  { create } for  pid=702 comm="(modprobe)" name="linger" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=1
Aug 01 18:58:27 host.example.com audit[702]: SYSCALL arch=c000003e syscall=83 success=yes exit=0 a0=561c368e9590 a1=1ed a2=0 a3=0 items=2 ppid=1 pid=702 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(modprobe)" exe="/usr/lib/systemd/systemd" subj=system_u:system_r:init_t:s0 key=(null)
Aug 01 18:58:27 host.example.com audit: CWD cwd="/"
Aug 01 18:58:27 host.example.com audit: PATH item=0 name="/var/lib/systemd/" inode=8604425 dev=fd:00 mode=040755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:init_var_lib_t:s0 nametype=PARENT cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Aug 01 18:58:27 host.example.com audit: PATH item=1 name="/var/lib/systemd/linger" inode=8604440 dev=fd:00 mode=040755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:systemd_logind_var_lib_t:s0 nametype=CREATE cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Aug 01 18:58:27 host.example.com audit: PROCTITLE proctitle="(modprobe)"
Aug 01 18:58:27 host.example.com audit[702]: AVC avc:  denied  { read } for  pid=702 comm="(modprobe)" name="linger" dev="dm-0" ino=8604440 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=1
Aug 01 18:58:27 host.example.com audit[702]: SYSCALL arch=c000003e syscall=257 success=yes exit=3 a0=ffffff9c a1=561c368e9590 a2=f0000 a3=0 items=1 ppid=1 pid=702 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(modprobe)" exe="/usr/lib/systemd/systemd" subj=system_u:system_r:init_t:s0 key=(null)
Aug 01 18:58:27 host.example.com audit: CWD cwd="/"
Aug 01 18:58:27 host.example.com audit: PATH item=0 name="/var/lib/systemd/linger" inode=8604440 dev=fd:00 mode=040755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:systemd_logind_var_lib_t:s0 nametype=NORMAL cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Aug 01 18:58:27 host.example.com audit: PROCTITLE proctitle="(modprobe)"
Aug 01 18:58:27 host.example.com systemd[702]: /run/systemd/unit-root/dev (rw-implicit) is duplicate.
Aug 01 18:58:27 host.example.com systemd[702]: /run/systemd/unit-root/home (rw-implicit) is duplicate.
Aug 01 18:58:27 host.example.com systemd[702]: /run/systemd/unit-root/proc (rw-implicit) is duplicate.
Aug 01 18:58:27 host.example.com systemd[702]: /run/systemd/unit-root/root (rw-implicit) is duplicate.
Aug 01 18:58:27 host.example.com systemd[702]: /run/systemd/unit-root/run/user (rw-implicit) is duplicate.
Aug 01 18:58:27 host.example.com systemd[702]: /run/systemd/unit-root/sys (rw-implicit) is duplicate.
Aug 01 18:58:27 host.example.com systemd[702]: Applying namespace mount on /run/systemd/unit-root/
Aug 01 18:58:27 host.example.com systemd[702]: Applying namespace mount on /run/systemd/unit-root/dev
Aug 01 18:58:27 host.example.com systemd[702]: Applying namespace mount on /run/systemd/unit-root/etc
Aug 01 18:58:27 host.example.com systemd[702]: Successfully mounted /run/systemd/unit-root/etc to /run/systemd/unit-root/etc
Aug 01 18:58:27 host.example.com systemd[702]: Applying namespace mount on /run/systemd/unit-root/home
Aug 01 18:58:27 host.example.com systemd[1]: systemd-journald.service: Got notification message from PID 537 (FDSTORE=1)
Aug 01 18:58:27 host.example.com systemd[1]: systemd-journald.service: Added fd 64 (n/a) to fd store.
Aug 01 18:58:27 host.example.com systemd[703]: systemd-user-sessions.service: Executing: /usr/lib/systemd/systemd-user-sessions start
Aug 01 18:58:27 host.example.com systemd[702]: Successfully mounted /run/systemd/inaccessible/dir to /run/systemd/unit-root/home
Aug 01 18:58:27 host.example.com systemd[702]: Applying namespace mount on /run/systemd/unit-root/proc
Aug 01 18:58:27 host.example.com systemd[1]: systemd-journald.service: Got notification message from PID 537 (FDSTORE=1)
Aug 01 18:58:27 host.example.com systemd[1]: systemd-journald.service: Added fd 65 (n/a) to fd store.
Aug 01 18:58:27 host.example.com systemd[702]: Applying namespace mount on /run/systemd/unit-root/proc/sys/kernel/domainname
Aug 01 18:58:27 host.example.com systemd[702]: Successfully mounted /run/systemd/unit-root/proc/sys/kernel/domainname to /run/systemd/unit-root/proc/sys/kernel/domainname
Aug 01 18:58:27 host.example.com systemd[702]: Applying namespace mount on /run/systemd/unit-root/proc/sys/kernel/hostname
Aug 01 18:58:27 host.example.com systemd[702]: Successfully mounted /run/systemd/unit-root/proc/sys/kernel/hostname to /run/systemd/unit-root/proc/sys/kernel/hostname
Aug 01 18:58:27 host.example.com systemd[702]: Applying namespace mount on /run/systemd/unit-root/root
Aug 01 18:58:27 host.example.com systemd[702]: Successfully mounted /run/systemd/inaccessible/dir to /run/systemd/unit-root/root

Comment 8 Lukas Slebodnik 2019-08-01 19:19:48 UTC
And here from enforcind mode

Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: About to execute: /sbin/modprobe -abq drm
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Forked /sbin/modprobe as 685
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Changed dead -> start-pre
Aug 01 19:02:35 host.example.com systemd[1]: Starting Login Service...
Aug 01 19:02:35 host.example.com audit[685]: AVC avc:  denied  { create } for  pid=685 comm="(modprobe)" name="linger" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=0
Aug 01 19:02:35 host.example.com systemd[1]: systemd-user-sessions.service: Passing 0 fds to service
Aug 01 19:02:35 host.example.com audit[685]: SYSCALL arch=c000003e syscall=83 success=no exit=-13 a0=5576d8947aa0 a1=1ed a2=0 a3=0 items=2 ppid=1 pid=685 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(modprobe)" exe="/usr/lib/systemd/systemd" subj=system_u:system_r:init_t:s0 key=(null)
Aug 01 19:02:35 host.example.com audit: CWD cwd="/"
Aug 01 19:02:35 host.example.com audit: PATH item=0 name="/var/lib/systemd/" inode=8605833 dev=fd:00 mode=040755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:init_var_lib_t:s0 nametype=PARENT cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Aug 01 19:02:35 host.example.com audit: PATH item=1 name="/var/lib/systemd/linger" nametype=CREATE cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Aug 01 19:02:35 host.example.com audit: PROCTITLE proctitle="(modprobe)"
Aug 01 19:02:35 host.example.com systemd[685]: systemd-logind.service: Failed to set up special execution directory in /var/lib: Permission denied
Aug 01 19:02:35 host.example.com systemd[685]: systemd-logind.service: Failed at step (null) spawning /sbin/modprobe: Permission denied
Aug 01 19:02:35 host.example.com systemd[1]: systemd-user-sessions.service: About to execute: /usr/lib/systemd/systemd-user-sessions start
Aug 01 19:02:35 host.example.com systemd[1]: systemd-user-sessions.service: Forked /usr/lib/systemd/systemd-user-sessions as 686
Aug 01 19:02:35 host.example.com systemd[1]: systemd-user-sessions.service: Changed dead -> start
Aug 01 19:02:35 host.example.com systemd[1]: Starting Permit User Sessions...
Aug 01 19:02:35 host.example.com systemd[1]: systemd-journald.service: Got notification message from PID 523 (FDSTORE=1)
Aug 01 19:02:35 host.example.com systemd[1]: systemd-journald.service: Added fd 64 (n/a) to fd store.
Aug 01 19:02:35 host.example.com systemd[1]: Received SIGCHLD from PID 685 ((modprobe)).
Aug 01 19:02:35 host.example.com systemd[1]: Child 685 ((modprobe)) died (code=exited, status=238/n/a)
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Failed to read oom_kill field of memory.events cgroup attribute: No such file or directory
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Child 685 belongs to systemd-logind.service.
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Control process exited, code=exited, status=238/n/a
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Got final SIGCHLD for state start-pre.
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Passing 0 fds to service
Aug 01 19:02:35 host.example.com systemd[686]: systemd-user-sessions.service: Executing: /usr/lib/systemd/systemd-user-sessions start
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: About to execute: /usr/lib/systemd/systemd-logind
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Forked /usr/lib/systemd/systemd-logind as 687
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Changed start-pre -> start
Aug 01 19:02:35 host.example.com audit[687]: AVC avc:  denied  { create } for  pid=687 comm="(d-logind)" name="linger" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=0
Aug 01 19:02:35 host.example.com systemd[1]: systemd-journald.service: Got notification message from PID 523 (FDSTORE=1)
Aug 01 19:02:35 host.example.com audit[687]: SYSCALL arch=c000003e syscall=83 success=no exit=-13 a0=5576d8943da0 a1=1ed a2=0 a3=0 items=2 ppid=1 pid=687 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(d-logind)" exe="/usr/lib/systemd/systemd" subj=system_u:system_r:init_t:s0 key=(null)
Aug 01 19:02:35 host.example.com systemd[1]: systemd-journald.service: Added fd 65 (n/a) to fd store.
Aug 01 19:02:35 host.example.com audit: CWD cwd="/"
Aug 01 19:02:35 host.example.com audit: PATH item=0 name="/var/lib/systemd/" inode=8605833 dev=fd:00 mode=040755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:init_var_lib_t:s0 nametype=PARENT cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Aug 01 19:02:35 host.example.com audit: PATH item=1 name="/var/lib/systemd/linger" nametype=CREATE cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Aug 01 19:02:35 host.example.com audit: PROCTITLE proctitle="(d-logind)"
Aug 01 19:02:35 host.example.com systemd[687]: systemd-logind.service: Failed to set up special execution directory in /var/lib: Permission denied

//snip

Aug 01 19:02:35 host.example.com systemd-user-sessions[686]: Successfully loaded SELinux database in 25.454ms, size on heap is 328K.
Aug 01 19:02:36 host.example.com audit[691]: AVC avc:  denied  { create } for  pid=691 comm="(d-logind)" name="linger" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:syst
emd_logind_var_lib_t:s0 tclass=dir permissive=0
Aug 01 19:02:36 host.example.com audit[691]: SYSCALL arch=c000003e syscall=83 success=no exit=-13 a0=5576d891e0b0 a1=1ed a2=0 a3=0 items=2 ppid=1 pid=691 auid=4294967295 uid=0 gid=0 euid=
0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="(d-logind)" exe="/usr/lib/systemd/systemd" subj=system_u:system_r:init_t:s0 key=(null)
Aug 01 19:02:36 host.example.com audit: CWD cwd="/"
Aug 01 19:02:36 host.example.com audit: PATH item=0 name="/var/lib/systemd/" inode=8605833 dev=fd:00 mode=040755 ouid=0 ogid=0 rdev=00:00 obj=system_u:object_r:init_var_lib_t:s0 nametype=
PARENT cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Aug 01 19:02:36 host.example.com audit: PATH item=1 name="/var/lib/systemd/linger" nametype=CREATE cap_fp=0 cap_fi=0 cap_fe=0 cap_fver=0 cap_frootid=0
Aug 01 19:02:36 host.example.com audit: PROCTITLE proctitle="(d-logind)"
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Installed new job systemd-logind.service/restart as 416
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Enqueued job systemd-logind.service/restart as 416
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Scheduled restart job, restart counter is at 1.
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Changed auto-restart -> dead
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Job 416 systemd-logind.service/restart finished, result=done
Aug 01 19:02:35 host.example.com systemd[1]: Stopped Login Service.
Aug 01 19:02:35 host.example.com systemd[1]: systemd-logind.service: Converting job systemd-logind.service/restart -> systemd-logind.service/start
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: About to execute: /sbin/modprobe -abq drm
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: Forked /sbin/modprobe as 690
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: Changed dead -> start-pre
Aug 01 19:02:36 host.example.com systemd[1]: Starting Login Service...
Aug 01 19:02:36 host.example.com systemd[1]: Received SIGCHLD from PID 686 (systemd-user-se).
Aug 01 19:02:36 host.example.com systemd[1]: Child 686 (systemd-user-se) died (code=exited, status=0/n/a)
Aug 01 19:02:36 host.example.com systemd[1]: systemd-user-sessions.service: Failed to read oom_kill field of memory.events cgroup attribute: No such file or directory
Aug 01 19:02:36 host.example.com systemd[1]: systemd-user-sessions.service: Child 686 belongs to systemd-user-sessions.service.
Aug 01 19:02:36 host.example.com systemd[1]: systemd-user-sessions.service: Main process exited, code=exited, status=0/n/a
Aug 01 19:02:36 host.example.com systemd[690]: systemd-logind.service: Failed to set up special execution directory in /var/lib: Permission denied
Aug 01 19:02:36 host.example.com systemd[690]: systemd-logind.service: Failed at step (null) spawning /sbin/modprobe: Permission denied
Aug 01 19:02:36 host.example.com systemd[1]: systemd-user-sessions.service: Changed start -> exited
Aug 01 19:02:36 host.example.com systemd[1]: systemd-user-sessions.service: Job 219 systemd-user-sessions.service/start finished, result=done
Aug 01 19:02:36 host.example.com systemd[1]: Started Permit User Sessions.
Aug 01 19:02:36 host.example.com systemd[1]: systemd-journald.service: Got notification message from PID 523 (FDSTORE=1)
Aug 01 19:02:36 host.example.com systemd[1]: systemd-journald.service: Added fd 64 (n/a) to fd store.
Aug 01 19:02:36 host.example.com systemd[1]: Child 690 ((modprobe)) died (code=exited, status=238/n/a)
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: Failed to read oom_kill field of memory.events cgroup attribute: No such file or directory
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: Child 690 belongs to systemd-logind.service.
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: Control process exited, code=exited, status=238/n/a
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: Got final SIGCHLD for state start-pre.
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: Passing 0 fds to service
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: About to execute: /usr/lib/systemd/systemd-logind
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: Forked /usr/lib/systemd/systemd-logind as 691
Aug 01 19:02:36 host.example.com systemd[1]: systemd-logind.service: Changed start-pre -> start
Aug 01 19:02:36 host.example.com systemd[1]: Received SIGCHLD from PID 690 (n/a).

Comment 9 dac.override 2019-08-04 19:37:13 UTC
systemd bind mounts all over the place

but there are generally two directives to consider:

BindPaths= and BindReadOnlyPaths=

you might consider a systemd_bind_path_type type attribute for this

what systemd does is

1. it bind mounts over the target (euther ro (BindReadOnlyPaths) or rw (BindPaths))

so youd get:

allow init_t systemd_bind_path_type:{dir file} mounton;

However to make things more complicated, systemd with create the target if it doesnt exist

(in the case of /var/lib/systemd/linger the target might not exist)

so systemd needs to be able to create the bind path target:

allow init_t systemd_bind_path_type:{dir file} { getattr create };

when bind path target is a dir then systemd needs to list it:

allow init_t systemd_bind_path_type:dir list_dir_perms;

Comment 10 dac.override 2019-08-04 19:40:13 UTC
and then make systemd_logind_var_lib_t a systemd_bind_path() (but you should probably revisit the whole policy because in the past you have been making these "mountpoint" which they arent.

systemd_bind_path(systemd_logind_var_lib_t)

Comment 11 MIBESIS 2019-08-04 21:39:53 UTC
Hi all,

I'm running F31 ( $ uname -a = Linux <hostname> 5.3.0-0.rc2.git4.1.fc31.x86_64 #1 SMP Fri Aug 2 13:10:34 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux ) and I get exact same error. It took me two days to locate exact error message in log files. As I am working on a DNS server I was focused on a DNS server related issues, but turned out different.

It all worked ( fresh setup ), than I was doing configuration modifications on a DNS ( and tested once ) as it all seemed to work, I've run a system update. When I realized login takes 25s.

I've found some old forum posts regarding D-Bus related timeout settings of 25s so it was geared toward that, but that was from 2015 and did not make much sense.

Anyhow, this is my error, that is found in: journalctl -xb


-- The job identifier is 5300 and the job result is done.
Aug 04 20:29:14 <hostname> systemd[1]: Starting Login Service...
-- Subject: A start job for unit systemd-logind.service has begun execution
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- A start job for unit systemd-logind.service has begun execution.
-- 
-- The job identifier is 5300.
Aug 04 20:29:14 <hostname> audit[1884]: AVC avc:  denied  { create } for  pid=1884 comm="(modprobe)" name="linger" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=0
Aug 04 20:29:14 <hostname> systemd[1884]: systemd-logind.service: Failed to set up special execution directory in /var/lib: Permission denied
Aug 04 20:29:14 <hostname> systemd[1884]: systemd-logind.service: Failed at step (null) spawning /sbin/modprobe: Permission denied
-- Subject: Process /sbin/modprobe could not be executed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- The process /sbin/modprobe could not be executed and failed.
-- 
-- The error number returned by this process is ERRNO.

Comment 12 MIBESIS 2019-08-04 21:45:40 UTC
$ dnf history list
ID     | Command line             | Date and time    | Action(s)      | Altered
-------------------------------------------------------------------------------
     7 | update                   | 2019-08-03 22:12 | I, U           |  252 EE

( CEST timezone )

Comment 13 MIBESIS 2019-08-04 22:00:50 UTC
I guess this is related: https://bugzilla.redhat.com/show_bug.cgi?id=1737193

Comment 14 Lukas Vrabec 2019-08-05 14:14:12 UTC
*** Bug 1737193 has been marked as a duplicate of this bug. ***

Comment 15 Lukas Vrabec 2019-08-05 14:15:54 UTC
*** Bug 1737189 has been marked as a duplicate of this bug. ***

Comment 16 Lukas Vrabec 2019-08-05 14:16:08 UTC
*** Bug 1737188 has been marked as a duplicate of this bug. ***

Comment 17 Lukas Vrabec 2019-08-05 16:24:15 UTC
commit cd63aff25446f708713cd6f9f65001e2b35b3427 (HEAD -> rawhide)
Author: Lukas Vrabec <lvrabec@redhat.com>
Date:   Mon Aug 5 18:18:03 2019 +0200

    Allow systemd to create and bindmount dirs.
    
    Add systemd_logind_var_lib_t to attribute systemd_mount_directory.
    Allow systemd create targets with labels part of systemd_mount_directory
    Resolves: rhbz#1734831



Adding fixes to Fedora Rawhide, thanks all of you for investigation.

Comment 18 Zbigniew Jędrzejewski-Szmek 2019-08-05 16:36:38 UTC
Lukas V., thanks!

Lukas S., thank you too. With your debug logs, it;s clear where the (modprobe) comes from:
> I don't know why comm="(modprobe)" is shown. This doesn't make much sense.
> systemd-logind.service: About to execute: /sbin/modprobe -abq drm

We added a modprobe in the systemd-loging.service file to work around another issue.
https://github.com/systemd/systemd/commit/11aa16bb35

Comment 19 dac.override 2019-08-05 16:41:39 UTC
(In reply to Lukas Vrabec from comment #17)
> commit cd63aff25446f708713cd6f9f65001e2b35b3427 (HEAD -> rawhide)
> Author: Lukas Vrabec <lvrabec@redhat.com>
> Date:   Mon Aug 5 18:18:03 2019 +0200
> 
>     Allow systemd to create and bindmount dirs.
>     
>     Add systemd_logind_var_lib_t to attribute systemd_mount_directory.
>     Allow systemd create targets with labels part of systemd_mount_directory
>     Resolves: rhbz#1734831
> 
> 
> 
> Adding fixes to Fedora Rawhide, thanks all of you for investigation.

dir is not enough, try it out:

setenforce 0
systemd-run -p BindReadOnlyPaths=/etc/virc /usr/bin/test
journalctl --since -10m --grep denied | less
-- Logs begin at Sun 2019-08-04 20:19:10 CEST, end at Mon 2019-08-05 18:35:14 CEST. --
Aug 05 18:34:47 agnusguest1 audit[1665]: AVC avc:  denied  { mounton } for  pid=1665 comm="(test)" path="/run/systemd/unit-root/etc/virc" dev="dm-0" ino=6644 scontext=sys.id:sys.role:systemd.system.subj:s0 tcontext=sys.id:sys.role:files.generic_config.config_file:s0 tclass=file permissive=1
Aug 05 18:34:47 agnusguest1 kernel: audit: type=1400 audit(1565022887.772:250): avc:  denied  { mounton } for  pid=1665 comm="(test)" path="/run/systemd/unit-root/etc/virc" dev="dm-0" ino=6644 scontext=sys.id:sys.role:systemd.system.subj:s0 tcontext=sys.id:sys.role:files.generic_config.config_file:s0 tclass=file permissive=1

Comment 20 dac.override 2019-08-05 16:54:38 UTC
(In reply to Zbigniew Jędrzejewski-Szmek from comment #18)
> Lukas V., thanks!
> 
> Lukas S., thank you too. With your debug logs, it;s clear where the
> (modprobe) comes from:
> > I don't know why comm="(modprobe)" is shown. This doesn't make much sense.
> > systemd-logind.service: About to execute: /sbin/modprobe -abq drm
> 
> We added a modprobe in the systemd-loging.service file to work around
> another issue.
> https://github.com/systemd/systemd/commit/11aa16bb35

Are you sure that this modprobe hack works? AFAICT it does not work (at least it does not work for me with nspawn/machinectl)

Comment 21 Zbigniew Jędrzejewski-Szmek 2019-08-05 17:06:32 UTC
> Are you sure that this modprobe hack works? AFAICT it does not work (at least it does not work for me with nspawn/machinectl)

If it doesn't work, open a separate bug report with some details and logs.

Comment 22 dac.override 2019-08-05 17:19:04 UTC
(In reply to Zbigniew Jędrzejewski-Szmek from comment #21)
> > Are you sure that this modprobe hack works? AFAICT it does not work (at least it does not work for me with nspawn/machinectl)
> 
> If it doesn't work, open a separate bug report with some details and logs.

Ok will see if i can reproduce it next time i reboot this machine.

Also the systemd 243 RC1 messes with the permissions on /dev/fuse

Comment 23 Zbigniew Jędrzejewski-Szmek 2019-08-05 17:24:06 UTC
> Also the systemd 243 RC1 messes with the permissions on /dev/fuse

Please stop dropping stuff like that in an unrelated bug. There are no details so this isn't
actionable in any way, but just makes noise in an unrelated bug report. There's 14 people in 
the CC list.

Comment 24 Lukas Slebodnik 2019-08-06 08:23:43 UTC
(In reply to Lukas Vrabec from comment #17)
> commit cd63aff25446f708713cd6f9f65001e2b35b3427 (HEAD -> rawhide)
> Author: Lukas Vrabec <lvrabec@redhat.com>
> Date:   Mon Aug 5 18:18:03 2019 +0200
> 
>     Allow systemd to create and bindmount dirs.
>     
>     Add systemd_logind_var_lib_t to attribute systemd_mount_directory.
>     Allow systemd create targets with labels part of systemd_mount_directory
>     Resolves: rhbz#1734831
> 
> 
> 
> Adding fixes to Fedora Rawhide, thanks all of you for investigation.

The changelog for 3.14.4-27 says it should fix this BZ

https://koji.fedoraproject.org/koji/buildinfo?buildID=1347557
* Mon Aug 05 2019 Lukas Vrabec <lvrabec@redhat.com> 
- 3.14.4-27 - Allow tlp domain run tlp in trace mode BZ(1737106) 
- Make timedatex_t domain system dbus bus client BZ(1737239) 
- Allow cgdcbxd_t domain to list cgroup dirs - Allow systemd to create and bindmount dirs. BZ(1734831)

However I can still see AVCs

SELinux status:                 enabled
SELinuxfs mount:                /sys/fs/selinux
SELinux root directory:         /etc/selinux
Loaded policy name:             targeted
Current mode:                   enforcing
Mode from config file:          enforcing
Policy MLS status:              enabled
Policy deny_unknown status:     allowed
Memory protection checking:     actual (secure)
Max kernel policy version:      31
selinux-policy-3.14.4-27.fc31.noarch
----
time->Tue Aug  6 07:56:31 2019
type=AVC msg=audit(1565070991.853:80): avc:  denied  { create } for  pid=701 comm="(modprobe)" name="linger" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=0
----
time->Tue Aug  6 07:56:31 2019
type=AVC msg=audit(1565070991.872:81): avc:  denied  { create } for  pid=703 comm="(d-logind)" name="linger" scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:systemd_logind_var_lib_t:s0 tclass=dir permissive=0

Lukas, Do you want to see AVCs also from permissive mode or comment 1 is enough.

Comment 25 dac.override 2019-08-06 08:41:53 UTC
The commit was not pushed to git

Comment 26 Lukas Vrabec 2019-08-06 10:05:19 UTC
Hi All, 

dac.override is right, sorry for that. 

I created new build:
https://koji.fedoraproject.org/koji/taskinfo?taskID=36829606


# rpm -q selinux-policy 
selinux-policy-3.14.4-28.fc31.noarch

# sesearch -A -s init_t -t systemd_logind_var_lib_t  -c dir -p create
allow init_t systemd_mount_directory:dir { create getattr ioctl lock mounton open read search };

# # seinfo -xasystemd_mount_directory

Type Attributes: 1
   attribute systemd_mount_directory;
	systemd_logind_var_lib_t


Lukas S. Could you please re-test this issue with the latest selinux-policy build for Rawhide? 

Thanks,
Lukas V.

Comment 27 Lukas Vrabec 2019-08-06 10:55:34 UTC
*** Bug 1737886 has been marked as a duplicate of this bug. ***

Comment 28 MIBESIS 2019-08-08 21:48:42 UTC
Hi all,

I've updated my Fedora yesterday, and it did not fix the problem.
I've updated my Fedora today, and it did fix the problem. It seems so, as login is working normal speed ( it does a bit more slow, due to DNS lookups but not related ).

I guess I will push this update to other nodes now.

Thanks for the quick fix and push.

Kind Regards,
Miroslav


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