Bug: 'A start job is running for udev wait for Complete Device Initialization'

[cprise]

When R2 was released, I simply updated my existing R2b3 install to R2.
But recently I had to install Qubes fresh and I used an R2 disc for
that. My system immediately became ill-behaved regarding startup or
shutdown of the bare metal system.

My installation choices which changed are KDE-only (was the default),
Btrfs/no LVM (was Ext4+LVM Thin Provisioning), and no default appVMs.

The problem is:

On boot, I get an idle pause for over 2 minutes with the following
console status:
"A start job is running for udev wait for Complete Device Initialization"

https://groups.google.com/forum/#!topic/qubes-users/PZxr68wtJRw

Note I reported this problem before. The difference is it has gone from
a 1-in-30 rarity to a 90% occurance; Its now practically certain the
delay will happen when I boot.

I found a reference to my symptoms that suggest there is a conflict with
systemd-udev-settle.service:

https://bugs.archlinux.org/task/43023
via https://bbs.archlinux.org/viewtopic.php?id=189106

It mentions an updated acpid as a fix, but dom0 doesn't even have an
acpid package (its masked from the fedora repository). Looking for
recommendations...

[Zrubi]

On 03/30/15 21:19, cprise wrote:

> The problem is:
>
> On boot, I get an idle pause for over 2 minutes with the following
> console status:
> "A start job is running for udev wait for Complete Device Initialization"

I have the same issue - but because I usually restarting my system only
in csase of a kernel/xen updates I do not see this too often.



--
Zrubi

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Can you check the logs afterwards? There should be an info at least
which devices rules caused that. If you'd find there which rules are
responsible, that would be great.

- --
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-----
Version: GnuPG v1

iQEcBAEBAgAGBQJVGmYhAAoJENuP0xzK19csHXwIAIwPwMhElO5s1bGI0JPoi+q4
JOzApUTAnzQ6ByC1NLWYHLttD81lJ5SrLGmHKbvhEu+7LKmpJzDAEiSaZldhlajQ
DRkojNGUTAfuXKQPEpgDYsy6ChjRF9x+WZ44PK48UxNK2a6YCJjsu7grXQ1ouZoD
czY4woLUoU1Us2Zx8bJkBoFF4+rmkTi8GVrajHxKKjsDkuebbnyz3zfKazZniBA5
UGFQxwHF3FIfchOiYcpEagxYqbvkMdZ3xYex7EBOx/ZkuOv08PJIyqgCJPpvARjl
mnFYmQve/4q1Le55+gYLV4eSsk9SerOgNothXofdSRO5z5TXRNd/ojQEj0N0ZB4=
=0w4S
-----END PGP SIGNATURE-----

[cprise]

This is what I got in system messages:

Apr 8 02:22:07 dom0 systemd: Found device Samsung_SSD_840_PRO_Series.
Apr 8 02:22:16 dom0 systemd: Received SIGRTMIN+20 from PID 194 (plymouthd).
Apr 8 02:24:07 dom0 udevadm: udevadm settle - timeout of 120 seconds
reached, the event queue contains:

[...list of 37 USB devices...]

Apr 8 02:24:07 dom0 systemd: systemd-udev-settle.service: main process
exited, code=exited, status=1/FAILURE
Apr 8 02:24:07 dom0 systemd: Failed to start udev Wait for Complete
Device Initialization.
Apr 8 02:24:07 dom0 systemd: Unit systemd-udev-settle.service entered
failed state.


I'll send you the full list as an attachment.

For now, I may just use 'systemctl mask systemd-udev-settle' to stop
these delays.

[cprise]

OK, so the physical trigger for the delay appears to be my Matias Quiet
Pro mechanical USB keyboard. This shows up as two devices in lsusb:
1111:1111 HID device, and a 4 port hub.

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Maybe it do not respond to some requests? Or something is wrong with the
hub (is it working?)?

- --
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-----
Version: GnuPG v1

iQEcBAEBAgAGBQJVJQ3kAAoJENuP0xzK19csmccH/07HLWtTLV3mOEaN/zhjKyfg
/5SsfuD98pMLiF4HftYSqDVtoZZDZfupPwY6uioGvCHl5e9FgbBdHjvm8y9yuEII
hD/rr/zPuKC98kPZCR/+PNBJ/7XGlbRe4i9FNIrEtbTY0saGyAAGaDG1Tdg7o4r6
0SqvaLcmlbOD8F0xgVjhinjDXC7WVTpC7m+3te/utQY67rHAXQ9AVy1IQg7U54CR
w9a+ixCIIochOZsuTMdquwGONH3EC/pPnYbo4DAvqYUElxYq92vRKlw4WHrkLV5i
CanU5n02tK3ur/W7uBWLdbLBiKviuFpRFoj+yrZRS3InZWcDJ4O0hJnqDB51rM0=
=E8Bj
-----END PGP SIGNATURE-----

[cprise]

On 04/08/15 07:15, Marek Marczykowski-Górecki wrote:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
> On Wed, Apr 08, 2015 at 06:59:40AM -0400, cprise wrote:
>> OK, so the physical trigger for the delay appears to be my Matias Quiet Pro
>> mechanical USB keyboard. This shows up as two devices in lsusb: 1111:1111
>> HID device, and a 4 port hub.
>
> Maybe it do not respond to some requests? Or something is wrong with the
> hub (is it working?)?
>
> - --

It works fine, and its never had a problem with any of my systems before
(Windows 7, OSX, Ubuntu) and I've used it for a long time with Qubes
without problems until about 3 months ago.

Curiously, if I mask systemd-udev-settle then unmask it, I can boot
without delays about 7-8 times before they start again.

[cprise]

On 04/08/15 07:15, Marek Marczykowski-Górecki wrote:

> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
> On Wed, Apr 08, 2015 at 06:59:40AM -0400, cprise wrote:
>> OK, so the physical trigger for the delay appears to be my Matias Quiet Pro
>> mechanical USB keyboard. This shows up as two devices in lsusb: 1111:1111
>> HID device, and a 4 port hub.
>
> Maybe it do not respond to some requests? Or something is wrong with the
> hub (is it working?)?
>
> - --

I just got a 2 min. pause without the keyboard attached. :/

I see there is a way to step up the logging level for udev. At this
point, however, I'm going to just mask the udev settle service.

BTW, using plymouth.enble=0 on the kernel command line will prevent the
udev settle delay for me. So maybe the difference is in my new Qubes
install which lacks LVM this time... plymouth is starting the settle
script instead of LVM?? Before I reinstalled I had LVM and the delay
occurred very rarely. Just some speculation.

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

I think it is some race condition and having LVM or not just change some
timing...

- --
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-----
Version: GnuPG v1

iQEcBAEBAgAGBQJVJTF1AAoJENuP0xzK19csiU0H/0uNdAdqjoggl4RWRVo1Ai1g
IgKeDC8lhhzriTeivu8vN+rGMAY1uJwu8Hkt0lSWz4YC4nCC0UxSVZ4/hxRM5VpU
kmsrzPoXTNHBVF5q+5XxKP69TdsVpURu+A4L2deiIUV+UcuP9xFY/Z+UYPdXOz+C
ahgYitgu679hsBEb+Wty5MbWGnV7Cr3QeL94kqQwNx8n9y+P5C6kE2bJb492iHA+
lgbHzPqIAKLvwJGNdglenlEIVxCjJrvoToPEfdX3yt+bX5EkuBbZ+6Nu14t05nJy
vcyxoUJ+/2m4skNAbBF1g+1NswxpFtNrRE4Rmisq/5qB1Tjq0bX7aFS+kf2fyjw=
=iAuG
-----END PGP SIGNATURE-----