Service not working after suspend

[dmitriy-ssh]

Device: 138a:0097 Machine: Lenovo T470P with Linux Mint 19.2 Description: Sometimes (1 in 10 cases approximately) when you wake up device after suspend the fingerprint sensor doesn't work and service stays in suspend mode. Restarting service doesn't have any effect, sensor still doesn't work. After reboot everything goes normal.

[exapsy]

Same here. Went to issues to report that :D I wonder why.

Lenovo Thinkpad T470S
5.10.34-1-MANJARO

[xAiLx]

Same here.

ThinkPad T480
5.10.34-1-MANJARO

In my case it happens after waking up from sleep mode and I can restart python3-validity.service for enable validation by fingerprint sensor.

[lo-zed]

I also have problems after sleep mode. In my case, authentication keeps failing until I'm not allowed to log in anymore.

Architecture: Lenovo ThinkPad P52s Archlinux 5.12.8-arch1-1 python-validity 0.12-3 gnome-shell 1:40.1-2 (it wasn't working on former versions of gnome shell either)

I found these lines with journalctl, I hope this can help

jun 02 13:26:49 lenovo-p52s open-fprintd[456]: DEBUG:root:GetDefaultDevice
jun 02 13:26:49 lenovo-p52s open-fprintd[456]: DEBUG:root:GetAll net.reactivated.Fprint.Device
jun 02 13:26:49 lenovo-p52s open-fprintd[456]: DEBUG:root:GetDevices
jun 02 13:26:49 lenovo-p52s open-fprintd[456]: DEBUG:root:ListEnrolledFingers
jun 02 13:26:49 lenovo-p52s python3[427]: DEBUG:root:In ListEnrolledFingers <username>
jun 02 13:26:49 lenovo-p52s python3[427]: DEBUG:root:>tls> 17: <some_long_hex_number>
jun 02 13:26:49 lenovo-p52s python3[427]: DEBUG:root:>cmd> <some_extra_long_hex_number>
jun 02 13:26:49 lenovo-p52s python3[427]: DEBUG:root:<cmd< 0404
jun 02 13:26:49 lenovo-p52s kernel: usb 1-9: usbfs: process 427 (python3) did not claim interface 0 before use
jun 02 13:26:49 lenovo-p52s audit[8379]: USER_AUTH pid=8379 uid=0 auid=1000 ses=6 msg='op=PAM:authentication grantors=? acct="<username>" exe="/usr/lib/gdm-session-worker" hostname=<hostname> addr=? terminal=/dev/tty1 res=failed'
jun 02 13:26:49 lenovo-p52s kernel: audit: type=1100 audit(1622633209.603:174): pid=8379 uid=0 auid=1000 ses=6 msg='op=PAM:authentication grantors=? acct="<username>" exe="/usr/lib/gdm-session-worker" hostname=<hostname> addr=? terminal=/dev/tty1 res=failed'

[exapsy]

authentication keeps failing until I'm not allowed to log in anymore.

I just got back to the issue just to report this issue as well. Which makes this issue much less harmless than I thought it was.

Before I thought it was just the fingerprint not working, but it turns out that it fails all of your 3 login attempts as well in login screen after a suspension. Which means you either have to wait 10 minutes before logging back in, or you have to restart your machine which means losing all the work you had open at the moment.

[dbanetto]

I get this issue as well & stops me from be able to use a finger print reader

ThinkPad T470 - 138a:0097
 ArchLinux - 5.14.2-arch1-2
 python-validity: 0.12-3

After resume trying out fprint commands return

❯ fprintd-list $USER                      
found 1 devices
Device at /net/reactivated/Fprint/Device/5
Using device /net/reactivated/Fprint/Device/5
ListEnrolledFingers failed: Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/dbus/service.py", line 715, in _message_cb
    retval = candidate_method(self, *args, **keywords)
  File "/usr/lib/python-validity/dbus-service", line 90, in ListEnrolledFingers
    raise e
  File "/usr/lib/python-validity/dbus-service", line 81, in ListEnrolledFingers
    usr = self.user2record(user)
  File "/usr/lib/python-validity/dbus-service", line 64, in user2record
    return db.lookup_user(self.user2identity(user))
  File "/usr/lib/python3.9/site-packages/validitysensor/db.py", line 163, in lookup_user
    stg = self.get_user_storage(name='StgWindsor')
  File "/usr/lib/python3.9/site-packages/validitysensor/db.py", line 149, in get_user_storage
    return parse_user_storage(tls.cmd(pack('<BHH', 0x4b, dbid, len(name)) + name))
  File "/usr/lib/python3.9/site-packages/validitysensor/tls.py", line 122, in cmd
    rsp = self.app(cmd)
  File "/usr/lib/python3.9/site-packages/validitysensor/tls.py", line 152, in app
    return self.parse_tls_response(self.usb.cmd(self.make_app_data(b)))
  File "/usr/lib/python3.9/site-packages/validitysensor/tls.py", line 351, in parse_tls_response
    raise Exception('Unexpected TLS version %d %d' % (mj, mn))
Exception: Unexpected TLS version 4 0

logs for python3-validity service are repeating this & hard to spot if this actually lines (some host details scrubbed):

Sep 24 09:27:40 HOST python3[98228]: DEBUG:root:VerifyStatus
Sep 24 09:27:41 HOST python3[98228]: DEBUG:root:>tls> 17: 3920bf0200ffff0000019900200000000099990000000000000000000000000020000000000000000000000000ffff0000009900200000000000000000000000000000000000000020>
Sep 24 09:27:41 HOST python3[98228]: DEBUG:root:>cmd> 17030300b05d5751eefb5062b9cbf68b1a62db850f5c3680f2cd83993eb57496af2fa5547b731ba02446f3c43b432dbd4af6f4d61f0a4727e702f106503fae358980ab3b1261244cc3342f>
Sep 24 09:27:41 HOST python3[98228]: DEBUG:root:<cmd< 0404
Sep 24 09:27:41 HOST python3[98228]: DEBUG:root:VerifyStatus
Sep 24 09:27:42 HOST python3[98228]: DEBUG:root:>tls> 17: 3920bf0200ffff0000019900200000000099990000000000000000000000000020000000000000000000000000ffff0000009900200000000000000000000000000000000000000020>
Sep 24 09:27:42 HOST python3[98228]: DEBUG:root:>cmd> 17030300b0eb7c5c3c22a539db9e2fa83ad690fc9c1da6fd8dd792e81359b5a8d37076b543e1305b6eb234fefe6932a33e94fe1596f6dde19d4edacb956b03ae4efbb21a05f2bafac4bbc8>
Sep 24 09:27:42 HOST python3[98228]: DEBUG:root:<cmd< 0404
Sep 24 09:27:42 HOST python3[98228]: DEBUG:root:VerifyStatus
Sep 24 09:27:42 HOST python3[98228]: DEBUG:root:In ListEnrolledFingers USER
Sep 24 09:27:42 HOST python3[98228]: DEBUG:root:>tls> 17: 4b00000b0053746757696e64736f7200
Sep 24 09:27:42 HOST python3[98228]: DEBUG:root:>cmd> 1703030050750986bd498103b14cb0655ad470d716f596b564219ef79bf8fd924a5bc1651261608c85db5df4c8adbee7928829328b64022ce3556fe3a3a11098b0b3dc8c5ae20077abd258>
Sep 24 09:27:42 HOST python3[98228]: DEBUG:root:<cmd< 0404
Sep 24 09:27:43 HOST python3[98228]: DEBUG:root:>tls> 17: 3920bf0200ffff0000019900200000000099990000000000000000000000000020000000000000000000000000ffff0000009900200000000000000000000000000000000000000020>
Sep 24 09:27:43 HOST python3[98228]: DEBUG:root:>cmd> 17030300b04487da580302be5262032208f63c434f93be13c8b99e6dfe7b10490f58d0ba4a1ec29d864cad824dcf303b56525b41de706f8b5fcda2d0d7631bd83a92463e1ac89111ce6a6a>
Sep 24 09:27:43 HOST python3[98228]: DEBUG:root:<cmd< 0404
Sep 24 09:27:43 HOST python3[98228]: DEBUG:root:VerifyStatus

After restarting the service it works again

Sep 24 09:30:51 HOST python3[98989]: DEBUG:root:In ListEnrolledFingers USER
Sep 24 09:30:51 HOST python3[98989]: DEBUG:root:>tls> 17: 4b00000b0053746757696e64736f7200
Sep 24 09:30:51 HOST python3[98989]: DEBUG:root:>cmd> 1703030050a9b49fb84a1c49e23b24c2d153e20f2369c27759cd17f415d6021f5675817376ea75cec285bcd8737720a0de3c471c83460f76934247b9a9f8a57ac0e80da6be69570d305ff1>
Sep 24 09:30:51 HOST python3[98989]: DEBUG:root:<cmd< 1703030050b2379f2b5ca0c5a3beb488174a026b57e4f827c62290097ff851b1ea6cb7970363b1e4302c92f6e237a887c2a9c6365db2716530cc2973c5642ca51467b9f01743e324ce0872>
Sep 24 09:30:51 HOST python3[98989]: DEBUG:root:<tls< 17: 0000030001000b00000004004c0053746757696e64736f7200
Sep 24 09:30:51 HOST python3[98989]: DEBUG:root:>tls> 17: 4a000003004c00030000001c000000010500000000000515000000c76b9f06c7353a42c7353a42e8030000000000000000000000000000000000000000000000000000000000000000>
Sep 24 09:30:51 HOST python3[98989]: DEBUG:root:>cmd> 1703030090129aa770f7c87789c3e239a5fcbc2efab02874ce13fef2388a7ffcda427bb3a8e5e5c783c79847389c78fc306de73ec47f34a19c612f7618a9b9aa4e38f709e27992790a6b20>
Sep 24 09:30:51 HOST python3[98989]: DEBUG:root:<cmd< 17030300a04240c560736a57ee8c69467a9666fc9777b5ed46ff9dd7af2a3783881ade5b57b394228c687e52c3f229f325732debed599de38e50bc1c789e06a41f4fe33a8c5c063661f2a7>
Sep 24 09:30:51 HOST python3[98989]: DEBUG:root:<tls< 17: 00000400020000004c00050004000300285a060009000300285a030000001c000000010500000000000515000000c76b9f06c7353a42c7353a42e80300000000000000000000000000>
Sep 24 09:30:51 HOST python3[98989]: DEBUG:root:['WINBIO_ANSI_381_POS_RH_RING_FINGER', 'WINBIO_ANSI_381_POS_LH_RING_FINGER']

Strangely the VerifyStatus commands are not there until after I resume :thinking:

[uunicorn]

Hi, can you check the status of open-fprintd-resume.service and open-fprintd-suspend.service services? It won't help with the OP problem (which is intermittent), but may be the answer to those who have this 0404 problem consistently each time after suspend.

[dbanetto]

Hi, can you check the status of open-fprintd-resume.service and open-fprintd-suspend.service services?

❯ systemctl status open-fprintd-suspend.service 
○ open-fprintd-suspend.service - Restart devices after resume
     Loaded: loaded (/usr/lib/systemd/system/open-fprintd-suspend.service; disabled; vendor preset: disabled)
     Active: inactive (dead)

❯ systemctl status open-fprintd-resume.service  
○ open-fprintd-resume.service - Restart devices after resume
     Loaded: loaded (/usr/lib/systemd/system/open-fprintd-resume.service; disabled; vendor preset: disabled)
     Active: inactive (dead)

Both are disabled & have no entries in journald.

I'll enable both of them & see if it helps

Update: I have enable both of these services and haven't been able to replicate the 0404 issue

[4rc0s]

Having the same issue. T480S with, per lsusb, a "Synaptics, Inc. Metallica MIS Touch Fingerprint Reader"

Works fine until suspend then doesn't activate after that. Seeing this:

$ systemctl status open-fprintd-resume.service 
× open-fprintd-resume.service - Restart devices after resume
     Loaded: loaded (/lib/systemd/system/open-fprintd-resume.service; enabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Sun 2023-02-19 01:14:01 EST; 23min ago
   Main PID: 56398 (code=exited, status=1/FAILURE)
        CPU: 180ms

Feb 19 01:14:01 mysystem resume.py[56398]:   File "/usr/lib/python3/dist-packages/usb/backend/libusb1.py", line 837, in bulk_write
Feb 19 01:14:01 mysystem resume.py[56398]:     return self.__write(self.lib.libusb_bulk_transfer,
Feb 19 01:14:01 mysystem resume.py[56398]:   File "/usr/lib/python3/dist-packages/usb/backend/libusb1.py", line 938, in __write
Feb 19 01:14:01 mysystem resume.py[56398]:     _check(retval)
Feb 19 01:14:01 mysystem resume.py[56398]:   File "/usr/lib/python3/dist-packages/usb/backend/libusb1.py", line 604, in _check
Feb 19 01:14:01 mysystem resume.py[56398]:     raise USBError(_strerror(ret), ret, _libusb_errno[ret])
Feb 19 01:14:01 mysystem resume.py[56398]: usb.core.USBError: [Errno 19] No such device (it may have been disconnected)
Feb 19 01:14:01 mysystem systemd[1]: open-fprintd-resume.service: Main process exited, code=exited, status=1/FAILURE
Feb 19 01:14:01 mysystem systemd[1]: open-fprintd-resume.service: Failed with result 'exit-code'.
Feb 19 01:14:01 mysystem systemd[1]: Failed to start Restart devices after resume.

[4rc0s]

Well, now it seems to be working again after suspend. No idea why (though I did some shotgun debugging before posting the message above).

Edit: it's only working sporadically after suspends.

[evil666]

Issue still occurring in Arch Linux. I made a temporary work around by creating a systemd service to restart python3-validity.service in /etc/systemd/system.

python3-validity-wakeup.service:

[Unit]
After=hibernate.target
After=hybrid-sleep.target
After=suspend.target
After=suspend-then-hibernate.target
 
[Service]
Type=simple
ExecStart=/bin/systemctl --no-block restart python3-validity.service

[Install]
WantedBy=hibernate.target
WantedBy=hybrid-sleep.target
WantedBy=suspend.target
WantedBy=suspend-then-hibernate.target

[Xaeroxe]

evil666's workaround works for me, I'm on Arch with a ThinkPad T580 though it's a little sluggish on the uptake. It takes a few seconds for the fingerprint reader to activate.

Here's the info for my fingerprint reader.

$ lsusb
...
Bus 001 Device 006: ID 06cb:009a Synaptics, Inc. Metallica MIS Touch Fingerprint Reader
...