Better systrace slices for application startup.

This change adds three new timeslices :

- PostFork : As soon as possible after the app forks from the
  zygote. Can be used in conjunction with the system_server
  "Start proc:" event to derive an upper bound on fork() and
  zygote overhead.

- RuntimeInit & ActivityThreadMain for ZygoteInit#runtimeInit
  and ActivityThread#main.

ActivityThread#handleBindApplication and higher level functions
are already well instrumented in systrace. handleBindApplication
should occur immediately after ActivityThread#main.

Note that we use the Activity manager tag to make it easier to
correlate these new events with surrounding events (Start proc
and handleBindApplication) that are already using the AM tag.

bug: 21632700
Change-Id: Ibc01f1721f962c913f3c02a51763b6feb1eb6a4d

5 files changed, 23 insertions, 5 deletions

diff --git a/cmds/app_process/app_main.cpp b/cmds/app_process/app_main.cpp
index c5af992..449a4ab 100644
--- a/cmds/app_process/app_main.cpp
+++ b/cmds/app_process/app_main.cpp
@@ -90,9 +90,6 @@ public:
 
     virtual void onZygoteInit()
     {
-        // Re-enable tracing now that we're no longer in Zygote.
-        atrace_set_tracing_enabled(true);
-
         sp<ProcessState> proc = ProcessState::self();
         ALOGV("App process: starting thread pool.\n");
         proc->startThreadPool();
diff --git a/core/java/android/app/ActivityThread.java b/core/java/android/app/ActivityThread.java
index e21c04a..828dc0a 100644
--- a/core/java/android/app/ActivityThread.java
+++ b/core/java/android/app/ActivityThread.java
@@ -5375,6 +5375,7 @@ public final class ActivityThread {
     }
 
     public static void main(String[] args) {
+        Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "ActivityThreadMain");
         SamplingProfilerIntegration.start();
 
         // CloseGuard defaults to true and can be quite spammy.  We
@@ -5409,6 +5410,8 @@ public final class ActivityThread {
                     LogPrinter(Log.DEBUG, "ActivityThread"));
         }
 
+        // End of event ActivityThreadMain.
+        Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
         Looper.loop();
 
         throw new RuntimeException("Main thread loop unexpectedly exited");
diff --git a/core/java/com/android/internal/os/RuntimeInit.java b/core/java/com/android/internal/os/RuntimeInit.java
index 2539a35..f81658e 100644
--- a/core/java/com/android/internal/os/RuntimeInit.java
+++ b/core/java/com/android/internal/os/RuntimeInit.java
@@ -24,6 +24,7 @@ import android.os.Debug;
 import android.os.IBinder;
 import android.os.Process;
 import android.os.SystemProperties;
+import android.os.Trace;
 import android.util.Log;
 import android.util.Slog;
 import com.android.internal.logging.AndroidConfig;
@@ -269,11 +270,11 @@ public class RuntimeInit {
             throws ZygoteInit.MethodAndArgsCaller {
         if (DEBUG) Slog.d(TAG, "RuntimeInit: Starting application from zygote");
 
+        Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "RuntimeInit");
         redirectLogStreams();
 
         commonInit();
         nativeZygoteInit();
-
         applicationInit(targetSdkVersion, argv, classLoader);
     }
 
@@ -318,6 +319,9 @@ public class RuntimeInit {
             return;
         }
 
+        // The end of of the RuntimeInit event (see #zygoteInit).
+        Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
+
         // Remaining arguments are passed to the start class's static main
         invokeStaticMain(args.startClass, args.startArgs, classLoader);
     }
diff --git a/core/java/com/android/internal/os/Zygote.java b/core/java/com/android/internal/os/Zygote.java
index 1e7ee5a..4f6d781 100644
--- a/core/java/com/android/internal/os/Zygote.java
+++ b/core/java/com/android/internal/os/Zygote.java
@@ -17,6 +17,7 @@
 package com.android.internal.os;
 
 
+import android.os.Trace;
 import dalvik.system.ZygoteHooks;
 import android.system.ErrnoException;
 import android.system.Os;
@@ -88,6 +89,13 @@ public final class Zygote {
         int pid = nativeForkAndSpecialize(
                   uid, gid, gids, debugFlags, rlimits, mountExternal, seInfo, niceName, fdsToClose,
                   instructionSet, appDataDir);
+        // Enable tracing as soon as possible for the child process.
+        if (pid == 0) {
+            Trace.setTracingEnabled(true);
+
+            // Note that this event ends at the end of handleChildProc,
+            Trace.traceBegin(Trace.TRACE_TAG_ACTIVITY_MANAGER, "PostFork");
+        }
         VM_HOOKS.postForkCommon();
         return pid;
     }
@@ -124,6 +132,10 @@ public final class Zygote {
         VM_HOOKS.preFork();
         int pid = nativeForkSystemServer(
                 uid, gid, gids, debugFlags, rlimits, permittedCapabilities, effectiveCapabilities);
+        // Enable tracing as soon as we enter the system_server.
+        if (pid == 0) {
+            Trace.setTracingEnabled(true);
+        }
         VM_HOOKS.postForkCommon();
         return pid;
     }
diff --git a/core/java/com/android/internal/os/ZygoteConnection.java b/core/java/com/android/internal/os/ZygoteConnection.java
index 969d236..1a0345b 100644
--- a/core/java/com/android/internal/os/ZygoteConnection.java
+++ b/core/java/com/android/internal/os/ZygoteConnection.java
@@ -27,6 +27,7 @@ import android.net.LocalSocket;
 import android.os.Process;
 import android.os.SELinux;
 import android.os.SystemProperties;
+import android.os.Trace;
 import android.system.ErrnoException;
 import android.system.Os;
 import android.util.Log;
@@ -711,7 +712,6 @@ class ZygoteConnection {
     private void handleChildProc(Arguments parsedArgs,
             FileDescriptor[] descriptors, FileDescriptor pipeFd, PrintStream newStderr)
             throws ZygoteInit.MethodAndArgsCaller {
-
         /**
          * By the time we get here, the native code has closed the two actual Zygote
          * socket connections, and substituted /dev/null in their place.  The LocalSocket
@@ -740,6 +740,8 @@ class ZygoteConnection {
             Process.setArgV0(parsedArgs.niceName);
         }
 
+        // End of the postFork event.
+        Trace.traceEnd(Trace.TRACE_TAG_ACTIVITY_MANAGER);
         if (parsedArgs.invokeWith != null) {
             WrapperInit.execApplication(parsedArgs.invokeWith,
                     parsedArgs.niceName, parsedArgs.targetSdkVersion,