Loading services/core/java/com/android/server/rollback/WatchdogRollbackLogger.java +9 −38 Original line number Diff line number Diff line Loading @@ -16,6 +16,7 @@ package com.android.server.rollback; import static com.android.server.crashrecovery.CrashRecoveryUtils.logCrashRecoveryEvent; import static com.android.server.crashrecovery.proto.CrashRecoveryStatsLog.WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_REASON__REASON_APP_CRASH; import static com.android.server.crashrecovery.proto.CrashRecoveryStatsLog.WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_REASON__REASON_APP_NOT_RESPONDING; import static com.android.server.crashrecovery.proto.CrashRecoveryStatsLog.WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_REASON__REASON_BOOT_LOOPING; Loading @@ -39,7 +40,7 @@ import android.content.rollback.PackageRollbackInfo; import android.content.rollback.RollbackInfo; import android.os.SystemProperties; import android.text.TextUtils; import android.util.ArraySet; import android.util.Log; import android.util.Slog; import com.android.internal.annotations.VisibleForTesting; Loading @@ -47,7 +48,6 @@ import com.android.server.PackageWatchdog; import com.android.server.crashrecovery.proto.CrashRecoveryStatsLog; import java.util.List; import java.util.Set; /** * This class handles the logic for logging Watchdog-triggered rollback events. Loading Loading @@ -101,22 +101,6 @@ public final class WatchdogRollbackLogger { return loggingParent; } /** * Gets the set of parent packages for a given set of failed package names. In the case that * multiple sessions have failed, we want to log failure for each of the parent packages. * Even if multiple failed packages have the same parent, we only log the parent package once. */ private static Set<VersionedPackage> getLogPackages(Context context, @NonNull List<String> failedPackageNames) { Set<VersionedPackage> parentPackages = new ArraySet<>(); for (String failedPackageName: failedPackageNames) { parentPackages.add(getLogPackage(context, new VersionedPackage(failedPackageName, 0))); } return parentPackages; } static void logRollbackStatusOnBoot(Context context, int rollbackId, String logPackageName, List<RollbackInfo> recentlyCommittedRollbacks) { PackageInstaller packageInstaller = context.getPackageManager().getPackageInstaller(); Loading Loading @@ -174,10 +158,11 @@ public final class WatchdogRollbackLogger { */ public static void logEvent(@Nullable VersionedPackage logPackage, int type, int rollbackReason, @NonNull String failingPackageName) { Slog.i(TAG, "Watchdog event occurred with type: " + rollbackTypeToString(type) String logMsg = "Watchdog event occurred with type: " + rollbackTypeToString(type) + " logPackage: " + logPackage + " rollbackReason: " + rollbackReasonToString(rollbackReason) + " failedPackageName: " + failingPackageName); + " failedPackageName: " + failingPackageName; Slog.i(TAG, logMsg); if (logPackage != null) { CrashRecoveryStatsLog.write( CrashRecoveryStatsLog.WATCHDOG_ROLLBACK_OCCURRED, Loading @@ -200,33 +185,19 @@ public final class WatchdogRollbackLogger { new byte[]{}); } logTestProperties(logPackage, type, rollbackReason, failingPackageName); logTestProperties(logMsg); } /** * Writes properties which will be used by rollback tests to check if particular rollback * events have occurred. * * persist.sys.rollbacktest.enabled: true if rollback tests are running * persist.sys.rollbacktest.EVENT_TYPE: true if a particular rollback event has occurred * ex: persist.sys.rollbacktest.ROLLBACK_INITIATE is true if ROLLBACK_INITIATE has happened * persist.sys.rollbacktest.EVENT_TYPE.logPackage: the package to associate the rollback with * persist.sys.rollbacktest.EVENT_TYPE.rollbackReason: the reason Watchdog triggered a rollback * persist.sys.rollbacktest.EVENT_TYPE.failedPackageName: the failing package or process which * triggered the rollback */ private static void logTestProperties(@Nullable VersionedPackage logPackage, int type, int rollbackReason, @NonNull String failingPackageName) { private static void logTestProperties(String logMsg) { // This property should be on only during the tests final String prefix = "persist.sys.rollbacktest."; if (!SystemProperties.getBoolean(prefix + "enabled", false)) { if (!SystemProperties.getBoolean("persist.sys.rollbacktest.enabled", false)) { return; } String key = prefix + rollbackTypeToString(type); SystemProperties.set(key, String.valueOf(true)); SystemProperties.set(key + ".logPackage", logPackage != null ? logPackage.toString() : ""); SystemProperties.set(key + ".rollbackReason", rollbackReasonToString(rollbackReason)); SystemProperties.set(key + ".failedPackageName", failingPackageName); logCrashRecoveryEvent(Log.DEBUG, logMsg); } @VisibleForTesting Loading tests/RollbackTest/lib/src/com/android/tests/rollback/host/WatchdogEventLogger.java +40 −27 Original line number Diff line number Diff line Loading @@ -16,33 +16,26 @@ package com.android.tests.rollback.host; import static com.google.common.truth.Truth.assertThat; import com.android.tradefed.device.ITestDevice; import com.android.tradefed.log.LogUtil.CLog; import com.google.common.truth.FailureMetadata; import com.google.common.truth.Truth; import static com.google.common.truth.Truth.assertThat; import java.util.regex.Matcher; import java.util.regex.Pattern; public class WatchdogEventLogger { private static final String[] ROLLBACK_EVENT_TYPES = { "ROLLBACK_INITIATE", "ROLLBACK_BOOT_TRIGGERED", "ROLLBACK_SUCCESS"}; private static final String[] ROLLBACK_EVENT_ATTRS = { "logPackage", "rollbackReason", "failedPackageName"}; private static final String PROP_PREFIX = "persist.sys.rollbacktest."; private ITestDevice mDevice; private void resetProperties(boolean enabled) throws Exception { private void updateTestSysProp(boolean enabled) throws Exception { try { mDevice.enableAdbRoot(); assertThat(mDevice.setProperty( PROP_PREFIX + "enabled", String.valueOf(enabled))).isTrue(); for (String type : ROLLBACK_EVENT_TYPES) { String key = PROP_PREFIX + type; assertThat(mDevice.setProperty(key, "")).isTrue(); for (String attr : ROLLBACK_EVENT_ATTRS) { assertThat(mDevice.setProperty(key + "." + attr, "")).isTrue(); } } "persist.sys.rollbacktest.enabled", String.valueOf(enabled))).isTrue(); } finally { mDevice.disableAdbRoot(); } Loading @@ -50,19 +43,17 @@ public class WatchdogEventLogger { public void start(ITestDevice device) throws Exception { mDevice = device; resetProperties(true); updateTestSysProp(true); } public void stop() throws Exception { if (mDevice != null) { resetProperties(false); updateTestSysProp(false); } } private boolean matchProperty(String type, String attr, String expectedVal) throws Exception { String key = PROP_PREFIX + type + "." + attr; String val = mDevice.getProperty(key); return expectedVal == null || expectedVal.equals(val); private boolean verifyEventContainsVal(String watchdogEvent, String expectedVal) { return expectedVal == null || watchdogEvent.contains(expectedVal); } /** Loading @@ -72,11 +63,33 @@ public class WatchdogEventLogger { * occurred, and return {@code true} if an event exists which matches all criteria. */ public boolean watchdogEventOccurred(String type, String logPackage, String rollbackReason, String failedPackageName) throws Exception { return mDevice.getBooleanProperty(PROP_PREFIX + type, false) && matchProperty(type, "logPackage", logPackage) && matchProperty(type, "rollbackReason", rollbackReason) && matchProperty(type, "failedPackageName", failedPackageName); String rollbackReason, String failedPackageName) { String watchdogEvent = getEventForRollbackType(type); return (watchdogEvent != null) && verifyEventContainsVal(watchdogEvent, logPackage) && verifyEventContainsVal(watchdogEvent, rollbackReason) && verifyEventContainsVal(watchdogEvent, failedPackageName); } /** Returns last matched event for rollbackType **/ private String getEventForRollbackType(String rollbackType) { String lastMatchedEvent = null; try { String rollbackDump = mDevice.executeShellCommand("dumpsys rollback"); String eventRegex = ".*%s%s(.*)\\n"; String eventPrefix = "Watchdog event occurred with type: "; final Pattern pattern = Pattern.compile( String.format(eventRegex, eventPrefix, rollbackType)); final Matcher matcher = pattern.matcher(rollbackDump); while (matcher.find()) { lastMatchedEvent = matcher.group(1); } CLog.d("Found watchdogEvent: " + lastMatchedEvent + " for type: " + rollbackType); } catch (Exception e) { CLog.e("Unable to find event for type: " + rollbackType, e); } return lastMatchedEvent; } static class Subject extends com.google.common.truth.Subject { Loading @@ -97,7 +110,7 @@ public class WatchdogEventLogger { } void eventOccurred(String type, String logPackage, String rollbackReason, String failedPackageName) throws Exception { String failedPackageName) { check("watchdogEventOccurred(type=%s, logPackage=%s, rollbackReason=%s, " + "failedPackageName=%s)", type, logPackage, rollbackReason, failedPackageName) .that(mActual.watchdogEventOccurred(type, logPackage, rollbackReason, Loading Loading
services/core/java/com/android/server/rollback/WatchdogRollbackLogger.java +9 −38 Original line number Diff line number Diff line Loading @@ -16,6 +16,7 @@ package com.android.server.rollback; import static com.android.server.crashrecovery.CrashRecoveryUtils.logCrashRecoveryEvent; import static com.android.server.crashrecovery.proto.CrashRecoveryStatsLog.WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_REASON__REASON_APP_CRASH; import static com.android.server.crashrecovery.proto.CrashRecoveryStatsLog.WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_REASON__REASON_APP_NOT_RESPONDING; import static com.android.server.crashrecovery.proto.CrashRecoveryStatsLog.WATCHDOG_ROLLBACK_OCCURRED__ROLLBACK_REASON__REASON_BOOT_LOOPING; Loading @@ -39,7 +40,7 @@ import android.content.rollback.PackageRollbackInfo; import android.content.rollback.RollbackInfo; import android.os.SystemProperties; import android.text.TextUtils; import android.util.ArraySet; import android.util.Log; import android.util.Slog; import com.android.internal.annotations.VisibleForTesting; Loading @@ -47,7 +48,6 @@ import com.android.server.PackageWatchdog; import com.android.server.crashrecovery.proto.CrashRecoveryStatsLog; import java.util.List; import java.util.Set; /** * This class handles the logic for logging Watchdog-triggered rollback events. Loading Loading @@ -101,22 +101,6 @@ public final class WatchdogRollbackLogger { return loggingParent; } /** * Gets the set of parent packages for a given set of failed package names. In the case that * multiple sessions have failed, we want to log failure for each of the parent packages. * Even if multiple failed packages have the same parent, we only log the parent package once. */ private static Set<VersionedPackage> getLogPackages(Context context, @NonNull List<String> failedPackageNames) { Set<VersionedPackage> parentPackages = new ArraySet<>(); for (String failedPackageName: failedPackageNames) { parentPackages.add(getLogPackage(context, new VersionedPackage(failedPackageName, 0))); } return parentPackages; } static void logRollbackStatusOnBoot(Context context, int rollbackId, String logPackageName, List<RollbackInfo> recentlyCommittedRollbacks) { PackageInstaller packageInstaller = context.getPackageManager().getPackageInstaller(); Loading Loading @@ -174,10 +158,11 @@ public final class WatchdogRollbackLogger { */ public static void logEvent(@Nullable VersionedPackage logPackage, int type, int rollbackReason, @NonNull String failingPackageName) { Slog.i(TAG, "Watchdog event occurred with type: " + rollbackTypeToString(type) String logMsg = "Watchdog event occurred with type: " + rollbackTypeToString(type) + " logPackage: " + logPackage + " rollbackReason: " + rollbackReasonToString(rollbackReason) + " failedPackageName: " + failingPackageName); + " failedPackageName: " + failingPackageName; Slog.i(TAG, logMsg); if (logPackage != null) { CrashRecoveryStatsLog.write( CrashRecoveryStatsLog.WATCHDOG_ROLLBACK_OCCURRED, Loading @@ -200,33 +185,19 @@ public final class WatchdogRollbackLogger { new byte[]{}); } logTestProperties(logPackage, type, rollbackReason, failingPackageName); logTestProperties(logMsg); } /** * Writes properties which will be used by rollback tests to check if particular rollback * events have occurred. * * persist.sys.rollbacktest.enabled: true if rollback tests are running * persist.sys.rollbacktest.EVENT_TYPE: true if a particular rollback event has occurred * ex: persist.sys.rollbacktest.ROLLBACK_INITIATE is true if ROLLBACK_INITIATE has happened * persist.sys.rollbacktest.EVENT_TYPE.logPackage: the package to associate the rollback with * persist.sys.rollbacktest.EVENT_TYPE.rollbackReason: the reason Watchdog triggered a rollback * persist.sys.rollbacktest.EVENT_TYPE.failedPackageName: the failing package or process which * triggered the rollback */ private static void logTestProperties(@Nullable VersionedPackage logPackage, int type, int rollbackReason, @NonNull String failingPackageName) { private static void logTestProperties(String logMsg) { // This property should be on only during the tests final String prefix = "persist.sys.rollbacktest."; if (!SystemProperties.getBoolean(prefix + "enabled", false)) { if (!SystemProperties.getBoolean("persist.sys.rollbacktest.enabled", false)) { return; } String key = prefix + rollbackTypeToString(type); SystemProperties.set(key, String.valueOf(true)); SystemProperties.set(key + ".logPackage", logPackage != null ? logPackage.toString() : ""); SystemProperties.set(key + ".rollbackReason", rollbackReasonToString(rollbackReason)); SystemProperties.set(key + ".failedPackageName", failingPackageName); logCrashRecoveryEvent(Log.DEBUG, logMsg); } @VisibleForTesting Loading
tests/RollbackTest/lib/src/com/android/tests/rollback/host/WatchdogEventLogger.java +40 −27 Original line number Diff line number Diff line Loading @@ -16,33 +16,26 @@ package com.android.tests.rollback.host; import static com.google.common.truth.Truth.assertThat; import com.android.tradefed.device.ITestDevice; import com.android.tradefed.log.LogUtil.CLog; import com.google.common.truth.FailureMetadata; import com.google.common.truth.Truth; import static com.google.common.truth.Truth.assertThat; import java.util.regex.Matcher; import java.util.regex.Pattern; public class WatchdogEventLogger { private static final String[] ROLLBACK_EVENT_TYPES = { "ROLLBACK_INITIATE", "ROLLBACK_BOOT_TRIGGERED", "ROLLBACK_SUCCESS"}; private static final String[] ROLLBACK_EVENT_ATTRS = { "logPackage", "rollbackReason", "failedPackageName"}; private static final String PROP_PREFIX = "persist.sys.rollbacktest."; private ITestDevice mDevice; private void resetProperties(boolean enabled) throws Exception { private void updateTestSysProp(boolean enabled) throws Exception { try { mDevice.enableAdbRoot(); assertThat(mDevice.setProperty( PROP_PREFIX + "enabled", String.valueOf(enabled))).isTrue(); for (String type : ROLLBACK_EVENT_TYPES) { String key = PROP_PREFIX + type; assertThat(mDevice.setProperty(key, "")).isTrue(); for (String attr : ROLLBACK_EVENT_ATTRS) { assertThat(mDevice.setProperty(key + "." + attr, "")).isTrue(); } } "persist.sys.rollbacktest.enabled", String.valueOf(enabled))).isTrue(); } finally { mDevice.disableAdbRoot(); } Loading @@ -50,19 +43,17 @@ public class WatchdogEventLogger { public void start(ITestDevice device) throws Exception { mDevice = device; resetProperties(true); updateTestSysProp(true); } public void stop() throws Exception { if (mDevice != null) { resetProperties(false); updateTestSysProp(false); } } private boolean matchProperty(String type, String attr, String expectedVal) throws Exception { String key = PROP_PREFIX + type + "." + attr; String val = mDevice.getProperty(key); return expectedVal == null || expectedVal.equals(val); private boolean verifyEventContainsVal(String watchdogEvent, String expectedVal) { return expectedVal == null || watchdogEvent.contains(expectedVal); } /** Loading @@ -72,11 +63,33 @@ public class WatchdogEventLogger { * occurred, and return {@code true} if an event exists which matches all criteria. */ public boolean watchdogEventOccurred(String type, String logPackage, String rollbackReason, String failedPackageName) throws Exception { return mDevice.getBooleanProperty(PROP_PREFIX + type, false) && matchProperty(type, "logPackage", logPackage) && matchProperty(type, "rollbackReason", rollbackReason) && matchProperty(type, "failedPackageName", failedPackageName); String rollbackReason, String failedPackageName) { String watchdogEvent = getEventForRollbackType(type); return (watchdogEvent != null) && verifyEventContainsVal(watchdogEvent, logPackage) && verifyEventContainsVal(watchdogEvent, rollbackReason) && verifyEventContainsVal(watchdogEvent, failedPackageName); } /** Returns last matched event for rollbackType **/ private String getEventForRollbackType(String rollbackType) { String lastMatchedEvent = null; try { String rollbackDump = mDevice.executeShellCommand("dumpsys rollback"); String eventRegex = ".*%s%s(.*)\\n"; String eventPrefix = "Watchdog event occurred with type: "; final Pattern pattern = Pattern.compile( String.format(eventRegex, eventPrefix, rollbackType)); final Matcher matcher = pattern.matcher(rollbackDump); while (matcher.find()) { lastMatchedEvent = matcher.group(1); } CLog.d("Found watchdogEvent: " + lastMatchedEvent + " for type: " + rollbackType); } catch (Exception e) { CLog.e("Unable to find event for type: " + rollbackType, e); } return lastMatchedEvent; } static class Subject extends com.google.common.truth.Subject { Loading @@ -97,7 +110,7 @@ public class WatchdogEventLogger { } void eventOccurred(String type, String logPackage, String rollbackReason, String failedPackageName) throws Exception { String failedPackageName) { check("watchdogEventOccurred(type=%s, logPackage=%s, rollbackReason=%s, " + "failedPackageName=%s)", type, logPackage, rollbackReason, failedPackageName) .that(mActual.watchdogEventOccurred(type, logPackage, rollbackReason, Loading