USB mouse #71

suedi · 2015-09-29T18:48:25Z

I am on an Arch derivative OS.

Using vdev of date 2015-09-05

Testing first system with udev and USB mouse works.
Switching to vdev and reboot, USB mouse doesn't work

To my eye it looks like vdev is creating the correct entries in /dev

Incorrect interaction with evdev?

This archive contains data from both udev and vdev runs
(OBS! udev-compat.log is not from the same run)
https://www.dropbox.com/s/3u80tifl5wkbxfw/USB_mouse_problem.tar.gz?dl=1

|-- [root     4.0K]  udev
|   |-- [root      29K]  Xorg.0.log
|   |-- [root      75K]  current
|   |-- [root      34K]  udev-dev.txt
|   |-- [root     2.0K]  udev-input.txt
|   `-- [root     3.3K]  udev-lsmod.txt
`-- [root     4.0K]  vdev
    |-- [root      13K]  Xorg.0.log
    |-- [root      71K]  current
    |-- [root     3.4K]  lsmod.txt
    |-- [root      70K]  udev-compat.log
    |-- [root     459K]  vdev-dev.txt
    `-- [root     2.6K]  vdev-input.txt

tried restarting vdevd == nothing changed

tried removing and re-connecting usb mouse == devices disappears and comes again, no mouse
these lines appears in Xorg.log

[  2569.622] (II) config/udev: Adding input device USB Optical Mouse (/dev/input/mouse1)
[  2569.623] (II) No input driver specified, ignoring this device.
[  2569.623] (II) This device may have been added with another device file.

I tried building latest vdev but then /dev/dri went missing altogether, dunnow why
but it halted further testing.

How to proceed, try to solve /dev/dri problem or usb mouse first

Also trying mdev-like-a-boss with files in /etc/X11/xorg.conf.d does get me a working USB mouse

suedi · 2015-10-01T18:47:58Z

Tried a new rebuild of vdev, this time got to desktop but had to wait a long time for X to start up.

...
[   379.680] intel: waited 50000 ms for '/dev/dri/card0' to appear
[   379.751] (EE) open /dev/dri/card0: No such file or directory
[   379.751] (WW) Falling back to old probe method for modesetting
[   379.751] (EE) open /dev/dri/card0: No such file or directory
[   379.751] (II) Loading sub module "fbdevhw"
[   379.751] (II) LoadModule: "fbdevhw"
[   379.753] (II) Loading /usr/lib/xorg/modules/libfbdevhw.so
[   379.753] (II) Module fbdevhw: vendor="X.Org Foundation"
[   379.753]    compiled for 1.17.2, module version = 0.0.2
[   379.753]    ABI class: X.Org Video Driver, version 19.0
[   379.753] (**) FBDEV(1): claimed PCI slot 0@0:2:0
[   379.753] (II) FBDEV(1): using default device
[   379.753] (WW) Falling back to old probe method for vesa
...

Observe! /dev/dri is present on same system with slightly older vdev!?

log files for latest version of vdev per 2015-10-01 regarding no /dev/dri

https://www.dropbox.com/s/hq1l14bj73kdzdb/no-dev-dri-problem.tar.gz?dl=1

suedi · 2015-10-07T16:33:06Z

lsusb for USB mouse

Bus 002 Device 004: ID 192f:0916  
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass            0 
  bDeviceSubClass         0 
  bDeviceProtocol         0 
  bMaxPacketSize0         8
  idVendor           0x192f 
  idProduct          0x0916 
  bcdDevice            2.00
  iManufacturer           0 
  iProduct                2 USB Optical Mouse
  iSerial                 0 
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength           34
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0 
    bmAttributes         0xa0
      (Bus Powered)
      Remote Wakeup
    MaxPower               98mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         3 
      bInterfaceSubClass      1 
      bInterfaceProtocol      2 
      iInterface              0 
        HID Device Descriptor:
          bLength                 9
          bDescriptorType        33
          bcdHID               1.11
          bCountryCode            0 Not supported
          bNumDescriptors         1
          bDescriptorType        34 Report
          wDescriptorLength      64
         Report Descriptors: 
           ** UNAVAILABLE **
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0005  1x 5 bytes
        bInterval              10
Device Status:     0x0000
  (Bus Powered)

jcnelson · 2015-10-08T01:28:39Z

Thank you for sending the logs to me. Apologies for the late reply; I've been sick this past week and had to spend my spare time recovering.

Regarding /dev/dri, I pushed a possible fix a few days ago (I was getting the same problem). Can you try the code as of a81f7bc?

I'm still trying to figure out the problem with your mouse.

suedi · 2015-10-08T14:11:58Z

Apologies are of course accepted, good to see you back in the swing of things.

CONFIRMED - /dev/dri problem is now fixed

Please let me know if you need anything regarding USB-mouse problem

suedi · 2015-10-12T19:16:54Z

I saw you had an USB mouse in #52

Does your USB mouse work flawlessly?

jcnelson · 2015-10-13T05:45:10Z

I'm still trying to figure out the USB mouse problem--I'm having a hard time duplicating it. When I plug a USB mouse into my laptop (running the same vdevd you are, but with X.org 1.17.2), it works as expected.

From your logs, it looks like vdevd is generating the same device files as udev, so I think this might be a problem with libudev-compat.

Can you try the following?

Verify with ldd that Xorg is linked against the libudev-compat's libudev libraries, and not udev's libudev.
Run tail -f /run/vdev/vdevd.log to see if vdevd logs any errors when you plug in your USB mouse.
Run tail -f /tmp/udev-compat.txt to verify that udev-compat propagates the device events when you plug in your USB mouse.

Thanks!

fbt · 2015-10-13T09:35:48Z

Hi, @suedi. Just in case: what are the contents of your /proc/sys/kernel/hotplug file?

suedi · 2015-10-13T17:44:34Z

@fbt

ls /proc/sys/kernel/hotplug -l
-rw-r--r-- 1 root root 0 Oct 13  2015 /proc/sys/kernel/hotplug

cat /proc/sys/kernel/hotplug

its empty

suedi · 2015-10-13T18:28:22Z

I am not sure what you mean by Xorg linked against libudev-compat libraries?
Is there a condition on recompiling Xorg against that? I thought it was a drop-in replacement?

Maybe I misunderstand

anyway

ldd -v Xorg
...
    libudev.so.1 => /usr/lib/libudev.so.1 (0x00007f6db1daa000)
...
    /usr/lib/libudev.so.1:
        libpthread.so.0 (GLIBC_2.2.5) => /usr/lib/libpthread.so.0
        libc.so.6 (GLIBC_2.3) => /usr/lib/libc.so.6
        libc.so.6 (GLIBC_2.9) => /usr/lib/libc.so.6
        libc.so.6 (GLIBC_2.3.3) => /usr/lib/libc.so.6
        libc.so.6 (GLIBC_2.14) => /usr/lib/libc.so.6
        libc.so.6 (GLIBC_2.3.2) => /usr/lib/libc.so.6
        libc.so.6 (GLIBC_2.15) => /usr/lib/libc.so.6
        libc.so.6 (GLIBC_2.4) => /usr/lib/libc.so.6
        libc.so.6 (GLIBC_2.17) => /usr/lib/libc.so.6
        libc.so.6 (GLIBC_2.2.5) => /usr/lib/libc.so.6

libsystemd not present so no old libudev present!?

in tail -f /run/vdev/vdevd.log found this error

02053:00007F9205B7E700: [        action.c:0650] vdev_action_run_sync: DEBUG: run command: '"$VDEV_HELPERS/VBoxCreateUSBNode.sh" $VDEV_MAJOR $VDEV_MINOR $(/bin/cat "$VDEV_OS_SYSFS_MOUNTPOINT/$VDEV_OS_DEVPATH/bDeviceClass" 2>/dev/null) vboxusers'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_MOUNTPOINT=/dev'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_ACTION=add'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_PATH=bus/usb/002/007'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_METADATA=/dev/metadata//dev/bus/usb/002/007'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_GLOBAL_METADATA=/dev/metadata/'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_CONFIG_FILE=/etc/vdev/vdevd.conf'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_MAJOR=189'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_MINOR=134'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_MODE=char'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_HELPERS=/usr/lib/vdev'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_LOGFILE=/run/vdev/vdevd.log'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_INSTANCE=PLL2L7551878OLNLP3P7691M93289PP226K8POKK48KLNN1M85309OPL1M760O6O'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_DAEMONLET=0'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_OS_BUSNUM=002'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_OS_DEVNAME=bus/usb/002/007'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_OS_DEVNUM=007'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_OS_DEVPATH=/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.3'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_OS_DEVTYPE=usb_device'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_OS_PRODUCT=192f/916/200'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_OS_SEQNUM=1838'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_OS_SUBSYSTEM=usb'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_OS_SYSFS_MOUNTPOINT=/sys'
02053:00007F9205B7E700: [        action.c:0653] vdev_action_run_sync: DEBUG: command env: 'VDEV_OS_TYPE=0/0/0'
02053:00007F9205B7E700: [        action.c:0658] vdev_action_run_sync: DEBUG: exit status 1
02053:00007F9205B7E700: [        action.c:0676] vdev_action_run_sync: ERROR: vdev_subprocess('"$VDEV_HELPERS/VBoxCreateUSBNode.sh" $VDEV_MAJOR $VDEV_MINOR $(/bin/cat "$VDEV_OS_SYSFS_MOUNTPOINT/$VDEV_OS_DEVPATH/bDeviceClass" 2>/dev/null) vboxusers', use_shell=1) exit status = 1
02053:00007F9205B7E700: [        action.c:1666] vdev_action_run_commands: ERROR: vdev_action_run_sync('"$VDEV_HELPERS/VBoxCreateUSBNode.sh" $VDEV_MAJOR $VDEV_MINOR $(/bin/cat "$VDEV_OS_SYSFS_MOUNTPOINT/$VDEV_OS_DEVPATH/bDeviceClass" 2>/dev/null) vboxusers') rc = 1
02053:00007F9205B7E700: [        action.c:1677] vdev_action_run_commands: DEBUG: Benchmark: action /etc/vdev/actions/virtualbox-usb_device.act failed (exit 1) in 25 millis

regarding tail -f /tmp/udev-compat.log I don't know what to expect?
files for both tries are included here
https://www.dropbox.com/s/4a2stn77d51in62/tailf_results.tar.gz?dl=1

archive contains files with self explanatory names.

tail_f_vdevdlog.txt
tail_f_udevcompat.log.txt

Will make simple test of disabling virtualbox-usb_device.act and see what happens

jcnelson · 2015-10-13T19:03:31Z

Hi @suedi,

Thank you for sending me more logs!

I am not sure what you mean by Xorg linked against libudev-compat libraries?
Is there a condition on recompiling Xorg against that? I thought it was a drop-in replacement?

It's a drop-in replacement--there's no need to re-compile Xorg. I was trying to see whether or not you still had the systemd libudev installed somewhere, and if so, whether or not the dynamic linker was resolving Xorg's libudev symbols to the right libudev (i.e. the one from libudev-compat).

To confirm, /usr/lib/libudev.so.1 is definitely from libudev-compat, and not systemd libudev, right? IIRC systemd's libudev does not depend on libsystemd, so it shouldn't show up in the ldd output either way.

in tail -f /run/vdev/vdevd.log found this error
The virtualbox USB helper failed. It's probably not related to Xorg not finding your mouse (unless you are running Xorg in a virtualbox VM), but nevertheless I will look more into it. Do you have a special user group for virtualbox users on your system (something like vboxusers)? If not, that's probably why it's failing.

regarding tail -f /tmp/udev-compat.log I don't know what to expect?

I was looking to see that each device vdevd processed had a 4-line stanza with the following format:

udev_generate_data ...
udev_generate_links ...
udev_generate_tags ...
event-put ...

It looks like this is the case for you, which indicates that udev-compat.sh is probably not the cause of the problem.

I need to see more debugging output from libudev-compat. Can you try stopping Xorg, and starting it with startx in the following manner?

$ LIBUDEV_COMPAT_DEBUG=1 startx >/tmp/libudev-compat.txt 2>&1

This will cause libudev to print extra debugging information. When you get a chance, can you run the above command, plug in and unplug your USB mouse, quit X, and send me the contents of /tmp/libudev-compat.txt? Thanks!

fbt · 2015-10-13T19:15:36Z

To clarify: yes, /proc/sys/kernel/hotplug should be emtpy.
The reason I've asked is I've encountered vdev not behaving correctly because I had /sbin/hotplug in it.
Maybe that should be documented btw.

suedi · 2015-10-13T19:26:33Z

No libsystemd means no libudev from systemd

I recognize your point is a valid one especially in an aufs environment
were you can mix things up if not careful

however with libudev.so.1 a symlink to libudev.so.1.6.4

> cmp /usr/lib/libudev.so.1.6.4 /mnt/live/memory/bundles/vdev-20151008.sb/usr/lib/libudev.so.1.6.4 
>

which means in pseudo code
cmp libudev_used_in_system libudev_in_git_vdev_squash_archive

and it comes out equal so yes I'm sure I am using your libudev

I am not running in VirtualBox and have no vboxusers or similar on my system.
VBoxCreateUSBNode.sh does not seem to be the problem.

I am out of time for now but will expediently provide the logs you sought

suedi · 2015-10-13T19:36:56Z

@fbt
Yeah I seem to remember that from @idunham email to devuan

/proc/sys/kernel/hotplug (aka "hotplug helper"):
On each hotplug event, the kernel starts the hotplug helper with
an appropriate environment.
hotplug, hotplug2, and mdev/smdev use this.

netlink:
A daemon connects to the kernel and listens for hotplug events.
udev, s6-devd, nldev, and vdev use this.

devtmpfs:
The kernel maintains a filesystem in RAM containing all devices that
are present, and at hotplug the kernel automatically adds a new device
with default permissions and name.
This can sometimes be used alone; udev and perhaps Android's hotplug
solution rely on this and change the permissions/owners/... after the
fact.

suedi · 2015-10-15T17:35:24Z

I don't use startx but a custom script
however here is the info you asked for

https://www.dropbox.com/s/fxsepffhf6puiy6/libudev-compat.txt.tar.gz?dl=1

I hope I followed the correct procedure!?

What I did

quit X
restart with LIBUDEV_COMPAT_DEBUG=1
plug and unplug USB mouse
quit x
cp file for sharing on github

Tell me if it was wrong procedure, if you want more information
or have some idea to test

If I unplug and replug USB mouse, Xorg.log doesn't change at all

if I do cat /dev/hidraw0 I get a lot of garbage ouput in terminal when moving USB mouse.

Did you test with you USB mouse on laptop with touchpad

suedi · 2015-10-21T15:29:01Z

I have tried many possible and impossible ways to debug this.

Cannot find root cause.

IGNORE BELOW see edit 2!!!!!

What I did find was an artifact in my rc.d script from udev days
( I'm on busybox init )

UDEV="/usr/lib/systemd/systemd-udevd"

now the file /usr/lib/systemd/systemd-udevd does not exist
but if I comment out this variable and do nothing else to my system
I loose keyboard and touchpad.

I think I am loosing my mind, how can that be?

EDIT

If I replaced the UDEV declaration with a sleep 1 it also works
some timing issue

EDIT 2
Tried this with an un-tired brain and could not reproduce so IGNORE

suedi · 2015-10-22T19:03:45Z

Starting Xorg with --verbose 20 --logverbose 20 with

/dev/input/by-path for USB mouse

pci-0000:00:1d.0-usb-0:1.2:1.0-event-mouse -> ../../input/event14
pci-0000:00:1d.0-usb-0:1.2:1.0-mouse -> ../../input/mouse1

yields in Xorg.log

[   340.511] (II) config/udev: ignoring device /dev/input/event14 without property ID_INPUT set
[   340.511] (II) config/udev: ignoring device /dev/input/mouse1 without property ID_INPUT set

full log
https://www.dropbox.com/s/77l9onixklg7te4/Xorg.0.log?dl=1

Anyone knows this ID_INPUT ?
will research further

found only reference in vdev

 ./vdevd/helpers/LINUX/stat_input.c:387:   // replaces ID_INPUT
 vdev_property_add( "VDEV_INPUT", "1" );

suedi · 2015-10-27T16:27:03Z

more info

> /usr/lib/vdev/stat_input /dev/input/event14
VDEV_INPUT=1
VDEV_INPUT_MOUSE=1
VDEV_INPUT_CLASS=mouse
VDEV_PROPERTIES="VDEV_INPUT ID_INPUT VDEV_INPUT_MOUSE VDEV_INPUT_CLASS "

seems like code in vdev( Forked from systemd/src/udev/udev-builtin-input_id.c) detects the
USB mouse correctly!

But somewhere along the way VDEV_INPUT (ID_INPUT) is lost

Keeping on digging...

suedi · 2015-10-27T17:29:35Z

> cat /dev/metadata/dev/input/event14/properties 
VDEV_PERSISTENT_PATH=pci-0000:00:1d.0-usb-0:1.3:1.0
VDEV_PERSISTENT_PATH_TAG=pci-0000_00_1d_0-usb-0_1_3_1_0
VDEV_INPUT=1
VDEV_INPUT_MOUSE=1
VDEV_INPUT_CLASS=mouse

seems OK to me

suedi · 2015-10-27T17:48:59Z

> cat /dev/metadata/dev/input/event14/links | grep /dev/char
/dev/char/13:78

> cat /run/udev/data/c13:78
I:10055410000

this can be compared to my touchpad that is c13:70

> cat /run/udev/data/c13:70
I:46650000
E:ID_PATH=platform-i8042-serio-4
E:ID_PATH_TAG=platform-i8042-serio-4
E:ID_INPUT=1
E:ID_INPUT_TOUCHPAD=1
E:ID_INPUT_CLASS=mouse

somehow /usr/lib/udev-compat.sh-->udev_enumerate_properties()
does not get called or does not correctly output properties

going deeper into the rabbit hole...

suedi · 2015-10-27T17:56:49Z

printed information from /usr/lib/udev-compat.sh-->udev_enumerate_properties()
when unplugging mouse

/dev/metadata//dev/input/mouse1/properties
/dev/metadata//dev/input/event14/properties
/dev/metadata//dev/UNKNOWN/properties
/dev/metadata//dev/hidraw0/properties
/dev/metadata//dev/UNKNOWN/properties
/dev/metadata//dev/UNKNOWN/properties
/dev/metadata//dev/bus/usb/002/009/properties

could same device be detected multiple times and overwrite good values?

....

suedi · 2015-10-27T18:18:55Z

when I plug and replug USB mouse /run/udev/data/c13:78 disappears

allthough this is still the case

> cat /dev/metadata/dev/input/event14/links | grep /dev/char
/dev/char/13:78

output from /usr/lib/udev-compat.sh-->udev_enumerate_properties()

... 
/dev/metadata//dev/UNKNOWN/properties
/dev/metadata//dev/bus/usb/002/011/properties
/dev/metadata//dev/UNKNOWN/properties
/dev/metadata//dev/UNKNOWN/properties
/dev/metadata//dev/UNKNOWN/properties
/dev/metadata//dev/input/mouse1/properties
/dev/metadata//dev/input/event14/properties
/dev/metadata//dev/hidraw0/properties

hidraw0 is last in line and checking /dev/metadata/dev/hidraw0 dir
there are no properties file. hmm

lost... rebooting now

suedi · 2015-10-27T19:56:48Z

There is a racecondition between when /dev/metadata/dev/input/event14/properties is created and
when udev-compat.sh-->udev_enumerate_properties() is called with

if [ -f "$_METADATA/properties" ]; then

This fails

but after vdevd has run the file exists

suedi · 2015-10-27T20:05:42Z

$_METADATA is in previous comment /dev/metadata//dev/input/event14
and contains when udev-compat.sh-->udev_enumerate_properties() is called

ls -l total 8
-rw-r--r-- 1 root root 181 Oct 27 21:58 links
-rw-r--r-- 1 root root  65 Oct 27 21:58 vdev_instance

confirmed this with introducing a sleep in udev-compat.sh-->udev_enumerate_properties()
with this I got a working USB mouse --- YEAH!!!

will try to remove daemonlet=true from input.act and see if that helps

Yeah it seems to solve this issue

Rebooted with this setup and it is confirmed.
Keyboard, touchpad and USB mouse working

Makes me think about if the deamonlet approach is robust
I think it was introduced as a speed up?

please commment

Obarun · 2015-10-29T05:47:49Z

@suedi for me don't change anything, but i have find the solution. i have added 60-evdev.hwdb on the /usr/lib/vdev/hwdb/hwdb.squashfs and now i have mouse and keyboard. i have rebuild it with the tools gen_database.sh. i have already error on the log and hotplug doesn't work but it's in progress :)

jcnelson · 2015-11-02T00:05:33Z

@suedi The daemonlet solution was meant primarily as a speed-up. However, daemonlets still process device events in sequential order--the only thing the daemonlet does is saves vdevd the need to fork and exec a new process for each device event.

Does @Obarun's pull request fix the USB mouse detection problem? I just merged it.
Do you have async=True set in any of your .act files? If so, that might introduce races, and you could try removing them.

suedi · 2015-11-02T08:52:33Z

okay, I thought there was some parallell execution going on when using deamonlet.

I am a 100% certain there is a racecondition though and me removing deamonlet
from input only slowed things down enough to work.

I will test obaruns updates but if that fixes the problem I will run naked
around the block.

suedi · 2015-11-02T18:36:23Z

Obaruns commit did not change anything and I have no async=true statements in *.act

I don't think you are right Jude.

I logged start and end of input.sh and udev-compat.sh in nano seconds
and $VDEV_PATH when plugging in mouse

1446488503.152340599 input/event14 input.sh
1446488503.265076416 input/event14 udev-compat.sh
1446488503.287351812 input/event14 udev-compat.sh END
1446488503.310253010 input/event14 input.sh END

clearly shows they are run simultaneously.
Thats why it works when I introduce a sleep in udev-compat.sh to allow
input.sh to finish before trying to read file /dev/metadata/dev/input/event14/properties.

The same setup without daemonlet=true in input.act

1446489016.470216358 input/event14 input.sh
1446489016.640307658 input/event14 input.sh END
1446489016.769888235 input/event14 udev-compat.sh
1446489016.810394011 input/event14 udev-compat.sh END

I will keep digging but am not familiar with the code so if you could comment on likely place in code
where this happens I would be most grateful.

EDIT

I was thinking

Does creation of /dev/metadata/dev/input/event14/ trigger any actions?
because at the time of failure for /dev/metadata/dev/input/event14/properties
the dir already exists with contents

-rw-r--r-- 1 root root 181 Oct 27 21:58 links
-rw-r--r-- 1 root root  65 Oct 27 21:58 vdev_instance

jcnelson · 2015-11-11T06:14:38Z

@suedi Thank you for your detailed analysis of the race condition. The code that runs actions is in vdevd/action.c. It is controlled by the vdev_action_run_commands function, which gets called by vdev_device_add (vdevd/device.c) whenever a new device event gets accepted. What should happen is that vdevd should match the device event to each action in lexicographic order by action name (i.e. input.act should be considered before zzz-udev-compat.act), and if the action matches the event, then the action's command is invoked.

An action's command gets invoked in one of four ways: as a synchronous subprocess, as an asynchronous subprocess, as a synchronous request to a running daemonlet, or as an asynchronous request to a running daemonlet. By "synchronous", I mean that the subprocess or daemonlet should be completely finished processing the event before the next action is started.

The behavior you're seeing indicates that this isn't happening, and that there is probably a bug somewhere. I'm having a hard time replicating it on my laptop, but I'll keep trying. Just for reference, my input.act and zzz-udev-compat.act files are:

$ cat /etc/vdev/actions/input.act 
[vdev-action]
event=any
OS_SUBSYSTEM=input
helper=input.sh
daemonlet=true

$ cat /etc/vdev/actions/zzz-udev-compat.act 
[vdev-action]
event=any
helper=udev-compat.sh

suedi · 2015-11-11T11:51:27Z

I have the same values in input.act and zzz-udev-compat.act

I am more used to c++ but there the old saying

When in doubt, cout

could probably be translated to c and printf, right?

by that I mean since I have the bug a 100% reproducable I will
corner it.

I may need your expertise though

suedi · 2016-01-05T21:19:21Z

As of commit 1f17250

This now works for me! 👍

Thank you @jcnelson and @jimyyz for solving this issue

suedi mentioned this issue Oct 28, 2015

Fix for racecondition with input devices #75

Closed

jcnelson mentioned this issue Nov 25, 2015

symlinks not created for usb hard drives #81

Closed

suedi closed this as completed Jan 5, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

USB mouse #71

USB mouse #71

suedi commented Sep 29, 2015

suedi commented Oct 1, 2015

suedi commented Oct 7, 2015

jcnelson commented Oct 8, 2015

suedi commented Oct 8, 2015

suedi commented Oct 12, 2015

jcnelson commented Oct 13, 2015

fbt commented Oct 13, 2015

suedi commented Oct 13, 2015

suedi commented Oct 13, 2015

jcnelson commented Oct 13, 2015

fbt commented Oct 13, 2015

suedi commented Oct 13, 2015

suedi commented Oct 13, 2015

suedi commented Oct 15, 2015

suedi commented Oct 21, 2015

suedi commented Oct 22, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

Obarun commented Oct 29, 2015

jcnelson commented Nov 2, 2015

suedi commented Nov 2, 2015

suedi commented Nov 2, 2015

jcnelson commented Nov 11, 2015

suedi commented Nov 11, 2015

suedi commented Jan 5, 2016

USB mouse #71

USB mouse #71

Comments

suedi commented Sep 29, 2015

suedi commented Oct 1, 2015

suedi commented Oct 7, 2015

jcnelson commented Oct 8, 2015

suedi commented Oct 8, 2015

suedi commented Oct 12, 2015

jcnelson commented Oct 13, 2015

fbt commented Oct 13, 2015

suedi commented Oct 13, 2015

suedi commented Oct 13, 2015

jcnelson commented Oct 13, 2015

fbt commented Oct 13, 2015

suedi commented Oct 13, 2015

suedi commented Oct 13, 2015

suedi commented Oct 15, 2015

suedi commented Oct 21, 2015

suedi commented Oct 22, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

suedi commented Oct 27, 2015

Obarun commented Oct 29, 2015

jcnelson commented Nov 2, 2015

suedi commented Nov 2, 2015

suedi commented Nov 2, 2015

jcnelson commented Nov 11, 2015

suedi commented Nov 11, 2015

suedi commented Jan 5, 2016