From b56a4292011fe18cbcb63181131dda5974dc102f Mon Sep 17 00:00:00 2001 From: Eric Biggers Date: Mon, 27 Feb 2023 19:20:46 +0000 Subject: [PATCH] locksettings: improve logging of SP and protector changes Improve the logging for synthetic password protectors being created and deleted, and the synthetic password itself being created. This includes the case where a user's LSKF is being changed. These are infrequent and important operations, so generally we should error on the side of being verbose for them. Bug: 268526331 Change-Id: I9cd91ecd3bb80b59fb367072d7f30dc90a5ee332 Merged-In: I9cd91ecd3bb80b59fb367072d7f30dc90a5ee332 (cherry picked from commit 72ba837864de6a6740a5c5a2646dad838a99d3ab) --- .../server/locksettings/LockSettingsService.java | 16 ++++++++-------- .../locksettings/SyntheticPasswordManager.java | 14 ++++++++++---- 2 files changed, 18 insertions(+), 12 deletions(-) diff --git a/services/core/java/com/android/server/locksettings/LockSettingsService.java b/services/core/java/com/android/server/locksettings/LockSettingsService.java index 29868aca0b497..5f34770e07b5c 100644 --- a/services/core/java/com/android/server/locksettings/LockSettingsService.java +++ b/services/core/java/com/android/server/locksettings/LockSettingsService.java @@ -380,7 +380,6 @@ public class LockSettingsService extends ILockSettings.Stub { */ private void tieProfileLockIfNecessary(int profileUserId, LockscreenCredential profileUserPassword) { - if (DEBUG) Slog.v(TAG, "Check child profile lock for user: " + profileUserId); // Only for profiles that shares credential with parent if (!isCredentialSharableWithParent(profileUserId)) { return; @@ -398,8 +397,7 @@ public class LockSettingsService extends ILockSettings.Stub { // as its parent. final int parentId = mUserManager.getProfileParent(profileUserId).id; if (!isUserSecure(parentId) && !profileUserPassword.isNone()) { - if (DEBUG) Slog.v(TAG, "Parent does not have a screen lock but profile has one"); - + Slogf.i(TAG, "Clearing password for profile user %d to match parent", profileUserId); setLockCredentialInternal(LockscreenCredential.createNone(), profileUserPassword, profileUserId, /* isLockTiedToParent= */ true); return; @@ -415,7 +413,6 @@ public class LockSettingsService extends ILockSettings.Stub { Slog.e(TAG, "Failed to talk to GateKeeper service", e); return; } - if (DEBUG) Slog.v(TAG, "Tie profile to parent now!"); try (LockscreenCredential unifiedProfilePassword = generateRandomProfilePassword()) { setLockCredentialInternal(unifiedProfilePassword, profileUserPassword, profileUserId, /* isLockTiedToParent= */ true); @@ -1634,7 +1631,6 @@ public class LockSettingsService extends ILockSettings.Stub { LockscreenCredential savedCredential, int userId, boolean isLockTiedToParent) { Objects.requireNonNull(credential); Objects.requireNonNull(savedCredential); - if (DEBUG) Slog.d(TAG, "setLockCredentialInternal: user=" + userId); synchronized (mSpManager) { if (savedCredential.isNone() && isProfileWithUnifiedLock(userId)) { // get credential from keystore when profile has unified lock @@ -1871,7 +1867,8 @@ public class LockSettingsService extends ILockSettings.Stub { @VisibleForTesting /** Note: this method is overridden in unit tests */ protected void tieProfileLockToParent(int profileUserId, int parentUserId, LockscreenCredential password) { - if (DEBUG) Slog.v(TAG, "tieProfileLockToParent for user: " + profileUserId); + Slogf.i(TAG, "Tying lock for profile user %d to parent user %d", profileUserId, + parentUserId); final byte[] iv; final byte[] ciphertext; final long parentSid; @@ -2680,7 +2677,7 @@ public class LockSettingsService extends ILockSettings.Stub { @VisibleForTesting SyntheticPassword initializeSyntheticPassword(int userId) { synchronized (mSpManager) { - Slog.i(TAG, "Initialize SyntheticPassword for user: " + userId); + Slogf.i(TAG, "Initializing synthetic password for user %d", userId); Preconditions.checkState(getCurrentLskfBasedProtectorId(userId) == SyntheticPasswordManager.NULL_PROTECTOR_ID, "Cannot reinitialize SP"); @@ -2691,6 +2688,7 @@ public class LockSettingsService extends ILockSettings.Stub { setCurrentLskfBasedProtectorId(protectorId, userId); setUserKeyProtection(userId, sp.deriveFileBasedEncryptionKey()); onSyntheticPasswordCreated(userId, sp); + Slogf.i(TAG, "Successfully initialized synthetic password for user %d", userId); return sp; } } @@ -2780,7 +2778,8 @@ public class LockSettingsService extends ILockSettings.Stub { @GuardedBy("mSpManager") private long setLockCredentialWithSpLocked(LockscreenCredential credential, SyntheticPassword sp, int userId) { - if (DEBUG) Slog.d(TAG, "setLockCredentialWithSpLocked: user=" + userId); + Slogf.i(TAG, "Changing lockscreen credential of user %d; newCredentialType=%s\n", + userId, LockPatternUtils.credentialTypeToString(credential.getType())); final int savedCredentialType = getCredentialTypeInternal(userId); final long oldProtectorId = getCurrentLskfBasedProtectorId(userId); final long newProtectorId = mSpManager.createLskfBasedProtector(getGateKeeperService(), @@ -2825,6 +2824,7 @@ public class LockSettingsService extends ILockSettings.Stub { } } mSpManager.destroyLskfBasedProtector(oldProtectorId, userId); + Slogf.i(TAG, "Successfully changed lockscreen credential of user %d", userId); return newProtectorId; } diff --git a/services/core/java/com/android/server/locksettings/SyntheticPasswordManager.java b/services/core/java/com/android/server/locksettings/SyntheticPasswordManager.java index b54ee7f36c47c..1663b019d769a 100644 --- a/services/core/java/com/android/server/locksettings/SyntheticPasswordManager.java +++ b/services/core/java/com/android/server/locksettings/SyntheticPasswordManager.java @@ -791,11 +791,11 @@ class SyntheticPasswordManager { } Set usedSlots = getUsedWeaverSlots(); if (!usedSlots.contains(slot)) { - Slog.i(TAG, "Destroy weaver slot " + slot + " for user " + userId); + Slogf.i(TAG, "Erasing Weaver slot %d", slot); weaverEnroll(slot, null, null); mPasswordSlotManager.markSlotDeleted(slot); } else { - Slog.w(TAG, "Skip destroying reused weaver slot " + slot + " for user " + userId); + Slogf.i(TAG, "Weaver slot %d was already reused; not erasing it", slot); } } } @@ -863,11 +863,13 @@ class SyntheticPasswordManager { long sid = GateKeeper.INVALID_SECURE_USER_ID; final byte[] protectorSecret; + Slogf.i(TAG, "Creating LSKF-based protector %016x for user %d", protectorId, userId); + if (isWeaverAvailable()) { // Weaver is available, so make the protector use it to verify the LSKF. Do this even // if the LSKF is empty, as that gives us support for securely deleting the protector. int weaverSlot = getNextAvailableWeaverSlot(); - Slog.i(TAG, "Weaver enroll password to slot " + weaverSlot + " for user " + userId); + Slogf.i(TAG, "Enrolling LSKF for user %d into Weaver slot %d", userId, weaverSlot); byte[] weaverSecret = weaverEnroll(weaverSlot, stretchedLskfToWeaverKey(stretchedLskf), null); if (weaverSecret == null) { @@ -897,6 +899,7 @@ class SyntheticPasswordManager { } catch (RemoteException ignore) { Slog.w(TAG, "Failed to clear SID from gatekeeper"); } + Slogf.i(TAG, "Enrolling LSKF for user %d into Gatekeeper", userId); GateKeeperResponse response; try { response = gatekeeper.enroll(fakeUserId(userId), null, null, @@ -1098,9 +1101,10 @@ class SyntheticPasswordManager { Slog.w(TAG, "User is not escrowable"); return false; } + Slogf.i(TAG, "Creating token-based protector %016x for user %d", tokenHandle, userId); if (isWeaverAvailable()) { int slot = getNextAvailableWeaverSlot(); - Slog.i(TAG, "Weaver enroll token to slot " + slot + " for user " + userId); + Slogf.i(TAG, "Using Weaver slot %d for new token-based protector", slot); if (weaverEnroll(slot, null, tokenData.weaverSecret) == null) { Slog.e(TAG, "Failed to enroll weaver secret when activating token"); return false; @@ -1480,6 +1484,7 @@ class SyntheticPasswordManager { /** Destroy a token-based SP protector. */ public void destroyTokenBasedProtector(long protectorId, int userId) { + Slogf.i(TAG, "Destroying token-based protector %016x for user %d", protectorId, userId); SyntheticPasswordBlob blob = SyntheticPasswordBlob.fromBytes(loadState(SP_BLOB_NAME, protectorId, userId)); destroyProtectorCommon(protectorId, userId); @@ -1505,6 +1510,7 @@ class SyntheticPasswordManager { * Destroy an LSKF-based SP protector. This is used when the user's LSKF is changed. */ public void destroyLskfBasedProtector(long protectorId, int userId) { + Slogf.i(TAG, "Destroying LSKF-based protector %016x for user %d", protectorId, userId); destroyProtectorCommon(protectorId, userId); destroyState(PASSWORD_DATA_NAME, protectorId, userId); destroyState(PASSWORD_METRICS_NAME, protectorId, userId);