atrace.cpp revision 0db38b1133ad18201c0e5c436dd33bdff787ccaf
1/*
2 * Copyright (C) 2012 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 *      http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17#include <errno.h>
18#include <fcntl.h>
19#include <getopt.h>
20#include <inttypes.h>
21#include <signal.h>
22#include <stdarg.h>
23#include <stdbool.h>
24#include <stdio.h>
25#include <stdlib.h>
26#include <string.h>
27#include <sys/sendfile.h>
28#include <time.h>
29#include <zlib.h>
30
31#include <binder/IBinder.h>
32#include <binder/IServiceManager.h>
33#include <binder/Parcel.h>
34
35#include <cutils/properties.h>
36
37#include <utils/String8.h>
38#include <utils/Timers.h>
39#include <utils/Tokenizer.h>
40#include <utils/Trace.h>
41
42using namespace android;
43
44#define NELEM(x) ((int) (sizeof(x) / sizeof((x)[0])))
45
46enum { MAX_SYS_FILES = 10 };
47
48const char* k_traceTagsProperty = "debug.atrace.tags.enableflags";
49const char* k_traceAppCmdlineProperty = "debug.atrace.app_cmdlines";
50
51typedef enum { OPT, REQ } requiredness  ;
52
53struct TracingCategory {
54    // The name identifying the category.
55    const char* name;
56
57    // A longer description of the category.
58    const char* longname;
59
60    // The userland tracing tags that the category enables.
61    uint64_t tags;
62
63    // The fname==NULL terminated list of /sys/ files that the category
64    // enables.
65    struct {
66        // Whether the file must be writable in order to enable the tracing
67        // category.
68        requiredness required;
69
70        // The path to the enable file.
71        const char* path;
72    } sysfiles[MAX_SYS_FILES];
73};
74
75/* Tracing categories */
76static const TracingCategory k_categories[] = {
77    { "gfx",        "Graphics",         ATRACE_TAG_GRAPHICS, { } },
78    { "input",      "Input",            ATRACE_TAG_INPUT, { } },
79    { "view",       "View System",      ATRACE_TAG_VIEW, { } },
80    { "webview",    "WebView",          ATRACE_TAG_WEBVIEW, { } },
81    { "wm",         "Window Manager",   ATRACE_TAG_WINDOW_MANAGER, { } },
82    { "am",         "Activity Manager", ATRACE_TAG_ACTIVITY_MANAGER, { } },
83    { "sm",         "Sync Manager",     ATRACE_TAG_SYNC_MANAGER, { } },
84    { "audio",      "Audio",            ATRACE_TAG_AUDIO, { } },
85    { "video",      "Video",            ATRACE_TAG_VIDEO, { } },
86    { "camera",     "Camera",           ATRACE_TAG_CAMERA, { } },
87    { "hal",        "Hardware Modules", ATRACE_TAG_HAL, { } },
88    { "app",        "Application",      ATRACE_TAG_APP, { } },
89    { "res",        "Resource Loading", ATRACE_TAG_RESOURCES, { } },
90    { "dalvik",     "Dalvik VM",        ATRACE_TAG_DALVIK, { } },
91    { "rs",         "RenderScript",     ATRACE_TAG_RS, { } },
92    { "bionic",     "Bionic C Library", ATRACE_TAG_BIONIC, { } },
93    { "power",      "Power Management", ATRACE_TAG_POWER, { } },
94    { "pm",         "Package Manager",  ATRACE_TAG_PACKAGE_MANAGER, { } },
95    { "ss",         "System Server",    ATRACE_TAG_SYSTEM_SERVER, { } },
96    { "sched",      "CPU Scheduling",   0, {
97        { REQ,      "/sys/kernel/debug/tracing/events/sched/sched_switch/enable" },
98        { REQ,      "/sys/kernel/debug/tracing/events/sched/sched_wakeup/enable" },
99        { OPT,      "/sys/kernel/debug/tracing/events/sched/sched_blocked_reason/enable" },
100    } },
101    { "irq",        "IRQ Events",   0, {
102        { REQ,      "/sys/kernel/debug/tracing/events/irq/enable" },
103        { OPT,      "/sys/kernel/debug/tracing/events/ipi/enable" },
104    } },
105    { "freq",       "CPU Frequency",    0, {
106        { REQ,      "/sys/kernel/debug/tracing/events/power/cpu_frequency/enable" },
107        { OPT,      "/sys/kernel/debug/tracing/events/power/clock_set_rate/enable" },
108    } },
109    { "membus",     "Memory Bus Utilization", 0, {
110        { REQ,      "/sys/kernel/debug/tracing/events/memory_bus/enable" },
111    } },
112    { "idle",       "CPU Idle",         0, {
113        { REQ,      "/sys/kernel/debug/tracing/events/power/cpu_idle/enable" },
114    } },
115    { "disk",       "Disk I/O",         0, {
116        { OPT,      "/sys/kernel/debug/tracing/events/f2fs/f2fs_sync_file_enter/enable" },
117        { OPT,      "/sys/kernel/debug/tracing/events/f2fs/f2fs_sync_file_exit/enable" },
118        { OPT,      "/sys/kernel/debug/tracing/events/f2fs/f2fs_write_begin/enable" },
119        { OPT,      "/sys/kernel/debug/tracing/events/f2fs/f2fs_write_end/enable" },
120        { OPT,      "/sys/kernel/debug/tracing/events/ext4/ext4_da_write_begin/enable" },
121        { OPT,      "/sys/kernel/debug/tracing/events/ext4/ext4_da_write_end/enable" },
122        { OPT,      "/sys/kernel/debug/tracing/events/ext4/ext4_sync_file_enter/enable" },
123        { OPT,      "/sys/kernel/debug/tracing/events/ext4/ext4_sync_file_exit/enable" },
124        { REQ,      "/sys/kernel/debug/tracing/events/block/block_rq_issue/enable" },
125        { REQ,      "/sys/kernel/debug/tracing/events/block/block_rq_complete/enable" },
126    } },
127    { "mmc",        "eMMC commands",    0, {
128        { REQ,      "/sys/kernel/debug/tracing/events/mmc/enable" },
129    } },
130    { "load",       "CPU Load",         0, {
131        { REQ,      "/sys/kernel/debug/tracing/events/cpufreq_interactive/enable" },
132    } },
133    { "sync",       "Synchronization",  0, {
134        { REQ,      "/sys/kernel/debug/tracing/events/sync/enable" },
135    } },
136    { "workq",      "Kernel Workqueues", 0, {
137        { REQ,      "/sys/kernel/debug/tracing/events/workqueue/enable" },
138    } },
139    { "memreclaim", "Kernel Memory Reclaim", 0, {
140        { REQ,      "/sys/kernel/debug/tracing/events/vmscan/mm_vmscan_direct_reclaim_begin/enable" },
141        { REQ,      "/sys/kernel/debug/tracing/events/vmscan/mm_vmscan_direct_reclaim_end/enable" },
142        { REQ,      "/sys/kernel/debug/tracing/events/vmscan/mm_vmscan_kswapd_wake/enable" },
143        { REQ,      "/sys/kernel/debug/tracing/events/vmscan/mm_vmscan_kswapd_sleep/enable" },
144    } },
145    { "regulators",  "Voltage and Current Regulators", 0, {
146        { REQ,      "/sys/kernel/debug/tracing/events/regulator/enable" },
147    } },
148    { "binder_driver", "Binder Kernel driver", 0, {
149        { REQ,      "/sys/kernel/debug/tracing/events/binder/binder_transaction/enable" },
150        { REQ,      "/sys/kernel/debug/tracing/events/binder/binder_transaction_received/enable" },
151    } },
152    { "binder_lock", "Binder global lock trace", 0, {
153        { REQ,      "/sys/kernel/debug/tracing/events/binder/binder_lock/enable" },
154        { REQ,      "/sys/kernel/debug/tracing/events/binder/binder_locked/enable" },
155        { REQ,      "/sys/kernel/debug/tracing/events/binder/binder_unlock/enable" },
156    } },
157    { "pagecache",  "Page cache", 0, {
158        { REQ,      "/sys/kernel/debug/tracing/events/filemap/enable" },
159    } },
160};
161
162/* Command line options */
163static int g_traceDurationSeconds = 5;
164static bool g_traceOverwrite = false;
165static int g_traceBufferSizeKB = 2048;
166static bool g_compress = false;
167static bool g_nohup = false;
168static int g_initialSleepSecs = 0;
169static const char* g_categoriesFile = NULL;
170static const char* g_kernelTraceFuncs = NULL;
171static const char* g_debugAppCmdLine = "";
172
173/* Global state */
174static bool g_traceAborted = false;
175static bool g_categoryEnables[NELEM(k_categories)] = {};
176
177/* Sys file paths */
178static const char* k_traceClockPath =
179    "/sys/kernel/debug/tracing/trace_clock";
180
181static const char* k_traceBufferSizePath =
182    "/sys/kernel/debug/tracing/buffer_size_kb";
183
184static const char* k_tracingOverwriteEnablePath =
185    "/sys/kernel/debug/tracing/options/overwrite";
186
187static const char* k_currentTracerPath =
188    "/sys/kernel/debug/tracing/current_tracer";
189
190static const char* k_printTgidPath =
191    "/sys/kernel/debug/tracing/options/print-tgid";
192
193static const char* k_funcgraphAbsTimePath =
194    "/sys/kernel/debug/tracing/options/funcgraph-abstime";
195
196static const char* k_funcgraphCpuPath =
197    "/sys/kernel/debug/tracing/options/funcgraph-cpu";
198
199static const char* k_funcgraphProcPath =
200    "/sys/kernel/debug/tracing/options/funcgraph-proc";
201
202static const char* k_funcgraphFlatPath =
203    "/sys/kernel/debug/tracing/options/funcgraph-flat";
204
205static const char* k_funcgraphDurationPath =
206    "/sys/kernel/debug/tracing/options/funcgraph-duration";
207
208static const char* k_ftraceFilterPath =
209    "/sys/kernel/debug/tracing/set_ftrace_filter";
210
211static const char* k_tracingOnPath =
212    "/sys/kernel/debug/tracing/tracing_on";
213
214static const char* k_tracePath =
215    "/sys/kernel/debug/tracing/trace";
216
217static const char* k_traceMarkerPath =
218    "/sys/kernel/debug/tracing/trace_marker";
219
220// Check whether a file exists.
221static bool fileExists(const char* filename) {
222    return access(filename, F_OK) != -1;
223}
224
225// Check whether a file is writable.
226static bool fileIsWritable(const char* filename) {
227    return access(filename, W_OK) != -1;
228}
229
230// Truncate a file.
231static bool truncateFile(const char* path)
232{
233    // This uses creat rather than truncate because some of the debug kernel
234    // device nodes (e.g. k_ftraceFilterPath) currently aren't changed by
235    // calls to truncate, but they are cleared by calls to creat.
236    int traceFD = creat(path, 0);
237    if (traceFD == -1) {
238        fprintf(stderr, "error truncating %s: %s (%d)\n", path,
239            strerror(errno), errno);
240        return false;
241    }
242
243    close(traceFD);
244
245    return true;
246}
247
248static bool _writeStr(const char* filename, const char* str, int flags)
249{
250    int fd = open(filename, flags);
251    if (fd == -1) {
252        fprintf(stderr, "error opening %s: %s (%d)\n", filename,
253                strerror(errno), errno);
254        return false;
255    }
256
257    bool ok = true;
258    ssize_t len = strlen(str);
259    if (write(fd, str, len) != len) {
260        fprintf(stderr, "error writing to %s: %s (%d)\n", filename,
261                strerror(errno), errno);
262        ok = false;
263    }
264
265    close(fd);
266
267    return ok;
268}
269
270// Write a string to a file, returning true if the write was successful.
271static bool writeStr(const char* filename, const char* str)
272{
273    return _writeStr(filename, str, O_WRONLY);
274}
275
276// Append a string to a file, returning true if the write was successful.
277static bool appendStr(const char* filename, const char* str)
278{
279    return _writeStr(filename, str, O_APPEND|O_WRONLY);
280}
281
282static void writeClockSyncMarker()
283{
284  char buffer[128];
285  int len = 0;
286  int fd = open(k_traceMarkerPath, O_WRONLY);
287  if (fd == -1) {
288      fprintf(stderr, "error opening %s: %s (%d)\n", k_traceMarkerPath,
289              strerror(errno), errno);
290      return;
291  }
292  float now_in_seconds = systemTime(CLOCK_MONOTONIC) / 1000000000.0f;
293
294  len = snprintf(buffer, 128, "trace_event_clock_sync: parent_ts=%f\n", now_in_seconds);
295  if (write(fd, buffer, len) != len) {
296      fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
297  }
298
299  int64_t realtime_in_ms = systemTime(CLOCK_REALTIME) / 1000000;
300  len = snprintf(buffer, 128, "trace_event_clock_sync: realtime_ts=%" PRId64 "\n", realtime_in_ms);
301  if (write(fd, buffer, len) != len) {
302      fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
303  }
304
305  close(fd);
306}
307
308// Enable or disable a kernel option by writing a "1" or a "0" into a /sys
309// file.
310static bool setKernelOptionEnable(const char* filename, bool enable)
311{
312    return writeStr(filename, enable ? "1" : "0");
313}
314
315// Check whether the category is supported on the device with the current
316// rootness.  A category is supported only if all its required /sys/ files are
317// writable and if enabling the category will enable one or more tracing tags
318// or /sys/ files.
319static bool isCategorySupported(const TracingCategory& category)
320{
321    bool ok = category.tags != 0;
322    for (int i = 0; i < MAX_SYS_FILES; i++) {
323        const char* path = category.sysfiles[i].path;
324        bool req = category.sysfiles[i].required == REQ;
325        if (path != NULL) {
326            if (req) {
327                if (!fileIsWritable(path)) {
328                    return false;
329                } else {
330                    ok = true;
331                }
332            } else {
333                ok |= fileIsWritable(path);
334            }
335        }
336    }
337    return ok;
338}
339
340// Check whether the category would be supported on the device if the user
341// were root.  This function assumes that root is able to write to any file
342// that exists.  It performs the same logic as isCategorySupported, but it
343// uses file existance rather than writability in the /sys/ file checks.
344static bool isCategorySupportedForRoot(const TracingCategory& category)
345{
346    bool ok = category.tags != 0;
347    for (int i = 0; i < MAX_SYS_FILES; i++) {
348        const char* path = category.sysfiles[i].path;
349        bool req = category.sysfiles[i].required == REQ;
350        if (path != NULL) {
351            if (req) {
352                if (!fileExists(path)) {
353                    return false;
354                } else {
355                    ok = true;
356                }
357            } else {
358                ok |= fileExists(path);
359            }
360        }
361    }
362    return ok;
363}
364
365// Enable or disable overwriting of the kernel trace buffers.  Disabling this
366// will cause tracing to stop once the trace buffers have filled up.
367static bool setTraceOverwriteEnable(bool enable)
368{
369    return setKernelOptionEnable(k_tracingOverwriteEnablePath, enable);
370}
371
372// Enable or disable kernel tracing.
373static bool setTracingEnabled(bool enable)
374{
375    return setKernelOptionEnable(k_tracingOnPath, enable);
376}
377
378// Clear the contents of the kernel trace.
379static bool clearTrace()
380{
381    return truncateFile(k_tracePath);
382}
383
384// Set the size of the kernel's trace buffer in kilobytes.
385static bool setTraceBufferSizeKB(int size)
386{
387    char str[32] = "1";
388    int len;
389    if (size < 1) {
390        size = 1;
391    }
392    snprintf(str, 32, "%d", size);
393    return writeStr(k_traceBufferSizePath, str);
394}
395
396// Read the trace_clock sysfs file and return true if it matches the requested
397// value.  The trace_clock file format is:
398// local [global] counter uptime perf
399static bool isTraceClock(const char *mode)
400{
401    int fd = open(k_traceClockPath, O_RDONLY);
402    if (fd == -1) {
403        fprintf(stderr, "error opening %s: %s (%d)\n", k_traceClockPath,
404            strerror(errno), errno);
405        return false;
406    }
407
408    char buf[4097];
409    ssize_t n = read(fd, buf, 4096);
410    close(fd);
411    if (n == -1) {
412        fprintf(stderr, "error reading %s: %s (%d)\n", k_traceClockPath,
413            strerror(errno), errno);
414        return false;
415    }
416    buf[n] = '\0';
417
418    char *start = strchr(buf, '[');
419    if (start == NULL) {
420        return false;
421    }
422    start++;
423
424    char *end = strchr(start, ']');
425    if (end == NULL) {
426        return false;
427    }
428    *end = '\0';
429
430    return strcmp(mode, start) == 0;
431}
432
433// Enable or disable the kernel's use of the global clock.  Disabling the global
434// clock will result in the kernel using a per-CPU local clock.
435// Any write to the trace_clock sysfs file will reset the buffer, so only
436// update it if the requested value is not the current value.
437static bool setGlobalClockEnable(bool enable)
438{
439    const char *clock = enable ? "global" : "local";
440
441    if (isTraceClock(clock)) {
442        return true;
443    }
444
445    return writeStr(k_traceClockPath, clock);
446}
447
448static bool setPrintTgidEnableIfPresent(bool enable)
449{
450    if (fileExists(k_printTgidPath)) {
451        return setKernelOptionEnable(k_printTgidPath, enable);
452    }
453    return true;
454}
455
456// Poke all the binder-enabled processes in the system to get them to re-read
457// their system properties.
458static bool pokeBinderServices()
459{
460    sp<IServiceManager> sm = defaultServiceManager();
461    Vector<String16> services = sm->listServices();
462    for (size_t i = 0; i < services.size(); i++) {
463        sp<IBinder> obj = sm->checkService(services[i]);
464        if (obj != NULL) {
465            Parcel data;
466            if (obj->transact(IBinder::SYSPROPS_TRANSACTION, data,
467                    NULL, 0) != OK) {
468                if (false) {
469                    // XXX: For some reason this fails on tablets trying to
470                    // poke the "phone" service.  It's not clear whether some
471                    // are expected to fail.
472                    String8 svc(services[i]);
473                    fprintf(stderr, "error poking binder service %s\n",
474                        svc.string());
475                    return false;
476                }
477            }
478        }
479    }
480    return true;
481}
482
483// Set the trace tags that userland tracing uses, and poke the running
484// processes to pick up the new value.
485static bool setTagsProperty(uint64_t tags)
486{
487    char buf[64];
488    snprintf(buf, 64, "%#" PRIx64, tags);
489    if (property_set(k_traceTagsProperty, buf) < 0) {
490        fprintf(stderr, "error setting trace tags system property\n");
491        return false;
492    }
493    return true;
494}
495
496// Set the system property that indicates which apps should perform
497// application-level tracing.
498static bool setAppCmdlineProperty(const char* cmdline)
499{
500    if (property_set(k_traceAppCmdlineProperty, cmdline) < 0) {
501        fprintf(stderr, "error setting trace app system property\n");
502        return false;
503    }
504    return true;
505}
506
507// Disable all /sys/ enable files.
508static bool disableKernelTraceEvents() {
509    bool ok = true;
510    for (int i = 0; i < NELEM(k_categories); i++) {
511        const TracingCategory &c = k_categories[i];
512        for (int j = 0; j < MAX_SYS_FILES; j++) {
513            const char* path = c.sysfiles[j].path;
514            if (path != NULL && fileIsWritable(path)) {
515                ok &= setKernelOptionEnable(path, false);
516            }
517        }
518    }
519    return ok;
520}
521
522// Verify that the comma separated list of functions are being traced by the
523// kernel.
524static bool verifyKernelTraceFuncs(const char* funcs)
525{
526    int fd = open(k_ftraceFilterPath, O_RDONLY);
527    if (fd == -1) {
528        fprintf(stderr, "error opening %s: %s (%d)\n", k_ftraceFilterPath,
529            strerror(errno), errno);
530        return false;
531    }
532
533    char buf[4097];
534    ssize_t n = read(fd, buf, 4096);
535    close(fd);
536    if (n == -1) {
537        fprintf(stderr, "error reading %s: %s (%d)\n", k_ftraceFilterPath,
538            strerror(errno), errno);
539        return false;
540    }
541
542    buf[n] = '\0';
543    String8 funcList = String8::format("\n%s", buf);
544
545    // Make sure that every function listed in funcs is in the list we just
546    // read from the kernel.
547    bool ok = true;
548    char* myFuncs = strdup(funcs);
549    char* func = strtok(myFuncs, ",");
550    while (func) {
551        String8 fancyFunc = String8::format("\n%s\n", func);
552        bool found = funcList.find(fancyFunc.string(), 0) >= 0;
553        if (!found || func[0] == '\0') {
554            fprintf(stderr, "error: \"%s\" is not a valid kernel function "
555                "to trace.\n", func);
556            ok = false;
557        }
558        func = strtok(NULL, ",");
559    }
560    free(myFuncs);
561
562    return ok;
563}
564
565// Set the comma separated list of functions that the kernel is to trace.
566static bool setKernelTraceFuncs(const char* funcs)
567{
568    bool ok = true;
569
570    if (funcs == NULL || funcs[0] == '\0') {
571        // Disable kernel function tracing.
572        if (fileIsWritable(k_currentTracerPath)) {
573            ok &= writeStr(k_currentTracerPath, "nop");
574        }
575        if (fileIsWritable(k_ftraceFilterPath)) {
576            ok &= truncateFile(k_ftraceFilterPath);
577        }
578    } else {
579        // Enable kernel function tracing.
580        ok &= writeStr(k_currentTracerPath, "function_graph");
581        ok &= setKernelOptionEnable(k_funcgraphAbsTimePath, true);
582        ok &= setKernelOptionEnable(k_funcgraphCpuPath, true);
583        ok &= setKernelOptionEnable(k_funcgraphProcPath, true);
584        ok &= setKernelOptionEnable(k_funcgraphFlatPath, true);
585
586        // Set the requested filter functions.
587        ok &= truncateFile(k_ftraceFilterPath);
588        char* myFuncs = strdup(funcs);
589        char* func = strtok(myFuncs, ",");
590        while (func) {
591            ok &= appendStr(k_ftraceFilterPath, func);
592            func = strtok(NULL, ",");
593        }
594        free(myFuncs);
595
596        // Verify that the set functions are being traced.
597        if (ok) {
598            ok &= verifyKernelTraceFuncs(funcs);
599        }
600    }
601
602    return ok;
603}
604
605static bool setCategoryEnable(const char* name, bool enable)
606{
607    for (int i = 0; i < NELEM(k_categories); i++) {
608        const TracingCategory& c = k_categories[i];
609        if (strcmp(name, c.name) == 0) {
610            if (isCategorySupported(c)) {
611                g_categoryEnables[i] = enable;
612                return true;
613            } else {
614                if (isCategorySupportedForRoot(c)) {
615                    fprintf(stderr, "error: category \"%s\" requires root "
616                            "privileges.\n", name);
617                } else {
618                    fprintf(stderr, "error: category \"%s\" is not supported "
619                            "on this device.\n", name);
620                }
621                return false;
622            }
623        }
624    }
625    fprintf(stderr, "error: unknown tracing category \"%s\"\n", name);
626    return false;
627}
628
629static bool setCategoriesEnableFromFile(const char* categories_file)
630{
631    if (!categories_file) {
632        return true;
633    }
634    Tokenizer* tokenizer = NULL;
635    if (Tokenizer::open(String8(categories_file), &tokenizer) != NO_ERROR) {
636        return false;
637    }
638    bool ok = true;
639    while (!tokenizer->isEol()) {
640        String8 token = tokenizer->nextToken(" ");
641        if (token.isEmpty()) {
642            tokenizer->skipDelimiters(" ");
643            continue;
644        }
645        ok &= setCategoryEnable(token.string(), true);
646    }
647    delete tokenizer;
648    return ok;
649}
650
651// Set all the kernel tracing settings to the desired state for this trace
652// capture.
653static bool setUpTrace()
654{
655    bool ok = true;
656
657    // Set up the tracing options.
658    ok &= setCategoriesEnableFromFile(g_categoriesFile);
659    ok &= setTraceOverwriteEnable(g_traceOverwrite);
660    ok &= setTraceBufferSizeKB(g_traceBufferSizeKB);
661    ok &= setGlobalClockEnable(true);
662    ok &= setPrintTgidEnableIfPresent(true);
663    ok &= setKernelTraceFuncs(g_kernelTraceFuncs);
664
665    // Set up the tags property.
666    uint64_t tags = 0;
667    for (int i = 0; i < NELEM(k_categories); i++) {
668        if (g_categoryEnables[i]) {
669            const TracingCategory &c = k_categories[i];
670            tags |= c.tags;
671        }
672    }
673    ok &= setTagsProperty(tags);
674    ok &= setAppCmdlineProperty(g_debugAppCmdLine);
675    ok &= pokeBinderServices();
676
677    // Disable all the sysfs enables.  This is done as a separate loop from
678    // the enables to allow the same enable to exist in multiple categories.
679    ok &= disableKernelTraceEvents();
680
681    // Enable all the sysfs enables that are in an enabled category.
682    for (int i = 0; i < NELEM(k_categories); i++) {
683        if (g_categoryEnables[i]) {
684            const TracingCategory &c = k_categories[i];
685            for (int j = 0; j < MAX_SYS_FILES; j++) {
686                const char* path = c.sysfiles[j].path;
687                bool required = c.sysfiles[j].required == REQ;
688                if (path != NULL) {
689                    if (fileIsWritable(path)) {
690                        ok &= setKernelOptionEnable(path, true);
691                    } else if (required) {
692                        fprintf(stderr, "error writing file %s\n", path);
693                        ok = false;
694                    }
695                }
696            }
697        }
698    }
699
700    return ok;
701}
702
703// Reset all the kernel tracing settings to their default state.
704static void cleanUpTrace()
705{
706    // Disable all tracing that we're able to.
707    disableKernelTraceEvents();
708
709    // Reset the system properties.
710    setTagsProperty(0);
711    setAppCmdlineProperty("");
712    pokeBinderServices();
713
714    // Set the options back to their defaults.
715    setTraceOverwriteEnable(true);
716    setTraceBufferSizeKB(1);
717    setGlobalClockEnable(false);
718    setPrintTgidEnableIfPresent(false);
719    setKernelTraceFuncs(NULL);
720}
721
722
723// Enable tracing in the kernel.
724static bool startTrace()
725{
726    return setTracingEnabled(true);
727}
728
729// Disable tracing in the kernel.
730static void stopTrace()
731{
732    setTracingEnabled(false);
733}
734
735// Read the current kernel trace and write it to stdout.
736static void dumpTrace()
737{
738    int traceFD = open(k_tracePath, O_RDWR);
739    if (traceFD == -1) {
740        fprintf(stderr, "error opening %s: %s (%d)\n", k_tracePath,
741                strerror(errno), errno);
742        return;
743    }
744
745    if (g_compress) {
746        z_stream zs;
747        uint8_t *in, *out;
748        int result, flush;
749
750        memset(&zs, 0, sizeof(zs));
751        result = deflateInit(&zs, Z_DEFAULT_COMPRESSION);
752        if (result != Z_OK) {
753            fprintf(stderr, "error initializing zlib: %d\n", result);
754            close(traceFD);
755            return;
756        }
757
758        const size_t bufSize = 64*1024;
759        in = (uint8_t*)malloc(bufSize);
760        out = (uint8_t*)malloc(bufSize);
761        flush = Z_NO_FLUSH;
762
763        zs.next_out = out;
764        zs.avail_out = bufSize;
765
766        do {
767
768            if (zs.avail_in == 0) {
769                // More input is needed.
770                result = read(traceFD, in, bufSize);
771                if (result < 0) {
772                    fprintf(stderr, "error reading trace: %s (%d)\n",
773                            strerror(errno), errno);
774                    result = Z_STREAM_END;
775                    break;
776                } else if (result == 0) {
777                    flush = Z_FINISH;
778                } else {
779                    zs.next_in = in;
780                    zs.avail_in = result;
781                }
782            }
783
784            if (zs.avail_out == 0) {
785                // Need to write the output.
786                result = write(STDOUT_FILENO, out, bufSize);
787                if ((size_t)result < bufSize) {
788                    fprintf(stderr, "error writing deflated trace: %s (%d)\n",
789                            strerror(errno), errno);
790                    result = Z_STREAM_END; // skip deflate error message
791                    zs.avail_out = bufSize; // skip the final write
792                    break;
793                }
794                zs.next_out = out;
795                zs.avail_out = bufSize;
796            }
797
798        } while ((result = deflate(&zs, flush)) == Z_OK);
799
800        if (result != Z_STREAM_END) {
801            fprintf(stderr, "error deflating trace: %s\n", zs.msg);
802        }
803
804        if (zs.avail_out < bufSize) {
805            size_t bytes = bufSize - zs.avail_out;
806            result = write(STDOUT_FILENO, out, bytes);
807            if ((size_t)result < bytes) {
808                fprintf(stderr, "error writing deflated trace: %s (%d)\n",
809                        strerror(errno), errno);
810            }
811        }
812
813        result = deflateEnd(&zs);
814        if (result != Z_OK) {
815            fprintf(stderr, "error cleaning up zlib: %d\n", result);
816        }
817
818        free(in);
819        free(out);
820    } else {
821        ssize_t sent = 0;
822        while ((sent = sendfile(STDOUT_FILENO, traceFD, NULL, 64*1024*1024)) > 0);
823        if (sent == -1) {
824            fprintf(stderr, "error dumping trace: %s (%d)\n", strerror(errno),
825                    errno);
826        }
827    }
828
829    close(traceFD);
830}
831
832static void handleSignal(int /*signo*/)
833{
834    if (!g_nohup) {
835        g_traceAborted = true;
836    }
837}
838
839static void registerSigHandler()
840{
841    struct sigaction sa;
842    sigemptyset(&sa.sa_mask);
843    sa.sa_flags = 0;
844    sa.sa_handler = handleSignal;
845    sigaction(SIGHUP, &sa, NULL);
846    sigaction(SIGINT, &sa, NULL);
847    sigaction(SIGQUIT, &sa, NULL);
848    sigaction(SIGTERM, &sa, NULL);
849}
850
851static void listSupportedCategories()
852{
853    for (int i = 0; i < NELEM(k_categories); i++) {
854        const TracingCategory& c = k_categories[i];
855        if (isCategorySupported(c)) {
856            printf("  %10s - %s\n", c.name, c.longname);
857        }
858    }
859}
860
861// Print the command usage help to stderr.
862static void showHelp(const char *cmd)
863{
864    fprintf(stderr, "usage: %s [options] [categories...]\n", cmd);
865    fprintf(stderr, "options include:\n"
866                    "  -a appname      enable app-level tracing for a comma "
867                        "separated list of cmdlines\n"
868                    "  -b N            use a trace buffer size of N KB\n"
869                    "  -c              trace into a circular buffer\n"
870                    "  -f filename     use the categories written in a file as space-separated\n"
871                    "                    values in a line\n"
872                    "  -k fname,...    trace the listed kernel functions\n"
873                    "  -n              ignore signals\n"
874                    "  -s N            sleep for N seconds before tracing [default 0]\n"
875                    "  -t N            trace for N seconds [defualt 5]\n"
876                    "  -z              compress the trace dump\n"
877                    "  --async_start   start circular trace and return immediatly\n"
878                    "  --async_dump    dump the current contents of circular trace buffer\n"
879                    "  --async_stop    stop tracing and dump the current contents of circular\n"
880                    "                    trace buffer\n"
881                    "  --list_categories\n"
882                    "                  list the available tracing categories\n"
883            );
884}
885
886int main(int argc, char **argv)
887{
888    bool async = false;
889    bool traceStart = true;
890    bool traceStop = true;
891    bool traceDump = true;
892
893    if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
894        showHelp(argv[0]);
895        exit(0);
896    }
897
898    for (;;) {
899        int ret;
900        int option_index = 0;
901        static struct option long_options[] = {
902            {"async_start",     no_argument, 0,  0 },
903            {"async_stop",      no_argument, 0,  0 },
904            {"async_dump",      no_argument, 0,  0 },
905            {"list_categories", no_argument, 0,  0 },
906            {           0,                0, 0,  0 }
907        };
908
909        ret = getopt_long(argc, argv, "a:b:cf:k:ns:t:z",
910                          long_options, &option_index);
911
912        if (ret < 0) {
913            for (int i = optind; i < argc; i++) {
914                if (!setCategoryEnable(argv[i], true)) {
915                    fprintf(stderr, "error enabling tracing category \"%s\"\n", argv[i]);
916                    exit(1);
917                }
918            }
919            break;
920        }
921
922        switch(ret) {
923            case 'a':
924                g_debugAppCmdLine = optarg;
925            break;
926
927            case 'b':
928                g_traceBufferSizeKB = atoi(optarg);
929            break;
930
931            case 'c':
932                g_traceOverwrite = true;
933            break;
934
935            case 'f':
936                g_categoriesFile = optarg;
937            break;
938
939            case 'k':
940                g_kernelTraceFuncs = optarg;
941            break;
942
943            case 'n':
944                g_nohup = true;
945            break;
946
947            case 's':
948                g_initialSleepSecs = atoi(optarg);
949            break;
950
951            case 't':
952                g_traceDurationSeconds = atoi(optarg);
953            break;
954
955            case 'z':
956                g_compress = true;
957            break;
958
959            case 0:
960                if (!strcmp(long_options[option_index].name, "async_start")) {
961                    async = true;
962                    traceStop = false;
963                    traceDump = false;
964                    g_traceOverwrite = true;
965                } else if (!strcmp(long_options[option_index].name, "async_stop")) {
966                    async = true;
967                    traceStart = false;
968                } else if (!strcmp(long_options[option_index].name, "async_dump")) {
969                    async = true;
970                    traceStart = false;
971                    traceStop = false;
972                } else if (!strcmp(long_options[option_index].name, "list_categories")) {
973                    listSupportedCategories();
974                    exit(0);
975                }
976            break;
977
978            default:
979                fprintf(stderr, "\n");
980                showHelp(argv[0]);
981                exit(-1);
982            break;
983        }
984    }
985
986    registerSigHandler();
987
988    if (g_initialSleepSecs > 0) {
989        sleep(g_initialSleepSecs);
990    }
991
992    bool ok = true;
993    ok &= setUpTrace();
994    ok &= startTrace();
995
996    if (ok && traceStart) {
997        printf("capturing trace...");
998        fflush(stdout);
999
1000        // We clear the trace after starting it because tracing gets enabled for
1001        // each CPU individually in the kernel. Having the beginning of the trace
1002        // contain entries from only one CPU can cause "begin" entries without a
1003        // matching "end" entry to show up if a task gets migrated from one CPU to
1004        // another.
1005        ok = clearTrace();
1006
1007        writeClockSyncMarker();
1008        if (ok && !async) {
1009            // Sleep to allow the trace to be captured.
1010            struct timespec timeLeft;
1011            timeLeft.tv_sec = g_traceDurationSeconds;
1012            timeLeft.tv_nsec = 0;
1013            do {
1014                if (g_traceAborted) {
1015                    break;
1016                }
1017            } while (nanosleep(&timeLeft, &timeLeft) == -1 && errno == EINTR);
1018        }
1019    }
1020
1021    // Stop the trace and restore the default settings.
1022    if (traceStop)
1023        stopTrace();
1024
1025    if (ok && traceDump) {
1026        if (!g_traceAborted) {
1027            printf(" done\nTRACE:\n");
1028            fflush(stdout);
1029            dumpTrace();
1030        } else {
1031            printf("\ntrace aborted.\n");
1032            fflush(stdout);
1033        }
1034        clearTrace();
1035    } else if (!ok) {
1036        fprintf(stderr, "unable to start tracing\n");
1037    }
1038
1039    // Reset the trace buffer size to 1.
1040    if (traceStop)
1041        cleanUpTrace();
1042
1043    return g_traceAborted ? 1 : 0;
1044}
1045