Performance measurement framework:

+ For bug 1810508
  - Added PerformanceCollector class to collect runtime and memory usage data
    * Moved performance snapshotting from Intrumentation to PerformanceCollector
  - Added PerformanceResultsWriter interface which defines functions for
    reporting performance data

+ Framework integration
  - Added TimedTest annotation to automatically time tests and write results
    to instrumentation output
  - Modified PerformanceTestBase to add collection hooks and wrapper methods
  - Modified WatcherResultPrinter in InstrumentationTestRunner to implement
    PerformanceResultsWriter for instrumentation output of performance data
  - Modified InstrumentationTestRunner and AndroidTestRunner to pass writer
    instance to test

1 files changed, 524 insertions, 0 deletions

diff --git a/core/java/android/os/PerformanceCollector.java b/core/java/android/os/PerformanceCollector.java
new file mode 100644
index 0000000..4ca1f32
--- /dev/null
+++ b/core/java/android/os/PerformanceCollector.java
@@ -0,0 +1,524 @@
+/*
+ * Copyright (C) 2009 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.os;
+
+
+import java.util.ArrayList;
+
+/**
+ * Collects performance data between two function calls in Bundle objects and
+ * outputs the results using writer of type {@link PerformanceResultsWriter}.
+ * <p>
+ * {@link #beginSnapshot(String)} and {@link #endSnapshot()} functions collect
+ * memory usage information and measure runtime between calls to begin and end.
+ * These functions logically wrap around an entire test, and should be called
+ * with name of test as the label, e.g. EmailPerformanceTest.
+ * <p>
+ * {@link #startTiming(String)} and {@link #stopTiming(String)} functions
+ * measure runtime between calls to start and stop. These functions logically
+ * wrap around a single test case or a small block of code, and should be called
+ * with the name of test case as the label, e.g. testSimpleSendMailSequence.
+ * <p>
+ * {@link #addIteration(String)} inserts intermediate measurement point which
+ * can be labeled with a String, e.g. Launch email app, compose, send, etc.
+ * <p>
+ * Snapshot and timing functions do not interfere with each other, and thus can
+ * be called in any order. The intended structure is to wrap begin/endSnapshot
+ * around calls to start/stopTiming, for example:
+ * <p>
+ * <code>beginSnapshot("EmailPerformanceTest");
+ * startTiming("testSimpleSendSequence");
+ * addIteration("Launch email app");
+ * addIteration("Compose");
+ * stopTiming("Send");
+ * startTiming("testComplexSendSequence");
+ * stopTiming("");
+ * startTiming("testAddLabel");
+ * stopTiming("");
+ * endSnapshot();</code>
+ * <p>
+ * Structure of results output is up to implementor of
+ * {@link PerformanceResultsWriter }.
+ *
+ * {@hide} Pending approval for public API.
+ */
+public class PerformanceCollector {
+
+    /**
+     * Interface for reporting performance data.
+     */
+    public interface PerformanceResultsWriter {
+
+        /**
+         * Callback invoked as first action in
+         * PerformanceCollector#beginSnapshot(String) for reporting the start of
+         * a performance snapshot.
+         *
+         * @param label description of code block between beginSnapshot and
+         *              PerformanceCollector#endSnapshot()
+         * @see PerformanceCollector#beginSnapshot(String)
+         */
+        public void writeBeginSnapshot(String label);
+
+        /**
+         * Callback invoked as last action in PerformanceCollector#endSnapshot()
+         * for reporting performance data collected in the snapshot.
+         *
+         * @param results memory and runtime metrics stored as key/value pairs,
+         *        in the same structure as returned by
+         *        PerformanceCollector#endSnapshot()
+         * @see PerformanceCollector#endSnapshot()
+         */
+        public void writeEndSnapshot(Bundle results);
+
+        /**
+         * Callback invoked as first action in
+         * PerformanceCollector#startTiming(String) for reporting the start of
+         * a timing measurement.
+         *
+         * @param label description of code block between startTiming and
+         *              PerformanceCollector#stopTiming(String)
+         * @see PerformanceCollector#startTiming(String)
+         */
+        public void writeStartTiming(String label);
+
+        /**
+         * Callback invoked as last action in
+         * {@link PerformanceCollector#stopTiming(String)} for reporting the
+         * sequence of timings measured.
+         *
+         * @param results runtime metrics of code block between calls to
+         *                startTiming and stopTiming, in the same structure as
+         *                returned by PerformanceCollector#stopTiming(String)
+         * @see PerformanceCollector#stopTiming(String)
+         */
+        public void writeStopTiming(Bundle results);
+    }
+
+    /**
+     * In a results Bundle, this key references a List of iteration Bundles.
+     */
+    public static final String METRIC_KEY_ITERATIONS = "iterations";
+    /**
+     * In an iteration Bundle, this key describes the iteration.
+     */
+    public static final String METRIC_KEY_LABEL = "label";
+    /**
+     * In a results Bundle, this key reports the cpu time of the code block
+     * under measurement.
+     */
+    public static final String METRIC_KEY_CPU_TIME = "cpu_time";
+    /**
+     * In a results Bundle, this key reports the execution time of the code
+     * block under measurement.
+     */
+    public static final String METRIC_KEY_EXECUTION_TIME = "execution_time";
+    /**
+     * In a snapshot Bundle, this key reports the number of received
+     * transactions from the binder driver before collection started.
+     */
+    public static final String METRIC_KEY_PRE_RECEIVED_TRANSACTIONS = "pre_received_transactions";
+    /**
+     * In a snapshot Bundle, this key reports the number of transactions sent by
+     * the running program before collection started.
+     */
+    public static final String METRIC_KEY_PRE_SENT_TRANSACTIONS = "pre_sent_transactions";
+    /**
+     * In a snapshot Bundle, this key reports the number of received
+     * transactions from the binder driver.
+     */
+    public static final String METRIC_KEY_RECEIVED_TRANSACTIONS = "received_transactions";
+    /**
+     * In a snapshot Bundle, this key reports the number of transactions sent by
+     * the running program.
+     */
+    public static final String METRIC_KEY_SENT_TRANSACTIONS = "sent_transactions";
+    /**
+     * In a snapshot Bundle, this key reports the number of garbage collection
+     * invocations.
+     */
+    public static final String METRIC_KEY_GC_INVOCATION_COUNT = "gc_invocation_count";
+    /**
+     * In a snapshot Bundle, this key reports the amount of allocated memory
+     * used by the running program.
+     */
+    public static final String METRIC_KEY_JAVA_ALLOCATED = "java_allocated";
+    /**
+     * In a snapshot Bundle, this key reports the amount of free memory
+     * available to the running program.
+     */
+    public static final String METRIC_KEY_JAVA_FREE = "java_free";
+    /**
+     * In a snapshot Bundle, this key reports the number of private dirty pages
+     * used by dalvik.
+     */
+    public static final String METRIC_KEY_JAVA_PRIVATE_DIRTY = "java_private_dirty";
+    /**
+     * In a snapshot Bundle, this key reports the proportional set size for
+     * dalvik.
+     */
+    public static final String METRIC_KEY_JAVA_PSS = "java_pss";
+    /**
+     * In a snapshot Bundle, this key reports the number of shared dirty pages
+     * used by dalvik.
+     */
+    public static final String METRIC_KEY_JAVA_SHARED_DIRTY = "java_shared_dirty";
+    /**
+     * In a snapshot Bundle, this key reports the total amount of memory
+     * available to the running program.
+     */
+    public static final String METRIC_KEY_JAVA_SIZE = "java_size";
+    /**
+     * In a snapshot Bundle, this key reports the amount of allocated memory in
+     * the native heap.
+     */
+    public static final String METRIC_KEY_NATIVE_ALLOCATED = "native_allocated";
+    /**
+     * In a snapshot Bundle, this key reports the amount of free memory in the
+     * native heap.
+     */
+    public static final String METRIC_KEY_NATIVE_FREE = "native_free";
+    /**
+     * In a snapshot Bundle, this key reports the number of private dirty pages
+     * used by the native heap.
+     */
+    public static final String METRIC_KEY_NATIVE_PRIVATE_DIRTY = "native_private_dirty";
+    /**
+     * In a snapshot Bundle, this key reports the proportional set size for the
+     * native heap.
+     */
+    public static final String METRIC_KEY_NATIVE_PSS = "native_pss";
+    /**
+     * In a snapshot Bundle, this key reports the number of shared dirty pages
+     * used by the native heap.
+     */
+    public static final String METRIC_KEY_NATIVE_SHARED_DIRTY = "native_shared_dirty";
+    /**
+     * In a snapshot Bundle, this key reports the size of the native heap.
+     */
+    public static final String METRIC_KEY_NATIVE_SIZE = "native_size";
+    /**
+     * In a snapshot Bundle, this key reports the number of objects allocated
+     * globally.
+     */
+    public static final String METRIC_KEY_GLOBAL_ALLOC_COUNT = "global_alloc_count";
+    /**
+     * In a snapshot Bundle, this key reports the size of all objects allocated
+     * globally.
+     */
+    public static final String METRIC_KEY_GLOBAL_ALLOC_SIZE = "global_alloc_size";
+    /**
+     * In a snapshot Bundle, this key reports the number of objects freed
+     * globally.
+     */
+    public static final String METRIC_KEY_GLOBAL_FREED_COUNT = "global_freed_count";
+    /**
+     * In a snapshot Bundle, this key reports the size of all objects freed
+     * globally.
+     */
+    public static final String METRIC_KEY_GLOBAL_FREED_SIZE = "global_freed_size";
+    /**
+     * In a snapshot Bundle, this key reports the number of private dirty pages
+     * used by everything else.
+     */
+    public static final String METRIC_KEY_OTHER_PRIVATE_DIRTY = "other_private_dirty";
+    /**
+     * In a snapshot Bundle, this key reports the proportional set size for
+     * everything else.
+     */
+    public static final String METRIC_KEY_OTHER_PSS = "other_pss";
+    /**
+     * In a snapshot Bundle, this key reports the number of shared dirty pages
+     * used by everything else.
+     */
+    public static final String METRIC_KEY_OTHER_SHARED_DIRTY = "other_shared_dirty";
+
+    private PerformanceResultsWriter mPerfWriter;
+    private Bundle mPerfSnapshot;
+    private Bundle mPerfMeasurement;
+    private long mSnapshotCpuTime;
+    private long mSnapshotExecTime;
+    private long mCpuTime;
+    private long mExecTime;
+
+    public PerformanceCollector() {
+    }
+
+    public PerformanceCollector(PerformanceResultsWriter writer) {
+        setPerformanceResultsWriter(writer);
+    }
+
+    public void setPerformanceResultsWriter(PerformanceResultsWriter writer) {
+        mPerfWriter = writer;
+    }
+
+    /**
+     * Begin collection of memory usage information.
+     *
+     * @param label description of code block between beginSnapshot and
+     *              endSnapshot, used to label output
+     */
+    public void beginSnapshot(String label) {
+        if (mPerfWriter != null)
+            mPerfWriter.writeBeginSnapshot(label);
+        startPerformanceSnapshot();
+    }
+
+    /**
+     * End collection of memory usage information. Returns collected data in a
+     * Bundle object.
+     *
+     * @return Memory and runtime metrics stored as key/value pairs. Values are
+     *         of type long, and keys include:
+     *         <ul>
+     *         <li>{@link #METRIC_KEY_CPU_TIME cpu_time}
+     *         <li>{@link #METRIC_KEY_EXECUTION_TIME execution_time}
+     *         <li>{@link #METRIC_KEY_PRE_RECEIVED_TRANSACTIONS
+     *         pre_received_transactions}
+     *         <li>{@link #METRIC_KEY_PRE_SENT_TRANSACTIONS
+     *         pre_sent_transactions}
+     *         <li>{@link #METRIC_KEY_RECEIVED_TRANSACTIONS
+     *         received_transactions}
+     *         <li>{@link #METRIC_KEY_SENT_TRANSACTIONS sent_transactions}
+     *         <li>{@link #METRIC_KEY_GC_INVOCATION_COUNT gc_invocation_count}
+     *         <li>{@link #METRIC_KEY_JAVA_ALLOCATED java_allocated}
+     *         <li>{@link #METRIC_KEY_JAVA_FREE java_free}
+     *         <li>{@link #METRIC_KEY_JAVA_PRIVATE_DIRTY java_private_dirty}
+     *         <li>{@link #METRIC_KEY_JAVA_PSS java_pss}
+     *         <li>{@link #METRIC_KEY_JAVA_SHARED_DIRTY java_shared_dirty}
+     *         <li>{@link #METRIC_KEY_JAVA_SIZE java_size}
+     *         <li>{@link #METRIC_KEY_NATIVE_ALLOCATED native_allocated}
+     *         <li>{@link #METRIC_KEY_NATIVE_FREE native_free}
+     *         <li>{@link #METRIC_KEY_NATIVE_PRIVATE_DIRTY native_private_dirty}
+     *         <li>{@link #METRIC_KEY_NATIVE_PSS native_pss}
+     *         <li>{@link #METRIC_KEY_NATIVE_SHARED_DIRTY native_shared_dirty}
+     *         <li>{@link #METRIC_KEY_NATIVE_SIZE native_size}
+     *         <li>{@link #METRIC_KEY_GLOBAL_ALLOC_COUNT global_alloc_count}
+     *         <li>{@link #METRIC_KEY_GLOBAL_ALLOC_SIZE global_alloc_size}
+     *         <li>{@link #METRIC_KEY_GLOBAL_FREED_COUNT global_freed_count}
+     *         <li>{@link #METRIC_KEY_GLOBAL_FREED_SIZE global_freed_size}
+     *         <li>{@link #METRIC_KEY_OTHER_PRIVATE_DIRTY other_private_dirty}
+     *         <li>{@link #METRIC_KEY_OTHER_PSS other_pss}
+     *         <li>{@link #METRIC_KEY_OTHER_SHARED_DIRTY other_shared_dirty}
+     *         </ul>
+     */
+    public Bundle endSnapshot() {
+        endPerformanceSnapshot();
+        if (mPerfWriter != null)
+            mPerfWriter.writeEndSnapshot(mPerfSnapshot);
+        return mPerfSnapshot;
+    }
+
+    /**
+     * Start measurement of user and cpu time.
+     *
+     * @param label description of code block between startTiming and
+     *        stopTiming, used to label output
+     */
+    public void startTiming(String label) {
+        if (mPerfWriter != null)
+            mPerfWriter.writeStartTiming(label);
+        mPerfMeasurement = new Bundle();
+        mPerfMeasurement.putParcelableArrayList(
+                METRIC_KEY_ITERATIONS, new ArrayList<Parcelable>());
+        mExecTime = SystemClock.uptimeMillis();
+        mCpuTime = Process.getElapsedCpuTime();
+    }
+
+    /**
+     * Add a measured segment, and start measuring the next segment. Returns
+     * collected data in a Bundle object.
+     *
+     * @param label description of code block between startTiming and
+     *              addIteration, and between two calls to addIteration, used
+     *              to label output
+     * @return Runtime metrics stored as key/value pairs. Values are of type
+     *         long, and keys include:
+     *         <ul>
+     *         <li>{@link #METRIC_KEY_LABEL label}
+     *         <li>{@link #METRIC_KEY_CPU_TIME cpu_time}
+     *         <li>{@link #METRIC_KEY_EXECUTION_TIME execution_time}
+     *         </ul>
+     */
+    public Bundle addIteration(String label) {
+        mCpuTime = Process.getElapsedCpuTime() - mCpuTime;
+        mExecTime = SystemClock.uptimeMillis() - mExecTime;
+
+        Bundle iteration = new Bundle();
+        iteration.putString(METRIC_KEY_LABEL, label);
+        iteration.putLong(METRIC_KEY_EXECUTION_TIME, mExecTime);
+        iteration.putLong(METRIC_KEY_CPU_TIME, mCpuTime);
+        mPerfMeasurement.getParcelableArrayList(METRIC_KEY_ITERATIONS).add(iteration);
+
+        mExecTime = SystemClock.uptimeMillis();
+        mCpuTime = Process.getElapsedCpuTime();
+        return iteration;
+    }
+
+    /**
+     * Stop measurement of user and cpu time.
+     *
+     * @param label description of code block between addIteration or
+     *              startTiming and stopTiming, used to label output
+     * @return Runtime metrics stored in a bundle, including all iterations
+     *         between calls to startTiming and stopTiming. List of iterations
+     *         is keyed by {@link #METRIC_KEY_ITERATIONS iterations}.
+     */
+    public Bundle stopTiming(String label) {
+        addIteration(label);
+        if (mPerfWriter != null)
+            mPerfWriter.writeStopTiming(mPerfMeasurement);
+        return mPerfMeasurement;
+    }
+
+    /*
+     * Starts tracking memory usage, binder transactions, and real & cpu timing.
+     */
+    private void startPerformanceSnapshot() {
+        // Create new snapshot
+        mPerfSnapshot = new Bundle();
+
+        // Add initial binder counts
+        Bundle binderCounts = getBinderCounts();
+        for (String key : binderCounts.keySet()) {
+            mPerfSnapshot.putLong("pre_" + key, binderCounts.getLong(key));
+        }
+
+        // Force a GC and zero out the performance counters. Do this
+        // before reading initial CPU/wall-clock times so we don't include
+        // the cost of this setup in our final metrics.
+        startAllocCounting();
+
+        // Record CPU time up to this point, and start timing. Note: this
+        // must happen at the end of this method, otherwise the timing will
+        // include noise.
+        mSnapshotExecTime = SystemClock.uptimeMillis();
+        mSnapshotCpuTime = Process.getElapsedCpuTime();
+    }
+
+    /*
+     * Stops tracking memory usage, binder transactions, and real & cpu timing.
+     * Stores collected data as type long into Bundle object for reporting.
+     */
+    private void endPerformanceSnapshot() {
+        // Stop the timing. This must be done first before any other counting is
+        // stopped.
+        mSnapshotCpuTime = Process.getElapsedCpuTime() - mSnapshotCpuTime;
+        mSnapshotExecTime = SystemClock.uptimeMillis() - mSnapshotExecTime;
+
+        stopAllocCounting();
+
+        long nativeMax = Debug.getNativeHeapSize() / 1024;
+        long nativeAllocated = Debug.getNativeHeapAllocatedSize() / 1024;
+        long nativeFree = Debug.getNativeHeapFreeSize() / 1024;
+
+        Debug.MemoryInfo memInfo = new Debug.MemoryInfo();
+        Debug.getMemoryInfo(memInfo);
+
+        Runtime runtime = Runtime.getRuntime();
+
+        long dalvikMax = runtime.totalMemory() / 1024;
+        long dalvikFree = runtime.freeMemory() / 1024;
+        long dalvikAllocated = dalvikMax - dalvikFree;
+
+        // Add final binder counts
+        Bundle binderCounts = getBinderCounts();
+        for (String key : binderCounts.keySet()) {
+            mPerfSnapshot.putLong(key, binderCounts.getLong(key));
+        }
+
+        // Add alloc counts
+        Bundle allocCounts = getAllocCounts();
+        for (String key : allocCounts.keySet()) {
+            mPerfSnapshot.putLong(key, allocCounts.getLong(key));
+        }
+
+        mPerfSnapshot.putLong(METRIC_KEY_EXECUTION_TIME, mSnapshotExecTime);
+        mPerfSnapshot.putLong(METRIC_KEY_CPU_TIME, mSnapshotCpuTime);
+
+        mPerfSnapshot.putLong(METRIC_KEY_NATIVE_SIZE, nativeMax);
+        mPerfSnapshot.putLong(METRIC_KEY_NATIVE_ALLOCATED, nativeAllocated);
+        mPerfSnapshot.putLong(METRIC_KEY_NATIVE_FREE, nativeFree);
+        mPerfSnapshot.putLong(METRIC_KEY_NATIVE_PSS, memInfo.nativePss);
+        mPerfSnapshot.putLong(METRIC_KEY_NATIVE_PRIVATE_DIRTY, memInfo.nativePrivateDirty);
+        mPerfSnapshot.putLong(METRIC_KEY_NATIVE_SHARED_DIRTY, memInfo.nativeSharedDirty);
+
+        mPerfSnapshot.putLong(METRIC_KEY_JAVA_SIZE, dalvikMax);
+        mPerfSnapshot.putLong(METRIC_KEY_JAVA_ALLOCATED, dalvikAllocated);
+        mPerfSnapshot.putLong(METRIC_KEY_JAVA_FREE, dalvikFree);
+        mPerfSnapshot.putLong(METRIC_KEY_JAVA_PSS, memInfo.dalvikPss);
+        mPerfSnapshot.putLong(METRIC_KEY_JAVA_PRIVATE_DIRTY, memInfo.dalvikPrivateDirty);
+        mPerfSnapshot.putLong(METRIC_KEY_JAVA_SHARED_DIRTY, memInfo.dalvikSharedDirty);
+
+        mPerfSnapshot.putLong(METRIC_KEY_OTHER_PSS, memInfo.otherPss);
+        mPerfSnapshot.putLong(METRIC_KEY_OTHER_PRIVATE_DIRTY, memInfo.otherPrivateDirty);
+        mPerfSnapshot.putLong(METRIC_KEY_OTHER_SHARED_DIRTY, memInfo.otherSharedDirty);
+    }
+
+    /*
+     * Starts allocation counting. This triggers a gc and resets the counts.
+     */
+    private static void startAllocCounting() {
+        // Before we start trigger a GC and reset the debug counts. Run the
+        // finalizers and another GC before starting and stopping the alloc
+        // counts. This will free up any objects that were just sitting around
+        // waiting for their finalizers to be run.
+        Runtime.getRuntime().gc();
+        Runtime.getRuntime().runFinalization();
+        Runtime.getRuntime().gc();
+
+        Debug.resetAllCounts();
+
+        // start the counts
+        Debug.startAllocCounting();
+    }
+
+    /*
+     * Stops allocation counting.
+     */
+    private static void stopAllocCounting() {
+        Runtime.getRuntime().gc();
+        Runtime.getRuntime().runFinalization();
+        Runtime.getRuntime().gc();
+        Debug.stopAllocCounting();
+    }
+
+    /*
+     * Returns a bundle with the current results from the allocation counting.
+     */
+    private static Bundle getAllocCounts() {
+        Bundle results = new Bundle();
+        results.putLong(METRIC_KEY_GLOBAL_ALLOC_COUNT, Debug.getGlobalAllocCount());
+        results.putLong(METRIC_KEY_GLOBAL_ALLOC_SIZE, Debug.getGlobalAllocSize());
+        results.putLong(METRIC_KEY_GLOBAL_FREED_COUNT, Debug.getGlobalFreedCount());
+        results.putLong(METRIC_KEY_GLOBAL_FREED_SIZE, Debug.getGlobalFreedSize());
+        results.putLong(METRIC_KEY_GC_INVOCATION_COUNT, Debug.getGlobalGcInvocationCount());
+        return results;
+    }
+
+    /*
+     * Returns a bundle with the counts for various binder counts for this
+     * process. Currently the only two that are reported are the number of send
+     * and the number of received transactions.
+     */
+    private static Bundle getBinderCounts() {
+        Bundle results = new Bundle();
+        results.putLong(METRIC_KEY_SENT_TRANSACTIONS, Debug.getBinderSentTransactions());
+        results.putLong(METRIC_KEY_RECEIVED_TRANSACTIONS, Debug.getBinderReceivedTransactions());
+        return results;
+    }
+}