Bug 1664143

Summary: Fedora KDE systemd stop process timeout on dbus
Product: [Fedora] Fedora Reporter: Paul Sadauskas <psadauskas>
Component: selinux-policy-targetedAssignee: Zdenek Pytela <zpytela>
Status: CLOSED ERRATA QA Contact: Ben Levenson <benl>
Severity: medium Docs Contact:
Priority: medium    
Version: 29CC: dwalsh, flaviohenriquedesousaribeiro, psadauskas, th4949
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-01-18 02:14:06 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Paul Sadauskas 2019-01-07 20:16:04 UTC
Description of problem:

When shutting down or rebooting, one of the systemd stop jobs hangs until the 90s timeout and gets killed. Looking at the log, I find:

```
Jan 07 12:55:25 boyd systemd[1]: session-12.scope: Stopping timed out. Killing.
Jan 07 12:55:25 boyd systemd[1]: session-12.scope: Killing process 13352 (dbus-daemon) with signal SIGKILL.
Jan 07 12:55:25 boyd org.a11y.Bus[13338]: Failed to launch bus: Failed to execute child process ?/usr/bin/dbus-broker-launch? (No such file or directory)
Jan 07 12:55:25 boyd systemd[1]: session-12.scope: Failed with result 'timeout'.
```

I do not have a `/usr/bin/dbus-broker-launch` file, and the only reference I can find for it on my system is in `/usr/share/selinux/targeted/default/active/file_contexts` on line 5543:

```
/usr/bin/dbus-broker-launch    --  system_u:object_r:dbusd_exec_t:s0
```

That selinux file is owned by selinux-policy-targeted`

```
$ rpm -qf /usr/share/selinux/targeted/default/active/file_contexts
selinux-policy-targeted-3.14.2-44.fc29.noarch
```

`/usr/bin/dbus-broker-launch` is provided by by `dbus-broker-16-1.fc29.x86_64`, which I do not have installed.

```
$ dnf provides /usr/bin/dbus-broker-launch
dbus-broker-16-1.fc29.x86_64 : Linux D-Bus Message Broker
Repo        : updates
Matched from:
Filename    : /usr/bin/dbus-broker-launch

dbus-broker-15-2.fc29.1.x86_64 : Linux D-Bus Message Broker
Repo        : fedora
Matched from:
Filename    : /usr/bin/dbus-broker-launch
```

I'm not sure which component is at fault, and I'm not sure if the right thing to do is to install dbus-broker. If its needed, does it need to be installed by default?


Version-Release number of selected component (if applicable):

Fedora KDE spin
selinux-policy-targeted-3.14.2-44.fc29.noarch


How reproducible:

Happens on every reboot for me.


Steps to Reproduce:
1. Install Fedora 29 KDE Spin
2. ???
3. Reboot

Actual results:

"A stop job is running ... 1m30s"

Expected results:

Immediate reboot.


Additional info:

Comment 1 Lukas Vrabec 2019-01-07 21:35:00 UTC
Could you attach output of:

# sestatus 

Thanks,
Lukas.

Comment 2 Paul Sadauskas 2019-01-07 22:18:46 UTC
$ sudo sestatus
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

Comment 3 Lukas Vrabec 2019-01-09 11:13:13 UTC
Hi Paul, 

Thanks for update. 

Could you put SELinux to permissive mode:
# setenforce 0 

and reproduce the issue? 

Then please attach ouput of:

# ausearch -m AVC -m USER_AVC -m SELINUX_ERR -ts today 

Thanks,
Lukas.

Comment 4 Paul Sadauskas 2019-01-09 17:51:17 UTC
I rebooted once before setting `setenforce 0` (the entry at 10:40:47), then ran the `setenforce 0` and rebooted again.


$ sudo ausearch -m AVC -m USER_AVC -m SELINUX_ERR -ts today
----
time->Wed Jan  9 10:40:47 2019
type=AVC msg=audit(1547055647.716:640): avc:  denied  { getattr } for  pid=6640 comm="plymouthd" path="/sys/firmware/efi/efivars" dev="efivarfs" ino=15506 scontext=system_u:system_r:plymouthd_t:s0 tcontext=system_u:object_r:efivarfs_t:s0 tclass=dir permissive=0
----
time->Wed Jan  9 10:45:18 2019
type=USER_AVC msg=audit(1547055918.368:322): pid=1811 uid=81 auid=4294967295 ses=4294967295 subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc:  received setenforce notice (enforcing=0)  exe="/usr/bin/dbus-daemon" sauid=81 hostname=? addr=? terminal=?'
----
time->Wed Jan  9 10:45:43 2019
type=USER_AVC msg=audit(1547055943.437:326): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='avc:  received setenforce notice (enforcing=0)  exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
----
time->Wed Jan  9 10:45:44 2019
type=AVC msg=audit(1547055944.468:374): avc:  denied  { getattr } for  pid=5973 comm="plymouthd" path="/sys/firmware/efi/efivars" dev="efivarfs" ino=16400 scontext=system_u:system_r:plymouthd_t:s0 tcontext=system_u:object_r:efivarfs_t:s0 tclass=dir permissive=1

Comment 5 Lukas Vrabec 2019-01-10 17:16:55 UTC
Hi Paul, 

Could you try to reproduce with custom SELinux module? 

# cat local_plymouthd_efivarfs.cil 
(allow plymouthd_t efivarfs_t(dir (open read getattr)))
(allow plymouthd_t efivarfs_t(file (open read getattr)))

# semodule -i local_plymouthd_efivarfs.cil

Thanks,
Lukas.

Comment 6 Paul Sadauskas 2019-01-10 17:46:12 UTC
It appear to have no effect, I still have the stuck stop job.

$ sudo ausearch -m AVC -m USER_AVC -m SELINUX_ERR -ts today
----
time->Thu Jan 10 10:41:56 2019
type=USER_AVC msg=audit(1547142116.840:375): pid=1172 uid=81 auid=4294967295 ses=4294967295 subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc:  received policyload notice (seqno=2)  exe="/usr/bin/dbus-daemon" sauid=81 hostname=? addr=? terminal=?'
----
time->Thu Jan 10 10:42:12 2019
type=USER_AVC msg=audit(1547142132.156:382): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='avc:  received policyload notice (seqno=2)  exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'

Comment 7 Lukas Vrabec 2019-01-11 14:24:18 UTC
Paul, 

These AVCs are just information about Security SELinux policy reload.

Comment 8 Paul Sadauskas 2019-01-11 15:40:02 UTC
Hrm, OK. That makes sense. I pulled up the log for that reboot, and it looks like dbus isn't the one hanging the boot anymore, its something else:

Jan 10 10:43:42 boyd systemd[1]: session-2.scope: Stopping timed out. Killing.
Jan 10 10:43:42 boyd systemd[1]: session-2.scope: Killing process 2578 (vivaldi-bin) with signal SIGKILL.
Jan 10 10:43:42 boyd systemd[1]: session-2.scope: Killing process 3084 (CacheThread_Blo) with signal SIGKILL.
Jan 10 10:43:42 boyd systemd[1]: session-2.scope: Failed with result 'timeout'.

I won't be back at that computer again until Monday, to double-check, but it looks like that selinux module fixed it? I didn't do anything exotic to this install, is something missing in the default configs that needs to be fixed?

Thanks,
Paul

Comment 9 Lukas Vrabec 2019-01-14 17:02:54 UTC
Zdenek, 

Could you please add rules from comment#5 ? 

Thanks,
Lukas.

Comment 10 Zdenek Pytela 2019-01-15 15:26:09 UTC
Pull requests created to grant the dir:getattr and related permissions:

https://github.com/fedora-selinux/selinux-policy/pull/240

https://github.com/fedora-selinux/selinux-policy-contrib/pull/82

Comment 11 Zdenek Pytela 2019-01-15 17:11:41 UTC
*** Bug 1648978 has been marked as a duplicate of this bug. ***

Comment 12 Zdenek Pytela 2019-01-16 12:24:10 UTC
The pull requests have been merged to the main branch and should be a part of the next selinux-policy packages update.

Comment 13 Fedora Update System 2019-01-16 16:16:50 UTC
selinux-policy-3.14.2-47.fc29 has been submitted as an update to Fedora 29. https://bodhi.fedoraproject.org/updates/FEDORA-2019-fe7af4a346

Comment 14 Fedora Update System 2019-01-17 02:11:23 UTC
selinux-policy-3.14.2-47.fc29 has been pushed to the Fedora 29 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-fe7af4a346

Comment 15 Zdenek Pytela 2019-01-17 15:36:41 UTC
*** Bug 1665580 has been marked as a duplicate of this bug. ***

Comment 16 Fedora Update System 2019-01-18 02:14:06 UTC
selinux-policy-3.14.2-47.fc29 has been pushed to the Fedora 29 stable repository. If problems still persist, please make note of it in this bug report.