[maple] keymaster related boot failure after OTA from 8.1.0_r26 to 8.1.0_r46

[jamuir]

Platform: yoshino Device: maple Kernel version: 4.4 (prebuilt) Android version: 8.1.0_r26 / 8.1.0_r46

Description I built and flashed a maple image from the Sony 8.1.0_r26 tree. Then I built an ota image from the Sony 8.1.0_r46 tree and applied it using recovery. The recovery log indicates that the ota update completed successfully, but, after rebooting, the android ui does not come up (it boot-loops while displaying the "android" splash screen).

Logcat seems to indicate that this is due to an FBE related failure. Note the messages from "KeyMasterHalDevice" (see below).

I did not encounter this problem with OTA upgrades that stayed on 8.1.0_r26.

--------- beginning of main
06-19 03:13:51.299 W/auditd  (  573): type=2000 audit(0.0:1): initialized
06-19 03:13:53.212 I/auditd  (  573): type=1403 audit(0.0:2): policy loaded auid=4294967295 ses=4294967295
06-19 03:13:53.212 W/auditd  (  573): type=1404 audit(0.0:3): enforcing=1 old_enforcing=0 auid=4294967295 ses=4294967295
06-19 03:13:53.586 I/SELinux (  574): SELinux: Loaded service_contexts from:
06-19 03:13:53.588 I/SELinux (  575): SELinux: Loaded service_contexts from:
06-19 03:13:53.588 I/SELinux (  574):     /plat_service_contexts
06-19 03:13:53.589 I/SELinux (  574):     /nonplat_service_contexts
06-19 03:13:53.589 I/SELinux (  575):     /vndservice_contexts
06-19 03:13:53.601 D/vndksupport(  576): Loading /odm/lib64/hw/android.hardware.gatekeeper@1.0-impl-qti.so from current namespace instead of sphal namespace.
06-19 03:13:53.606 D/vndksupport(  577): Loading /odm/lib64/hw/android.hardware.keymaster@3.0-impl-qti.so from current namespace instead of sphal namespace.
06-19 03:13:53.607 D/QSEECOMAPI(  576): QSEECom_get_handle sb_length = 0xa000
06-19 03:13:53.608 D/QSEECOMAPI(  577): QSEECom_get_handle sb_length = 0xa000
06-19 03:13:53.625 D/QSEECOMAPI(  576): App is already loaded QSEE and app id = 65537
06-19 03:13:53.625 D/QSEECOMAPI(  577): App is already loaded QSEE and app id = 65537
--------- beginning of system
06-19 03:13:53.627 I/vold    (  579): Vold 3.0 (the awakening) firing up
06-19 03:13:53.627 V/vold    (  579): Detected support for: ext4 vfat
06-19 03:13:53.632 I/vold    (  579): [libfs_mgr]dt_fstab: Skip disabled entry for partition vendor
06-19 03:13:53.638 I/vold    (  579): e4crypt_initialize_global_de
06-19 03:13:53.640 D/vold    (  579): Key exists, using: /data/unencrypted/key
06-19 03:13:53.653 E/KeymasterUtils(  577): TA API Major Verion: 2
06-19 03:13:53.653 E/KeymasterUtils(  577): TA API Minor Verion: 0
06-19 03:13:53.653 E/KeymasterUtils(  577): TA Major Verion: 2
06-19 03:13:53.654 E/KeymasterUtils(  577): TA Minor Verion: 26
06-19 03:13:53.656 E/KeymasterUtils(  576): TA API Major Verion: 2
06-19 03:13:53.656 E/KeymasterUtils(  576): TA API Minor Verion: 0
06-19 03:13:53.657 E/KeymasterUtils(  576): TA Major Verion: 2
06-19 03:13:53.657 E/KeymasterUtils(  576): TA Minor Verion: 26
06-19 03:13:53.659 I/ServiceManagement(  577): Removing namespace from process name android.hardware.keymaster@3.0-service-qti to keymaster@3.0-s.
06-19 03:13:53.660 I/android.hardware.keymaster@3.0-service(  577): Registration complete for android.hardware.keymaster@3.0::IKeymasterDevice/default.
06-19 03:13:53.660 E/vold    (  579): Could not unregister service notification for android.hardware.keymaster@3.0::IKeymasterDevice/default.
06-19 03:13:53.660 I/ServiceManagement(  576): Removing namespace from process name android.hardware.gatekeeper@1.0-service-qti to gatekeeper@1.0-.
06-19 03:13:53.661 I/android.hardware.gatekeeper@1.0-service(  576): Registration complete for android.hardware.gatekeeper@1.0::IGatekeeper/default.
06-19 03:13:53.664 E/KeyMasterHalDevice(  577): Begin send cmd failed
06-19 03:13:53.664 E/KeyMasterHalDevice(  577): ret: 0
06-19 03:13:53.664 E/KeyMasterHalDevice(  577): resp->status: -62
06-19 03:13:53.665 E/vold    (  579): begin failed, code -62
06-19 03:13:53.665 D/vold    (  579): Upgrading key: /data/unencrypted/key
06-19 03:13:53.680 E/KeyMasterHalDevice(  577): Upgrade key send cmd failed
06-19 03:13:53.680 E/KeyMasterHalDevice(  577): ret: 0
06-19 03:13:53.680 E/KeyMasterHalDevice(  577): resp->status: 1
06-19 03:13:53.680 E/vold    (  579): upgrade_key failed, code 1
06-19 03:13:53.718 D/vold    (  579): e4crypt_init_user0
06-19 03:13:53.718 D/vold    (  579): Preparing: /data/misc/vold/user_keys
06-19 03:13:53.718 E/cutils  (  579): Failed to mkdir(/data/misc/vold/user_keys): No such file or directory
06-19 03:13:53.719 E/vold    (  579): Failed to prepare /data/misc/vold/user_keys: No such file or directory

Symptoms device does not boot after an OTA is applied.

How to reproduce See above.

[jamuir]

For some reason, there is a key-upgrade command attempted, and that fails:

https://android.googlesource.com/platform/system/vold/+/android-8.1.0_r46/KeyStorage.cpp#199

[jamuir]

I suspect it is the new security-patch-level (ro.build.version.security_patch) that is triggering the attempt to upgrade the key. See docs below:

https://source.android.com/reference/hidl/android/hardware/keymaster/3.0/IKeymasterDevice#upgradekey

upgradeKey

upgradeKey (vec keyBlobToUpgrade, vec upgradeParams) generates (ErrorCode error, vec upgradedKeyBlob)

Upgrades an old key. Keys can become "old" in two ways:Keymaster can be upgraded to a new version, or the system can be updated to invalidate the OS version and/or patch level. In either case, attempts to use an old key with getKeyCharacteristics(), exportKey(), attestKey() or begin() will result in keymaster returning ErrorCode::KEY_REQUIRES_UPGRADE.This method must then be called to upgrade the key.

[jamuir]

I am able to get the device to boot by manually changing ro.build.version.security_patch to 2018-05-05 in /system/build.prop. So it is indeed the new SPL that is the cause.

@jerpelea : are there some qcom keymaster 3.0 tests that can be run to try and reproduce the key-upgrade failures I am seeing?

[jamuir]

I found some here:

https://android.googlesource.com/platform/hardware/interfaces/+/master/keymaster/3.0/vts/functional/

[updateing]

The exactly same error also happens when upgrading from 9.0.0_r1 to 9.0.0_r6 on maple. My repos are synced before SODP 9.0 bring up, though.

[jamuir]

@jerpelea : is there someone on your side who can comment on this?

I don't think the keymaster implementation is open source (please correct me if I am wrong) so I am not sure how much help I can offer here.

[jamuir]

Note that you don't have to do an ota upgrade to reproduce this defect. Just boot an image and then manually change ro.build.version.security_patch in /system/build.prop (increment by one month) and reboot.

Also, I did run the keymaster tests I pointed to above. Unfortunately, the API upgradeKey(...) is not exercised there. However, out of 106 tests, 15 failed; 9 of those failures are annotated with Google bug-ids. So there appears to be only 6 failures that are unexplained.

vts-hal-keymaster-results-20180921-1447.txt logcat-20180921-1447.txt

[jamuir]

attached is a patch that adds a test for upgradeKey() to hardware/interfaces/keymaster/3.0/vts/functional/keymaster_hidl_hal_test.cpp.

it fails when I run it.

0001-WIP-add-test-for-upgradeKey.patch.txt

(edit: I am calling upgradeKey(...) with the wrong parameters, so the test is broken. However, the maple keymaster does not seem to handle upgradeKey(...) at all; it returns an invalid error code of 1 when you call it.)

[jerpelea]

the Keymaster 3.0 binaryes did not change and the breackage appears after the AOSP part has been upgraded. Please try to revert it to the old version while i will check if there are new blobs available

[jamuir]

I have done the same upgrade (r26 to r46) on another FBE device (non-Sony) and did not hit this. I don't think it is an aosp issue.

The maple keymaster fails when you call upgradeKey(...).

The error code it returns is "1", but that is not even a valid error code for the keymaster hal:

https://android.googlesource.com/platform/hardware/interfaces/+/master/keymaster/3.0/types.hal#268

[jerpelea]

maple was shipped with FBE while all other yoahino devices were shipped with FDE

[jamuir]

I tried calling upgradeKey(...) in an 8.1.0_r26 image and it also returns the same invalid error code.

[jamuir]

@jerpelea : is there another keymaster binary I can try?

[jerpelea]

unfortunately there is no update for maple

[jamuir]

ok, but the current version of keymaster is defective and breaks OTA updates (when the SPL moves ahead).

Should we just treat this as a known issue and try to work-around it?

[jerpelea]

please try to work around it and I will look for a proper solution

[updateing]

Found a clean (sort of) workaround:

1. hex edit /odm/lib64/hw/android.hardware.keymaster@3.0-impl-qti.so, replace the only occurrence of ro.build.version.security_patch to something else like ro.build.version.security_patc0
2. add ro.build.version.security_patc0=2018-09-05(the initial setup version) to build.prop.

In this way we can keep ro.build.version.security_patch up to date and have working FBE across OTAs. The final solution could be changing the property to the standard ro.vendor.build.security_patch, and give it a fixed value in /odm/build.prop.

[jamuir]

@jerpelea : has anyone on your side been able to confirm the failure in upgradeKey(...)?

It might be that this api is called in other situations, which would mean that the impact of this bug is not limited to FBE keys.

This seems like an important defect to resolve, but I understand there are likely priorities ahead of this (e.g. supporting new devices, getting Pie working).

[jerpelea]

I will ask again next week

[jamuir]

@jerpelea ?

[jerpelea]

please update to the new Android 9 release and check if the bug still persists

[jamuir]

We need a fix for this in Oreo.

Note that updateing already reported that the bug exists in P.

[updateing]

Sorry but I should have mentioned that I was using Oreo blobs on P - there were only Oreo blobs available when I tried to bring up Pie. I'm using Oreo as daily driver so I could not test the new P blobs at this time...

[mengxiaoxi]

I read 1st message only, but -62 in err log should mean KM_ERROR_KEY_REQUIRES_UPGRADE according to hardware/libhardware/include/hardware/keymaster_defs.h

[jamuir]

I used the Emma tool to flash 47.2.A.2.33 (android 9) on an XZP. I let it boot up and then flashed an open-devices image.

The new bootloader version is 1306-5035_X_Boot_MSM8998_LA2.0_P_104.

Unfortunately, the keymaster defect is still present.

[djselbeck]

Tone/Kagura also exhibts this behavior. For example after upgrading from january to February 2019 I can boot up the device but not get rid of the lock screen, it will just reappear. The logcat contains:

02-06 08:53:19.113 2743 2743 D keystore: AddAuthenticationToken: timestamp = 133626, time_received = 126 02-06 08:53:19.122 514 514 E KeyMasterHalDevice: get_key_characteristics 02-06 08:53:19.122 514 514 E KeyMasterHalDevice: ret: 0 02-06 08:53:19.122 514 514 E KeyMasterHalDevice: resp->status: -62 02-06 08:53:19.123 2743 2743 I keystore: upgradeKeyBlob USRPKEY_synthetic_password_92a1a1c600a3ad6e 1000 02-06 08:53:19.125 514 514 E KeyMasterHalDevice: Upgrade key send cmd failed 02-06 08:53:19.126 514 514 E KeyMasterHalDevice: ret: 0 02-06 08:53:19.126 514 514 E KeyMasterHalDevice: resp->status: -21

Edit: On Android 9

[jamuir]

@djselbeck : thanks for reporting that you are also effected by this.

you are getting back -21, which at least is a valid error code :-) On maple, the error code returned is 1.

https://android.googlesource.com/platform/hardware/interfaces/+/master/keymaster/3.0/types.hal

This is a horrible defect.

[jamuir]

New firmware for the XZ Premium was just released (47.2.A.6.30). Unfortunately, this defect is still present.

[jamuir]

I pursued this issue with Sony, outside of Sony Open Devices.

After a long wait, I finally got a response confirming the defect in the keymaster binary provided by Qualcomm. The response also stated that due to the upcoming end-of-updates for the XZ Premium, a new version of keymaster would not be released.

So, this is broken and it will not be fixed.

This is disappointing, for a number of reasons, but it is good to finally get a definitive statement after 5 months.

[jerpelea]

Deprecated Android version: this bug is old and will be closed