Add measurements for TransportClient connections

Retrievable via 'adb shell dumpsys backup transportstats'.
Sample output:

Average connection time: 36.00 ms
Max connection time: 181 ms
Min connection time: 7 ms
Number of connections: 16
Per transport:
    com.google.android.gms/.backup.BackupTransportService
        Average connection time: 27.71 ms
        Max connection time: 139 ms
        Min connection time: 13 ms
        Number of connections: 14
    com.google.android.gms/.backup.component.D2dTransportService
        Average connection time: 181.00 ms
        Max connection time: 181 ms
        Min connection time: 181 ms
        Number of connections: 1
    android/com.android.internal.backup.LocalTransportService
        Average connection time: 7.00 ms
        Max connection time: 7 ms
        Min connection time: 7 ms
        Number of connections: 1

Bug: 72485465
Test: Will follow in another CL if reviewers OK w/ approach.
Change-Id: I133ed423d0b8471d69e3c3631aadee7d42d0ec0e
(cherry picked from commit e5a976404c66c054fbec9b124f816a90f9d6b4dc)

diff --git a/services/backup/java/com/android/server/backup/BackupManagerService.java b/services/backup/java/com/android/server/backup/BackupManagerService.java
index 369df54..6469091 100644 (file)
--- a/services/backup/java/com/android/server/backup/BackupManagerService.java
+++ b/services/backup/java/com/android/server/backup/BackupManagerService.java
@@ -3525,7 +3525,10 @@ public class BackupManagerService implements BackupManagerServiceInterface {
                         dumpAgents(pw);
                         return;
                     } else if ("transportclients".equals(arg.toLowerCase())) {
-                        mTransportManager.dump(pw);
+                        mTransportManager.dumpTransportClients(pw);
+                        return;
+                    } else if ("transportstats".equals(arg.toLowerCase())) {
+                        mTransportManager.dumpTransportStats(pw);
                         return;
                     }
                 }
@@ -3590,7 +3593,7 @@ public class BackupManagerService implements BackupManagerServiceInterface {
                 }
             }
 
-            mTransportManager.dump(pw);
+            mTransportManager.dumpTransportClients(pw);
 
             pw.println("Pending init: " + mPendingInits.size());
             for (String s : mPendingInits) {

diff --git a/services/backup/java/com/android/server/backup/TransportManager.java b/services/backup/java/com/android/server/backup/TransportManager.java
index c87d298..6a1bf17 100644 (file)
--- a/services/backup/java/com/android/server/backup/TransportManager.java
+++ b/services/backup/java/com/android/server/backup/TransportManager.java
@@ -44,6 +44,7 @@ import com.android.server.backup.transport.TransportClientManager;
 import com.android.server.backup.transport.TransportConnectionListener;
 import com.android.server.backup.transport.TransportNotAvailableException;
 import com.android.server.backup.transport.TransportNotRegisteredException;
+import com.android.server.backup.transport.TransportStats;
 
 import java.io.PrintWriter;
 import java.util.List;
@@ -64,6 +65,7 @@ public class TransportManager {
     private final PackageManager mPackageManager;
     private final Set<ComponentName> mTransportWhitelist;
     private final TransportClientManager mTransportClientManager;
+    private final TransportStats mTransportStats;
     private OnTransportRegisteredListener mOnTransportRegisteredListener = (c, n) -> {};
 
     /**
@@ -85,7 +87,12 @@ public class TransportManager {
     private volatile String mCurrentTransportName;
 
     TransportManager(Context context, Set<ComponentName> whitelist, String selectedTransport) {
-        this(context, whitelist, selectedTransport, new TransportClientManager(context));
+        mContext = context;
+        mPackageManager = context.getPackageManager();
+        mTransportWhitelist = Preconditions.checkNotNull(whitelist);
+        mCurrentTransportName = selectedTransport;
+        mTransportStats = new TransportStats();
+        mTransportClientManager = new TransportClientManager(context, mTransportStats);
     }
 
     @VisibleForTesting
@@ -98,6 +105,7 @@ public class TransportManager {
         mPackageManager = context.getPackageManager();
         mTransportWhitelist = Preconditions.checkNotNull(whitelist);
         mCurrentTransportName = selectedTransport;
+        mTransportStats = new TransportStats();
         mTransportClientManager = transportClientManager;
     }
 
@@ -640,10 +648,14 @@ public class TransportManager {
                 !Thread.holdsLock(mTransportLock), "Can't call transport with transport lock held");
     }
 
-    public void dump(PrintWriter pw) {
+    public void dumpTransportClients(PrintWriter pw) {
         mTransportClientManager.dump(pw);
     }
 
+    public void dumpTransportStats(PrintWriter pw) {
+        mTransportStats.dump(pw);
+    }
+
     private static Predicate<ComponentName> fromPackageFilter(String packageName) {
         return transportComponent -> packageName.equals(transportComponent.getPackageName());
     }

diff --git a/services/backup/java/com/android/server/backup/transport/TransportClient.java b/services/backup/java/com/android/server/backup/transport/TransportClient.java
index 1a2ca92..fa881a9 100644 (file)
--- a/services/backup/java/com/android/server/backup/transport/TransportClient.java
+++ b/services/backup/java/com/android/server/backup/transport/TransportClient.java
@@ -29,6 +29,7 @@ import android.os.DeadObjectException;
 import android.os.Handler;
 import android.os.IBinder;
 import android.os.Looper;
+import android.os.SystemClock;
 import android.os.UserHandle;
 import android.text.format.DateFormat;
 import android.util.ArrayMap;
@@ -51,6 +52,7 @@ import java.lang.ref.WeakReference;
 import java.util.Collections;
 import java.util.LinkedList;
 import java.util.List;
+import java.util.Locale;
 import java.util.Map;
 import java.util.concurrent.CompletableFuture;
 import java.util.concurrent.ExecutionException;
@@ -78,6 +80,7 @@ public class TransportClient {
     private static final int LOG_BUFFER_SIZE = 5;
 
     private final Context mContext;
+    private final TransportStats mTransportStats;
     private final Intent mBindIntent;
     private final ServiceConnection mConnection;
     private final String mIdentifier;
@@ -104,12 +107,14 @@ public class TransportClient {
 
     TransportClient(
             Context context,
+            TransportStats transportStats,
             Intent bindIntent,
             ComponentName transportComponent,
             String identifier,
             String caller) {
         this(
                 context,
+                transportStats,
                 bindIntent,
                 transportComponent,
                 identifier,
@@ -120,12 +125,14 @@ public class TransportClient {
     @VisibleForTesting
     TransportClient(
             Context context,
+            TransportStats transportStats,
             Intent bindIntent,
             ComponentName transportComponent,
             String identifier,
             String caller,
             Handler listenerHandler) {
         mContext = context;
+        mTransportStats = transportStats;
         mTransportComponent = transportComponent;
         mBindIntent = bindIntent;
         mIdentifier = identifier;
@@ -321,11 +328,16 @@ public class TransportClient {
                 (requestedTransport, transportClient) ->
                         transportFuture.complete(requestedTransport);
 
+        long requestTime = SystemClock.elapsedRealtime();
         log(Priority.DEBUG, caller, "Sync connect: calling async");
         connectAsync(requestListener, caller);
 
         try {
-            return transportFuture.get();
+            transport = transportFuture.get();
+            long time = SystemClock.elapsedRealtime() - requestTime;
+            mTransportStats.registerConnectionTime(mTransportComponent, time);
+            log(Priority.DEBUG, caller, String.format(Locale.US, "Connect took %d ms", time));
+            return transport;
         } catch (InterruptedException | ExecutionException e) {
             String error = e.getClass().getSimpleName();
             log(Priority.ERROR, caller, error + " while waiting for transport: " + e.getMessage());

diff --git a/services/backup/java/com/android/server/backup/transport/TransportClientManager.java b/services/backup/java/com/android/server/backup/transport/TransportClientManager.java
index 96e7d2f..f4e3928 100644 (file)
--- a/services/backup/java/com/android/server/backup/transport/TransportClientManager.java
+++ b/services/backup/java/com/android/server/backup/transport/TransportClientManager.java
@@ -37,12 +37,14 @@ public class TransportClientManager {
     private static final String TAG = "TransportClientManager";
 
     private final Context mContext;
+    private final TransportStats mTransportStats;
     private final Object mTransportClientsLock = new Object();
     private int mTransportClientsCreated = 0;
     private Map<TransportClient, String> mTransportClientsCallerMap = new WeakHashMap<>();
 
-    public TransportClientManager(Context context) {
+    public TransportClientManager(Context context, TransportStats transportStats) {
         mContext = context;
+        mTransportStats = transportStats;
     }
 
     /**
@@ -88,6 +90,7 @@ public class TransportClientManager {
             TransportClient transportClient =
                     new TransportClient(
                             mContext,
+                            mTransportStats,
                             bindIntent,
                             transportComponent,
                             Integer.toString(mTransportClientsCreated),

diff --git a/services/backup/java/com/android/server/backup/transport/TransportStats.java b/services/backup/java/com/android/server/backup/transport/TransportStats.java
new file mode 100644 (file)
index 0000000..4bef81a
--- /dev/null
+++ b/services/backup/java/com/android/server/backup/transport/TransportStats.java
@@ -0,0 +1,122 @@
+/*
+ * Copyright (C) 2018 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 com.android.server.backup.transport;
+
+import android.annotation.Nullable;
+import android.content.ComponentName;
+
+import java.io.PrintWriter;
+import java.util.HashMap;
+import java.util.Locale;
+import java.util.Map;
+import java.util.Optional;
+
+/** Responsible for aggregating {@link TransportClient} relevant times. */
+public class TransportStats {
+    private final Object mStatsLock = new Object();
+    private final Map<ComponentName, Stats> mTransportStats = new HashMap<>();
+
+    void registerConnectionTime(ComponentName transportComponent, long timeMs) {
+        synchronized (mStatsLock) {
+            mTransportStats
+                    .computeIfAbsent(transportComponent, name -> new Stats())
+                    .register(timeMs);
+        }
+    }
+
+    /** Returns {@link Stats} for transport whose host service is {@code transportComponent}. */
+    @Nullable
+    public Stats getStatsForTransport(ComponentName transportComponent) {
+        synchronized (mStatsLock) {
+            Stats stats = mTransportStats.get(transportComponent);
+            if (stats == null) {
+                return null;
+            }
+            return new Stats(stats);
+        }
+    }
+
+    public void dump(PrintWriter pw) {
+        synchronized (mStatsLock) {
+            Optional<Stats> aggregatedStats =
+                    mTransportStats.values().stream().reduce(Stats::merge);
+            if (aggregatedStats.isPresent()) {
+                dumpStats(pw, "", aggregatedStats.get());
+            }
+            if (!mTransportStats.isEmpty()) {
+                pw.println("Per transport:");
+                for (ComponentName transportComponent : mTransportStats.keySet()) {
+                    Stats stats = mTransportStats.get(transportComponent);
+                    pw.println("    " + transportComponent.flattenToShortString());
+                    dumpStats(pw, "        ", stats);
+                }
+            }
+        }
+    }
+
+    private static void dumpStats(PrintWriter pw, String prefix, Stats stats) {
+        pw.println(
+                String.format(
+                        Locale.US, "%sAverage connection time: %.2f ms", prefix, stats.mAverage));
+        pw.println(String.format(Locale.US, "%sMax connection time: %d ms", prefix, stats.mMax));
+        pw.println(String.format(Locale.US, "%sMin connection time: %d ms", prefix, stats.mMin));
+        pw.println(String.format(Locale.US, "%sNumber of connections: %d ", prefix, stats.mN));
+    }
+
+    public static final class Stats {
+        public static Stats merge(Stats a, Stats b) {
+            return new Stats(
+                    a.mN + b.mN,
+                    (a.mAverage * a.mN + b.mAverage * b.mN) / (a.mN + b.mN),
+                    Math.max(a.mMax, b.mMax),
+                    Math.min(a.mMin, b.mMin));
+        }
+
+        public int mN;
+        public double mAverage;
+        public long mMax;
+        public long mMin;
+
+        public Stats() {
+            mN = 0;
+            mAverage = 0;
+            mMax = 0;
+            mMin = Long.MAX_VALUE;
+        }
+
+        private Stats(Stats original) {
+            mN = original.mN;
+            mAverage = original.mAverage;
+            mMax = original.mMax;
+            mMin = original.mMin;
+        }
+
+        private Stats(int n, double average, long max, long min) {
+            mN = n;
+            mAverage = average;
+            mMax = max;
+            mMin = min;
+        }
+
+        private void register(long sample) {
+            mAverage = (mAverage * mN + sample) / (mN + 1);
+            mN++;
+            mMax = Math.max(mMax, sample);
+            mMin = Math.min(mMin, sample);
+        }
+    }
+}

diff --git a/services/robotests/src/com/android/server/backup/transport/TransportClientManagerTest.java b/services/robotests/src/com/android/server/backup/transport/TransportClientManagerTest.java
index 3d2d8af..bbec7af 100644 (file)
--- a/services/robotests/src/com/android/server/backup/transport/TransportClientManagerTest.java
+++ b/services/robotests/src/com/android/server/backup/transport/TransportClientManagerTest.java
@@ -60,7 +60,7 @@ public class TransportClientManagerTest {
     public void setUp() {
         MockitoAnnotations.initMocks(this);
 
-        mTransportClientManager = new TransportClientManager(mContext);
+        mTransportClientManager = new TransportClientManager(mContext, new TransportStats());
         mTransportComponent = new ComponentName(PACKAGE_NAME, CLASS_NAME);
         mBindIntent = new Intent(SERVICE_ACTION_TRANSPORT_HOST).setComponent(mTransportComponent);
 

diff --git a/services/robotests/src/com/android/server/backup/transport/TransportClientTest.java b/services/robotests/src/com/android/server/backup/transport/TransportClientTest.java
index 5b65473..49ef581 100644 (file)
--- a/services/robotests/src/com/android/server/backup/transport/TransportClientTest.java
+++ b/services/robotests/src/com/android/server/backup/transport/TransportClientTest.java
@@ -88,6 +88,7 @@ public class TransportClientTest {
     @Mock private TransportConnectionListener mTransportConnectionListener;
     @Mock private TransportConnectionListener mTransportConnectionListener2;
     @Mock private IBackupTransport.Stub mTransportBinder;
+    private TransportStats mTransportStats;
     private TransportClient mTransportClient;
     private ComponentName mTransportComponent;
     private String mTransportString;
@@ -105,10 +106,12 @@ public class TransportClientTest {
         mTransportComponent =
                 new ComponentName(PACKAGE_NAME, PACKAGE_NAME + ".transport.Transport");
         mTransportString = mTransportComponent.flattenToShortString();
+        mTransportStats = new TransportStats();
         mBindIntent = new Intent(SERVICE_ACTION_TRANSPORT_HOST).setComponent(mTransportComponent);
         mTransportClient =
                 new TransportClient(
                         mContext,
+                        mTransportStats,
                         mBindIntent,
                         mTransportComponent,
                         "1",