udevadm settle persistently failing

[Nix]

I know that you're not supposed to rely on 'udevadm settle' anymore, but
I rely on it across the board for systems with root filesystems that
aren't expected to move around (i.e. all of them), because massively
reengineering working systems' boot processes is generally considered a
bad thing. And it's stopped working. Given how many things expect /dev
to be populated, this has fairly serious effects.

I can be certain that as of somewhere between udev 164 and 167, 'udevadm
settle' has stopped waiting for block devices to appear (though I
suspect others have vanished too). I'm booting udev as recommended in
the release notes, via

udevd --daemon
udevadm trigger --action=add --type=subsystems
udevadm trigger --action=add --type=devices
udevadm settle

but this is what I now see:

,----
| Creating initial device nodes...
| [ 2.035253] <30>udevd[297]: starting version 168
| udevd[297]: specified group 'audio' unknown
|
| [ 2.151279] <30>udevd[297]: converting old udev database
| udevd[316]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv pci:v00001022d00002080sv00001022sd00002080bc06sc00i00': No such file or directory
|
| umount: /run: device is busy.
| (In some cases useful info about processes that use
| the device is found by lsof(8) or fuser(1))
| Cannot find device "gordianet"
| fsck from util-linux 2.19
| udevd[334]: failed to exec[ 2.457619] EXT2-fs (sda1): warning: mounting unchecked fs, running e2fsck is recommended
| ute '/sbin/modprobe' '/sbin/modprobe -bv platform:cs5535-gpio': No such file or directory
|
| udevd[333]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv platform:cs5535-acpi': No such file or directory
|
| udevd[335]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv platform:cs5535-pms': No such file or directory
|
| udevd[336]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv sg': No such file or directory
|
| udevd[339]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv platform:rtc_cmos': No such file or directory
|
| fsck.ext2: No such file or directory while trying to open /dev/sda1
| Possibly non-existent device?
`----

I have no clue why udev is trying to run modprobe when this is a
non-modular kernel with all necessary devices built in. But that's not
important.

By the time of that 'umount', 'udevadm settle' has returned. Shortly
afterwards you see fsck claiming that devices don't exist. Look at
it the filesystem after the resulting failed half-boot and you see:

fold:~# ls -l /dev/sda1
brw-rw---- 1 root disk 8, 1 May 15 18:56 /dev/sda1

it's there. udevadm settle just didn't bother to wait for it to appear.
(This is not a device on a bus for which enumeration takes some time:
it's an SD card on an IDE-lookalike cs5535 bus. I've also seen this
on LVM-atop-RAID-atop-SATA and on ordinary LVM-atop-SATA, so it doesn't
require anything particularly unusual.)

Other things seem to have failed too. I have renaming rules:

SUBSYSTEM=="net", ATTR{address}=="00:00:24:cb:c6:a0", NAME="gordianet"
SUBSYSTEM=="net", ATTR{address}=="00:00:24:cb:c6:a1", NAME="adsl"
SUBSYSTEM=="net", ATTR{address}=="00:00:24:cb:c6:a3", NAME="wireless"

yet the devices were not renamed:

2: eth0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000
link/ether 00:00:24:cb:c6:a0 brd ff:ff:ff:ff:ff:ff
3: eth1: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000
link/ether 00:00:24:cb:c6:a1 brd ff:ff:ff:ff:ff:ff
5: eth3: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000
link/ether 00:00:24:cb:c6:a3 brd ff:ff:ff:ff:ff:ff

Put a 'sleep 1' after the udev call, and everything works.

Anyone know what's going on? I haven't bisected yet (the problem is
intermittent), but I strongly suspect that

commit ead7c62ab7641e150c6d668f939c102a6771ce60
Author: Kay Sievers <***@vrfy.org>
Date: Wed Apr 20 02:18:22 2011 +0200

udevadm: settle - kill alarm()

commit 2181d30a342dd9fb168b7077ae5095849e328689
Author: Kay Sievers <***@vrfy.org>
Date: Wed Apr 20 01:53:03 2011 +0200

timeout handling without alarm()

has broken udevadm settle and caused it to not wait at all. I'll
check that next time I reboot (with my heart in my mouth).

[Tom Gundersen]

I know that you're not supposed to rely on 'udevadm settle' anymore, =

but

I rely on it across the board for systems with root filesystems that
aren't expected to move around (i.e. all of them), because massively
reengineering working systems' boot processes is generally considered=

a

bad thing. And it's stopped working. Given how many things expect /de=

v

to be populated, this has fairly serious effects.
I can be certain that as of somewhere between udev 164 and 167, 'udev=

adm

settle' has stopped waiting for block devices to appear (though I
suspect others have vanished too). I'm booting udev as recommended in
the release notes, via
=C2=A0udevd --daemon
=C2=A0udevadm trigger --action=3Dadd --type=3Dsubsystems
=C2=A0udevadm trigger --action=3Dadd --type=3Ddevices
=C2=A0udevadm settle

We are doing the same on Arch and today I started seeing bug reports
(after the upgrade to udev 168). So here are my two cents:

Most of the time the problem seems to be related to LVM, but I have
also seen regular block devices having problems. As would be expected
using devtmpfs greatly reduces (if not eliminates) the problem. My
guess was (like Nix said) that "udevadm settle" is somehow broken.

Some related bug reports:

Arch: <https://bugs.archlinux.org/task/24288>,
Debian: <http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=3D624010>.

Cheers,

Tom
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug=
" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Kay Sievers]

Post by Tom Gundersen

I know that you're not supposed to rely on 'udevadm settle' anymore,=

but

Post by Tom Gundersen

I rely on it across the board for systems with root filesystems that
aren't expected to move around (i.e. all of them), because massively
reengineering working systems' boot processes is generally considere=

d a

Post by Tom Gundersen

bad thing. And it's stopped working. Given how many things expect /d=

ev

Post by Tom Gundersen

to be populated, this has fairly serious effects.
I can be certain that as of somewhere between udev 164 and 167, 'ude=

vadm

Post by Tom Gundersen

settle' has stopped waiting for block devices to appear (though I
suspect others have vanished too). I'm booting udev as recommended i=

n

Post by Tom Gundersen

the release notes, via
=C2=A0udevd --daemon
=C2=A0udevadm trigger --action=3Dadd --type=3Dsubsystems
=C2=A0udevadm trigger --action=3Dadd --type=3Ddevices
=C2=A0udevadm settle

We are doing the same on Arch and today I started seeing bug reports
Most of the time the problem seems to be related to LVM, but I have
also seen regular block devices having problems. As would be expected
using devtmpfs greatly reduces (if not eliminates) the problem. My
guess was (like Nix said) that "udevadm settle" is somehow broken.

We are sure it's not related to /run? We keep the state there and need
a tmpfs there before udevd is started, and it must not be touched, or
cleaned by some other stuff, that thinks /var/run (bind mount or
symlink) needs to be cleaned during boot.

Devtmpfs solves a lot of settle races, yeah. We should run fine on
tmpfs, but it's the only config that is really tested these days, so
it might be a problem nobody else is really seeing.

The current settle wakes up in exactly the moment the last event is
gone, instead of it sleep()ing in a loop. It might be a bit earlier,
not really before stuff has settled though.

Does this work for you?
time (udevadm trigger; udevadm settle)

It should not return immediately. You can watch the events with:
udevadm monitor
at the same time and check if it really only returns after the last eve=
nt.

Kay
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug=
" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Nix]

Post by Kay Sievers
We are sure it's not related to /run? We keep the state there and need
a tmpfs there before udevd is started, and it must not be touched, or
cleaned by some other stuff, that thinks /var/run (bind mount or
symlink) needs to be cleaned during boot.

Just to confirm, I'm not cleaning out /run, or touching it at all except
to create /run/lock later in boot.

Post by Kay Sievers
Devtmpfs solves a lot of settle races, yeah. We should run fine on
tmpfs, but it's the only config that is really tested these days, so
it might be a problem nobody else is really seeing.

I could turn on devtmpfs, I suppose, except that I have an early
userspace and I'm not sure how I'd need to change it: devtmpfs gets
mounted on the rootfs, doesn't it? This problem isn't happening on the
rootfs, it's on the root filesystem that is overmounted over that. (I'm
using busybox mdev to populate the rootfs /dev because it works for such
a simple case, and never goes wrong because it's too simple to go wrong.
However it's also too simple to be much use for a running system.)

Post by Kay Sievers
The current settle wakes up in exactly the moment the last event is
gone, instead of it sleep()ing in a loop. It might be a bit earlier,
not really before stuff has settled though.
Does this work for you?
time (udevadm trigger; udevadm settle)
udevadm monitor
at the same time and check if it really only returns after the last event.

Hm, well, that seems to be working, at least once the system is all the
way up. But *something* plainly isn't.

On my next boot I'll time the trigger-and-settle pair and see how long
it takes...

[Kay Sievers]

We are sure it's not related to /run? We keep the state there and ne=

ed

a tmpfs there before udevd is started, and it must not be touched, o=

r

cleaned by some other stuff, that thinks /var/run (bind mount or
symlink) needs to be cleaned during boot.

Just to confirm, I'm not cleaning out /run, or touching it at all exc=

ept

to create /run/lock later in boot.

Ok, sounds good.

Devtmpfs solves a lot of settle races, yeah. We should run fine on
tmpfs, but it's the only config that is really tested these days, so
it might be a problem nobody else is really seeing.

I could turn on devtmpfs, I suppose, except that I have an early
userspace and I'm not sure how I'd need to change it: devtmpfs gets
mounted on the rootfs, doesn't it?

If you ask the kernel to do that at compile time or with a parameter,
it does that, but only if the rootfs is mounted by the kernel itself,
not in any initramfs case.

This problem isn't happening on the
rootfs, it's on the root filesystem that is overmounted over that. (I=

'm

using busybox mdev to populate the rootfs /dev because it works for s=

uch

a simple case, and never goes wrong because it's too simple to go wro=

ng.

However it's also too simple to be much use for a running system.)

With devtmpfs you get the "early" /dev for free, and you preserve the
"early" /dev in the real root. Instead of mounting a 'tmpfs' just
mount a 'devtmpfs' at /dev, and it will be magically filled already,
that's the only difference.

When mounting the real root, just mount --move it over to the real
root before switching to the real root.

The current settle wakes up in exactly the moment the last event is
gone, instead of it sleep()ing in a loop. It might be a bit earlier,
not really before stuff has settled though.
Does this work for you?
=C2=A0 time (udevadm trigger; udevadm settle)
=C2=A0 udevadm monitor
at the same time and check if it really only returns after the last =

event.

Hm, well, that seems to be working, at least once the system is all t=

he

way up. But *something* plainly isn't.
On my next boot I'll time the trigger-and-settle pair and see how lon=

g

it takes...

Good.

Maybe you can run:
udevadm monitor
in the background writing to a file, and get timestamps of your command=
s too.

=46or testing, you could also add test rules like:
KERNEL=3D=3D"null", PROGRAM=3D"/bin/sleep 10"

Which should make settle definitely block for that amount of time.

Kay
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug=
" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Nix]

Post by Kay Sievers
With devtmpfs you get the "early" /dev for free, and you preserve the
"early" /dev in the real root. Instead of mounting a 'tmpfs' just
mount a 'devtmpfs' at /dev, and it will be magically filled already,
that's the only difference.
When mounting the real root, just mount --move it over to the real
root before switching to the real root.

I'll have to see what busybox's switch_root does. I know it deletes
the entire contents of the root directory it switches away from: I'll
have to make sure that doesn't somehow include moved-away mountpoints.
(I doubt it does.)

Post by Kay Sievers
udevadm monitor
in the background writing to a file, and get timestamps of your commands too.

They're fine.

After a bunch of straces, I think the problem is different. As I
suspected from its intermittent nature, it's a race.

When udevd starts up, it looks for an old database and converts it into
a new-style /run database. This takes nonzero time, and is done *after*
daemonization. Unfortunately, in the same time window it is quite
possible to fit a pair of 'udevadm trigger's and a 'udevadm settle': and
when udevadm settle kicks up and finds that udev hasn't even initialized
yet, what does it do? Well, unless I misread the code
udev_queue_get_queue_is_empty() returns 1 in this situation, so 'udevadm
settle' returns EXIT_SUCCESS, and boom.

My evidence for this is very thin: it's no more than a hypothesis
really. My only evidence for this so far is that I haven't managed to
get the failure to happen unless I mkdir the old udev directories first
to force udev to do an old->new db conversion. It would be nice to
gather more data, but it's hard to do that without perturbing the race
:/ even an ls of /run slows it down enough that it doesn't happen
anymore. Hm, perhaps an echo would be fast enough, it's a shell
builtin after all...

If I'm right (and I'm not sure I am, but it feels plausible), then I
suspect the only fix is to move the db conversion so that it happens
before daemonization.

[Marco d'Itri]

Post by Nix
My evidence for this is very thin: it's no more than a hypothesis
really. My only evidence for this so far is that I haven't managed to
get the failure to happen unless I mkdir the old udev directories first
to force udev to do an old->new db conversion. It would be nice to

The Debian initramfs does not do this, so I do not think that this is
the cause.

[Nix]

Post by Marco d'Itri

Post by Nix
My evidence for this is very thin: it's no more than a hypothesis
really. My only evidence for this so far is that I haven't managed to
get the failure to happen unless I mkdir the old udev directories first
to force udev to do an old->new db conversion. It would be nice to

The Debian initramfs does not do this, so I do not think that this is
the cause.

Curses. Oh well, back to the research drawing board.

[Kay Sievers]

Post by Nix

With devtmpfs you get the "early" /dev for free, and you preserve th=

e

Post by Nix

"early" /dev in the real root. Instead of mounting a 'tmpfs' just
mount a 'devtmpfs' at /dev, and it will be magically filled already,
that's the only difference.
When mounting the real root, just mount --move it over to the real
root before switching to the real root.

I'll have to see what busybox's switch_root does. I know it deletes
the entire contents of the root directory it switches away from: I'll
have to make sure that doesn't somehow include moved-away mountpoints=

=2E

Post by Nix
(I doubt it does.)

=C2=A0 udevadm monitor
in the background writing to a file, and get timestamps of your comm=

ands too.

Post by Nix
They're fine.
After a bunch of straces, I think the problem is different. As I
suspected from its intermittent nature, it's a race.
When udevd starts up, it looks for an old database and converts it in=

to

Post by Nix
a new-style /run database. This takes nonzero time, and is done *afte=

r*

Post by Nix
daemonization. Unfortunately, in the same time window it is quite
possible to fit a pair of 'udevadm trigger's and a 'udevadm settle': =

and

Post by Nix
when udevadm settle kicks up and finds that udev hasn't even initiali=

zed

Post by Nix
yet, what does it do? Well, unless I misread the code
udev_queue_get_queue_is_empty() returns 1 in this situation, so 'udev=

adm

Post by Nix
settle' returns EXIT_SUCCESS, and boom.
My evidence for this is very thin: it's no more than a hypothesis
really. My only evidence for this so far is that I haven't managed to
get the failure to happen unless I mkdir the old udev directories fir=

st

Post by Nix
to force udev to do an old->new db conversion. It would be nice to
gather more data, but it's hard to do that without perturbing the rac=

e

Post by Nix
:/ even an ls of /run slows it down enough that it doesn't happen
anymore. Hm, perhaps an echo would be fast enough, it's a shell
builtin after all...
If I'm right (and I'm not sure I am, but it feels plausible), then I
suspect the only fix is to move the db conversion so that it happens
before daemonization.

Hmm, the trigger should increase the kernel's current uevent seqnum.
udev_queue_get_queue_is_empty() should see that there are events
pending, not seen by udevd, and should make settle block until they
are all handled.

But maybe udev_queue_export_new() needs to move above the daemonize?
It will create the initial queue file, that will make settle check for
the udevd vs. kernel number. That could be the reason, for the race.

Kay
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug=
" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Kay Sievers]

Post by Kay Sievers

Post by Nix

With devtmpfs you get the "early" /dev for free, and you preserve t=

he

Post by Kay Sievers

Post by Nix

"early" /dev in the real root. Instead of mounting a 'tmpfs' just
mount a 'devtmpfs' at /dev, and it will be magically filled already=

,

Post by Kay Sievers

Post by Nix

that's the only difference.
When mounting the real root, just mount --move it over to the real
root before switching to the real root.

I'll have to see what busybox's switch_root does. I know it deletes
the entire contents of the root directory it switches away from: I'l=

l

Post by Kay Sievers

Post by Nix
have to make sure that doesn't somehow include moved-away mountpoint=

s.

Post by Kay Sievers

Post by Nix
(I doubt it does.)

=C2=A0 udevadm monitor
in the background writing to a file, and get timestamps of your com=

mands too.

Post by Kay Sievers

Post by Nix
They're fine.
After a bunch of straces, I think the problem is different. As I
suspected from its intermittent nature, it's a race.
When udevd starts up, it looks for an old database and converts it i=

nto

Post by Kay Sievers

Post by Nix
a new-style /run database. This takes nonzero time, and is done *aft=

er*

Post by Kay Sievers

Post by Nix
daemonization. Unfortunately, in the same time window it is quite
possible to fit a pair of 'udevadm trigger's and a 'udevadm settle':=

and

Post by Kay Sievers

Post by Nix
when udevadm settle kicks up and finds that udev hasn't even initial=

ized

Post by Kay Sievers

Post by Nix
yet, what does it do? Well, unless I misread the code
udev_queue_get_queue_is_empty() returns 1 in this situation, so 'ude=

vadm

Post by Kay Sievers

Post by Nix
settle' returns EXIT_SUCCESS, and boom.
My evidence for this is very thin: it's no more than a hypothesis
really. My only evidence for this so far is that I haven't managed t=

o

Post by Kay Sievers

Post by Nix
get the failure to happen unless I mkdir the old udev directories fi=

rst

Post by Kay Sievers

Post by Nix
to force udev to do an old->new db conversion. It would be nice to
gather more data, but it's hard to do that without perturbing the ra=

ce

Post by Kay Sievers

Post by Nix
:/ even an ls of /run slows it down enough that it doesn't happen
anymore. Hm, perhaps an echo would be fast enough, it's a shell
builtin after all...
If I'm right (and I'm not sure I am, but it feels plausible), then I
suspect the only fix is to move the db conversion so that it happens
before daemonization.

Hmm, the trigger should increase the kernel's current uevent seqnum.
udev_queue_get_queue_is_empty() should see that there are events
pending, not seen by udevd, and should make settle block until they
are all handled.
But maybe udev_queue_export_new() needs to move above the daemonize?
It will create the initial queue file, that will make settle check fo=

r

Post by Kay Sievers
the udevd vs. kernel number. That could be the reason, for the race.

Commited a fix to git, that moves the creation of the queue file above
the daemonize. Hopefully that's the race you are seeing.

Kay
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug=
" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Nix]

Post by Kay Sievers
Commited a fix to git, that moves the creation of the queue file above
the daemonize. Hopefully that's the race you are seeing.

I'll try it later today, and scatter printf()s through the code to see
what path it's taking out if that doesn't work.

[Nix]

Post by Kay Sievers
Commited a fix to git, that moves the creation of the queue file above
the daemonize. Hopefully that's the race you are seeing.

Hm, not done more than compile it yet, but there's definitely still
something wrong here: it coredumps if called with invalid arguments.

mutilate:/lib/udev/rules.d# gdb --args /sbin/udevd --no-daemon
[...]
Program received signal SIGSEGV, Segmentation fault.
0x0000000000418a0c in udev_queue_export_cleanup ()
(gdb) bt
#0 udev_queue_export_cleanup (udev_queue_export=0x0) at libudev/libudev-queue-private.c:107
#1 0x00007fffffffc130 in ?? ()
#2 0x00007fffffffc070 in ?? ()
#3 0x0000000000000000 in ?? ()

Fixed by initializing the queue variable to NULL at startup, and making
udev_queue_export_cleanup() just return if called with NULL, like
free().
---
libudev/libudev-queue-private.c | 3 +++
udev/udevd.c | 2 +-
2 files changed, 4 insertions(+), 1 deletions(-)

diff --git a/libudev/libudev-queue-private.c b/libudev/libudev-queue-private.c
index 0dcf9b0..747d555 100644
--- a/libudev/libudev-queue-private.c
+++ b/libudev/libudev-queue-private.c
@@ -104,6 +104,9 @@ void udev_queue_export_cleanup(struct udev_queue_export *udev_queue_export)
{
char filename[UTIL_PATH_SIZE];

+ if (udev_queue_export == NULL)
+ return;
+
util_strscpyl(filename, sizeof(filename), udev_get_run_path(udev_queue_export->udev), "/queue.tmp", NULL);
unlink(filename);

diff --git a/udev/udevd.c b/udev/udevd.c
index e7384e1..937717a 100644
--- a/udev/udevd.c
+++ b/udev/udevd.c
@@ -69,7 +69,7 @@ static void log_fn(struct udev *udev, int priority,
}

static struct udev_rules *rules;
-static struct udev_queue_export *udev_queue_export;
+static struct udev_queue_export *udev_queue_export = NULL;
static struct udev_ctrl *udev_ctrl;
static struct udev_monitor *monitor;
static int worker_watch[2] = { -1, -1 };

[Kay Sievers]

Post by Nix

Commited a fix to git, that moves the creation of the queue file abo=

ve

Post by Nix

the daemonize. Hopefully that's the race you are seeing.

Hm, not done more than compile it yet, but there's definitely still
something wrong here: it coredumps if called with invalid arguments.
--- a/libudev/libudev-queue-private.c
+++ b/libudev/libudev-queue-private.c
@@ -104,6 +104,9 @@ void udev_queue_export_cleanup(struct udev_queue_=

export *udev_queue_export)

Post by Nix
=C2=A0{
=C2=A0 =C2=A0 =C2=A0 =C2=A0char filename[UTIL_PATH_SIZE];
+ =C2=A0 =C2=A0 =C2=A0 if (udev_queue_export =3D=3D NULL)
+ =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 return;
+

Committed.

Post by Nix
--- a/udev/udevd.c
+++ b/udev/udevd.c
@@ -69,7 +69,7 @@ static void log_fn(struct udev *udev, int priority,
=C2=A0}
=C2=A0static struct udev_rules *rules;
-static struct udev_queue_export *udev_queue_export;
+static struct udev_queue_export *udev_queue_export =3D NULL;

That's not needed for static vars.

Thanks,
Kay
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug=
" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Nix]

Post by Kay Sievers

Post by Nix
--- a/udev/udevd.c
+++ b/udev/udevd.c
@@ -69,7 +69,7 @@ static void log_fn(struct udev *udev, int priority=

,

Post by Kay Sievers

Post by Nix
=C2=A0}
=C2=A0static struct udev_rules *rules;
-static struct udev_queue_export *udev_queue_export;
+static struct udev_queue_export *udev_queue_export =3D NULL;

That's not needed for static vars.

Oh yes. *slaps self*

Obviously I am too tired to be working on Hello World, let alone stuff
running as root...

btw, that patch might have worked. I had a trouble-free boot without
pausing this time... but of course this is an intermittent bug so it
is hard to be sure.

I'll yell if it goes wrong again.

--=20
NULL && (void)
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug=
" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[DJ Lucas]

Post by Tom Gundersen

Post by Nix
I know that you're not supposed to rely on 'udevadm settle' anymore, but
I rely on it across the board for systems with root filesystems that
aren't expected to move around (i.e. all of them), because massively
reengineering working systems' boot processes is generally considered a
bad thing. And it's stopped working. Given how many things expect /dev
to be populated, this has fairly serious effects.
I can be certain that as of somewhere between udev 164 and 167, 'udevadm
settle' has stopped waiting for block devices to appear (though I
suspect others have vanished too). I'm booting udev as recommended in
the release notes, via
udevd --daemon
udevadm trigger --action=add --type=subsystems
udevadm trigger --action=add --type=devices
udevadm settle

We are doing the same on Arch and today I started seeing bug reports
Most of the time the problem seems to be related to LVM, but I have
also seen regular block devices having problems. As would be expected
using devtmpfs greatly reduces (if not eliminates) the problem. My
guess was (like Nix said) that "udevadm settle" is somehow broken.
Arch:<https://bugs.archlinux.org/task/24288>,
Debian:<http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=624010>.
Cheers,
Tom
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug" in
More majordomo info at http://vger.kernel.org/majordomo-info.html

Just to add a "me too" regarding regular block devices. First noticed
with 168, coming from 165. /dev was tmpfs and swap is /dev/sda3 and
mounted immediately after udevadm --settle. Kernel is 2.6.36.2. In
addition to the udev change, I added the /run mount point to the mix
(started very early, directly in rc before any scripts are run). Moving
to devtmpfs 'fixed' it for me, but that was because devtmpfs has the raw
sd* nodes, as explained to me by another dev. If I flip to use by-id, it
breaks again. I plan to go back and see exactly where stuff broke, but
haven't had the time just yet, more pressing issues. Probably a
Wednesday evening project (CDT).

-- DJ Lucas

[DJ Lucas]

Probably a Wednesday evening project (CDT).

Nevermind, found time. Tracked it down to this commit:

http://git.kernel.org/?p=linux/hotplug/udev.git;a=commit;h=ff2c503df091e6e4e9ab48cdb6df6ec8b7b525d0

-- DJ Lucas

[Kay Sievers]

I know that you're not supposed to rely on 'udevadm settle' anymore, =

but

I rely on it across the board for systems with root filesystems that
aren't expected to move around (i.e. all of them), because massively
reengineering working systems' boot processes is generally considered=

a

bad thing. And it's stopped working. Given how many things expect /de=

v

to be populated, this has fairly serious effects.
I can be certain that as of somewhere between udev 164 and 167, 'udev=

adm

settle' has stopped waiting for block devices to appear (though I
suspect others have vanished too). I'm booting udev as recommended in
the release notes, via
=C2=A0udevd --daemon
=C2=A0udevadm trigger --action=3Dadd --type=3Dsubsystems
=C2=A0udevadm trigger --action=3Dadd --type=3Ddevices
=C2=A0udevadm settle
,----
| Creating initial device nodes...
| [ =C2=A0 =C2=A02.035253] <30>udevd[297]: starting version 168
| udevd[297]: specified group 'audio' unknown
|
| [ =C2=A0 =C2=A02.151279] <30>udevd[297]: converting old udev databa=

se

| udevd[316]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv =

pci:v00001022d00002080sv00001022sd00002080bc06sc00i00': No such file or=
directory

|
| umount: /run: device is busy.

What's 'umount /run' during bootup? That sounds really strange.

| =C2=A0 =C2=A0 =C2=A0 =C2=A0 (In some cases useful info about proces=

ses that use

| =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0the device is found by lsof(8) or=

fuser(1))

| Cannot find device "gordianet"
| fsck from util-linux 2.19
| udevd[334]: failed to exec[ =C2=A0 =C2=A02.457619] EXT2-fs (sda1): =

warning: mounting unchecked fs, running e2fsck is recommended

| ute '/sbin/modprobe' '/sbin/modprobe -bv platform:cs5535-gpio': No =

such file or directory

|
| udevd[333]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv =

platform:cs5535-acpi': No such file or directory

|
| udevd[335]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv =

platform:cs5535-pms': No such file or directory

|
| udevd[336]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv =

sg': No such file or directory

|
| udevd[339]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv =

platform:rtc_cmos': No such file or directory

|
| fsck.ext2: No such file or directory while trying to open /dev/sda1
| Possibly non-existent device?
`----
I have no clue why udev is trying to run modprobe when this is a
non-modular kernel with all necessary devices built in. But that's no=

t

important.

Udev has no idea what the kernel supports, it calls modprobe for all
devices with a 'modalias' but no attached driver.

By the time of that 'umount', 'udevadm settle' has returned. Shortly
afterwards you see fsck claiming that devices don't exist. Look at
fold:~# ls -l /dev/sda1
brw-rw---- 1 root disk 8, 1 May 15 18:56 /dev/sda1
it's there. udevadm settle just didn't bother to wait for it to appea=

r.

it's an SD card on an IDE-lookalike cs5535 bus. I've also seen this
on LVM-atop-RAID-atop-SATA and on ordinary LVM-atop-SATA, so it doesn=

't

require anything particularly unusual.)

Sounds weird. Settle should not return at that point. You are not
altering the content of /run/udev/ or /dev/.udev/ in any way right?
And you provide the /run tmpfs before you start udevd and don't touch
it again, right?

SUBSYSTEM=3D=3D"net", ATTR{address}=3D=3D"00:00:24:cb:c6:a0", NAME=3D=

"gordianet"

SUBSYSTEM=3D=3D"net", ATTR{address}=3D=3D"00:00:24:cb:c6:a1", NAME=3D=

"adsl"

SUBSYSTEM=3D=3D"net", ATTR{address}=3D=3D"00:00:24:cb:c6:a3", NAME=3D=

"wireless"
Hmm, that should be unrelated to the possible settle problem

2: eth0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 10=

00

=C2=A0 =C2=A0link/ether 00:00:24:cb:c6:a0 brd ff:ff:ff:ff:ff:ff
3: eth1: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 10=

00

=C2=A0 =C2=A0link/ether 00:00:24:cb:c6:a1 brd ff:ff:ff:ff:ff:ff
5: eth3: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 10=

00

=C2=A0 =C2=A0link/ether 00:00:24:cb:c6:a3 brd ff:ff:ff:ff:ff:ff
Put a 'sleep 1' after the udev call, and everything works.

Which call? The trigger?

Kay
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug=
" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Nix]

Post by Kay Sievers

Post by Nix
,----
| Creating initial device nodes...
| [ =C2=A0 =C2=A02.035253] <30>udevd[297]: starting version 168
| udevd[297]: specified group 'audio' unknown
|
| [ =C2=A0 =C2=A02.151279] <30>udevd[297]: converting old udev datab=

ase

Post by Kay Sievers

Post by Nix
| udevd[316]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv=

pci:v00001022d00002080sv00001022sd00002080bc06sc00i00': No such file o=
r directory

Post by Kay Sievers

Post by Nix
|
| umount: /run: device is busy.

What's 'umount /run' during bootup? That sounds really strange.

Hm, I didn't notice that. Yes, that does seem very odd indeed.

I'll have a look soon, if probably not on that system (it's a headless
system that does my firewalling so quite hard to reboot). I see the
symptoms on other systems too.

Post by Kay Sievers

Post by Nix
| udevd[339]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv=

platform:rtc_cmos': No such file or directory

Post by Kay Sievers

Post by Nix
|
| fsck.ext2: No such file or directory while trying to open /dev/sda=

1

Post by Kay Sievers

Post by Nix
| Possibly non-existent device?
`----
I have no clue why udev is trying to run modprobe when this is a
non-modular kernel with all necessary devices built in. But that's n=

ot

Post by Kay Sievers

Post by Nix
important.

Udev has no idea what the kernel supports, it calls modprobe for all
devices with a 'modalias' but no attached driver.

Yeah, it's not terribly important (though why they even have a modalias
if this kernel does not have modules built in is also unclear. Anyway,
it can do no harm, since modprobe doesn't even exist on that system.)

Post by Kay Sievers

Post by Nix
fold:~# ls -l /dev/sda1
brw-rw---- 1 root disk 8, 1 May 15 18:56 /dev/sda1
it's there. udevadm settle just didn't bother to wait for it to appe=

ar.

Post by Kay Sievers

Post by Nix
(This is not a device on a bus for which enumeration takes some time=
it's an SD card on an IDE-lookalike cs5535 bus. I've also seen this
on LVM-atop-RAID-atop-SATA and on ordinary LVM-atop-SATA, so it does=

n't

Post by Kay Sievers

Post by Nix
require anything particularly unusual.)

Sounds weird. Settle should not return at that point.

Agreed! (This is why I suspect the timeout stuff is simply timing out
immediately.)

Post by Kay Sievers
You are not
altering the content of /run/udev/ or /dev/.udev/ in any way right?

Gods, no. Recipe for disaster.

Post by Kay Sievers
And you provide the /run tmpfs before you start udevd and don't touch
it again, right?

ooo! possible bug. Here's my udev startup script:

mount -n /proc
mount -n /sys
mount -n /run
[...]
mount_tmpfs
mkdir -p $udev_root/.udev/db $udev_root/.udev/queue $udev_root/.udev/fa=
iled
echo "Creating initial device nodes..."
udevd --daemon
udevadm trigger --action=3Dadd --type=3Dsubsystems
udevadm trigger --action=3Dadd --type=3Ddevices
udevadm settle
sleep 1

*That* is going to cause udev to try to convert from the old to the new
udev database format every single time it starts, even though there *is=
*
no old udev database there, just skeletal directories. I wonder if
that's causing it?

(I've ripped that mkdir out. Let's see if that fixes things. If it does=
,
this suggests that udev needs further bulletproofing, because my udev
startup script was derived directly from one provided by earlier
versions of udev: a *lot* of people will have scripts like it.)

Post by Kay Sievers

Post by Nix
SUBSYSTEM=3D=3D"net", ATTR{address}=3D=3D"00:00:24:cb:c6:a0", NAME=3D=

"gordianet"

Post by Kay Sievers

Post by Nix
SUBSYSTEM=3D=3D"net", ATTR{address}=3D=3D"00:00:24:cb:c6:a1", NAME=3D=

"adsl"

Post by Kay Sievers

Post by Nix
SUBSYSTEM=3D=3D"net", ATTR{address}=3D=3D"00:00:24:cb:c6:a3", NAME=3D=

"wireless"

Post by Kay Sievers
Hmm, that should be unrelated to the possible settle problem

Yeah. The rename-failure only seems to happen when the settle failure
happens, so perhaps it's related to parts of the startup script messing
with the interfaces and causing the kernel to ban renames because
they're in use. Obviously this doesn't happen if we're still sitting in
'udevadm settle' when this takes place.

Post by Kay Sievers

Post by Nix
2: eth0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1=

000

Post by Kay Sievers

Post by Nix
=C2=A0 =C2=A0link/ether 00:00:24:cb:c6:a0 brd ff:ff:ff:ff:ff:ff
3: eth1: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1=

000

Post by Kay Sievers

Post by Nix
=C2=A0 =C2=A0link/ether 00:00:24:cb:c6:a1 brd ff:ff:ff:ff:ff:ff
5: eth3: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1=

000

Post by Kay Sievers

Post by Nix
=C2=A0 =C2=A0link/ether 00:00:24:cb:c6:a3 brd ff:ff:ff:ff:ff:ff
Put a 'sleep 1' after the udev call, and everything works.

Which call? The trigger?

See above: it was right after the settle call.

Anyway, more tomorrow sometime after more testing. (It's past midnight
here.)

--=20
NULL && (void)
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug=
" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

[Kay Sievers]

Post by Nix

Post by Kay Sievers
What's 'umount /run' during bootup? That sounds really strange.

Hm, I didn't notice that. Yes, that does seem very odd indeed.
I'll have a look soon, if probably not on that system (it's a headles=

s

Post by Nix
system that does my firewalling so quite hard to reboot). I see the
symptoms on other systems too.

Post by Kay Sievers

| udevd[339]: failed to execute '/sbin/modprobe' '/sbin/modprobe -b=

v platform:rtc_cmos': No such file or directory

Post by Nix

Post by Kay Sievers

I have no clue why udev is trying to run modprobe when this is a
non-modular kernel with all necessary devices built in. But that's =

not

Post by Nix

Post by Kay Sievers

important.

Udev has no idea what the kernel supports, it calls modprobe for all
devices with a 'modalias' but no attached driver.

Yeah, it's not terribly important (though why they even have a modali=

as

Post by Nix
if this kernel does not have modules built in is also unclear. Anyway=

,

Post by Nix
it can do no harm, since modprobe doesn't even exist on that system.)

Yeah, you could #ifdef the modalias export if the kernel does not
support module loading. This is not optimized.

It' probably just easier to delete the default udev rule that calls
modprobe, if you don't need it. :)

Post by Nix

Post by Kay Sievers

fold:~# ls -l /dev/sda1
brw-rw---- 1 root disk 8, 1 May 15 18:56 /dev/sda1
it's there. udevadm settle just didn't bother to wait for it to app=

ear.

Post by Nix

Post by Kay Sievers

(This is not a device on a bus for which enumeration takes some tim=
it's an SD card on an IDE-lookalike cs5535 bus. I've also seen this
on LVM-atop-RAID-atop-SATA and on ordinary LVM-atop-SATA, so it doe=

sn't

Post by Nix

Post by Kay Sievers

require anything particularly unusual.)

Sounds weird. Settle should not return at that point.

Agreed! (This is why I suspect the timeout stuff is simply timing out
immediately.)

Yeah, that could happen too, if /run/udev/queue.bin would be deleted
by some cleanup script, after udevd is started.

Post by Nix

Post by Kay Sievers
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0=

=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 You are not

Post by Nix

Post by Kay Sievers
altering the content of /run/udev/ or /dev/.udev/ in any way right?

Gods, no. Recipe for disaster.

Ok, fine.

Post by Nix

Post by Kay Sievers
And you provide the /run tmpfs before you start udevd and don't touc=

h

Post by Nix

Post by Kay Sievers
it again, right?

mount -n /proc
mount -n /sys
mount -n /run
[...]
mount_tmpfs
mkdir -p $udev_root/.udev/db $udev_root/.udev/queue $udev_root/.udev/=

failed

Yeah, never create any private directories of udevd. Most of them do
not even exist anymore in today's udev.

Post by Nix
echo "Creating initial device nodes..."
udevd --daemon
udevadm trigger --action=3Dadd --type=3Dsubsystems
udevadm trigger --action=3Dadd --type=3Ddevices
udevadm settle
sleep 1
*That* is going to cause udev to try to convert from the old to the n=

ew

Post by Nix
udev database format every single time it starts, even though there *=

is*

Post by Nix
no old udev database there, just skeletal directories. I wonder if
that's causing it?
(I've ripped that mkdir out. Let's see if that fixes things. If it do=

es,

Post by Nix
this suggests that udev needs further bulletproofing, because my udev
startup script was derived directly from one provided by earlier
versions of udev: a *lot* of people will have scripts like it.)

Yeah, not a good idea to fiddle around with udev internals. The
existence of the old directory names indicates a need to convert. It
should not really break anything, just waste some time during udevd
startup.

Post by Nix

Post by Kay Sievers

SUBSYSTEM=3D=3D"net", ATTR{address}=3D=3D"00:00:24:cb:c6:a0", NAME=3D=

"gordianet"

Post by Nix

Post by Kay Sievers

SUBSYSTEM=3D=3D"net", ATTR{address}=3D=3D"00:00:24:cb:c6:a1", NAME=3D=

"adsl"

Post by Nix

Post by Kay Sievers

SUBSYSTEM=3D=3D"net", ATTR{address}=3D=3D"00:00:24:cb:c6:a3", NAME=3D=

"wireless"

Post by Nix

Post by Kay Sievers
Hmm, that should be unrelated to the possible settle problem

Yeah. The rename-failure only seems to happen when the settle failure
happens, so perhaps it's related to parts of the startup script messi=

ng

Post by Nix
with the interfaces and causing the kernel to ban renames because
they're in use. Obviously this doesn't happen if we're still sitting =

in

Post by Nix
'udevadm settle' when this takes place.

Yeah, that could explain it. A soon as the netif is up, we can not
rename it anymore.

Post by Nix

Post by Kay Sievers

Put a 'sleep 1' after the udev call, and everything works.

Which call? The trigger?

See above: it was right after the settle call.

I see. Hmm, no good idea why this would be.

Post by Nix
Anyway, more tomorrow sometime after more testing. (It's past midnigh=

t

Post by Nix
here.)

Sounds good, let me know, if you find something out.

Kay
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug=
" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html