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