From 5d639783a3619ef5f70af31b4ed420455d1e7329 Mon Sep 17 00:00:00 2001 From: Adrian Roos Date: Thu, 21 Jul 2016 11:43:02 -0700 Subject: [PATCH] TrustAgents: Improve debug logging Bug: 30037948 Change-Id: If374c6d4b4fb6e5341986dc42a2f7debb60a4955 --- .../server/trust/TrustAgentWrapper.java | 36 +++++++------ .../server/trust/TrustManagerService.java | 52 +++++++++++++++---- 2 files changed, 62 insertions(+), 26 deletions(-) diff --git a/services/core/java/com/android/server/trust/TrustAgentWrapper.java b/services/core/java/com/android/server/trust/TrustAgentWrapper.java index 9c2c6bfe828c0..e7c5384b9932e 100644 --- a/services/core/java/com/android/server/trust/TrustAgentWrapper.java +++ b/services/core/java/com/android/server/trust/TrustAgentWrapper.java @@ -51,7 +51,7 @@ public class TrustAgentWrapper { private static final String EXTRA_COMPONENT_NAME = "componentName"; private static final String TRUST_EXPIRED_ACTION = "android.server.trust.TRUST_EXPIRED_ACTION"; private static final String PERMISSION = android.Manifest.permission.PROVIDE_TRUST_AGENT; - private static final boolean DEBUG = false; + private static final boolean DEBUG = TrustManagerService.DEBUG; private static final String TAG = "TrustAgentWrapper"; private static final int MSG_GRANT_TRUST = 1; @@ -128,7 +128,7 @@ public class TrustAgentWrapper { // DevicePolicyManager#KEYGUARD_DISABLE_TRUST_AGENTS. duration = Math.min(durationMs, mMaximumTimeToLock); if (DEBUG) { - Log.v(TAG, "DPM lock timeout in effect. Timeout adjusted from " + Slog.d(TAG, "DPM lock timeout in effect. Timeout adjusted from " + durationMs + " to " + duration); } } else { @@ -146,7 +146,7 @@ public class TrustAgentWrapper { mTrustManagerService.updateTrust(mUserId, flags); break; case MSG_TRUST_TIMEOUT: - if (DEBUG) Slog.v(TAG, "Trust timed out : " + mName.flattenToShortString()); + if (DEBUG) Slog.d(TAG, "Trust timed out : " + mName.flattenToShortString()); mTrustManagerService.mArchive.logTrustTimeout(mUserId, mName); onTrustTimeout(); // Fall through. @@ -160,6 +160,8 @@ public class TrustAgentWrapper { mTrustManagerService.updateTrust(mUserId, 0); break; case MSG_RESTART_TIMEOUT: + Slog.w(TAG, "Connection attempt to agent " + mName.flattenToShortString() + + " timed out, rebinding"); destroy(); mTrustManagerService.resetAgent(mName, mUserId); break; @@ -169,14 +171,14 @@ public class TrustAgentWrapper { if (mSetTrustAgentFeaturesToken == token) { mSetTrustAgentFeaturesToken = null; if (mTrustDisabledByDpm && result) { - if (DEBUG) Log.v(TAG, "Re-enabling agent because it acknowledged " - + "enabled features: " + mName); + if (DEBUG) Slog.d(TAG, "Re-enabling agent because it acknowledged " + + "enabled features: " + mName.flattenToShortString()); mTrustDisabledByDpm = false; mTrustManagerService.updateTrust(mUserId, 0); } } else { - if (DEBUG) Log.w(TAG, "Ignoring MSG_SET_TRUST_AGENT_FEATURES_COMPLETED " - + "with obsolete token: " + mName); + if (DEBUG) Slog.w(TAG, "Ignoring MSG_SET_TRUST_AGENT_FEATURES_COMPLETED " + + "with obsolete token: " + mName.flattenToShortString()); } break; case MSG_MANAGING_TRUST: @@ -196,7 +198,7 @@ public class TrustAgentWrapper { @Override public void grantTrust(CharSequence userMessage, long durationMs, int flags) { - if (DEBUG) Slog.v(TAG, "enableTrust(" + userMessage + ", durationMs = " + durationMs + if (DEBUG) Slog.d(TAG, "enableTrust(" + userMessage + ", durationMs = " + durationMs + ", flags = " + flags + ")"); Message msg = mHandler.obtainMessage( @@ -207,19 +209,19 @@ public class TrustAgentWrapper { @Override public void revokeTrust() { - if (DEBUG) Slog.v(TAG, "revokeTrust()"); + if (DEBUG) Slog.d(TAG, "revokeTrust()"); mHandler.sendEmptyMessage(MSG_REVOKE_TRUST); } @Override public void setManagingTrust(boolean managingTrust) { - if (DEBUG) Slog.v(TAG, "managingTrust()"); + if (DEBUG) Slog.d(TAG, "managingTrust()"); mHandler.obtainMessage(MSG_MANAGING_TRUST, managingTrust ? 1 : 0, 0).sendToTarget(); } @Override public void onConfigureCompleted(boolean result, IBinder token) { - if (DEBUG) Slog.v(TAG, "onSetTrustAgentFeaturesEnabledCompleted(result=" + result); + if (DEBUG) Slog.d(TAG, "onSetTrustAgentFeaturesEnabledCompleted(result=" + result); mHandler.obtainMessage(MSG_SET_TRUST_AGENT_FEATURES_COMPLETED, result ? 1 : 0, 0, token).sendToTarget(); } @@ -228,7 +230,7 @@ public class TrustAgentWrapper { private final ServiceConnection mConnection = new ServiceConnection() { @Override public void onServiceConnected(ComponentName name, IBinder service) { - if (DEBUG) Log.v(TAG, "TrustAgent started : " + name.flattenToString()); + if (DEBUG) Slog.d(TAG, "TrustAgent started : " + name.flattenToString()); mHandler.removeMessages(MSG_RESTART_TIMEOUT); mTrustAgentService = ITrustAgentService.Stub.asInterface(service); mTrustManagerService.mArchive.logAgentConnected(mUserId, name); @@ -249,7 +251,7 @@ public class TrustAgentWrapper { @Override public void onServiceDisconnected(ComponentName name) { - if (DEBUG) Log.v(TAG, "TrustAgent disconnected : " + name.flattenToShortString()); + if (DEBUG) Slog.d(TAG, "TrustAgent disconnected : " + name.flattenToShortString()); mTrustAgentService = null; mManagingTrust = false; mSetTrustAgentFeaturesToken = null; @@ -352,7 +354,7 @@ public class TrustAgentWrapper { boolean updateDevicePolicyFeatures() { boolean trustDisabled = false; - if (DEBUG) Slog.v(TAG, "updateDevicePolicyFeatures(" + mName + ")"); + if (DEBUG) Slog.d(TAG, "updateDevicePolicyFeatures(" + mName + ")"); try { if (mTrustAgentService != null) { DevicePolicyManager dpm = @@ -363,10 +365,10 @@ public class TrustAgentWrapper { List config = dpm.getTrustAgentConfiguration( null, mName, mUserId); trustDisabled = true; - if (DEBUG) Slog.v(TAG, "Detected trust agents disabled. Config = " + config); + if (DEBUG) Slog.d(TAG, "Detected trust agents disabled. Config = " + config); if (config != null && config.size() > 0) { if (DEBUG) { - Slog.v(TAG, "TrustAgent " + mName.flattenToShortString() + Slog.d(TAG, "TrustAgent " + mName.flattenToShortString() + " disabled until it acknowledges "+ config); } mSetTrustAgentFeaturesToken = new Binder(); @@ -415,7 +417,7 @@ public class TrustAgentWrapper { if (!mBound) { return; } - if (DEBUG) Log.v(TAG, "TrustAgent unbound : " + mName.flattenToShortString()); + if (DEBUG) Slog.d(TAG, "TrustAgent unbound : " + mName.flattenToShortString()); mTrustManagerService.mArchive.logAgentStopped(mUserId, mName); mContext.unbindService(mConnection); mBound = false; diff --git a/services/core/java/com/android/server/trust/TrustManagerService.java b/services/core/java/com/android/server/trust/TrustManagerService.java index 95550aaa2f6c4..e60488a48bddb 100644 --- a/services/core/java/com/android/server/trust/TrustManagerService.java +++ b/services/core/java/com/android/server/trust/TrustManagerService.java @@ -44,6 +44,7 @@ import android.content.res.TypedArray; import android.content.res.XmlResourceParser; import android.graphics.drawable.Drawable; import android.os.Binder; +import android.os.Build; import android.os.DeadObjectException; import android.os.Handler; import android.os.IBinder; @@ -86,9 +87,8 @@ import java.util.List; * instance of a {@link android.service.trust.TrustAgentService}. */ public class TrustManagerService extends SystemService { - - private static final boolean DEBUG = false; private static final String TAG = "TrustManagerService"; + static final boolean DEBUG = Build.IS_DEBUGGABLE && Log.isLoggable(TAG, Log.VERBOSE); private static final Intent TRUST_AGENT_INTENT = new Intent(TrustAgentService.SERVICE_INTERFACE); @@ -255,11 +255,33 @@ public class TrustManagerService extends SystemService { for (UserInfo userInfo : userInfos) { if (userInfo == null || userInfo.partial || !userInfo.isEnabled() || userInfo.guestToRemove) continue; - if (!userInfo.supportsSwitchToByUser()) continue; - if (!StorageManager.isUserKeyUnlocked(userInfo.id)) continue; - if (!mActivityManager.isUserRunning(userInfo.id)) continue; - if (!lockPatternUtils.isSecure(userInfo.id)) continue; - if (!mStrongAuthTracker.canAgentsRunForUser(userInfo.id)) continue; + if (!userInfo.supportsSwitchToByUser()) { + if (DEBUG) Slog.d(TAG, "refreshAgentList: skipping user " + userInfo.id + + ": switchToByUser=false"); + continue; + } + if (!StorageManager.isUserKeyUnlocked(userInfo.id)) { + if (DEBUG) Slog.d(TAG, "refreshAgentList: skipping user " + userInfo.id + + ": FDE still locked"); + continue; + } + if (!mActivityManager.isUserRunning(userInfo.id)) { + if (DEBUG) Slog.d(TAG, "refreshAgentList: skipping user " + userInfo.id + + ": user not started"); + continue; + } + if (!lockPatternUtils.isSecure(userInfo.id)) { + if (DEBUG) Slog.d(TAG, "refreshAgentList: skipping user " + userInfo.id + + ": no secure credential"); + continue; + } + if (!mStrongAuthTracker.canAgentsRunForUser(userInfo.id)) { + if (DEBUG) Slog.d(TAG, "refreshAgentList: skipping user " + userInfo.id + + ": prevented by StrongAuthTracker = 0x" + + Integer.toHexString(mStrongAuthTracker.getStrongAuthForUser( + userInfo.id))); + continue; + } DevicePolicyManager dpm = lockPatternUtils.getDevicePolicyManager(); int disabledFeatures = dpm.getKeyguardDisabledFeatures(null, userInfo.id); final boolean disableTrustAgents = @@ -267,18 +289,30 @@ public class TrustManagerService extends SystemService { List enabledAgents = lockPatternUtils.getEnabledTrustAgents(userInfo.id); if (enabledAgents == null) { + if (DEBUG) Slog.d(TAG, "refreshAgentList: skipping user " + userInfo.id + + ": no agents enabled by user"); continue; } List resolveInfos = resolveAllowedTrustAgents(pm, userInfo.id); for (ResolveInfo resolveInfo : resolveInfos) { ComponentName name = getComponentName(resolveInfo); - if (!enabledAgents.contains(name)) continue; + if (!enabledAgents.contains(name)) { + if (DEBUG) Slog.d(TAG, "refreshAgentList: skipping " + + name.flattenToShortString() + " u"+ userInfo.id + + ": not enabled by user"); + continue; + } if (disableTrustAgents) { List config = dpm.getTrustAgentConfiguration(null /* admin */, name, userInfo.id); // Disable agent if no features are enabled. - if (config == null || config.isEmpty()) continue; + if (config == null || config.isEmpty()) { + if (DEBUG) Slog.d(TAG, "refreshAgentList: skipping " + + name.flattenToShortString() + " u"+ userInfo.id + + ": not allowed by DPM"); + continue; + } } AgentInfo agentInfo = new AgentInfo();