Fingerprint service fails to load on XZ3

[rinigus]

XZ3 (Akatsuki) users have issues with AOSP FPC HAL with

06-09 21:14:49.056  3801  3801 D QSEECOMAPI: Loaded image: APP id = 3
06-09 21:14:49.056  3801  3801 I QSEE_WRAPPER: TZ App loaded: fpctzfingerprint
06-09 21:14:49.059  3801  3801 I FPC IMP : Keymaster Response Code : 4294967272
06-09 21:14:49.059  3801  3801 I FPC IMP : Keymaster Response Length : 0
06-09 21:14:49.059  3801  3801 I FPC IMP : Keymaster Response Offset: 0
06-09 21:14:49.059  3801  3801 D QSEECOMAPI: QSEECom_dealloc_memory 
06-09 21:14:49.059  3801  3801 D QSEECOMAPI: QSEECom_shutdown_app, app_id = 1
06-09 21:14:49.059  3801  3801 E ion     : ioctl c0044901 failed with code -1: Invalid argument
06-09 21:14:49.062  3801  3801 D FPC IMP : FPC_SET_KEY_DATA Result: -6
06-09 21:14:49.062  4398  4586 W SDM     : HWCSession::UEventThread: UEvent dropped. No uevent listener.
06-09 21:14:49.062  3801  3801 F AOSP FPC HAL (Binder): Could not init FPC device

Looks like something is wrong with the keymaster response code (on akari its 0). Corresponding XZ3 crash report

06-09 21:14:49.165  4637  4637 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
06-09 21:14:49.166  4637  4637 F DEBUG   : Build fingerprint: 'Sony/aosp_h8416/akatsuki:9/PQ3A.190801.002/mer12012159:user/test-keys'
06-09 21:14:49.166  4637  4637 F DEBUG   : Revision: '0'
06-09 21:14:49.166  4637  4637 F DEBUG   : ABI: 'arm64'
06-09 21:14:49.166  4637  4637 F DEBUG   : pid: 3801, tid: 3801, name: android.hardwar  >>> /vendor/bin/hw/android.hardware.biometrics.fingerprint@2.1-service.sony-updated <<<
06-09 21:14:49.166  4637  4637 F DEBUG   : signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------
06-09 21:14:49.166  4637  4637 F DEBUG   : Abort message: 'Could not init FPC device'
06-09 21:14:49.166  4637  4637 F DEBUG   :     x0  0000000000000000  x1  0000000000000ed9  x2  0000000000000006  x3  0000000000000008
06-09 21:14:49.166  4637  4637 F DEBUG   :     x4  fefeff7d13672717  x5  fefeff7d13672717  x6  fefeff7d13672717  x7  7f7f7f7f7f7f7f7f
06-09 21:14:49.166  4637  4637 F DEBUG   :     x8  0000000000000083  x9  0000007e146ba420  x10 fffffff87fffffdf  x11 0000000000000001
06-09 21:14:49.166  4637  4637 F DEBUG   :     x12 0000007fc0826500  x13 ffffffffffffffff  x14 ffffffffff000000  x15 ffffffffffffffff
06-09 21:14:49.166  4637  4637 F DEBUG   :     x16 0000007e146f32c8  x17 0000007e14631450  x18 0000007fc0825cea  x19 0000000000000ed9
06-09 21:14:49.166  4637  4637 F DEBUG   :     x20 0000000000000ed9  x21 0000000000000083  x22 0000007e13c410d8  x23 0000007e13c41000
06-09 21:14:49.166  4637  4637 F DEBUG   :     x24 0000007e14b335e0  x25 0000000000000000  x26 0000000000000000  x27 0000000000000000
06-09 21:14:49.166  4637  4637 F DEBUG   :     x28 0000000000000000  x29 0000007fc0826420
06-09 21:14:49.166  4637  4637 F DEBUG   :     sp  0000007fc08263e0  lr  0000007e14625cf0  pc  0000007e14625d1c
06-09 21:14:49.169  4637  4637 F DEBUG   : 
06-09 21:14:49.169  4637  4637 F DEBUG   : backtrace:
06-09 21:14:49.169  4637  4637 F DEBUG   :     #00 pc 0000000000021d1c  /system/lib64/libc.so (abort+124)
06-09 21:14:49.169  4637  4637 F DEBUG   :     #01 pc 00000000000080f0  /system/lib64/liblog.so (__android_log_assert+296)
06-09 21:14:49.169  4637  4637 F DEBUG   :     #02 pc 0000000000004488  /vendor/bin/hw/android.hardware.biometrics.fingerprint@2.1-service.sony-updated (fpc::BiometricsFingerprint::BiometricsFingerprint()+288)
06-09 21:14:49.169  4637  4637 F DEBUG   :     #03 pc 0000000000007844  /vendor/bin/hw/android.hardware.biometrics.fingerprint@2.1-service.sony-updated (main+52)
06-09 21:14:49.169  4637  4637 F DEBUG   :     #04 pc 00000000000ae208  /system/lib64/libc.so (__libc_init+88)

Here, -updated version corresponds to the current master of https://github.com/sonyxperiadev/vendor-sony-oss-fingerprint/; same response from the earlier AOSP9 version as well.

@MarijnS95, any ideas?

[MarijnS95]

https://github.com/sonyxperiadev/vendor-sony-oss-fingerprint/commit/f1eb1938c421e543764691352d5e7cfc708c2ca2

I wouldn't be surprised if this is related, and/or https://github.com/sonyxperiadev/device-sony-common/pull/743 + https://github.com/sonyxperiadev/device-sony-tama/pull/87

Unfortunately your log omits "vital" lines before it from the keymaster tzapp load

[rinigus]

Thanks for help and very fast response! As I am not sure what info is required, I have sent the log by email. Hopefully, it will get through.

[rinigus]

Note that the code used here is from https://github.com/sailfishos-sony-tama/vendor-sony-oss-fingerprint/commits/dtap, which has your patch incorporated. However, failure has been reported with the version that I distributed originally as well (https://github.com/sonyxperiadev/vendor-sony-oss-fingerprint/tree/ab0d04393c95bb1436f61a65b5a8f9829bd5ad68). Although, I don't have the full log for the latter one, but can ask for it.

[MarijnS95]

I am merely looking for preceding log lines from the same process/pid, containing keymaster start:

06-09 21:14:48.110  3801  3801 I FPC IMP : Starting app keymaster64
06-09 21:14:48.110  3801  3801 I QSEE_WRAPPER: Starting app keymaster64
06-09 21:14:48.110  3801  3801 D QSEECOMAPI: QSEECom_get_handle sb_length = 0x400
06-09 21:14:48.110  3801  3801 D QSEECOMAPI: App is already loaded QSEE and app id = 1
06-09 21:14:48.110  3801  3801 I QSEE_WRAPPER: TZ App loaded: keymaster64
06-09 21:14:48.110  3801  3801 I FPC IMP : Starting app fpctzfingerprint
06-09 21:14:48.110  3801  3801 D QSEE_WRAPPER: Warning: sb_size too small, increasing to avoid breakage
06-09 21:14:48.110  3801  3801 I QSEE_WRAPPER: Starting app fpctzfingerprint
06-09 21:14:48.110  3801  3801 D QSEECOMAPI: QSEECom_get_handle sb_length = 0x400
06-09 21:14:48.110  3801  3801 D QSEECOMAPI: App is not loaded in QSEE
06-09 21:14:48.121  3801  3801 D QSEECOMAPI: app_arch = 1, total_files = 9

These look just fine. There is a vague memory of a similar issue where an app seems to load fine but immediately errors out, as it hasn't loaded at all. But the fact that these users can decrypt and use their device indicates keymaster + QSEE operate as normal.

Let's try to pin this issue down to something more specific:

• When did this start happening?
• Do your SFOS builds include anything related to the /firmware link changes from me two weeks ago?
• What firmware revisions are known working? Perhaps it's an Android-10 base incompatibility issue.

[rinigus]

To my knowledge, XZ2 works; XZ2c works; XZ3 fails.

When: I happened to have a log from a user from the original version as well - it fails the same way. Sending it to you by email. So, on XZ3, as we had no fingerprint support before, we did not notice it was crashing from the beginning.

SFOS port is using android-9.0.0_r46 as a base. That's where XZ3 users complained regarding broken FPC. One of the users was asked to use recent https://github.com/sailfishos-sony-tama/vendor-sony-oss-fingerprint/commits/dtap version. That's the version I am using on Akari with your delete-all fix and I am testing double-tap-to-wake patch that I wrote for it. This version has your changes in /firmware related to FPC. Note that, in Akari, I have had original android-9.0.0_r46 and the latest FPC version working fine.

In addition, SFOS base is still android-9.0.0_r46, even with the newer vendor-sony-oss-fingerprint.

/firmware: no, nothing is included. unless user, as in this case, used https://github.com/sailfishos-sony-tama/vendor-sony-oss-fingerprint/commits/dtap. But that's all which has something from recent times.

revisions working: android-9.0.0_r46 XZ2, XZ2c; not working XZ3

[MarijnS95]

I have no explanation as to why FPC doesn't work at all on the XZ3, it's the first thing I invested time in since getting the device :)

In any case our HAL is masking the issue by passing a needlessly empty key to the FPC tzapp, the actual culprit is Keymaster itself failing with -24 (4294967272):

hardware/libhardware/include/hardware/keymaster_defs.h
418:    KM_ERROR_KEY_NOT_YET_VALID = -24,

I have yet to fully understand how this "key" pulled out of KM is associated to our application, and what it actually means. Assuming the KM TZ returns the same error codes as the userspace libhardware module, there's a mismatch in time: this key is not yet allowed to be used. Why, I have no idea yet :| Is this reproducible on all XZ3s running SFOS?

[rinigus]

Currently, I have 2 users confirming the same on XZ3. It may well be 100% of SFOS-XZ3 users, no idea on how many have this device :)

It is possible that some service is not started on SFOS which starts on AOSP as well as something in the order of the start. I wonder if you have some logcat from AOSP9 days to compare with...

[kholk]

Perhaps that may be valuable info for you... Akari and Apollo use keymaster 3.... Akatsuki uses keymaster 4.

Translated: are you starting km3 or km4 service?

[MarijnS95]

@kholk Thanks, one would almost forget...

12-07 15:33:54.165  3309  3309 I ServiceManagement: Removing namespace from process name android.hardware.keymaster@4.0-service-qti to keymaster@4.0-service-qti.

Checked that one already :wink:

But yes, it is likely handled in a different way (inside SFOS) as it is completely fine on AOSP. Again, I don't exactly know what kind of key the FPC HAL requests here, who "put it there" or granted this access etc etc... Will have to dive into the KM API for that.

[rinigus]

@kholk and @MarijnS95, thank you, that could be the key. We had few issues with km4 devices and there is a workaround for them. I will ask users to test and then report back.

[rinigus]

@kholk and @MarijnS95: Issue was fixed by starting https://github.com/erfanoabdi/fake_crypt on boot. XZ3 user has reported FP working now.

I will have to polish a bit few things and will close it when all is ready.

[kholk]

AHA! YAY! I knew it was km4. We had the same issues on android when we were early porting this device :D

I'm happy it worked on sfos too :D

[rinigus]

Fixed now, thanks again! :)