Arch Linux

Please read this before reporting a bug:
https://wiki.archlinux.org/title/Bug_reporting_guidelines

Do NOT report bugs when a package is just outdated, or it is in the AUR. Use the 'flag out of date' link on the package page, or the Mailing List.

REPEAT: Do NOT report bugs for outdated packages!
Tasklist

FS#78957 - [linux] usbguard Locks fingerprint reader after kernel update

Attached to Project: Arch Linux
Opened by Ilario Gelmetti (ilario) - Monday, 03 July 2023, 10:56 GMT
Last edited by Toolybird (Toolybird) - Monday, 03 July 2023, 21:28 GMT
Task Type Bug Report
Category Kernel
Status Waiting on Response
Assigned To No-one
Architecture x86_64
Severity Low
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 0%
Votes 0
Private No

Details

Description:

After kernel upgrades, usbguard locks the fingerprint reader of a Lenovo ThinkPad X1 Carbon 2nd gen. as if it was a new device.
In this case I have to reboot, as for some other unidentified bug (PAM or fprintd) I cannot unlock the Gnome screen lock with password.

```
$ lsusb -d 138a:0017

Bus 002 Device 002: ID 138a:0017 Validity Sensors, Inc. VFS 5011 fingerprint sensor
```

```
# grep 138a:0017 /etc/usbguard/rules.conf [12:51:33]
allow id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" with-interface ff:00:00 with-connect-type "not used"
```

Here some lines from journalctl:

```
$ journalctl --since "2023-07-03" | grep -i "usb\|fingerprint"

Jul 03 08:40:48 iglaptop kernel: usb 2-6: new full-speed USB device number 2 using xhci_hcd
Jul 03 08:40:48 iglaptop kernel: usb 2-6: New USB device found, idVendor=138a, idProduct=0017, bcdDevice= 0.78
Jul 03 08:40:48 iglaptop kernel: usb 2-6: New USB device strings: Mfr=0, Product=0, SerialNumber=1
Jul 03 08:40:48 iglaptop kernel: usb 2-6: SerialNumber: 9585d92de732

[...]

Jul 03 08:40:50 iglaptop systemd[1]: Starting USBGuard D-Bus Service...
Jul 03 08:40:50 iglaptop systemd[1]: Starting USBGuard daemon...

[...]

Jul 03 08:40:50 iglaptop usbguard-daemon[369]: uid=0 pid=359 result='SUCCESS' device.rule='allow id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' type='Device.Present'
Jul 03 08:40:50 iglaptop usbguard-daemon[369]: uid=0 pid=359 result='SUCCESS' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' target.new='allow' device.rule='allow id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' target.old='allow' type='Policy.Device.Update'

[...]

Jul 03 08:40:50 iglaptop systemd[1]: Started USBGuard daemon.
Jul 03 08:40:50 iglaptop systemd[1]: Started USBGuard D-Bus Service.
Jul 03 08:40:54 iglaptop systemd[1]: Starting Fingerprint Authentication Daemon...
Jul 03 08:40:54 iglaptop systemd[1]: Started Fingerprint Authentication Daemon.
Jul 03 08:41:03 iglaptop kernel: usb 2-6: USB disconnect, device number 2
Jul 03 08:41:03 iglaptop usbguard-daemon[369]: uid=0 pid=359 result='SUCCESS' device.rule='allow id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' type='Device.Remove'
Jul 03 08:41:04 iglaptop kernel: usb 2-6: new full-speed USB device number 4 using xhci_hcd
Jul 03 08:41:04 iglaptop usbguard-daemon[369]: uid=0 pid=359 result='SUCCESS' device.rule='block id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' type='Device.Insert'
Jul 03 08:41:04 iglaptop kernel: usb 2-6: New USB device found, idVendor=138a, idProduct=0017, bcdDevice= 0.78
Jul 03 08:41:04 iglaptop kernel: usb 2-6: New USB device strings: Mfr=0, Product=0, SerialNumber=1
Jul 03 08:41:04 iglaptop kernel: usb 2-6: SerialNumber: 9585d92de732
Jul 03 08:41:04 iglaptop kernel: usb 2-6: Device is not authorized for usage
Jul 03 08:41:04 iglaptop kernel: usb 2-6: authorized to connect
Jul 03 08:41:04 iglaptop usbguard-daemon[369]: uid=0 pid=359 result='SUCCESS' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' target.new='allow' device.rule='block id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' target.old='block' type='Policy.Device.Update'
Jul 03 08:41:04 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:14.0/usb2/2-6 action=change
Jul 03 08:41:04 iglaptop mtp-probe[933]: checking bus 2, device 4: "/sys/devices/pci0000:00/0000:00:14.0/usb2/2-6"
Jul 03 08:41:04 iglaptop mtp-probe[934]: checking bus 2, device 4: "/sys/devices/pci0000:00/0000:00:14.0/usb2/2-6"
Jul 03 08:41:04 iglaptop fprintd[790]: libusb: error [udev_hotplug_event] ignoring udev action change
Jul 03 08:41:08 iglaptop systemd[905]: Starting GNOME USB protection service...
Jul 03 08:41:08 iglaptop systemd[905]: Started GNOME USB protection service.
Jul 03 08:41:08 iglaptop systemd[905]: Reached target GNOME USB protection target.
Jul 03 08:41:08 iglaptop dbus-daemon[927]: [session uid=1000 pid=927] Activating service name='org.gnome.ScreenSaver' requested by ':1.50' (uid=1000 pid=1279 comm="/usr/lib/gsd-usb-protection")

[[[HERE I LOCKED THE SCREEN AND UNLOCKED IT USING THE FINGERPRINT]]]

Jul 03 10:02:27 iglaptop systemd[1]: Starting Fingerprint Authentication Daemon...
Jul 03 10:02:27 iglaptop systemd[1]: Started Fingerprint Authentication Daemon.

[[[HERE I START THE SYSTEM UPGRADE WHICH INCLUDED A KERNEL UPGRADE]]]

Jul 03 10:10:10 iglaptop systemd[1]: Starting Fingerprint Authentication Daemon...
Jul 03 10:10:10 iglaptop systemd[1]: Started Fingerprint Authentication Daemon.

[[[THE FINGERPRINT READER WORKED FOR SUDO]]]

Jul 03 10:12:45 iglaptop systemd[1]: Starting Fingerprint Authentication Daemon...
Jul 03 10:12:45 iglaptop systemd[1]: Started Fingerprint Authentication Daemon.
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:14.0/usb2 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:14.0/usb2/2-0:1.0 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:14.0/usb2/2-6 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:14.0/usb2/2-6/2-6:1.0 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:14.0/usb3 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:14.0/usb3/3-0:1.0 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:1d.0/usb1 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:1d.0/usb1/1-0:1.0 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:1d.0/usb1/1-1 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.8 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.8/1-1.8:1.0 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.8/1-1.8:1.1 action=change
Jul 03 10:17:22 iglaptop usbguard-daemon[369]: Ignoring unknown UEvent action: sysfs_devpath=/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1:1.0 action=change

[[[HERE I LOCK THE SCREEN USING THE GNOME SCREEN LOCKER]]]

Jul 03 11:16:04 iglaptop systemd[1]: Starting Fingerprint Authentication Daemon...
Jul 03 11:16:04 iglaptop systemd[1]: Started Fingerprint Authentication Daemon.
Jul 03 11:16:06 iglaptop kernel: usb 2-6: USB disconnect, device number 4
Jul 03 11:16:06 iglaptop usbguard-daemon[369]: uid=0 pid=359 result='SUCCESS' device.rule='allow id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' type='Device.Remove'
Jul 03 11:16:07 iglaptop kernel: usb 2-6: new full-speed USB device number 5 using xhci_hcd
Jul 03 11:16:07 iglaptop usbguard-daemon[369]: uid=0 pid=359 result='SUCCESS' device.rule='block id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' type='Device.Insert'
Jul 03 11:16:07 iglaptop usbguard-daemon[369]: uid=0 pid=359 result='SUCCESS' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' target.new='block' device.rule='block id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' target.old='block' type='Policy.Device.Update'
Jul 03 11:16:07 iglaptop kernel: usb 2-6: New USB device found, idVendor=138a, idProduct=0017, bcdDevice= 0.78
Jul 03 11:16:07 iglaptop kernel: usb 2-6: New USB device strings: Mfr=0, Product=0, SerialNumber=1
Jul 03 11:16:07 iglaptop kernel: usb 2-6: SerialNumber: 9585d92de732
Jul 03 11:16:07 iglaptop kernel: usb 2-6: Device is not authorized for usage
Jul 03 11:16:07 iglaptop mtp-probe[19880]: checking bus 2, device 5: "/sys/devices/pci0000:00/0000:00:14.0/usb2/2-6"
Jul 03 11:16:07 iglaptop mtp-probe[19881]: checking bus 2, device 5: "/sys/devices/pci0000:00/0000:00:14.0/usb2/2-6"
Jul 03 11:16:51 iglaptop systemd[1]: Starting Fingerprint Authentication Daemon...
Jul 03 11:16:51 iglaptop systemd[1]: Started Fingerprint Authentication Daemon.

[[[AS THE FINGERPRINT READER GOT BLOCKED BY USBGUARD, 3 CONSECUTIVE LOGIN FAILURES ARE DETECTED]]]

Jul 03 11:16:51 iglaptop gdm-fingerprint][19923]: pam_faillock(gdm-fingerprint:auth): Consecutive login failures for user ilario account temporarily locked
```


Additional info:
* usbguard 1.1.2-1 from Extra repository
* kernel 6.4.1.arch1-1

Steps to reproduce:

Update the kernel using pacman, lock the screen, try to unlock using the fingerprint reader.
This task depends upon

Comment by Toolybird (Toolybird) - Monday, 03 July 2023, 21:27 GMT
> After kernel upgrades

Which strongly indicates it's a kernel regression. General advice for debugging kernel regressions [1]. You'll have better luck reporting this upstream to the kernel folks...maybe also talk to the usbguard folks. Please let us know what you find out.

[1] https://wiki.archlinux.org/title/Kernel#Debugging_regressions
Comment by Ilario Gelmetti (ilario) - Tuesday, 04 July 2023, 08:29 GMT
Wait, I did not explain enough, sorry.
It is not a kernel regression as once rebooted USBguard worked perfectly again (or at least didn't block my fingerprint reader when locking the screen).
As soon as a new kernel update arrives, I will try to reproduce and post here. To prove that the problem is the limbo status that happens after an update (e.g. new modules cannot be loaded because the current kernel do not find them where expected, as they got deleted and replaced by the ones from the new kernel, or something like that, just throwing (unrelated) hypotheses).
Comment by Ilario Gelmetti (ilario) - Friday, 07 July 2023, 13:28 GMT
I just observed this again, but this time there was no kernel update.
So the title should be updated.
I have no idea anymore about what triggers this.

Some logs:

```
$ journalctl --since "2023-07-07" | grep -i "usb\|fingerprint"
[...]
Jul 07 12:11:36 iglaptop systemd[1]: Starting Fingerprint Authentication Daemon...
Jul 07 12:11:36 iglaptop systemd[1]: Started Fingerprint Authentication Daemon.
Jul 07 12:11:40 iglaptop gdm-fingerprint][28998]: pam_faillock(gdm-fingerprint:auth): Consecutive login failures for user ilario account temporarily locked
Jul 07 12:12:54 iglaptop kernel: usb 2-6: USB disconnect, device number 2
Jul 07 12:12:54 iglaptop usbguard-daemon[372]: uid=0 pid=357 result='SUCCESS' device.rule='allow id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' type='Device.Remove'
Jul 07 12:12:54 iglaptop kernel: usb 2-6: new full-speed USB device number 4 using xhci_hcd
Jul 07 12:12:54 iglaptop kernel: usb 2-6: New USB device found, idVendor=138a, idProduct=0017, bcdDevice= 0.78
Jul 07 12:12:54 iglaptop kernel: usb 2-6: New USB device strings: Mfr=0, Product=0, SerialNumber=1
Jul 07 12:12:54 iglaptop kernel: usb 2-6: SerialNumber: 9585d92de732
Jul 07 12:12:54 iglaptop kernel: usb 2-6: Device is not authorized for usage
Jul 07 12:12:54 iglaptop usbguard-daemon[372]: uid=0 pid=357 result='SUCCESS' device.rule='block id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' type='Device.Insert'
Jul 07 12:12:54 iglaptop usbguard-daemon[372]: uid=0 pid=357 result='SUCCESS' device.system_name='/devices/pci0000:00/0000:00:14.0/usb2/2-6' target.new='block' device.rule='block id 138a:0017 serial "9585d92de732" name "" hash "I42u56Qym91l9WYPg8wt7+lqHyWekuV0oMt0Urt15FA=" parent-hash "jEP/6WzviqdJ5VSeTUY8PatCNBKeaREvo2OqdplND/o=" via-port "2-6" with-interface ff:00:00 with-connect-type "not used"' target.old='block' type='Policy.Device.Update'
```

Comment by Toolybird (Toolybird) - Monday, 07 August 2023, 07:41 GMT
Is this still an issue with latest pkgs?

> the limbo status that happens after an update (e.g. new modules cannot be loaded because the current kernel do not find them where expected, as they got deleted and replaced by the ones from the new kernel

If that is indeed what is happening then unfortunately it cannot be fixed. The general Arch advice is *always* reboot after installing a new kernel. It's simply asking for trouble if you don't. Either that, or hold back installation of the new kernel until you're ready to reboot e.g.

$ sudo pacman -Syu --ignore linux

Loading...