qubes-iptables not starting properly

[Elias Mårtenson]

After my most recently upgrade of dom0 and all templates on my Qubes 4 installation (two days ago), I started facing the following problem:

After booting the system, all networking is down. I traced the problem to sys-firewall failing to start qubes-iptables:

=====================
[user@sys-firewall ~]$ systemctl status qubes-iptables
● qubes-iptables.service - Qubes base firewall settings
Loaded: loaded (/usr/lib/systemd/system/qubes-iptables.service; enabled; vend
Active: failed (Result: exit-code) since Wed 2018-05-16 20:44:47 +08; 2min 42
Process: 417 ExecStart=/usr/lib/qubes/init/qubes-iptables start (code=exited,
Main PID: 417 (code=exited, status=1/FAILURE)
=====================

The interesting thing is that I don't see anything in the log. When looking at the log, everything seems to have started correctly, and there is no further message suggesting it failed later:

=====================
May 16 20:47:38 sys-firewall audit[1023]: USER_START pid=1023 uid=0 auid=1000 ses=1 msg='op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="root" exe="/usr/bin/
sudo" hostname=? addr=? terminal=/dev/pts/0 res=success'
May 16 20:47:38 sys-firewall systemd[1]: Starting Qubes base firewall settings...
May 16 20:47:38 sys-firewall audit: NETFILTER_CFG table=nat family=2 entries=5
May 16 20:47:38 sys-firewall audit: NETFILTER_CFG table=filter family=2 entries=4
May 16 20:47:38 sys-firewall qubes-iptables[1026]: iptables: Applying firewall rules: OK
May 16 20:47:38 sys-firewall audit: NETFILTER_CFG table=filter family=10 entries=0
May 16 20:47:38 sys-firewall audit: NETFILTER_CFG table=filter family=10 entries=4
May 16 20:47:38 sys-firewall qubes-iptables[1026]: ip6tables: Applying firewall rules: OK
May 16 20:47:38 sys-firewall systemd[1]: Started Qubes base firewall settings.
=====================

If restart the service by calling “systemctl start qubes-iptables” everything works correctly.

Is this a known problem?

Regards,
Elias

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On Wed, May 16, 2018 at 06:11:26AM -0700, Elias Mårtenson wrote:
> After my most recently upgrade of dom0 and all templates on my Qubes 4 installation (two days ago), I started facing the following problem:
>
> After booting the system, all networking is down. I traced the problem to sys-firewall failing to start qubes-iptables:
>
> =====================
> [user@sys-firewall ~]$ systemctl status qubes-iptables
> ● qubes-iptables.service - Qubes base firewall settings
> Loaded: loaded (/usr/lib/systemd/system/qubes-iptables.service; enabled; vend
> Active: failed (Result: exit-code) since Wed 2018-05-16 20:44:47 +08; 2min 42

It failed at 20:44:47, but...

> Process: 417 ExecStart=/usr/lib/qubes/init/qubes-iptables start (code=exited,
> Main PID: 417 (code=exited, status=1/FAILURE)
> =====================
>
> The interesting thing is that I don't see anything in the log. When looking at the log, everything seems to have started correctly, and there is no further message suggesting it failed later:
>
> =====================
> May 16 20:47:38 sys-firewall audit[1023]: USER_START pid=1023 uid=0 auid=1000 ses=1 msg='op=PAM:session_open grantors=pam_keyinit,pam_limits,pam_keyinit,pam_limits,pam_systemd,pam_unix acct="root" exe="/usr/bin/
> sudo" hostname=? addr=? terminal=/dev/pts/0 res=success'
> May 16 20:47:38 sys-firewall systemd[1]: Starting Qubes base firewall settings...
> May 16 20:47:38 sys-firewall audit: NETFILTER_CFG table=nat family=2 entries=5
> May 16 20:47:38 sys-firewall audit: NETFILTER_CFG table=filter family=2 entries=4
> May 16 20:47:38 sys-firewall qubes-iptables[1026]: iptables: Applying firewall rules: OK
> May 16 20:47:38 sys-firewall audit: NETFILTER_CFG table=filter family=10 entries=0
> May 16 20:47:38 sys-firewall audit: NETFILTER_CFG table=filter family=10 entries=4
> May 16 20:47:38 sys-firewall qubes-iptables[1026]: ip6tables: Applying firewall rules: OK
> May 16 20:47:38 sys-firewall systemd[1]: Started Qubes base firewall settings.

... this log is from 20:47:38.

See for earlier log entries.

> =====================
>
> If restart the service by calling “systemctl start qubes-iptables” everything works correctly.
>
> Is this a known problem?
>
> Regards,
> Elias
>

- --
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
A: Because it messes up the order in which people normally read text.
Q: Why is top-posting such a bad thing?
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAlr8LqAACgkQ24/THMrX
1ywaQgf+JA+R7lKRoOeoCK1xfKbYZ8oIwFMgWHghi0kSJ6UEZ0H5OksgdT/VIaLJ
Z7qJzGkpMzB63HIkchxMjUow3jAIUO+6bA08Izp4GYqPbYm4RtiK6lI5OBUU7Dp3
424Y/oP6QToKNg8mqegKJ9BSqfhFIeBV2Tyg+FRWXbVBN7xGIUvbYv3sDS228iwl
umppuKz6s3Coa8PqqHvqw/piWf9QTi4Ub2bOmVbJmWpEjt1iI+SESyTLpXXmBaHO
q727GU3GBoK13oGLCxqC1/39OxzIsnJpUa4IX/bqVc689Wroz8hOFy174HrSdiWQ
LopwGlPtjeQqsmLv/06UllaQdR8RgQ==
=IzBP
-----END PGP SIGNATURE-----

[Elias Mårtenson]

On 16 May 2018 at 21:14, Marek Marczykowski-Górecki <marm...@invisiblethingslab.com> wrote:

... this log is from 20:47:38.

See for earlier log entries.

You are right. I'm stupid.

Here's the relevant log. There was indeed an error:

May 16 20:44:47 sys-firewall qubes-iptables[417]: iptables: Applying firewall rules: Another app is currently holding the xtables lock. Perhaps you want to use the -w option?

May 16 20:44:47 sys-firewall audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=qubes-gui-agent comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'

May 16 20:44:47 sys-firewall audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=qubes-iptables comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'

May 16 20:44:47 sys-firewall qubes-iptables[417]: FAIL

May 16 20:44:47 sys-firewall systemd[1]: Started Qubes GUI Agent.

May 16 20:44:47 sys-firewall systemd[1]: qubes-iptables.service: Main process exited, code=exited, status=1/FAILURE

May 16 20:44:47 sys-firewall systemd[1]: Failed to start Qubes base firewall settings.

May 16 20:44:47 sys-firewall systemd[1]: qubes-iptables.service: Unit entered failed state.

May 16 20:44:47 sys-firewall systemd[1]: qubes-iptables.service: Failed with result 'exit-code'.

Regards,

Elias 

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On Wed, May 16, 2018 at 09:17:42PM +0800, Elias Mårtenson wrote:
> On 16 May 2018 at 21:14, Marek Marczykowski-Górecki <
> marm...@invisiblethingslab.com> wrote:
>
> ... this log is from 20:47:38.
> >
> > See for earlier log entries.
> >
>
> You are right. I'm stupid.
>
> Here's the relevant log. There was indeed an error:
>
> May 16 20:44:47 sys-firewall qubes-iptables[417]: iptables: Applying
> firewall rules: Another app is currently holding the xtables lock. Perhaps
> you want to use the -w option?

Here is a hint how to fix this. The problem is that iptables-restore -w
is not available in (still supported) Debian jessie, which makes
applying this fix a little bit more complex.

Independently, it would be interesting to find out what is that "Another
app". You can either look at the log and correlate "Starting ..." and
"Started ..." messages. Or use `systemd-analyze plot` and look closely
what else is running at the time of qubes-iptables startup.
Or don't bother, because we already know the fix.

- --
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
A: Because it messes up the order in which people normally read text.
Q: Why is top-posting such a bad thing?
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAlr8XkIACgkQ24/THMrX
1yzvtQf9HCci9sgA1EMDC3wtdLZt9cJYjZOpZwrPCaPof7uJGJZClN310B7sctiY
EhgJMY1FNau/+E6ulF+z0oSkBWOE9bxT7dvc6eyl1ks5CaOfioEXC/aUpq+L7ePM
A3zXhSdZGkR0qrD+Qs+3MgkZeZ64rvB/8WSfORYmZR4OIXZHu0VmUcJC82zQvNPi
kDIlCf7b3HqGueerjSZsYE6RPEzdADFr7U60RCHePkz8AK2IQo/syGnRL32V6Xjl
jyUKar3PaNjAOCnsEnsMXzwy4S9fBYBn/M1Uxs+k+uonXCTFqkOwBpy4VZJpuKMw
yCvp2aRLo5FiEqYty+zfxkrdWCIbCQ==
=kJg7
-----END PGP SIGNATURE-----