From 6318c7e12c130be2e7767c49e956ae2f5e56c9e8 Mon Sep 17 00:00:00 2001
From: Eric Biggers <ebiggers@google.com>
Date: Mon, 27 Feb 2023 19:20:45 +0000
Subject: [PATCH] locksettings: improve logging of LSKF verification

Improve the logging related to verifying the LSKF.

We generally don't want to be super verbose here, but it does make sense
to have an INFO message at the beginning and end.  There was already a
DEBUG message at the beginning and an INFO message near the end, but
they were unclear, so replace them with clearer INFO messages.

Bug: 268526331
Change-Id: Iaccbbd0d5a297bf97ff6ef31630eeec19fe3277b
Merged-In: Iaccbbd0d5a297bf97ff6ef31630eeec19fe3277b
(cherry picked from commit 18045f36e80f80aee4968c6a91c643c419bd8c6b)
---
 .../android/server/locksettings/LockSettingsService.java | 9 +++++----
 .../server/locksettings/SyntheticPasswordManager.java    | 5 +++--
 2 files changed, 8 insertions(+), 6 deletions(-)

diff --git a/services/core/java/com/android/server/locksettings/LockSettingsService.java b/services/core/java/com/android/server/locksettings/LockSettingsService.java
index c00561219e29c..29868aca0b497 100644
--- a/services/core/java/com/android/server/locksettings/LockSettingsService.java
+++ b/services/core/java/com/android/server/locksettings/LockSettingsService.java
@@ -1267,7 +1267,6 @@ public class LockSettingsService extends ILockSettings.Stub {
     }
 
     private void unlockKeystore(byte[] password, int userHandle) {
-        if (DEBUG) Slog.v(TAG, "Unlock keystore for user: " + userHandle);
         Authorization.onLockScreenEvent(false, userHandle, password, null);
     }
 
@@ -1277,7 +1276,7 @@ public class LockSettingsService extends ILockSettings.Stub {
             NoSuchAlgorithmException, NoSuchPaddingException, InvalidKeyException,
             InvalidAlgorithmParameterException, IllegalBlockSizeException, BadPaddingException,
             CertificateException, IOException {
-        if (DEBUG) Slog.v(TAG, "Get child profile decrypted key");
+        Slogf.d(TAG, "Decrypting password for tied profile %d", userId);
         byte[] storedData = mStorage.readChildProfileLock(userId);
         if (storedData == null) {
             throw new FileNotFoundException("Child profile lock file not found");
@@ -1326,7 +1325,6 @@ public class LockSettingsService extends ILockSettings.Stub {
      * {@link com.android.server.SystemServiceManager#unlockUser} </em>
      */
     private void unlockUser(@UserIdInt int userId) {
-        Slogf.i(TAG, "Unlocking user %d", userId);
         // TODO: make this method fully async so we can update UI with progress strings
         final boolean alreadyUnlocked = mUserManager.isUserUnlockingOrUnlocked(userId);
         final CountDownLatch latch = new CountDownLatch(1);
@@ -2130,7 +2128,7 @@ public class LockSettingsService extends ILockSettings.Stub {
             Slog.e(TAG, "FRP credential can only be verified prior to provisioning.");
             return VerifyCredentialResponse.ERROR;
         }
-        Slog.d(TAG, "doVerifyCredential: user=" + userId);
+        Slogf.i(TAG, "Verifying lockscreen credential for user %d", userId);
 
         final AuthenticationResult authResult;
         VerifyCredentialResponse response;
@@ -2164,6 +2162,7 @@ public class LockSettingsService extends ILockSettings.Stub {
             }
         }
         if (response.getResponseCode() == VerifyCredentialResponse.RESPONSE_OK) {
+            Slogf.i(TAG, "Successfully verified lockscreen credential for user %d", userId);
             onCredentialVerified(authResult.syntheticPassword,
                     PasswordMetrics.computeForCredential(credential), userId);
             if ((flags & VERIFY_FLAG_REQUEST_GK_PW_HANDLE) != 0) {
@@ -2910,6 +2909,7 @@ public class LockSettingsService extends ILockSettings.Stub {
     public byte[] getHashFactor(LockscreenCredential currentCredential, int userId) {
         checkPasswordReadPermission();
         try {
+            Slogf.d(TAG, "Getting password history hash factor for user %d", userId);
             if (isProfileWithUnifiedLock(userId)) {
                 try {
                     currentCredential = getDecryptedPasswordForTiedProfile(userId);
@@ -3473,6 +3473,7 @@ public class LockSettingsService extends ILockSettings.Stub {
             synchronized (mSpManager) {
                 mSpManager.verifyChallenge(getGateKeeperService(), sp, 0L, userId);
             }
+            Slogf.i(TAG, "Restored synthetic password for user %d using reboot escrow", userId);
             onCredentialVerified(sp, loadPasswordMetrics(sp, userId), userId);
         }
     }
diff --git a/services/core/java/com/android/server/locksettings/SyntheticPasswordManager.java b/services/core/java/com/android/server/locksettings/SyntheticPasswordManager.java
index fe15bce061dc6..b54ee7f36c47c 100644
--- a/services/core/java/com/android/server/locksettings/SyntheticPasswordManager.java
+++ b/services/core/java/com/android/server/locksettings/SyntheticPasswordManager.java
@@ -1176,8 +1176,9 @@ class SyntheticPasswordManager {
             storedType = pwd.credentialType;
         }
         if (!credential.checkAgainstStoredType(storedType)) {
-            Slog.e(TAG, TextUtils.formatSimple("Credential type mismatch: expected %d actual %d",
-                    storedType, credential.getType()));
+            Slogf.e(TAG, "Credential type mismatch: stored type is %s but provided type is %s",
+                    LockPatternUtils.credentialTypeToString(storedType),
+                    LockPatternUtils.credentialTypeToString(credential.getType()));
             result.gkResponse = VerifyCredentialResponse.ERROR;
             return result;
         }