Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 1 | /* |
| 2 | * Copyright (C) 2018 The Android Open Source Project |
| 3 | * |
| 4 | * Licensed under the Apache License, Version 2.0 (the "License"); |
| 5 | * you may not use this file except in compliance with the License. |
| 6 | * You may obtain a copy of the License at |
| 7 | * |
| 8 | * http://www.apache.org/licenses/LICENSE-2.0 |
| 9 | * |
| 10 | * Unless required by applicable law or agreed to in writing, software |
| 11 | * distributed under the License is distributed on an "AS IS" BASIS, |
| 12 | * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| 13 | * See the License for the specific language governing permissions and |
| 14 | * limitations under the License |
| 15 | */ |
| 16 | |
Tadashi G. Takaoka | e2bd5c5 | 2019-04-15 14:29:33 +0900 | [diff] [blame] | 17 | package android.server.wm; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 18 | |
Vishnu Nair | 6caf417 | 2018-10-29 21:46:56 -0700 | [diff] [blame] | 19 | import static android.os.SystemClock.sleep; |
Riddle Hsu | d63da27 | 2020-02-14 00:13:35 +0800 | [diff] [blame] | 20 | import static android.server.wm.ActivityLauncher.KEY_LAUNCH_ACTIVITY; |
| 21 | import static android.server.wm.ActivityLauncher.KEY_TARGET_COMPONENT; |
Wale Ogunwale | cd73910 | 2020-01-29 06:15:52 -0800 | [diff] [blame] | 22 | import static android.server.wm.WindowManagerState.STATE_STOPPED; |
Tadashi G. Takaoka | e2bd5c5 | 2019-04-15 14:29:33 +0900 | [diff] [blame] | 23 | import static android.server.wm.app.Components.ENTRY_POINT_ALIAS_ACTIVITY; |
Riddle Hsu | d63da27 | 2020-02-14 00:13:35 +0800 | [diff] [blame] | 24 | import static android.server.wm.app.Components.LAUNCHING_ACTIVITY; |
Tadashi G. Takaoka | e2bd5c5 | 2019-04-15 14:29:33 +0900 | [diff] [blame] | 25 | import static android.server.wm.app.Components.NO_DISPLAY_ACTIVITY; |
| 26 | import static android.server.wm.app.Components.REPORT_FULLY_DRAWN_ACTIVITY; |
| 27 | import static android.server.wm.app.Components.SINGLE_TASK_ACTIVITY; |
| 28 | import static android.server.wm.app.Components.TEST_ACTIVITY; |
| 29 | import static android.server.wm.app.Components.TRANSLUCENT_TEST_ACTIVITY; |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 30 | import static android.server.wm.app.Components.TRANSLUCENT_TOP_ACTIVITY; |
| 31 | import static android.server.wm.app.Components.TopActivity.EXTRA_FINISH_IN_ON_CREATE; |
Tadashi G. Takaoka | e2bd5c5 | 2019-04-15 14:29:33 +0900 | [diff] [blame] | 32 | import static android.server.wm.second.Components.SECOND_ACTIVITY; |
| 33 | import static android.server.wm.third.Components.THIRD_ACTIVITY; |
Vishnu Nair | 86b03b8 | 2018-10-31 08:48:08 -0700 | [diff] [blame] | 34 | import static android.util.TimeUtils.formatDuration; |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 35 | |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 36 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION; |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 37 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_CANCELLED; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 38 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DELAY_MS; |
| 39 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_DEVICE_UPTIME_SECONDS; |
| 40 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN; |
| 41 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_REPORTED_DRAWN_MS; |
| 42 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_STARTING_WINDOW_DELAY_MS; |
| 43 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS; |
| 44 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.FIELD_CLASS_NAME; |
| 45 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_COLD_LAUNCH; |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 46 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_HOT_LAUNCH; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 47 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE; |
| 48 | import static com.android.internal.logging.nano.MetricsProto.MetricsEvent.TYPE_TRANSITION_WARM_LAUNCH; |
| 49 | |
| 50 | import static org.hamcrest.MatcherAssert.assertThat; |
| 51 | import static org.hamcrest.Matchers.containsString; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 52 | import static org.hamcrest.Matchers.greaterThanOrEqualTo; |
| 53 | import static org.hamcrest.Matchers.lessThanOrEqualTo; |
| 54 | import static org.junit.Assert.assertEquals; |
Riddle Hsu | 3c5a1da | 2019-11-27 00:24:44 +0800 | [diff] [blame] | 55 | import static org.junit.Assert.assertNotEquals; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 56 | import static org.junit.Assert.assertNotNull; |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 57 | import static org.junit.Assert.assertNull; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 58 | import static org.junit.Assert.fail; |
| 59 | |
| 60 | import android.app.Activity; |
| 61 | import android.content.ComponentName; |
| 62 | import android.metrics.LogMaker; |
| 63 | import android.metrics.MetricsReader; |
| 64 | import android.os.SystemClock; |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 65 | import android.platform.test.annotations.Presubmit; |
Riddle Hsu | b2452a3 | 2019-11-04 17:32:57 +0800 | [diff] [blame] | 66 | import android.server.wm.CommandSession.ActivitySessionClient; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 67 | import android.support.test.metricshelper.MetricsAsserts; |
| 68 | import android.util.EventLog.Event; |
| 69 | |
Charles Chen | 00a11b3 | 2019-11-04 15:46:08 +0800 | [diff] [blame] | 70 | |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 71 | import androidx.annotation.NonNull; |
| 72 | import androidx.annotation.Nullable; |
Charles Chen | 00a11b3 | 2019-11-04 15:46:08 +0800 | [diff] [blame] | 73 | |
Tadashi G. Takaoka | f280a9b | 2019-02-01 15:28:04 +0900 | [diff] [blame] | 74 | import com.android.compatibility.common.util.SystemUtil; |
| 75 | |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 76 | import org.hamcrest.collection.IsIn; |
| 77 | import org.junit.Before; |
| 78 | import org.junit.Test; |
| 79 | |
| 80 | import java.util.Arrays; |
| 81 | import java.util.List; |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 82 | import java.util.Objects; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 83 | import java.util.Queue; |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 84 | import java.util.concurrent.TimeUnit; |
Riddle Hsu | 3c5a1da | 2019-11-27 00:24:44 +0800 | [diff] [blame] | 85 | import java.util.function.IntConsumer; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 86 | |
| 87 | /** |
Tadashi G. Takaoka | f280a9b | 2019-02-01 15:28:04 +0900 | [diff] [blame] | 88 | * CTS device tests for {@link com.android.server.wm.ActivityMetricsLogger}. |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 89 | * Build/Install/Run: |
Tadashi G. Takaoka | e2bd5c5 | 2019-04-15 14:29:33 +0900 | [diff] [blame] | 90 | * atest CtsWindowManagerDeviceTestCases:ActivityMetricsLoggerTests |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 91 | */ |
Wale Ogunwale | 5871c5b | 2019-02-21 15:56:14 -0800 | [diff] [blame] | 92 | @Presubmit |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 93 | public class ActivityMetricsLoggerTests extends ActivityManagerTestBase { |
Vishnu Nair | 6caf417 | 2018-10-29 21:46:56 -0700 | [diff] [blame] | 94 | private static final String TAG_ATM = "ActivityTaskManager"; |
Riddle Hsu | d63da27 | 2020-02-14 00:13:35 +0800 | [diff] [blame] | 95 | private static final String LAUNCH_STATE_COLD = "COLD"; |
| 96 | private static final String LAUNCH_STATE_WARM = "WARM"; |
| 97 | private static final String LAUNCH_STATE_HOT = "HOT"; |
Riddle Hsu | 7efc47e | 2020-11-19 15:47:16 +0800 | [diff] [blame] | 98 | private static final String LAUNCH_STATE_RELAUNCH = "RELAUNCH"; |
Riddle Hsu | 3c5a1da | 2019-11-27 00:24:44 +0800 | [diff] [blame] | 99 | private static final int EVENT_WM_ACTIVITY_LAUNCH_TIME = 30009; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 100 | private final MetricsReader mMetricsReader = new MetricsReader(); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 101 | private long mPreUptimeMs; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 102 | private LogSeparator mLogSeparator; |
| 103 | |
| 104 | @Before |
| 105 | public void setUp() throws Exception { |
| 106 | super.setUp(); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 107 | mPreUptimeMs = SystemClock.uptimeMillis(); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 108 | mMetricsReader.checkpoint(); // clear out old logs |
| 109 | mLogSeparator = separateLogs(); // add a new separator for logs |
| 110 | } |
| 111 | |
| 112 | /** |
| 113 | * Launch an app and verify: |
| 114 | * - appropriate metrics logs are added |
| 115 | * - "Displayed activity ..." log is added to logcat |
| 116 | * - am_activity_launch_time event is generated |
| 117 | * In all three cases, verify the delay measurements are the same. |
| 118 | */ |
| 119 | @Test |
| 120 | public void testAppLaunchIsLogged() { |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 121 | launchAndWaitForActivity(TEST_ACTIVITY); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 122 | |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 123 | final LogMaker metricsLog = waitForMetricsLog(TEST_ACTIVITY, APP_TRANSITION); |
Vishnu Nair | 6caf417 | 2018-10-29 21:46:56 -0700 | [diff] [blame] | 124 | final String[] deviceLogs = getDeviceLogsForComponents(mLogSeparator, TAG_ATM); |
| 125 | final List<Event> eventLogs = getEventLogsForComponents(mLogSeparator, |
Riddle Hsu | 3c5a1da | 2019-11-27 00:24:44 +0800 | [diff] [blame] | 126 | EVENT_WM_ACTIVITY_LAUNCH_TIME); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 127 | |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 128 | final long postUptimeMs = SystemClock.uptimeMillis(); |
| 129 | assertMetricsLogs(TEST_ACTIVITY, APP_TRANSITION, metricsLog, mPreUptimeMs, postUptimeMs); |
Vishnu Nair | ce3ba63 | 2018-11-16 07:50:27 -0800 | [diff] [blame] | 130 | assertTransitionIsStartingWindow(metricsLog); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 131 | final int windowsDrawnDelayMs = |
| 132 | (int) metricsLog.getTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS); |
| 133 | final String expectedLog = |
| 134 | "Displayed " + TEST_ACTIVITY.flattenToShortString() |
Vishnu Nair | 86b03b8 | 2018-10-31 08:48:08 -0700 | [diff] [blame] | 135 | + ": " + formatDuration(windowsDrawnDelayMs); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 136 | assertLogsContain(deviceLogs, expectedLog); |
| 137 | assertEventLogsContainsLaunchTime(eventLogs, TEST_ACTIVITY, windowsDrawnDelayMs); |
| 138 | } |
| 139 | |
| 140 | private void assertMetricsLogs(ComponentName componentName, |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 141 | int category, LogMaker log, long preUptimeMs, long postUptimeMs) { |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 142 | assertNotNull("did not find the metrics log for: " + componentName |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 143 | + " category:" + categoryToString(category), log); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 144 | int startUptimeSec = |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 145 | ((Number) log.getTaggedData(APP_TRANSITION_DEVICE_UPTIME_SECONDS)).intValue(); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 146 | int preUptimeSec = (int) (TimeUnit.MILLISECONDS.toSeconds(preUptimeMs)); |
| 147 | int postUptimeSec = (int) (TimeUnit.MILLISECONDS.toSeconds(postUptimeMs)); |
| 148 | long testElapsedTimeMs = postUptimeMs - preUptimeMs; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 149 | assertThat("must be either cold or warm launch", log.getType(), |
| 150 | IsIn.oneOf(TYPE_TRANSITION_COLD_LAUNCH, TYPE_TRANSITION_WARM_LAUNCH)); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 151 | assertThat("reported uptime should be after the app was started", startUptimeSec, |
| 152 | greaterThanOrEqualTo(preUptimeSec)); |
| 153 | assertThat("reported uptime should be before assertion time", startUptimeSec, |
| 154 | lessThanOrEqualTo(postUptimeSec)); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 155 | assertNotNull("log should have delay", log.getTaggedData(APP_TRANSITION_DELAY_MS)); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 156 | assertNotNull("log should have windows drawn delay", |
| 157 | log.getTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS)); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 158 | long windowsDrawnDelayMs = (int) log.getTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS); |
| 159 | assertThat("windows drawn delay should be less that total elapsed time", |
| 160 | windowsDrawnDelayMs, lessThanOrEqualTo(testElapsedTimeMs)); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 161 | } |
| 162 | |
Vishnu Nair | ce3ba63 | 2018-11-16 07:50:27 -0800 | [diff] [blame] | 163 | private void assertTransitionIsStartingWindow(LogMaker log) { |
| 164 | assertEquals("transition should be started because of starting window", |
| 165 | 1 /* APP_TRANSITION_STARTING_WINDOW */, log.getSubtype()); |
| 166 | assertNotNull("log should have starting window delay", |
| 167 | log.getTaggedData(APP_TRANSITION_STARTING_WINDOW_DELAY_MS)); |
| 168 | } |
| 169 | |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 170 | private void assertEventLogsContainsLaunchTime(List<Event> events, ComponentName componentName, |
| 171 | int windowsDrawnDelayMs) { |
Riddle Hsu | 3c5a1da | 2019-11-27 00:24:44 +0800 | [diff] [blame] | 172 | verifyLaunchTimeEventLogs(events, componentName, |
| 173 | delay -> assertEquals("Unexpected windows drawn delay for " + componentName, |
| 174 | delay, windowsDrawnDelayMs)); |
| 175 | } |
| 176 | |
| 177 | private void verifyLaunchTimeEventLogs(List<Event> launchTimeEvents, |
| 178 | ComponentName componentName, IntConsumer launchTimeVerifier) { |
| 179 | for (Event event : launchTimeEvents) { |
| 180 | final Object[] arr = (Object[]) event.getData(); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 181 | assertEquals(4, arr.length); |
| 182 | final String name = (String) arr[2]; |
Riddle Hsu | 3c5a1da | 2019-11-27 00:24:44 +0800 | [diff] [blame] | 183 | final int launchTime = (int) arr[3]; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 184 | if (name.equals(componentName.flattenToShortString())) { |
Riddle Hsu | 3c5a1da | 2019-11-27 00:24:44 +0800 | [diff] [blame] | 185 | launchTimeVerifier.accept(launchTime); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 186 | return; |
| 187 | } |
| 188 | } |
Riddle Hsu | 3c5a1da | 2019-11-27 00:24:44 +0800 | [diff] [blame] | 189 | fail("Could not find wm_activity_launch_time for " + componentName); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 190 | } |
| 191 | |
| 192 | /** |
| 193 | * Start an activity that reports full drawn and verify: |
| 194 | * - fully drawn metrics are added to metrics logs |
| 195 | * - "Fully drawn activity ..." log is added to logcat |
| 196 | * In both cases verify fully drawn delay measurements are equal. |
| 197 | * See {@link Activity#reportFullyDrawn()} |
| 198 | */ |
| 199 | @Test |
| 200 | public void testAppFullyDrawnReportIsLogged() { |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 201 | launchAndWaitForActivity(REPORT_FULLY_DRAWN_ACTIVITY); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 202 | |
| 203 | // Sleep until activity under test has reported drawn (after 500ms) |
Vishnu Nair | 6caf417 | 2018-10-29 21:46:56 -0700 | [diff] [blame] | 204 | sleep(1000); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 205 | |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 206 | final LogMaker metricsLog = waitForMetricsLog(REPORT_FULLY_DRAWN_ACTIVITY, |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 207 | APP_TRANSITION_REPORTED_DRAWN); |
Vishnu Nair | 6caf417 | 2018-10-29 21:46:56 -0700 | [diff] [blame] | 208 | final String[] deviceLogs = getDeviceLogsForComponents(mLogSeparator, TAG_ATM); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 209 | |
| 210 | assertNotNull("did not find the metrics log for: " + REPORT_FULLY_DRAWN_ACTIVITY |
| 211 | + " category:" + APP_TRANSITION_REPORTED_DRAWN, metricsLog); |
| 212 | assertThat("test activity has a 500ms delay before reporting fully drawn", |
| 213 | (long) metricsLog.getTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS), |
| 214 | greaterThanOrEqualTo(500L)); |
| 215 | assertEquals(TYPE_TRANSITION_REPORTED_DRAWN_NO_BUNDLE, metricsLog.getType()); |
| 216 | |
| 217 | final long fullyDrawnDelayMs = |
| 218 | (long) metricsLog.getTaggedData(APP_TRANSITION_REPORTED_DRAWN_MS); |
| 219 | final String expectedLog = |
| 220 | "Fully drawn " + REPORT_FULLY_DRAWN_ACTIVITY.flattenToShortString() |
Vishnu Nair | 86b03b8 | 2018-10-31 08:48:08 -0700 | [diff] [blame] | 221 | + ": " + formatDuration(fullyDrawnDelayMs); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 222 | assertLogsContain(deviceLogs, expectedLog); |
| 223 | } |
| 224 | |
| 225 | /** |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 226 | * Warm launch an activity with wait option and verify that {@link android.app.WaitResult#totalTime} |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 227 | * totalTime is set correctly. Make sure the reported value is consistent with value reported to |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 228 | * metrics logs. Verify we output the correct launch state. |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 229 | */ |
| 230 | @Test |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 231 | public void testAppWarmLaunchSetsWaitResultDelayData() { |
Riddle Hsu | b2452a3 | 2019-11-04 17:32:57 +0800 | [diff] [blame] | 232 | try (ActivitySessionClient client = createActivitySessionClient()) { |
| 233 | client.startActivity(getLaunchActivityBuilder() |
| 234 | .setUseInstrumentation() |
| 235 | .setTargetActivity(TEST_ACTIVITY) |
| 236 | .setWaitForLaunched(true)); |
| 237 | separateTestJournal(); |
| 238 | // The activity will be finished when closing the session client. |
| 239 | } |
| 240 | assertActivityDestroyed(TEST_ACTIVITY); |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 241 | mMetricsReader.checkpoint(); // clear out old logs |
| 242 | |
Riddle Hsu | b2452a3 | 2019-11-04 17:32:57 +0800 | [diff] [blame] | 243 | // This is warm launch because its process should be alive after the above steps. |
Tadashi G. Takaoka | f280a9b | 2019-02-01 15:28:04 +0900 | [diff] [blame] | 244 | final String amStartOutput = SystemUtil.runShellCommand( |
| 245 | "am start -W " + TEST_ACTIVITY.flattenToShortString()); |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 246 | |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 247 | final LogMaker metricsLog = waitForMetricsLog(TEST_ACTIVITY, APP_TRANSITION); |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 248 | final int windowsDrawnDelayMs = |
| 249 | (int) metricsLog.getTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS); |
| 250 | |
| 251 | assertEquals("Expected a cold launch.", metricsLog.getType(), TYPE_TRANSITION_WARM_LAUNCH); |
| 252 | |
Riddle Hsu | d63da27 | 2020-02-14 00:13:35 +0800 | [diff] [blame] | 253 | assertLaunchComponentStateAndTime(amStartOutput, TEST_ACTIVITY, LAUNCH_STATE_WARM, |
| 254 | windowsDrawnDelayMs); |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 255 | } |
| 256 | |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 257 | /** |
| 258 | * Hot launch an activity with wait option and verify that {@link android.app.WaitResult#totalTime} |
| 259 | * totalTime is set correctly. Make sure the reported value is consistent with value reported to |
| 260 | * metrics logs. Verify we output the correct launch state. |
| 261 | */ |
| 262 | @Test |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 263 | public void testAppHotLaunchSetsWaitResultDelayData() { |
Tadashi G. Takaoka | f280a9b | 2019-02-01 15:28:04 +0900 | [diff] [blame] | 264 | SystemUtil.runShellCommand("am start -S -W " + TEST_ACTIVITY.flattenToShortString()); |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 265 | |
| 266 | // Test hot launch |
Riddle Hsu | 79c77e0 | 2019-09-23 23:56:41 +0800 | [diff] [blame] | 267 | launchHomeActivityNoWait(); |
Riddle Hsu | b2452a3 | 2019-11-04 17:32:57 +0800 | [diff] [blame] | 268 | waitAndAssertActivityState(TEST_ACTIVITY, STATE_STOPPED, "Activity should be stopped"); |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 269 | mMetricsReader.checkpoint(); // clear out old logs |
| 270 | |
Tadashi G. Takaoka | f280a9b | 2019-02-01 15:28:04 +0900 | [diff] [blame] | 271 | final String amStartOutput = SystemUtil.runShellCommand( |
| 272 | "am start -W " + TEST_ACTIVITY.flattenToShortString()); |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 273 | |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 274 | final LogMaker metricsLog = waitForMetricsLog(TEST_ACTIVITY, APP_TRANSITION); |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 275 | final int windowsDrawnDelayMs = |
| 276 | (int) metricsLog.getTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS); |
| 277 | |
| 278 | assertEquals("Expected a cold launch.", metricsLog.getType(), TYPE_TRANSITION_HOT_LAUNCH); |
| 279 | |
Riddle Hsu | d63da27 | 2020-02-14 00:13:35 +0800 | [diff] [blame] | 280 | assertLaunchComponentStateAndTime(amStartOutput, TEST_ACTIVITY, LAUNCH_STATE_HOT, |
| 281 | windowsDrawnDelayMs); |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 282 | } |
| 283 | |
Tadashi G. Takaoka | f34fd01 | 2019-04-18 10:18:02 +0900 | [diff] [blame] | 284 | /** |
Riddle Hsu | 7efc47e | 2020-11-19 15:47:16 +0800 | [diff] [blame] | 285 | * Launch an existing background activity after the device configuration is changed and the |
| 286 | * activity doesn't declare to handle the change. The state should be RELAUNCH instead of HOT. |
| 287 | */ |
| 288 | @Test |
| 289 | public void testAppRelaunchSetsWaitResultDelayData() { |
| 290 | final String startTestActivityCmd = "am start -W " + TEST_ACTIVITY.flattenToShortString(); |
| 291 | SystemUtil.runShellCommand(startTestActivityCmd); |
| 292 | |
| 293 | // Launch another task and make sure a configuration change triggers relaunch. |
| 294 | launchAndWaitForActivity(SECOND_ACTIVITY); |
Jing Ji | a2e87c3 | 2021-02-02 17:53:13 -0800 | [diff] [blame] | 295 | separateTestJournal(); |
| 296 | |
Riddle Hsu | 7efc47e | 2020-11-19 15:47:16 +0800 | [diff] [blame] | 297 | final FontScaleSession fontScaleSession = mObjectTracker.manage(new FontScaleSession()); |
| 298 | final Float originalScale = fontScaleSession.get(); |
| 299 | fontScaleSession.set((originalScale == null ? 1f : originalScale) + 0.1f); |
| 300 | assertActivityLifecycle(SECOND_ACTIVITY, true /* relaunched */); |
| 301 | |
| 302 | // Move the task of test activity to front. |
| 303 | final String amStartOutput = SystemUtil.runShellCommand(startTestActivityCmd); |
| 304 | assertLaunchComponentState(amStartOutput, TEST_ACTIVITY, LAUNCH_STATE_RELAUNCH); |
| 305 | } |
| 306 | |
| 307 | /** |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 308 | * Cold launch an activity with wait option and verify that {@link android.app.WaitResult#totalTime} |
| 309 | * totalTime is set correctly. Make sure the reported value is consistent with value reported to |
| 310 | * metrics logs. Verify we output the correct launch state. |
| 311 | */ |
| 312 | @Test |
Vishnu Nair | 9fc15c9 | 2018-12-21 08:28:24 -0800 | [diff] [blame] | 313 | public void testAppColdLaunchSetsWaitResultDelayData() { |
Tadashi G. Takaoka | f280a9b | 2019-02-01 15:28:04 +0900 | [diff] [blame] | 314 | final String amStartOutput = SystemUtil.runShellCommand( |
| 315 | "am start -S -W " + TEST_ACTIVITY.flattenToShortString()); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 316 | |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 317 | final LogMaker metricsLog = waitForMetricsLog(TEST_ACTIVITY, APP_TRANSITION); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 318 | final int windowsDrawnDelayMs = |
| 319 | (int) metricsLog.getTaggedData(APP_TRANSITION_WINDOWS_DRAWN_DELAY_MS); |
| 320 | |
| 321 | assertEquals("Expected a cold launch.", metricsLog.getType(), TYPE_TRANSITION_COLD_LAUNCH); |
| 322 | |
Riddle Hsu | d63da27 | 2020-02-14 00:13:35 +0800 | [diff] [blame] | 323 | assertLaunchComponentStateAndTime(amStartOutput, TEST_ACTIVITY, LAUNCH_STATE_COLD, |
| 324 | windowsDrawnDelayMs); |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 325 | } |
| 326 | |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 327 | /** |
| 328 | * Launch an app that is already visible and verify we handle cases where we will not |
| 329 | * receive a windows drawn message. |
| 330 | * see b/117148004 |
| 331 | */ |
| 332 | @Test |
| 333 | public void testLaunchOfVisibleApp() { |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 334 | // Launch an activity. |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 335 | launchAndWaitForActivity(SECOND_ACTIVITY); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 336 | |
| 337 | // Launch a translucent activity on top. |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 338 | launchAndWaitForActivity(TRANSLUCENT_TEST_ACTIVITY); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 339 | |
| 340 | // Launch the first activity again. This will not trigger a windows drawn message since |
| 341 | // its windows were visible before launching. |
| 342 | mMetricsReader.checkpoint(); // clear out old logs |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 343 | launchAndWaitForActivity(SECOND_ACTIVITY); |
| 344 | |
Vishnu Nair | 6caf417 | 2018-10-29 21:46:56 -0700 | [diff] [blame] | 345 | LogMaker metricsLog = getMetricsLog(SECOND_ACTIVITY, APP_TRANSITION); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 346 | // Verify transition logs are absent since we cannot measure windows drawn delay. |
| 347 | assertNull("transition logs should be reset.", metricsLog); |
| 348 | |
| 349 | // Verify metrics for subsequent launches are generated as expected. |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 350 | mPreUptimeMs = SystemClock.uptimeMillis(); |
| 351 | mMetricsReader.checkpoint(); // clear out old logs |
| 352 | |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 353 | launchAndWaitForActivity(THIRD_ACTIVITY); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 354 | |
| 355 | long postUptimeMs = SystemClock.uptimeMillis(); |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 356 | metricsLog = waitForMetricsLog(THIRD_ACTIVITY, APP_TRANSITION); |
Vishnu Nair | 6caf417 | 2018-10-29 21:46:56 -0700 | [diff] [blame] | 357 | assertMetricsLogs(THIRD_ACTIVITY, APP_TRANSITION, metricsLog, mPreUptimeMs, |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 358 | postUptimeMs); |
Vishnu Nair | ce3ba63 | 2018-11-16 07:50:27 -0800 | [diff] [blame] | 359 | assertTransitionIsStartingWindow(metricsLog); |
| 360 | } |
| 361 | |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 362 | @Test |
| 363 | public void testAppLaunchCancelledSameTask() { |
| 364 | launchAndWaitForActivity(TEST_ACTIVITY); |
| 365 | |
| 366 | // Start a non-opaque activity in a different process in the same task. |
| 367 | getLaunchActivityBuilder() |
| 368 | .setUseInstrumentation() |
| 369 | .setTargetActivity(TRANSLUCENT_TOP_ACTIVITY) |
| 370 | .setIntentExtra(extra -> extra.putBoolean(EXTRA_FINISH_IN_ON_CREATE, true)) |
| 371 | .setWaitForLaunched(false) |
| 372 | .execute(); |
| 373 | |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 374 | final LogMaker metricsLog = waitForMetricsLog(TRANSLUCENT_TOP_ACTIVITY, |
| 375 | APP_TRANSITION_CANCELLED); |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 376 | |
| 377 | assertNotNull("Metrics log APP_TRANSITION_CANCELLED not found", metricsLog); |
| 378 | } |
| 379 | |
Vishnu Nair | ce3ba63 | 2018-11-16 07:50:27 -0800 | [diff] [blame] | 380 | /** |
| 381 | * Launch a NoDisplay activity and verify it does not affect subsequent activity launch |
| 382 | * metrics. NoDisplay activities do not draw any windows and may be incorrectly identified as a |
| 383 | * trampoline activity. See b/80380150 (Long warm launch times reported in dev play console) |
| 384 | */ |
| 385 | @Test |
| 386 | public void testNoDisplayActivityLaunch() { |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 387 | launchAndWaitForActivity(NO_DISPLAY_ACTIVITY); |
Vishnu Nair | ce3ba63 | 2018-11-16 07:50:27 -0800 | [diff] [blame] | 388 | |
| 389 | mPreUptimeMs = SystemClock.uptimeMillis(); |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 390 | launchAndWaitForActivity(SECOND_ACTIVITY); |
| 391 | |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 392 | final LogMaker metricsLog = waitForMetricsLog(SECOND_ACTIVITY, APP_TRANSITION); |
Vishnu Nair | ce3ba63 | 2018-11-16 07:50:27 -0800 | [diff] [blame] | 393 | final long postUptimeMs = SystemClock.uptimeMillis(); |
| 394 | assertMetricsLogs(SECOND_ACTIVITY, APP_TRANSITION, metricsLog, mPreUptimeMs, postUptimeMs); |
| 395 | assertTransitionIsStartingWindow(metricsLog); |
| 396 | } |
| 397 | |
| 398 | /** |
| 399 | * Launch an activity with a trampoline activity and verify launch metrics measures the complete |
| 400 | * launch sequence from when the trampoline activity is launching to when the target activity |
| 401 | * draws on screen. |
| 402 | */ |
| 403 | @Test |
| 404 | public void testTrampolineActivityLaunch() { |
| 405 | // Launch a trampoline activity that will launch single task activity. |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 406 | launchAndWaitForActivity(ENTRY_POINT_ALIAS_ACTIVITY); |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 407 | final LogMaker metricsLog = waitForMetricsLog(SINGLE_TASK_ACTIVITY, APP_TRANSITION); |
Vishnu Nair | ce3ba63 | 2018-11-16 07:50:27 -0800 | [diff] [blame] | 408 | final long postUptimeMs = SystemClock.uptimeMillis(); |
| 409 | assertMetricsLogs(SINGLE_TASK_ACTIVITY, APP_TRANSITION, metricsLog, mPreUptimeMs, |
| 410 | postUptimeMs); |
Vishnu Nair | 1cb588a | 2018-10-11 10:07:55 -0700 | [diff] [blame] | 411 | } |
| 412 | |
Riddle Hsu | d63da27 | 2020-02-14 00:13:35 +0800 | [diff] [blame] | 413 | /** |
| 414 | * Launch an activity which will start another activity immediately. The reported component |
| 415 | * name should be the last one with valid launch state. |
| 416 | */ |
| 417 | @Test |
| 418 | public void testConsecutiveLaunch() { |
| 419 | final String amStartOutput = executeShellCommand("am start --ez " + KEY_LAUNCH_ACTIVITY |
| 420 | + " true --es " + KEY_TARGET_COMPONENT + " " + TEST_ACTIVITY.flattenToShortString() |
| 421 | + " -W " + LAUNCHING_ACTIVITY.flattenToShortString()); |
| 422 | assertLaunchComponentState(amStartOutput, TEST_ACTIVITY, LAUNCH_STATE_COLD); |
| 423 | } |
| 424 | |
Riddle Hsu | 3c5a1da | 2019-11-27 00:24:44 +0800 | [diff] [blame] | 425 | @Test |
| 426 | public void testLaunchTimeEventLogNonProcessSwitch() { |
| 427 | launchAndWaitForActivity(SINGLE_TASK_ACTIVITY); |
| 428 | mLogSeparator = separateLogs(); |
| 429 | |
| 430 | // Launch another activity in the same process. |
| 431 | launchAndWaitForActivity(TEST_ACTIVITY); |
| 432 | final List<Event> eventLogs = getEventLogsForComponents(mLogSeparator, |
| 433 | EVENT_WM_ACTIVITY_LAUNCH_TIME); |
| 434 | verifyLaunchTimeEventLogs(eventLogs, TEST_ACTIVITY, time -> assertNotEquals(0, time)); |
| 435 | } |
| 436 | |
Riddle Hsu | 230d231 | 2019-10-29 14:47:14 +0800 | [diff] [blame] | 437 | private void launchAndWaitForActivity(ComponentName activity) { |
| 438 | getLaunchActivityBuilder() |
| 439 | .setUseInstrumentation() |
| 440 | .setTargetActivity(activity) |
| 441 | .setWaitForLaunched(true) |
| 442 | .execute(); |
| 443 | } |
| 444 | |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 445 | @NonNull |
| 446 | private LogMaker waitForMetricsLog(ComponentName componentName, int category) { |
| 447 | final String categoryName = categoryToString(category); |
| 448 | final String message = componentName.toShortString() + " with category " + categoryName; |
| 449 | final LogMaker metricsLog = Condition.waitForResult(new Condition<LogMaker>(message) |
| 450 | .setResultSupplier(() -> getMetricsLog(componentName, category)) |
| 451 | .setResultValidator(Objects::nonNull)); |
| 452 | if (metricsLog != null) { |
| 453 | return metricsLog; |
| 454 | } |
| 455 | |
| 456 | // Fallback to check again from raw event log. Not sure if sometimes MetricsAsserts cannot |
| 457 | // find the expected log. |
| 458 | final LogMaker template = new LogMaker(category); |
| 459 | final List<Event> eventLogs = getEventLogsForComponents(mLogSeparator, |
| 460 | android.util.EventLog.getTagCode("sysui_multi_action")); |
| 461 | for (Event event : eventLogs) { |
| 462 | final LogMaker log = new LogMaker((Object[]) event.getData()); |
| 463 | if (isComponentMatched(log, componentName) && template.isSubsetOf(log)) { |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 464 | return log; |
| 465 | } |
| 466 | } |
Riddle Hsu | 6caae9c | 2020-03-11 18:06:24 +0800 | [diff] [blame] | 467 | |
| 468 | throw new AssertionError("Log should have " + categoryName + " of " + componentName); |
| 469 | } |
| 470 | |
| 471 | @Nullable |
| 472 | private LogMaker getMetricsLog(ComponentName componentName, int category) { |
| 473 | final Queue<LogMaker> startLogs = MetricsAsserts.findMatchingLogs(mMetricsReader, |
| 474 | new LogMaker(category)); |
| 475 | return startLogs.stream().filter(log -> isComponentMatched(log, componentName)) |
| 476 | .findFirst().orElse(null); |
| 477 | } |
| 478 | |
| 479 | private static boolean isComponentMatched(LogMaker log, ComponentName componentName) { |
| 480 | final String actualClassName = (String) log.getTaggedData(FIELD_CLASS_NAME); |
| 481 | final String actualPackageName = log.getPackageName(); |
| 482 | return componentName.getClassName().equals(actualClassName) && |
| 483 | componentName.getPackageName().equals(actualPackageName); |
| 484 | } |
| 485 | |
| 486 | private static String categoryToString(int category) { |
| 487 | return (category == APP_TRANSITION ? "APP_TRANSITION" |
| 488 | : category == APP_TRANSITION_CANCELLED ? "APP_TRANSITION_CANCELLED" |
| 489 | : category == APP_TRANSITION_REPORTED_DRAWN ? "APP_TRANSITION_REPORTED_DRAWN" |
| 490 | : "Unknown") + "(" + category + ")"; |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 491 | } |
| 492 | |
Riddle Hsu | d63da27 | 2020-02-14 00:13:35 +0800 | [diff] [blame] | 493 | private static void assertLaunchComponentState(String amStartOutput, ComponentName component, |
| 494 | String state) { |
| 495 | assertThat("did not find component in am start output.", amStartOutput, |
| 496 | containsString(component.flattenToShortString())); |
| 497 | assertThat("did not find launch state in am start output.", amStartOutput, |
| 498 | containsString(state)); |
| 499 | } |
| 500 | |
| 501 | private static void assertLaunchComponentStateAndTime(String amStartOutput, |
| 502 | ComponentName component, String state, int windowsDrawnDelayMs) { |
| 503 | assertLaunchComponentState(amStartOutput, component, state); |
| 504 | assertThat("did not find windows drawn delay time in am start output.", amStartOutput, |
| 505 | containsString(Integer.toString(windowsDrawnDelayMs))); |
| 506 | } |
| 507 | |
Vishnu Nair | 8e3f5f7 | 2018-10-01 11:12:51 -0700 | [diff] [blame] | 508 | private void assertLogsContain(String[] logs, String expectedLog) { |
| 509 | for (String line : logs) { |
| 510 | if (line.contains(expectedLog)) { |
| 511 | return; |
| 512 | } |
| 513 | } |
| 514 | fail("Expected to find '" + expectedLog + "' in " + Arrays.toString(logs)); |
| 515 | } |
| 516 | } |