Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 257a8afc authored by Felipe Leme's avatar Felipe Leme
Browse files

Logging improvements on DevicePolicyManagerService classes:

- Overloaded most Slog methods to support string formatting.
- Uses Locale.ENGLISH on such string formatting calls.
- Fixed logging statements that were using DEBUG inside a method
  (as it wouldn't prevent the calling code to be compiled out when
  it's value is 'false').
- Changed  some secondary classes (i.e., not on DPMS itself) to
  use Slog instead of Log.
- Added some extra info like file name and user id.
- Removed unused variables.

Test: m services
Test: atest FactoryResetterTest FrameworksServicesTests:DevicePolicyManagerTest

Bug: 156263735

Change-Id: Ie15e0c3bd75c845de79f6e724b65578272e45410
parent ff340887
Loading
Loading
Loading
Loading
+17 −30
Original line number Diff line number Diff line
@@ -19,6 +19,8 @@ package com.android.server.devicepolicy;
import static android.app.admin.DevicePolicyManager.PASSWORD_COMPLEXITY_NONE;
import static android.app.admin.DevicePolicyManager.PASSWORD_QUALITY_UNSPECIFIED;

import static com.android.server.devicepolicy.DevicePolicyManagerService.LOG_TAG;

import static org.xmlpull.v1.XmlPullParser.END_DOCUMENT;
import static org.xmlpull.v1.XmlPullParser.END_TAG;
import static org.xmlpull.v1.XmlPullParser.TEXT;
@@ -38,7 +40,6 @@ import android.text.TextUtils;
import android.util.ArrayMap;
import android.util.ArraySet;
import android.util.IndentingPrintWriter;
import android.util.Log;
import android.util.Slog;
import android.util.TypedXmlPullParser;
import android.util.TypedXmlSerializer;
@@ -455,8 +456,7 @@ class ActiveAdmin {
                    try {
                        trustAgentInfo.options.saveToXml(out);
                    } catch (XmlPullParserException e) {
                        Log.e(DevicePolicyManagerService.LOG_TAG,
                                "Failed to save TrustAgent options", e);
                        Slog.e(LOG_TAG, e, "Failed to save TrustAgent options");
                    }
                    out.endTag(null, TAG_TRUST_AGENT_COMPONENT_OPTIONS);
                }
@@ -629,8 +629,7 @@ class ActiveAdmin {
            String tag = parser.getName();
            if (TAG_POLICIES.equals(tag)) {
                if (shouldOverridePolicies) {
                    Log.d(DevicePolicyManagerService.LOG_TAG,
                            "Overriding device admin policies from XML.");
                    Slog.d(LOG_TAG, "Overriding device admin policies from XML.");
                    info.readPoliciesFromXml(parser);
                }
            } else if (TAG_PASSWORD_QUALITY.equals(tag)) {
@@ -726,16 +725,14 @@ class ActiveAdmin {
                if (type == TypedXmlPullParser.TEXT) {
                    shortSupportMessage = parser.getText();
                } else {
                    Log.w(DevicePolicyManagerService.LOG_TAG,
                            "Missing text when loading short support message");
                    Slog.w(LOG_TAG, "Missing text when loading short support message");
                }
            } else if (TAG_LONG_SUPPORT_MESSAGE.equals(tag)) {
                type = parser.next();
                if (type == TypedXmlPullParser.TEXT) {
                    longSupportMessage = parser.getText();
                } else {
                    Log.w(DevicePolicyManagerService.LOG_TAG,
                            "Missing text when loading long support message");
                    Slog.w(LOG_TAG, "Missing text when loading long support message");
                }
            } else if (TAG_PARENT_ADMIN.equals(tag)) {
                Preconditions.checkState(!isParent);
@@ -748,8 +745,7 @@ class ActiveAdmin {
                if (type == TypedXmlPullParser.TEXT) {
                    organizationName = parser.getText();
                } else {
                    Log.w(DevicePolicyManagerService.LOG_TAG,
                            "Missing text when loading organization name");
                    Slog.w(LOG_TAG, "Missing text when loading organization name");
                }
            } else if (TAG_IS_LOGOUT_ENABLED.equals(tag)) {
                isLogoutEnabled = parser.getAttributeBoolean(null, ATTR_VALUE, false);
@@ -758,16 +754,14 @@ class ActiveAdmin {
                if (type == TypedXmlPullParser.TEXT) {
                    startUserSessionMessage = parser.getText();
                } else {
                    Log.w(DevicePolicyManagerService.LOG_TAG,
                            "Missing text when loading start session message");
                    Slog.w(LOG_TAG, "Missing text when loading start session message");
                }
            } else if (TAG_END_USER_SESSION_MESSAGE.equals(tag)) {
                type = parser.next();
                if (type == TypedXmlPullParser.TEXT) {
                    endUserSessionMessage = parser.getText();
                } else {
                    Log.w(DevicePolicyManagerService.LOG_TAG,
                            "Missing text when loading end session message");
                    Slog.w(LOG_TAG, "Missing text when loading end session message");
                }
            } else if (TAG_CROSS_PROFILE_CALENDAR_PACKAGES.equals(tag)) {
                mCrossProfileCalendarPackages = readPackageList(parser, tag);
@@ -802,16 +796,14 @@ class ActiveAdmin {
                if (type == TypedXmlPullParser.TEXT) {
                    mOrganizationId = parser.getText();
                } else {
                    Log.w(DevicePolicyManagerService.LOG_TAG,
                            "Missing Organization ID.");
                    Slog.w(LOG_TAG, "Missing Organization ID.");
                }
            } else if (TAG_ENROLLMENT_SPECIFIC_ID.equals(tag)) {
                type = parser.next();
                if (type == TypedXmlPullParser.TEXT) {
                    mEnrollmentSpecificId = parser.getText();
                } else {
                    Log.w(DevicePolicyManagerService.LOG_TAG,
                            "Missing Enrollment-specific ID.");
                    Slog.w(LOG_TAG, "Missing Enrollment-specific ID.");
                }
            } else if (TAG_ADMIN_CAN_GRANT_SENSORS_PERMISSIONS.equals(tag)) {
                mAdminCanGrantSensorsPermissions = parser.getAttributeBoolean(null, ATTR_VALUE,
@@ -820,7 +812,7 @@ class ActiveAdmin {
                mUsbDataSignalingEnabled = parser.getAttributeBoolean(null, ATTR_VALUE,
                        USB_DATA_SIGNALING_ENABLED_DEFAULT);
            } else {
                Slog.w(DevicePolicyManagerService.LOG_TAG, "Unknown admin tag: " + tag);
                Slog.w(LOG_TAG, "Unknown admin tag: %s", tag);
                XmlUtils.skipCurrentTag(parser);
            }
        }
@@ -842,12 +834,10 @@ class ActiveAdmin {
                if (packageName != null) {
                    result.add(packageName);
                } else {
                    Slog.w(DevicePolicyManagerService.LOG_TAG,
                            "Package name missing under " + outerTag);
                    Slog.w(LOG_TAG, "Package name missing under %s", outerTag);
                }
            } else {
                Slog.w(DevicePolicyManagerService.LOG_TAG,
                        "Unknown tag under " + tag +  ": " + outerTag);
                Slog.w(LOG_TAG, "Unknown tag under %s: ", tag, outerTag);
            }
        }
        return result;
@@ -868,8 +858,7 @@ class ActiveAdmin {
            if (tag.equals(tagDAM)) {
                result.add(parser.getAttributeValue(null, ATTR_VALUE));
            } else {
                Slog.e(DevicePolicyManagerService.LOG_TAG,
                        "Expected tag " + tag +  " but found " + tagDAM);
                Slog.e(LOG_TAG, "Expected tag %s but found %s", tag, tagDAM);
            }
        }
    }
@@ -891,8 +880,7 @@ class ActiveAdmin {
                final TrustAgentInfo trustAgentInfo = getTrustAgentInfo(parser, tag);
                result.put(component, trustAgentInfo);
            } else {
                Slog.w(DevicePolicyManagerService.LOG_TAG,
                        "Unknown tag under " + tag +  ": " + tagDAM);
                Slog.w(LOG_TAG, "Unknown tag under %s: %s", tag, tagDAM);
            }
        }
        return result;
@@ -912,8 +900,7 @@ class ActiveAdmin {
            if (TAG_TRUST_AGENT_COMPONENT_OPTIONS.equals(tagDAM)) {
                result.options = PersistableBundle.restoreFromXml(parser);
            } else {
                Slog.w(DevicePolicyManagerService.LOG_TAG,
                        "Unknown tag under " + tag +  ": " + tagDAM);
                Slog.w(LOG_TAG, "Unknown tag under %s: %s", tag, tagDAM);
            }
        }
        return result;
+13 −11
Original line number Diff line number Diff line
@@ -16,6 +16,8 @@

package com.android.server.devicepolicy;

import static com.android.server.devicepolicy.DevicePolicyManagerService.LOG_TAG;

import android.app.Notification;
import android.app.PendingIntent;
import android.content.BroadcastReceiver;
@@ -33,7 +35,7 @@ import android.provider.Settings;
import android.security.Credentials;
import android.security.KeyChain;
import android.security.KeyChain.KeyChainConnection;
import android.util.Log;
import android.util.Slog;

import com.android.internal.R;
import com.android.internal.messages.nano.SystemMessageProto.SystemMessage;
@@ -47,7 +49,6 @@ import java.security.cert.X509Certificate;
import java.util.List;

public class CertificateMonitor {
    protected static final String LOG_TAG = DevicePolicyManagerService.LOG_TAG;
    protected static final int MONITORING_CERT_NOTIFICATION_ID = SystemMessage.NOTE_SSL_CERT_INFO;

    private final DevicePolicyManagerService mService;
@@ -78,16 +79,16 @@ public class CertificateMonitor {
            X509Certificate cert = parseCert(certBuffer);
            pemCert = Credentials.convertToPem(cert);
        } catch (CertificateException | IOException ce) {
            Log.e(LOG_TAG, "Problem converting cert", ce);
            Slog.e(LOG_TAG, ce, "Problem converting cert");
            return null;
        }

        try (KeyChainConnection keyChainConnection = mInjector.keyChainBindAsUser(userHandle)) {
            return keyChainConnection.getService().installCaCertificate(pemCert);
        } catch (RemoteException e) {
            Log.e(LOG_TAG, "installCaCertsToKeyChain(): ", e);
            Slog.e(LOG_TAG, e, "installCaCertsToKeyChain(): ");
        } catch (InterruptedException e1) {
            Log.w(LOG_TAG, "installCaCertsToKeyChain(): ", e1);
            Slog.w(LOG_TAG, e1, "installCaCertsToKeyChain(): ");
            Thread.currentThread().interrupt();
        }
        return null;
@@ -99,9 +100,9 @@ public class CertificateMonitor {
                keyChainConnection.getService().deleteCaCertificate(aliases[i]);
            }
        } catch (RemoteException e) {
            Log.e(LOG_TAG, "from CaCertUninstaller: ", e);
            Slog.e(LOG_TAG, e, "from CaCertUninstaller: ");
        } catch (InterruptedException ie) {
            Log.w(LOG_TAG, "CaCertUninstaller: ", ie);
            Slog.w(LOG_TAG, ie, "CaCertUninstaller: ");
            Thread.currentThread().interrupt();
        }
    }
@@ -137,7 +138,8 @@ public class CertificateMonitor {
    };

    private void updateInstalledCertificates(final UserHandle userHandle) {
        if (!mInjector.getUserManager().isUserUnlocked(userHandle.getIdentifier())) {
        final int userId = userHandle.getIdentifier();
        if (!mInjector.getUserManager().isUserUnlocked(userId)) {
            return;
        }

@@ -145,7 +147,8 @@ public class CertificateMonitor {
        try {
            installedCerts = getInstalledCaCertificates(userHandle);
        } catch (RemoteException | RuntimeException e) {
            Log.e(LOG_TAG, "Could not retrieve certificates from KeyChain service", e);
            Slog.e(LOG_TAG, e, "Could not retrieve certificates from KeyChain service for user %d",
                    userId);
            return;
        }
        mService.onInstalledCertificatesChanged(userHandle, installedCerts);
@@ -167,7 +170,7 @@ public class CertificateMonitor {
        try {
            userContext = mInjector.createContextAsUser(userHandle);
        } catch (PackageManager.NameNotFoundException e) {
            Log.e(LOG_TAG, "Create context as " + userHandle + " failed", e);
            Slog.e(LOG_TAG, e, "Create context as %s failed", userHandle);
            return null;
        }

@@ -183,7 +186,6 @@ public class CertificateMonitor {
            smallIconId = R.drawable.stat_sys_certificate_info;
            parentUserId = mService.getProfileParentId(userHandle.getIdentifier());
        } else if (mService.getDeviceOwnerUserId() == userHandle.getIdentifier()) {
            final String ownerName = mService.getDeviceOwnerName();
            contentText = resources.getString(R.string.ssl_ca_cert_noti_managed,
                    mService.getDeviceOwnerName());
            smallIconId = R.drawable.stat_sys_certificate_info;
+14 −17
Original line number Diff line number Diff line
@@ -46,19 +46,11 @@ public class DeviceAdminServiceController {
    final Object mLock = new Object();
    final Context mContext;

    private final DevicePolicyManagerService mService;
    private final DevicePolicyManagerService.Injector mInjector;
    private final DevicePolicyConstants mConstants;

    private final Handler mHandler; // needed?

    static void debug(String format, Object... args) {
        if (!DEBUG) {
            return;
        }
        Slog.d(TAG, String.format(format, args));
    }

    private class DevicePolicyServiceConnection
            extends PersistentConnection<IDeviceAdminService> {
        public DevicePolicyServiceConnection(int userId, @NonNull ComponentName componentName) {
@@ -88,7 +80,6 @@ public class DeviceAdminServiceController {

    public DeviceAdminServiceController(DevicePolicyManagerService service,
            DevicePolicyConstants constants) {
        mService = service;
        mInjector = service.mInjector;
        mContext = mInjector.mContext;
        mHandler = new Handler(BackgroundThread.get().getLooper());
@@ -122,8 +113,9 @@ public class DeviceAdminServiceController {
            synchronized (mLock) {
                final ServiceInfo service = findService(packageName, userId);
                if (service == null) {
                    debug("Owner package %s on u%d has no service.",
                            packageName, userId);
                    if (DEBUG) {
                        Slog.d(TAG, "Owner package %s on u%d has no service.", packageName, userId);
                    }
                    disconnectServiceOnUserLocked(userId, actionForLog);
                    return;
                }
@@ -134,14 +126,17 @@ public class DeviceAdminServiceController {
                    // Note even when we're already connected to the same service, the binding
                    // would have died at this point due to a package update.  So we disconnect
                    // anyway and re-connect.
                    debug("Disconnecting from existing service connection.",
                            packageName, userId);
                    if (DEBUG) {
                        Slog.d("Disconnecting from existing service connection.", packageName,
                                userId);
                    }
                    disconnectServiceOnUserLocked(userId, actionForLog);
                }

                debug("Owner package %s on u%d has service %s for %s",
                        packageName, userId,
                if (DEBUG) {
                    Slog.d("Owner package %s on u%d has service %s for %s", packageName, userId,
                        service.getComponentName().flattenToShortString(), actionForLog);
                }

                final DevicePolicyServiceConnection conn =
                        new DevicePolicyServiceConnection(
@@ -172,8 +167,10 @@ public class DeviceAdminServiceController {
    private void disconnectServiceOnUserLocked(int userId, @NonNull String actionForLog) {
        final DevicePolicyServiceConnection conn = mConnections.get(userId);
        if (conn != null) {
            debug("Stopping service for u%d if already running for %s.",
                    userId, actionForLog);
            if (DEBUG) {
                Slog.d(TAG, "Stopping service for u%d if already running for %s.", userId,
                        actionForLog);
            }
            conn.unbind();
            mConnections.remove(userId);
        }
+1 −1
Original line number Diff line number Diff line
@@ -88,7 +88,7 @@ public class DevicePolicyConstants {
        } catch (IllegalArgumentException e) {
            // Failed to parse the settings string, log this and move on
            // with defaults.
            Slog.e(TAG, "Bad device policy settings: " + settings);
            Slog.e(TAG, "Bad device policy settings: %s", settings);
        }

        long dasDiedServiceReconnectBackoffSec = parser.getLong(
+16 −18
Original line number Diff line number Diff line
@@ -179,11 +179,11 @@ class DevicePolicyData {
     */
    static boolean store(DevicePolicyData policyData, JournaledFile file, boolean isFdeDevice) {
        FileOutputStream stream = null;
        File chooseForWrite = null;
        try {
            File chooseForWrite = file.chooseForWrite();
            chooseForWrite = file.chooseForWrite();
            if (VERBOSE_LOG) {
                Slog.v(TAG, "Storing data for user " + policyData.mUserId + " on "
                        + chooseForWrite);
                Slog.v(TAG, "Storing data for user %d on %s ", policyData.mUserId, chooseForWrite);
            }
            stream = new FileOutputStream(chooseForWrite, false);
            TypedXmlSerializer out = Xml.resolveSerializer(stream);
@@ -195,7 +195,7 @@ class DevicePolicyData {
                        policyData.mRestrictionsProvider.flattenToString());
            }
            if (policyData.mUserSetupComplete) {
                if (VERBOSE_LOG) Slog.v(TAG, "setting " + ATTR_SETUP_COMPLETE + " to true");
                if (VERBOSE_LOG) Slog.v(TAG, "setting %s to true", ATTR_SETUP_COMPLETE);
                out.attributeBoolean(null, ATTR_SETUP_COMPLETE, true);
            }
            if (policyData.mPaired) {
@@ -216,8 +216,8 @@ class DevicePolicyData {

            if (policyData.mFactoryResetFlags != 0) {
                if (VERBOSE_LOG) {
                    Slog.v(TAG, "Storing factory reset flags for user " + policyData.mUserId + ": "
                            + factoryResetFlagsToString(policyData.mFactoryResetFlags));
                    Slog.v(TAG, "Storing factory reset flags for user %d: %s", policyData.mUserId,
                            factoryResetFlagsToString(policyData.mFactoryResetFlags));
                }
                out.attributeInt(null, ATTR_FACTORY_RESET_FLAGS, policyData.mFactoryResetFlags);
            }
@@ -382,7 +382,7 @@ class DevicePolicyData {
            file.commit();
            return true;
        } catch (XmlPullParserException | IOException e) {
            Slog.w(TAG, "failed writing file", e);
            Slog.w(TAG, e, "failed writing file %s", chooseForWrite);
            try {
                if (stream != null) {
                    stream.close();
@@ -404,10 +404,8 @@ class DevicePolicyData {
            ComponentName ownerComponent) {
        FileInputStream stream = null;
        File file = journaledFile.chooseForRead();
        if (VERBOSE_LOG) {
            Slog.v(TAG, "Loading data for user " + policy.mUserId + " from " + file);
        }

        if (VERBOSE_LOG) Slog.v(TAG, "Loading data for user %d from %s", policy.mUserId, file);
        boolean needsRewrite = false;
        try {
            stream = new FileInputStream(file);
            TypedXmlPullParser parser = Xml.resolvePullParser(stream);
@@ -454,8 +452,8 @@ class DevicePolicyData {

            policy.mFactoryResetFlags = parser.getAttributeInt(null, ATTR_FACTORY_RESET_FLAGS, 0);
            if (VERBOSE_LOG) {
                Slog.v(TAG, "Restored factory reset flags for user " + policy.mUserId + ": "
                        + factoryResetFlagsToString(policy.mFactoryResetFlags));
                Slog.v(TAG, "Restored factory reset flags for user %d: %s", policy.mUserId,
                        factoryResetFlagsToString(policy.mFactoryResetFlags));
            }
            policy.mFactoryResetReason = parser.getAttributeValue(null, ATTR_FACTORY_RESET_REASON);

@@ -488,7 +486,7 @@ class DevicePolicyData {
                            policy.mAdminMap.put(ap.info.getComponent(), ap);
                        }
                    } catch (RuntimeException e) {
                        Slog.w(TAG, "Failed loading admin " + name, e);
                        Slog.w(TAG, e, "Failed loading admin %s", name);
                    }
                } else if ("delegation".equals(tag)) {
                    // Parse delegation info.
@@ -560,7 +558,7 @@ class DevicePolicyData {
                    policy.mAppsSuspended =
                            parser.getAttributeBoolean(null, ATTR_VALUE, false);
                } else {
                    Slog.w(TAG, "Unknown tag: " + tag);
                    Slog.w(TAG, "Unknown tag: %s", tag);
                    XmlUtils.skipCurrentTag(parser);
                }
            }
@@ -568,7 +566,7 @@ class DevicePolicyData {
            // Don't be noisy, this is normal if we haven't defined any policies.
        } catch (NullPointerException | NumberFormatException | XmlPullParserException | IOException
                | IndexOutOfBoundsException e) {
            Slog.w(TAG, "failed parsing " + file, e);
            Slog.w(TAG, e, "failed parsing %s", file);
        }
        try {
            if (stream != null) {
@@ -592,8 +590,8 @@ class DevicePolicyData {
                }
            }
            if (!haveOwner) {
                Slog.w(TAG, "Previous password owner " + mPasswordOwner
                        + " no longer active; disabling");
                Slog.w(TAG, "Previous password owner %s no longer active; disabling",
                        mPasswordOwner);
                mPasswordOwner = -1;
            }
        }
Loading