atrace.cpp revision 5672bb755e306d9c315c47190df4a79f7f52889c
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};
158
159/* Command line options */
160static int g_traceDurationSeconds = 5;
161static bool g_traceOverwrite = false;
162static int g_traceBufferSizeKB = 2048;
163static bool g_compress = false;
164static bool g_nohup = false;
165static int g_initialSleepSecs = 0;
166static const char* g_categoriesFile = NULL;
167static const char* g_kernelTraceFuncs = NULL;
168static const char* g_debugAppCmdLine = "";
169
170/* Global state */
171static bool g_traceAborted = false;
172static bool g_categoryEnables[NELEM(k_categories)] = {};
173
174/* Sys file paths */
175static const char* k_traceClockPath =
176    "/sys/kernel/debug/tracing/trace_clock";
177
178static const char* k_traceBufferSizePath =
179    "/sys/kernel/debug/tracing/buffer_size_kb";
180
181static const char* k_tracingOverwriteEnablePath =
182    "/sys/kernel/debug/tracing/options/overwrite";
183
184static const char* k_currentTracerPath =
185    "/sys/kernel/debug/tracing/current_tracer";
186
187static const char* k_printTgidPath =
188    "/sys/kernel/debug/tracing/options/print-tgid";
189
190static const char* k_funcgraphAbsTimePath =
191    "/sys/kernel/debug/tracing/options/funcgraph-abstime";
192
193static const char* k_funcgraphCpuPath =
194    "/sys/kernel/debug/tracing/options/funcgraph-cpu";
195
196static const char* k_funcgraphProcPath =
197    "/sys/kernel/debug/tracing/options/funcgraph-proc";
198
199static const char* k_funcgraphFlatPath =
200    "/sys/kernel/debug/tracing/options/funcgraph-flat";
201
202static const char* k_funcgraphDurationPath =
203    "/sys/kernel/debug/tracing/options/funcgraph-duration";
204
205static const char* k_ftraceFilterPath =
206    "/sys/kernel/debug/tracing/set_ftrace_filter";
207
208static const char* k_tracingOnPath =
209    "/sys/kernel/debug/tracing/tracing_on";
210
211static const char* k_tracePath =
212    "/sys/kernel/debug/tracing/trace";
213
214static const char* k_traceMarkerPath =
215    "/sys/kernel/debug/tracing/trace_marker";
216
217// Check whether a file exists.
218static bool fileExists(const char* filename) {
219    return access(filename, F_OK) != -1;
220}
221
222// Check whether a file is writable.
223static bool fileIsWritable(const char* filename) {
224    return access(filename, W_OK) != -1;
225}
226
227// Truncate a file.
228static bool truncateFile(const char* path)
229{
230    // This uses creat rather than truncate because some of the debug kernel
231    // device nodes (e.g. k_ftraceFilterPath) currently aren't changed by
232    // calls to truncate, but they are cleared by calls to creat.
233    int traceFD = creat(path, 0);
234    if (traceFD == -1) {
235        fprintf(stderr, "error truncating %s: %s (%d)\n", path,
236            strerror(errno), errno);
237        return false;
238    }
239
240    close(traceFD);
241
242    return true;
243}
244
245static bool _writeStr(const char* filename, const char* str, int flags)
246{
247    int fd = open(filename, flags);
248    if (fd == -1) {
249        fprintf(stderr, "error opening %s: %s (%d)\n", filename,
250                strerror(errno), errno);
251        return false;
252    }
253
254    bool ok = true;
255    ssize_t len = strlen(str);
256    if (write(fd, str, len) != len) {
257        fprintf(stderr, "error writing to %s: %s (%d)\n", filename,
258                strerror(errno), errno);
259        ok = false;
260    }
261
262    close(fd);
263
264    return ok;
265}
266
267// Write a string to a file, returning true if the write was successful.
268static bool writeStr(const char* filename, const char* str)
269{
270    return _writeStr(filename, str, O_WRONLY);
271}
272
273// Append a string to a file, returning true if the write was successful.
274static bool appendStr(const char* filename, const char* str)
275{
276    return _writeStr(filename, str, O_APPEND|O_WRONLY);
277}
278
279static void writeClockSyncMarker()
280{
281  char buffer[128];
282  int len = 0;
283  int fd = open(k_traceMarkerPath, O_WRONLY);
284  if (fd == -1) {
285      fprintf(stderr, "error opening %s: %s (%d)\n", k_traceMarkerPath,
286              strerror(errno), errno);
287      return;
288  }
289  float now_in_seconds = systemTime(CLOCK_MONOTONIC) / 1000000000.0f;
290
291  len = snprintf(buffer, 128, "trace_event_clock_sync: parent_ts=%f\n", now_in_seconds);
292  if (write(fd, buffer, len) != len) {
293      fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
294  }
295
296  int64_t realtime_in_ms = systemTime(CLOCK_REALTIME) / 1000000;
297  len = snprintf(buffer, 128, "trace_event_clock_sync: realtime_ts=%" PRId64 "\n", realtime_in_ms);
298  if (write(fd, buffer, len) != len) {
299      fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
300  }
301
302  close(fd);
303}
304
305// Enable or disable a kernel option by writing a "1" or a "0" into a /sys
306// file.
307static bool setKernelOptionEnable(const char* filename, bool enable)
308{
309    return writeStr(filename, enable ? "1" : "0");
310}
311
312// Check whether the category is supported on the device with the current
313// rootness.  A category is supported only if all its required /sys/ files are
314// writable and if enabling the category will enable one or more tracing tags
315// or /sys/ files.
316static bool isCategorySupported(const TracingCategory& category)
317{
318    bool ok = category.tags != 0;
319    for (int i = 0; i < MAX_SYS_FILES; i++) {
320        const char* path = category.sysfiles[i].path;
321        bool req = category.sysfiles[i].required == REQ;
322        if (path != NULL) {
323            if (req) {
324                if (!fileIsWritable(path)) {
325                    return false;
326                } else {
327                    ok = true;
328                }
329            } else {
330                ok |= fileIsWritable(path);
331            }
332        }
333    }
334    return ok;
335}
336
337// Check whether the category would be supported on the device if the user
338// were root.  This function assumes that root is able to write to any file
339// that exists.  It performs the same logic as isCategorySupported, but it
340// uses file existance rather than writability in the /sys/ file checks.
341static bool isCategorySupportedForRoot(const TracingCategory& category)
342{
343    bool ok = category.tags != 0;
344    for (int i = 0; i < MAX_SYS_FILES; i++) {
345        const char* path = category.sysfiles[i].path;
346        bool req = category.sysfiles[i].required == REQ;
347        if (path != NULL) {
348            if (req) {
349                if (!fileExists(path)) {
350                    return false;
351                } else {
352                    ok = true;
353                }
354            } else {
355                ok |= fileExists(path);
356            }
357        }
358    }
359    return ok;
360}
361
362// Enable or disable overwriting of the kernel trace buffers.  Disabling this
363// will cause tracing to stop once the trace buffers have filled up.
364static bool setTraceOverwriteEnable(bool enable)
365{
366    return setKernelOptionEnable(k_tracingOverwriteEnablePath, enable);
367}
368
369// Enable or disable kernel tracing.
370static bool setTracingEnabled(bool enable)
371{
372    return setKernelOptionEnable(k_tracingOnPath, enable);
373}
374
375// Clear the contents of the kernel trace.
376static bool clearTrace()
377{
378    return truncateFile(k_tracePath);
379}
380
381// Set the size of the kernel's trace buffer in kilobytes.
382static bool setTraceBufferSizeKB(int size)
383{
384    char str[32] = "1";
385    int len;
386    if (size < 1) {
387        size = 1;
388    }
389    snprintf(str, 32, "%d", size);
390    return writeStr(k_traceBufferSizePath, str);
391}
392
393// Read the trace_clock sysfs file and return true if it matches the requested
394// value.  The trace_clock file format is:
395// local [global] counter uptime perf
396static bool isTraceClock(const char *mode)
397{
398    int fd = open(k_traceClockPath, O_RDONLY);
399    if (fd == -1) {
400        fprintf(stderr, "error opening %s: %s (%d)\n", k_traceClockPath,
401            strerror(errno), errno);
402        return false;
403    }
404
405    char buf[4097];
406    ssize_t n = read(fd, buf, 4096);
407    close(fd);
408    if (n == -1) {
409        fprintf(stderr, "error reading %s: %s (%d)\n", k_traceClockPath,
410            strerror(errno), errno);
411        return false;
412    }
413    buf[n] = '\0';
414
415    char *start = strchr(buf, '[');
416    if (start == NULL) {
417        return false;
418    }
419    start++;
420
421    char *end = strchr(start, ']');
422    if (end == NULL) {
423        return false;
424    }
425    *end = '\0';
426
427    return strcmp(mode, start) == 0;
428}
429
430// Enable or disable the kernel's use of the global clock.  Disabling the global
431// clock will result in the kernel using a per-CPU local clock.
432// Any write to the trace_clock sysfs file will reset the buffer, so only
433// update it if the requested value is not the current value.
434static bool setGlobalClockEnable(bool enable)
435{
436    const char *clock = enable ? "global" : "local";
437
438    if (isTraceClock(clock)) {
439        return true;
440    }
441
442    return writeStr(k_traceClockPath, clock);
443}
444
445static bool setPrintTgidEnableIfPresent(bool enable)
446{
447    if (fileExists(k_printTgidPath)) {
448        return setKernelOptionEnable(k_printTgidPath, enable);
449    }
450    return true;
451}
452
453// Poke all the binder-enabled processes in the system to get them to re-read
454// their system properties.
455static bool pokeBinderServices()
456{
457    sp<IServiceManager> sm = defaultServiceManager();
458    Vector<String16> services = sm->listServices();
459    for (size_t i = 0; i < services.size(); i++) {
460        sp<IBinder> obj = sm->checkService(services[i]);
461        if (obj != NULL) {
462            Parcel data;
463            if (obj->transact(IBinder::SYSPROPS_TRANSACTION, data,
464                    NULL, 0) != OK) {
465                if (false) {
466                    // XXX: For some reason this fails on tablets trying to
467                    // poke the "phone" service.  It's not clear whether some
468                    // are expected to fail.
469                    String8 svc(services[i]);
470                    fprintf(stderr, "error poking binder service %s\n",
471                        svc.string());
472                    return false;
473                }
474            }
475        }
476    }
477    return true;
478}
479
480// Set the trace tags that userland tracing uses, and poke the running
481// processes to pick up the new value.
482static bool setTagsProperty(uint64_t tags)
483{
484    char buf[64];
485    snprintf(buf, 64, "%#" PRIx64, tags);
486    if (property_set(k_traceTagsProperty, buf) < 0) {
487        fprintf(stderr, "error setting trace tags system property\n");
488        return false;
489    }
490    return true;
491}
492
493// Set the system property that indicates which apps should perform
494// application-level tracing.
495static bool setAppCmdlineProperty(const char* cmdline)
496{
497    if (property_set(k_traceAppCmdlineProperty, cmdline) < 0) {
498        fprintf(stderr, "error setting trace app system property\n");
499        return false;
500    }
501    return true;
502}
503
504// Disable all /sys/ enable files.
505static bool disableKernelTraceEvents() {
506    bool ok = true;
507    for (int i = 0; i < NELEM(k_categories); i++) {
508        const TracingCategory &c = k_categories[i];
509        for (int j = 0; j < MAX_SYS_FILES; j++) {
510            const char* path = c.sysfiles[j].path;
511            if (path != NULL && fileIsWritable(path)) {
512                ok &= setKernelOptionEnable(path, false);
513            }
514        }
515    }
516    return ok;
517}
518
519// Verify that the comma separated list of functions are being traced by the
520// kernel.
521static bool verifyKernelTraceFuncs(const char* funcs)
522{
523    int fd = open(k_ftraceFilterPath, O_RDONLY);
524    if (fd == -1) {
525        fprintf(stderr, "error opening %s: %s (%d)\n", k_ftraceFilterPath,
526            strerror(errno), errno);
527        return false;
528    }
529
530    char buf[4097];
531    ssize_t n = read(fd, buf, 4096);
532    close(fd);
533    if (n == -1) {
534        fprintf(stderr, "error reading %s: %s (%d)\n", k_ftraceFilterPath,
535            strerror(errno), errno);
536        return false;
537    }
538
539    buf[n] = '\0';
540    String8 funcList = String8::format("\n%s", buf);
541
542    // Make sure that every function listed in funcs is in the list we just
543    // read from the kernel.
544    bool ok = true;
545    char* myFuncs = strdup(funcs);
546    char* func = strtok(myFuncs, ",");
547    while (func) {
548        String8 fancyFunc = String8::format("\n%s\n", func);
549        bool found = funcList.find(fancyFunc.string(), 0) >= 0;
550        if (!found || func[0] == '\0') {
551            fprintf(stderr, "error: \"%s\" is not a valid kernel function "
552                "to trace.\n", func);
553            ok = false;
554        }
555        func = strtok(NULL, ",");
556    }
557    free(myFuncs);
558
559    return ok;
560}
561
562// Set the comma separated list of functions that the kernel is to trace.
563static bool setKernelTraceFuncs(const char* funcs)
564{
565    bool ok = true;
566
567    if (funcs == NULL || funcs[0] == '\0') {
568        // Disable kernel function tracing.
569        if (fileIsWritable(k_currentTracerPath)) {
570            ok &= writeStr(k_currentTracerPath, "nop");
571        }
572        if (fileIsWritable(k_ftraceFilterPath)) {
573            ok &= truncateFile(k_ftraceFilterPath);
574        }
575    } else {
576        // Enable kernel function tracing.
577        ok &= writeStr(k_currentTracerPath, "function_graph");
578        ok &= setKernelOptionEnable(k_funcgraphAbsTimePath, true);
579        ok &= setKernelOptionEnable(k_funcgraphCpuPath, true);
580        ok &= setKernelOptionEnable(k_funcgraphProcPath, true);
581        ok &= setKernelOptionEnable(k_funcgraphFlatPath, true);
582
583        // Set the requested filter functions.
584        ok &= truncateFile(k_ftraceFilterPath);
585        char* myFuncs = strdup(funcs);
586        char* func = strtok(myFuncs, ",");
587        while (func) {
588            ok &= appendStr(k_ftraceFilterPath, func);
589            func = strtok(NULL, ",");
590        }
591        free(myFuncs);
592
593        // Verify that the set functions are being traced.
594        if (ok) {
595            ok &= verifyKernelTraceFuncs(funcs);
596        }
597    }
598
599    return ok;
600}
601
602static bool setCategoryEnable(const char* name, bool enable)
603{
604    for (int i = 0; i < NELEM(k_categories); i++) {
605        const TracingCategory& c = k_categories[i];
606        if (strcmp(name, c.name) == 0) {
607            if (isCategorySupported(c)) {
608                g_categoryEnables[i] = enable;
609                return true;
610            } else {
611                if (isCategorySupportedForRoot(c)) {
612                    fprintf(stderr, "error: category \"%s\" requires root "
613                            "privileges.\n", name);
614                } else {
615                    fprintf(stderr, "error: category \"%s\" is not supported "
616                            "on this device.\n", name);
617                }
618                return false;
619            }
620        }
621    }
622    fprintf(stderr, "error: unknown tracing category \"%s\"\n", name);
623    return false;
624}
625
626static bool setCategoriesEnableFromFile(const char* categories_file)
627{
628    if (!categories_file) {
629        return true;
630    }
631    Tokenizer* tokenizer = NULL;
632    if (Tokenizer::open(String8(categories_file), &tokenizer) != NO_ERROR) {
633        return false;
634    }
635    bool ok = true;
636    while (!tokenizer->isEol()) {
637        String8 token = tokenizer->nextToken(" ");
638        if (token.isEmpty()) {
639            tokenizer->skipDelimiters(" ");
640            continue;
641        }
642        ok &= setCategoryEnable(token.string(), true);
643    }
644    delete tokenizer;
645    return ok;
646}
647
648// Set all the kernel tracing settings to the desired state for this trace
649// capture.
650static bool setUpTrace()
651{
652    bool ok = true;
653
654    // Set up the tracing options.
655    ok &= setCategoriesEnableFromFile(g_categoriesFile);
656    ok &= setTraceOverwriteEnable(g_traceOverwrite);
657    ok &= setTraceBufferSizeKB(g_traceBufferSizeKB);
658    ok &= setGlobalClockEnable(true);
659    ok &= setPrintTgidEnableIfPresent(true);
660    ok &= setKernelTraceFuncs(g_kernelTraceFuncs);
661
662    // Set up the tags property.
663    uint64_t tags = 0;
664    for (int i = 0; i < NELEM(k_categories); i++) {
665        if (g_categoryEnables[i]) {
666            const TracingCategory &c = k_categories[i];
667            tags |= c.tags;
668        }
669    }
670    ok &= setTagsProperty(tags);
671    ok &= setAppCmdlineProperty(g_debugAppCmdLine);
672    ok &= pokeBinderServices();
673
674    // Disable all the sysfs enables.  This is done as a separate loop from
675    // the enables to allow the same enable to exist in multiple categories.
676    ok &= disableKernelTraceEvents();
677
678    // Enable all the sysfs enables that are in an enabled category.
679    for (int i = 0; i < NELEM(k_categories); i++) {
680        if (g_categoryEnables[i]) {
681            const TracingCategory &c = k_categories[i];
682            for (int j = 0; j < MAX_SYS_FILES; j++) {
683                const char* path = c.sysfiles[j].path;
684                bool required = c.sysfiles[j].required == REQ;
685                if (path != NULL) {
686                    if (fileIsWritable(path)) {
687                        ok &= setKernelOptionEnable(path, true);
688                    } else if (required) {
689                        fprintf(stderr, "error writing file %s\n", path);
690                        ok = false;
691                    }
692                }
693            }
694        }
695    }
696
697    return ok;
698}
699
700// Reset all the kernel tracing settings to their default state.
701static void cleanUpTrace()
702{
703    // Disable all tracing that we're able to.
704    disableKernelTraceEvents();
705
706    // Reset the system properties.
707    setTagsProperty(0);
708    setAppCmdlineProperty("");
709    pokeBinderServices();
710
711    // Set the options back to their defaults.
712    setTraceOverwriteEnable(true);
713    setTraceBufferSizeKB(1);
714    setGlobalClockEnable(false);
715    setPrintTgidEnableIfPresent(false);
716    setKernelTraceFuncs(NULL);
717}
718
719
720// Enable tracing in the kernel.
721static bool startTrace()
722{
723    return setTracingEnabled(true);
724}
725
726// Disable tracing in the kernel.
727static void stopTrace()
728{
729    setTracingEnabled(false);
730}
731
732// Read the current kernel trace and write it to stdout.
733static void dumpTrace()
734{
735    int traceFD = open(k_tracePath, O_RDWR);
736    if (traceFD == -1) {
737        fprintf(stderr, "error opening %s: %s (%d)\n", k_tracePath,
738                strerror(errno), errno);
739        return;
740    }
741
742    if (g_compress) {
743        z_stream zs;
744        uint8_t *in, *out;
745        int result, flush;
746
747        memset(&zs, 0, sizeof(zs));
748        result = deflateInit(&zs, Z_DEFAULT_COMPRESSION);
749        if (result != Z_OK) {
750            fprintf(stderr, "error initializing zlib: %d\n", result);
751            close(traceFD);
752            return;
753        }
754
755        const size_t bufSize = 64*1024;
756        in = (uint8_t*)malloc(bufSize);
757        out = (uint8_t*)malloc(bufSize);
758        flush = Z_NO_FLUSH;
759
760        zs.next_out = out;
761        zs.avail_out = bufSize;
762
763        do {
764
765            if (zs.avail_in == 0) {
766                // More input is needed.
767                result = read(traceFD, in, bufSize);
768                if (result < 0) {
769                    fprintf(stderr, "error reading trace: %s (%d)\n",
770                            strerror(errno), errno);
771                    result = Z_STREAM_END;
772                    break;
773                } else if (result == 0) {
774                    flush = Z_FINISH;
775                } else {
776                    zs.next_in = in;
777                    zs.avail_in = result;
778                }
779            }
780
781            if (zs.avail_out == 0) {
782                // Need to write the output.
783                result = write(STDOUT_FILENO, out, bufSize);
784                if ((size_t)result < bufSize) {
785                    fprintf(stderr, "error writing deflated trace: %s (%d)\n",
786                            strerror(errno), errno);
787                    result = Z_STREAM_END; // skip deflate error message
788                    zs.avail_out = bufSize; // skip the final write
789                    break;
790                }
791                zs.next_out = out;
792                zs.avail_out = bufSize;
793            }
794
795        } while ((result = deflate(&zs, flush)) == Z_OK);
796
797        if (result != Z_STREAM_END) {
798            fprintf(stderr, "error deflating trace: %s\n", zs.msg);
799        }
800
801        if (zs.avail_out < bufSize) {
802            size_t bytes = bufSize - zs.avail_out;
803            result = write(STDOUT_FILENO, out, bytes);
804            if ((size_t)result < bytes) {
805                fprintf(stderr, "error writing deflated trace: %s (%d)\n",
806                        strerror(errno), errno);
807            }
808        }
809
810        result = deflateEnd(&zs);
811        if (result != Z_OK) {
812            fprintf(stderr, "error cleaning up zlib: %d\n", result);
813        }
814
815        free(in);
816        free(out);
817    } else {
818        ssize_t sent = 0;
819        while ((sent = sendfile(STDOUT_FILENO, traceFD, NULL, 64*1024*1024)) > 0);
820        if (sent == -1) {
821            fprintf(stderr, "error dumping trace: %s (%d)\n", strerror(errno),
822                    errno);
823        }
824    }
825
826    close(traceFD);
827}
828
829static void handleSignal(int /*signo*/)
830{
831    if (!g_nohup) {
832        g_traceAborted = true;
833    }
834}
835
836static void registerSigHandler()
837{
838    struct sigaction sa;
839    sigemptyset(&sa.sa_mask);
840    sa.sa_flags = 0;
841    sa.sa_handler = handleSignal;
842    sigaction(SIGHUP, &sa, NULL);
843    sigaction(SIGINT, &sa, NULL);
844    sigaction(SIGQUIT, &sa, NULL);
845    sigaction(SIGTERM, &sa, NULL);
846}
847
848static void listSupportedCategories()
849{
850    for (int i = 0; i < NELEM(k_categories); i++) {
851        const TracingCategory& c = k_categories[i];
852        if (isCategorySupported(c)) {
853            printf("  %10s - %s\n", c.name, c.longname);
854        }
855    }
856}
857
858// Print the command usage help to stderr.
859static void showHelp(const char *cmd)
860{
861    fprintf(stderr, "usage: %s [options] [categories...]\n", cmd);
862    fprintf(stderr, "options include:\n"
863                    "  -a appname      enable app-level tracing for a comma "
864                        "separated list of cmdlines\n"
865                    "  -b N            use a trace buffer size of N KB\n"
866                    "  -c              trace into a circular buffer\n"
867                    "  -f filename     use the categories written in a file as space-separated\n"
868                    "                    values in a line\n"
869                    "  -k fname,...    trace the listed kernel functions\n"
870                    "  -n              ignore signals\n"
871                    "  -s N            sleep for N seconds before tracing [default 0]\n"
872                    "  -t N            trace for N seconds [defualt 5]\n"
873                    "  -z              compress the trace dump\n"
874                    "  --async_start   start circular trace and return immediatly\n"
875                    "  --async_dump    dump the current contents of circular trace buffer\n"
876                    "  --async_stop    stop tracing and dump the current contents of circular\n"
877                    "                    trace buffer\n"
878                    "  --list_categories\n"
879                    "                  list the available tracing categories\n"
880            );
881}
882
883int main(int argc, char **argv)
884{
885    bool async = false;
886    bool traceStart = true;
887    bool traceStop = true;
888    bool traceDump = true;
889
890    if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
891        showHelp(argv[0]);
892        exit(0);
893    }
894
895    for (;;) {
896        int ret;
897        int option_index = 0;
898        static struct option long_options[] = {
899            {"async_start",     no_argument, 0,  0 },
900            {"async_stop",      no_argument, 0,  0 },
901            {"async_dump",      no_argument, 0,  0 },
902            {"list_categories", no_argument, 0,  0 },
903            {           0,                0, 0,  0 }
904        };
905
906        ret = getopt_long(argc, argv, "a:b:cf:k:ns:t:z",
907                          long_options, &option_index);
908
909        if (ret < 0) {
910            for (int i = optind; i < argc; i++) {
911                if (!setCategoryEnable(argv[i], true)) {
912                    fprintf(stderr, "error enabling tracing category \"%s\"\n", argv[i]);
913                    exit(1);
914                }
915            }
916            break;
917        }
918
919        switch(ret) {
920            case 'a':
921                g_debugAppCmdLine = optarg;
922            break;
923
924            case 'b':
925                g_traceBufferSizeKB = atoi(optarg);
926            break;
927
928            case 'c':
929                g_traceOverwrite = true;
930            break;
931
932            case 'f':
933                g_categoriesFile = optarg;
934            break;
935
936            case 'k':
937                g_kernelTraceFuncs = optarg;
938            break;
939
940            case 'n':
941                g_nohup = true;
942            break;
943
944            case 's':
945                g_initialSleepSecs = atoi(optarg);
946            break;
947
948            case 't':
949                g_traceDurationSeconds = atoi(optarg);
950            break;
951
952            case 'z':
953                g_compress = true;
954            break;
955
956            case 0:
957                if (!strcmp(long_options[option_index].name, "async_start")) {
958                    async = true;
959                    traceStop = false;
960                    traceDump = false;
961                    g_traceOverwrite = true;
962                } else if (!strcmp(long_options[option_index].name, "async_stop")) {
963                    async = true;
964                    traceStart = false;
965                } else if (!strcmp(long_options[option_index].name, "async_dump")) {
966                    async = true;
967                    traceStart = false;
968                    traceStop = false;
969                } else if (!strcmp(long_options[option_index].name, "list_categories")) {
970                    listSupportedCategories();
971                    exit(0);
972                }
973            break;
974
975            default:
976                fprintf(stderr, "\n");
977                showHelp(argv[0]);
978                exit(-1);
979            break;
980        }
981    }
982
983    registerSigHandler();
984
985    if (g_initialSleepSecs > 0) {
986        sleep(g_initialSleepSecs);
987    }
988
989    bool ok = true;
990    ok &= setUpTrace();
991    ok &= startTrace();
992
993    if (ok && traceStart) {
994        printf("capturing trace...");
995        fflush(stdout);
996
997        // We clear the trace after starting it because tracing gets enabled for
998        // each CPU individually in the kernel. Having the beginning of the trace
999        // contain entries from only one CPU can cause "begin" entries without a
1000        // matching "end" entry to show up if a task gets migrated from one CPU to
1001        // another.
1002        ok = clearTrace();
1003
1004        writeClockSyncMarker();
1005        if (ok && !async) {
1006            // Sleep to allow the trace to be captured.
1007            struct timespec timeLeft;
1008            timeLeft.tv_sec = g_traceDurationSeconds;
1009            timeLeft.tv_nsec = 0;
1010            do {
1011                if (g_traceAborted) {
1012                    break;
1013                }
1014            } while (nanosleep(&timeLeft, &timeLeft) == -1 && errno == EINTR);
1015        }
1016    }
1017
1018    // Stop the trace and restore the default settings.
1019    if (traceStop)
1020        stopTrace();
1021
1022    if (ok && traceDump) {
1023        if (!g_traceAborted) {
1024            printf(" done\nTRACE:\n");
1025            fflush(stdout);
1026            dumpTrace();
1027        } else {
1028            printf("\ntrace aborted.\n");
1029            fflush(stdout);
1030        }
1031        clearTrace();
1032    } else if (!ok) {
1033        fprintf(stderr, "unable to start tracing\n");
1034    }
1035
1036    // Reset the trace buffer size to 1.
1037    if (traceStop)
1038        cleanUpTrace();
1039
1040    return g_traceAborted ? 1 : 0;
1041}
1042