Issue when unplug device while enrollment or verify process (UareU 4500) (#355) · Issues · libfprint / libfprint

Issue when unplug device while enrollment or verify process (UareU 4500)

I have tested the examples provided in the library v1.90.6 for the enroll and verify processes in Linux (Ubuntu 18.04 LTS) using the device: Digital Persona U are U 4500. So the driver used is the uru4000.

When the process for Enroll or Verify is executing and ask for the FINGER ON, if I unplug the USB device then the user callback will never be called. Internally the device is DEACTIVATE so the state change to DEACTIVATE but the action remains as FPI_DEVICE_ACTION_ENROLL or FPI_DEVICE_ACTION_VERIFY according to the case. This is a problem because I'm never notified and it causes the app to hang.

I Previously sent and email to the Mailing list (fprint@lists.freedesktop.org) and was told the following:

You should get a well defined behaviour. i.e. the following happening (in this order):

"removed" property changes from FALSE to TRUE
enroll callback being called with error
"removed" signal is called
FpContext emits the "device-removed" signal

But the enroll callback in point 2 is never called. I have enabled more debug output by setting:

G_MESSAGES_DEBUG=all and maybe also FP_DEBUG_TRANSFER=1

Here is my Debug trace for Enrollment process:

Selected device 0 (Digital Persona U.are.U 4000/4000B/4500) claimed by uru4000 driver
(process:5048): libfprint-image_device-DEBUG: 18:38:41.396: Image device open completed
(process:5048): libfprint-device-DEBUG: 18:38:41.396: Device reported open completion
(process:5048): libfprint-device-DEBUG: 18:38:41.396: Completing action FPI_DEVICE_ACTION_OPEN in idle!
Opened device. It's now time to enroll your finger.

You will need to successfully scan your right index finger 1 times to complete the process.

Scan your finger now.
(process:5048): libfprint-image_device-DEBUG: 18:38:46.443: Activating image device
(process:5048): libfprint-image_device-DEBUG: 18:38:46.443: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
(process:5048): libfprint-DEBUG: 18:38:46.443: Transfer 0x5599c62b29f0 submitted, requested length 64, endpoint 0x81
(process:5048): libfprint-SSM-DEBUG: 18:38:46.443: [uru4000] INIT_NUM_STATES entering state 0
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.443: read 1 regs at 7
(process:5048): libfprint-DEBUG: 18:38:46.443: Transfer 0x5599c62b2a60 submitted, requested length 1, endpoint 0x0
(process:5048): libfprint-DEBUG: 18:38:46.443: 00 
(process:5048): libfprint-DEBUG: 18:38:46.450: Transfer 0x5599c62b2a60 completed successfully, requested length 1, actual length 1, endpoint 0x0
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.450: reg value 1
(process:5048): libfprint-SSM-DEBUG: 18:38:46.450: [uru4000] INIT_NUM_STATES entering state 1
(process:5048): libfprint-SSM-DEBUG: 18:38:46.450: [uru4000] INIT_NUM_STATES entering state 3
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.450: set 81
(process:5048): libfprint-DEBUG: 18:38:46.450: Transfer 0x5599c62b2ad0 submitted, requested length 1, endpoint 0x0
(process:5048): libfprint-DEBUG: 18:38:46.450: 81 
(process:5048): libfprint-DEBUG: 18:38:46.458: Transfer 0x5599c62b2ad0 completed successfully, requested length 1, actual length 1, endpoint 0x0
(process:5048): libfprint-SSM-DEBUG: 18:38:46.458: [uru4000] INIT_NUM_STATES entering state 4
(process:5048): libfprint-SSM-DEBUG: 18:38:46.458: [uru4000] POWERUP_NUM_STATES entering state 0
(process:5048): libfprint-SSM-DEBUG: 18:38:46.458: [uru4000] POWERUP_NUM_STATES entering state 1
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.458: set 01
(process:5048): libfprint-DEBUG: 18:38:46.458: Transfer 0x5599c62b2b40 submitted, requested length 1, endpoint 0x0
(process:5048): libfprint-DEBUG: 18:38:46.458: 01 
(process:5048): libfprint-DEBUG: 18:38:46.458: Transfer 0x5599c62b29f0 completed successfully, requested length 64, actual length 64, endpoint 0x81
(process:5048): libfprint-DEBUG: 18:38:46.458: 56 aa 03 91 0e fe 0c 54 02 01 0d ee 0c 40 14 04 
(process:5048): libfprint-DEBUG: 18:38:46.458: 0c 44 16 04 02 70 0c 51 14 02 0f 11 0c 44 0f 10 
(process:5048): libfprint-DEBUG: 18:38:46.458: 16 0a 0c 40 02 3f 14 01 0f 10 0c 44 0d e0 0e f1 
(process:5048): libfprint-DEBUG: 18:38:46.458: 0c 40 00 4c 0e fe 14 01 0c 44 0d ee 00 10 0c 40 
(process:5048): libfprint-DEBUG: 18:38:46.458: Transfer 0x5599c62ddc40 submitted, requested length 64, endpoint 0x81
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.458: recv irq type 56aa
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.458: early scanpwr interrupt
(process:5048): libfprint-DEBUG: 18:38:46.463: Transfer 0x5599c62b2b40 completed successfully, requested length 1, actual length 1, endpoint 0x0
(process:5048): libfprint-SSM-DEBUG: 18:38:46.463: [uru4000] POWERUP_NUM_STATES entering state 2
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.463: read 1 regs at 7
(process:5048): libfprint-DEBUG: 18:38:46.463: Transfer 0x5599c62ddcb0 submitted, requested length 1, endpoint 0x0
(process:5048): libfprint-DEBUG: 18:38:46.463: 00 
(process:5048): libfprint-DEBUG: 18:38:46.468: Transfer 0x5599c62ddcb0 completed successfully, requested length 1, actual length 1, endpoint 0x0
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.468: reg value 0
(process:5048): libfprint-SSM-DEBUG: 18:38:46.468: [uru4000] POWERUP_NUM_STATES entering state 3
(process:5048): libfprint-SSM-DEBUG: 18:38:46.468: [uru4000] POWERUP_NUM_STATES completed successfully
(process:5048): libfprint-SSM-DEBUG: 18:38:46.468: [uru4000] INIT_NUM_STATES entering state 5
(process:5048): libfprint-SSM-DEBUG: 18:38:46.468: [uru4000] INIT_NUM_STATES entering state 6
(process:5048): libfprint-SSM-DEBUG: 18:38:46.468: [uru4000] INIT_NUM_STATES entering state 7
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.468: read 16 regs at f0
(process:5048): libfprint-DEBUG: 18:38:46.468: Transfer 0x5599c62ddd20 submitted, requested length 16, endpoint 0x0
(process:5048): libfprint-DEBUG: 18:38:46.468: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
(process:5048): libfprint-DEBUG: 18:38:46.472: Transfer 0x5599c62ddc40 completed successfully, requested length 64, actual length 64, endpoint 0x81
(process:5048): libfprint-DEBUG: 18:38:46.472: 56 aa 03 91 0e fe 0c 54 02 01 0d ee 0c 40 14 04 
(process:5048): libfprint-DEBUG: 18:38:46.472: 0c 44 16 04 02 70 0c 51 14 02 0f 11 0c 44 0f 10 
(process:5048): libfprint-DEBUG: 18:38:46.472: 16 0a 0c 40 02 3f 14 01 0f 10 0c 44 0d e0 0e f1 
(process:5048): libfprint-DEBUG: 18:38:46.472: 0c 40 00 4c 0e fe 14 01 0c 44 0d ee 00 10 0c 40 
(process:5048): libfprint-DEBUG: 18:38:46.472: Transfer 0x5599c62ddd90 submitted, requested length 64, endpoint 0x81
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.472: recv irq type 56aa
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.472: ignoring interrupt
(process:5048): libfprint-DEBUG: 18:38:46.473: Transfer 0x5599c62ddd20 completed successfully, requested length 16, actual length 16, endpoint 0x0
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.473: reg value 1a
(process:5048): libfprint-SSM-DEBUG: 18:38:46.473: [uru4000] INIT_NUM_STATES entering state 8
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.473: Versions 0010 and 0115
(process:5048): libfprint-SSM-DEBUG: 18:38:46.473: [uru4000] INIT_NUM_STATES completed successfully
(process:5048): libfprint-image_device-DEBUG: 18:38:46.473: Image device activation completed
(process:5048): libfprint-image_device-DEBUG: 18:38:46.473: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
(process:5048): libfprint-image_device-DEBUG: 18:38:46.473: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
(process:5048): libfprint-uru4000-DEBUG: 18:38:46.473: wait finger on
(process:5048): libfprint-DEBUG: 18:38:46.473: Transfer 0x5599c62dde00 submitted, requested length 1, endpoint 0x0
(process:5048): libfprint-DEBUG: 18:38:46.473: 10 
(process:5048): libfprint-device-DEBUG: 18:38:46.473: Device reported finger status change: FP_FINGER_STATUS_NEEDED
(process:5048): libfprint-DEBUG: 18:38:46.479: Transfer 0x5599c62dde00 completed successfully, requested length 1, actual length 1, endpoint 0x0
(process:5048): libfprint-DEBUG: 18:39:01.263: Transfer 0x5599c62ddd90 completed with error (endpoint stalled or request not supported), requested length 64, actual length -1, endpoint 0x81
(process:5048): libfprint-image_device-DEBUG: 18:39:01.263: Deactivating image device
(process:5048): libfprint-image_device-DEBUG: 18:39:01.263: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
(process:5048): libfprint-uru4000-DEBUG: 18:39:01.263: deactivating
(process:5048): libfprint-DEBUG: 18:39:01.263: Transfer 0x5599c62dde70 submitted, requested length 1, endpoint 0x0
(process:5048): libfprint-DEBUG: 18:39:01.263: 70 
(process:5048): libfprint-DEBUG: 18:39:01.303: Transfer 0x5599c62dde70 completed with error (endpoint stalled or request not supported), requested length 1, actual length -1, endpoint 0x0

Here is my Debug trace for Verify process

Selected device 0 (Digital Persona U.are.U 4000/4000B/4500) claimed by uru4000 driver
(process:5307): libfprint-image_device-DEBUG: 19:48:32.024: Image device open completed
(process:5307): libfprint-device-DEBUG: 19:48:32.024: Device reported open completion
(process:5307): libfprint-device-DEBUG: 19:48:32.024: Completing action FPI_DEVICE_ACTION_OPEN in idle!
Opened device. Choose the finger to verify:
  [0] left thumb
  [1] left index
  [2] left middle
  [3] left ring
  [4] left little
  [5] right thumb
  [6] right index
  [7] right middle
  [8] right ring
  [9] right little
> 6
Loading previously enrolled right index finger data...
Print loaded. Time to verify!
(process:5307): libfprint-image_device-DEBUG: 19:48:38.276: Activating image device
(process:5307): libfprint-image_device-DEBUG: 19:48:38.276: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
(process:5307): libfprint-DEBUG: 19:48:38.276: Transfer 0x55aeee4d51f0 submitted, requested length 64, endpoint 0x81
(process:5307): libfprint-SSM-DEBUG: 19:48:38.276: [uru4000] INIT_NUM_STATES entering state 0
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.276: read 1 regs at 7
(process:5307): libfprint-DEBUG: 19:48:38.276: Transfer 0x55aeee4d5260 submitted, requested length 1, endpoint 0x0
(process:5307): libfprint-DEBUG: 19:48:38.276: 00 
(process:5307): libfprint-DEBUG: 19:48:38.297: Transfer 0x55aeee4d51f0 completed successfully, requested length 64, actual length 64, endpoint 0x81
(process:5307): libfprint-DEBUG: 19:48:38.297: 56 aa 03 91 0e fe 0c 54 02 01 0d ee 0c 40 14 04 
(process:5307): libfprint-DEBUG: 19:48:38.297: 0c 44 16 04 02 70 0c 51 14 02 0f 11 0c 44 0f 10 
(process:5307): libfprint-DEBUG: 19:48:38.297: 16 0a 0c 40 02 3f 14 01 0f 10 0c 44 0d e0 0e f1 
(process:5307): libfprint-DEBUG: 19:48:38.297: 0c 40 00 4c 0e fe 14 01 0c 44 0d ee 00 10 0c 40 
(process:5307): libfprint-DEBUG: 19:48:38.297: Transfer 0x55aeee4d52d0 submitted, requested length 64, endpoint 0x81
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.297: recv irq type 56aa
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.297: ignoring interrupt
(process:5307): libfprint-DEBUG: 19:48:38.297: Transfer 0x55aeee4d5260 completed successfully, requested length 1, actual length 1, endpoint 0x0
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.297: reg value 1
(process:5307): libfprint-SSM-DEBUG: 19:48:38.297: [uru4000] INIT_NUM_STATES entering state 1
(process:5307): libfprint-SSM-DEBUG: 19:48:38.297: [uru4000] INIT_NUM_STATES entering state 3
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.297: set 81
(process:5307): libfprint-DEBUG: 19:48:38.297: Transfer 0x55aeee4d5340 submitted, requested length 1, endpoint 0x0
(process:5307): libfprint-DEBUG: 19:48:38.297: 81 
(process:5307): libfprint-DEBUG: 19:48:38.306: Transfer 0x55aeee4d5340 completed successfully, requested length 1, actual length 1, endpoint 0x0
(process:5307): libfprint-SSM-DEBUG: 19:48:38.306: [uru4000] INIT_NUM_STATES entering state 4
(process:5307): libfprint-SSM-DEBUG: 19:48:38.306: [uru4000] POWERUP_NUM_STATES entering state 0
(process:5307): libfprint-SSM-DEBUG: 19:48:38.306: [uru4000] POWERUP_NUM_STATES entering state 1
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.306: set 01
(process:5307): libfprint-DEBUG: 19:48:38.306: Transfer 0x55aeee4ffc00 submitted, requested length 1, endpoint 0x0
(process:5307): libfprint-DEBUG: 19:48:38.306: 01 
(process:5307): libfprint-DEBUG: 19:48:38.312: Transfer 0x55aeee4ffc00 completed successfully, requested length 1, actual length 1, endpoint 0x0
(process:5307): libfprint-SSM-DEBUG: 19:48:38.312: [uru4000] POWERUP_NUM_STATES entering state 2
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.312: read 1 regs at 7
(process:5307): libfprint-DEBUG: 19:48:38.312: Transfer 0x55aeee4ffc70 submitted, requested length 1, endpoint 0x0
(process:5307): libfprint-DEBUG: 19:48:38.312: 00 
(process:5307): libfprint-DEBUG: 19:48:38.319: Transfer 0x55aeee4ffc70 completed successfully, requested length 1, actual length 1, endpoint 0x0
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.319: reg value 0
(process:5307): libfprint-SSM-DEBUG: 19:48:38.319: [uru4000] POWERUP_NUM_STATES entering state 3
(process:5307): libfprint-SSM-DEBUG: 19:48:38.319: [uru4000] POWERUP_NUM_STATES completed successfully
(process:5307): libfprint-SSM-DEBUG: 19:48:38.319: [uru4000] INIT_NUM_STATES entering state 5
(process:5307): libfprint-DEBUG: 19:48:38.321: Transfer 0x55aeee4d52d0 completed successfully, requested length 64, actual length 64, endpoint 0x81
(process:5307): libfprint-DEBUG: 19:48:38.321: 56 aa 03 91 0e fe 0c 54 02 01 0d ee 0c 40 14 04 
(process:5307): libfprint-DEBUG: 19:48:38.321: 0c 44 16 04 02 70 0c 51 14 02 0f 11 0c 44 0f 10 
(process:5307): libfprint-DEBUG: 19:48:38.321: 16 0a 0c 40 02 3f 14 01 0f 10 0c 44 0d e0 0e f1 
(process:5307): libfprint-DEBUG: 19:48:38.321: 0c 40 00 4c 0e fe 14 01 0c 44 0d ee 00 10 0c 40 
(process:5307): libfprint-DEBUG: 19:48:38.321: Transfer 0x55aeee4ffce0 submitted, requested length 64, endpoint 0x81
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.321: recv irq type 56aa
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.321: late scanpwr interrupt
(process:5307): libfprint-SSM-DEBUG: 19:48:38.321: [uru4000] INIT_NUM_STATES entering state 6
(process:5307): libfprint-SSM-DEBUG: 19:48:38.321: [uru4000] INIT_NUM_STATES entering state 7
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.321: read 16 regs at f0
(process:5307): libfprint-DEBUG: 19:48:38.321: Transfer 0x55aeee4ffd50 submitted, requested length 16, endpoint 0x0
(process:5307): libfprint-DEBUG: 19:48:38.321: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
(process:5307): libfprint-DEBUG: 19:48:38.327: Transfer 0x55aeee4ffd50 completed successfully, requested length 16, actual length 16, endpoint 0x0
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.327: reg value 1a
(process:5307): libfprint-SSM-DEBUG: 19:48:38.327: [uru4000] INIT_NUM_STATES entering state 8
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.327: Versions 0010 and 0115
(process:5307): libfprint-SSM-DEBUG: 19:48:38.327: [uru4000] INIT_NUM_STATES completed successfully
(process:5307): libfprint-image_device-DEBUG: 19:48:38.327: Image device activation completed
(process:5307): libfprint-image_device-DEBUG: 19:48:38.327: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
(process:5307): libfprint-image_device-DEBUG: 19:48:38.327: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
(process:5307): libfprint-uru4000-DEBUG: 19:48:38.327: wait finger on
(process:5307): libfprint-DEBUG: 19:48:38.327: Transfer 0x55aeee4ffdc0 submitted, requested length 1, endpoint 0x0
(process:5307): libfprint-DEBUG: 19:48:38.327: 10 
(process:5307): libfprint-device-DEBUG: 19:48:38.327: Device reported finger status change: FP_FINGER_STATUS_NEEDED
(process:5307): libfprint-DEBUG: 19:48:38.335: Transfer 0x55aeee4ffdc0 completed successfully, requested length 1, actual length 1, endpoint 0x0
(process:5307): libfprint-DEBUG: 19:48:43.769: Transfer 0x55aeee4ffce0 completed with error (endpoint stalled or request not supported), requested length 64, actual length -1, endpoint 0x81
(process:5307): libfprint-image_device-DEBUG: 19:48:43.769: Deactivating image device
(process:5307): libfprint-image_device-DEBUG: 19:48:43.769: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
(process:5307): libfprint-uru4000-DEBUG: 19:48:43.769: deactivating
(process:5307): libfprint-DEBUG: 19:48:43.769: Transfer 0x55aeee4ffe30 submitted, requested length 1, endpoint 0x0
(process:5307): libfprint-DEBUG: 19:48:43.769: 70 
(process:5307): libfprint-DEBUG: 19:48:43.807: Transfer 0x55aeee4ffe30 completed with error (endpoint stalled or request not supported), requested length 1, actual length -1, endpoint 0x0