Bug 1439263

Summary:	Following a reboot, firewalld broke and is no longer configurable
Product:	[Fedora] Fedora	Reporter:	David Hill <dhill>
Component:	polkit	Assignee:	Miloslav Trmač <mitr>
Status:	CLOSED DUPLICATE	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	high	Docs Contact:
Priority:	unspecified
Version:	rawhide	CC:	dhill, mitr, twoerner
Target Milestone:	---
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2017-04-07 18:17:26 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 David Hill 2017-04-05 14:19:55 UTC

Description of problem:

Following a reboot, firewalld broke and is no longer configurable
+ firewall-cmd --reload
ERROR:dbus.proxies:Introspect error on :1.107:/org/fedoraproject/FirewallD1: dbus.exceptions.DBusException: org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.


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


How reproducible:
don't know yet, trying to fix it

Steps to Reproduce:
1. Rebooted the server many times following electrical glitches
2.
3.

Actual results:
firewall-cmd no longer works

Expected results:
should always be working

Additional info:

Comment 1 David Hill 2017-04-05 14:23:47 UTC

"firewallctl config list" is also not responding

Comment 2 Thomas Woerner 2017-04-05 14:43:11 UTC

Do you see error messages in the logs?

Comment 3 David Hill 2017-04-05 15:31:39 UTC

[root@zappa /]# sestatus
SELinux status:                 enabled
SELinuxfs mount:                /sys/fs/selinux
SELinux root directory:         /etc/selinux
Loaded policy name:             targeted
Current mode:                   permissive
Mode from config file:          permissive
Policy MLS status:              enabled
Policy deny_unknown status:     allowed
Max kernel policy version:      30



Apr 05 10:11:34 zappa.orion systemd[1]: Started D-Bus System Message Bus.
Apr 05 10:11:38 zappa.orion dbus-daemon[1672]: [system] Successfully activated service 'org.freedesktop.systemd1'
Apr 05 10:11:41 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.3' (uid=0 pid=1700 comm="/usr/libexec/accounts
Apr 05 10:11:45 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.8' (uid=0 pid=1
Apr 05 10:11:48 zappa.orion dbus-daemon[1672]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Apr 05 10:11:50 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.Accounts' unit='accounts-daemon.service' requested by ':1.15' (uid=0 pid=1826 comm="/usr/sbin/gdm
Apr 05 10:11:50 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.8' (uid=0 pid=1769 comm
Apr 05 10:11:51 zappa.orion dbus-daemon[1672]: [system] Successfully activated service 'org.freedesktop.hostname1'
Apr 05 10:12:06 zappa.orion dbus-daemon[1672]: [system] Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms)
Apr 05 10:12:06 zappa.orion dbus-daemon[1672]: [system] Successfully activated service 'org.freedesktop.Accounts'
Apr 05 10:12:06 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.7' (uid=0 pid=1696 comm="/usr/bin/python3 -Es
Apr 05 10:12:18 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.8' (uid=0 pid=1
Apr 05 10:12:18 zappa.orion dbus-daemon[1672]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Apr 05 10:12:31 zappa.orion dbus-daemon[1672]: [system] Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms)
Apr 05 10:12:31 zappa.orion dbus-daemon[1672]: [system] Rejected send message, 5 matched rules; type="error", sender=":1.7" (uid=0 pid=1696 comm="/usr/bin/python3 -Es /usr/sbin/firewalld --nofork " label="sy
Apr 05 10:12:31 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.7' (uid=0 pid=1696 comm="/usr/bin/python3 -Es
Apr 05 10:12:56 zappa.orion dbus-daemon[1672]: [system] Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms)
Apr 05 10:12:56 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.7' (uid=0 pid=1696 comm="/usr/bin/python3 -Es
Apr 05 10:13:21 zappa.orion dbus-daemon[1672]: [system] Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms)
Apr 05 10:13:21 zappa.orion dbus-daemon[1672]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.7" (uid=0 pid=1696 comm="/usr/bin/python3 -Es /usr/sbin/firewalld --nofork " label="sy
Apr 05 10:13:21 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.7' (uid=0 pid=1696 comm="/usr/bin/python3 -Es
Apr 05 10:13:46 zappa.orion dbus-daemon[1672]: [system] Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms)
Apr 05 10:13:46 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.7' (uid=0 pid=1696 comm="/usr/bin/python3 -Es
Apr 05 10:14:11 zappa.orion dbus-daemon[1672]: [system] Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms)
Apr 05 10:14:11 zappa.orion dbus-daemon[1672]: [system] Rejected send message, 5 matched rules; type="error", sender=":1.7" (uid=0 pid=1696 comm="/usr/bin/python3 -Es /usr/sbin/firewalld --nofork " label="sy
Apr 05 10:14:11 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.7' (uid=0 pid=1696 comm="/usr/bin/python3 -Es
Apr 05 10:14:36 zappa.orion dbus-daemon[1672]: [system] Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms)
Apr 05 10:14:36 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.7' (uid=0 pid=1696 comm="/usr/bin/python3 -Es
Apr 05 10:15:01 zappa.orion dbus-daemon[1672]: [system] Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms)
Apr 05 10:15:08 zappa.orion dbus-daemon[1672]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.64' (uid=0 pid=7058 comm="/usr/bin/python3 -Es
Apr 05 10:15:33 zappa.orion dbus-daemon[1672]: [system] Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms)

Comment 4 David Hill 2017-04-05 15:32:39 UTC

The only error message I found in firewalld is a warning:

Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: FedoraServer: 
INVALID_SERVICE: cockpit

Comment 5 David Hill 2017-04-05 15:34:47 UTC

Also found this :

Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table mangle --delete POSTROUTING --out-interface virbr0 --protocol udp --destination-port 68 --jump CHECKSU
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table nat --delete POSTROUTING --source 192.168.122.0/24 --destination 224.0.0.0/24 --jump RETURN' failed:
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table nat --delete POSTROUTING --source 192.168.122.0/24 --destination 255.255.255.255/32 --jump RETURN' fai
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table nat --delete POSTROUTING --source 192.168.122.0/24 -p tcp ! --destination 192.168.122.0/24 --jump MASQ
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table nat --delete POSTROUTING --source 192.168.122.0/24 -p udp ! --destination 192.168.122.0/24 --jump MASQ
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table nat --delete POSTROUTING --source 192.168.122.0/24 ! --destination 192.168.122.0/24 --jump MASQUERADE'
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table filter --delete FORWARD --destination 192.168.122.0/24 --out-interface virbr0 --match conntrack --ctst
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table filter --delete FORWARD --source 192.168.122.0/24 --in-interface virbr0 --jump ACCEPT' failed:
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table filter --delete FORWARD --in-interface virbr0 --out-interface virbr0 --jump ACCEPT' failed:
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table filter --delete FORWARD --out-interface virbr0 --jump REJECT' failed:
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table filter --delete FORWARD --in-interface virbr0 --jump REJECT' failed:
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table filter --delete INPUT --in-interface virbr0 --protocol udp --destination-port 53 --jump ACCEPT' failed
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table filter --delete INPUT --in-interface virbr0 --protocol tcp --destination-port 53 --jump ACCEPT' failed
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table filter --delete OUTPUT --out-interface virbr0 --protocol udp --destination-port 68 --jump ACCEPT' fail
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table filter --delete INPUT --in-interface virbr0 --protocol udp --destination-port 67 --jump ACCEPT' failed
Mar 31 21:02:57 zappa.orion firewalld[1684]: WARNING: COMMAND_FAILED: '/usr/sbin/iptables -w2 -w --table filter --delete INPUT --in-interface virbr0 --protocol tcp --destination-port 67 --jump ACCEPT' failed

Comment 6 Thomas Woerner 2017-04-05 15:46:37 UTC

There is an issue with PolicyKit:

dbus-daemon[1672]: [system] Failed to activate service 'org.freedesktop.PolicyKit1': timed out (service_start_timeout=25000ms)

This then results in issues with firewalld as firewalld is using PolicyKit.

The warning about unknwon service cockpit is expected as long as cockpit is not installed.

The COMMAND_FAILED warnings are form libvirt that tries to remove rules that do not exits. As firewalld is not aware if this is expected or an error, it logs these as warnings.

Comment 7 David Hill 2017-04-05 15:59:36 UTC

That's it.

I downgraded polkit to latest version polkit-0.113-5 and everything works as expected.

Comment 8 David Hill 2017-04-05 16:01:12 UTC

Broken : polkit-0.113-9.fc27.x86_64

Comment 9 Thomas Woerner 2017-04-05 16:02:21 UTC

Reassigning to polkit.

Comment 10 Miloslav Trmač 2017-04-05 16:15:21 UTC

Please update to polkit ≥ 0.113-11, and report whether it is still occurring.

Comment 11 David Hill 2017-04-05 18:06:56 UTC

When will it be available?  I only see 0.113-9.fc27

Comment 12 Miloslav Trmač 2017-04-06 14:21:02 UTC

*shrug* whenever rawhide publishes it, or perhaps grab it directly from koji.

Comment 13 David Hill 2017-04-07 14:43:13 UTC

This solves the issue.

Thanks

Comment 14 Miloslav Trmač 2017-04-07 18:17:26 UTC


*** This bug has been marked as a duplicate of bug 1438086 ***