Workers do not timeout when udev_log="err"

ardrabczyk commented 3 years ago

Steps to reproduce:

/etc/udev/rules.d/50-test.rules:

ACTION=="add",KERNEL=="sd?[0-9]",RUN+="/home/ja/udev/udev-script.sh"

/home/ja/udev/udev-script.sh:

#!/usr/bin/env sh

echo $$ > /tmp/UDEV
/home/ja/udev/sleep.sh &

/home/ja/udev/sleep.sh:

#!/usr/bin/env sh
sleep 9999

/etc/udev/udev.conf:

# see udev.conf(5) for details

udev_log="err"

Start udevd in daemon mode:

$ /sbin/udevd --daemon

What happens:

Insert an USB stick, /tmp/UDEV gets created but udev-script.sh is quickly reaped:

$ ps   $(cat /tmp/UDEV)
PID TTY      STAT   TIME COMMAND

even though sleep.sh is still running:

$ ps aux | grep '[s]leep'
root     21787  0.0  0.0   4080  3072 ?        S    01:41   0:00 sh /home/ja/udev/sleep.sh
root     21788  0.0  0.0   2452   684 ?        S    01:41   0:00 sleep 9999

What should happen:

When udev_log is set to debug, info or is not set udev-script.sh becomes zombie process:

$ ps $(cat /tmp/UDEV)
PID TTY      STAT   TIME COMMAND
23462 ?        Z      0:00 [sh] <defunct>

and after some time you can see this in /var/log/syslog:

May  3 01:49:36 darkstar kernel: [324524.629614] udevd[23327]: worker [23427] /devices/pci0000:00/0000:00:14.0/usb2/2-6/2-6:1.0/host7/target7:0:0/7:0:0:0/block/sdc/sdc1 is taking a long time
May  3 01:51:36 darkstar kernel: [324644.684026] udevd[23327]: worker [23427] /devices/pci0000:00/0000:00:14.0/usb2/2-6/2-6:1.0/host7/target7:0:0/7:0:0:0/block/sdc/sdc1 timeout; kill it
May  3 01:51:36 darkstar kernel: [324644.684047] udevd[23327]: seq 38047 '/devices/pci0000:00/0000:00:14.0/usb2/2-6/2-6:1.0/host7/target7:0:0/7:0:0:0/block/sdc/sdc1' killed
May  3 01:51:36 darkstar kernel: [324644.684449] udevd[23327]: worker [23427] terminated by signal 9 (Killed)
May  3 01:51:36 darkstar kernel: [324644.684452] udevd[23327]: worker [23427] failed while handling '/devices/pci0000:00/0000:00:14.0/usb2/2-6/2-6:1.0/host7/target7:0:0/7:0:0:0/block/sdc/sdc1'

In this case udev waits not only for death of its own children but also children of children and so on before reaping udev-script.sh by passing a file descriptor that will be inherited by all descendant processes. Why doesn't it work like that with udev_log="err"?

ardrabczyk commented 3 years ago

It looks like a feature - pipes from child to parent are created in udev_event_spawn() only if udev_log is >= LOG_INFO.

bbonev commented 1 year ago

The documentation clearly says that spawned programs should be short lived.

One way to solve the problem is to daemonize the worker that may get delayed (become session leader, detach from parent, close all descriptors). Thus eudev will just trigger the worker execution and continue without waiting for it.

There are also standard ways to implement timeout for the already detached worker - e.g. timeout 5m worker params...

I am closing the issue, in case you can propose a sane fix, please reopen with comments.

eudev-project / eudev

Workers do not timeout when udev_log="err" #197