Connectivity metrics: collect NFLOG wakeup events

This patch stores NFLOG packet wakeup events sent by Netd to the system
server into a ring buffer inside NetdEventListenerService. The content
of this buffer is accessible by $ dumpsys connmetrics or $ dumpsys
connmetrics list, and is added to bug reports.

The wakeup event buffer stores currently uid and timestamps.

Bug: 34901696
Bug: 62179647
Test: runtest frameworks-net, new unit tests

Merged-In: Ie8db6f8572b1a929a20398d8dc03e189bc488382

(cherry picked from commit f562ac34a51da55e4d15e34f0cd1cb597e7d926c)

Change-Id: Ibe706872a80dfd06abd9779a2116ca7e4bc0fb77

diff --git a/core/java/android/net/metrics/WakeupEvent.java b/core/java/android/net/metrics/WakeupEvent.java
new file mode 100644 (file)
index 0000000..cbf3fc8
--- /dev/null
+++ b/core/java/android/net/metrics/WakeupEvent.java
@@ -0,0 +1,34 @@
+/*
+ * Copyright (C) 2017 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package android.net.metrics;
+
+/**
+ * An event logged when NFLOG notifies userspace of a wakeup packet for
+ * watched interfaces.
+ * {@hide}
+ */
+public class WakeupEvent {
+    public String iface;
+    public long timestampMs;
+    public int uid;
+
+    @Override
+    public String toString() {
+        return String.format("WakeupEvent(%tT.%tL, %s, uid: %d)",
+                timestampMs, timestampMs, iface, uid);
+    }
+}

diff --git a/services/core/java/com/android/server/connectivity/NetdEventListenerService.java b/services/core/java/com/android/server/connectivity/NetdEventListenerService.java
index 4094083..833457c 100644 (file)
--- a/services/core/java/com/android/server/connectivity/NetdEventListenerService.java
+++ b/services/core/java/com/android/server/connectivity/NetdEventListenerService.java
@@ -25,6 +25,7 @@ import android.net.metrics.ConnectStats;
 import android.net.metrics.DnsEvent;
 import android.net.metrics.INetdEventListener;
 import android.net.metrics.IpConnectivityLog;
+import android.net.metrics.WakeupEvent;
 import android.os.RemoteException;
 import android.text.format.DateUtils;
 import android.util.Log;
@@ -59,12 +60,23 @@ public class NetdEventListenerService extends INetdEventListener.Stub {
     private static final int CONNECT_LATENCY_FILL_RATE    = 15 * (int) DateUtils.SECOND_IN_MILLIS;
     private static final int CONNECT_LATENCY_MAXIMUM_RECORDS = 20000;
 
+    @VisibleForTesting
+    static final int WAKEUP_EVENT_BUFFER_LENGTH = 1024;
+
+    private static final String WAKEUP_EVENT_IFACE_PREFIX = "iface:";
+
     // Sparse arrays of DNS and connect events, grouped by net id.
     @GuardedBy("this")
     private final SparseArray<DnsEvent> mDnsEvents = new SparseArray<>();
     @GuardedBy("this")
     private final SparseArray<ConnectStats> mConnectEvents = new SparseArray<>();
 
+    // Ring buffer array for storing packet wake up events sent by Netd.
+    @GuardedBy("this")
+    private final WakeupEvent[] mWakeupEvents = new WakeupEvent[WAKEUP_EVENT_BUFFER_LENGTH];
+    @GuardedBy("this")
+    private long mWakeupEventCursor = 0;
+
     private final ConnectivityManager mCm;
 
     @GuardedBy("this")
@@ -137,6 +149,44 @@ public class NetdEventListenerService extends INetdEventListener.Stub {
 
     @Override
     public synchronized void onWakeupEvent(String prefix, int uid, int gid, long timestampNs) {
+        maybeVerboseLog("onWakeupEvent(%s, %d, %d, %sns)", prefix, uid, gid, timestampNs);
+
+        // TODO: add ip protocol and port
+
+        String iface = prefix.replaceFirst(WAKEUP_EVENT_IFACE_PREFIX, "");
+        long timestampMs = timestampNs / 1000000;
+        // FIXME: Netd timestampNs is always 0.
+        timestampMs = System.currentTimeMillis();
+
+        addWakupEvent(iface, timestampMs, uid);
+    }
+
+    @GuardedBy("this")
+    private void addWakupEvent(String iface, long timestampMs, int uid) {
+        int index = wakeupEventIndex(mWakeupEventCursor);
+        mWakeupEventCursor++;
+        WakeupEvent event = new WakeupEvent();
+        event.iface = iface;
+        event.timestampMs = timestampMs;
+        event.uid = uid;
+        mWakeupEvents[index] = event;
+    }
+
+    @GuardedBy("this")
+    private WakeupEvent[] getWakeupEvents() {
+        int length = (int) Math.min(mWakeupEventCursor, (long) mWakeupEvents.length);
+        WakeupEvent[] out = new WakeupEvent[length];
+        // Reverse iteration from youngest event to oldest event.
+        long inCursor = mWakeupEventCursor - 1;
+        int outIdx = out.length - 1;
+        while (outIdx >= 0) {
+            out[outIdx--] = mWakeupEvents[wakeupEventIndex(inCursor--)];
+        }
+        return out;
+    }
+
+    private static int wakeupEventIndex(long cursor) {
+        return (int) Math.abs(cursor % WAKEUP_EVENT_BUFFER_LENGTH);
     }
 
     public synchronized void flushStatistics(List<IpConnectivityEvent> events) {
@@ -155,6 +205,7 @@ public class NetdEventListenerService extends INetdEventListener.Stub {
     public synchronized void list(PrintWriter pw) {
         listEvents(pw, mConnectEvents, (x) -> x);
         listEvents(pw, mDnsEvents, (x) -> x);
+        listWakeupEvents(pw, getWakeupEvents());
     }
 
     public synchronized void listAsProtos(PrintWriter pw) {
@@ -170,13 +221,19 @@ public class NetdEventListenerService extends INetdEventListener.Stub {
         in.clear();
     }
 
-    public static <T> void listEvents(
+    private static <T> void listEvents(
             PrintWriter pw, SparseArray<T> events, Function<T, Object> mapper) {
         for (int i = 0; i < events.size(); i++) {
             pw.println(mapper.apply(events.valueAt(i)).toString());
         }
     }
 
+    private static void listWakeupEvents(PrintWriter pw, WakeupEvent[] events) {
+        for (WakeupEvent wakeup : events) {
+            pw.println(wakeup);
+        }
+    }
+
     private ConnectStats makeConnectStats(int netId) {
         long transports = getTransports(netId);
         return new ConnectStats(netId, transports, mConnectTb, CONNECT_LATENCY_MAXIMUM_RECORDS);

diff --git a/tests/net/java/com/android/server/connectivity/NetdEventListenerServiceTest.java b/tests/net/java/com/android/server/connectivity/NetdEventListenerServiceTest.java
index 46f395e..3a93b94 100644 (file)
--- a/tests/net/java/com/android/server/connectivity/NetdEventListenerServiceTest.java
+++ b/tests/net/java/com/android/server/connectivity/NetdEventListenerServiceTest.java
@@ -19,6 +19,7 @@ package com.android.server.connectivity;
 import static android.net.metrics.INetdEventListener.EVENT_GETADDRINFO;
 import static android.net.metrics.INetdEventListener.EVENT_GETHOSTBYNAME;
 import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertTrue;
 import static org.junit.Assert.fail;
 import static org.mockito.Mockito.any;
 import static org.mockito.Mockito.mock;
@@ -75,6 +76,52 @@ public class NetdEventListenerServiceTest {
     }
 
     @Test
+    public void testWakeupEventLogging() throws Exception {
+        final int BUFFER_LENGTH = NetdEventListenerService.WAKEUP_EVENT_BUFFER_LENGTH;
+
+        // Assert no events
+        String[] events1 = listNetdEvent();
+        assertEquals(new String[]{""}, events1);
+
+        long now = System.currentTimeMillis();
+        String prefix = "iface:wlan0";
+        int[] uids = { 10001, 10002, 10004, 1000, 10052, 10023, 10002, 10123, 10004 };
+        for (int uid : uids) {
+            mNetdEventListenerService.onWakeupEvent(prefix, uid, uid, now);
+        }
+
+        String[] events2 = listNetdEvent();
+        assertEquals(uids.length, events2.length);
+        for (int i = 0; i < uids.length; i++) {
+            String got = events2[i];
+            assertContains(got, "wlan0");
+            assertContains(got, "uid: " + uids[i]);
+        }
+
+        int uid = 20000;
+        for (int i = 0; i < BUFFER_LENGTH * 2; i++) {
+            long ts = now + 10;
+            mNetdEventListenerService.onWakeupEvent(prefix, uid, uid, ts);
+        }
+
+        // Assert there are BUFFER_LENGTH events all with uid 20000
+        String[] events3 = listNetdEvent();
+        assertEquals(BUFFER_LENGTH, events3.length);
+        for (String got : events3) {
+            assertContains(got, "wlan0");
+            assertContains(got, "uid: " + uid);
+        }
+
+        uid = 45678;
+        mNetdEventListenerService.onWakeupEvent(prefix, uid, uid, now);
+
+        String[] events4 = listNetdEvent();
+        String lastEvent = events4[events4.length - 1];
+        assertContains(lastEvent, "wlan0");
+        assertContains(lastEvent, "uid: " + uid);
+    }
+
+    @Test
     public void testDnsLogging() throws Exception {
         asyncDump(100);
 
@@ -329,4 +376,15 @@ public class NetdEventListenerServiceTest {
         }
         return log.toString();
     }
+
+    String[] listNetdEvent() throws Exception {
+        StringWriter buffer = new StringWriter();
+        PrintWriter writer = new PrintWriter(buffer);
+        mNetdEventListenerService.list(writer);
+        return buffer.toString().split("\\n");
+    }
+
+    static void assertContains(String got, String want) {
+        assertTrue(got + " did not contain \"" + want + "\"", got.contains(want));
+    }
 }