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

Commit 6a126d83 authored by JW Wang's avatar JW Wang
Browse files

Use system properties to log rollback events 

Sometimes logcat messages are missing and causing rollback tests
to fail which check logcat messages to confirm some particular
rollback events have happened.

Let's use system properties as a reliable way to log rollback
events.

Bug: 171853854
Test: atest StagedRollbackTest NetworkStagedRollbackTest
Change-Id: Ia74da915811978008eed501049f5f44029e5c81a
parent d00e7d7c

services/core/java/com/android/server/rollback/WatchdogRollbackLogger.java

+29 −0
Original line number Diff line number Diff line
@@ -36,6 +36,7 @@ import android.content.pm.PackageManager; 
import android.content.pm.VersionedPackage;

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.Slog;
@@ -216,6 +217,34 @@ public final class WatchdogRollbackLogger { 
                    failingPackageName,

                    new byte[]{});

        }



        logTestProperties(logPackage, type, rollbackReason, failingPackageName);

    }



    /**

     * 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) {

        // This property should be on only during the tests

        final String prefix = "persist.sys.rollbacktest.";

        if (!SystemProperties.getBoolean(prefix + "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);

    }



    @VisibleForTesting

tests/RollbackTest/NetworkStagedRollbackTest/src/com/android/tests/rollback/host/NetworkStagedRollbackTest.java

+4 −9
Original line number Diff line number Diff line
@@ -16,8 +16,6 @@ 


package com.android.tests.rollback.host;



import static com.android.tests.rollback.host.WatchdogEventLogger.watchdogEventOccurred;



import static org.junit.Assert.assertEquals;

import static org.junit.Assert.assertTrue;
@@ -31,7 +29,6 @@ import org.junit.Rule; 
import org.junit.Test;

import org.junit.runner.RunWith;



import java.util.List;

import java.util.concurrent.TimeUnit;



/**
@@ -98,12 +95,11 @@ public class NetworkStagedRollbackTest extends BaseHostJUnit4Test { 
            // Verify rollback was executed after health check deadline

            runPhase("testNetworkFailedRollback_Phase3");



            List<String> watchdogEvents = mLogger.getWatchdogLoggingEvents();

            assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_INITIATE, null,

            assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_INITIATE, null,

                    REASON_EXPLICIT_HEALTH_CHECK, null));

            assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_BOOT_TRIGGERED, null,

            assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_BOOT_TRIGGERED, null,

                    null, null));

            assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_SUCCESS, null, null, null));

            assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_SUCCESS, null, null, null));

        } finally {

            // Reconnect internet again so we won't break tests which assume internet available

            getDevice().executeShellCommand("svc wifi enable");
@@ -134,8 +130,7 @@ public class NetworkStagedRollbackTest extends BaseHostJUnit4Test { 
        // Verify rollback was not executed after health check deadline

        runPhase("testNetworkPassedDoesNotRollback_Phase3");



        List<String> watchdogEvents = mLogger.getWatchdogLoggingEvents();

        assertEquals(watchdogEventOccurred(watchdogEvents, null, null,

        assertEquals(mLogger.watchdogEventOccurred(null, null,

                REASON_EXPLICIT_HEALTH_CHECK, null), false);

    }

}

tests/RollbackTest/StagedRollbackTest/src/com/android/tests/rollback/host/StagedRollbackTest.java

+12 −18
Original line number Diff line number Diff line
@@ -16,8 +16,6 @@ 


package com.android.tests.rollback.host;



import static com.android.tests.rollback.host.WatchdogEventLogger.watchdogEventOccurred;



import static com.google.common.truth.Truth.assertThat;



import static org.junit.Assert.assertEquals;
@@ -158,12 +156,11 @@ public class StagedRollbackTest extends BaseHostJUnit4Test { 


        runPhase("testBadApkOnly_Phase4");



        List<String> watchdogEvents = mLogger.getWatchdogLoggingEvents();

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_INITIATE, null,

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_INITIATE, null,

                REASON_APP_CRASH, TESTAPP_A));

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_BOOT_TRIGGERED, null,

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_BOOT_TRIGGERED, null,

                null, null));

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_SUCCESS, null, null, null));

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_SUCCESS, null, null, null));

    }



    @Test
@@ -192,12 +189,11 @@ public class StagedRollbackTest extends BaseHostJUnit4Test { 
        // verify rollback committed

        runPhase("testNativeWatchdogTriggersRollback_Phase3");



        List<String> watchdogEvents = mLogger.getWatchdogLoggingEvents();

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_INITIATE, null,

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_INITIATE, null,

                        REASON_NATIVE_CRASH, null));

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_BOOT_TRIGGERED, null,

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_BOOT_TRIGGERED, null,

                null, null));

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_SUCCESS, null, null, null));

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_SUCCESS, null, null, null));

    }



    @Test
@@ -233,12 +229,11 @@ public class StagedRollbackTest extends BaseHostJUnit4Test { 
        // verify all available rollbacks have been committed

        runPhase("testNativeWatchdogTriggersRollbackForAll_Phase4");



        List<String> watchdogEvents = mLogger.getWatchdogLoggingEvents();

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_INITIATE, null,

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_INITIATE, null,

                        REASON_NATIVE_CRASH, null));

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_BOOT_TRIGGERED, null,

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_BOOT_TRIGGERED, null,

                null, null));

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_SUCCESS, null, null, null));

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_SUCCESS, null, null, null));

    }



    /**
@@ -316,12 +311,11 @@ public class StagedRollbackTest extends BaseHostJUnit4Test { 
        // Verify rollback occurred due to crash of apk-in-apex

        runPhase("testRollbackApexWithApkCrashing_Phase3");



        List<String> watchdogEvents = mLogger.getWatchdogLoggingEvents();

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_INITIATE, null,

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_INITIATE, null,

                REASON_APP_CRASH, TESTAPP_A));

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_BOOT_TRIGGERED, null,

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_BOOT_TRIGGERED, null,

                null, null));

        assertTrue(watchdogEventOccurred(watchdogEvents, ROLLBACK_SUCCESS, null, null, null));

        assertTrue(mLogger.watchdogEventOccurred(ROLLBACK_SUCCESS, null, null, null));

    }



    /**

tests/RollbackTest/lib/src/com/android/tests/rollback/host/WatchdogEventLogger.java

+38 −62
Original line number Diff line number Diff line
@@ -17,52 +17,50 @@ 
package com.android.tests.rollback.host;



import com.android.tradefed.device.ITestDevice;

import com.android.tradefed.device.LogcatReceiver;

import com.android.tradefed.result.InputStreamSource;



import java.io.BufferedReader;

import java.io.InputStream;

import java.io.InputStreamReader;

import java.util.ArrayList;

import java.util.List;

import static com.google.common.truth.Truth.assertThat;



public class WatchdogEventLogger {

    private LogcatReceiver mReceiver;

    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.";



    public void start(ITestDevice device) {

        mReceiver =  new LogcatReceiver(device, "logcat -s WatchdogRollbackLogger",

                device.getOptions().getMaxLogcatDataSize(), 0);

        mReceiver.start();

    }

    private ITestDevice mDevice;



    public void stop() {

        if (mReceiver != null) {

            mReceiver.stop();

            mReceiver.clear();

    private void resetProperties(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();

                }

            }



    /**

     * Returns a list of all Watchdog logging events which have occurred.

     */

    public List<String> getWatchdogLoggingEvents() throws Exception {

        try (InputStreamSource logcatStream = mReceiver.getLogcatData()) {

            return getWatchdogLoggingEvents(logcatStream);

        } finally {

            mDevice.disableAdbRoot();

        }

    }



    private static List<String> getWatchdogLoggingEvents(InputStreamSource inputStreamSource)

            throws Exception {

        List<String> watchdogEvents = new ArrayList<>();

        InputStream inputStream = inputStreamSource.createInputStream();

        BufferedReader reader = new BufferedReader(new InputStreamReader(inputStream));

        String line;

        while ((line = reader.readLine()) != null) {

            if (line.contains("Watchdog event occurred")) {

                watchdogEvents.add(line);

    public void start(ITestDevice device) throws Exception {

        mDevice = device;

        resetProperties(true);

    }



    public void stop() throws Exception {

        if (mDevice != null) {

            resetProperties(false);

        }

    }

        return watchdogEvents;



    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);

    }



    /**
@@ -71,33 +69,11 @@ public class WatchdogEventLogger { 
     * Check the value of all non-null parameters against the list of Watchdog events that have

     * occurred, and return {@code true} if an event exists which matches all criteria.

     */

    public static boolean watchdogEventOccurred(List<String> loggingEvents,

            String type, String logPackage,

    public boolean watchdogEventOccurred(String type, String logPackage,

            String rollbackReason, String failedPackageName) throws Exception {

        List<String> eventCriteria = new ArrayList<>();

        if (type != null) {

            eventCriteria.add("type: " + type);

        }

        if (logPackage != null) {

            eventCriteria.add("logPackage: " + logPackage);

        }

        if (rollbackReason != null) {

            eventCriteria.add("rollbackReason: " + rollbackReason);

        }

        if (failedPackageName != null) {

            eventCriteria.add("failedPackageName: " + failedPackageName);

        }

        for (String loggingEvent: loggingEvents) {

            boolean matchesCriteria = true;

            for (String criterion: eventCriteria) {

                if (!loggingEvent.contains(criterion)) {

                    matchesCriteria = false;

                }

            }

            if (matchesCriteria) {

                return true;

            }

        }

        return false;

        return mDevice.getBooleanProperty(PROP_PREFIX + type, false)

                && matchProperty(type, "logPackage", logPackage)

                && matchProperty(type, "rollbackReason", rollbackReason)

                && matchProperty(type, "failedPackageName", failedPackageName);

    }

}