[Fingerforce-devel] Bug#978256: libfprint: FTBFS: dh_auto_test: error: cd obj-x86_64-linux-gnu && LC_ALL=C.UTF-8 MESON_TESTTHREADS=4 meson test -C /<<PKGBUILDDIR>>/obj-x86_64-linux-gnu --timeout-multiplier 5 returned exit code 7
Lucas Nussbaum
lucas at debian.org
Sat Dec 26 21:44:58 GMT 2020
Source: libfprint
Version: 1:1.90.6-2
Severity: serious
Justification: FTBFS on amd64
Tags: bullseye sid ftbfs
Usertags: ftbfs-20201226 ftbfs-bullseye
Hi,
During a rebuild of all packages in sid, your package failed to build
on amd64.
Relevant part (hopefully):
> make[1]: Entering directory '/<<PKGBUILDDIR>>'
> dh_auto_test -- -C /<<PKGBUILDDIR>>/obj-x86_64-linux-gnu --timeout-multiplier 5
> cd obj-x86_64-linux-gnu && LC_ALL=C.UTF-8 MESON_TESTTHREADS=4 meson test -C /<<PKGBUILDDIR>>/obj-x86_64-linux-gnu --timeout-multiplier 5
> ninja: Entering directory `/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu'
> ninja: no work to do.
> 1/16 libfprint:virtual-image+VirtualImage / VirtualImage.test_capture_prevents_close OK 0.37s
> 2/16 libfprint:virtual-image+VirtualImage / VirtualImage.test_enroll_verify OK 1.98s
> 3/16 libfprint:virtual-image+VirtualImage / VirtualImage.test_identify OK 2.53s
> 4/16 libfprint:virtual-image+VirtualImage / VirtualImage.test_verify_serialized OK 2.20s
> 12/16 libfprint:unit-tests / fpi-device OK 0.27s
> 13/16 libfprint:unit-tests / fpi-ssm OK 1.07s
> 14/16 libfprint:unit-tests / fpi-assembling OK 0.37s
> 15/16 libfprint:unit-tests / fp-context OK 0.87s
> 16/16 libfprint:unit-tests / fp-device OK 3.07s
>
> Summary of Failures:
>
> 5/16 libfprint:drivers / aes3500 FAIL 0.17s (exit status 1)
> 6/16 libfprint:drivers / elan FAIL 0.17s (exit status 1)
> 7/16 libfprint:drivers / synaptics FAIL 0.17s (exit status 1)
> 8/16 libfprint:drivers / vfs0050 FAIL 0.17s (exit status 1)
> 9/16 libfprint:drivers / vfs301 FAIL 0.17s (exit status 1)
> 10/16 libfprint:drivers / vfs5011 FAIL 0.17s (exit status 1)
> 11/16 libfprint:drivers / goodixmoc FAIL 0.17s (exit status 1)
>
> Ok: 9
> Expected Fail: 0
> Fail: 7
> Unexpected Pass: 0
> Skipped: 0
> Timeout: 0
>
> Full log written to /<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/meson-logs/testlog.txt
> cd obj-x86_64-linux-gnu && tail -v -n \+0 meson-logs/testlog.txt
> ==> meson-logs/testlog.txt <==
> Log of Meson test suite run on 2020-12-26T18:42:59.683158
>
> Inherited environment: SCHROOT_GID='1001' DEB_HOST_MULTIARCH='x86_64-linux-gnu' LC_ALL='C.UTF-8' DEB_HOST_GNU_SYSTEM='linux-gnu' DEB_BUILD_GNU_TYPE='x86_64-linux-gnu' DEB_TARGET_ARCH_LIBC='gnu' FFLAGS='-g -O2 -fdebug-prefix-map=/<<PKGBUILDDIR>>=. -fstack-protector-strong' DEB_BUILD_ARCH_ENDIAN='little' DEB_BUILD_GNU_SYSTEM='linux-gnu' DEB_BUILD_ARCH_BITS='64' DEB_BUILD_OPTIONS='parallel=4' DEB_HOST_ARCH='amd64' DEB_TARGET_ARCH_ENDIAN='little' SOURCE_DATE_EPOCH='1607632369' OBJCXXFLAGS='-g -O2 -fdebug-prefix-map=/<<PKGBUILDDIR>>=. -fstack-protector-strong -Wformat -Werror=format-security' DEB_HOST_ARCH_BITS='64' LANG='C.UTF-8' MAKEFLAGS='w' SCHROOT_GROUP='user42' DEB_TARGET_ARCH='amd64' DPKG_GENSYMBOLS_CHECK_LEVEL='2' DH_INTERNAL_OPTIONS='' DEB_HOST_GNU_CPU='x86_64' DEB_BUILD_ARCH_LIBC='gnu' MFLAGS='-w' DEB_TARGET_ARCH_BITS='64' DEB_BUILD_ARCH_CPU='amd64' SCHROOT_ALIAS_NAME='unstable' DEB_HOST_ARCH_OS='linux' SHELL='/bin/sh' FCFLAGS='-g -O2 -fdebug-prefix-map=/<<PKGBUILDDIR>>=. -fstack-protector-strong' DEB_HOST_ARCH_CPU='amd64' SCHROOT_USER='user42' PATH='/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games' DEB_BUILD_ARCH_ABI='base' DEB_BUILD_ARCH='amd64' DEB_HOST_ARCH_LIBC='gnu' SCHROOT_SESSION_ID='sid-amd64-sbuild-a6508221-9911-4bdc-a467-9a030232c289' GCJFLAGS='-g -O2 -fdebug-prefix-map=/<<PKGBUILDDIR>>=. -fstack-protector-strong' DEB_TARGET_ARCH_CPU='amd64' DEB_HOST_GNU_TYPE='x86_64-linux-gnu' DEB_BUILD_ARCH_OS='linux' LOGNAME='user42' CPPFLAGS='-Wdate-time -D_FORTIFY_SOURCE=2' DEB_TARGET_MULTIARCH='x86_64-linux-gnu' DEB_BUILD_GNU_CPU='x86_64' DEB_TARGET_ARCH_OS='linux' USER='user42' DEB_HOST_ARCH_ABI='base' DEB_BUILD_MULTIARCH='x86_64-linux-gnu' LDFLAGS='-Wl,-z,relro' DEB_TARGET_GNU_TYPE='x86_64-linux-gnu' DEB_TARGET_ARCH_ABI='base' CFLAGS='-g -O2 -fdebug-prefix-map=/<<PKGBUILDDIR>>=. -fstack-protector-strong -Wformat -Werror=format-security' SCHROOT_UID='1001' SCHROOT_COMMAND='dpkg-buildpackage -us -uc -sa -rfakeroot' DEB_TARGET_GNU_CPU='x86_64' APT_CONFIG='/var/lib/sbuild/apt.conf' HOME='/<<PKGBUILDDIR>>/debian/.debhelper/generated/_source/home' DEB_RULES_REQUIRES_ROOT='binary-targets' DEB_TARGET_GNU_SYSTEM='linux-gnu' DEB_HOST_ARCH_ENDIAN='little' OBJCFLAGS='-g -O2 -fdebug-prefix-map=/<<PKGBUILDDIR>>=. -fstack-protector-strong -Wformat -Werror=format-security' SCHROOT_CHROOT_NAME='sid-amd64-sbuild' DH_INTERNAL_BUILDFLAGS='1' CXXFLAGS='-g -O2 -fdebug-prefix-map=/<<PKGBUILDDIR>>=. -fstack-protector-strong -Wformat -Werror=format-security' DH_INTERNAL_OVERRIDE='dh_auto_test' MAKELEVEL='2' XDG_RUNTIME_DIR='/tmp/dh-xdg-rundir-c9fIfcrL' MESON_TESTTHREADS='4'
>
> 1/16 libfprint:virtual-image+VirtualImage / VirtualImage.test_capture_prevents_close OK 0.37s
>
> --- command ---
> 18:42:59 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' FP_DRIVERS_WHITELIST='virtual_image' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /usr/bin/python3 /<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/../tests/virtual-image.py VirtualImage.test_capture_prevents_close
> --- stdout ---
> (process:15705): libfprint-context-DEBUG: 18:42:59.776: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-7arcz5nh/virtual-image.socket
> (process:15705): libfprint-context-DEBUG: 18:42:59.776: created
> test_capture_prevents_close (__main__.VirtualImage) ... (process:15705): libfprint-virtual_image-DEBUG: 18:42:59.792: 39113295038: ../libfprint/drivers/virtual-image.c:294
> (process:15705): libfprint-image_device-DEBUG: 18:42:59.893: Image device open completed
> (process:15705): libfprint-device-DEBUG: 18:42:59.893: Device reported open completion
> (process:15705): libfprint-device-DEBUG: 18:42:59.893: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (process:15705): libfprint-image_device-DEBUG: 18:42:59.893: Activating image device
> (process:15705): libfprint-image_device-DEBUG: 18:42:59.893: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15705): libfprint-image_device-DEBUG: 18:42:59.893: Image device activation completed
> (process:15705): libfprint-image_device-DEBUG: 18:42:59.893: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15705): libfprint-image_device-DEBUG: 18:42:59.893: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15705): libfprint-device-DEBUG: 18:42:59.894: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15705): libfprint-virtual_image-DEBUG: 18:42:59.894: Got a new connection!
> (process:15705): libfprint-virtual_image-DEBUG: 18:42:59.894: Starting image receive (if active), state is: 4
> (process:15705): libfprint-device-DEBUG: 18:42:59.894: Idle cancelling on ongoing operation!
> (process:15705): libfprint-image_device-DEBUG: 18:42:59.894: Deactivating image device
> (process:15705): libfprint-image_device-DEBUG: 18:42:59.894: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15705): libfprint-device-DEBUG: 18:42:59.894: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15705): libfprint-image_device-DEBUG: 18:42:59.904: Image device deactivation completed
> (process:15705): libfprint-image_device-DEBUG: 18:42:59.904: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15705): libfprint-device-DEBUG: 18:42:59.904: Device reported generic error (Operation was cancelled) during action; action was: FPI_DEVICE_ACTION_CAPTURE
> (process:15705): libfprint-device-DEBUG: 18:42:59.904: Device reported capture completion
> (process:15705): libfprint-device-DEBUG: 18:42:59.904: Completing action FPI_DEVICE_ACTION_CAPTURE in idle!
> (process:15705): libfprint-virtual_image-DEBUG: 18:42:59.905: 39113407927: ../libfprint/drivers/virtual-image.c:338
> (process:15705): libfprint-image_device-DEBUG: 18:43:00.005: Image device close completed
> (process:15705): libfprint-device-DEBUG: 18:43:00.006: Device reported close completion
> (process:15705): libfprint-device-DEBUG: 18:43:00.006: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> Capture operation finished
> Capture cancelled as expected
> ok
>
> ----------------------------------------------------------------------
> Ran 1 test in 0.233s
>
> OK
> -------
>
> 2/16 libfprint:virtual-image+VirtualImage / VirtualImage.test_enroll_verify OK 1.98s
>
> --- command ---
> 18:42:59 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' FP_DRIVERS_WHITELIST='virtual_image' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /usr/bin/python3 /<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/../tests/virtual-image.py VirtualImage.test_enroll_verify
> --- stdout ---
> (process:15708): libfprint-context-DEBUG: 18:42:59.781: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-qytfd756/virtual-image.socket
> (process:15708): libfprint-context-DEBUG: 18:42:59.781: created
> test_enroll_verify (__main__.VirtualImage) ... (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.796: 39113298219: ../libfprint/drivers/virtual-image.c:294
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.896: Image device open completed
> (process:15708): libfprint-device-DEBUG: 18:42:59.896: Device reported open completion
> (process:15708): libfprint-device-DEBUG: 18:42:59.896: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Activating image device
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Image device activation completed
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15708): libfprint-device-DEBUG: 18:42:59.898: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.898: Got a new connection!
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.898: Starting image receive (if active), state is: 4
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.898: image data: 0x1e65360
> (process:15708): libfprint-device-DEBUG: 18:42:59.898: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Image device reported finger status: on
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Image device captured an image
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15708): libfprint-device-DEBUG: 18:42:59.898: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-device-DEBUG: 18:42:59.898: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Image device reported finger status: off
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.898: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.898: Starting image receive (if active), state is: 3
> (process:15708): libfprint-image-DEBUG: 18:42:59.937: Minutiae scan completed in 0.038869 secs
> (process:15708): libfprint-device-DEBUG: 18:42:59.937: Device reported enroll progress, reported 1 of 5 have been completed
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.937: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15708): libfprint-device-DEBUG: 18:42:59.937: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.938: Starting image receive (if active), state is: 4
> (process:15708): libfprint-device-DEBUG: 18:42:59.938: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.938: Image device reported finger status: on
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.938: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.938: Starting image receive (if active), state is: 5
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.938: image data: 0x1e466b0
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.938: Image device captured an image
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.938: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15708): libfprint-device-DEBUG: 18:42:59.938: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.938: Starting image receive (if active), state is: 6
> (process:15708): libfprint-image-DEBUG: 18:42:59.982: Minutiae scan completed in 0.043720 secs
> (process:15708): libfprint-device-DEBUG: 18:42:59.982: Device reported enroll progress, reported 2 of 5 have been completed
> (process:15708): libfprint-device-DEBUG: 18:42:59.982: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.982: Image device reported finger status: off
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.982: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.982: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15708): libfprint-device-DEBUG: 18:42:59.982: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.982: Starting image receive (if active), state is: 4
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.982: Starting image receive (if active), state is: 4
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.982: image data: 0x1e466b0
> (process:15708): libfprint-device-DEBUG: 18:42:59.982: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.982: Image device reported finger status: on
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.982: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.982: Image device captured an image
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.982: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15708): libfprint-device-DEBUG: 18:42:59.982: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-device-DEBUG: 18:42:59.982: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.982: Image device reported finger status: off
> (process:15708): libfprint-image_device-DEBUG: 18:42:59.982: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-virtual_image-DEBUG: 18:42:59.982: Starting image receive (if active), state is: 3
> (process:15708): libfprint-image-DEBUG: 18:43:00.026: Minutiae scan completed in 0.044068 secs
> (process:15708): libfprint-device-DEBUG: 18:43:00.026: Device reported enroll progress, reported 3 of 5 have been completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.027: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15708): libfprint-device-DEBUG: 18:43:00.027: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:00.027: image data: 0x1e466b0
> (process:15708): libfprint-device-DEBUG: 18:43:00.027: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.027: Image device reported finger status: on
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.027: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.027: Image device captured an image
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.027: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15708): libfprint-device-DEBUG: 18:43:00.027: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-device-DEBUG: 18:43:00.027: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.027: Image device reported finger status: off
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.027: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:00.027: Starting image receive (if active), state is: 3
> (process:15708): libfprint-image-DEBUG: 18:43:00.072: Minutiae scan completed in 0.044920 secs
> (process:15708): libfprint-device-DEBUG: 18:43:00.072: Device reported enroll progress, reported 4 of 5 have been completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.072: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15708): libfprint-device-DEBUG: 18:43:00.072: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:00.072: image data: 0x1e466b0
> (process:15708): libfprint-device-DEBUG: 18:43:00.072: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.072: Image device reported finger status: on
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.072: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.072: Image device captured an image
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.072: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15708): libfprint-device-DEBUG: 18:43:00.072: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-device-DEBUG: 18:43:00.072: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.072: Image device reported finger status: off
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.072: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:00.072: Starting image receive (if active), state is: 3
> (process:15708): libfprint-image-DEBUG: 18:43:00.117: Minutiae scan completed in 0.044282 secs
> (process:15708): libfprint-device-DEBUG: 18:43:00.117: Device reported enroll progress, reported 5 of 5 have been completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.117: Deactivating image device
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.117: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.127: Image device deactivation completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.127: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15708): libfprint-device-DEBUG: 18:43:00.127: Device reported enroll completion
> (process:15708): libfprint-device-DEBUG: 18:43:00.127: Print for finger FP_FINGER_LEFT_THUMB enrolled
> (process:15708): libfprint-device-DEBUG: 18:43:00.127: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Activating image device
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device activation completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15708): libfprint-device-DEBUG: 18:43:00.128: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:00.128: Starting image receive (if active), state is: 4
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:00.128: image data: 0x1e466b0
> (process:15708): libfprint-device-DEBUG: 18:43:00.128: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device reported finger status: on
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device captured an image
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15708): libfprint-device-DEBUG: 18:43:00.128: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-device-DEBUG: 18:43:00.128: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device reported finger status: off
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Deactivating image device
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.128: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:00.128: Starting image receive (if active), state is: 2
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.138: Image device deactivation completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:00.138: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15708): libfprint-image-DEBUG: 18:43:00.174: Minutiae scan completed in 0.045821 secs
> (process:15708): libfprint-print-DEBUG: 18:43:01.447: score 1093/40
> (process:15708): libfprint-device-DEBUG: 18:43:01.447: Device reported verify result
> (process:15708): libfprint-device-DEBUG: 18:43:01.447: Device reported verify completion
> (process:15708): libfprint-device-DEBUG: 18:43:01.447: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Activating image device
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device activation completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15708): libfprint-device-DEBUG: 18:43:01.447: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:01.447: Starting image receive (if active), state is: 4
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:01.447: image data: 0x1ec2d90
> (process:15708): libfprint-device-DEBUG: 18:43:01.447: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device reported finger status: on
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device captured an image
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15708): libfprint-device-DEBUG: 18:43:01.447: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15708): libfprint-device-DEBUG: 18:43:01.447: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device reported finger status: off
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Deactivating image device
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.447: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:01.447: Starting image receive (if active), state is: 2
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.458: Image device deactivation completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.458: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15708): libfprint-image-DEBUG: 18:43:01.469: Minutiae scan completed in 0.021845 secs
> (process:15708): libfprint-print-DEBUG: 18:43:01.475: score 10/40
> (process:15708): libfprint-print-DEBUG: 18:43:01.481: score 10/40
> (process:15708): libfprint-print-DEBUG: 18:43:01.486: score 10/40
> (process:15708): libfprint-print-DEBUG: 18:43:01.492: score 10/40
> (process:15708): libfprint-print-DEBUG: 18:43:01.497: score 10/40
> (process:15708): libfprint-device-DEBUG: 18:43:01.497: Device reported verify result
> (process:15708): libfprint-device-DEBUG: 18:43:01.497: Device reported verify completion
> (process:15708): libfprint-device-DEBUG: 18:43:01.498: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.498: Activating image device
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.498: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.498: Image device activation completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.498: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.498: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15708): libfprint-device-DEBUG: 18:43:01.498: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:01.498: Starting image receive (if active), state is: 4
> (process:15708): libfprint-device-DEBUG: 18:43:01.498: Device reported verify result
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.498: Deactivating image device
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.498: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:01.498: Starting image receive (if active), state is: 2
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.508: Image device deactivation completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.508: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15708): libfprint-device-DEBUG: 18:43:01.508: Device reported verify completion
> (process:15708): libfprint-device-DEBUG: 18:43:01.508: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15708): libfprint-device-DEBUG: 18:43:01.508: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.508: Activating image device
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.508: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.508: Image device activation completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.508: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.508: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15708): libfprint-device-DEBUG: 18:43:01.508: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:01.508: Starting image receive (if active), state is: 4
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.508: Deactivating image device
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.508: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:01.508: Starting image receive (if active), state is: 2
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.518: Image device deactivation completed
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.518: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15708): libfprint-device-DEBUG: 18:43:01.518: Device reported generic error (An unspecified error occurred!) during action; action was: FPI_DEVICE_ACTION_VERIFY
> (process:15708): libfprint-device-DEBUG: 18:43:01.518: Device reported verify completion
> (process:15708): libfprint-device-DEBUG: 18:43:01.518: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15708): libfprint-device-DEBUG: 18:43:01.519: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (process:15708): libfprint-virtual_image-DEBUG: 18:43:01.519: 39115021381: ../libfprint/drivers/virtual-image.c:338
> (process:15708): libfprint-image_device-DEBUG: 18:43:01.619: Image device close completed
> (process:15708): libfprint-device-DEBUG: 18:43:01.619: Device reported close completion
> (process:15708): libfprint-device-DEBUG: 18:43:01.619: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Enroll done
> fp - device - error - quark: An unspecified error occurred! (0)
> ok
>
> ----------------------------------------------------------------------
> Ran 1 test in 1.841s
>
> OK
> -------
>
> 3/16 libfprint:virtual-image+VirtualImage / VirtualImage.test_identify OK 2.53s
>
> --- command ---
> 18:42:59 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' FP_DRIVERS_WHITELIST='virtual_image' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /usr/bin/python3 /<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/../tests/virtual-image.py VirtualImage.test_identify
> --- stdout ---
> (process:15706): libfprint-context-DEBUG: 18:42:59.778: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-nti7vlm0/virtual-image.socket
> (process:15706): libfprint-context-DEBUG: 18:42:59.778: created
> test_identify (__main__.VirtualImage) ... (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.796: 39113298943: ../libfprint/drivers/virtual-image.c:294
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.897: Image device open completed
> (process:15706): libfprint-device-DEBUG: 18:42:59.897: Device reported open completion
> (process:15706): libfprint-device-DEBUG: 18:42:59.897: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.898: Activating image device
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.898: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.898: Image device activation completed
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.899: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.899: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:42:59.899: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.899: Got a new connection!
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.899: Starting image receive (if active), state is: 4
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.899: image data: 0x1ad4ca0
> (process:15706): libfprint-device-DEBUG: 18:42:59.899: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.899: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.899: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.899: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.899: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:42:59.899: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-device-DEBUG: 18:42:59.899: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.899: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.899: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.899: Starting image receive (if active), state is: 3
> (process:15706): libfprint-image-DEBUG: 18:42:59.926: Minutiae scan completed in 0.026762 secs
> (process:15706): libfprint-device-DEBUG: 18:42:59.926: Device reported enroll progress, reported 1 of 5 have been completed
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.926: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:42:59.926: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.926: Starting image receive (if active), state is: 4
> (process:15706): libfprint-device-DEBUG: 18:42:59.926: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.926: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.926: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.926: Starting image receive (if active), state is: 5
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.926: image data: 0x1ae36e0
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.926: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.926: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:42:59.926: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.926: Starting image receive (if active), state is: 6
> (process:15706): libfprint-image-DEBUG: 18:42:59.952: Minutiae scan completed in 0.025686 secs
> (process:15706): libfprint-device-DEBUG: 18:42:59.952: Device reported enroll progress, reported 2 of 5 have been completed
> (process:15706): libfprint-device-DEBUG: 18:42:59.952: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.952: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.952: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.952: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:42:59.952: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.952: Starting image receive (if active), state is: 4
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.952: Starting image receive (if active), state is: 4
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.952: image data: 0x1ae36e0
> (process:15706): libfprint-device-DEBUG: 18:42:59.952: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.952: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.952: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.952: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.952: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:42:59.952: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-device-DEBUG: 18:42:59.952: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.952: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.952: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.952: Starting image receive (if active), state is: 3
> (process:15706): libfprint-image-DEBUG: 18:42:59.976: Minutiae scan completed in 0.024024 secs
> (process:15706): libfprint-device-DEBUG: 18:42:59.976: Device reported enroll progress, reported 3 of 5 have been completed
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.976: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:42:59.977: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.977: image data: 0x1ac48c0
> (process:15706): libfprint-device-DEBUG: 18:42:59.977: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.977: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.977: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.977: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.977: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:42:59.977: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-device-DEBUG: 18:42:59.977: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.977: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:42:59.977: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-virtual_image-DEBUG: 18:42:59.977: Starting image receive (if active), state is: 3
> (process:15706): libfprint-image-DEBUG: 18:43:00.002: Minutiae scan completed in 0.025574 secs
> (process:15706): libfprint-device-DEBUG: 18:43:00.002: Device reported enroll progress, reported 4 of 5 have been completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.002: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:43:00.002: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.003: image data: 0x1ac48c0
> (process:15706): libfprint-device-DEBUG: 18:43:00.003: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.003: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.003: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.003: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.003: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:43:00.003: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-device-DEBUG: 18:43:00.003: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.003: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.003: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.003: Starting image receive (if active), state is: 3
> (process:15706): libfprint-image-DEBUG: 18:43:00.034: Minutiae scan completed in 0.031655 secs
> (process:15706): libfprint-device-DEBUG: 18:43:00.034: Device reported enroll progress, reported 5 of 5 have been completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.034: Deactivating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.034: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.045: Image device deactivation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.045: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15706): libfprint-device-DEBUG: 18:43:00.045: Device reported enroll completion
> (process:15706): libfprint-device-DEBUG: 18:43:00.045: Print for finger FP_FINGER_LEFT_THUMB enrolled
> (process:15706): libfprint-device-DEBUG: 18:43:00.045: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.045: Activating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.045: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.045: Image device activation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.045: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.045: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:43:00.045: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.045: Starting image receive (if active), state is: 4
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.045: image data: 0x1b22040
> (process:15706): libfprint-device-DEBUG: 18:43:00.045: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.045: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.045: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.045: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.046: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:43:00.046: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-device-DEBUG: 18:43:00.046: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.046: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.046: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.046: Starting image receive (if active), state is: 3
> (process:15706): libfprint-image-DEBUG: 18:43:00.073: Minutiae scan completed in 0.027412 secs
> (process:15706): libfprint-device-DEBUG: 18:43:00.073: Device reported enroll progress, reported 1 of 5 have been completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.073: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:43:00.073: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.073: Starting image receive (if active), state is: 4
> (process:15706): libfprint-device-DEBUG: 18:43:00.073: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.073: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.073: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.073: Starting image receive (if active), state is: 5
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.073: image data: 0x1b22040
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.074: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.074: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:43:00.074: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.074: Starting image receive (if active), state is: 6
> (process:15706): libfprint-image-DEBUG: 18:43:00.115: Minutiae scan completed in 0.040800 secs
> (process:15706): libfprint-device-DEBUG: 18:43:00.115: Device reported enroll progress, reported 2 of 5 have been completed
> (process:15706): libfprint-device-DEBUG: 18:43:00.115: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.115: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.115: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.115: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:43:00.115: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.115: Starting image receive (if active), state is: 4
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.115: Starting image receive (if active), state is: 4
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.115: image data: 0x1b22040
> (process:15706): libfprint-device-DEBUG: 18:43:00.115: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.115: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.115: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.115: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.115: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:43:00.115: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-device-DEBUG: 18:43:00.115: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.115: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.115: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.115: Starting image receive (if active), state is: 3
> (process:15706): libfprint-image-DEBUG: 18:43:00.146: Minutiae scan completed in 0.030279 secs
> (process:15706): libfprint-device-DEBUG: 18:43:00.146: Device reported enroll progress, reported 3 of 5 have been completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.146: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:43:00.146: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.146: image data: 0x1b22040
> (process:15706): libfprint-device-DEBUG: 18:43:00.146: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.146: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.146: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.146: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.146: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:43:00.146: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-device-DEBUG: 18:43:00.146: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.146: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.146: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.146: Starting image receive (if active), state is: 3
> (process:15706): libfprint-image-DEBUG: 18:43:00.188: Minutiae scan completed in 0.041614 secs
> (process:15706): libfprint-device-DEBUG: 18:43:00.188: Device reported enroll progress, reported 4 of 5 have been completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.188: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:43:00.188: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.188: image data: 0x1b22040
> (process:15706): libfprint-device-DEBUG: 18:43:00.188: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.188: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.188: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.188: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.188: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:43:00.188: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-device-DEBUG: 18:43:00.188: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.188: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.188: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.188: Starting image receive (if active), state is: 3
> (process:15706): libfprint-image-DEBUG: 18:43:00.224: Minutiae scan completed in 0.035379 secs
> (process:15706): libfprint-device-DEBUG: 18:43:00.224: Device reported enroll progress, reported 5 of 5 have been completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.224: Deactivating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.224: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.234: Image device deactivation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.234: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15706): libfprint-device-DEBUG: 18:43:00.234: Device reported enroll completion
> (process:15706): libfprint-device-DEBUG: 18:43:00.234: Print for finger FP_FINGER_LEFT_THUMB enrolled
> (process:15706): libfprint-device-DEBUG: 18:43:00.234: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.234: Activating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.234: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.234: Image device activation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.234: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.234: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:43:00.234: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.234: Starting image receive (if active), state is: 4
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.235: image data: 0x1b22040
> (process:15706): libfprint-device-DEBUG: 18:43:00.235: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.235: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.235: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.235: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.235: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:43:00.235: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-device-DEBUG: 18:43:00.235: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.235: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.235: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.235: Deactivating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.235: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.235: Starting image receive (if active), state is: 2
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.245: Image device deactivation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.245: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15706): libfprint-image-DEBUG: 18:43:00.274: Minutiae scan completed in 0.039398 secs
> (process:15706): libfprint-print-DEBUG: 18:43:00.286: score 10/40
> (process:15706): libfprint-print-DEBUG: 18:43:00.296: score 10/40
> (process:15706): libfprint-print-DEBUG: 18:43:00.305: score 10/40
> (process:15706): libfprint-print-DEBUG: 18:43:00.314: score 10/40
> (process:15706): libfprint-print-DEBUG: 18:43:00.323: score 10/40
> (process:15706): libfprint-print-DEBUG: 18:43:00.659: score 855/40
> (process:15706): libfprint-device-DEBUG: 18:43:00.659: Device reported identify result
> (process:15706): libfprint-device-DEBUG: 18:43:00.659: Device reported identify completion
> (process:15706): libfprint-device-DEBUG: 18:43:00.659: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Activating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device activation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:43:00.660: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.660: Starting image receive (if active), state is: 4
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.660: image data: 0x1ab6030
> (process:15706): libfprint-device-DEBUG: 18:43:00.660: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device reported finger status: on
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device captured an image
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15706): libfprint-device-DEBUG: 18:43:00.660: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15706): libfprint-device-DEBUG: 18:43:00.660: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device reported finger status: off
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Deactivating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.660: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:00.660: Starting image receive (if active), state is: 2
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.670: Image device deactivation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:00.670: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15706): libfprint-image-DEBUG: 18:43:00.704: Minutiae scan completed in 0.044285 secs
> (process:15706): libfprint-print-DEBUG: 18:43:02.085: score 1093/40
> (process:15706): libfprint-device-DEBUG: 18:43:02.085: Device reported identify result
> (process:15706): libfprint-device-DEBUG: 18:43:02.085: Device reported identify completion
> (process:15706): libfprint-device-DEBUG: 18:43:02.085: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.085: Activating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.085: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.085: Image device activation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.085: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.085: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:43:02.085: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:02.085: Starting image receive (if active), state is: 4
> (process:15706): libfprint-device-DEBUG: 18:43:02.086: Device reported identify result
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.086: Deactivating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.086: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:02.086: Starting image receive (if active), state is: 2
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.096: Image device deactivation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.096: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15706): libfprint-device-DEBUG: 18:43:02.096: Device reported identify completion
> (process:15706): libfprint-device-DEBUG: 18:43:02.096: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-device-DEBUG: 18:43:02.096: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.096: Activating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.096: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.096: Image device activation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.096: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.096: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15706): libfprint-device-DEBUG: 18:43:02.096: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:02.096: Starting image receive (if active), state is: 4
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.096: Deactivating image device
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.096: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:02.096: Starting image receive (if active), state is: 2
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.106: Image device deactivation completed
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.106: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15706): libfprint-device-DEBUG: 18:43:02.106: Device reported generic error (An unspecified error occurred!) during action; action was: FPI_DEVICE_ACTION_IDENTIFY
> (process:15706): libfprint-device-DEBUG: 18:43:02.106: Device reported identify completion
> (process:15706): libfprint-device-DEBUG: 18:43:02.106: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15706): libfprint-device-DEBUG: 18:43:02.106: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (process:15706): libfprint-virtual_image-DEBUG: 18:43:02.106: 39115609041: ../libfprint/drivers/virtual-image.c:338
> (process:15706): libfprint-image_device-DEBUG: 18:43:02.207: Image device close completed
> (process:15706): libfprint-device-DEBUG: 18:43:02.207: Device reported close completion
> (process:15706): libfprint-device-DEBUG: 18:43:02.207: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Enroll done
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Enroll done
> Identify finished
> Identify finished
> Identify finished
> fp - device - retry - quark: The swipe was too short, please try again. (1)
> Identify finished
> fp - device - error - quark: An unspecified error occurred! (0)
> ok
>
> ----------------------------------------------------------------------
> Ran 1 test in 2.432s
>
> OK
> -------
>
> 4/16 libfprint:virtual-image+VirtualImage / VirtualImage.test_verify_serialized OK 2.20s
>
> --- command ---
> 18:42:59 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' FP_DRIVERS_WHITELIST='virtual_image' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /usr/bin/python3 /<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/../tests/virtual-image.py VirtualImage.test_verify_serialized
> --- stdout ---
> (process:15707): libfprint-context-DEBUG: 18:42:59.788: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-4h14tdo8/virtual-image.socket
> (process:15707): libfprint-context-DEBUG: 18:42:59.788: created
> test_verify_serialized (__main__.VirtualImage) ... (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.800: 39113303140: ../libfprint/drivers/virtual-image.c:294
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.901: Image device open completed
> (process:15707): libfprint-device-DEBUG: 18:42:59.901: Device reported open completion
> (process:15707): libfprint-device-DEBUG: 18:42:59.901: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.902: Activating image device
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.902: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.903: Image device activation completed
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.903: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.903: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15707): libfprint-device-DEBUG: 18:42:59.903: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.903: Got a new connection!
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.903: Starting image receive (if active), state is: 4
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.903: image data: 0x1e6fa20
> (process:15707): libfprint-device-DEBUG: 18:42:59.903: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.903: Image device reported finger status: on
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.903: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.903: Image device captured an image
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.904: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15707): libfprint-device-DEBUG: 18:42:59.904: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-device-DEBUG: 18:42:59.904: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.904: Image device reported finger status: off
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.904: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.904: Starting image receive (if active), state is: 3
> (process:15707): libfprint-image-DEBUG: 18:42:59.948: Minutiae scan completed in 0.044332 secs
> (process:15707): libfprint-device-DEBUG: 18:42:59.948: Device reported enroll progress, reported 1 of 5 have been completed
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.948: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15707): libfprint-device-DEBUG: 18:42:59.948: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.948: Starting image receive (if active), state is: 4
> (process:15707): libfprint-device-DEBUG: 18:42:59.948: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.948: Image device reported finger status: on
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.948: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.948: Starting image receive (if active), state is: 5
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.948: image data: 0x1e50d10
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.948: Image device captured an image
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.948: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15707): libfprint-device-DEBUG: 18:42:59.948: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.949: Starting image receive (if active), state is: 6
> (process:15707): libfprint-image-DEBUG: 18:42:59.992: Minutiae scan completed in 0.043495 secs
> (process:15707): libfprint-device-DEBUG: 18:42:59.992: Device reported enroll progress, reported 2 of 5 have been completed
> (process:15707): libfprint-device-DEBUG: 18:42:59.992: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.992: Image device reported finger status: off
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.992: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.992: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15707): libfprint-device-DEBUG: 18:42:59.992: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.992: Starting image receive (if active), state is: 4
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.992: Starting image receive (if active), state is: 4
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.992: image data: 0x1e50d10
> (process:15707): libfprint-device-DEBUG: 18:42:59.993: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.993: Image device reported finger status: on
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.993: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.993: Image device captured an image
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.993: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15707): libfprint-device-DEBUG: 18:42:59.993: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-device-DEBUG: 18:42:59.993: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.993: Image device reported finger status: off
> (process:15707): libfprint-image_device-DEBUG: 18:42:59.993: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15707): libfprint-virtual_image-DEBUG: 18:42:59.993: Starting image receive (if active), state is: 3
> (process:15707): libfprint-image-DEBUG: 18:43:00.037: Minutiae scan completed in 0.043957 secs
> (process:15707): libfprint-device-DEBUG: 18:43:00.037: Device reported enroll progress, reported 3 of 5 have been completed
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.037: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15707): libfprint-device-DEBUG: 18:43:00.037: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:00.037: image data: 0x1e5f5a0
> (process:15707): libfprint-device-DEBUG: 18:43:00.037: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.037: Image device reported finger status: on
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.037: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.037: Image device captured an image
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.037: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15707): libfprint-device-DEBUG: 18:43:00.037: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-device-DEBUG: 18:43:00.037: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.037: Image device reported finger status: off
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.037: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:00.037: Starting image receive (if active), state is: 3
> (process:15707): libfprint-image-DEBUG: 18:43:00.081: Minutiae scan completed in 0.043727 secs
> (process:15707): libfprint-device-DEBUG: 18:43:00.081: Device reported enroll progress, reported 4 of 5 have been completed
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.081: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15707): libfprint-device-DEBUG: 18:43:00.081: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:00.081: image data: 0x1e50d10
> (process:15707): libfprint-device-DEBUG: 18:43:00.081: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.081: Image device reported finger status: on
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.081: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.081: Image device captured an image
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.081: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15707): libfprint-device-DEBUG: 18:43:00.081: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-device-DEBUG: 18:43:00.081: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.081: Image device reported finger status: off
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.081: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:00.081: Starting image receive (if active), state is: 3
> (process:15707): libfprint-image-DEBUG: 18:43:00.122: Minutiae scan completed in 0.040427 secs
> (process:15707): libfprint-device-DEBUG: 18:43:00.122: Device reported enroll progress, reported 5 of 5 have been completed
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.122: Deactivating image device
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.122: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.132: Image device deactivation completed
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.132: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15707): libfprint-device-DEBUG: 18:43:00.132: Device reported enroll completion
> (process:15707): libfprint-device-DEBUG: 18:43:00.132: Print for finger FP_FINGER_LEFT_THUMB enrolled
> (process:15707): libfprint-device-DEBUG: 18:43:00.132: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.133: Activating image device
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.133: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.133: Image device activation completed
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.133: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.133: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15707): libfprint-device-DEBUG: 18:43:00.133: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:00.133: Starting image receive (if active), state is: 4
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:00.134: image data: 0x1e5f5a0
> (process:15707): libfprint-device-DEBUG: 18:43:00.134: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.134: Image device reported finger status: on
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.134: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.134: Image device captured an image
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.134: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15707): libfprint-device-DEBUG: 18:43:00.134: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-device-DEBUG: 18:43:00.134: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.134: Image device reported finger status: off
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.134: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.134: Deactivating image device
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.134: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:00.134: Starting image receive (if active), state is: 2
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.144: Image device deactivation completed
> (process:15707): libfprint-image_device-DEBUG: 18:43:00.144: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15707): libfprint-image-DEBUG: 18:43:00.179: Minutiae scan completed in 0.045130 secs
> (process:15707): libfprint-print-DEBUG: 18:43:01.701: score 1093/40
> (process:15707): libfprint-device-DEBUG: 18:43:01.701: Device reported verify result
> (process:15707): libfprint-device-DEBUG: 18:43:01.701: Device reported verify completion
> (process:15707): libfprint-device-DEBUG: 18:43:01.701: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.701: Activating image device
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.701: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.701: Image device activation completed
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.701: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.701: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (process:15707): libfprint-device-DEBUG: 18:43:01.701: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:01.701: Starting image receive (if active), state is: 4
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:01.701: image data: 0x1ebdeb0
> (process:15707): libfprint-device-DEBUG: 18:43:01.701: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.701: Image device reported finger status: on
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.702: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_CAPTURE
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.702: Image device captured an image
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.702: Image device internal state change from FPI_IMAGE_DEVICE_STATE_CAPTURE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF
> (process:15707): libfprint-device-DEBUG: 18:43:01.702: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (process:15707): libfprint-device-DEBUG: 18:43:01.702: Device reported finger status change: FP_FINGER_STATUS_NONE
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.702: Image device reported finger status: off
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.702: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_OFF to FPI_IMAGE_DEVICE_STATE_IDLE
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.702: Deactivating image device
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.702: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:01.702: Starting image receive (if active), state is: 2
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.712: Image device deactivation completed
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.712: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (process:15707): libfprint-image-DEBUG: 18:43:01.724: Minutiae scan completed in 0.022007 secs
> (process:15707): libfprint-print-DEBUG: 18:43:01.730: score 10/40
> (process:15707): libfprint-print-DEBUG: 18:43:01.735: score 10/40
> (process:15707): libfprint-print-DEBUG: 18:43:01.741: score 10/40
> (process:15707): libfprint-print-DEBUG: 18:43:01.747: score 10/40
> (process:15707): libfprint-print-DEBUG: 18:43:01.752: score 10/40
> (process:15707): libfprint-device-DEBUG: 18:43:01.752: Device reported verify result
> (process:15707): libfprint-device-DEBUG: 18:43:01.752: Device reported verify completion
> (process:15707): libfprint-device-DEBUG: 18:43:01.752: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (process:15707): libfprint-virtual_image-DEBUG: 18:43:01.752: 39115255022: ../libfprint/drivers/virtual-image.c:338
> (process:15707): libfprint-image_device-DEBUG: 18:43:01.853: Image device close completed
> (process:15707): libfprint-device-DEBUG: 18:43:01.853: Device reported close completion
> (process:15707): libfprint-device-DEBUG: 18:43:01.853: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Print was processed, continuing
> Enroll done
> ok
>
> ----------------------------------------------------------------------
> Ran 1 test in 2.068s
>
> OK
> -------
>
> 5/16 libfprint:drivers / aes3500 FAIL 0.17s (exit status 1)
>
> --- command ---
> 18:43:00 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' FP_DRIVERS_WHITELIST='aes3500' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /usr/bin/python3 /<<PKGBUILDDIR>>/tests/umockdev-test.py /<<PKGBUILDDIR>>/tests/aes3500
> --- stdout ---
> ** (umockdev-run:15729): DEBUG: 18:43:00.102: umockdev.vala:79: Created udev test bed /tmp/umockdev.6IU6V0
> ** (umockdev-run:15729): DEBUG: 18:43:00.102: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0/usb3/3-1/3-1.1/3-1.1.3
> ** (umockdev-run:15729): DEBUG: 18:43:00.103: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0/usb3/3-1/3-1.1/3-1.1.3 (subsystem usb)
> ** (umockdev-run:15729): DEBUG: 18:43:00.105: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.6IU6V0/dev/bus/usb/003/004
> ** (umockdev-run:15729): DEBUG: 18:43:00.105: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0/usb3/3-1/3-1.1
> ** (umockdev-run:15729): DEBUG: 18:43:00.105: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0/usb3/3-1/3-1.1 (subsystem usb)
> ** (umockdev-run:15729): DEBUG: 18:43:00.107: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.6IU6V0/dev/bus/usb/003/003
> ** (umockdev-run:15729): DEBUG: 18:43:00.107: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0/usb3/3-1
> ** (umockdev-run:15729): DEBUG: 18:43:00.108: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0/usb3/3-1 (subsystem usb)
> ** (umockdev-run:15729): DEBUG: 18:43:00.110: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.6IU6V0/dev/bus/usb/003/002
> ** (umockdev-run:15729): DEBUG: 18:43:00.110: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0/usb3
> ** (umockdev-run:15729): DEBUG: 18:43:00.110: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0/usb3 (subsystem usb)
> ** (umockdev-run:15729): DEBUG: 18:43:00.112: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.6IU6V0/dev/bus/usb/003/001
> ** (umockdev-run:15729): DEBUG: 18:43:00.112: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0
> ** (umockdev-run:15729): DEBUG: 18:43:00.113: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0/0000:39:00.0 (subsystem pci)
> ** (umockdev-run:15729): DEBUG: 18:43:00.114: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0
> ** (umockdev-run:15729): DEBUG: 18:43:00.115: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1c.0/0000:01:00.0/0000:02:02.0 (subsystem pci)
> ** (umockdev-run:15729): DEBUG: 18:43:00.116: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1c.0/0000:01:00.0
> ** (umockdev-run:15729): DEBUG: 18:43:00.117: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1c.0/0000:01:00.0 (subsystem pci)
> ** (umockdev-run:15729): DEBUG: 18:43:00.119: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1c.0
> ** (umockdev-run:15729): DEBUG: 18:43:00.119: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1c.0 (subsystem pci)
> (umockdev-run:15729): GLib-GIO-DEBUG: 18:43:00.121: _g_io_module_get_default: Found default implementation local (GLocalVfs) for ?gio-vfs?
> ** (umockdev-run:15729): DEBUG: 18:43:00.197: umockdev.vala:101: Removing test bed /tmp/umockdev.6IU6V0
> --- stderr ---
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/capture.py", line 19, in <module>
> d = devices[0]
> IndexError: list index out of range
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 94, in <module>
> raise e
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 85, in <module>
> capture()
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 70, in capture
> subprocess.check_call(get_umockdev_runner("capture") +
> File "/usr/lib/python3.9/subprocess.py", line 373, in check_call
> raise CalledProcessError(retcode, cmd)
> subprocess.CalledProcessError: Command '['umockdev-run', '-d', '/<<PKGBUILDDIR>>/tests/aes3500/device', '-i', '/dev/bus/usb/003/004=/<<PKGBUILDDIR>>/tests/aes3500/capture.ioctl', '--', '/usr/bin/python3', '/<<PKGBUILDDIR>>/tests/capture.py', '/tmp/libfprint-umockdev-test-4kcuc5lq/capture.png']' returned non-zero exit status 1.
> -------
>
> 6/16 libfprint:drivers / elan FAIL 0.17s (exit status 1)
>
> --- command ---
> 18:43:00 G_MESSAGES_DEBUG='all' FP_DRIVERS_WHITELIST='elan' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /usr/bin/python3 /<<PKGBUILDDIR>>/tests/umockdev-test.py /<<PKGBUILDDIR>>/tests/elan
> --- stdout ---
> ** (umockdev-run:15735): DEBUG: 18:43:00.270: umockdev.vala:79: Created udev test bed /tmp/umockdev.LAH3V0
> ** (umockdev-run:15735): DEBUG: 18:43:00.270: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:14.0/usb1/1-4/1-4.4
> ** (umockdev-run:15735): DEBUG: 18:43:00.271: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:14.0/usb1/1-4/1-4.4 (subsystem usb)
> ** (umockdev-run:15735): DEBUG: 18:43:00.273: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.LAH3V0/dev/bus/usb/001/094
> ** (umockdev-run:15735): DEBUG: 18:43:00.273: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:14.0/usb1/1-4
> ** (umockdev-run:15735): DEBUG: 18:43:00.273: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:14.0/usb1/1-4 (subsystem usb)
> ** (umockdev-run:15735): DEBUG: 18:43:00.275: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.LAH3V0/dev/bus/usb/001/083
> ** (umockdev-run:15735): DEBUG: 18:43:00.275: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:14.0/usb1
> ** (umockdev-run:15735): DEBUG: 18:43:00.275: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:14.0/usb1 (subsystem usb)
> ** (umockdev-run:15735): DEBUG: 18:43:00.277: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.LAH3V0/dev/bus/usb/001/001
> ** (umockdev-run:15735): DEBUG: 18:43:00.277: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:14.0
> ** (umockdev-run:15735): DEBUG: 18:43:00.277: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:14.0 (subsystem pci)
> (umockdev-run:15735): GLib-GIO-DEBUG: 18:43:00.279: _g_io_module_get_default: Found default implementation local (GLocalVfs) for ?gio-vfs?
> ** (umockdev-run:15735): DEBUG: 18:43:00.351: umockdev.vala:101: Removing test bed /tmp/umockdev.LAH3V0
> --- stderr ---
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/capture.py", line 19, in <module>
> d = devices[0]
> IndexError: list index out of range
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 94, in <module>
> raise e
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 85, in <module>
> capture()
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 70, in capture
> subprocess.check_call(get_umockdev_runner("capture") +
> File "/usr/lib/python3.9/subprocess.py", line 373, in check_call
> raise CalledProcessError(retcode, cmd)
> subprocess.CalledProcessError: Command '['umockdev-run', '-d', '/<<PKGBUILDDIR>>/tests/elan/device', '-i', '/dev/bus/usb/001/094=/<<PKGBUILDDIR>>/tests/elan/capture.ioctl', '--', '/usr/bin/python3', '/<<PKGBUILDDIR>>/tests/capture.py', '/tmp/libfprint-umockdev-test-n4y9kcuc/capture.png']' returned non-zero exit status 1.
> -------
>
> 7/16 libfprint:drivers / synaptics FAIL 0.17s (exit status 1)
>
> --- command ---
> 18:43:00 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' FP_DRIVERS_WHITELIST='synaptics' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /usr/bin/python3 /<<PKGBUILDDIR>>/tests/umockdev-test.py /<<PKGBUILDDIR>>/tests/synaptics
> --- stdout ---
> ** (umockdev-run:15741): DEBUG: 18:43:00.439: umockdev.vala:79: Created udev test bed /tmp/umockdev.F60ZV0
> ** (umockdev-run:15741): DEBUG: 18:43:00.439: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:14.0/usb1/1-1
> ** (umockdev-run:15741): DEBUG: 18:43:00.440: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:14.0/usb1/1-1 (subsystem usb)
> ** (umockdev-run:15741): DEBUG: 18:43:00.442: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.F60ZV0/dev/bus/usb/001/070
> (umockdev-run:15741): GLib-GIO-DEBUG: 18:43:00.442: _g_io_module_get_default: Found default implementation local (GLocalVfs) for ?gio-vfs?
> ** (umockdev-run:15741): DEBUG: 18:43:00.509: umockdev.vala:101: Removing test bed /tmp/umockdev.F60ZV0
> --- stderr ---
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/synaptics/custom.py", line 13, in <module>
> d = devices[0]
> IndexError: list index out of range
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 94, in <module>
> raise e
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 88, in <module>
> custom()
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 80, in custom
> subprocess.check_call(get_umockdev_runner("custom") +
> File "/usr/lib/python3.9/subprocess.py", line 373, in check_call
> raise CalledProcessError(retcode, cmd)
> subprocess.CalledProcessError: Command '['umockdev-run', '-d', '/<<PKGBUILDDIR>>/tests/synaptics/device', '-i', '/dev/bus/usb/001/070=/<<PKGBUILDDIR>>/tests/synaptics/custom.ioctl', '--', '/usr/bin/python3', '/<<PKGBUILDDIR>>/tests/synaptics/custom.py']' returned non-zero exit status 1.
> -------
>
> 8/16 libfprint:drivers / vfs0050 FAIL 0.17s (exit status 1)
>
> --- command ---
> 18:43:00 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' FP_DRIVERS_WHITELIST='vfs0050' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /usr/bin/python3 /<<PKGBUILDDIR>>/tests/umockdev-test.py /<<PKGBUILDDIR>>/tests/vfs0050
> --- stdout ---
> ** (umockdev-run:15747): DEBUG: 18:43:00.607: umockdev.vala:79: Created udev test bed /tmp/umockdev.NV2IW0
> ** (umockdev-run:15747): DEBUG: 18:43:00.607: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:14.0/usb1/1-9
> ** (umockdev-run:15747): DEBUG: 18:43:00.607: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:14.0/usb1/1-9 (subsystem usb)
> ** (umockdev-run:15747): DEBUG: 18:43:00.610: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.NV2IW0/dev/bus/usb/001/004
> (umockdev-run:15747): GLib-GIO-DEBUG: 18:43:00.610: _g_io_module_get_default: Found default implementation local (GLocalVfs) for ?gio-vfs?
> ** (umockdev-run:15747): DEBUG: 18:43:00.697: umockdev.vala:101: Removing test bed /tmp/umockdev.NV2IW0
> --- stderr ---
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/capture.py", line 19, in <module>
> d = devices[0]
> IndexError: list index out of range
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 94, in <module>
> raise e
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 85, in <module>
> capture()
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 70, in capture
> subprocess.check_call(get_umockdev_runner("capture") +
> File "/usr/lib/python3.9/subprocess.py", line 373, in check_call
> raise CalledProcessError(retcode, cmd)
> subprocess.CalledProcessError: Command '['umockdev-run', '-d', '/<<PKGBUILDDIR>>/tests/vfs0050/device', '-i', '/dev/bus/usb/001/004=/<<PKGBUILDDIR>>/tests/vfs0050/capture.ioctl', '--', '/usr/bin/python3', '/<<PKGBUILDDIR>>/tests/capture.py', '/tmp/libfprint-umockdev-test-eflf7179/capture.png']' returned non-zero exit status 1.
> -------
>
> 9/16 libfprint:drivers / vfs301 FAIL 0.17s (exit status 1)
>
> --- command ---
> 18:43:00 G_MESSAGES_DEBUG='all' FP_DRIVERS_WHITELIST='vfs301' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /usr/bin/python3 /<<PKGBUILDDIR>>/tests/umockdev-test.py /<<PKGBUILDDIR>>/tests/vfs301
> --- stdout ---
> ** (umockdev-run:15753): DEBUG: 18:43:00.775: umockdev.vala:79: Created udev test bed /tmp/umockdev.UVOFW0
> ** (umockdev-run:15753): DEBUG: 18:43:00.775: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.3
> ** (umockdev-run:15753): DEBUG: 18:43:00.775: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.3 (subsystem usb)
> ** (umockdev-run:15753): DEBUG: 18:43:00.777: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.UVOFW0/dev/bus/usb/002/005
> ** (umockdev-run:15753): DEBUG: 18:43:00.777: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1d.0/usb2/2-1
> ** (umockdev-run:15753): DEBUG: 18:43:00.778: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1d.0/usb2/2-1 (subsystem usb)
> ** (umockdev-run:15753): DEBUG: 18:43:00.779: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.UVOFW0/dev/bus/usb/002/002
> ** (umockdev-run:15753): DEBUG: 18:43:00.779: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1d.0/usb2
> ** (umockdev-run:15753): DEBUG: 18:43:00.780: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1d.0/usb2 (subsystem usb)
> ** (umockdev-run:15753): DEBUG: 18:43:00.782: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.UVOFW0/dev/bus/usb/002/001
> ** (umockdev-run:15753): DEBUG: 18:43:00.782: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:1d.0
> ** (umockdev-run:15753): DEBUG: 18:43:00.782: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:1d.0 (subsystem pci)
> (umockdev-run:15753): GLib-GIO-DEBUG: 18:43:00.784: _g_io_module_get_default: Found default implementation local (GLocalVfs) for ?gio-vfs?
> ** (umockdev-run:15753): DEBUG: 18:43:00.866: umockdev.vala:101: Removing test bed /tmp/umockdev.UVOFW0
> --- stderr ---
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/capture.py", line 19, in <module>
> d = devices[0]
> IndexError: list index out of range
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 94, in <module>
> raise e
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 85, in <module>
> capture()
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 70, in capture
> subprocess.check_call(get_umockdev_runner("capture") +
> File "/usr/lib/python3.9/subprocess.py", line 373, in check_call
> raise CalledProcessError(retcode, cmd)
> subprocess.CalledProcessError: Command '['umockdev-run', '-d', '/<<PKGBUILDDIR>>/tests/vfs301/device', '-i', '/dev/bus/usb/002/005=/<<PKGBUILDDIR>>/tests/vfs301/capture.ioctl', '--', '/usr/bin/python3', '/<<PKGBUILDDIR>>/tests/capture.py', '/tmp/libfprint-umockdev-test-o6eedg2p/capture.png']' returned non-zero exit status 1.
> -------
>
> 10/16 libfprint:drivers / vfs5011 FAIL 0.17s (exit status 1)
>
> --- command ---
> 18:43:00 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' FP_DRIVERS_WHITELIST='vfs5011' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /usr/bin/python3 /<<PKGBUILDDIR>>/tests/umockdev-test.py /<<PKGBUILDDIR>>/tests/vfs5011
> --- stdout ---
> ** (umockdev-run:15759): DEBUG: 18:43:00.942: umockdev.vala:79: Created udev test bed /tmp/umockdev.U96BW0
> ** (umockdev-run:15759): DEBUG: 18:43:00.942: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:14.0/usb2/2-6
> ** (umockdev-run:15759): DEBUG: 18:43:00.942: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:14.0/usb2/2-6 (subsystem usb)
> ** (umockdev-run:15759): DEBUG: 18:43:00.944: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.U96BW0/dev/bus/usb/002/017
> (umockdev-run:15759): GLib-GIO-DEBUG: 18:43:00.944: _g_io_module_get_default: Found default implementation local (GLocalVfs) for ?gio-vfs?
> ** (umockdev-run:15759): DEBUG: 18:43:01.021: umockdev.vala:101: Removing test bed /tmp/umockdev.U96BW0
> --- stderr ---
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/capture.py", line 19, in <module>
> d = devices[0]
> IndexError: list index out of range
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 94, in <module>
> raise e
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 85, in <module>
> capture()
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 70, in capture
> subprocess.check_call(get_umockdev_runner("capture") +
> File "/usr/lib/python3.9/subprocess.py", line 373, in check_call
> raise CalledProcessError(retcode, cmd)
> subprocess.CalledProcessError: Command '['umockdev-run', '-d', '/<<PKGBUILDDIR>>/tests/vfs5011/device', '-i', '/dev/bus/usb/002/017=/<<PKGBUILDDIR>>/tests/vfs5011/capture.ioctl', '--', '/usr/bin/python3', '/<<PKGBUILDDIR>>/tests/capture.py', '/tmp/libfprint-umockdev-test-1n2vku4j/capture.png']' returned non-zero exit status 1.
> -------
>
> 11/16 libfprint:drivers / goodixmoc FAIL 0.17s (exit status 1)
>
> --- command ---
> 18:43:01 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' FP_DRIVERS_WHITELIST='goodixmoc' /usr/bin/python3 /<<PKGBUILDDIR>>/tests/umockdev-test.py /<<PKGBUILDDIR>>/tests/goodixmoc
> --- stdout ---
> ** (umockdev-run:15765): DEBUG: 18:43:01.112: umockdev.vala:79: Created udev test bed /tmp/umockdev.R836V0
> ** (umockdev-run:15765): DEBUG: 18:43:01.112: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:14.0/usb1/1-8
> ** (umockdev-run:15765): DEBUG: 18:43:01.113: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:14.0/usb1/1-8 (subsystem usb)
> ** (umockdev-run:15765): DEBUG: 18:43:01.115: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.R836V0/dev/bus/usb/001/003
> ** (umockdev-run:15765): DEBUG: 18:43:01.115: umockdev.vala:1116: parsing device description for /devices/pci0000:00/0000:00:14.0/usb1
> ** (umockdev-run:15765): DEBUG: 18:43:01.115: umockdev.vala:1185: creating device /devices/pci0000:00/0000:00:14.0/usb1 (subsystem usb)
> ** (umockdev-run:15765): DEBUG: 18:43:01.117: umockdev.vala:1227: create_node_for_device: creating file device /tmp/umockdev.R836V0/dev/bus/usb/001/001
> (umockdev-run:15765): GLib-GIO-DEBUG: 18:43:01.118: _g_io_module_get_default: Found default implementation local (GLocalVfs) for ?gio-vfs?
> ** (umockdev-run:15765): DEBUG: 18:43:01.185: umockdev.vala:101: Removing test bed /tmp/umockdev.R836V0
> --- stderr ---
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/goodixmoc/custom.py", line 13, in <module>
> d = devices[0]
> IndexError: list index out of range
> Traceback (most recent call last):
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 94, in <module>
> raise e
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 88, in <module>
> custom()
> File "/<<PKGBUILDDIR>>/tests/umockdev-test.py", line 80, in custom
> subprocess.check_call(get_umockdev_runner("custom") +
> File "/usr/lib/python3.9/subprocess.py", line 373, in check_call
> raise CalledProcessError(retcode, cmd)
> subprocess.CalledProcessError: Command '['umockdev-run', '-d', '/<<PKGBUILDDIR>>/tests/goodixmoc/device', '-i', '/dev/bus/usb/001/003=/<<PKGBUILDDIR>>/tests/goodixmoc/custom.ioctl', '--', '/usr/bin/python3', '/<<PKGBUILDDIR>>/tests/goodixmoc/custom.py']' returned non-zero exit status 1.
> -------
>
> 12/16 libfprint:unit-tests / fpi-device OK 0.27s
>
> --- command ---
> 18:43:01 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' FP_DRIVERS_WHITELIST='virtual_image' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /<<PKGBUILDDIR>>/tests/test-runner.sh tests/test-fpi-device
> --- stdout ---
> # random seed: R02Sa7fe5fbbeb8e50e1c4155c1730da3d9a
> 1..72
> # Start of driver tests
> ok 1 /driver/get_driver
> ok 2 /driver/get_device_id
> ok 3 /driver/get_name
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.252: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.252: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.252: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.252: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 4 /driver/is_open
> ok 5 /driver/get_nr_enroll_stages
> ok 6 /driver/set_nr_enroll_stages
> ok 7 /driver/supports_identify
> ok 8 /driver/supports_capture
> ok 9 /driver/has_storage
> ok 10 /driver/do_not_support_identify
> ok 11 /driver/do_not_support_capture
> ok 12 /driver/has_not_storage
> ok 13 /driver/get_usb_device
> ok 14 /driver/get_virtual_env
> ok 15 /driver/get_driver_data
> # libfprint-device-DEBUG: Device reported probe completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.252: Device reported probe completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_PROBE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.252: Completing action FPI_DEVICE_ACTION_PROBE in idle!
> ok 16 /driver/probe
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.252: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.252: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.252: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.252: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 17 /driver/open
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 18 /driver/close
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported enroll completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Device reported enroll completion
> # libfprint-device-DEBUG: Print for finger FP_FINGER_UNKNOWN enrolled
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Print for finger FP_FINGER_UNKNOWN enrolled
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 19 /driver/enroll
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported verify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Device reported verify result
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 20 /driver/verify
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.253: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported identify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.255: Device reported identify result
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.273: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.273: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.273: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.273: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 21 /driver/identify
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.273: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.273: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported capture completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.274: Device reported capture completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CAPTURE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.274: Completing action FPI_DEVICE_ACTION_CAPTURE in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.274: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.274: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 22 /driver/capture
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.274: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.274: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported listing completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.275: Device reported listing completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_LIST in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.275: Completing action FPI_DEVICE_ACTION_LIST in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 23 /driver/list
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported deletion completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Device reported deletion completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 24 /driver/delete
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Idle cancelling on ongoing operation!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.276: Idle cancelling on ongoing operation!
> # libfprint-device-DEBUG: Device reported deletion completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.376: Device reported deletion completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.376: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.376: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.376: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 25 /driver/cancel
> ok 26 /driver/get_current_action
> ok 27 /driver/timeout
> ok 28 /driver/error_types
> ok 29 /driver/retry_error_types
> # Start of get_scan_type tests
> ok 30 /driver/get_scan_type/press
> ok 31 /driver/get_scan_type/swipe
> # End of get_scan_type tests
> # Start of set_scan_type tests
> ok 32 /driver/set_scan_type/press
> ok 33 /driver/set_scan_type/swipe
> # End of set_scan_type tests
> # Start of finger_status tests
> ok 34 /driver/finger_status/inactive
> # libfprint-device-DEBUG: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> ok 35 /driver/finger_status/waiting
> # libfprint-device-DEBUG: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> ok 36 /driver/finger_status/present
> # libfprint-device-DEBUG: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> # libfprint-device-DEBUG: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported finger status change: FP_FINGER_STATUS_NEEDED | FP_FINGER_STATUS_PRESENT
> # libfprint-device-DEBUG: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported finger status change: FP_FINGER_STATUS_PRESENT
> # libfprint-device-DEBUG: Device reported finger status change: FP_FINGER_STATUS_NONE
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported finger status change: FP_FINGER_STATUS_NONE
> ok 37 /driver/finger_status/changes
> # End of finger_status tests
> # Start of probe tests
> # libfprint-device-DEBUG: Device reported probe completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported probe completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_PROBE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Completing action FPI_DEVICE_ACTION_PROBE in idle!
> ok 38 /driver/probe/error
> # libfprint-device-DEBUG: Device reported generic error (The operation is not supported on this device!) during action; action was: FPI_DEVICE_ACTION_PROBE
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported generic error (The operation is not supported on this device!) during action; action was: FPI_DEVICE_ACTION_PROBE
> # libfprint-device-DEBUG: Device reported probe completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported probe completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_PROBE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Completing action FPI_DEVICE_ACTION_PROBE in idle!
> ok 39 /driver/probe/action_error
> # End of probe tests
> # Start of open tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> ok 40 /driver/open/error
> # End of open tests
> # Start of close tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 41 /driver/close/error
> # End of close tests
> # Start of enroll tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.427: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported enroll completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported enroll completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 42 /driver/enroll/error
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported enroll progress, reported 1281421683 of 320072157 have been completed
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported enroll progress, reported 1281421683 of 320072157 have been completed
> # libfprint-device-DEBUG: Device reported enroll progress, reported 2007802948 of 320072157 have been completed
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported enroll progress, reported 2007802948 of 320072157 have been completed
> # libfprint-device-DEBUG: Device reported enroll progress, reported 1116539348 of 320072157 have been completed
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported enroll progress, reported 1116539348 of 320072157 have been completed
> # libfprint-device-DEBUG: Device reported enroll completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported enroll completion
> # libfprint-device-DEBUG: Print for finger FP_FINGER_UNKNOWN enrolled
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Print for finger FP_FINGER_UNKNOWN enrolled
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 43 /driver/enroll/progress
> # Start of error tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported enroll completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported enroll completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> # libfprint-device-DEBUG: Device reported enroll completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported enroll completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> # libfprint-device-DEBUG: Device reported enroll completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported enroll completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 44 /driver/enroll/error/no_print
> # End of error tests
> # End of enroll tests
> # Start of verify tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported verify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported verify result
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 45 /driver/verify/fail
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.428: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported verify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify result
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 46 /driver/verify/retry
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 47 /driver/verify/error
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported verify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify result
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 48 /driver/verify/report_no_cb
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 49 /driver/verify/not_reported
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported verify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify result
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported verify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify result
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported verify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify result
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.429: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported verify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.430: Device reported verify result
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.430: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.430: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported verify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.430: Device reported verify result
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.430: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.430: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.430: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.430: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 50 /driver/verify/complete_retry
> # End of verify tests
> # Start of identify tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.430: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.430: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported identify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.431: Device reported identify result
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.431: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.431: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.432: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.432: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 51 /driver/identify/fail
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.432: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.432: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported identify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.433: Device reported identify result
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.433: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.433: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.434: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.434: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 52 /driver/identify/retry
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.434: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.434: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.436: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.436: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.436: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.436: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 53 /driver/identify/error
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.437: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.438: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.438: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.438: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.438: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.438: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 54 /driver/identify/not_reported
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported identify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported identify result
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported identify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported identify result
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported identify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported identify result
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 55 /driver/identify/complete_retry
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported identify result
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported identify result
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.440: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 56 /driver/identify/report_no_cb
> # End of identify tests
> # Start of capture tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported capture completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported capture completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CAPTURE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_CAPTURE in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 57 /driver/capture/error
> # End of capture tests
> # Start of list tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported listing completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported listing completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_LIST in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_LIST in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 58 /driver/list/error
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 59 /driver/list/no_storage
> # End of list tests
> # Start of delete tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported deletion completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported deletion completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 60 /driver/delete/error
> # End of delete tests
> # Start of cancel tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported deletion completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported deletion completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 61 /driver/cancel/fail
> # End of cancel tests
> # Start of get_current_action tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.441: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 62 /driver/get_current_action/open
> # End of get_current_action tests
> # Start of get_cancellable tests
> ok 63 /driver/get_cancellable/error
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 64 /driver/get_cancellable/open
> # Start of open tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 65 /driver/get_cancellable/open/fail
> # End of open tests
> # End of get_cancellable tests
> # Start of action_is_cancelled tests
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 66 /driver/action_is_cancelled/open
> ok 67 /driver/action_is_cancelled/error
> # End of action_is_cancelled tests
> # Start of complete_action tests
> # Start of all tests
> ok 68 /driver/complete_action/all/error
> # End of all tests
> # End of complete_action tests
> # Start of action_error tests
> ok 69 /driver/action_error/error
> # libfprint-device-DEBUG: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_OPEN
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_OPEN
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_ENROLL
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_ENROLL
> # libfprint-device-DEBUG: Device reported enroll completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported enroll completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> # libfprint-device-DEBUG: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_VERIFY
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_VERIFY
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_IDENTIFY
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_IDENTIFY
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_CAPTURE
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_CAPTURE
> # libfprint-device-DEBUG: Device reported capture completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Device reported capture completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CAPTURE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.442: Completing action FPI_DEVICE_ACTION_CAPTURE in idle!
> # libfprint-device-DEBUG: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_LIST
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_LIST
> # libfprint-device-DEBUG: Device reported listing completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported listing completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_LIST in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_LIST in idle!
> # libfprint-device-DEBUG: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_DELETE
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_DELETE
> # libfprint-device-DEBUG: Device reported deletion completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported deletion completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> # libfprint-device-DEBUG: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_CLOSE
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported generic error (Passed (print) data is not valid.) during action; action was: FPI_DEVICE_ACTION_CLOSE
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 70 /driver/action_error/all
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-device-DEBUG: Device reported enroll completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported enroll completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> # libfprint-device-DEBUG: Device reported verify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported verify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_VERIFY in idle!
> # libfprint-device-DEBUG: Device reported identify completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported identify completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_IDENTIFY in idle!
> # libfprint-device-DEBUG: Device reported capture completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported capture completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CAPTURE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_CAPTURE in idle!
> # libfprint-device-DEBUG: Device reported listing completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported listing completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_LIST in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_LIST in idle!
> # libfprint-device-DEBUG: Device reported deletion completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported deletion completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_DELETE in idle!
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fpi-device:15769): libfprint-device-DEBUG: 18:43:01.443: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> ok 71 /driver/action_error/fail
> # End of action_error tests
> # Start of timeout tests
> ok 72 /driver/timeout/cancelled
> # End of timeout tests
> # End of driver tests
> -------
>
> 13/16 libfprint:unit-tests / fpi-ssm OK 1.07s
>
> --- command ---
> 18:43:01 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' FP_DRIVERS_WHITELIST='virtual_image' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /<<PKGBUILDDIR>>/tests/test-runner.sh tests/test-fpi-ssm
> --- stdout ---
> # random seed: R02Sbfecaed79676ffebb089d432021d9498
> 1..43
> # Start of ssm tests
> ok 1 /ssm/new
> ok 2 /ssm/set_data
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] FPI_TEST_SSM entering state 0
> ok 3 /ssm/start
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] FPI_TEST_SSM entering state 1
> ok 4 /ssm/next
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 2
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] FPI_TEST_SSM entering state 2
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] FPI_TEST_SSM entering state 1
> ok 5 /ssm/jump_to_state
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] FPI_TEST_SSM completed successfully
> ok 6 /ssm/mark_completed
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] SSM FPI_TEST_SSM failed in state 0 with error: The driver encountered a protocol error with the device.
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] SSM FPI_TEST_SSM failed in state 0 with error: The driver encountered a protocol error with the device.
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed with error: The driver encountered a protocol error with the device.
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.517: [fake_test_dev] FPI_TEST_SSM completed with error: The driver encountered a protocol error with the device.
> ok 7 /ssm/mark_failed
> # Start of new tests
> ok 8 /ssm/new/full
> ok 9 /ssm/new/no_handler
> ok 10 /ssm/new/wrong_states
> # End of new tests
> # Start of set_data tests
> ok 11 /ssm/set_data/cleanup
> # End of set_data tests
> # Start of start tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM_SINGLE_STATE entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.518: [fake_test_dev] FPI_TEST_SSM_SINGLE_STATE entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM_SINGLE_STATE completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.518: [fake_test_dev] FPI_TEST_SSM_SINGLE_STATE completed successfully
> ok 12 /ssm/start/single
> # End of start tests
> # Start of next tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.518: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.518: [fake_test_dev] FPI_TEST_SSM entering state 1
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 2
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.518: [fake_test_dev] FPI_TEST_SSM entering state 2
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 3
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.518: [fake_test_dev] FPI_TEST_SSM entering state 3
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.518: [fake_test_dev] FPI_TEST_SSM completed successfully
> ok 13 /ssm/next/complete
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.518: [fake_test_dev] FPI_TEST_SSM entering state 1
> ok 14 /ssm/next/not_started
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.518: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.518: [fake_test_dev] FPI_TEST_SSM entering state 1
> ok 15 /ssm/next/with_delayed
> # End of next tests
> # Start of jump_to_state tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 2
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.618: [fake_test_dev] FPI_TEST_SSM entering state 2
> ok 16 /ssm/jump_to_state/not_started
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.618: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 2
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.618: [fake_test_dev] FPI_TEST_SSM entering state 2
> ok 17 /ssm/jump_to_state/with_delayed
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.718: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 3
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.718: [fake_test_dev] FPI_TEST_SSM entering state 3
> ok 18 /ssm/jump_to_state/last
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.718: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 14
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.718: [fake_test_dev] FPI_TEST_SSM entering state 14
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state -10
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.718: [fake_test_dev] FPI_TEST_SSM entering state -10
> ok 19 /ssm/jump_to_state/wrong
> # End of jump_to_state tests
> # Start of mark_completed tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.719: [fake_test_dev] FPI_TEST_SSM completed successfully
> ok 20 /ssm/mark_completed/not_started
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.719: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.719: [fake_test_dev] FPI_TEST_SSM completed successfully
> ok 21 /ssm/mark_completed/with_delayed
> # End of mark_completed tests
> # Start of mark_failed tests
> # libfprint-SSM-DEBUG: [fake_test_dev] SSM FPI_TEST_SSM failed in state 0 with error: The driver encountered a protocol error with the device.
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.819: [fake_test_dev] SSM FPI_TEST_SSM failed in state 0 with error: The driver encountered a protocol error with the device.
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed with error: The driver encountered a protocol error with the device.
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.819: [fake_test_dev] FPI_TEST_SSM completed with error: The driver encountered a protocol error with the device.
> ok 22 /ssm/mark_failed/not_started
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.819: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] SSM FPI_TEST_SSM failed in state 0 with error: The driver encountered a protocol error with the device.
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.819: [fake_test_dev] SSM FPI_TEST_SSM failed in state 0 with error: The driver encountered a protocol error with the device.
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed with error: The driver encountered a protocol error with the device.
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.819: [fake_test_dev] FPI_TEST_SSM completed with error: The driver encountered a protocol error with the device.
> ok 23 /ssm/mark_failed/with_delayed
> # End of mark_failed tests
> # Start of delayed tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.919: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.929: [fake_test_dev] FPI_TEST_SSM entering state 1
> ok 24 /ssm/delayed/next
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.929: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 2
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.940: [fake_test_dev] FPI_TEST_SSM entering state 2
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.950: [fake_test_dev] FPI_TEST_SSM entering state 1
> ok 25 /ssm/delayed/jump_to_state
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.950: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.960: [fake_test_dev] FPI_TEST_SSM completed successfully
> ok 26 /ssm/delayed/mark_completed
> # Start of next tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.960: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:01.960: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> ok 27 /ssm/delayed/next/cancel
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.060: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.060: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.060: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> ok 28 /ssm/delayed/next/cancellable
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.070: [fake_test_dev] FPI_TEST_SSM entering state 1
> ok 29 /ssm/delayed/next/not_started
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.070: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.081: [fake_test_dev] FPI_TEST_SSM entering state 1
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 2
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.091: [fake_test_dev] FPI_TEST_SSM entering state 2
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 3
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.101: [fake_test_dev] FPI_TEST_SSM entering state 3
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.111: [fake_test_dev] FPI_TEST_SSM completed successfully
> ok 30 /ssm/delayed/next/complete
> # End of next tests
> # Start of jump_to_state tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.111: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.111: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> ok 31 /ssm/delayed/jump_to_state/cancel
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.211: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.211: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.211: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> ok 32 /ssm/delayed/jump_to_state/cancellable
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 2
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.221: [fake_test_dev] FPI_TEST_SSM entering state 2
> ok 33 /ssm/delayed/jump_to_state/not_started
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.222: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 3
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.232: [fake_test_dev] FPI_TEST_SSM entering state 3
> ok 34 /ssm/delayed/jump_to_state/last
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.232: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 14
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.242: [fake_test_dev] FPI_TEST_SSM entering state 14
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state -10
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.252: [fake_test_dev] FPI_TEST_SSM entering state -10
> ok 35 /ssm/delayed/jump_to_state/wrong
> # End of jump_to_state tests
> # Start of mark_completed tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.252: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.252: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> ok 36 /ssm/delayed/mark_completed/cancel
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.352: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.352: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.352: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> ok 37 /ssm/delayed/mark_completed/cancellable
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.362: [fake_test_dev] FPI_TEST_SSM completed successfully
> ok 38 /ssm/delayed/mark_completed/not_started
> # End of mark_completed tests
> # Start of cancel tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.452: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SSM cancelled delayed state change
> ok 39 /ssm/delayed/cancel/error
> # End of cancel tests
> # End of delayed tests
> # Start of subssm tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SUB_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SUB_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SUB_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SUB_SSM entering state 1
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SUB_SSM completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SUB_SSM completed successfully
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SSM entering state 1
> ok 40 /ssm/subssm/start
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SUB_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SUB_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] SSM FPI_TEST_SUB_SSM failed in state 0 with error: The device is still busy with another operation, please try again later.
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] SSM FPI_TEST_SUB_SSM failed in state 0 with error: The device is still busy with another operation, please try again later.
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SUB_SSM completed with error: The device is still busy with another operation, please try again later.
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SUB_SSM completed with error: The device is still busy with another operation, please try again later.
> # libfprint-SSM-DEBUG: [fake_test_dev] SSM FPI_TEST_SSM failed in state 0 with error: The device is still busy with another operation, please try again later.
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] SSM FPI_TEST_SSM failed in state 0 with error: The device is still busy with another operation, please try again later.
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM completed with error: The device is still busy with another operation, please try again later.
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SSM completed with error: The device is still busy with another operation, please try again later.
> ok 41 /ssm/subssm/mark_failed
> # Start of start tests
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SUB_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SUB_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SUB_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SUB_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SUB_SSM completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SUB_SSM completed successfully
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SSM entering state 1
> ok 42 /ssm/subssm/start/with_started
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SUB_SSM entering state 0
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.453: [fake_test_dev] FPI_TEST_SUB_SSM entering state 0
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SUB_SSM completed successfully
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.553: [fake_test_dev] FPI_TEST_SUB_SSM completed successfully
> # libfprint-SSM-DEBUG: [fake_test_dev] FPI_TEST_SSM entering state 1
> (tests/test-fpi-ssm:15771): libfprint-SSM-DEBUG: 18:43:02.553: [fake_test_dev] FPI_TEST_SSM entering state 1
> ok 43 /ssm/subssm/start/with_delayed
> # End of start tests
> # End of subssm tests
> # End of ssm tests
> -------
>
> 14/16 libfprint:unit-tests / fpi-assembling OK 0.37s
>
> --- command ---
> 18:43:01 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' FP_DRIVERS_WHITELIST='virtual_image' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /<<PKGBUILDDIR>>/tests/test-runner.sh tests/test-fpi-assembling
> --- stdout ---
> # random seed: R02Sbb1023e947e7eb30ba26d44ca015c27b
> 1..1
> # Start of assembling tests
> # libfprint-assembling-DEBUG: calc delta completed in 0.136262 secs
> (tests/test-fpi-assembling:15772): libfprint-assembling-DEBUG: 18:43:01.818: calc delta completed in 0.136262 secs
> # libfprint-assembling-DEBUG: calc delta completed in 0.095786 secs
> (tests/test-fpi-assembling:15772): libfprint-assembling-DEBUG: 18:43:01.914: calc delta completed in 0.095786 secs
> # libfprint-assembling-DEBUG: errors: 0 rev: 130848
> (tests/test-fpi-assembling:15772): libfprint-assembling-DEBUG: 18:43:01.914: errors: 0 rev: 130848
> # libfprint-assembling-DEBUG: calc delta completed in 0.091912 secs
> (tests/test-fpi-assembling:15772): libfprint-assembling-DEBUG: 18:43:02.006: calc delta completed in 0.091912 secs
> # libfprint-assembling-DEBUG: height is 310
> (tests/test-fpi-assembling:15772): libfprint-assembling-DEBUG: 18:43:02.006: height is 310
> ok 1 /assembling/frames
> # End of assembling tests
> -------
>
> 15/16 libfprint:unit-tests / fp-context OK 0.87s
>
> --- command ---
> 18:43:01 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' FP_DRIVERS_WHITELIST='virtual_image' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /<<PKGBUILDDIR>>/tests/test-runner.sh tests/test-fp-context
> --- stdout ---
> # random seed: R02Sc560bcf9eda55189bfc65ec4f1db4403
> 1..9
> # Start of context tests
> ok 1 /context/new
> ok 2 /context/no-devices
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:01.895: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-1ENCW0/virtual-image.socket
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:01.895: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-1ENCW0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:01.896: created
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:01.896: unsetenv() is not thread-safe and should not be used after threads are created
> ok 3 /context/has-virtual-device
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:01.896: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-2UMCW0/virtual-image.socket
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:01.896: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-2UMCW0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:01.896: created
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:01.896: unsetenv() is not thread-safe and should not be used after threads are created
> ok 4 /context/enumerates-new-devices
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:01.896: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-V1MCW0/virtual-image.socket
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:01.897: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-V1MCW0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:01.897: created
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:01.897: unsetenv() is not thread-safe and should not be used after threads are created
> ok 5 /context/remove-device-closed
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:01.897: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-72OCW0/virtual-image.socket
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:01.897: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-72OCW0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:01.897: created
> (tests/test-fp-context:15773): libfprint-virtual_image-DEBUG: 18:43:01.897: 39115399904: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:01.998: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:01.998: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:01.998: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-context:15773): libfprint-virtual_image-DEBUG: 18:43:01.998: 39115500419: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.098: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.098: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.098: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:02.098: unsetenv() is not thread-safe and should not be used after threads are created
> ok 6 /context/remove-device-closing
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:02.098: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-8ET6V0/virtual-image.socket
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:02.099: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-8ET6V0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:02.099: created
> (tests/test-fp-context:15773): libfprint-virtual_image-DEBUG: 18:43:02.099: 39115601388: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.199: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.199: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.199: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-context:15773): libfprint-virtual_image-DEBUG: 18:43:02.199: 39115701694: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.299: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.299: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.299: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:02.299: unsetenv() is not thread-safe and should not be used after threads are created
> ok 7 /context/remove-device-open
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:02.300: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-LQN2V0/virtual-image.socket
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:02.300: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-LQN2V0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:02.300: created
> (tests/test-fp-context:15773): libfprint-virtual_image-DEBUG: 18:43:02.300: 39115802638: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.400: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.400: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.400: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-context:15773): libfprint-virtual_image-DEBUG: 18:43:02.400: 39115902987: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.501: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.501: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.501: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:02.501: unsetenv() is not thread-safe and should not be used after threads are created
> ok 8 /context/remove-device-opening
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:02.501: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-3MJYV0/virtual-image.socket
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:02.501: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-3MJYV0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-context:15773): libfprint-context-DEBUG: 18:43:02.501: created
> (tests/test-fp-context:15773): libfprint-virtual_image-DEBUG: 18:43:02.501: 39116003926: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.601: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.602: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.602: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> # libfprint-image_device-DEBUG: Activating image device
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.602: Activating image device
> # libfprint-image_device-DEBUG: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.602: Image device internal state change from FPI_IMAGE_DEVICE_STATE_INACTIVE to FPI_IMAGE_DEVICE_STATE_ACTIVATING
> # libfprint-image_device-DEBUG: Image device activation completed
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.602: Image device activation completed
> # libfprint-image_device-DEBUG: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.602: Image device internal state change from FPI_IMAGE_DEVICE_STATE_ACTIVATING to FPI_IMAGE_DEVICE_STATE_IDLE
> # libfprint-image_device-DEBUG: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.602: Image device internal state change from FPI_IMAGE_DEVICE_STATE_IDLE to FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON
> # libfprint-device-DEBUG: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.602: Device reported finger status change: FP_FINGER_STATUS_NEEDED
> # libfprint-image_device-DEBUG: Deactivating image device
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.602: Deactivating image device
> # libfprint-image_device-DEBUG: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.602: Image device internal state change from FPI_IMAGE_DEVICE_STATE_AWAIT_FINGER_ON to FPI_IMAGE_DEVICE_STATE_DEACTIVATING
> # libfprint-image_device-DEBUG: Image device deactivation completed
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.612: Image device deactivation completed
> # libfprint-image_device-DEBUG: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.612: Image device internal state change from FPI_IMAGE_DEVICE_STATE_DEACTIVATING to FPI_IMAGE_DEVICE_STATE_INACTIVE
> # libfprint-device-DEBUG: Device reported generic error (The driver encountered a protocol error with the device.) during action; action was: FPI_DEVICE_ACTION_ENROLL
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.612: Device reported generic error (The driver encountered a protocol error with the device.) during action; action was: FPI_DEVICE_ACTION_ENROLL
> # libfprint-device-DEBUG: Device reported enroll completion
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.612: Device reported enroll completion
> # libfprint-device-DEBUG: Device reported finger status change: FP_FINGER_STATUS_NONE
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.612: Device reported finger status change: FP_FINGER_STATUS_NONE
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.612: Completing action FPI_DEVICE_ACTION_ENROLL in idle!
> (tests/test-fp-context:15773): libfprint-virtual_image-DEBUG: 18:43:02.612: 39116114679: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-context:15773): libfprint-image_device-DEBUG: 18:43:02.712: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.712: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-context:15773): libfprint-device-DEBUG: 18:43:02.712: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-context:15773): GLib-DEBUG: 18:43:02.712: unsetenv() is not thread-safe and should not be used after threads are created
> ok 9 /context/remove-device-active
> # End of context tests
> -------
>
> 16/16 libfprint:unit-tests / fp-device OK 3.07s
>
> --- command ---
> 18:43:02 G_MESSAGES_DEBUG='all' GI_TYPELIB_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' LD_LIBRARY_PATH='/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/libfprint' NO_AT_BRIDGE='1' G_DEBUG='fatal-warnings' FP_DEVICE_EMULATION='1' FP_DRIVERS_WHITELIST='virtual_image' MESON_SOURCE_ROOT='/<<PKGBUILDDIR>>' /<<PKGBUILDDIR>>/tests/test-runner.sh tests/test-fp-device
> --- stdout ---
> # random seed: R02Sb390a502efbf50bf48c08cb5827838dd
> 1..15
> # Start of device tests
> # Start of async tests
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-GCF8V0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:02.045: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-GCF8V0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:02.045: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:02.045: 39115547855: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:02.146: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.146: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.146: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:02.146: 39115648267: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:02.246: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.246: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.246: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:02.246: unsetenv() is not thread-safe and should not be used after threads are created
> ok 1 /device/async/open
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:02.246: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-F8C4V0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:02.247: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-F8C4V0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:02.247: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:02.247: 39115749222: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:02.347: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.347: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.347: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:02.347: 39115849524: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:02.447: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.447: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.447: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:02.447: unsetenv() is not thread-safe and should not be used after threads are created
> ok 2 /device/async/close
> # End of async tests
> # Start of sync tests
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:02.447: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-7G7ZV0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:02.448: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-7G7ZV0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:02.448: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:02.448: 39115950448: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:02.548: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.548: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.548: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:02.548: 39116050743: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:02.648: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.648: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.648: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:02.648: unsetenv() is not thread-safe and should not be used after threads are created
> ok 3 /device/sync/open
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:02.649: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-IFKIW0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:02.649: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-IFKIW0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:02.649: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:02.649: 39116151685: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:02.749: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.749: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.749: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:02.749: 39116251960: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:02.850: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.850: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.850: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:02.850: unsetenv() is not thread-safe and should not be used after threads are created
> ok 4 /device/sync/close
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:02.850: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-JUHEW0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:02.850: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-JUHEW0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:02.850: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:02.850: 39116352880: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:02.950: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.950: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:02.950: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:02.951: 39116453158: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:03.051: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.051: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.051: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:03.051: unsetenv() is not thread-safe and should not be used after threads are created
> ok 5 /device/sync/get_driver
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:03.051: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-TZL8V0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:03.051: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-TZL8V0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:03.051: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:03.051: 39116554019: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:03.152: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.152: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.152: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:03.152: 39116654294: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:03.252: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.252: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.252: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:03.252: unsetenv() is not thread-safe and should not be used after threads are created
> ok 6 /device/sync/get_device_id
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:03.252: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-ITH4V0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:03.252: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-ITH4V0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:03.252: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:03.253: 39116755156: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:03.353: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.353: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.353: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:03.353: 39116855435: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:03.453: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.453: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.453: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:03.453: unsetenv() is not thread-safe and should not be used after threads are created
> ok 7 /device/sync/get_name
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:03.453: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-P1B0V0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:03.454: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-P1B0V0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:03.454: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:03.454: 39116956287: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:03.554: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.554: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.554: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:03.554: 39117056567: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:03.654: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.654: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.654: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:03.654: unsetenv() is not thread-safe and should not be used after threads are created
> ok 8 /device/sync/get_scan_type
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:03.654: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-4XOIW0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:03.655: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-4XOIW0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:03.655: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:03.655: 39117157426: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:03.755: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.755: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.755: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:03.755: 39117257694: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:03.855: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.855: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.855: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:03.855: unsetenv() is not thread-safe and should not be used after threads are created
> ok 9 /device/sync/get_finger_status
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:03.856: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-735CW0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:03.856: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-735CW0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:03.856: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:03.856: 39117358561: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:03.956: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.956: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:03.956: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:03.956: 39117458851: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:04.056: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.056: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.056: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:04.057: unsetenv() is not thread-safe and should not be used after threads are created
> ok 10 /device/sync/get_nr_enroll_stages
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:04.057: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-HWO8V0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:04.057: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-HWO8V0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:04.057: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:04.057: 39117559756: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:04.157: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.157: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.157: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:04.157: 39117660030: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:04.258: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.258: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.258: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:04.258: unsetenv() is not thread-safe and should not be used after threads are created
> ok 11 /device/sync/supports_identify
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:04.258: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-26L4V0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:04.258: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-26L4V0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:04.258: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:04.258: 39117760873: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:04.358: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.358: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.358: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:04.358: 39117861142: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:04.459: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.459: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.459: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:04.459: unsetenv() is not thread-safe and should not be used after threads are created
> ok 12 /device/sync/supports_capture
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:04.459: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-GG3YV0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:04.459: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-GG3YV0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:04.459: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:04.459: 39117962000: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:04.560: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.560: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.560: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:04.560: 39118062267: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:04.660: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.660: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.660: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:04.660: unsetenv() is not thread-safe and should not be used after threads are created
> ok 13 /device/sync/has_storage
> # Start of open tests
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:04.660: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-ZOEHW0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:04.660: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-ZOEHW0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:04.660: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:04.660: 39118163115: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:04.761: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.761: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.761: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:04.761: 39118263397: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:04.861: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.861: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.861: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:04.861: unsetenv() is not thread-safe and should not be used after threads are created
> ok 14 /device/sync/open/notify
> # End of open tests
> # Start of close tests
> # GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:04.861: setenv()/putenv() are not thread-safe and should not be used after threads are created
> # libfprint-context-DEBUG: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-CIADW0/virtual-image.socket
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:04.862: Found virtual environment device: FP_VIRTUAL_IMAGE, /tmp/libfprint-CIADW0/virtual-image.socket
> # libfprint-context-DEBUG: created
> (tests/test-fp-device:15787): libfprint-context-DEBUG: 18:43:04.862: created
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:04.862: 39118364248: ../libfprint/drivers/virtual-image.c:294
> # libfprint-image_device-DEBUG: Image device open completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:04.962: Image device open completed
> # libfprint-device-DEBUG: Device reported open completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.962: Device reported open completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:04.962: Completing action FPI_DEVICE_ACTION_OPEN in idle!
> (tests/test-fp-device:15787): libfprint-virtual_image-DEBUG: 18:43:04.962: 39118464514: ../libfprint/drivers/virtual-image.c:338
> # libfprint-image_device-DEBUG: Image device close completed
> (tests/test-fp-device:15787): libfprint-image_device-DEBUG: 18:43:05.062: Image device close completed
> # libfprint-device-DEBUG: Device reported close completion
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:05.062: Device reported close completion
> # libfprint-device-DEBUG: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> (tests/test-fp-device:15787): libfprint-device-DEBUG: 18:43:05.062: Completing action FPI_DEVICE_ACTION_CLOSE in idle!
> # GLib-DEBUG: unsetenv() is not thread-safe and should not be used after threads are created
> (tests/test-fp-device:15787): GLib-DEBUG: 18:43:05.062: unsetenv() is not thread-safe and should not be used after threads are created
> ok 15 /device/sync/close/notify
> # End of close tests
> # End of sync tests
> # End of device tests
> -------
>
>
> Summary of Failures:
>
> 5/16 libfprint:drivers / aes3500 FAIL 0.17s (exit status 1)
> 6/16 libfprint:drivers / elan FAIL 0.17s (exit status 1)
> 7/16 libfprint:drivers / synaptics FAIL 0.17s (exit status 1)
> 8/16 libfprint:drivers / vfs0050 FAIL 0.17s (exit status 1)
> 9/16 libfprint:drivers / vfs301 FAIL 0.17s (exit status 1)
> 10/16 libfprint:drivers / vfs5011 FAIL 0.17s (exit status 1)
> 11/16 libfprint:drivers / goodixmoc FAIL 0.17s (exit status 1)
>
> Ok: 9
> Expected Fail: 0
> Fail: 7
> Unexpected Pass: 0
> Skipped: 0
> Timeout: 0
> dh_auto_test: error: cd obj-x86_64-linux-gnu && LC_ALL=C.UTF-8 MESON_TESTTHREADS=4 meson test -C /<<PKGBUILDDIR>>/obj-x86_64-linux-gnu --timeout-multiplier 5 returned exit code 7
The full build log is available from:
http://qa-logs.debian.net/2020/12/26/libfprint_1.90.6-2_unstable.log
A list of current common problems and possible solutions is available at
http://wiki.debian.org/qa.debian.org/FTBFS . You're welcome to contribute!
If you reassign this bug to another package, please marking it as 'affects'-ing
this package. See https://www.debian.org/Bugs/server-control#affects
If you fail to reproduce this, please provide a build log and diff it with me
so that we can identify if something relevant changed in the meantime.
About the archive rebuild: The rebuild was done on EC2 VM instances from
Amazon Web Services, using a clean, minimal and up-to-date chroot. Every
failed build was retried once to eliminate random failures.
More information about the Fingerforce-devel
mailing list