UDEV events not showing up in service

Hi,

I’m trying to get UDEV events to reach my container running on a BalenaFin.

I’m testing with a simple USB thumb drive and an an ATR210, manufactured by AccessIS: ATR210 - TripTick® Barcode & NFC Reader

I made a minimal working example indicated below. I think I followed all recommended practiced as documented:

docker-compose file

version: '2.1'

services:

   someservice:
    build:
      context: ./
      dockerfile: Dockerfile
    privileged: true
    environment:
      - UDEV=on

Dockerfile

FROM balenalib/generic-armv7ahf-dotnet:3.1-buster-20210201
WORKDIR /app
CMD sleep infinity

Results:
I ran udevadm monitorboth on the host and on the service. Then I first removed and then inserted the device.
udevadm_monitor_container.log (9.5 KB) udevadm_monitor_host.log (18.9 KB)

As you can see, I only see the UDEV events on the host and not on the service.

I noticed that the device does work perfectly fine in the service when I have it inserted and I restart the service. It’s just removing and inserting whilst the service is running that doesn’t work and I think it has to do with the UDEV events not showing up.

Other things I tried:
I can see that the udev service is running so all should be ok?

root@8de138db034b:/app# service udev status
[ ok ] systemd-udevd is running.

This seems similar to this topic: Balenadash keyboard not responding

If I can provide more info, please let me know.
Thanks for your time!

Hi, can you try the sample project and see if it works for your device and usb drive? If it works, we can then continue searching for the issue in your project configuration.

I tested it on device “balena dashboard”.
I granted support access for a week on this device.

I see the following in the Logs in BalenaCloud:

05.02.21 12:48:50 (+0100) external-drive Idling…

Once again with udevadm monitor I see UDEV entries on the host OS, but not in the “external-drive” service.

Hi, can you try reformatting usb drive to FAT32 or EXT4? I see error in logs (/usr/src/mount.log):

Could not get device information: /dev/sda1                                                                                                                                  
Mounting - Source: /dev/sda1 - Destination: /mnt/storage-usb-UBUNTU\x2020_0-E4EB-429C                                                                                        
Mounting - Source: /dev/sda1 - Destination: /mnt/storage-usb-UBUNTU\x2020_0-E4EB-429C                                                                                        
File system not supported: ntfs                                                                                                                                              
Mounting - Source: /dev/sda1 - Destination: /mnt/storage-usb-UBUNTU\x2020_0-E4EB-429C                                                                                        
Mounting - Source: /dev/sda1 - Destination: /mnt/storage-usb-UBUNTU\x2020_0-E4EB-429C                                                                                        
Could not get device information: /dev/sda1

Yes, I overlooked that. Sorry about that. Plug and play seems to work or at least the udev rules in /etc/udev/rules.d/usb.rules are being called.

I don’t think we need to waste time with the USB thumbdrive, I don’t need that to work in the end.
Instead I would like to focus on what I actually want to achieve:
I tried to use the PCSC library to access a smart card reader (ATR210).
I noticed it only worked when I started the service when the smart card reader is already connected to my BalenaFin.
To troubleshoot the issue I created an issue with the library github: ATR210 LIBUSB_ERROR_NO_DEVICE after disconnecting · Issue #95 · LudovicRousseau/PCSC · GitHub

The developer mentioned that “The USB device removal is NOT notified by libudev”.
Based on his advise I ran udevadm monitor on both the host and the service.
He then indicated that the difference in the reported events is the reason that the library was failing.
I checked if udev is actually running and it is:

root@8de138db034b:/app# service udev status
[ ok ] systemd-udevd is running.

It’s just the events that are not generated inside the container.

PCSC is using libudev events in some way shape or form, but I didn’t write the code, I only know that the creator mentions that they are needed.

Ok, after some testing it appears that the UDEV events actually do happen, but they’re just not printed?

I modified the balena-storage sample in the following ways:
Added an extra script to the scripts folder (accessis.sh):

#!/bin/bash
echo "detected accessIS device, arguments are: $@" >> /usr/src/accessis.log

and add this rule to udev/usb.rules
ACTION=="add", ENV{ID_VENDOR}=="Access_IS", RUN+="/bin/sh -c '/usr/src/scripts/accessis.sh'"

After I plug in my device I do see the following:

bash-5.1# cat /usr/src/accessis.log 
detected accessIS device, arguments are: 
detected accessIS device, arguments are: 
detected accessIS device, arguments are: 
detected accessIS device, arguments are:

So this seems to work?
I just don’t know what the PCSC library is doing that is failing…

I tested a sample program that uses libudev from Detecting USB devices with libudev. This is the library the PCSC uses to detect usb events.
The source file is here: https://raw.githubusercontent.com/gavv/snippets/master/udev/udev_monitor_usb.c.
I built it using: gcc -g -Wall -o udev_monitor_usb udev_monitor_usb.c -ludev on ubuntu20.04 on a spare laptop.
In Ubuuntu20.04 I do have the UDEV and KERNEL events in the udevadm monitor. this is the output of the program when I insert and remove in my usb thumbdrive:

ubuntu@ubuntu:~$ ./udev_monitor_usb 
usb usb_device exists 1d6b:0002 /dev/bus/usb/003/001
usb usb_device exists 058f:6387 /dev/bus/usb/003/002
usb usb_device exists 8087:07da /dev/bus/usb/003/003
usb usb_device exists 5986:0400 /dev/bus/usb/003/004
usb usb_device exists 1d6b:0003 /dev/bus/usb/004/001
usb usb_device exists 1d6b:0002 /dev/bus/usb/001/001
usb usb_device exists 8087:8008 /dev/bus/usb/001/002
usb usb_device exists 1d6b:0002 /dev/bus/usb/002/001
usb usb_device exists 8087:8000 /dev/bus/usb/002/002
usb usb_device    add 058f:6387 /dev/bus/usb/003/009
usb usb_device   bind 058f:6387 /dev/bus/usb/003/009
usb usb_device unbind 0000:0000 /dev/bus/usb/003/009
usb usb_device remove 0000:0000 /dev/bus/usb/003/009

When I compile and run this in the “external-drive” service on my balenaFin where I only have the KERNEL events in the udevadm monitor when I insert and remove in my usb thumbdrive:

bash-5.1# ./udev_monitor_usb 
usb usb_device exists 1d6b:0002 /dev/bus/usb/001/001
usb usb_device exists 0424:9514 /dev/bus/usb/001/002
usb usb_device exists 0424:ec00 /dev/bus/usb/001/003
usb usb_device exists 0424:2422 /dev/bus/usb/001/008
usb usb_device exists 0db5:0170 /dev/bus/usb/001/009
usb usb_device exists 0db5:0140 /dev/bus/usb/001/010

You can clearly see the absence of the add, bind, unbind and remove commands.

Looking at the logs, is 058f:6387 the USB stick then?

usb usb_device    add 058f:6387 /dev/bus/usb/003/009
usb usb_device   bind 058f:6387 /dev/bus/usb/003/009

Shouldn’t we at least see that the “usb_device exists” in the second snippet (container) that you’ve provided? Are you certain that the drive is still properly being recognized / mounted in that container (I realize we are trying to get to the bottom of udev logging, but, is the absence of a log in this case due to the fact it’s not even recognized at all?)

Completely correct. in the previous test I started the program when the usb thumbstick was not inserted yet.
I now did another test with the usb thumbstick already inserted when the program started. Now the usb device is visible:

bash-5.1# ./udev_monitor_usb
usb usb_device exists 1d6b:0002 /dev/bus/usb/001/001
usb usb_device exists 0424:9514 /dev/bus/usb/001/002
usb usb_device exists 0424:ec00 /dev/bus/usb/001/003
usb usb_device exists 058f:6387 /dev/bus/usb/001/012

I also tried to remove and insert the usb thumbdrive again, but no events showed up.
I’ll leave the usb thumbstick inserted if you remotely want to test something.

Edit:
Maybe these links help?

Hi,

I have been digging into this and I can confirm this does not indeed work as expected. Considering the balena-storage, exactly as you describe, UDEV events are dropped even though udev is apparently running:

bash-5.1# ps 
PID   USER     TIME  COMMAND
    1 root      0:00 /bin/bash /usr/src/scripts/idle.sh
   30 root      0:00 udevd --daemon
   38 root      0:00 sleep 600
   50 root      0:00 /bin/bash
  204 root      0:00 ps
bash-5.1# udevadm monitor
...
KERNEL...
KERNEL...
KERNEL...

After killing udev and restarting it manually it starts behaving correctly:

bash-5.1# kill -15 30
bash-5.1# udevd --daemon
bash-5.1# udevadm monitor
...
KERNEL...
KERNEL...
KERNEL...
UDEV...
UDEV...
UDEV...

I am not yet sure about the cause for this behavior but will be digging deeper. In the meantime would you be able to try killing/manually starting udev in your container and confirm that it does in fact help with the original issue that you are trying to solve? Thanks.

This seems to work for us, we see the UDEV events in udevadm monitor and in code.
Thanks a lot for the help!

I suppose once this gets fixed this thread will be updated so we can remove the workaround from our dockerfile?

Hi again, glad to hear that helps. We will look for the issue and keep you updated in this thread.

Hi again,

I have got an update on this: The reason why udev events are not propagated is that we run it in a separate net namespace. We do this because certain network devices become unstable or hang when double-initialized which happens when udev is running in the container - both the on-host and in-container udev instances may try to initialize the device. This is a safe default we chose and there is a note about it in the docs: Balena base images - Balena Documentation

Unfortunately udev internally uses a local network socket to propagate the events so running it in a separate net namespace breaks the connection and the events are not propagated correctly. As long as your connectivity is not affected the best solution for you is not to use the UDEV environment variable at all and simply start udev as a part of CMD in your Dockerfile. I hope this is acceptable.

1 Like

For now we just kill the udev daemon and restart it in the dockerfile as part of the CMD as you proposed.

We still use a balenalib base image and use the UDEV env var. I suppose the UDEV env var does not do anything special, but it also will not hurt us in any way? Just to be sure.

The UDEV variable triggers the start of the udev daemon you later need to kill, with the variable not set you would only need to start a fresh udev process.