1 /* 2 * Copyright (C) 2016 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 package com.android.cts.deviceowner; 17 18 import static com.android.bedstead.dpmwrapper.TestAppHelper.registerTestCaseReceiver; 19 import static com.android.bedstead.dpmwrapper.TestAppHelper.unregisterTestCaseReceiver; 20 21 import static com.google.common.truth.Truth.assertThat; 22 import static com.google.common.truth.Truth.assertWithMessage; 23 24 import android.app.admin.ConnectEvent; 25 import android.app.admin.DnsEvent; 26 import android.app.admin.NetworkEvent; 27 import android.content.BroadcastReceiver; 28 import android.content.ComponentName; 29 import android.content.Context; 30 import android.content.Intent; 31 import android.content.IntentFilter; 32 import android.os.Parcel; 33 import android.os.SystemClock; 34 import android.util.Log; 35 36 import androidx.test.InstrumentationRegistry; 37 38 import java.io.BufferedReader; 39 import java.io.IOException; 40 import java.io.InputStreamReader; 41 import java.io.PrintStream; 42 import java.net.HttpURLConnection; 43 import java.net.Inet4Address; 44 import java.net.Inet6Address; 45 import java.net.InetAddress; 46 import java.net.ServerSocket; 47 import java.net.Socket; 48 import java.net.URL; 49 import java.util.ArrayList; 50 import java.util.HashSet; 51 import java.util.List; 52 import java.util.concurrent.CountDownLatch; 53 import java.util.concurrent.TimeUnit; 54 55 public class NetworkLoggingTest extends BaseDeviceOwnerTest { 56 57 private static final String TAG = "NetworkLoggingTest"; 58 private static final boolean VERBOSE = false; 59 60 private static final String ARG_BATCH_COUNT = "batchCount"; 61 private static final int FAKE_BATCH_TOKEN = -666; // real batch tokens are always non-negative 62 private static final int FULL_LOG_BATCH_SIZE = 1200; 63 private static final String CTS_APP_PACKAGE_NAME = "com.android.cts.deviceowner"; 64 private static final int MAX_IP_ADDRESSES_LOGGED = 10; 65 66 private static final int CONNECTION_TIMEOUT_MS = 2_000; 67 68 private static final int TIMEOUT_PER_BATCH_MS = 3 * 60_000; // 3 minutes 69 70 /** How often events should be logged, when {@link #VERBOSE} is {@code false}. */ 71 private static final int LOGGING_FREQUENCY = FULL_LOG_BATCH_SIZE / 4; 72 73 private static final String[] NOT_LOGGED_URLS_LIST = { 74 "wikipedia.org", 75 "google.pl" 76 }; 77 78 private static final String[] LOGGED_URLS_LIST = { 79 "example.com", 80 "example.net", 81 "example.org", 82 "example.edu", 83 "ipv6.google.com", 84 "google.co.jp", 85 "google.fr", 86 "google.com.br", 87 "google.com.tr", 88 "google.co.uk", 89 "google.de" 90 }; 91 92 private final BroadcastReceiver mNetworkLogsReceiver = new BroadcastReceiver() { 93 94 @Override 95 public void onReceive(Context context, Intent intent) { 96 if (!BasicAdminReceiver.ACTION_NETWORK_LOGS_AVAILABLE.equals(intent.getAction())) { 97 Log.w(TAG, "Received unexpected intent: " + intent); 98 return; 99 } 100 final long token = 101 intent.getLongExtra(BasicAdminReceiver.EXTRA_NETWORK_LOGS_BATCH_TOKEN, 102 FAKE_BATCH_TOKEN); 103 final long latchCount = mBatchCountDown.getCount(); 104 Log.d(TAG, "Received " + intent + ": token=" + token + ", latch= " + latchCount); 105 // Retrieve network logs. 106 final List<NetworkEvent> events = mDevicePolicyManager.retrieveNetworkLogs(getWho(), 107 token); 108 Log.d(TAG, "Number of events: " + events.size()); 109 if (VERBOSE) Log.v(TAG, "Events: " + events); 110 if (events == null) { 111 fail("Failed to retrieve batch of network logs with batch token " + token); 112 return; 113 } 114 if (latchCount > 0) { 115 mNetworkEvents.addAll(events); 116 } else { 117 Log.e(TAG, "didn't receive any event"); 118 } 119 Log.d(TAG, "Counting down latch"); 120 mBatchCountDown.countDown(); 121 } 122 }; 123 124 private CountDownLatch mBatchCountDown; 125 private final ArrayList<NetworkEvent> mNetworkEvents = new ArrayList<>(); 126 private int mBatchesRequested = 1; 127 128 @Override tearDown()129 protected void tearDown() throws Exception { 130 // NOTE: if this was a "pure" device-side test, it should not throw an exception on 131 // tearDown() 132 setNetworkLoggingEnabled(false); 133 134 super.tearDown(); 135 } 136 137 /** 138 * Test: retrieving network logs can only be done if there's one user on the device or all 139 * secondary users / profiles are affiliated. 140 */ testRetrievingNetworkLogsThrowsSecurityException()141 public void testRetrievingNetworkLogsThrowsSecurityException() { 142 setNetworkLoggingEnabled(true); 143 144 try { 145 mDevicePolicyManager.retrieveNetworkLogs(getWho(), FAKE_BATCH_TOKEN); 146 fail("did not throw expected SecurityException"); 147 } catch (SecurityException expected) { 148 } 149 } 150 151 /** 152 * Test: when a wrong batch token id (not a token of the current batch) is provided, null should 153 * be returned. 154 */ testProvidingWrongBatchTokenReturnsNull()155 public void testProvidingWrongBatchTokenReturnsNull() { 156 setNetworkLoggingEnabled(true); 157 158 assertNull(mDevicePolicyManager.retrieveNetworkLogs(getWho(), FAKE_BATCH_TOKEN)); 159 } 160 161 /** 162 * Test: test that the actual logging happens when the network logging is enabled and doesn't 163 * happen before it's enabled; for this test to work we need to generate enough internet 164 * traffic, so that the batch of logs is created 165 */ testNetworkLoggingAndRetrieval()166 public void testNetworkLoggingAndRetrieval() throws Exception { 167 mBatchesRequested = 168 Integer.parseInt( 169 InstrumentationRegistry.getArguments().getString(ARG_BATCH_COUNT, "1")); 170 Log.d(TAG, "batches requested:" + mBatchesRequested); 171 mBatchCountDown = new CountDownLatch(mBatchesRequested); 172 // register a receiver that listens for DeviceAdminReceiver#onNetworkLogsAvailable() 173 final IntentFilter filterNetworkLogsAvailable = new IntentFilter( 174 BasicAdminReceiver.ACTION_NETWORK_LOGS_AVAILABLE); 175 176 registerTestCaseReceiver(mContext, mNetworkLogsReceiver, filterNetworkLogsAvailable); 177 178 // visit websites that shouldn't be logged as network logging isn't enabled yet 179 for (int i = 0; i < NOT_LOGGED_URLS_LIST.length; i++) { 180 connectToWebsite(NOT_LOGGED_URLS_LIST[i], shouldLog(i)); 181 } 182 183 // enable network logging and start the logging scenario 184 setNetworkLoggingEnabled(true); 185 186 // TODO: here test that facts about logging are shown in the UI 187 188 // Fetch and verify the batches of events. 189 generateBatches(); 190 } 191 shouldLog(int sample)192 private boolean shouldLog(int sample) { 193 return sample % LOGGING_FREQUENCY == 0; 194 } 195 generateBatches()196 private void generateBatches() throws Exception { 197 // visit websites to verify their dns lookups are logged 198 for (int i = 0; i < LOGGED_URLS_LIST.length; i++) { 199 connectToWebsite(LOGGED_URLS_LIST[i], shouldLog(i)); 200 } 201 202 // generate enough traffic to fill the batches. 203 int fakeReqNo = 0; 204 for (int i = 0; i < mBatchesRequested; i++) { 205 fakeReqNo += generateFakeTraffic(); 206 } 207 208 // if DeviceAdminReceiver#onNetworkLogsAvailable() hasn't been triggered yet, wait for up to 209 // 3 minutes per batch just in case 210 final int timeoutMs = TIMEOUT_PER_BATCH_MS * mBatchesRequested; 211 Log.d(TAG, "Waiting up to " + timeoutMs + "ms for " + mBatchesRequested + " batches"); 212 if (!mBatchCountDown.await(timeoutMs, TimeUnit.MILLISECONDS)) { 213 Log.e(TAG, "Timed out!"); 214 } 215 216 unregisterTestCaseReceiver(mContext, mNetworkLogsReceiver); 217 218 if (mBatchCountDown.getCount() > 0) { 219 fail("Generated events for " + mBatchesRequested + " batches and waited for " 220 + timeoutMs + " ms, but still didn't get" 221 + " DeviceAdminReceiver#onNetworkLogsAvailable() callback"); 222 } 223 224 // Verify network logs. 225 assertWithMessage("network events").that(mNetworkEvents).isNotEmpty(); 226 assertWithMessage("first event id").that(mNetworkEvents.get(0).getId()).isEqualTo(0L); 227 // For each of the real URLs we have two events: one DNS and one connect. Fake requests 228 // don't require DNS queries. 229 final int eventsExpected = 230 Math.min(FULL_LOG_BATCH_SIZE * mBatchesRequested, 231 2 * LOGGED_URLS_LIST.length + fakeReqNo); 232 verifyNetworkLogs(mNetworkEvents, eventsExpected); 233 } 234 verifyDnsEvent(DnsEvent dnsEvent)235 private void verifyDnsEvent(DnsEvent dnsEvent) { 236 // Verify that we didn't log a hostname lookup when network logging was disabled. 237 if (dnsEvent.getHostname().contains(NOT_LOGGED_URLS_LIST[0]) 238 || dnsEvent.getHostname().contains(NOT_LOGGED_URLS_LIST[1])) { 239 fail("A hostname that was looked-up when network logging was disabled" 240 + " was logged."); 241 } 242 243 // Verify that as many IP addresses were logged as were reported (max 10). 244 final List<InetAddress> ips = dnsEvent.getInetAddresses(); 245 assertThat(ips.size()).isAtMost(MAX_IP_ADDRESSES_LOGGED); 246 final int expectedAddressCount = Math.min(MAX_IP_ADDRESSES_LOGGED, 247 dnsEvent.getTotalResolvedAddressCount()); 248 assertThat(expectedAddressCount).isEqualTo(ips.size()); 249 250 // Verify the IP addresses are valid IPv4 or IPv6 addresses. 251 for (final InetAddress ipAddress : ips) { 252 assertTrue(isIpv4OrIpv6Address(ipAddress)); 253 } 254 255 //Verify writeToParcel. 256 Parcel parcel = Parcel.obtain(); 257 try { 258 dnsEvent.writeToParcel(parcel, 0); 259 parcel.setDataPosition(0); 260 final DnsEvent dnsEventOut = DnsEvent.CREATOR.createFromParcel(parcel); 261 assertThat(dnsEventOut).isNotNull(); 262 verifyDnsEventsEqual(dnsEvent, dnsEventOut); 263 } finally { 264 parcel.recycle(); 265 } 266 } 267 verifyDnsEventsEqual(DnsEvent event1, DnsEvent event2)268 private void verifyDnsEventsEqual(DnsEvent event1, DnsEvent event2) { 269 assertThat(event1.getHostname()).isEqualTo(event2.getHostname()); 270 assertThat(new HashSet<InetAddress>(event1.getInetAddresses())).isEqualTo( 271 new HashSet<InetAddress>(event2.getInetAddresses())); 272 assertThat(event1.getTotalResolvedAddressCount()).isEqualTo( 273 event2.getTotalResolvedAddressCount()); 274 assertThat(event1.getPackageName()).isEqualTo(event2.getPackageName()); 275 assertThat(event1.getTimestamp()).isEqualTo(event2.getTimestamp()); 276 assertThat(event1.getId()).isEqualTo(event2.getId()); 277 } 278 verifyConnectEvent(ConnectEvent connectEvent)279 private void verifyConnectEvent(ConnectEvent connectEvent) { 280 // Verify the IP address is a valid IPv4 or IPv6 address. 281 final InetAddress ip = connectEvent.getInetAddress(); 282 assertThat(isIpv4OrIpv6Address(ip)).isTrue(); 283 284 // Verify that the port is a valid port. 285 assertThat(connectEvent.getPort()).isAtLeast(0); 286 assertThat(connectEvent.getPort()).isAtMost(65535); 287 288 // Verify writeToParcel. 289 Parcel parcel = Parcel.obtain(); 290 try { 291 connectEvent.writeToParcel(parcel, 0); 292 parcel.setDataPosition(0); 293 final ConnectEvent connectEventOut = ConnectEvent.CREATOR.createFromParcel(parcel); 294 assertThat(connectEventOut).isNotNull(); 295 verifyConnectEventsEqual(connectEvent, connectEventOut); 296 } finally { 297 parcel.recycle(); 298 } 299 } 300 verifyConnectEventsEqual(ConnectEvent event1, ConnectEvent event2)301 private void verifyConnectEventsEqual(ConnectEvent event1, ConnectEvent event2) { 302 assertThat(event1.getInetAddress()).isEqualTo(event2.getInetAddress()); 303 assertThat(event1.getPort()).isEqualTo(event2.getPort()); 304 assertThat(event1.getPackageName()).isEqualTo(event2.getPackageName()); 305 assertThat(event1.getTimestamp()).isEqualTo(event2.getTimestamp()); 306 assertThat(event1.getId()).isEqualTo(event2.getId()); 307 } 308 verifyNetworkLogs(List<NetworkEvent> networkEvents, int eventsExpected)309 private void verifyNetworkLogs(List<NetworkEvent> networkEvents, int eventsExpected) { 310 Log.d(TAG, "verifyNetworkLogs(): expected " + eventsExpected + ", got " 311 + ((networkEvents == null) ? "null" : String.valueOf(networkEvents.size()))); 312 // allow a batch to be slightly smaller or larger. 313 assertTrue(Math.abs(eventsExpected - networkEvents.size()) <= 150); 314 int ctsPackageNameCounter = 0; 315 // allow a small down margin for verification, to avoid flakiness 316 final int eventsExpectedWithMargin = eventsExpected - 50; 317 final boolean[] visited = new boolean[LOGGED_URLS_LIST.length]; 318 319 for (int i = 0; i < networkEvents.size(); i++) { 320 final NetworkEvent currentEvent = networkEvents.get(i); 321 // verify that the events are in chronological order 322 if (i > 0) { 323 assertTrue(currentEvent.getTimestamp() >= networkEvents.get(i - 1).getTimestamp()); 324 } 325 // verify that the event IDs are monotonically increasing 326 if (i > 0) { 327 assertTrue(currentEvent.getId() == (networkEvents.get(i - 1).getId() + 1)); 328 } 329 // count how many events come from the CTS app 330 if (CTS_APP_PACKAGE_NAME.equals(currentEvent.getPackageName())) { 331 ctsPackageNameCounter++; 332 if (currentEvent instanceof DnsEvent) { 333 final DnsEvent dnsEvent = (DnsEvent) currentEvent; 334 // Mark which addresses from LOGGED_URLS_LIST were visited. 335 for (int j = 0; j < LOGGED_URLS_LIST.length; j++) { 336 if (dnsEvent.getHostname().contains(LOGGED_URLS_LIST[j])) { 337 visited[j] = true; 338 break; 339 } 340 } 341 342 verifyDnsEvent(dnsEvent); 343 } else if (currentEvent instanceof ConnectEvent) { 344 final ConnectEvent connectEvent = (ConnectEvent) currentEvent; 345 verifyConnectEvent(connectEvent); 346 } else { 347 fail("An unknown NetworkEvent type logged: " 348 + currentEvent.getClass().getName()); 349 } 350 } 351 } 352 353 // verify that each hostname from LOGGED_URLS_LIST was looked-up 354 for (int i = 0; i < 10; i++) { 355 assertTrue(LOGGED_URLS_LIST[i] + " wasn't visited", visited[i]); 356 } 357 // verify that sufficient iterations done by the CTS app were logged 358 assertTrue(ctsPackageNameCounter >= eventsExpectedWithMargin); 359 } 360 connectToWebsite(String server, boolean shouldLog)361 private void connectToWebsite(String server, boolean shouldLog) { 362 HttpURLConnection urlConnection = null; 363 try { 364 final URL url = new URL("http://" + server); 365 if (shouldLog || VERBOSE) { 366 Log.d(TAG, "Connecting to " + server + " with " + CONNECTION_TIMEOUT_MS 367 + "ms timeout"); 368 } 369 urlConnection = (HttpURLConnection) url.openConnection(); 370 urlConnection.setConnectTimeout(CONNECTION_TIMEOUT_MS); 371 urlConnection.setReadTimeout(CONNECTION_TIMEOUT_MS); 372 final int responseCode = urlConnection.getResponseCode(); 373 if (shouldLog || VERBOSE) { 374 Log.d(TAG, "Got response code: " + responseCode); 375 } 376 } catch (IOException e) { 377 Log.w(TAG, "Failed to connect to " + server, e); 378 } finally { 379 if (urlConnection != null) { 380 urlConnection.disconnect(); 381 } 382 } 383 } 384 385 /** Quickly generate loads of events by repeatedly connecting to a local server. */ generateFakeTraffic()386 private int generateFakeTraffic() throws IOException, InterruptedException { 387 final ServerSocket serverSocket = new ServerSocket(0); 388 final Thread serverThread = startFakeServer(serverSocket); 389 390 final int reqNo = makeFakeRequests(serverSocket.getLocalPort()); 391 392 serverSocket.close(); 393 serverThread.join(); 394 395 return reqNo; 396 } 397 makeFakeRequests(int port)398 private int makeFakeRequests(int port) { 399 int reqNo; 400 final String FAKE_SERVER = "127.0.0.1:" + port; 401 Log.d(TAG, "Making a fake request to " + FAKE_SERVER); 402 for (reqNo = 0; reqNo < FULL_LOG_BATCH_SIZE && mBatchCountDown.getCount() > 0; reqNo++) { 403 connectToWebsite(FAKE_SERVER, shouldLog(reqNo)); 404 // Just to prevent choking the server. 405 sleep(10); 406 } 407 Log.d(TAG, "Returning reqNo=" + reqNo); 408 return reqNo; 409 } 410 startFakeServer(ServerSocket serverSocket)411 private Thread startFakeServer(ServerSocket serverSocket) throws InterruptedException { 412 final Thread serverThread = new Thread(() -> { 413 while (!serverSocket.isClosed()) { 414 try { 415 final Socket socket = serverSocket.accept(); 416 // Consume input. 417 final BufferedReader input = 418 new BufferedReader(new InputStreamReader(socket.getInputStream())); 419 String line; 420 do { 421 line = input.readLine(); 422 } while (line != null && !line.equals("")); 423 // Return minimum valid response. 424 final PrintStream output = new PrintStream(socket.getOutputStream()); 425 output.println("HTTP/1.0 200 OK"); 426 output.println("Content-Length: 0"); 427 output.println(); 428 output.flush(); 429 output.close(); 430 } catch (IOException e) { 431 if (!serverSocket.isClosed()) { 432 Log.w(TAG, "Failed to serve connection", e); 433 } 434 } 435 } 436 Log.i(TAG, "Fake server closed"); 437 }, "FakeServerThread"); 438 Log.i(TAG, "starting a fake server (" + serverSocket + ") on thread " + serverThread); 439 serverThread.start(); 440 441 // Allow the server to start accepting. 442 sleep(1_000); 443 444 return serverThread; 445 } 446 isIpv4OrIpv6Address(InetAddress addr)447 private boolean isIpv4OrIpv6Address(InetAddress addr) { 448 return ((addr instanceof Inet4Address) || (addr instanceof Inet6Address)); 449 } 450 sleep(int timeMs)451 private void sleep(int timeMs) { 452 if (VERBOSE) Log.v(TAG, "Sleeping for " + timeMs + "ms"); 453 SystemClock.sleep(timeMs); 454 if (VERBOSE) Log.v(TAG, "Woke up"); 455 } 456 setNetworkLoggingEnabled(boolean enabled)457 private void setNetworkLoggingEnabled(boolean enabled) { 458 ComponentName admin = getWho(); 459 Log.d(TAG, "Calling setNetworkLoggingEnabled(" + enabled + ") for " + admin); 460 mDevicePolicyManager.setNetworkLoggingEnabled(admin, enabled); 461 boolean reallyEnabled = mDevicePolicyManager.isNetworkLoggingEnabled(admin); 462 Log.d(TAG, "getNetworkLoggingEnabled() result:" + reallyEnabled); 463 assertWithMessage("network logging enabled for %s", admin).that(reallyEnabled) 464 .isEqualTo(enabled); 465 } 466 } 467