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