hot-plugged USB Harddisk executes backup script in /etc/hotplug/usb

[Clemens Koller <clemens.koller@anagramm.de>]

Hello!

I want to start a backup script in /etc/hotplug/usb whenever I connect
an external USB harddisk (Maxtor OneTouch 300GB) to our fileserver to
make weekly rotating backups.

Kernel: 2.6.14 (not .2 yet)
Platform: i686
System: udev-075

Whenever I plug (turn on) the external harddisk, udevmonitor shows me
nice events and my script is called. But it's called TWICE at the same
time which leads to mount conflicts and other strange things.
If I call my backup script manually, it works fine.

The whole system was working on our "old" fileserver running 2.6.11.5
without udev. The configuration was adopted from the old system, by
copying the script called anabackup to /etc/hotplug/usb
and adding:

$ cat /etc/hotplug/usb.usermap
# usb module         match_flags idVendor idProduct bcdDevice_lo bcdDevice_hi bDeviceClass bDeviceSubClass bDeviceProtocol bInterfaceClass bInterfaceSubClass bInterfaceProtocol driver_info
anabackup       0x03 0x0d49 0x7000 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x0

The distribution is a fresh installation of a CRUX Linux 2.1
(from scratch) system without strange bells and whistles.
I updated from udev-071 to udev-075 but the behaviour didn't change.

Any ideas, what's wrong here?

Thanks in advance,

Clemens

-----------------------------------------------------------------------------
PLUGGING:

$ tail -f /var/log/messages
Nov 17 17:04:09 rio kernel: usb 1-1: new high speed USB device using ehci_hcd and address 7
Nov 17 17:04:09 rio kernel: scsi5 : SCSI emulation for USB Mass Storage devices
Nov 17 17:04:14 rio kernel:   Vendor: Maxtor    Model: OneTouch          Rev: 0201
Nov 17 17:04:14 rio kernel:   Type:   Direct-Access                      ANSI SCSI revision: 00
Nov 17 17:04:14 rio kernel: SCSI device sda: 585938944 512-byte hdwr sectors (300001 MB)
Nov 17 17:04:14 rio kernel: sda: assuming drive cache: write through
Nov 17 17:04:14 rio kernel: SCSI device sda: 585938944 512-byte hdwr sectors (300001 MB)
Nov 17 17:04:14 rio kernel: sda: assuming drive cache: write through
Nov 17 17:04:15 rio kernel:  sda: sda1 sda2 sda3
Nov 17 17:04:15 rio kernel: Attached scsi disk sda at scsi5, channel 0, id 0, lun 0
Nov 17 17:04:15 rio scsi.agent[18074]: disk at /devices/pci0000:00/0000:00:0b.2/usb1/1-1/1-1:1.0/host5/target5:0:0/5:0:0:0
Nov 17 17:04:37 rio scsi.agent[18155]: disk at /devices/pci0000:00/0000:00:0b.2/usb1/1-1/1-1:1.0/host5/target5:0:0/5:0:0:0

Note: The last line shows up twice and delayed by several seconds.
But a echo "\007" > /dev/console in my script tells me that it gets
called twice instantaneously (pairs of beeps).
Well... WHY?! I guess the problem is somewhere around scsi.agent.
Wrong kernel configuration? Any ideas where to start debugging?

root@rio:/etc/hotplug/usb$ udevmonitor
udevmonitor prints the received event from the kernel [UEVENT]
and the event which udev sends out after rule processing [UDEV]

UEVENT[1132243449.986726] add@/devices/pci0000:00/0000:00:0b.2/usb1/1-1
UEVENT[1132243449.986851] add@/devices/pci0000:00/0000:00:0b.2/usb1/1-1/1-1:1.0
UEVENT[1132243449.986900] add@/class/scsi_host/host5
UEVENT[1132243449.986944] add@/class/usb_device/usbdev1.7
UEVENT[1132243454.948573] add@/devices/pci0000:00/0000:00:0b.2/usb1/1-1/1-1:1.0/host5/target5:0:0/5:0:0:0
UEVENT[1132243454.996280] add@/block/sda
UEVENT[1132243455.216593] add@/block/sda/sda1
UEVENT[1132243455.216692] add@/block/sda/sda2
UEVENT[1132243455.216738] add@/block/sda/sda3
UEVENT[1132243455.216783] add@/class/scsi_device/5:0:0:0

-----------------------------------------------------------------------------
UNPLUGGING:

$ tail -f /var/log/messages
Nov 17 17:27:58 rio -- MARK --
Nov 17 17:45:33 rio kernel: usb 1-1: USB disconnect, address 7

$ udevmonitor
UEVENT[1132245933.614131] remove@/class/scsi_device/5:0:0:0
UEVENT[1132245933.614221] remove@/block/sda/sda3
UEVENT[1132245933.614269] remove@/block/sda/sda2
UEVENT[1132245933.614314] remove@/block/sda/sda1
UEVENT[1132245933.614360] remove@/block/sda
UEVENT[1132245933.614404] remove@/devices/pci0000:00/0000:00:0b.2/usb1/1-1/1-1:1.0/host5/target5:0:0/5:0:0:0
UEVENT[1132245933.614451] remove@/class/scsi_host/host5
UEVENT[1132245933.614495] remove@/devices/pci0000:00/0000:00:0b.2/usb1/1-1/1-1:1.0
UEVENT[1132245933.614540] remove@/class/usb_device/usbdev1.7
UEVENT[1132245933.614584] remove@/devices/pci0000:00/0000:00:0b.2/usb1/1-1

-----------------------------------------------------------------------------
OTHER INFO
root@rio:/etc/hotplug/usb$ udevinfo -V
udevinfo, version 075

root@rio:/etc/hotplug/usb$ udevinfo -a -p /sys/block/sda

udevinfo starts with the device the node belongs to and then walks up the
device chain, to print for every device found, all possibly useful attributes
in the udev key format.
Only attributes within one device section may be used together in one rule,
to match the device for which the node will be created.

device '/sys/block/sda' has major:minor 8:0
  looking at class device '/sys/block/sda':
    KERNEL="sda"
    SUBSYSTEM="block"
    SYSFS{dev}="8:0"
    SYSFS{range}="16"
    SYSFS{removable}="0"
    SYSFS{size}="585938944"
    SYSFS{stat}="       1        0        8       28        0        0        0        0        0       28       28"

follow the "device"-link to the physical device:
  looking at the device chain at '/sys/devices/pci0000:00/0000:00:0b.2/usb1/1-1/1-1:1.0/host4/target4:0:0/4:0:0:0':
    BUS="scsi"
    ID="4:0:0:0"
    DRIVER="sd"
    SYSFS{device_blocked}="0"
    SYSFS{iocounterbits}="32"
    SYSFS{iodone_cnt}="0x6"
    SYSFS{ioerr_cnt}="0x0"
    SYSFS{iorequest_cnt}="0x6"
    SYSFS{max_sectors}="240"
    SYSFS{model}="OneTouch        "
    SYSFS{queue_depth}="1"
    SYSFS{queue_type}="none"
    SYSFS{rev}="0201"
    SYSFS{scsi_level}="3"
    SYSFS{state}="running"
    SYSFS{timeout}="30"
    SYSFS{type}="0"
    SYSFS{vendor}="Maxtor  "

  looking at the device chain at '/sys/devices/pci0000:00/0000:00:0b.2/usb1/1-1/1-1:1.0/host4/target4:0:0':
    BUS=""
    ID="target4:0:0"
    DRIVER="unknown"

  looking at the device chain at '/sys/devices/pci0000:00/0000:00:0b.2/usb1/1-1/1-1:1.0/host4':
    BUS=""
    ID="host4"
    DRIVER="unknown"

  looking at the device chain at '/sys/devices/pci0000:00/0000:00:0b.2/usb1/1-1/1-1:1.0':
    BUS="usb"
    ID="1-1:1.0"
    DRIVER="usb-storage"
    SYSFS{bAlternateSetting}=" 0"
    SYSFS{bInterfaceClass}="08"
    SYSFS{bInterfaceNumber}="00"
    SYSFS{bInterfaceProtocol}="50"
    SYSFS{bInterfaceSubClass}="06"
    SYSFS{bNumEndpoints}="03"
    SYSFS{modalias}="usb:v0D49p7000d0200dc00dsc00dp00ic08isc06ip50"

  looking at the device chain at '/sys/devices/pci0000:00/0000:00:0b.2/usb1/1-1':
    BUS="usb"
    ID="1-1"
    DRIVER="usb"
    SYSFS{bConfigurationValue}="1"
    SYSFS{bDeviceClass}="00"
    SYSFS{bDeviceProtocol}="00"
    SYSFS{bDeviceSubClass}="00"
    SYSFS{bMaxPacketSize0}="64"
    SYSFS{bMaxPower}="  0mA"
    SYSFS{bNumConfigurations}="1"
    SYSFS{bNumInterfaces}=" 1"
    SYSFS{bcdDevice}="0200"
    SYSFS{bmAttributes}="c0"
    SYSFS{configuration}=""
    SYSFS{devnum}="6"
    SYSFS{idProduct}="7000"
    SYSFS{idVendor}="0d49"
    SYSFS{manufacturer}="Maxtor"
    SYSFS{maxchild}="0"
    SYSFS{product}="OneTouch"
    SYSFS{serial}="A81T990E    "
    SYSFS{speed}="480"
    SYSFS{version}=" 2.00"

  looking at the device chain at '/sys/devices/pci0000:00/0000:00:0b.2/usb1':
    BUS="usb"
    ID="usb1"
    DRIVER="usb"
    SYSFS{bConfigurationValue}="1"
    SYSFS{bDeviceClass}="09"
    SYSFS{bDeviceProtocol}="01"
    SYSFS{bDeviceSubClass}="00"
    SYSFS{bMaxPacketSize0}="8"
    SYSFS{bMaxPower}="  0mA"
    SYSFS{bNumConfigurations}="1"
    SYSFS{bNumInterfaces}=" 1"
    SYSFS{bcdDevice}="0206"
    SYSFS{bmAttributes}="e0"
    SYSFS{configuration}=""
    SYSFS{devnum}="1"
    SYSFS{idProduct}="0000"
    SYSFS{idVendor}="0000"
    SYSFS{manufacturer}="Linux 2.6.14 ehci_hcd"
    SYSFS{maxchild}="4"
    SYSFS{product}="EHCI Host Controller"
    SYSFS{serial}="0000:00:0b.2"
    SYSFS{speed}="480"
    SYSFS{version}=" 2.00"

  looking at the device chain at '/sys/devices/pci0000:00/0000:00:0b.2':
    BUS="pci"
    ID="0000:00:0b.2"
    DRIVER="ehci_hcd"
    SYSFS{class}="0x0c0320"
    SYSFS{device}="0x3104"
    SYSFS{irq}="5"
    SYSFS{local_cpus}="1"
    SYSFS{modalias}="pci:v00001106d00003104sv00000925sd00001234bc0Csc03i20"
    SYSFS{subsystem_device}="0x1234"
    SYSFS{subsystem_vendor}="0x0925"
    SYSFS{vendor}="0x1106"

  looking at the device chain at '/sys/devices/pci0000:00':
    BUS=""
    ID="pci0000:00"
    DRIVER="unknown"

root@rio:/etc/hotplug/usb$


-- 
Clemens Koller
_______________________________
R&D Imaging Devices
Anagramm GmbH
Rupert-Mayer-Str. 45/1
81379 Muenchen
Germany

http://www.anagramm.de
Phone: +49-89-741518-50
Fax: +49-89-741518-19


-------------------------------------------------------
This SF.Net email is sponsored by the JBoss Inc.  Get Certified Today
Register for a JBoss Training Course.  Free Certification Exam
for All Training Attendees Through End of 2005. For more info visit:
http://ads.osdn.com/?ad_idv28&alloc_id\x16845&op=click
_______________________________________________
Linux-hotplug-devel mailing list  http://linux-hotplug.sourceforge.net
Linux-hotplug-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/linux-hotplug-devel