uunicorn / python-validity

Validity fingerprint sensor prototype
MIT License
993 stars 83 forks source link

Fix for "Fingerprint not working after waking up from suspend" doesn't work on Fedora 36 #127

Open piotrowskiadam opened 2 years ago

piotrowskiadam commented 2 years ago

Fix for "Fingerprint not working after waking up from suspend"

sudo systemctl enable open-fprintd-resume open-fprintd-suspend

doesn't work on Fedora 36 on Thinkpad T480. Used to be fine before the upgrade to this version system.

Also after waking up from suspend now any command that requires 'sudo' in terminal makes the terminal wait around 20 seconds until there is a prompt to type password.

gnoamchomsky commented 2 years ago

Same issue on Fedora 35 after update. Stacktrace for open-fprintd-resume.service (ThinkPad x280):

May 27 19:55:43 thinkpadx280 systemd[1]: Starting Restart devices after resume... ░░ Subject: A start job for unit open-fprintd-resume.service has begun execution ░░ Defined-By: systemd ░░ Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel ░░ ░░ A start job for unit open-fprintd-resume.service has begun execution. ░░ ░░ The job identifier is 3909. May 27 19:55:43 thinkpadx280 python3[138637]: detected unhandled Python exception in '/usr/lib/open-fprintd/resume.py' May 27 19:55:43 thinkpadx280 resume.py[138637]: Traceback (most recent call last): May 27 19:55:43 thinkpadx280 resume.py[138637]: File "/usr/lib/open-fprintd/resume.py", line 11, in May 27 19:55:43 thinkpadx280 resume.py[138637]: o.Resume() May 27 19:55:43 thinkpadx280 resume.py[138637]: File "/usr/lib64/python3.10/site-packages/dbus/proxies.py", line 141, in call May 27 19:55:43 thinkpadx280 resume.py[138637]: return self._connection.call_blocking(self._named_service, May 27 19:55:43 thinkpadx280 resume.py[138637]: File "/usr/lib64/python3.10/site-packages/dbus/connection.py", line 652, in call_blocking May 27 19:55:43 thinkpadx280 resume.py[138637]: reply_message = self.send_message_with_reply_and_block( May 27 19:55:43 thinkpadx280 resume.py[138637]: dbus.exceptions.DBusException: org.freedesktop.DBus.Python.Exception: Traceback (most recent call last): May 27 19:55:43 thinkpadx280 resume.py[138637]: File "/usr/lib64/python3.10/site-packages/dbus/service.py", line 715, in _message_cb May 27 19:55:43 thinkpadx280 resume.py[138637]: retval = candidate_method(self, *args, **keywords) May 27 19:55:43 thinkpadx280 resume.py[138637]: File "/usr/lib/python-validity/dbus-service", line 74, in Resume May 27 19:55:43 thinkpadx280 resume.py[138637]: init.open_common() May 27 19:55:43 thinkpadx280 resume.py[138637]: File "/usr/lib/python3.10/site-packages/validitysensor/init.py", line 29, in open_common May 27 19:55:43 thinkpadx280 resume.py[138637]: init_flash() May 27 19:55:43 thinkpadx280 resume.py[138637]: File "/usr/lib/python3.10/site-packages/validitysensor/init_flash.py", line 113, in init_flash May 27 19:55:43 thinkpadx280 resume.py[138637]: info = get_flash_info() May 27 19:55:43 thinkpadx280 resume.py[138637]: File "/usr/lib/python3.10/site-packages/validitysensor/flash.py", line 41, in get_flash_info May 27 19:55:43 thinkpadx280 resume.py[138637]: assert_status(rsp) May 27 19:55:43 thinkpadx280 resume.py[138637]: File "/usr/lib/python3.10/site-packages/validitysensor/util.py", line 12, in assert_status May 27 19:55:43 thinkpadx280 resume.py[138637]: raise Exception('Failed: %04x' % s) May 27 19:55:43 thinkpadx280 resume.py[138637]: Exception: Failed: 0315 May 27 19:55:43 thinkpadx280 systemd[1]: open-fprintd-resume.service: Main process exited, code=exited, status=1/FAILURE ░░ Subject: Unit process exited ░░ Defined-By: systemd ░░ Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel ░░ ░░ An ExecStart= process belonging to unit open-fprintd-resume.service has exited. ░░ ░░ The process' exit code is 'exited' and its exit status is 1. May 27 19:55:43 thinkpadx280 systemd[1]: open-fprintd-resume.service: Failed with result 'exit-code'. ░░ Subject: Unit failed ░░ Defined-By: systemd ░░ Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel ░░ ░░ The unit open-fprintd-resume.service has entered the 'failed' state with result 'exit-code'. May 27 19:55:43 thinkpadx280 systemd[1]: Failed to start Restart devices after resume. ░░ Subject: A start job for unit open-fprintd-resume.service has failed ░░ Defined-By: systemd ░░ Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel ░░ ░░ A start job for unit open-fprintd-resume.service has finished with a failure. ░░ ░░ The job identifier is 3909 and the job result is failed.

nikita-dubrovskii commented 2 years ago

Try this:

sudo systemctl restart dbus.service 
sudo systemctl restart NetworkManager
piotrowskiadam commented 2 years ago

Doesn't work at least for me. Is there something I can put into terminal to get the log to diagnose it further?

piotrowskiadam commented 2 years ago

Worked with the solution found in #3

https://github.com/uunicorn/python-validity/issues/3#issuecomment-1127256921

gnoamchomsky commented 2 years ago

Can confirm that adding additional service worked, however this is workaround in my opinion. If python-validity has a service on it's own that handles that, it should work without us having to create additional service for it.

pendula95 commented 2 years ago

Can we please reopen this issue as this is a workaround as mentioned by @gnoamchomsky This is not how things are supposed to work

uunicorn commented 2 years ago

A bit of background in case some one wants to fix this and raise a PR:

Most of commands require to be sent over a secure channel (TLS). TLS wraps all command/response traffic between a host a device and encrypts+signs it. It is also used to establish a trust between the device and the host.

After TLS is established, both the device and the host must maintain their respective TLS states. There are a few cases when a device can loose it's TLS state:

This last bit is puzzling. On the driver's side we have no idea which state the device is in after resume. If we assume that TLS was established while it isn't, we'll get the dreaded "Unexpected TLS version 4 0" exception. If we assume that TLS was not established while it is, we'll get the 0315 error.

The good thing is that after both scenarios the state of device is the same - TLS is reset and the device is ready to establish another TLS session.

Here is an example which demonstrates this:

$ PYTHONPATH=scripts:. python3
Python 3.9.5 (default, Nov 18 2021, 16:00:48) 
[GCC 10.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> from prototype import *
>>> from validitysensor import init
>>> open9x()
>>> tls.reset()
>>> init.open_common()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/home/unicorn/Desktop/projects/python-validity/validitysensor/init.py", line 29, in open_common
    init_flash()
  File "/home/unicorn/Desktop/projects/python-validity/validitysensor/init_flash.py", line 115, in init_flash
    info = get_flash_info()
  File "/home/unicorn/Desktop/projects/python-validity/validitysensor/flash.py", line 41, in get_flash_info
    assert_status(rsp)
  File "/home/unicorn/Desktop/projects/python-validity/validitysensor/util.py", line 12, in assert_status
    raise Exception('Failed: %04x' % s)
Exception: Failed: 0315
>>> init.open_common()
>>> db.dump_all()
 4: User S-1-5-21-394619333-3876782012-1656198692-1004 with 1 fingers:
     5: f5 (WINBIO_FINGER_UNSPECIFIED_POS_01)
>>> 

As you can see, the second time we run init.open_common() it succeeds. Perhaps the best approach is to ignore the first exception in Device.Resume() from dbus_service/dbus-service and retry establishing TLS session. E.g:

diff --git a/dbus_service/dbus-service b/dbus_service/dbus-service
index 87430d8..038f866 100755
--- a/dbus_service/dbus-service
+++ b/dbus_service/dbus-service
@@ -70,7 +70,10 @@ class Device(dbus.service.Object):
     def Resume(self):
         logging.debug('In Resume')
         tls.reset()
-        init.open_common()
+        try:
+            init.open_common()
+        except:
+            init.open_common()

     @dbus.service.method(dbus_interface=INTERFACE_NAME, in_signature="s", out_signature="as")
     def ListEnrolledFingers(self, user):

It would be great If someone can test this and raise a PR.

uunicorn commented 2 years ago

I've pushed the fix and released 0.14 to Ubuntu PPA. Please test.

piotrowskiadam commented 2 years ago

I'm too much of a noob on linux most likely. I just copy things I find online and put in the terminal until something works for my device. PPA is used on ubuntu based distros only, right? Can you guide how would I test it now on Fedora when first I installed it via guide in README.md of the project with dnf commands and then tried the fix that didn't work and finally implemented a fix from https://github.com/uunicorn/python-validity/issues/3#issuecomment-1127256921 Probably I should revert all the changes and test it again. Sorry for the inconvenience.

pendula95 commented 2 years ago

@uunicorn I have tried the following test in playground and got same behavior as you. Initial init.open_common() will fail but if I retry I am able to processed. I have edited my /usr/lib/python-validity/dbus-service to retry init.open_common() but it did not resolve the issue, am I doing something wrong?

OS: Fedora release 36 (Thirty Six) x86 Host: 20KHS01000 ThinkPad X1 Carbon 6t Kernel: 5.18.18-200.fc36.x86_64

pendula95 commented 2 years ago

In regards to comments in #128 here is the output:

systemctl status open-fprintd-suspend.service
○ open-fprintd-suspend.service - Restart devices after resume
     Loaded: loaded (/usr/lib/systemd/system/open-fprintd-suspend.service; enabled; vendor preset: disabled)
     Active: inactive (dead) since Mon 2022-08-22 19:42:40 CEST; 5h 8min ago
    Process: 99220 ExecStart=/usr/lib/open-fprintd/suspend.py (code=exited, status=0/SUCCESS)
   Main PID: 99220 (code=exited, status=0/SUCCESS)
        CPU: 75ms
systemctl status open-fprintd-resume.service 
× open-fprintd-resume.service - Restart devices after resume
     Loaded: loaded (/usr/lib/systemd/system/open-fprintd-resume.service; enabled; vendor preset: disabled)
     Active: failed (Result: exit-code) since Tue 2022-08-23 00:27:14 CEST; 23min ago
    Process: 99264 ExecStart=/usr/lib/open-fprintd/resume.py (code=exited, status=1/FAILURE)
   Main PID: 99264 (code=exited, status=1/FAILURE)
        CPU: 107ms

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

Seems to be related to uunicorn/open-fprintd#12

sidneijp commented 2 weeks ago

Worked with the solution found in #3

#3 (comment)

This worked like a charm on Ubuntu 24.10. Thanks a lot!