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 module is loaded (modprobe bonding) that we get an
event for bond0 ... which may be triggering
the hotplug udev-rule which queues a ifup@bond0 job...

This is strange (to me):

# modprobe -vr bonding
rmmod bonding
root@x1:~# ifconfig -a
ens3      Link encap:Ethernet  HWaddr 52:54:00:87:54:74
          BROADCAST MULTICAST  MTU:1500  Metric:1
          RX packets:2 errors:0 dropped:0 overruns:0 frame:0
          TX packets:2 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:104 (104.0 B)  TX bytes:184 (184.0 B)

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:65536  Metric:1
          RX packets:320 errors:0 dropped:0 overruns:0 frame:0
          TX packets:320 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1
          RX bytes:23680 (23.6 KB)  TX bytes:23680 (23.6 KB)

root@x1:~# cat /etc/issue
Ubuntu 16.04.2 LTS \n \l

root@x1:~# lsb_release -rd
Description: Ubuntu 16.04.2 LTS
Release: 16.04
root@x1:~# ls -al /sys/class/net/
total 0
drwxr-xr-x  2 root root 0 May  9 16:36 .
drwxr-xr-x 63 root root 0 May  9 16:35 ..
lrwxrwxrwx  1 root root 0 May  9 16:35 ens3 ->
../../devices/pci0000:00/0000:00:03.0/virtio0/net/ens3
lrwxrwxrwx  1 root root 0 May  9 16:35 lo -> ../../devices/virtual/net/lo

root@x1:~# modprobe -v bonding
insmod /lib/modules/4.4.0-75-generic/kernel/drivers/net/bonding/bonding.ko
root@x1:~# ls -al /sys/class/net/
total 0
drwxr-xr-x  2 root root    0 May  9 16:36 .
drwxr-xr-x 63 root root    0 May  9 16:36 ..
lrwxrwxrwx  1 root root    0 May  9 16:36 bond0 ->
../../devices/virtual/net/bond0
-rw-r--r--  1 root root 4096 May  9 16:36 bonding_masters
lrwxrwxrwx  1 root root    0 May  9 16:36 ens3 ->
../../devices/pci0000:00/0000:00:03.0/virtio0/net/ens3
lrwxrwxrwx  1 root root    0 May  9 16:36 lo -> ../../devices/virtual/net/lo
root@x1:~# uname -r
4.4.0-75-generic


Why would bond0 get created when loading the bonding module?

@xnox, if you change your interfaces from bond0, to bond1 globally, does
your configuration
work ?



> --
> 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
>