Bug 1112924 - slow boot for firewalld
Summary: slow boot for firewalld
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: firewalld
Version: 20
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Thomas Woerner
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-06-25 04:09 UTC by lionghostshop
Modified: 2016-12-30 20:50 UTC (History)
4 users (show)

Fixed In Version:
Clone Of:
: 1294974 (view as bug list)
Environment:
Last Closed: 2015-06-29 21:18:41 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
required files, I zip it since there are a few (30.91 KB, application/zip)
2014-06-25 07:41 UTC, lionghostshop
no flags Details
journalct -b -o short-monotonic -u firewalld.service -u NetworkManager.service (91.25 KB, text/plain)
2015-03-26 18:47 UTC, Oliver Henshaw
no flags Details

Description lionghostshop 2014-06-25 04:09:53 UTC
Description of problem:


Version-Release number of selected component (if applicable):
firewalld-0.3.10-1.fc20.noarch

How reproducible:
boot system

Steps to Reproduce:
1. Boot system


Actual results:

[leo@desktopa ~]$ systemd-analyze blame
         12.997s firewalld.service
          6.341s accounts-daemon.service
          5.893s systemd-udev-settle.service
          5.105s ModemManager.service
          4.079s avahi-daemon.service
          4.078s systemd-logind.service
          3.738s gdm.service
          3.583s rpcbind.service
          3.559s proc-fs-nfsd.mount
          3.430s var-lib-nfs-rpc_pipefs.mount
          3.008s chronyd.service
          2.966s systemd-binfmt.service
          2.765s dmraid-activation.service
          2.245s proc-sys-fs-binfmt_misc.mount
          2.061s kmod-static-nodes.service
          2.049s systemd-tmpfiles-setup-dev.service
          1.809s vboxdrv.service
          1.319s colord.service

Expected results:
firewalld.service take less time

Additional info:

Comment 1 Jiri Popelka 2014-06-25 07:15:15 UTC
(In reply to lionghostshop from comment #0)
>          12.997s firewalld.service

That's a lot, yes.
Please add 'FIREWALLD_ARGS=--debug' into /etc/sysconfig/firewalld
then reboot and 
- attach output of 'journalctl -b'
- attach /var/log/firewalld
- attach files from /etc/firewalld/zones/ if there are any

thanks

Comment 2 lionghostshop 2014-06-25 07:41:06 UTC
Created attachment 911964 [details]
required files, I zip it since there are a few

required files, I zip it since there are a few

Comment 3 lionghostshop 2014-06-25 07:48:11 UTC
Note that I am using btrfs in /.
Previously, I found rsyslog is very slow using btrfs. I disable it and reduce boot time from 3 minutes to 32 seconds. 
After booting, applications start in reasonable time and are fast enough.

Comment 4 Jiri Popelka 2014-06-25 08:53:24 UTC
journalctl:
15:35:16 systemd[1]: Starting firewalld
15:35:23 polkitd[769]: Started polkitd version 0.112
15:35:30 systemd[1]: Started firewalld

/var/log/firewalld
15:35:30 DEBUG1: start()

My rough guess is that the whole 14s before firewalld actually started to "do something" had taken the initialization of things that firewalld requires, i.e. D-Bus, Polkit, loading of kernel netfilter modules etc.

Comment 5 Thomas Woerner 2014-06-25 12:20:25 UTC
The start times that systemd is reporting for a service is not only the start time of the service itself, but also the start time of other services, that are required by this service - if it is the first service that requires this  service. 
But the start times of other services that have the same requirement are not increased by the start times of the requirement. Therefore the start times reported by systemd are only some numbers and not suitable to compare or blame services.

There are start times for lots of requirements only added to firewalld, because it is started very early.

You can simply verify the whole blame issue by deactivating the service that is taking most time as reported by systemd-analyze blame over and over again. You will notice that other services need more time to start after deactivating the most consuming service and the start time of the system is not reduced a lot.

You system will boot faster in the end, after some iterations, because there are no services started anymore, but it will only be of limited use...

Comment 6 Oliver Henshaw 2015-03-26 18:47:11 UTC
Created attachment 1006965 [details]
journalct -b -o short-monotonic -u firewalld.service -u NetworkManager.service

I see this too and am not convinced by comment #5. firewalld would be started after any explicit dependencies specified in the .service file and I don't see any particular smoking guns for implicit dependencies in the journal output.

This is a low-powered machine (an AMD E-350) with classical hard drives so I'm not expecting blazing fast startup but still the startup time of firewalld.service is out of proportion to other services.

So I found if I set FIREWALLD_ARGS=--debug=10 in /etc/sysconfig/firewalld I got a bit more logging output between "Starting firewalld" and "Started firewalld"

I also added a snippet to make firewalld log to journalctl as well as its own file:

$ cat /etc/systemd/system/firewalld.service.d/logging.conf 
[Service]
# set back to defaults
# it logs debug output to /valor/log/firewalld.log anyways, this just helps line timestamps up
StandardOutput=journal
StandardError=inherit


The results are attached - the 10 seconds between firewalld starting and being started is on the high end for the machine but it's interesting that most of that is before the iptables calls.

I then sprinkled in some debugging lines in /usr/sbin/firewalld and found that most of the time happens before the first non-comment line of the file.

So the cause could actually be slowness in python startup?

Comment 7 Fedora End Of Life 2015-05-29 12:12:46 UTC
This message is a reminder that Fedora 20 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 20. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '20'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 20 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 8 Fedora End Of Life 2015-06-29 21:18:41 UTC
Fedora 20 changed to end-of-life (EOL) status on 2015-06-23. Fedora 20 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.

Comment 9 Denis Shulyaka 2016-12-30 20:50:33 UTC
Hi,

I have this issue on Fedora 25 with firewalld-0.4.4.2-1.fc25.noarch.

[denis@denis ~]$ cat /etc/fedora-release 
Fedora release 25 (Twenty Five)
[denis@denis ~]$ systemd-analyze blame
         20.043s firewalld.service
         14.496s akmods.service
          9.233s NetworkManager-wait-online.service
          7.737s plymouth-quit-wait.service
          4.681s accounts-daemon.service
          3.303s gssproxy.service
          2.023s auditd.service
          1.959s rsyslog.service
          1.696s polkit.service
          1.459s lm_sensors.service
          1.405s chronyd.service
          1.260s dev-mapper-fedora\x2droot.device
          1.238s avahi-daemon.service
          1.226s cups.service
          1.173s bluetooth.service
           922ms lvm2-monitor.service
           713ms NetworkManager.service


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