blob: 55282cf9aaa918c3c73f102f2c1a127084bfce76 [file] [log] [blame]
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001/*
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>
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -070020#include <inttypes.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080021#include <signal.h>
22#include <stdarg.h>
23#include <stdbool.h>
24#include <stdio.h>
25#include <stdlib.h>
Elliott Hughes3da5d232015-01-25 08:35:20 -080026#include <string.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080027#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>
John Reck469a1942015-03-26 15:31:35 -070038#include <utils/Timers.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080039#include <utils/Trace.h>
40
41using namespace android;
42
43#define NELEM(x) ((int) (sizeof(x) / sizeof((x)[0])))
44
Mohamad Ayyash26dbcbe2014-04-08 15:24:11 -070045enum { MAX_SYS_FILES = 10 };
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080046
47const char* k_traceTagsProperty = "debug.atrace.tags.enableflags";
Jamie Gennisf7f29c82013-03-27 15:50:58 -070048const char* k_traceAppCmdlineProperty = "debug.atrace.app_cmdlines";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080049
50typedef enum { OPT, REQ } requiredness ;
51
52struct 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 */
75static const TracingCategory k_categories[] = {
Jamie Gennisb2a89e32013-03-11 19:37:53 -070076 { "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, { } },
Patrick Auchter70ec2942014-09-30 15:38:30 -050082 { "sm", "Sync Manager", ATRACE_TAG_SYNC_MANAGER, { } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -070083 { "audio", "Audio", ATRACE_TAG_AUDIO, { } },
84 { "video", "Video", ATRACE_TAG_VIDEO, { } },
85 { "camera", "Camera", ATRACE_TAG_CAMERA, { } },
86 { "hal", "Hardware Modules", ATRACE_TAG_HAL, { } },
Jeff Brown3200b0b2014-08-14 19:24:47 -070087 { "app", "Application", ATRACE_TAG_APP, { } },
Dianne Hackborn9380d782013-04-12 14:52:35 -070088 { "res", "Resource Loading", ATRACE_TAG_RESOURCES, { } },
Jamie Genniseff2e8d2013-05-07 15:20:39 -070089 { "dalvik", "Dalvik VM", ATRACE_TAG_DALVIK, { } },
Tim Murrayf0f28412013-05-23 14:39:42 -070090 { "rs", "RenderScript", ATRACE_TAG_RS, { } },
Brigid Smith750aa972014-05-28 14:23:24 -070091 { "bionic", "Bionic C Library", ATRACE_TAG_BIONIC, { } },
Jeff Brown3200b0b2014-08-14 19:24:47 -070092 { "power", "Power Management", ATRACE_TAG_POWER, { } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -070093 { "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" },
Tim Murraybd651612015-11-30 10:59:55 -080096 { OPT, "/sys/kernel/debug/tracing/events/sched/sched_blocked_reason/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080097 } },
Dan Willemsenf440d392014-04-11 15:44:09 -070098 { "irq", "IRQ Events", 0, {
99 { REQ, "/sys/kernel/debug/tracing/events/irq/enable" },
100 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700101 { "freq", "CPU Frequency", 0, {
102 { REQ, "/sys/kernel/debug/tracing/events/power/cpu_frequency/enable" },
103 { OPT, "/sys/kernel/debug/tracing/events/power/clock_set_rate/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800104 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700105 { "membus", "Memory Bus Utilization", 0, {
106 { REQ, "/sys/kernel/debug/tracing/events/memory_bus/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800107 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700108 { "idle", "CPU Idle", 0, {
109 { REQ, "/sys/kernel/debug/tracing/events/power/cpu_idle/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800110 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700111 { "disk", "Disk I/O", 0, {
Greg Hackmanne80d32c2014-11-20 12:59:44 -0800112 { OPT, "/sys/kernel/debug/tracing/events/f2fs/f2fs_sync_file_enter/enable" },
113 { OPT, "/sys/kernel/debug/tracing/events/f2fs/f2fs_sync_file_exit/enable" },
114 { OPT, "/sys/kernel/debug/tracing/events/f2fs/f2fs_write_begin/enable" },
115 { OPT, "/sys/kernel/debug/tracing/events/f2fs/f2fs_write_end/enable" },
116 { OPT, "/sys/kernel/debug/tracing/events/ext4/ext4_da_write_begin/enable" },
117 { OPT, "/sys/kernel/debug/tracing/events/ext4/ext4_da_write_end/enable" },
118 { OPT, "/sys/kernel/debug/tracing/events/ext4/ext4_sync_file_enter/enable" },
119 { OPT, "/sys/kernel/debug/tracing/events/ext4/ext4_sync_file_exit/enable" },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700120 { REQ, "/sys/kernel/debug/tracing/events/block/block_rq_issue/enable" },
121 { REQ, "/sys/kernel/debug/tracing/events/block/block_rq_complete/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800122 } },
Ken Sumralld3fa5612013-07-03 12:32:03 -0700123 { "mmc", "eMMC commands", 0, {
124 { REQ, "/sys/kernel/debug/tracing/events/mmc/enable" },
125 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700126 { "load", "CPU Load", 0, {
127 { REQ, "/sys/kernel/debug/tracing/events/cpufreq_interactive/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800128 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700129 { "sync", "Synchronization", 0, {
130 { REQ, "/sys/kernel/debug/tracing/events/sync/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800131 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700132 { "workq", "Kernel Workqueues", 0, {
133 { REQ, "/sys/kernel/debug/tracing/events/workqueue/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800134 } },
Colin Cross580407f2014-08-18 15:22:13 -0700135 { "memreclaim", "Kernel Memory Reclaim", 0, {
136 { REQ, "/sys/kernel/debug/tracing/events/vmscan/mm_vmscan_direct_reclaim_begin/enable" },
137 { REQ, "/sys/kernel/debug/tracing/events/vmscan/mm_vmscan_direct_reclaim_end/enable" },
138 { REQ, "/sys/kernel/debug/tracing/events/vmscan/mm_vmscan_kswapd_wake/enable" },
139 { REQ, "/sys/kernel/debug/tracing/events/vmscan/mm_vmscan_kswapd_sleep/enable" },
140 } },
Aaron Schulmancbe13ef2015-02-25 08:37:09 -0800141 { "regulators", "Voltage and Current Regulators", 0, {
142 { REQ, "/sys/kernel/debug/tracing/events/regulator/enable" },
143 } },
Scott Bauer97e5be32015-06-08 16:32:36 -0700144 { "binder_driver", "Binder Kernel driver", 0, {
145 { REQ, "/sys/kernel/debug/tracing/events/binder/binder_transaction/enable" },
146 { REQ, "/sys/kernel/debug/tracing/events/binder/binder_transaction_received/enable" },
147 } },
148 { "binder_lock", "Binder global lock trace", 0, {
149 { REQ, "/sys/kernel/debug/tracing/events/binder/binder_lock/enable" },
150 { REQ, "/sys/kernel/debug/tracing/events/binder/binder_locked/enable" },
151 { REQ, "/sys/kernel/debug/tracing/events/binder/binder_unlock/enable" },
152 } },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800153};
154
155/* Command line options */
156static int g_traceDurationSeconds = 5;
157static bool g_traceOverwrite = false;
158static int g_traceBufferSizeKB = 2048;
159static bool g_compress = false;
160static bool g_nohup = false;
161static int g_initialSleepSecs = 0;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700162static const char* g_kernelTraceFuncs = NULL;
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700163static const char* g_debugAppCmdLine = "";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800164
165/* Global state */
166static bool g_traceAborted = false;
167static bool g_categoryEnables[NELEM(k_categories)] = {};
168
169/* Sys file paths */
170static const char* k_traceClockPath =
171 "/sys/kernel/debug/tracing/trace_clock";
172
173static const char* k_traceBufferSizePath =
174 "/sys/kernel/debug/tracing/buffer_size_kb";
175
176static const char* k_tracingOverwriteEnablePath =
177 "/sys/kernel/debug/tracing/options/overwrite";
178
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700179static const char* k_currentTracerPath =
180 "/sys/kernel/debug/tracing/current_tracer";
181
182static const char* k_printTgidPath =
183 "/sys/kernel/debug/tracing/options/print-tgid";
184
185static const char* k_funcgraphAbsTimePath =
186 "/sys/kernel/debug/tracing/options/funcgraph-abstime";
187
188static const char* k_funcgraphCpuPath =
189 "/sys/kernel/debug/tracing/options/funcgraph-cpu";
190
191static const char* k_funcgraphProcPath =
192 "/sys/kernel/debug/tracing/options/funcgraph-proc";
193
194static const char* k_funcgraphFlatPath =
195 "/sys/kernel/debug/tracing/options/funcgraph-flat";
196
197static const char* k_funcgraphDurationPath =
198 "/sys/kernel/debug/tracing/options/funcgraph-duration";
199
200static const char* k_ftraceFilterPath =
201 "/sys/kernel/debug/tracing/set_ftrace_filter";
202
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800203static const char* k_tracingOnPath =
204 "/sys/kernel/debug/tracing/tracing_on";
205
206static const char* k_tracePath =
207 "/sys/kernel/debug/tracing/trace";
208
John Reck469a1942015-03-26 15:31:35 -0700209static const char* k_traceMarkerPath =
210 "/sys/kernel/debug/tracing/trace_marker";
211
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800212// Check whether a file exists.
213static bool fileExists(const char* filename) {
214 return access(filename, F_OK) != -1;
215}
216
217// Check whether a file is writable.
218static bool fileIsWritable(const char* filename) {
219 return access(filename, W_OK) != -1;
220}
221
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700222// Truncate a file.
223static bool truncateFile(const char* path)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800224{
Jamie Gennis43122e72013-03-21 14:06:31 -0700225 // This uses creat rather than truncate because some of the debug kernel
226 // device nodes (e.g. k_ftraceFilterPath) currently aren't changed by
227 // calls to truncate, but they are cleared by calls to creat.
228 int traceFD = creat(path, 0);
229 if (traceFD == -1) {
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700230 fprintf(stderr, "error truncating %s: %s (%d)\n", path,
Jamie Gennis43122e72013-03-21 14:06:31 -0700231 strerror(errno), errno);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700232 return false;
233 }
234
Jamie Gennis43122e72013-03-21 14:06:31 -0700235 close(traceFD);
236
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700237 return true;
238}
239
240static bool _writeStr(const char* filename, const char* str, int flags)
241{
242 int fd = open(filename, flags);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800243 if (fd == -1) {
244 fprintf(stderr, "error opening %s: %s (%d)\n", filename,
245 strerror(errno), errno);
246 return false;
247 }
248
249 bool ok = true;
250 ssize_t len = strlen(str);
251 if (write(fd, str, len) != len) {
252 fprintf(stderr, "error writing to %s: %s (%d)\n", filename,
253 strerror(errno), errno);
254 ok = false;
255 }
256
257 close(fd);
258
259 return ok;
260}
261
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700262// Write a string to a file, returning true if the write was successful.
263static bool writeStr(const char* filename, const char* str)
264{
265 return _writeStr(filename, str, O_WRONLY);
266}
267
268// Append a string to a file, returning true if the write was successful.
269static bool appendStr(const char* filename, const char* str)
270{
271 return _writeStr(filename, str, O_APPEND|O_WRONLY);
272}
273
John Reck469a1942015-03-26 15:31:35 -0700274static void writeClockSyncMarker()
275{
276 char buffer[128];
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200277 int len = 0;
278 int fd = open(k_traceMarkerPath, O_WRONLY);
279 if (fd == -1) {
280 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceMarkerPath,
281 strerror(errno), errno);
282 return;
283 }
John Reck469a1942015-03-26 15:31:35 -0700284 float now_in_seconds = systemTime(CLOCK_MONOTONIC) / 1000000000.0f;
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200285
286 len = snprintf(buffer, 128, "trace_event_clock_sync: parent_ts=%f\n", now_in_seconds);
287 if (write(fd, buffer, len) != len) {
288 fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
289 }
290
291 int64_t realtime_in_ms = systemTime(CLOCK_REALTIME) / 1000000;
292 len = snprintf(buffer, 128, "trace_event_clock_sync: realtime_ts=%" PRId64 "\n", realtime_in_ms);
293 if (write(fd, buffer, len) != len) {
294 fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
295 }
296
297 close(fd);
John Reck469a1942015-03-26 15:31:35 -0700298}
299
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800300// Enable or disable a kernel option by writing a "1" or a "0" into a /sys
301// file.
302static bool setKernelOptionEnable(const char* filename, bool enable)
303{
304 return writeStr(filename, enable ? "1" : "0");
305}
306
307// Check whether the category is supported on the device with the current
308// rootness. A category is supported only if all its required /sys/ files are
309// writable and if enabling the category will enable one or more tracing tags
310// or /sys/ files.
311static bool isCategorySupported(const TracingCategory& category)
312{
313 bool ok = category.tags != 0;
314 for (int i = 0; i < MAX_SYS_FILES; i++) {
315 const char* path = category.sysfiles[i].path;
316 bool req = category.sysfiles[i].required == REQ;
317 if (path != NULL) {
318 if (req) {
319 if (!fileIsWritable(path)) {
320 return false;
321 } else {
322 ok = true;
323 }
324 } else {
325 ok |= fileIsWritable(path);
326 }
327 }
328 }
329 return ok;
330}
331
332// Check whether the category would be supported on the device if the user
333// were root. This function assumes that root is able to write to any file
334// that exists. It performs the same logic as isCategorySupported, but it
335// uses file existance rather than writability in the /sys/ file checks.
336static bool isCategorySupportedForRoot(const TracingCategory& category)
337{
338 bool ok = category.tags != 0;
339 for (int i = 0; i < MAX_SYS_FILES; i++) {
340 const char* path = category.sysfiles[i].path;
341 bool req = category.sysfiles[i].required == REQ;
342 if (path != NULL) {
343 if (req) {
344 if (!fileExists(path)) {
345 return false;
346 } else {
347 ok = true;
348 }
349 } else {
350 ok |= fileExists(path);
351 }
352 }
353 }
354 return ok;
355}
356
357// Enable or disable overwriting of the kernel trace buffers. Disabling this
358// will cause tracing to stop once the trace buffers have filled up.
359static bool setTraceOverwriteEnable(bool enable)
360{
361 return setKernelOptionEnable(k_tracingOverwriteEnablePath, enable);
362}
363
364// Enable or disable kernel tracing.
365static bool setTracingEnabled(bool enable)
366{
367 return setKernelOptionEnable(k_tracingOnPath, enable);
368}
369
370// Clear the contents of the kernel trace.
371static bool clearTrace()
372{
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700373 return truncateFile(k_tracePath);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800374}
375
376// Set the size of the kernel's trace buffer in kilobytes.
377static bool setTraceBufferSizeKB(int size)
378{
379 char str[32] = "1";
380 int len;
381 if (size < 1) {
382 size = 1;
383 }
384 snprintf(str, 32, "%d", size);
385 return writeStr(k_traceBufferSizePath, str);
386}
387
Colin Crossb1ce49b2014-08-20 14:28:47 -0700388// Read the trace_clock sysfs file and return true if it matches the requested
389// value. The trace_clock file format is:
390// local [global] counter uptime perf
391static bool isTraceClock(const char *mode)
392{
393 int fd = open(k_traceClockPath, O_RDONLY);
394 if (fd == -1) {
395 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceClockPath,
396 strerror(errno), errno);
397 return false;
398 }
399
400 char buf[4097];
401 ssize_t n = read(fd, buf, 4096);
402 close(fd);
403 if (n == -1) {
404 fprintf(stderr, "error reading %s: %s (%d)\n", k_traceClockPath,
405 strerror(errno), errno);
406 return false;
407 }
408 buf[n] = '\0';
409
410 char *start = strchr(buf, '[');
411 if (start == NULL) {
412 return false;
413 }
414 start++;
415
416 char *end = strchr(start, ']');
417 if (end == NULL) {
418 return false;
419 }
420 *end = '\0';
421
422 return strcmp(mode, start) == 0;
423}
424
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800425// Enable or disable the kernel's use of the global clock. Disabling the global
426// clock will result in the kernel using a per-CPU local clock.
Colin Crossb1ce49b2014-08-20 14:28:47 -0700427// Any write to the trace_clock sysfs file will reset the buffer, so only
428// update it if the requested value is not the current value.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800429static bool setGlobalClockEnable(bool enable)
430{
Colin Crossb1ce49b2014-08-20 14:28:47 -0700431 const char *clock = enable ? "global" : "local";
432
433 if (isTraceClock(clock)) {
434 return true;
435 }
436
437 return writeStr(k_traceClockPath, clock);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800438}
439
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700440static bool setPrintTgidEnableIfPresent(bool enable)
441{
442 if (fileExists(k_printTgidPath)) {
443 return setKernelOptionEnable(k_printTgidPath, enable);
444 }
445 return true;
446}
447
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800448// Poke all the binder-enabled processes in the system to get them to re-read
449// their system properties.
450static bool pokeBinderServices()
451{
452 sp<IServiceManager> sm = defaultServiceManager();
453 Vector<String16> services = sm->listServices();
454 for (size_t i = 0; i < services.size(); i++) {
455 sp<IBinder> obj = sm->checkService(services[i]);
456 if (obj != NULL) {
457 Parcel data;
458 if (obj->transact(IBinder::SYSPROPS_TRANSACTION, data,
459 NULL, 0) != OK) {
460 if (false) {
461 // XXX: For some reason this fails on tablets trying to
462 // poke the "phone" service. It's not clear whether some
463 // are expected to fail.
464 String8 svc(services[i]);
465 fprintf(stderr, "error poking binder service %s\n",
466 svc.string());
467 return false;
468 }
469 }
470 }
471 }
472 return true;
473}
474
475// Set the trace tags that userland tracing uses, and poke the running
476// processes to pick up the new value.
477static bool setTagsProperty(uint64_t tags)
478{
479 char buf[64];
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -0700480 snprintf(buf, 64, "%#" PRIx64, tags);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800481 if (property_set(k_traceTagsProperty, buf) < 0) {
482 fprintf(stderr, "error setting trace tags system property\n");
483 return false;
484 }
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700485 return true;
486}
487
488// Set the system property that indicates which apps should perform
489// application-level tracing.
490static bool setAppCmdlineProperty(const char* cmdline)
491{
492 if (property_set(k_traceAppCmdlineProperty, cmdline) < 0) {
493 fprintf(stderr, "error setting trace app system property\n");
494 return false;
495 }
496 return true;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800497}
498
499// Disable all /sys/ enable files.
500static bool disableKernelTraceEvents() {
501 bool ok = true;
502 for (int i = 0; i < NELEM(k_categories); i++) {
503 const TracingCategory &c = k_categories[i];
504 for (int j = 0; j < MAX_SYS_FILES; j++) {
505 const char* path = c.sysfiles[j].path;
506 if (path != NULL && fileIsWritable(path)) {
507 ok &= setKernelOptionEnable(path, false);
508 }
509 }
510 }
511 return ok;
512}
513
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700514// Verify that the comma separated list of functions are being traced by the
515// kernel.
516static bool verifyKernelTraceFuncs(const char* funcs)
517{
518 int fd = open(k_ftraceFilterPath, O_RDONLY);
519 if (fd == -1) {
520 fprintf(stderr, "error opening %s: %s (%d)\n", k_ftraceFilterPath,
521 strerror(errno), errno);
522 return false;
523 }
524
525 char buf[4097];
526 ssize_t n = read(fd, buf, 4096);
527 close(fd);
528 if (n == -1) {
529 fprintf(stderr, "error reading %s: %s (%d)\n", k_ftraceFilterPath,
530 strerror(errno), errno);
531 return false;
532 }
533
534 buf[n] = '\0';
535 String8 funcList = String8::format("\n%s", buf);
536
537 // Make sure that every function listed in funcs is in the list we just
538 // read from the kernel.
539 bool ok = true;
540 char* myFuncs = strdup(funcs);
541 char* func = strtok(myFuncs, ",");
542 while (func) {
543 String8 fancyFunc = String8::format("\n%s\n", func);
544 bool found = funcList.find(fancyFunc.string(), 0) >= 0;
545 if (!found || func[0] == '\0') {
546 fprintf(stderr, "error: \"%s\" is not a valid kernel function "
547 "to trace.\n", func);
548 ok = false;
549 }
550 func = strtok(NULL, ",");
551 }
552 free(myFuncs);
553
554 return ok;
555}
556
557// Set the comma separated list of functions that the kernel is to trace.
558static bool setKernelTraceFuncs(const char* funcs)
559{
560 bool ok = true;
561
562 if (funcs == NULL || funcs[0] == '\0') {
563 // Disable kernel function tracing.
Jamie Gennis6f6f3f72013-03-27 15:50:30 -0700564 if (fileIsWritable(k_currentTracerPath)) {
565 ok &= writeStr(k_currentTracerPath, "nop");
566 }
567 if (fileIsWritable(k_ftraceFilterPath)) {
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700568 ok &= truncateFile(k_ftraceFilterPath);
569 }
570 } else {
571 // Enable kernel function tracing.
572 ok &= writeStr(k_currentTracerPath, "function_graph");
573 ok &= setKernelOptionEnable(k_funcgraphAbsTimePath, true);
574 ok &= setKernelOptionEnable(k_funcgraphCpuPath, true);
575 ok &= setKernelOptionEnable(k_funcgraphProcPath, true);
576 ok &= setKernelOptionEnable(k_funcgraphFlatPath, true);
577
578 // Set the requested filter functions.
579 ok &= truncateFile(k_ftraceFilterPath);
580 char* myFuncs = strdup(funcs);
581 char* func = strtok(myFuncs, ",");
582 while (func) {
583 ok &= appendStr(k_ftraceFilterPath, func);
584 func = strtok(NULL, ",");
585 }
586 free(myFuncs);
587
588 // Verify that the set functions are being traced.
589 if (ok) {
590 ok &= verifyKernelTraceFuncs(funcs);
591 }
592 }
593
594 return ok;
595}
596
597// Set all the kernel tracing settings to the desired state for this trace
598// capture.
599static bool setUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800600{
601 bool ok = true;
602
603 // Set up the tracing options.
604 ok &= setTraceOverwriteEnable(g_traceOverwrite);
605 ok &= setTraceBufferSizeKB(g_traceBufferSizeKB);
606 ok &= setGlobalClockEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700607 ok &= setPrintTgidEnableIfPresent(true);
608 ok &= setKernelTraceFuncs(g_kernelTraceFuncs);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800609
610 // Set up the tags property.
611 uint64_t tags = 0;
612 for (int i = 0; i < NELEM(k_categories); i++) {
613 if (g_categoryEnables[i]) {
614 const TracingCategory &c = k_categories[i];
615 tags |= c.tags;
616 }
617 }
618 ok &= setTagsProperty(tags);
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700619 ok &= setAppCmdlineProperty(g_debugAppCmdLine);
620 ok &= pokeBinderServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800621
622 // Disable all the sysfs enables. This is done as a separate loop from
623 // the enables to allow the same enable to exist in multiple categories.
624 ok &= disableKernelTraceEvents();
625
626 // Enable all the sysfs enables that are in an enabled category.
627 for (int i = 0; i < NELEM(k_categories); i++) {
628 if (g_categoryEnables[i]) {
629 const TracingCategory &c = k_categories[i];
630 for (int j = 0; j < MAX_SYS_FILES; j++) {
631 const char* path = c.sysfiles[j].path;
632 bool required = c.sysfiles[j].required == REQ;
633 if (path != NULL) {
634 if (fileIsWritable(path)) {
635 ok &= setKernelOptionEnable(path, true);
636 } else if (required) {
637 fprintf(stderr, "error writing file %s\n", path);
638 ok = false;
639 }
640 }
641 }
642 }
643 }
644
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800645 return ok;
646}
647
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700648// Reset all the kernel tracing settings to their default state.
649static void cleanUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800650{
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800651 // Disable all tracing that we're able to.
652 disableKernelTraceEvents();
653
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700654 // Reset the system properties.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800655 setTagsProperty(0);
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700656 setAppCmdlineProperty("");
657 pokeBinderServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800658
659 // Set the options back to their defaults.
660 setTraceOverwriteEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700661 setTraceBufferSizeKB(1);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800662 setGlobalClockEnable(false);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700663 setPrintTgidEnableIfPresent(false);
664 setKernelTraceFuncs(NULL);
665}
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800666
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700667
668// Enable tracing in the kernel.
669static bool startTrace()
670{
671 return setTracingEnabled(true);
672}
673
674// Disable tracing in the kernel.
675static void stopTrace()
676{
677 setTracingEnabled(false);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800678}
679
680// Read the current kernel trace and write it to stdout.
681static void dumpTrace()
682{
683 int traceFD = open(k_tracePath, O_RDWR);
684 if (traceFD == -1) {
685 fprintf(stderr, "error opening %s: %s (%d)\n", k_tracePath,
686 strerror(errno), errno);
687 return;
688 }
689
690 if (g_compress) {
691 z_stream zs;
692 uint8_t *in, *out;
693 int result, flush;
694
Elliott Hughes3da5d232015-01-25 08:35:20 -0800695 memset(&zs, 0, sizeof(zs));
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800696 result = deflateInit(&zs, Z_DEFAULT_COMPRESSION);
697 if (result != Z_OK) {
698 fprintf(stderr, "error initializing zlib: %d\n", result);
699 close(traceFD);
700 return;
701 }
702
703 const size_t bufSize = 64*1024;
704 in = (uint8_t*)malloc(bufSize);
705 out = (uint8_t*)malloc(bufSize);
706 flush = Z_NO_FLUSH;
707
708 zs.next_out = out;
709 zs.avail_out = bufSize;
710
711 do {
712
713 if (zs.avail_in == 0) {
714 // More input is needed.
715 result = read(traceFD, in, bufSize);
716 if (result < 0) {
717 fprintf(stderr, "error reading trace: %s (%d)\n",
718 strerror(errno), errno);
719 result = Z_STREAM_END;
720 break;
721 } else if (result == 0) {
722 flush = Z_FINISH;
723 } else {
724 zs.next_in = in;
725 zs.avail_in = result;
726 }
727 }
728
729 if (zs.avail_out == 0) {
730 // Need to write the output.
731 result = write(STDOUT_FILENO, out, bufSize);
732 if ((size_t)result < bufSize) {
733 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
734 strerror(errno), errno);
735 result = Z_STREAM_END; // skip deflate error message
736 zs.avail_out = bufSize; // skip the final write
737 break;
738 }
739 zs.next_out = out;
740 zs.avail_out = bufSize;
741 }
742
743 } while ((result = deflate(&zs, flush)) == Z_OK);
744
745 if (result != Z_STREAM_END) {
746 fprintf(stderr, "error deflating trace: %s\n", zs.msg);
747 }
748
749 if (zs.avail_out < bufSize) {
750 size_t bytes = bufSize - zs.avail_out;
751 result = write(STDOUT_FILENO, out, bytes);
752 if ((size_t)result < bytes) {
753 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
754 strerror(errno), errno);
755 }
756 }
757
758 result = deflateEnd(&zs);
759 if (result != Z_OK) {
760 fprintf(stderr, "error cleaning up zlib: %d\n", result);
761 }
762
763 free(in);
764 free(out);
765 } else {
766 ssize_t sent = 0;
767 while ((sent = sendfile(STDOUT_FILENO, traceFD, NULL, 64*1024*1024)) > 0);
768 if (sent == -1) {
769 fprintf(stderr, "error dumping trace: %s (%d)\n", strerror(errno),
770 errno);
771 }
772 }
773
774 close(traceFD);
775}
776
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -0700777static void handleSignal(int /*signo*/)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800778{
779 if (!g_nohup) {
780 g_traceAborted = true;
781 }
782}
783
784static void registerSigHandler()
785{
786 struct sigaction sa;
787 sigemptyset(&sa.sa_mask);
788 sa.sa_flags = 0;
789 sa.sa_handler = handleSignal;
790 sigaction(SIGHUP, &sa, NULL);
791 sigaction(SIGINT, &sa, NULL);
792 sigaction(SIGQUIT, &sa, NULL);
793 sigaction(SIGTERM, &sa, NULL);
794}
795
796static bool setCategoryEnable(const char* name, bool enable)
797{
798 for (int i = 0; i < NELEM(k_categories); i++) {
799 const TracingCategory& c = k_categories[i];
800 if (strcmp(name, c.name) == 0) {
801 if (isCategorySupported(c)) {
802 g_categoryEnables[i] = enable;
803 return true;
804 } else {
805 if (isCategorySupportedForRoot(c)) {
806 fprintf(stderr, "error: category \"%s\" requires root "
807 "privileges.\n", name);
808 } else {
809 fprintf(stderr, "error: category \"%s\" is not supported "
810 "on this device.\n", name);
811 }
812 return false;
813 }
814 }
815 }
816 fprintf(stderr, "error: unknown tracing category \"%s\"\n", name);
817 return false;
818}
819
820static void listSupportedCategories()
821{
822 for (int i = 0; i < NELEM(k_categories); i++) {
823 const TracingCategory& c = k_categories[i];
824 if (isCategorySupported(c)) {
825 printf(" %10s - %s\n", c.name, c.longname);
826 }
827 }
828}
829
830// Print the command usage help to stderr.
831static void showHelp(const char *cmd)
832{
833 fprintf(stderr, "usage: %s [options] [categories...]\n", cmd);
834 fprintf(stderr, "options include:\n"
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700835 " -a appname enable app-level tracing for a comma "
836 "separated list of cmdlines\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800837 " -b N use a trace buffer size of N KB\n"
838 " -c trace into a circular buffer\n"
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700839 " -k fname,... trace the listed kernel functions\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800840 " -n ignore signals\n"
841 " -s N sleep for N seconds before tracing [default 0]\n"
842 " -t N trace for N seconds [defualt 5]\n"
843 " -z compress the trace dump\n"
844 " --async_start start circular trace and return immediatly\n"
845 " --async_dump dump the current contents of circular trace buffer\n"
846 " --async_stop stop tracing and dump the current contents of circular\n"
847 " trace buffer\n"
Jamie Gennis92573f12012-12-07 16:29:03 -0800848 " --list_categories\n"
849 " list the available tracing categories\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800850 );
851}
852
853int main(int argc, char **argv)
854{
855 bool async = false;
856 bool traceStart = true;
857 bool traceStop = true;
858 bool traceDump = true;
859
860 if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
861 showHelp(argv[0]);
862 exit(0);
863 }
864
865 for (;;) {
866 int ret;
867 int option_index = 0;
868 static struct option long_options[] = {
869 {"async_start", no_argument, 0, 0 },
870 {"async_stop", no_argument, 0, 0 },
871 {"async_dump", no_argument, 0, 0 },
872 {"list_categories", no_argument, 0, 0 },
873 { 0, 0, 0, 0 }
874 };
875
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700876 ret = getopt_long(argc, argv, "a:b:ck:ns:t:z",
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800877 long_options, &option_index);
878
879 if (ret < 0) {
880 for (int i = optind; i < argc; i++) {
881 if (!setCategoryEnable(argv[i], true)) {
882 fprintf(stderr, "error enabling tracing category \"%s\"\n", argv[i]);
883 exit(1);
884 }
885 }
886 break;
887 }
888
889 switch(ret) {
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700890 case 'a':
891 g_debugAppCmdLine = optarg;
892 break;
893
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800894 case 'b':
895 g_traceBufferSizeKB = atoi(optarg);
896 break;
897
898 case 'c':
899 g_traceOverwrite = true;
900 break;
901
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700902 case 'k':
903 g_kernelTraceFuncs = optarg;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -0700904 break;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700905
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800906 case 'n':
907 g_nohup = true;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -0700908 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800909
910 case 's':
911 g_initialSleepSecs = atoi(optarg);
912 break;
913
914 case 't':
915 g_traceDurationSeconds = atoi(optarg);
916 break;
917
918 case 'z':
919 g_compress = true;
920 break;
921
922 case 0:
923 if (!strcmp(long_options[option_index].name, "async_start")) {
924 async = true;
925 traceStop = false;
926 traceDump = false;
927 g_traceOverwrite = true;
928 } else if (!strcmp(long_options[option_index].name, "async_stop")) {
929 async = true;
John Reck2c237ee2015-05-15 10:00:34 -0700930 traceStart = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800931 } else if (!strcmp(long_options[option_index].name, "async_dump")) {
932 async = true;
933 traceStart = false;
934 traceStop = false;
935 } else if (!strcmp(long_options[option_index].name, "list_categories")) {
936 listSupportedCategories();
937 exit(0);
938 }
Jamie Gennis6f6f3f72013-03-27 15:50:30 -0700939 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800940
941 default:
942 fprintf(stderr, "\n");
943 showHelp(argv[0]);
944 exit(-1);
945 break;
946 }
947 }
948
949 registerSigHandler();
950
951 if (g_initialSleepSecs > 0) {
952 sleep(g_initialSleepSecs);
953 }
954
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700955 bool ok = true;
956 ok &= setUpTrace();
957 ok &= startTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800958
959 if (ok && traceStart) {
960 printf("capturing trace...");
961 fflush(stdout);
962
963 // We clear the trace after starting it because tracing gets enabled for
964 // each CPU individually in the kernel. Having the beginning of the trace
965 // contain entries from only one CPU can cause "begin" entries without a
966 // matching "end" entry to show up if a task gets migrated from one CPU to
967 // another.
968 ok = clearTrace();
969
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200970 writeClockSyncMarker();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800971 if (ok && !async) {
972 // Sleep to allow the trace to be captured.
973 struct timespec timeLeft;
974 timeLeft.tv_sec = g_traceDurationSeconds;
975 timeLeft.tv_nsec = 0;
976 do {
977 if (g_traceAborted) {
978 break;
979 }
980 } while (nanosleep(&timeLeft, &timeLeft) == -1 && errno == EINTR);
981 }
982 }
983
984 // Stop the trace and restore the default settings.
985 if (traceStop)
986 stopTrace();
987
988 if (ok && traceDump) {
989 if (!g_traceAborted) {
990 printf(" done\nTRACE:\n");
991 fflush(stdout);
992 dumpTrace();
993 } else {
994 printf("\ntrace aborted.\n");
995 fflush(stdout);
996 }
997 clearTrace();
998 } else if (!ok) {
999 fprintf(stderr, "unable to start tracing\n");
1000 }
1001
1002 // Reset the trace buffer size to 1.
1003 if (traceStop)
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001004 cleanUpTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001005
1006 return g_traceAborted ? 1 : 0;
1007}