OSDN Git Service

atrace: add the 'dalvik' trace category
[android-x86/frameworks-native.git] / cmds / atrace / atrace.cpp
index c6fda97..1911839 100644 (file)
@@ -42,6 +42,7 @@ using namespace android;
 enum { MAX_SYS_FILES = 8 };
 
 const char* k_traceTagsProperty = "debug.atrace.tags.enableflags";
+const char* k_traceAppCmdlineProperty = "debug.atrace.app_cmdlines";
 
 typedef enum { OPT, REQ } requiredness  ;
 
@@ -69,43 +70,46 @@ struct TracingCategory {
 
 /* Tracing categories */
 static const TracingCategory k_categories[] = {
-    { "gfx",    "Graphics",         ATRACE_TAG_GRAPHICS, { } },
-    { "input",  "Input",            ATRACE_TAG_INPUT, { } },
-    { "view",   "View System",      ATRACE_TAG_VIEW, { } },
-    { "wm",     "Window Manager",   ATRACE_TAG_WINDOW_MANAGER, { } },
-    { "am",     "Activity Manager", ATRACE_TAG_ACTIVITY_MANAGER, { } },
-    { "audio",  "Audio",            ATRACE_TAG_AUDIO, { } },
-    { "video",  "Video",            ATRACE_TAG_VIDEO, { } },
-    { "camera", "Camera",           ATRACE_TAG_CAMERA, { } },
-    { "hal",    "Hardware Modules", ATRACE_TAG_HAL, { } },
-    { "sched",  "CPU Scheduling",   0, {
-        { REQ,  "/sys/kernel/debug/tracing/events/sched/sched_switch/enable" },
-        { REQ,  "/sys/kernel/debug/tracing/events/sched/sched_wakeup/enable" },
+    { "gfx",        "Graphics",         ATRACE_TAG_GRAPHICS, { } },
+    { "input",      "Input",            ATRACE_TAG_INPUT, { } },
+    { "view",       "View System",      ATRACE_TAG_VIEW, { } },
+    { "webview",    "WebView",          ATRACE_TAG_WEBVIEW, { } },
+    { "wm",         "Window Manager",   ATRACE_TAG_WINDOW_MANAGER, { } },
+    { "am",         "Activity Manager", ATRACE_TAG_ACTIVITY_MANAGER, { } },
+    { "audio",      "Audio",            ATRACE_TAG_AUDIO, { } },
+    { "video",      "Video",            ATRACE_TAG_VIDEO, { } },
+    { "camera",     "Camera",           ATRACE_TAG_CAMERA, { } },
+    { "hal",        "Hardware Modules", ATRACE_TAG_HAL, { } },
+    { "res",        "Resource Loading", ATRACE_TAG_RESOURCES, { } },
+    { "dalvik",     "Dalvik VM",        ATRACE_TAG_DALVIK, { } },
+    { "sched",      "CPU Scheduling",   0, {
+        { REQ,      "/sys/kernel/debug/tracing/events/sched/sched_switch/enable" },
+        { REQ,      "/sys/kernel/debug/tracing/events/sched/sched_wakeup/enable" },
     } },
-    { "freq",   "CPU Frequency",    0, {
-        { REQ,  "/sys/kernel/debug/tracing/events/power/cpu_frequency/enable" },
-        { OPT, "/sys/kernel/debug/tracing/events/power/clock_set_rate/enable" },
+    { "freq",       "CPU Frequency",    0, {
+        { REQ,      "/sys/kernel/debug/tracing/events/power/cpu_frequency/enable" },
+        { OPT,      "/sys/kernel/debug/tracing/events/power/clock_set_rate/enable" },
     } },
-    { "membus", "Memory Bus Utilization", 0, {
-        { REQ,  "/sys/kernel/debug/tracing/events/memory_bus/enable" },
+    { "membus",     "Memory Bus Utilization", 0, {
+        { REQ,      "/sys/kernel/debug/tracing/events/memory_bus/enable" },
     } },
-    { "idle",   "CPU Idle",         0, {
-        { REQ,  "/sys/kernel/debug/tracing/events/power/cpu_idle/enable" },
+    { "idle",       "CPU Idle",         0, {
+        { REQ,      "/sys/kernel/debug/tracing/events/power/cpu_idle/enable" },
     } },
-    { "disk",   "Disk I/O",         0, {
-        { REQ,  "/sys/kernel/debug/tracing/events/ext4/ext4_sync_file_enter/enable" },
-        { REQ,  "/sys/kernel/debug/tracing/events/ext4/ext4_sync_file_exit/enable" },
-        { REQ,  "/sys/kernel/debug/tracing/events/block/block_rq_issue/enable" },
-        { REQ,  "/sys/kernel/debug/tracing/events/block/block_rq_complete/enable" },
+    { "disk",       "Disk I/O",         0, {
+        { REQ,      "/sys/kernel/debug/tracing/events/ext4/ext4_sync_file_enter/enable" },
+        { REQ,      "/sys/kernel/debug/tracing/events/ext4/ext4_sync_file_exit/enable" },
+        { REQ,      "/sys/kernel/debug/tracing/events/block/block_rq_issue/enable" },
+        { REQ,      "/sys/kernel/debug/tracing/events/block/block_rq_complete/enable" },
     } },
-    { "load",   "CPU Load",         0, {
-        { REQ,  "/sys/kernel/debug/tracing/events/cpufreq_interactive/enable" },
+    { "load",       "CPU Load",         0, {
+        { REQ,      "/sys/kernel/debug/tracing/events/cpufreq_interactive/enable" },
     } },
-    { "sync",   "Synchronization",  0, {
-        { REQ,  "/sys/kernel/debug/tracing/events/sync/enable" },
+    { "sync",       "Synchronization",  0, {
+        { REQ,      "/sys/kernel/debug/tracing/events/sync/enable" },
     } },
-    { "workq",  "Kernel Workqueues", 0, {
-        { REQ,  "/sys/kernel/debug/tracing/events/workqueue/enable" },
+    { "workq",      "Kernel Workqueues", 0, {
+        { REQ,      "/sys/kernel/debug/tracing/events/workqueue/enable" },
     } },
 };
 
@@ -116,6 +120,8 @@ static int g_traceBufferSizeKB = 2048;
 static bool g_compress = false;
 static bool g_nohup = false;
 static int g_initialSleepSecs = 0;
+static const char* g_kernelTraceFuncs = NULL;
+static const char* g_debugAppCmdLine = "";
 
 /* Global state */
 static bool g_traceAborted = false;
@@ -131,6 +137,30 @@ static const char* k_traceBufferSizePath =
 static const char* k_tracingOverwriteEnablePath =
     "/sys/kernel/debug/tracing/options/overwrite";
 
+static const char* k_currentTracerPath =
+    "/sys/kernel/debug/tracing/current_tracer";
+
+static const char* k_printTgidPath =
+    "/sys/kernel/debug/tracing/options/print-tgid";
+
+static const char* k_funcgraphAbsTimePath =
+    "/sys/kernel/debug/tracing/options/funcgraph-abstime";
+
+static const char* k_funcgraphCpuPath =
+    "/sys/kernel/debug/tracing/options/funcgraph-cpu";
+
+static const char* k_funcgraphProcPath =
+    "/sys/kernel/debug/tracing/options/funcgraph-proc";
+
+static const char* k_funcgraphFlatPath =
+    "/sys/kernel/debug/tracing/options/funcgraph-flat";
+
+static const char* k_funcgraphDurationPath =
+    "/sys/kernel/debug/tracing/options/funcgraph-duration";
+
+static const char* k_ftraceFilterPath =
+    "/sys/kernel/debug/tracing/set_ftrace_filter";
+
 static const char* k_tracingOnPath =
     "/sys/kernel/debug/tracing/tracing_on";
 
@@ -147,10 +177,27 @@ static bool fileIsWritable(const char* filename) {
     return access(filename, W_OK) != -1;
 }
 
-// Write a string to a file, returning true if the write was successful.
-static bool writeStr(const char* filename, const char* str)
+// Truncate a file.
+static bool truncateFile(const char* path)
+{
+    // This uses creat rather than truncate because some of the debug kernel
+    // device nodes (e.g. k_ftraceFilterPath) currently aren't changed by
+    // calls to truncate, but they are cleared by calls to creat.
+    int traceFD = creat(path, 0);
+    if (traceFD == -1) {
+        fprintf(stderr, "error truncating %s: %s (%d)\n", path,
+            strerror(errno), errno);
+        return false;
+    }
+
+    close(traceFD);
+
+    return true;
+}
+
+static bool _writeStr(const char* filename, const char* str, int flags)
 {
-    int fd = open(filename, O_WRONLY);
+    int fd = open(filename, flags);
     if (fd == -1) {
         fprintf(stderr, "error opening %s: %s (%d)\n", filename,
                 strerror(errno), errno);
@@ -170,6 +217,18 @@ static bool writeStr(const char* filename, const char* str)
     return ok;
 }
 
+// Write a string to a file, returning true if the write was successful.
+static bool writeStr(const char* filename, const char* str)
+{
+    return _writeStr(filename, str, O_WRONLY);
+}
+
+// Append a string to a file, returning true if the write was successful.
+static bool appendStr(const char* filename, const char* str)
+{
+    return _writeStr(filename, str, O_APPEND|O_WRONLY);
+}
+
 // Enable or disable a kernel option by writing a "1" or a "0" into a /sys
 // file.
 static bool setKernelOptionEnable(const char* filename, bool enable)
@@ -243,16 +302,7 @@ static bool setTracingEnabled(bool enable)
 // Clear the contents of the kernel trace.
 static bool clearTrace()
 {
-    int traceFD = creat(k_tracePath, 0);
-    if (traceFD == -1) {
-        fprintf(stderr, "error truncating %s: %s (%d)\n", k_tracePath,
-                strerror(errno), errno);
-        return false;
-    }
-
-    close(traceFD);
-
-    return true;
+    return truncateFile(k_tracePath);
 }
 
 // Set the size of the kernel's trace buffer in kilobytes.
@@ -274,6 +324,14 @@ static bool setGlobalClockEnable(bool enable)
     return writeStr(k_traceClockPath, enable ? "global" : "local");
 }
 
+static bool setPrintTgidEnableIfPresent(bool enable)
+{
+    if (fileExists(k_printTgidPath)) {
+        return setKernelOptionEnable(k_printTgidPath, enable);
+    }
+    return true;
+}
+
 // Poke all the binder-enabled processes in the system to get them to re-read
 // their system properties.
 static bool pokeBinderServices()
@@ -311,7 +369,18 @@ static bool setTagsProperty(uint64_t tags)
         fprintf(stderr, "error setting trace tags system property\n");
         return false;
     }
-    return pokeBinderServices();
+    return true;
+}
+
+// Set the system property that indicates which apps should perform
+// application-level tracing.
+static bool setAppCmdlineProperty(const char* cmdline)
+{
+    if (property_set(k_traceAppCmdlineProperty, cmdline) < 0) {
+        fprintf(stderr, "error setting trace app system property\n");
+        return false;
+    }
+    return true;
 }
 
 // Disable all /sys/ enable files.
@@ -329,8 +398,92 @@ static bool disableKernelTraceEvents() {
     return ok;
 }
 
-// Enable tracing in the kernel.
-static bool startTrace()
+// Verify that the comma separated list of functions are being traced by the
+// kernel.
+static bool verifyKernelTraceFuncs(const char* funcs)
+{
+    int fd = open(k_ftraceFilterPath, O_RDONLY);
+    if (fd == -1) {
+        fprintf(stderr, "error opening %s: %s (%d)\n", k_ftraceFilterPath,
+            strerror(errno), errno);
+        return false;
+    }
+
+    char buf[4097];
+    ssize_t n = read(fd, buf, 4096);
+    close(fd);
+    if (n == -1) {
+        fprintf(stderr, "error reading %s: %s (%d)\n", k_ftraceFilterPath,
+            strerror(errno), errno);
+        return false;
+    }
+
+    buf[n] = '\0';
+    String8 funcList = String8::format("\n%s", buf);
+
+    // Make sure that every function listed in funcs is in the list we just
+    // read from the kernel.
+    bool ok = true;
+    char* myFuncs = strdup(funcs);
+    char* func = strtok(myFuncs, ",");
+    while (func) {
+        String8 fancyFunc = String8::format("\n%s\n", func);
+        bool found = funcList.find(fancyFunc.string(), 0) >= 0;
+        if (!found || func[0] == '\0') {
+            fprintf(stderr, "error: \"%s\" is not a valid kernel function "
+                "to trace.\n", func);
+            ok = false;
+        }
+        func = strtok(NULL, ",");
+    }
+    free(myFuncs);
+
+    return ok;
+}
+
+// Set the comma separated list of functions that the kernel is to trace.
+static bool setKernelTraceFuncs(const char* funcs)
+{
+    bool ok = true;
+
+    if (funcs == NULL || funcs[0] == '\0') {
+        // Disable kernel function tracing.
+        if (fileIsWritable(k_currentTracerPath)) {
+            ok &= writeStr(k_currentTracerPath, "nop");
+        }
+        if (fileIsWritable(k_ftraceFilterPath)) {
+            ok &= truncateFile(k_ftraceFilterPath);
+        }
+    } else {
+        // Enable kernel function tracing.
+        ok &= writeStr(k_currentTracerPath, "function_graph");
+        ok &= setKernelOptionEnable(k_funcgraphAbsTimePath, true);
+        ok &= setKernelOptionEnable(k_funcgraphCpuPath, true);
+        ok &= setKernelOptionEnable(k_funcgraphProcPath, true);
+        ok &= setKernelOptionEnable(k_funcgraphFlatPath, true);
+
+        // Set the requested filter functions.
+        ok &= truncateFile(k_ftraceFilterPath);
+        char* myFuncs = strdup(funcs);
+        char* func = strtok(myFuncs, ",");
+        while (func) {
+            ok &= appendStr(k_ftraceFilterPath, func);
+            func = strtok(NULL, ",");
+        }
+        free(myFuncs);
+
+        // Verify that the set functions are being traced.
+        if (ok) {
+            ok &= verifyKernelTraceFuncs(funcs);
+        }
+    }
+
+    return ok;
+}
+
+// Set all the kernel tracing settings to the desired state for this trace
+// capture.
+static bool setUpTrace()
 {
     bool ok = true;
 
@@ -338,6 +491,8 @@ static bool startTrace()
     ok &= setTraceOverwriteEnable(g_traceOverwrite);
     ok &= setTraceBufferSizeKB(g_traceBufferSizeKB);
     ok &= setGlobalClockEnable(true);
+    ok &= setPrintTgidEnableIfPresent(true);
+    ok &= setKernelTraceFuncs(g_kernelTraceFuncs);
 
     // Set up the tags property.
     uint64_t tags = 0;
@@ -348,6 +503,8 @@ static bool startTrace()
         }
     }
     ok &= setTagsProperty(tags);
+    ok &= setAppCmdlineProperty(g_debugAppCmdLine);
+    ok &= pokeBinderServices();
 
     // Disable all the sysfs enables.  This is done as a separate loop from
     // the enables to allow the same enable to exist in multiple categories.
@@ -372,30 +529,39 @@ static bool startTrace()
         }
     }
 
-    // Enable tracing.
-    ok &= setTracingEnabled(true);
-
     return ok;
 }
 
-// Disable tracing in the kernel.
-static void stopTrace()
+// Reset all the kernel tracing settings to their default state.
+static void cleanUpTrace()
 {
-    // Disable tracing.
-    setTracingEnabled(false);
-
     // Disable all tracing that we're able to.
     disableKernelTraceEvents();
 
-    // Disable all the trace tags.
+    // Reset the system properties.
     setTagsProperty(0);
+    setAppCmdlineProperty("");
+    pokeBinderServices();
 
     // Set the options back to their defaults.
     setTraceOverwriteEnable(true);
+    setTraceBufferSizeKB(1);
     setGlobalClockEnable(false);
+    setPrintTgidEnableIfPresent(false);
+    setKernelTraceFuncs(NULL);
+}
+
+
+// Enable tracing in the kernel.
+static bool startTrace()
+{
+    return setTracingEnabled(true);
+}
 
-    // Note that we can't reset the trace buffer size here because that would
-    // clear the trace before we've read it.
+// Disable tracing in the kernel.
+static void stopTrace()
+{
+    setTracingEnabled(false);
 }
 
 // Read the current kernel trace and write it to stdout.
@@ -553,8 +719,11 @@ static void showHelp(const char *cmd)
 {
     fprintf(stderr, "usage: %s [options] [categories...]\n", cmd);
     fprintf(stderr, "options include:\n"
+                    "  -a appname      enable app-level tracing for a comma "
+                        "separated list of cmdlines\n"
                     "  -b N            use a trace buffer size of N KB\n"
                     "  -c              trace into a circular buffer\n"
+                    "  -k fname,...    trace the listed kernel functions\n"
                     "  -n              ignore signals\n"
                     "  -s N            sleep for N seconds before tracing [default 0]\n"
                     "  -t N            trace for N seconds [defualt 5]\n"
@@ -591,7 +760,7 @@ int main(int argc, char **argv)
             {           0,                0, 0,  0 }
         };
 
-        ret = getopt_long(argc, argv, "b:cns:t:z",
+        ret = getopt_long(argc, argv, "a:b:ck:ns:t:z",
                           long_options, &option_index);
 
         if (ret < 0) {
@@ -605,6 +774,10 @@ int main(int argc, char **argv)
         }
 
         switch(ret) {
+            case 'a':
+                g_debugAppCmdLine = optarg;
+            break;
+
             case 'b':
                 g_traceBufferSizeKB = atoi(optarg);
             break;
@@ -613,9 +786,13 @@ int main(int argc, char **argv)
                 g_traceOverwrite = true;
             break;
 
+            case 'k':
+                g_kernelTraceFuncs = optarg;
+            break;
+
             case 'n':
                 g_nohup = true;
-                break;
+            break;
 
             case 's':
                 g_initialSleepSecs = atoi(optarg);
@@ -646,7 +823,7 @@ int main(int argc, char **argv)
                     listSupportedCategories();
                     exit(0);
                 }
-                break;
+            break;
 
             default:
                 fprintf(stderr, "\n");
@@ -662,7 +839,9 @@ int main(int argc, char **argv)
         sleep(g_initialSleepSecs);
     }
 
-    bool ok = startTrace();
+    bool ok = true;
+    ok &= setUpTrace();
+    ok &= startTrace();
 
     if (ok && traceStart) {
         printf("capturing trace...");
@@ -708,7 +887,7 @@ int main(int argc, char **argv)
 
     // Reset the trace buffer size to 1.
     if (traceStop)
-        setTraceBufferSizeKB(1);
+        cleanUpTrace();
 
     return g_traceAborted ? 1 : 0;
 }