[systemd-devel] systemd195: issue with udev launched script

Thu Nov 15 11:41:06 PST 2012

On Thu, Nov 15, 2012 at 07:40:19PM +0100, Warpme wrote:
> Hi *
> 
> Sometime ago upgraded my ArchLinux (kernel3.3.8) server to systemd195.
> Today I discovered that my backup procedure fails. It was working OK
> with previous systemd.
> Forgive me if this forum is wrong place to ask such questions, but
> as udev is now part of systemd - I decided to ask here...
> I know that long tasks launched by udev should be detached.

No, they aren't detached. They remain in a cgroup for the udev worker
which is eventually pruned. It's completely wrong to launch any long
running task from a udev rule and you should expect that it will be
killed. If you need to launch a process from a udev rule, use
ENV{SYSTEMD_WANTS} to activate a service.

> Maybe some merciful soul help me with finding error in following approach:
> (maybe there is better way do to launching scripts on USN attach ?)
> 
> Goal:
> attaching USB-HD should launch backup script.
> 
> Solution:
> udev rule mounting hd fs and launching script.
>
> udev rule is following:
> SUBSYSTEM=="block", KERNEL=="sd[c-z][0-9]", GOTO="begin"
> GOTO="end"
> LABEL="begin"
>   ACTION=="add", GOTO="begin_add"
>   ACTION=="remove", GOTO="begin_remove"
>   GOTO="end"
> 
> LABEL="begin_add"
>   SYMLINK+="usbhd-%k", GROUP="root"
>   ENV{ID_FS_LABEL_ENC}="usbhd-%k"
>   IMPORT{program}="/sbin/blkid -o udev -p $tempnode"
>   ENV{ID_FS_LABEL_ENC}==".myth.backup", GOTO="backup_begin"
>   ENV{ID_FS_LABEL_ENC}=="USB-Movies*", GOTO="rips_begin"
>   GOTO="user_storage_begin"
> 
> LABEL="backup_begin"
>   ENV{MOUNT_DIR}="/media/$env{ID_FS_LABEL_ENC}"
>   RUN+="/bin/mkdir -p $env{MOUNT_DIR}"
>   RUN+="/bin/mount -t auto -o rw,noauto,noatime /dev/%k $env{MOUNT_DIR}"
>   RUN+="/usr/bin/sleep 15"
>   RUN+="/usr/local/bin/run-backup.sh &"
>   GOTO="end"
> 
> Issue:
> Script starts but seems to be killed by udev :-(
> 
> relevant kernel log:
> Nov 15 19:18:50 systemd-udevd[3749]: LINK 'usbhd-sdc1'
> /etc/udev/rules.d/98-usbhd.rules:52
> Nov 15 19:18:50 systemd-udevd[3749]: IMPORT '/sbin/blkid -o udev -p
> /dev/sdc1' /etc/udev/rules.d/98-usbhd.rules:54
> Nov 15 19:18:50 systemd-udevd[3796]: starting '/sbin/blkid -o udev
> -p /dev/sdc1'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_FS_LABEL=.myth.backup'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_FS_LABEL_ENC=.myth.backup'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_FS_UUID=fd3104ea-d5c0-4a8f-beba-8ab69115b192'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out)
> 'ID_FS_UUID_ENC=fd3104ea-d5c0-4a8f-beba-8ab69115b192'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_FS_SEC_TYPE=ext2'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_FS_VERSION=1.0'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_FS_TYPE=ext3'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_FS_USAGE=filesystem'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_PART_ENTRY_SCHEME=dos'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_PART_ENTRY_TYPE=0x83'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_PART_ENTRY_NUMBER=1'
> Nov 15 19:18:50 systemd-udevd[3749]: '/sbin/blkid -o udev -p
> /dev/sdc1'(out) 'ID_PART_ENTRY_OFFSET=63'
> Nov 15 19:18:50 systemd-udevd[3749]: '/bin/mount -t auto -o
> rw,noauto,noatime /dev/sdc1 /media/.myth.backup' [3798] exit with
> return code 0
> Nov 15 19:18:50 systemd-udevd[3801]: starting '/usr/bin/sleep 15'
> Nov 15 19:18:52 systemd-udevd[180]: validate module index
> Nov 15 19:18:55 systemd-udevd[180]: validate module index
> Nov 15 19:18:58 systemd-udevd[180]: validate module index
> Nov 15 19:19:01 systemd-udevd[180]: validate module index
> Nov 15 19:19:04 systemd-udevd[180]: validate module index
> Nov 15 19:19:05 systemd-udevd[3749]: '/usr/bin/sleep 15' [3801] exit
> with return code 0
> Nov 15 19:19:05 systemd-udevd[3858]: starting
> '/usr/local/bin/run-backup.sh &'
> Nov 15 19:19:07 systemd-udevd[180]: validate module index
> Nov 15 19:19:10 systemd-udevd[180]: validate module index
> Nov 15 19:19:13 systemd-udevd[180]: validate module index
> Nov 15 19:19:16 systemd-udevd[180]: validate module index
> Nov 15 19:19:19 systemd-udevd[180]: worker [3749] /devices/pci0000:00/0000:00:09.0/0000:04:00.0/usb3/3-1/3-1:1.0/host11/target11:0:0/11:0:0:0/block/sdc/sdc1
> timeout; kill it
> Nov 15 19:19:19 systemd-udevd[180]: seq 1787 '/devices/pci0000:00/0000:00:09.0/0000:04:00.0/usb3/3-1/3-1:1.0/host11/target11:0:0/11:0:0:0/block/sdc/sdc1'
> killed
> Nov 15 19:19:19 systemd-udevd[180]: seq 1787 done with -64
> Nov 15 19:19:19 systemd-udevd[180]: validate module index
> Nov 15 19:19:19 systemd-udevd[180]: worker [3749] exit
> Nov 15 19:19:19 systemd-udevd[180]: worker [3749] terminated by
> signal 9 (Killed)
> Nov 15 19:19:19 systemd-udevd[180]: worker [3749] cleaned up
> Nov 15 19:19:22 systemd-udevd[180]: cleanup idle workers
> Nov 15 19:19:22 systemd-udevd[180]: validate module index
> Nov 15 19:19:22 systemd-udevd[3750]: unload module index
> Nov 15 19:19:22 systemd-udevd[180]: worker [3750] exit
> Nov 15 19:19:22 systemd-udevd[180]: worker [3750] cleaned up

> begin:vcard
> fn:Warpme
> n:;Warpme
> email;internet:warpme at o2.pl
> version:2.1
> end:vcard
> 

> _______________________________________________
> systemd-devel mailing list
> systemd-devel at lists.freedesktop.org
> http://lists.freedesktop.org/mailman/listinfo/systemd-devel