Add profiling tools.

Change-Id: Ieab118ededaab5ef46408fac6fdb66b9fff4900e

4 files changed, 611 insertions, 11 deletions

diff --git a/src/com/android/gallery3d/ui/GLRootView.java b/src/com/android/gallery3d/ui/GLRootView.java
index f2140bf07..3f2269f4f 100644
--- a/src/com/android/gallery3d/ui/GLRootView.java
+++ b/src/com/android/gallery3d/ui/GLRootView.java
@@ -19,6 +19,7 @@ package com.android.gallery3d.ui;
 import com.android.gallery3d.anim.CanvasAnimation;
 import com.android.gallery3d.common.Utils;
 import com.android.gallery3d.util.GalleryUtils;
+import com.android.gallery3d.util.Profile;
 
 import android.app.Activity;
 import android.content.Context;
@@ -59,6 +60,8 @@ public class GLRootView extends GLSurfaceView
 
     private static final boolean DEBUG_DRAWING_STAT = false;
 
+    private static final boolean DEBUG_PROFILE = false;
+
     private static final int FLAG_INITIALIZED = 1;
     private static final int FLAG_NEED_LAYOUT = 2;
 
@@ -87,7 +90,6 @@ public class GLRootView extends GLSurfaceView
 
     private final ReentrantLock mRenderLock = new ReentrantLock();
 
-    private static final int TARGET_FRAME_TIME = 16;
     private long mLastDrawFinishTime;
     private boolean mInDownState = false;
 
@@ -219,10 +221,10 @@ public class GLRootView extends GLSurfaceView
         }
         mGL = gl;
         mCanvas = new GLCanvasImpl(gl);
-        if (!DEBUG_FPS) {
-            setRenderMode(GLSurfaceView.RENDERMODE_WHEN_DIRTY);
-        } else {
+        if (DEBUG_FPS || DEBUG_PROFILE) {
             setRenderMode(GLSurfaceView.RENDERMODE_CONTINUOUSLY);
+        } else {
+            setRenderMode(GLSurfaceView.RENDERMODE_WHEN_DIRTY);
         }
     }
 
@@ -237,6 +239,10 @@ public class GLRootView extends GLSurfaceView
                 + ", gl10: " + gl1.toString());
         Process.setThreadPriority(Process.THREAD_PRIORITY_DISPLAY);
         GalleryUtils.setRenderThread();
+        if (DEBUG_PROFILE) {
+            Log.d(TAG, "Start profiling");
+            Profile.enable(20);  // take a sample every 20ms
+        }
         GL11 gl = (GL11) gl1;
         Utils.assertTrue(mGL == gl);
 
@@ -261,21 +267,31 @@ public class GLRootView extends GLSurfaceView
 
     @Override
     public void onDrawFrame(GL10 gl) {
+        long t0;
+        if (DEBUG_PROFILE) {
+            Profile.hold();
+            t0 = System.nanoTime();
+        }
         mRenderLock.lock();
         try {
             onDrawFrameLocked(gl);
         } finally {
             mRenderLock.unlock();
         }
-        long end = SystemClock.uptimeMillis();
-
-        if (mLastDrawFinishTime != 0) {
-            long wait = mLastDrawFinishTime + TARGET_FRAME_TIME - end;
-            if (wait > 0) {
-                SystemClock.sleep(wait);
+        if (DEBUG_PROFILE) {
+            long t = System.nanoTime();
+            long durationInMs = (t - mLastDrawFinishTime) / 1000000;
+            long durationDrawInMs = (t - t0) / 1000000;
+            mLastDrawFinishTime = t;
+
+            if (durationInMs > 34) {  // 34ms -> we skipped at least 2 frames
+                Log.v(TAG, "----- SLOW (" + durationDrawInMs + "/" +
+                        durationInMs + ") -----");
+                Profile.commit();
+            } else {
+                Profile.drop();
             }
         }
-        mLastDrawFinishTime = SystemClock.uptimeMillis();
     }
 
     private void onDrawFrameLocked(GL10 gl) {
@@ -411,4 +427,15 @@ public class GLRootView extends GLSurfaceView
     public void unlockRenderThread() {
         mRenderLock.unlock();
     }
+
+    @Override
+    public void onPause() {
+        super.onPause();
+        if (DEBUG_PROFILE) {
+            Log.d(TAG, "Stop profiling");
+            Profile.disableAll();
+            Profile.dumpToFile("/sdcard/gallery.prof");
+            Profile.reset();
+        }
+    }
 }
diff --git a/src/com/android/gallery3d/util/Profile.java b/src/com/android/gallery3d/util/Profile.java
new file mode 100644
index 000000000..96a815397
--- /dev/null
+++ b/src/com/android/gallery3d/util/Profile.java
@@ -0,0 +1,227 @@
+/*
+ * Copyright (C) 2012 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.gallery3d.util;
+
+import com.android.gallery3d.common.Utils;
+
+import android.os.Handler;
+import android.os.HandlerThread;
+import android.os.Process;
+import android.util.Log;
+
+import java.util.ArrayList;
+import java.util.Random;
+
+// The Profile class is used to collect profiling information for a thread. It
+// samples stack traces for a thread periodically. enable() and disable() is
+// used to enable and disable profiling for the calling thread. The profiling
+// information can then be dumped to a file using the dumpToFile() method.
+//
+// The disableAll() method can be used to disable profiling for all threads and
+// can be called in onPause() to ensure all profiling is disabled when an
+// activity is paused.
+public class Profile {
+    private static final String TAG = "Profile";
+    private static final int NS_PER_MS = 1000000;
+
+    // This is a watchdog entry for one thread.
+    // For every cycleTime period, we dump the stack of the thread.
+    private static class WatchEntry {
+        Thread thread;
+
+        // Both are in milliseconds
+        int cycleTime;
+        int wakeTime;
+
+        boolean isHolding;
+        ArrayList<String[]> holdingStacks = new ArrayList<String[]>();
+    }
+
+    // This is a watchdog thread which dumps stacks of other threads periodically.
+    private static Watchdog sWatchdog = new Watchdog();
+
+    private static class Watchdog {
+        private ArrayList<WatchEntry> mList = new ArrayList<WatchEntry>();
+        private HandlerThread mHandlerThread;
+        private Handler mHandler;
+        private Runnable mProcessRunnable = new Runnable() {
+            public void run() {
+                synchronized (Watchdog.this) {
+                    processList();
+                }
+            }
+        };
+        private Random mRandom = new Random();
+        private ProfileData mProfileData = new ProfileData();
+
+        public Watchdog() {
+            mHandlerThread = new HandlerThread("Watchdog Handler",
+                    Process.THREAD_PRIORITY_FOREGROUND);
+            mHandlerThread.start();
+            mHandler = new Handler(mHandlerThread.getLooper());
+        }
+
+        public synchronized void addWatchEntry(Thread thread, int cycleTime) {
+            WatchEntry e = new WatchEntry();
+            e.thread = thread;
+            e.cycleTime = cycleTime;
+            int firstDelay = 1 + mRandom.nextInt(cycleTime);
+            e.wakeTime = (int) (System.nanoTime() / NS_PER_MS) + firstDelay;
+            mList.add(e);
+            processList();
+        }
+
+        public synchronized void removeWatchEntry(Thread thread) {
+            for (int i = 0; i < mList.size(); i++) {
+                if (mList.get(i).thread == thread) {
+                    mList.remove(i);
+                    break;
+                }
+            }
+            processList();
+        }
+
+        public synchronized void removeAllWatchEntries() {
+            mList.clear();
+            processList();
+        }
+
+        private void processList() {
+            mHandler.removeCallbacks(mProcessRunnable);
+            if (mList.size() == 0) return;
+
+            int currentTime = (int) (System.nanoTime() / NS_PER_MS);
+            int nextWakeTime = 0;
+
+            for (WatchEntry entry : mList) {
+                if (currentTime > entry.wakeTime) {
+                    entry.wakeTime += entry.cycleTime;
+                    Thread thread = entry.thread;
+                    sampleStack(entry);
+                }
+
+                if (entry.wakeTime > nextWakeTime) {
+                    nextWakeTime = entry.wakeTime;
+                }
+            }
+
+            long delay = nextWakeTime - currentTime;
+            mHandler.postDelayed(mProcessRunnable, delay);
+        }
+
+        private void sampleStack(WatchEntry entry) {
+            Thread thread = entry.thread;
+            StackTraceElement[] stack = thread.getStackTrace();
+            String[] lines = new String[stack.length];
+            for (int i = 0; i < stack.length; i++) {
+                lines[i] = stack[i].toString();
+            }
+            if (entry.isHolding) {
+                entry.holdingStacks.add(lines);
+            } else {
+                mProfileData.addSample(lines);
+            }
+        }
+
+        private WatchEntry findEntry(Thread thread) {
+            for (int i = 0; i < mList.size(); i++) {
+                WatchEntry entry = mList.get(i);
+                if (entry.thread == thread) return entry;
+            }
+            return null;
+        }
+
+        public synchronized void dumpToFile(String filename) {
+            mProfileData.dumpToFile(filename);
+        }
+
+        public synchronized void reset() {
+            mProfileData.reset();
+        }
+
+        public synchronized void hold(Thread t) {
+            WatchEntry entry = findEntry(t);
+
+            // This can happen if the profiling is disabled (probably from
+            // another thread). Same check is applied in commit() and drop()
+            // below.
+            if (entry == null) return;
+
+            entry.isHolding = true;
+        }
+
+        public synchronized void commit(Thread t) {
+            WatchEntry entry = findEntry(t);
+            if (entry == null) return;
+            ArrayList<String[]> stacks = entry.holdingStacks;
+            for (int i = 0; i < stacks.size(); i++) {
+                mProfileData.addSample(stacks.get(i));
+            }
+            entry.isHolding = false;
+            entry.holdingStacks.clear();
+        }
+
+        public synchronized void drop(Thread t) {
+            WatchEntry entry = findEntry(t);
+            if (entry == null) return;
+            entry.isHolding = false;
+            entry.holdingStacks.clear();
+        }
+    }
+
+    // Enable profiling for the calling thread. Periodically (every cycleTimeInMs
+    // milliseconds) sample the stack trace of the calling thread.
+    public static void enable(int cycleTimeInMs) {
+        Thread t = Thread.currentThread();
+        sWatchdog.addWatchEntry(t, cycleTimeInMs);
+    }
+
+    // Disable profiling for the calling thread.
+    public static void disable() {
+        sWatchdog.removeWatchEntry(Thread.currentThread());
+    }
+
+    // Disable profiling for all threads.
+    public static void disableAll() {
+        sWatchdog.removeAllWatchEntries();
+    }
+
+    // Dump the profiling data to a file.
+    public static void dumpToFile(String filename) {
+        sWatchdog.dumpToFile(filename);
+    }
+
+    // Reset the collected profiling data.
+    public static void reset() {
+        sWatchdog.reset();
+    }
+
+    // Hold the future samples coming from current thread until commit() or
+    // drop() is called, and those samples are recorded or ignored as a result.
+    // This must called after enable() to be effective.
+    public static void hold() {
+        sWatchdog.hold(Thread.currentThread());
+    }
+
+    public static void commit() {
+        sWatchdog.commit(Thread.currentThread());
+    }
+
+    public static void drop() {
+        sWatchdog.drop(Thread.currentThread());
+    }
+}
diff --git a/src/com/android/gallery3d/util/ProfileData.java b/src/com/android/gallery3d/util/ProfileData.java
new file mode 100644
index 000000000..8de4c76ca
--- /dev/null
+++ b/src/com/android/gallery3d/util/ProfileData.java
@@ -0,0 +1,167 @@
+/*
+ * Copyright (C) 2012 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.gallery3d.util;
+
+import com.android.gallery3d.common.Utils;
+
+import android.util.Log;
+
+import java.io.DataOutputStream;
+import java.io.FileOutputStream;
+import java.io.IOException;
+import java.util.ArrayList;
+import java.util.HashMap;
+import java.util.Map.Entry;
+
+// ProfileData keeps profiling samples in a tree structure.
+// The addSample() method adds a sample. The dumpToFile() method saves the data
+// to a file. The reset() method clears all samples.
+public class ProfileData {
+    private static final String TAG = "ProfileData";
+
+    private static class Node {
+        public int id;  // this is the name of this node, mapped from mNameToId
+        public Node parent;
+        public int sampleCount;
+        public ArrayList<Node> children;
+        public Node(Node parent, int id) {
+            this.parent = parent;
+            this.id = id;
+        }
+    }
+
+    private Node mRoot;
+    private int mNextId;
+    private HashMap<String, Integer> mNameToId;
+    private DataOutputStream mOut;
+    private byte mScratch[] = new byte[4];  // scratch space for writeInt()
+
+    public ProfileData() {
+        mRoot = new Node(null, -1);  // The id of the root node is unused.
+        mNameToId = new HashMap<String, Integer>();
+    }
+
+    public void reset() {
+        mRoot = new Node(null, -1);
+        mNameToId.clear();
+        mNextId = 0;
+    }
+
+    private int nameToId(String name) {
+        Integer id = mNameToId.get(name);
+        if (id == null) {
+            id = ++mNextId;  // The tool doesn't want id=0, so we start from 1.
+            mNameToId.put(name, id);
+        }
+        return id;
+    }
+
+    public void addSample(String[] stack) {
+        int[] ids = new int[stack.length];
+        for (int i = 0; i < stack.length; i++) {
+            ids[i] = nameToId(stack[i]);
+        }
+
+        Node node = mRoot;
+        for (int i = stack.length - 1; i >= 0; i--) {
+            if (node.children == null) {
+                node.children = new ArrayList<Node>();
+            }
+
+            int id = ids[i];
+            ArrayList<Node> children = node.children;
+            int j;
+            for (j = 0; j < children.size(); j++) {
+                if (children.get(j).id == id) break;
+            }
+            if (j == children.size()) {
+                children.add(new Node(node, id));
+            }
+
+            node = children.get(j);
+        }
+
+        node.sampleCount++;
+    }
+
+    public void dumpToFile(String filename) {
+        try {
+            mOut = new DataOutputStream(new FileOutputStream(filename));
+            // Start record
+            writeInt(0);
+            writeInt(3);
+            writeInt(1);
+            writeInt(20000);  // Sampling period: 20ms
+            writeInt(0);
+
+            // Samples
+            writeAllStacks(mRoot, 0);
+
+            // End record
+            writeInt(0);
+            writeInt(1);
+            writeInt(0);
+            writeAllSymbols();
+        } catch (IOException ex) {
+            Log.w("Failed to dump to file", ex);
+        } finally {
+            Utils.closeSilently(mOut);
+        }
+    }
+
+    // Writes out one stack, consisting of N+2 words:
+    // first word: sample count
+    // second word: depth of the stack (N)
+    // N words: each word is the id of one address in the stack
+    private void writeOneStack(Node node, int depth) throws IOException {
+        writeInt(node.sampleCount);
+        writeInt(depth);
+        while (depth-- > 0) {
+            writeInt(node.id);
+            node = node.parent;
+        }
+    }
+
+    private void writeAllStacks(Node node, int depth) throws IOException {
+        if (node.sampleCount > 0) {
+            writeOneStack(node, depth);
+        }
+
+        ArrayList<Node> children = node.children;
+        if (children != null) {
+            for (int i = 0; i < children.size(); i++) {
+                writeAllStacks(children.get(i), depth + 1);
+            }
+        }
+    }
+
+    // Writes out the symbol table. Each line is like:
+    // 0x17e java.util.ArrayList.isEmpty(ArrayList.java:319)
+    private void writeAllSymbols() throws IOException {
+        for (Entry<String, Integer> entry : mNameToId.entrySet()) {
+            mOut.writeBytes(String.format("0x%x %s\n", entry.getValue(), entry.getKey()));
+        }
+    }
+
+    private void writeInt(int v) throws IOException {
+        mScratch[0] = (byte) v;
+        mScratch[1] = (byte) (v >> 8);
+        mScratch[2] = (byte) (v >> 16);
+        mScratch[3] = (byte) (v >> 24);
+        mOut.write(mScratch);
+    }
+}
diff --git a/tests/src/com/android/gallery3d/util/ProfileTest.java b/tests/src/com/android/gallery3d/util/ProfileTest.java
new file mode 100644
index 000000000..798b905f5
--- /dev/null
+++ b/tests/src/com/android/gallery3d/util/ProfileTest.java
@@ -0,0 +1,179 @@
+/*
+ * Copyright (C) 2012 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.gallery3d.util;
+
+import com.android.gallery3d.util.Profile;
+
+import android.os.Environment;
+import android.test.suitebuilder.annotation.SmallTest;
+import android.util.Log;
+
+import java.io.DataInputStream;
+import java.io.File;
+import java.io.FileInputStream;
+import java.io.IOException;
+import java.util.ArrayList;
+import java.util.HashMap;
+import junit.framework.Assert;
+import junit.framework.TestCase;
+
+@SmallTest
+public class ProfileTest extends TestCase {
+    private static final String TAG = "ProfileTest";
+    private static final String TEST_FILE =
+            Environment.getExternalStorageDirectory().getPath() + "/test.dat";
+
+
+    public void testProfile() throws IOException {
+        ProfileData p = new ProfileData();
+        ParsedProfile q;
+        String[] A = {"A"};
+        String[] B = {"B"};
+        String[] AC = {"A", "C"};
+        String[] AD = {"A", "D"};
+
+        // Empty profile
+        p.dumpToFile(TEST_FILE);
+        q = new ParsedProfile(TEST_FILE);
+        assertTrue(q.mEntries.isEmpty());
+        assertTrue(q.mSymbols.isEmpty());
+
+        // Only one sample
+        p.addSample(A);
+        p.dumpToFile(TEST_FILE);
+        q = new ParsedProfile(TEST_FILE);
+        assertEquals(1, q.mEntries.size());
+        assertEquals(1, q.mSymbols.size());
+        assertEquals(1, q.mEntries.get(0).sampleCount);
+
+        // Two samples at the same place
+        p.addSample(A);
+        p.dumpToFile(TEST_FILE);
+        q = new ParsedProfile(TEST_FILE);
+        assertEquals(1, q.mEntries.size());
+        assertEquals(1, q.mSymbols.size());
+        assertEquals(2, q.mEntries.get(0).sampleCount);
+
+        // Two samples at the different places
+        p.reset();
+        p.addSample(A);
+        p.addSample(B);
+        p.dumpToFile(TEST_FILE);
+        q = new ParsedProfile(TEST_FILE);
+        assertEquals(2, q.mEntries.size());
+        assertEquals(2, q.mSymbols.size());
+        assertEquals(1, q.mEntries.get(0).sampleCount);
+        assertEquals(1, q.mEntries.get(1).sampleCount);
+
+        // depth > 1
+        p.reset();
+        p.addSample(AC);
+        p.dumpToFile(TEST_FILE);
+        q = new ParsedProfile(TEST_FILE);
+        assertEquals(1, q.mEntries.size());
+        assertEquals(2, q.mSymbols.size());
+        assertEquals(1, q.mEntries.get(0).sampleCount);
+
+        // two samples (AC and AD)
+        p.addSample(AD);
+        p.dumpToFile(TEST_FILE);
+        q = new ParsedProfile(TEST_FILE);
+        assertEquals(2, q.mEntries.size());
+        assertEquals(3, q.mSymbols.size());  // three symbols: A, C, D
+        assertEquals(1, q.mEntries.get(0).sampleCount);
+        assertEquals(1, q.mEntries.get(0).sampleCount);
+
+        // Remove the test file
+        new File(TEST_FILE).delete();
+    }
+}
+
+class ParsedProfile {
+    public class Entry {
+        int sampleCount;
+        int stackId[];
+    }
+
+    ArrayList<Entry> mEntries = new ArrayList<Entry>();
+    HashMap<Integer, String> mSymbols = new HashMap<Integer, String>();
+    private DataInputStream mIn;
+    private byte[] mScratch = new byte[4];  // scratch buffer for readInt
+
+    public ParsedProfile(String filename) throws IOException {
+        mIn = new DataInputStream(new FileInputStream(filename));
+
+        Entry entry = parseOneEntry();
+        checkIsFirstEntry(entry);
+
+        while (true) {
+            entry = parseOneEntry();
+            if (entry.sampleCount == 0) {
+                checkIsLastEntry(entry);
+                break;
+            }
+            mEntries.add(entry);
+        }
+
+        // Read symbol table
+        while (true) {
+            String line = mIn.readLine();
+            if (line == null) break;
+            String[] fields = line.split(" +");
+            checkIsValidSymbolLine(fields);
+            mSymbols.put(Integer.decode(fields[0]), fields[1]);
+        }
+    }
+
+    private void checkIsFirstEntry(Entry entry) {
+        Assert.assertEquals(0, entry.sampleCount);
+        Assert.assertEquals(3, entry.stackId.length);
+        Assert.assertEquals(1, entry.stackId[0]);
+        Assert.assertTrue(entry.stackId[1] > 0);  // sampling period
+        Assert.assertEquals(0, entry.stackId[2]);  // padding
+    }
+
+    private void checkIsLastEntry(Entry entry) {
+        Assert.assertEquals(0, entry.sampleCount);
+        Assert.assertEquals(1, entry.stackId.length);
+        Assert.assertEquals(0, entry.stackId[0]);
+    }
+
+    private void checkIsValidSymbolLine(String[] fields) {
+        Assert.assertEquals(2, fields.length);
+        Assert.assertTrue(fields[0].startsWith("0x"));
+    }
+
+    private Entry parseOneEntry() throws IOException {
+        int sampleCount = readInt();
+        int depth = readInt();
+        Entry e = new Entry();
+        e.sampleCount = sampleCount;
+        e.stackId = new int[depth];
+        for (int i = 0; i < depth; i++) {
+            e.stackId[i] = readInt();
+        }
+        return e;
+    }
+
+    private int readInt() throws IOException {
+        mIn.read(mScratch, 0, 4);
+        return (mScratch[0] & 0xff) |
+                ((mScratch[1] & 0xff) << 8) |
+                ((mScratch[2] & 0xff) << 16) |
+                ((mScratch[3] & 0xff) << 24);
+    }
+}