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