Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 1 | /* |
| 2 | * Copyright 2017 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 | |
Alan Stokes | 55d11f6 | 2018-01-09 10:04:21 +0000 | [diff] [blame] | 17 | package com.android.server.pm.dex; |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 18 | |
| 19 | import static com.google.common.truth.Truth.assertThat; |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 20 | import static com.google.common.truth.Truth.assertWithMessage; |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 21 | |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 22 | import android.app.UiAutomation; |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 23 | import android.content.Context; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 24 | import android.os.ParcelFileDescriptor; |
| 25 | import android.os.SystemClock; |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 26 | import android.support.test.InstrumentationRegistry; |
Alan Stokes | 55d11f6 | 2018-01-09 10:04:21 +0000 | [diff] [blame] | 27 | import android.support.test.filters.LargeTest; |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 28 | import android.util.EventLog; |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 29 | import android.util.EventLog.Event; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 30 | |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 31 | import dalvik.system.DexClassLoader; |
| 32 | |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 33 | import org.junit.Before; |
| 34 | import org.junit.BeforeClass; |
| 35 | import org.junit.Test; |
| 36 | import org.junit.runner.RunWith; |
| 37 | import org.junit.runners.JUnit4; |
| 38 | |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 39 | import java.io.ByteArrayOutputStream; |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 40 | import java.io.File; |
| 41 | import java.io.FileOutputStream; |
| 42 | import java.io.InputStream; |
| 43 | import java.io.OutputStream; |
| 44 | import java.security.MessageDigest; |
| 45 | import java.util.ArrayList; |
| 46 | import java.util.Formatter; |
| 47 | import java.util.List; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 48 | import java.util.concurrent.TimeUnit; |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 49 | |
| 50 | /** |
| 51 | * Integration tests for {@link com.android.server.pm.dex.DexLogger}. |
| 52 | * |
| 53 | * The setup for the test dynamically loads code in a jar extracted |
| 54 | * from our assets (a secondary dex file). |
| 55 | * |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 56 | * We then use shell commands to trigger dynamic code logging (and wait |
| 57 | * for it to complete). This causes DexLogger to log the hash of the |
| 58 | * file's name and content. We verify that this message appears in |
| 59 | * the event log. |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 60 | * |
| 61 | * Run with "atest DexLoggerIntegrationTests". |
| 62 | */ |
Alan Stokes | 55d11f6 | 2018-01-09 10:04:21 +0000 | [diff] [blame] | 63 | @LargeTest |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 64 | @RunWith(JUnit4.class) |
| 65 | public final class DexLoggerIntegrationTests { |
| 66 | |
Alan Stokes | 1e24bf6 | 2018-01-05 14:36:00 +0000 | [diff] [blame] | 67 | // Event log tag used for SNET related events |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 68 | private static final int SNET_TAG = 0x534e4554; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 69 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 70 | // Subtags used to distinguish dynamic code loading events |
| 71 | private static final String DCL_DEX_SUBTAG = "dcl"; |
| 72 | private static final String DCL_NATIVE_SUBTAG = "dcln"; |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 73 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 74 | // These are job IDs from DynamicCodeLoggingService |
| 75 | private static final int IDLE_LOGGING_JOB_ID = 2030028; |
| 76 | private static final int AUDIT_WATCHING_JOB_ID = 203142925; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 77 | |
| 78 | private static Context sContext; |
| 79 | private static int sMyUid; |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 80 | |
| 81 | @BeforeClass |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 82 | public static void setUpAll() { |
| 83 | sContext = InstrumentationRegistry.getTargetContext(); |
| 84 | sMyUid = android.os.Process.myUid(); |
| 85 | } |
| 86 | |
| 87 | @Before |
| 88 | public void primeEventLog() { |
| 89 | // Force a round trip to logd to make sure everything is up to date. |
| 90 | // Without this the first test passes and others don't - we don't see new events in the |
| 91 | // log. The exact reason is unclear. |
| 92 | EventLog.writeEvent(SNET_TAG, "Dummy event"); |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 93 | |
| 94 | // Audit log messages are throttled by the kernel (at the request of logd) to 5 per |
| 95 | // second, so running the tests too quickly in sequence means we lose some and get |
| 96 | // spurious failures. Sigh. |
| 97 | SystemClock.sleep(1000); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 98 | } |
| 99 | |
| 100 | @Test |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 101 | public void testDexLoggerGeneratesEvents_standardClassLoader() throws Exception { |
| 102 | File privateCopyFile = privateFile("copied.jar"); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 103 | // Obtained via "echo -n copied.jar | sha256sum" |
| 104 | String expectedNameHash = |
| 105 | "1B6C71DB26F36582867432CCA12FB6A517470C9F9AABE9198DD4C5C030D6DC0C"; |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 106 | String expectedContentHash = copyAndHashResource("/javalib.jar", privateCopyFile); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 107 | |
| 108 | // Feed the jar to a class loader and make sure it contains what we expect. |
| 109 | ClassLoader parentClassLoader = sContext.getClass().getClassLoader(); |
| 110 | ClassLoader loader = |
| 111 | new DexClassLoader(privateCopyFile.toString(), null, null, parentClassLoader); |
| 112 | loader.loadClass("com.android.dcl.Simple"); |
| 113 | |
| 114 | // And make sure we log events about it |
| 115 | long previousEventNanos = mostRecentEventTimeNanos(); |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 116 | runDynamicCodeLoggingJob(IDLE_LOGGING_JOB_ID); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 117 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 118 | assertDclLoggedSince(previousEventNanos, DCL_DEX_SUBTAG, |
| 119 | expectedNameHash, expectedContentHash); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 120 | } |
| 121 | |
| 122 | @Test |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 123 | public void testDexLoggerGeneratesEvents_unknownClassLoader() throws Exception { |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 124 | File privateCopyFile = privateFile("copied2.jar"); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 125 | String expectedNameHash = |
| 126 | "202158B6A3169D78F1722487205A6B036B3F2F5653FDCFB4E74710611AC7EB93"; |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 127 | String expectedContentHash = copyAndHashResource("/javalib.jar", privateCopyFile); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 128 | |
| 129 | // This time make sure an unknown class loader is an ancestor of the class loader we use. |
| 130 | ClassLoader knownClassLoader = sContext.getClass().getClassLoader(); |
| 131 | ClassLoader unknownClassLoader = new UnknownClassLoader(knownClassLoader); |
| 132 | ClassLoader loader = |
| 133 | new DexClassLoader(privateCopyFile.toString(), null, null, unknownClassLoader); |
| 134 | loader.loadClass("com.android.dcl.Simple"); |
| 135 | |
| 136 | // And make sure we log events about it |
| 137 | long previousEventNanos = mostRecentEventTimeNanos(); |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 138 | runDynamicCodeLoggingJob(IDLE_LOGGING_JOB_ID); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 139 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 140 | assertDclLoggedSince(previousEventNanos, DCL_DEX_SUBTAG, |
| 141 | expectedNameHash, expectedContentHash); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 142 | } |
| 143 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 144 | @Test |
| 145 | public void testDexLoggerGeneratesEvents_nativeLibrary() throws Exception { |
| 146 | File privateCopyFile = privateFile("copied.so"); |
| 147 | String expectedNameHash = |
| 148 | "996223BAD4B4FE75C57A3DEC61DB9C0B38E0A7AD479FC95F33494F4BC55A0F0E"; |
| 149 | String expectedContentHash = |
| 150 | copyAndHashResource("/DexLoggerNativeTestLibrary.so", privateCopyFile); |
| 151 | |
| 152 | System.load(privateCopyFile.toString()); |
| 153 | |
| 154 | // Run the job to scan generated audit log entries |
| 155 | runDynamicCodeLoggingJob(AUDIT_WATCHING_JOB_ID); |
| 156 | |
| 157 | // And then make sure we log events about it |
| 158 | long previousEventNanos = mostRecentEventTimeNanos(); |
| 159 | runDynamicCodeLoggingJob(IDLE_LOGGING_JOB_ID); |
| 160 | |
| 161 | assertDclLoggedSince(previousEventNanos, DCL_NATIVE_SUBTAG, |
| 162 | expectedNameHash, expectedContentHash); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 163 | } |
| 164 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 165 | @Test |
| 166 | public void testDexLoggerGeneratesEvents_nativeLibrary_escapedName() throws Exception { |
| 167 | // A file name with a space will be escaped in the audit log; verify we un-escape it |
| 168 | // correctly. |
| 169 | File privateCopyFile = privateFile("second copy.so"); |
| 170 | String expectedNameHash = |
| 171 | "8C39990C560B4F36F83E208E279F678746FE23A790E4C50F92686584EA2041CA"; |
| 172 | String expectedContentHash = |
| 173 | copyAndHashResource("/DexLoggerNativeTestLibrary.so", privateCopyFile); |
| 174 | |
| 175 | System.load(privateCopyFile.toString()); |
| 176 | |
| 177 | // Run the job to scan generated audit log entries |
| 178 | runDynamicCodeLoggingJob(AUDIT_WATCHING_JOB_ID); |
| 179 | |
| 180 | // And then make sure we log events about it |
| 181 | long previousEventNanos = mostRecentEventTimeNanos(); |
| 182 | runDynamicCodeLoggingJob(IDLE_LOGGING_JOB_ID); |
| 183 | |
| 184 | assertDclLoggedSince(previousEventNanos, DCL_NATIVE_SUBTAG, |
| 185 | expectedNameHash, expectedContentHash); |
| 186 | } |
| 187 | |
| 188 | @Test |
| 189 | public void testDexLoggerGeneratesEvents_nativeExecutable() throws Exception { |
| 190 | File privateCopyFile = privateFile("test_executable"); |
| 191 | String expectedNameHash = |
| 192 | "3FBEC3F925A132D18F347F11AE9A5BB8DE1238828F8B4E064AA86EB68BD46DCF"; |
| 193 | String expectedContentHash = |
| 194 | copyAndHashResource("/DexLoggerNativeExecutable", privateCopyFile); |
| 195 | assertThat(privateCopyFile.setExecutable(true)).isTrue(); |
| 196 | |
| 197 | Process process = Runtime.getRuntime().exec(privateCopyFile.toString()); |
| 198 | int exitCode = process.waitFor(); |
| 199 | assertThat(exitCode).isEqualTo(0); |
| 200 | |
| 201 | // Run the job to scan generated audit log entries |
| 202 | runDynamicCodeLoggingJob(AUDIT_WATCHING_JOB_ID); |
| 203 | |
| 204 | // And then make sure we log events about it |
| 205 | long previousEventNanos = mostRecentEventTimeNanos(); |
| 206 | runDynamicCodeLoggingJob(IDLE_LOGGING_JOB_ID); |
| 207 | |
| 208 | assertDclLoggedSince(previousEventNanos, DCL_NATIVE_SUBTAG, |
| 209 | expectedNameHash, expectedContentHash); |
| 210 | } |
| 211 | |
| 212 | @Test |
| 213 | public void testDexLoggerGeneratesEvents_spoofed_validFile() throws Exception { |
| 214 | File privateCopyFile = privateFile("spoofed"); |
| 215 | |
| 216 | String expectedContentHash = |
| 217 | copyAndHashResource("/DexLoggerNativeExecutable", privateCopyFile); |
| 218 | |
| 219 | EventLog.writeEvent(EventLog.getTagCode("auditd"), |
| 220 | "type=1400 avc: granted { execute_no_trans } " |
| 221 | + "path=\"" + privateCopyFile + "\" " |
| 222 | + "scontext=u:r:untrusted_app_27: " |
| 223 | + "tcontext=u:object_r:app_data_file: " |
| 224 | + "tclass=file "); |
| 225 | |
| 226 | String expectedNameHash = |
| 227 | "1CF36F503A02877BB775DC23C1C5A47A95F2684B6A1A83B11795B856D88861E3"; |
| 228 | |
| 229 | // Run the job to scan generated audit log entries |
| 230 | runDynamicCodeLoggingJob(AUDIT_WATCHING_JOB_ID); |
| 231 | |
| 232 | // And then make sure we log events about it |
| 233 | long previousEventNanos = mostRecentEventTimeNanos(); |
| 234 | runDynamicCodeLoggingJob(IDLE_LOGGING_JOB_ID); |
| 235 | |
| 236 | assertDclLoggedSince(previousEventNanos, DCL_NATIVE_SUBTAG, |
| 237 | expectedNameHash, expectedContentHash); |
| 238 | } |
| 239 | |
| 240 | @Test |
| 241 | public void testDexLoggerGeneratesEvents_spoofed_pathTraversal() throws Exception { |
| 242 | File privateDir = privateFile("x").getParentFile(); |
| 243 | |
| 244 | // Transform /a/b/c -> /a/b/c/../../.. so we get back to the root |
| 245 | File pathTraversalToRoot = privateDir; |
| 246 | File root = new File("/"); |
| 247 | while (!privateDir.equals(root)) { |
| 248 | pathTraversalToRoot = new File(pathTraversalToRoot, ".."); |
| 249 | privateDir = privateDir.getParentFile(); |
| 250 | } |
| 251 | |
| 252 | File spoofedFile = new File(pathTraversalToRoot, "dev/urandom"); |
| 253 | |
| 254 | assertWithMessage("Expected " + spoofedFile + " to be readable") |
| 255 | .that(spoofedFile.canRead()).isTrue(); |
| 256 | |
| 257 | EventLog.writeEvent(EventLog.getTagCode("auditd"), |
| 258 | "type=1400 avc: granted { execute_no_trans } " |
| 259 | + "path=\"" + spoofedFile + "\" " |
| 260 | + "scontext=u:r:untrusted_app_27: " |
| 261 | + "tcontext=u:object_r:app_data_file: " |
| 262 | + "tclass=file "); |
| 263 | |
| 264 | String expectedNameHash = |
| 265 | "65528FE876BD676B0DFCC9A8ACA8988E026766F99EEC1E1FB48F46B2F635E225"; |
| 266 | |
| 267 | // Run the job to scan generated audit log entries |
| 268 | runDynamicCodeLoggingJob(AUDIT_WATCHING_JOB_ID); |
| 269 | |
| 270 | // And then trigger generating DCL events |
| 271 | long previousEventNanos = mostRecentEventTimeNanos(); |
| 272 | runDynamicCodeLoggingJob(IDLE_LOGGING_JOB_ID); |
| 273 | |
| 274 | assertNoDclLoggedSince(previousEventNanos, DCL_NATIVE_SUBTAG, expectedNameHash); |
| 275 | } |
| 276 | |
| 277 | @Test |
| 278 | public void testDexLoggerGeneratesEvents_spoofed_otherAppFile() throws Exception { |
| 279 | File ourPath = sContext.getDatabasePath("android_pay"); |
| 280 | File targetPath = new File(ourPath.toString() |
| 281 | .replace("com.android.frameworks.dexloggertest", "com.google.android.gms")); |
| 282 | |
| 283 | assertWithMessage("Expected " + targetPath + " to not be readable") |
| 284 | .that(targetPath.canRead()).isFalse(); |
| 285 | |
| 286 | EventLog.writeEvent(EventLog.getTagCode("auditd"), |
| 287 | "type=1400 avc: granted { execute_no_trans } " |
| 288 | + "path=\"" + targetPath + "\" " |
| 289 | + "scontext=u:r:untrusted_app_27: " |
| 290 | + "tcontext=u:object_r:app_data_file: " |
| 291 | + "tclass=file "); |
| 292 | |
| 293 | String expectedNameHash = |
| 294 | "CBE04E8AB9E7199FC19CBAAF9C774B88E56B3B19E823F2251693380AD6F515E6"; |
| 295 | |
| 296 | // Run the job to scan generated audit log entries |
| 297 | runDynamicCodeLoggingJob(AUDIT_WATCHING_JOB_ID); |
| 298 | |
| 299 | // And then trigger generating DCL events |
| 300 | long previousEventNanos = mostRecentEventTimeNanos(); |
| 301 | runDynamicCodeLoggingJob(IDLE_LOGGING_JOB_ID); |
| 302 | |
| 303 | assertNoDclLoggedSince(previousEventNanos, DCL_NATIVE_SUBTAG, expectedNameHash); |
| 304 | } |
| 305 | |
| 306 | private static File privateFile(String name) { |
| 307 | return new File(sContext.getDir("dcl", Context.MODE_PRIVATE), name); |
| 308 | } |
| 309 | |
| 310 | private static String copyAndHashResource(String resourcePath, File copyTo) throws Exception { |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 311 | MessageDigest hasher = MessageDigest.getInstance("SHA-256"); |
| 312 | |
| 313 | // Copy the jar from our Java resources to a private data directory |
Alan Stokes | 1e24bf6 | 2018-01-05 14:36:00 +0000 | [diff] [blame] | 314 | Class<?> thisClass = DexLoggerIntegrationTests.class; |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 315 | try (InputStream input = thisClass.getResourceAsStream(resourcePath); |
| 316 | OutputStream output = new FileOutputStream(copyTo)) { |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 317 | byte[] buffer = new byte[1024]; |
| 318 | while (true) { |
| 319 | int numRead = input.read(buffer); |
| 320 | if (numRead < 0) { |
| 321 | break; |
| 322 | } |
| 323 | output.write(buffer, 0, numRead); |
| 324 | hasher.update(buffer, 0, numRead); |
| 325 | } |
| 326 | } |
| 327 | |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 328 | // Compute the SHA-256 of the file content so we can check that it is the same as the value |
| 329 | // we see logged. |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 330 | Formatter formatter = new Formatter(); |
| 331 | for (byte b : hasher.digest()) { |
| 332 | formatter.format("%02X", b); |
| 333 | } |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 334 | |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 335 | return formatter.toString(); |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 336 | } |
| 337 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 338 | private static void runDynamicCodeLoggingJob(int jobId) throws Exception { |
| 339 | // This forces the DynamicCodeLoggingService job to start now. |
| 340 | runCommand("cmd jobscheduler run -f android " + jobId); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 341 | // Wait for the job to have run. |
| 342 | long startTime = SystemClock.elapsedRealtime(); |
| 343 | while (true) { |
| 344 | String response = runCommand( |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 345 | "cmd jobscheduler get-job-state android " + jobId); |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 346 | if (!response.contains("pending") && !response.contains("active")) { |
| 347 | break; |
| 348 | } |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 349 | // Don't wait forever - if it's taken > 10s then something is very wrong. |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 350 | if (SystemClock.elapsedRealtime() - startTime > TimeUnit.SECONDS.toMillis(10)) { |
| 351 | throw new AssertionError("Job has not completed: " + response); |
| 352 | } |
| 353 | SystemClock.sleep(100); |
| 354 | } |
| 355 | } |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 356 | |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 357 | private static String runCommand(String command) throws Exception { |
| 358 | ByteArrayOutputStream response = new ByteArrayOutputStream(); |
| 359 | byte[] buffer = new byte[1000]; |
| 360 | UiAutomation ui = InstrumentationRegistry.getInstrumentation().getUiAutomation(); |
| 361 | ParcelFileDescriptor fd = ui.executeShellCommand(command); |
| 362 | try (InputStream input = new ParcelFileDescriptor.AutoCloseInputStream(fd)) { |
| 363 | while (true) { |
| 364 | int count = input.read(buffer); |
| 365 | if (count == -1) { |
| 366 | break; |
| 367 | } |
| 368 | response.write(buffer, 0, count); |
| 369 | } |
| 370 | } |
| 371 | return response.toString("UTF-8"); |
| 372 | } |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 373 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 374 | private static long mostRecentEventTimeNanos() throws Exception { |
| 375 | List<Event> events = readSnetEvents(); |
| 376 | return events.isEmpty() ? 0 : events.get(events.size() - 1).getTimeNanos(); |
| 377 | } |
| 378 | |
| 379 | private static void assertDclLoggedSince(long previousEventNanos, String expectedSubTag, |
| 380 | String expectedNameHash, String expectedContentHash) throws Exception { |
| 381 | List<String> messages = |
| 382 | findMatchingEvents(previousEventNanos, expectedSubTag, expectedNameHash); |
| 383 | |
| 384 | assertWithMessage("Expected exactly one matching log entry").that(messages).hasSize(1); |
| 385 | assertThat(messages.get(0)).endsWith(expectedContentHash); |
| 386 | } |
| 387 | |
| 388 | private static void assertNoDclLoggedSince(long previousEventNanos, String expectedSubTag, |
| 389 | String expectedNameHash) throws Exception { |
| 390 | List<String> messages = |
| 391 | findMatchingEvents(previousEventNanos, expectedSubTag, expectedNameHash); |
| 392 | |
| 393 | assertWithMessage("Expected no matching log entries").that(messages).isEmpty(); |
| 394 | } |
| 395 | |
| 396 | private static List<String> findMatchingEvents(long previousEventNanos, String expectedSubTag, |
| 397 | String expectedNameHash) throws Exception { |
| 398 | List<String> messages = new ArrayList<>(); |
| 399 | |
| 400 | for (Event event : readSnetEvents()) { |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 401 | if (event.getTimeNanos() <= previousEventNanos) { |
| 402 | continue; |
| 403 | } |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 404 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 405 | Object data = event.getData(); |
| 406 | if (!(data instanceof Object[])) { |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 407 | continue; |
| 408 | } |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 409 | Object[] fields = (Object[]) data; |
| 410 | |
| 411 | // We only care about DCL events that we generated. |
| 412 | String subTag = (String) fields[0]; |
| 413 | if (!expectedSubTag.equals(subTag)) { |
| 414 | continue; |
| 415 | } |
| 416 | int uid = (int) fields[1]; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 417 | if (uid != sMyUid) { |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 418 | continue; |
| 419 | } |
| 420 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 421 | String message = (String) fields[2]; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 422 | if (!message.startsWith(expectedNameHash)) { |
| 423 | continue; |
| 424 | } |
| 425 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 426 | messages.add(message); |
| 427 | //assertThat(message).endsWith(expectedContentHash); |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 428 | } |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 429 | return messages; |
| 430 | } |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 431 | |
Alan Stokes | e9d3314 | 2018-12-19 09:31:21 +0000 | [diff] [blame] | 432 | private static List<Event> readSnetEvents() throws Exception { |
| 433 | List<Event> events = new ArrayList<>(); |
| 434 | EventLog.readEvents(new int[] { SNET_TAG }, events); |
| 435 | return events; |
Alan Stokes | be9ec97 | 2018-12-10 14:07:47 +0000 | [diff] [blame] | 436 | } |
| 437 | |
| 438 | /** |
| 439 | * A class loader that does nothing useful, but importantly doesn't extend BaseDexClassLoader. |
| 440 | */ |
| 441 | private static class UnknownClassLoader extends ClassLoader { |
| 442 | UnknownClassLoader(ClassLoader parent) { |
| 443 | super(parent); |
| 444 | } |
Alan Stokes | 761d618 | 2017-12-19 11:48:19 +0000 | [diff] [blame] | 445 | } |
| 446 | } |