ifup -a does not start dependants last, causes deadlocks with vlans/bonding

Status changed to 'Confirmed' because the bug affects multiple users.

I thought we have systemd hotplugging as well, can we not generate depedencies that <email address hidden> Wants= and After= <email address hidden>? and prevent all of these locks?

On Mon, May 8, 2017 at 9:06 AM, Dimitri John Ledkov <email address hidden>
wrote:

> I thought we have systemd hotplugging as well, can we not generate
>

I'm not sure what this means

> depedencies that <email address hidden> Wants= and After=
> <email address hidden>? and prevent all of these locks?
>

Wants= and AFter= are systemd *unit* dependencies, the locks and order
here
are internal states for ifupdown itself.

Systemd isn't in the picture other than it triggers calls, either ifup@.service
calling ifup on a specific interface (physical ones due do hotplug)
Or the networking.service, which invokes ifup -a (for all non-physical
interfaces defined).

>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1636708
>
> Title:
> ifup -a does not start dependants last, causes deadlocks with
> vlans/bonding
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/ubuntu/+source/ifupdown/+bug/
> 1636708/+subscriptions
>

Not quite.

On boot, there are multiple ways that ifup is called, and effectively it races with itself.

In my case I have two vlans, on top of a bond, of two NICs. By the time networking.service is called, the two NICs are present. networking.service is essentially `ifup -a`, it looks at the eni file and realises that it should bring bond0. It looks for bond0 in its internal state and creates it.

This is where the race starts.

ifupdown ships /lib/udev/rules.d/80-ifupdown.rules which calls /lib/udev/ifupdown-hotplug which effectively does
$ exec systemctl --no-block start $(systemd-escape --template ifup@.service $INTERFACE)
(very strange to do this on systemd systems, because one could have just did SYSTEMD_WANTS, but anyway)

At this point bond0 is being brought up by networking.service unit (ifup -a) and <email address hidden> (ifup bond0). Sometimes one can see "already configured" message from either of the two units in the logs.

But also, at this point it time, <email address hidden> and <email address hidden> may have been started as well.

In my case my machine manages to hit this race quite a bit. I am attaching a journal log, of what is happening.

The log is produced using:
journalctl -u ifup@*.service -u networking -o verbose | grep -e UTC -e UNIT -e MESSAGE

You can see messages that things are waiting on bond0 to be up; and that one or the other vlan is waiting on bond0 lock. To beat the locks and to prevent ifup@.service interfering with networking@.service, or executing in parallel and creating deadlocks, I had to encode the dependencies between these units in systemd brain by doing this:

# cat /<email address hidden>/order.conf
[Unit]
<email address hidden>
<email address hidden>
# cat /<email address hidden>/order.conf
[Unit]
<email address hidden>
<email address hidden>

This way the ordering is enforced for the ifup@.service hotplug. IMHO ifupdown should ship a generator, that would create these dependencies and orderings between interfaces. And possibly ifup -a should be reduced to starting ifup@%I.service for every interface it is meant to start for a given command.

I'm not sure if we can cheat and state that ifup@.service should be Wants=networking.service After=networking.service. Because I think then we may get ourselves into the situation that ifupdown fails to resolve cycles in the eni, when eni is specified out of order.

For cloud-init, this is more complicated. As on boot the generators will fire, before eni is populated. Therefore cloud-init should probably re-run this magical ifupdwon generator (just like it does for netplan) or cloud-init should create these symlinks directly, and reload systemd before moving onto networking.service.

Does above make sense at all?

@ Chris Pitchford

Could you please try below, and let us know if that works for you, with your proposed workaround reverted?
The reason being, is that with a generator we should be able to create these orderings using the original / unmodified eni files as generated by installers / were in use in Trusty.

mkdir -p /<email address hidden>
cat > /<email address hidden>/order.conf << EOF
[Unit]
<email address hidden>
<email address hidden>

EOF

Maybe this is easier to read.

root@xnox-iad-nr5:~# journalctl -o short-monotonic -u <email address hidden>
-- Logs begin at Tue 2017-05-09 10:57:18 UTC, end at Tue 2017-05-09 15:22:34 UTC. --
[ 6.740201] xnox-iad-nr5 systemd[1]: Started ifup for bond0.
[ 6.750333] xnox-iad-nr5 sh[1184]: Waiting for a slave to join bond0 (will timeout after 60s)
[ 6.987241] xnox-iad-nr5 sh[1184]: ifquery: recursion detected for interface bond0 in pre-up phase
[ 6.987341] xnox-iad-nr5 sh[1184]: ifquery: recursion detected for parent interface bond0 in pre-up phase
[ 6.987425] xnox-iad-nr5 sh[1184]: ifquery: recursion detected for parent interface bond0 in pre-up phase
root@xnox-iad-nr5:~# journalctl -o short-monotonic -u <email address hidden>
-- Logs begin at Tue 2017-05-09 10:57:18 UTC, end at Tue 2017-05-09 15:22:34 UTC. --
[ 6.755723] xnox-iad-nr5 systemd[1]: Started ifup for bond0.101.
[ 6.757056] xnox-iad-nr5 sh[1286]: ifup: waiting for lock on /run/network/ifstate.bond0
[ 7.227572] xnox-iad-nr5 sh[1286]: Set name-type for VLAN subsystem. Should be visible in /proc/net/vlan/config
root@xnox-iad-nr5:~# journalctl -o short-monotonic -u <email address hidden>
-- Logs begin at Tue 2017-05-09 10:57:18 UTC, end at Tue 2017-05-09 15:22:34 UTC. --
[ 6.760568] xnox-iad-nr5 systemd[1]: Started ifup for bond0.401.
[ 6.761920] xnox-iad-nr5 sh[1290]: ifup: waiting for lock on /run/network/ifstate.bond0
[ 7.197983] xnox-iad-nr5 sh[1290]: Set name-type for VLAN subsystem. Should be visible in /proc/net/vlan/config
root@xnox-iad-nr5:~# journalctl -o short-monotonic -u networking.service
-- Logs begin at Tue 2017-05-09 10:57:18 UTC, end at Tue 2017-05-09 15:22:34 UTC. --
[ 6.645323] xnox-iad-nr5 systemd[1]: Starting Raise network interfaces...
[ 6.692530] xnox-iad-nr5 ifup[992]: Waiting for bonding kernel module to be ready (will timeout after 5s)
[ 6.693104] xnox-iad-nr5 ifup[992]: Waiting for bond master bond0 to be ready
[ 7.221867] xnox-iad-nr5 ifup[992]: /sbin/ifup: waiting for lock on /run/network/ifstate.bond0
[ 7.263179] xnox-iad-nr5 systemd[1]: Started Raise network interfaces.

Note that networking, <email address hidden>, and <email address hidden> all hit locks that are held by bond0.
Note that <email address hidden> beats networking.service to acquire the lock.
And that netwokring.service is blocked until after ifup@bond0.*01 vlans release the locks.

On Tue, May 9, 2017 at 10:32 AM, Dimitri John Ledkov <<email address hidden>
> wrote:

> Maybe this is easier to read.
>
> root@xnox-iad-nr5:~# journalctl -o short-monotonic -u <email address hidden>
> -- Logs begin at Tue 2017-05-09 10:57:18 UTC, end at Tue 2017-05-09
> 15:22:34 UTC. --
> [ 6.740201] xnox-iad-nr5 systemd[1]: Started ifup for bond0.
> [ 6.750333] xnox-iad-nr5 sh[1184]: Waiting for a slave to join bond0
> (will timeout after 60s)
> [ 6.987241] xnox-iad-nr5 sh[1184]: ifquery: recursion detected for
> interface bond0 in pre-up phase
> [ 6.987341] xnox-iad-nr5 sh[1184]: ifquery: recursion detected for
> parent interface bond0 in pre-up phase
> [ 6.987425] xnox-iad-nr5 sh[1184]: ifquery: recursion detected for
> parent interface bond0 in pre-up phase
> root@xnox-iad-nr5:~# journalctl -o short-monotonic -u
> <email address hidden>
> -- Logs begin at Tue 2017-05-09 10:57:18 UTC, end at Tue 2017-05-09
> 15:22:34 UTC. --
> [ 6.755723] xnox-iad-nr5 systemd[1]: Started ifup for bond0.101.
> [ 6.757056] xnox-iad-nr5 sh[1286]: ifup: waiting for lock on
> /run/network/ifstate.bond0
> [ 7.227572] xnox-iad-nr5 sh[1286]: Set name-type for VLAN subsystem.
> Should be visible in /proc/net/vlan/config
> root@xnox-iad-nr5:~# journalctl -o short-monotonic -u
> <email address hidden>
> -- Logs begin at Tue 2017-05-09 10:57:18 UTC, end at Tue 2017-05-09
> 15:22:34 UTC. --
> [ 6.760568] xnox-iad-nr5 systemd[1]: Started ifup for bond0.401.
> [ 6.761920] xnox-iad-nr5 sh[1290]: ifup: waiting for lock on
> /run/network/ifstate.bond0
> [ 7.197983] xnox-iad-nr5 sh[1290]: Set name-type for VLAN subsystem.
> Should be visible in /proc/net/vlan/config
> root@xnox-iad-nr5:~# journalctl -o short-monotonic -u networking.service
> -- Logs begin at Tue 2017-05-09 10:57:18 UTC, end at Tue 2017-05-09
> 15:22:34 UTC. --
> [ 6.645323] xnox-iad-nr5 systemd[1]: Starting Raise network
> interfaces...
> [ 6.692530] xnox-iad-nr5 ifup[992]: Waiting for bonding kernel module
> to be ready (will timeout after 5s)
> [ 6.693104] xnox-iad-nr5 ifup[992]: Waiting for bond master bond0 to be
> ready
> [ 7.221867] xnox-iad-nr5 ifup[992]: /sbin/ifup: waiting for lock on
> /run/network/ifstate.bond0
> [ 7.263179] xnox-iad-nr5 systemd[1]: Started Raise network interfaces.
>
>
What is the status/timestamp of the physical devices (enspf90 and 91) ?

 Note that networking, <email address hidden>, and <email address hidden> all hit locks
that are held by bond0.

> Note that <email address hidden> beats networking.service to acquire the lock.
>

hrm, I didn't think we got ifup events for non-physical devices; this is
certainly problematic;
the design, IIUC, is for physical devices to get ifup@.service triggers via
udev events; see the the BindsTo=sys-subsystem-net-devices-%i.device

The result in this boot is that networking.service (which starts at 6.64
seconds calls ifup -a (pid 992) which is racing with
the ifup@bond0 (started at 6.74, pid 1184); so we have *two* ifups locking
bond0; I think this is the real deadlock.

I'm not sure why we're getting an ifup@bond0 unit execution, the udev
scripts are only triggered for physical devices;

Looks like when the modu...

> Why would bond0 get created when loading the bonding module?

Because the default module parameter max_bonds for bonding module is 1, meaning create one bond upon bond module loading.

I have since hit similar issue with networkd where bonding module would be autoprobed, bond0 created, and confuse networkd (bond0 already exists, not touching it).

I have since applied max_bonds=0 and used networkd. I guess I can try this again with ifupdown, max_bond=0, and check what sort of udev events are received.

Imho we should default to max_bonds=0 such that loading bonding module doesn't create stray interfaces.

Status changed to 'Confirmed' because the bug affects multiple users.

We upgraded to the vlan 1.9-3.2ubuntu1.16.04.3 package and our networking broke horribly in a very similar way.

Let me start with our networking configuration. Two slaves, a bond and a vlan on top of that bond:

auto eno1
iface eno1 inet manual
   mtu 1500
   bond-master bond1
   bond-primary eno1

auto eno2
iface eno2 inet manual
   mtu 1500
   bond-master bond1

auto bond1
iface bond1 inet static
   mtu 1500
   address 10.10.10.3
   bond-miimon 100
   bond-mode active-backup
   bond-slaves none
   bond-downdelay 200
   bond-updelay 200
   dns-nameservers 10.10.0.1
   netmask 255.255.0.0

auto bond1.2
iface bond1.2 inet static
   mtu 1500
   address 10.11.10.3
   netmask 255.255.0.0
   vlan-raw-device bond1

This fails to come up correctly, both during boot and manually. Bringing up either eno1, eno2, bond1 or bond1.2 all result in the same problem: "ifup: waiting for lock on /run/network/ifstate.bond1".

Problem seems to be that ifup tries to bring up the base bond1 interface *again*. Even if it is already up. And it gets stuck waiting for the bond1 interface to be unlocked so it can bring it up, but it is already up and thus locked so that will never happen.

We also tried bringing all interfaces down and just running "ifup bond1.2" but that results in the same behavior.

Only workaround that seemed to work for us was to:
1) temporarily remove the bond1.2.cfg from /etc/network/interfaces.d
2) bring up eno1, eno2 and bond1
3) put the bond1.2.cfg back in its place
4) run "ifup bond1.2"
5) using another terminal, list all open processes using "ps -ef | grep ifup"
6) kill the "ifup bond1" process

The "ps -ef | grep ifup" during step 5, outputs two ifup processes. One for bond1 and one for bond1.2. As soon as we kill the "ifup bond1" process, the "ifup bond1.2" process completes immediately and correctly configures the vlan 2 subinterface.

This is clearly linked to vlan, because our infiniband interfaces work just fine. Also it worked just fine before upgrading the package. So my best guess would be that something broke in the code that detects if the vlan-raw-device is up. Perhaps related to LP #1573272 ?

First, I believe the original description of this case shows it's the same problem (or same fix at least) as bug 1573272 - the vlan is racing with its raw device bond to come up. The fix in that bug should address this problem, by forcing the bond interface to always come up first (it's forced during udev processing when udev detects a new vlan interface). So I think this bug can be marked as fixed or duplicate - can anyone who had the original problem please test with the latest vlan package to verify this is fixed?

Second, @tom-verdaat, re: comment 11, I set up a system with that config, and rebooted many times and saw no problem. As your description doesn't involve dhcp on the vlan interface - which is what caused the long-term locking of the ifupdown bond0 lock from the initial problem description - it sounds like a new issue. Especially since this is an older bug, and you only now started seeing the problem after upgrading to the latest vlan package. Can you open a new bug for your issue please?

The fixes in vlan package are insufficient, as networking.service spawns ifup@.services in parallel with no ordering information and therefore systemd is free to process them in a racy manner. At boot ifup@.services are racing with networking.service and can result in a deadlock as you have experienced.

@tom-verdaat To resolve boot time races, you need to provide manual dependency ordering of the ifup@.service systemd units, as at the moment, unfortunately, these are not automatically generated. For you pasted config I believe you require the following files:

# cat /<email address hidden>/order.conf
[Unit]
<email address hidden>
<email address hidden>

# cat /<email address hidden>/order.conf
[Unit]
<email address hidden>
<email address hidden>
<email address hidden>
<email address hidden>

In 17.10 and later releases these races are fixed with netplan. netplan is also available and can be used on xenial. netplan generates correct configuration and then all of bonds/vlans are managed by networkd in a race-free manner.

I apologize for the inconvenience =(

> networking.service spawns ifup@.services in parallel with no ordering information

no, networking.service calls ifup -a, it doesn't spawn ifup@ services.

ifup -a doesn't bring up interfaces in parallel, it brings them up sequentially as ordered in the /etc/networking/interface file(s). However, while bringing up an interface frequently other interfaces are created which does trigger parallel ifup@ service calls - for example, if bond1 and bond1.2 are both defined, while bond1 is being ifup'ed, the actual bond1 interface is created and processed by udev, which then calls /lib/udev/vlan-network-interface with bond1, which then parses the ifupdown configuration and finds the bond1.2 interface that uses bond1 as its raw-device, and so it runs /etc/network/if-pre-up.d/vlan which creates the bond1.2 interface - that is then processed by udev, which then ifup's it in parallel to bond1's ifup, etc.

> To resolve boot time races, you need to provide manual dependency ordering of the
> ifup@.service systemd units

i don't believe that is entirely correct, but if your suggestion fixes things for @tom-verdaat then great. ifupdown (and the vlan add-on to it) is rather a mess, and i can't wait to move on to netplan with networkd.

@ddstreet I opened a separate ticket as requested a while ago. Some eyes on it would be very welcome. It's bug 1759573

@newsuk-platform, are you still having this problem? If not, let's close this bug.

[Expired for ifupdown (Ubuntu Xenial) because there has been no activity for 60 days.]