Bug 1625218

Summary: Fedora Workstation 29 takes a long time to boot in enforcing mode.
Product: [Fedora] Fedora Reporter: Lukas Ruzicka <lruzicka>
Component: selinux-policyAssignee: Lukas Vrabec <lvrabec>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: high    
Version: 29CC: awilliam, dustymabe, dwalsh, edoubrayrie, kparal, lruzicka, lvrabec, mattias.eriksson, mgrepl, nonamedotc, plautrba, pmoore, projects.rg, robatino, rymg19
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard: AcceptedFreezeException
Fixed In Version: selinux-policy-3.14.2-34.fc29 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-09-12 02:56:16 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:
Bug Depends On:    
Bug Blocks: 1517012, 1517013    
Attachments:
Description Flags
The SElinux related lines from journalctl. lruzicka: review+

Description Lukas Ruzicka 2018-09-04 12:15:43 UTC
Description of problem:

Booting the fresh installation of Fedora Workstation 29, the system take a long time to boot when SElinux is in enforcing mode than it takes if SElinux is in permissive mode. Also, after a successful login, user has to wait about 50 seconds to get the DE and some user also report that running system is slower than running in permissive mode.

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

Fedora 29, nightly build from Sept 3, 2018.

How reproducible:

Always

Steps to Reproduce:
1. Install Fedora Workstation 29.
2. After installation, reboot.
3. Time the booting process.
4. Log in and time the starting process.

Actual results:

* Workstation in enforcing mode takes approx. 70 seconds to boot.
* Workstation in permissive mode takes approx. 18 seconds to boot.
* Minimal Fedora system takes approx. 8 seconds to boot.

Expected results:

* Enforcing mode should not affect the time needed to boot the computer.

Additional info:

Unfortunately, no critical error reported in journalctl has been shown except some denials in journactl (provided).

Comment 1 Lukas Ruzicka 2018-09-04 12:16:33 UTC
Created attachment 1480759 [details]
The SElinux related lines from journalctl.

Comment 2 Fedora Blocker Bugs Application 2018-09-04 12:23:01 UTC
Proposed as a Blocker for 29-final by Fedora user lruzicka using the blocker tracking app because:

 This one is an annoying bug, even though it only slows down the machine. Anyway, I am proposing this as a blocker because the bug violates the Final Release Criteria described as:

# SELinux and crash notifications
There must be no SELinux denial notifications or crash notifications on boot of or during installation from a release-blocking live image, or at first login after a default install of a release-blocking desktop.

Comment 3 Lukas Vrabec 2018-09-04 16:31:15 UTC
Hi, 

Could you put system to permissive mode. 
In /etc/selinux/config change option "SELINUX"  to permissive like:
SELINUX=permissive

and reboot the system. 

Then, please attach output of:
# ausearch -m AVC -ts today

THanks,
Lukas.

Comment 4 Lukas Ruzicka 2018-09-05 10:16:53 UTC
Hi, the output from the mentioned command booted with SELINUX=permissive:

----
time->Wed Sep  5 12:11:33 2018
type=AVC msg=audit(1536142293.243:112): avc:  denied  { create } for  pid=776 comm="ebtables" scontext=system_u:system_r:firewalld_t:s0 tcontext=system_u:system_r:firewalld_t:s0 tclass=rawip_socket permissive=0
----
time->Wed Sep  5 12:13:43 2018
type=AVC msg=audit(1536142423.191:112): avc:  denied  { create } for  pid=769 comm="ebtables" scontext=system_u:system_r:firewalld_t:s0 tcontext=system_u:system_r:firewalld_t:s0 tclass=rawip_socket permissive=1
----
time->Wed Sep  5 12:13:43 2018
type=AVC msg=audit(1536142423.195:113): avc:  denied  { net_raw } for  pid=769 comm="ebtables" capability=13  scontext=system_u:system_r:firewalld_t:s0 tcontext=system_u:system_r:firewalld_t:s0 tclass=capability permissive=1
----
time->Wed Sep  5 12:13:43 2018
type=AVC msg=audit(1536142423.195:114): avc:  denied  { getopt } for  pid=769 comm="ebtables" lport=2 scontext=system_u:system_r:firewalld_t:s0 tcontext=system_u:system_r:firewalld_t:s0 tclass=rawip_socket permissive=1
----
time->Wed Sep  5 12:13:43 2018
type=AVC msg=audit(1536142423.207:116): avc:  denied  { mounton } for  pid=770 comm="(ostnamed)" path="/run/systemd/unit-root/proc/kallsyms" dev="proc" ino=4026532064 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:system_map_t:s0 tclass=file permissive=1
----
time->Wed Sep  5 12:13:47 2018
type=AVC msg=audit(1536142427.642:160): avc:  denied  { mounton } for  pid=1203 comm="(-localed)" path="/run/systemd/unit-root/proc/kallsyms" dev="proc" ino=4026532064 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:system_map_t:s0 tclass=file permissive=1
----
time->Wed Sep  5 12:13:48 2018
type=AVC msg=audit(1536142428.150:162): avc:  denied  { mounton } for  pid=1227 comm="(upowerd)" path="/run/systemd/unit-root/var/lib/upower" dev="dm-0" ino=412858 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:devicekit_var_lib_t:s0 tclass=dir permissive=1
----
time->Wed Sep  5 12:13:48 2018
type=AVC msg=audit(1536142428.332:163): avc:  denied  { mounton } for  pid=1245 comm="(geoclue)" path="/run/systemd/unit-root/proc/kallsyms" dev="proc" ino=4026532064 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:system_map_t:s0 tclass=file permissive=1
----
time->Wed Sep  5 12:13:49 2018
type=AVC msg=audit(1536142429.387:170): avc:  denied  { mounton } for  pid=1353 comm="(fprintd)" path="/run/systemd/unit-root/proc/kallsyms" dev="proc" ino=4026532064 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:system_map_t:s0 tclass=file permissive=1
----
time->Wed Sep  5 12:13:50 2018
type=AVC msg=audit(1536142430.059:326): avc:  denied  { read } for  pid=683 comm="firewalld" name="random" dev="devtmpfs" ino=9610 scontext=system_u:system_r:firewalld_t:s0 tcontext=system_u:object_r:random_device_t:s0 tclass=chr_file permissive=0
----
time->Wed Sep  5 12:14:25 2018
type=AVC msg=audit(1536142465.188:195): avc:  denied  { mounton } for  pid=1627 comm="(geoclue)" path="/run/systemd/unit-root/proc/kallsyms" dev="proc" ino=4026532064 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:system_map_t:s0 tclass=file permissive=1
----
time->Wed Sep  5 12:14:57 2018
type=AVC msg=audit(1536142497.667:204): avc:  denied  { mounton } for  pid=2256 comm="(fprintd)" path="/run/systemd/unit-root/proc/kallsyms" dev="proc" ino=4026532064 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:system_map_t:s0 tclass=file permissive=1

Comment 5 Lukas Ruzicka 2018-09-05 10:17:47 UTC
And, as expected, the system reached much higher booting and response speeds. :)

Comment 6 Adam Williamson 2018-09-05 16:49:40 UTC
We should make this a Beta FE, obviously it's best if this does *not* happen on every Workstation Beta install / boot.

Comment 7 Raphael Groner 2018-09-08 19:43:48 UTC
This bug shows also with Xfce and LXQt spins.

Comment 8 Dusty Mabe 2018-09-09 18:32:11 UTC
+1 FE

Comment 9 Ryan Gonzalez 2018-09-10 00:20:26 UTC
Okay, here's a little more info on this I've gathered:

- Interestingly enough, systemd-analyze plot shows that, after all services are ready, plymouth-quit-wait.service waits around 50 seconds more than required, which is what leads to the lock up. Not sure if this is just a symptom of SELinux issues or...?
- I'm using GNOME on X11, and with SELinux set to enforcing, getting from GDM to the GNOME Shell takes around an extra minute or two. I have yet to test GNOME on Wayland

Comment 10 Adam Williamson 2018-09-10 20:43:19 UTC
Lukas: can we please have an F29 build soon with fixes for this and other F29 issues? We are only 3 days from the first Beta Go/No-Go date at this point and we'd really like this and other significant issues fixed. Thanks!

Comment 11 Lukas Vrabec 2018-09-10 20:48:15 UTC
Adam:
Please push this somehow to stable:
https://bodhi.fedoraproject.org/updates/FEDORA-2018-2fe202ceb9

to have it in buildroot and I'll do the build ASAP. (Build is ready bud it failing on because of old version of setools)

Thanks,
Lukas.

Comment 12 Adam Williamson 2018-09-10 22:35:15 UTC
The correct procedure would be to submit a buildroot override:

https://bodhi.fedoraproject.org/overrides/new

run the build, and then edit the new selinux-policy into the same update. Thanks!

Comment 13 Adam Williamson 2018-09-10 23:14:08 UTC
Discussed at 2018-09-10 freeze exception review meeting: https://meetbot-raw.fedoraproject.org/fedora-blocker-review/2018-09-10/f29-blocker-review.2018-09-10-16.01.html . Accepted as a freeze exception issue as a significant and obvious bug that is present when booting live images and on first boot after install (thus cannot be entirely fixed with an update).

Comment 14 Fedora Update System 2018-09-11 12:50:03 UTC
selinux-policy-3.14.2-34.fc29 has been submitted as an update to Fedora 29. https://bodhi.fedoraproject.org/updates/FEDORA-2018-db240a1726

Comment 15 Fedora Update System 2018-09-12 02:56:16 UTC
selinux-policy-3.14.2-34.fc29 has been pushed to the Fedora 29 stable repository. If problems still persist, please make note of it in this bug report.