These remove/add lines for sda14 are consistent with what I saw when just running `partx` by hand in an instance.
Looking at the passing instance, there is one noticeable difference: the sda14 remove/add KERNEL events are emitted to the log _before_ any of the UDEV events from the resizing are emitted. This means that:
* On the failing instance, we see the first resizing KERNEL event (sda) emitted at 12:09:25.347818 and the sda1 UDEV event emitted at 12:09:25.372478; .025s.
* On the passing instance, we see the first resizing KERNEL event (sda) emitted at 12:14:21.925924 and the sda1 UDEV event emitted at 12:14:22.002377; .076s.
(And, once again, we see that the order in which udev processes those events goes sda15, sda14, sda1.)
Thanks! TL;DR: the partx call didn't change much.
On the failing instance, this is when the partx call happens:
2019-07-29 12:09:25,391 - util.py[DEBUG]: Running command ['partx', '--update', '/dev/sda']
Looking in the journal at that timestamp, I see (lines omitted and/or edited for brevity):
2019-07- 29T12:09: 25.395099+ 0000 udevadm[246]: KERNEL[27.837161] remove /devices/ LNXSYSTM: 00/LNXSYBUS: 00/PNP0A03: 00/device: 07/VMBUS: 01/00000000- 0000-8899- 0000-0000000000 00/host0/ target0: 0:0/0:0: 0:0/block/ sda/sda14 (block) 29T12:09: 25.396119+ 0000 tobijk- x-alan- eoan-base- uutvyfllcflbntz jhhes udevadm[246]: UDEV [27.838088] remove /devices/ LNXSYSTM: 00/LNXSYBUS: 00/PNP0A03: 00/device: 07/VMBUS: 01/00000000- 0000-8899- 0000-0000000000 00/host0/ target0: 0:0/0:0: 0:0/block/ sda/sda14 (block) 29T12:09: 25.397301+ 0000 udevadm[246]: KERNEL[27.838192] add /devices/ LNXSYSTM: 00/LNXSYBUS: 00/PNP0A03: 00/device: 07/VMBUS: 01/00000000- 0000-8899- 0000-0000000000 00/host0/ target0: 0:0/0:0: 0:0/block/ sda/sda14 (block) 29T12:09: 25.405384+ 0000 inotifywait[462]: 1564402165 /dev/disk/ by-partuuid/ 9c72c02a- 6134-4811- 86d8-feee960b40 b2 CREATE 29T12:09: 25.418906+ 0000 udevadm[246]: UDEV [27.860977] add /devices/ LNXSYSTM: 00/LNXSYBUS: 00/PNP0A03: 00/device: 07/VMBUS: 01/00000000- 0000-8899- 0000-0000000000 00/host0/ target0: 0:0/0:0: 0:0/block/ sda/sda14 (block)
2019-07-
2019-07-
2019-07-
2019-07-
These remove/add lines for sda14 are consistent with what I saw when just running `partx` by hand in an instance.
Looking at the passing instance, there is one noticeable difference: the sda14 remove/add KERNEL events are emitted to the log _before_ any of the UDEV events from the resizing are emitted. This means that:
* On the failing instance, we see the first resizing KERNEL event (sda) emitted at 12:09:25.347818 and the sda1 UDEV event emitted at 12:09:25.372478; .025s.
* On the passing instance, we see the first resizing KERNEL event (sda) emitted at 12:14:21.925924 and the sda1 UDEV event emitted at 12:14:22.002377; .076s.
(And, once again, we see that the order in which udev processes those events goes sda15, sda14, sda1.)