blob: ee2b2758fc8144d6b50ce5434e3167311420ebe1 [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
Paul Lawrence2cd93cc2017-01-17 09:50:18 -080017#define LOG_TAG "atrace"
John Reck40b26b42016-03-30 09:44:36 -070018
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080019#include <errno.h>
20#include <fcntl.h>
21#include <getopt.h>
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -070022#include <inttypes.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080023#include <signal.h>
24#include <stdarg.h>
25#include <stdbool.h>
26#include <stdio.h>
27#include <stdlib.h>
Elliott Hughes3da5d232015-01-25 08:35:20 -080028#include <string.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080029#include <sys/sendfile.h>
30#include <time.h>
Martijn Coenend9535872015-11-26 10:00:55 +010031#include <unistd.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080032#include <zlib.h>
33
Elliott Hughesa252f4d2016-07-21 17:12:15 -070034#include <memory>
35
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080036#include <binder/IBinder.h>
37#include <binder/IServiceManager.h>
38#include <binder/Parcel.h>
39
Martijn Coenenee9b97e2016-11-16 16:00:26 +010040#include <android/hidl/manager/1.0/IServiceManager.h>
41#include <hidl/ServiceManagement.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080042#include <cutils/properties.h>
43
44#include <utils/String8.h>
John Reck469a1942015-03-26 15:31:35 -070045#include <utils/Timers.h>
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +090046#include <utils/Tokenizer.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080047#include <utils/Trace.h>
Stephane Gasparinid8419c22016-03-02 13:45:15 +010048#include <android-base/file.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080049
50using namespace android;
51
Martijn Coenenee9b97e2016-11-16 16:00:26 +010052using std::string;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080053#define NELEM(x) ((int) (sizeof(x) / sizeof((x)[0])))
54
sergeyv4144eff2016-04-28 11:40:04 -070055#define MAX_SYS_FILES 10
56#define MAX_PACKAGES 16
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080057
58const char* k_traceTagsProperty = "debug.atrace.tags.enableflags";
sergeyv4144eff2016-04-28 11:40:04 -070059
60const char* k_traceAppsNumberProperty = "debug.atrace.app_number";
61const char* k_traceAppsPropertyTemplate = "debug.atrace.app_%d";
sergeyvdb404152016-05-02 19:26:07 -070062const char* k_coreServiceCategory = "core_services";
63const char* k_coreServicesProp = "ro.atrace.core.services";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080064
65typedef enum { OPT, REQ } requiredness ;
66
67struct TracingCategory {
68 // The name identifying the category.
69 const char* name;
70
71 // A longer description of the category.
72 const char* longname;
73
74 // The userland tracing tags that the category enables.
75 uint64_t tags;
76
77 // The fname==NULL terminated list of /sys/ files that the category
78 // enables.
79 struct {
80 // Whether the file must be writable in order to enable the tracing
81 // category.
82 requiredness required;
83
84 // The path to the enable file.
85 const char* path;
86 } sysfiles[MAX_SYS_FILES];
87};
88
89/* Tracing categories */
90static const TracingCategory k_categories[] = {
Jamie Gennisb2a89e32013-03-11 19:37:53 -070091 { "gfx", "Graphics", ATRACE_TAG_GRAPHICS, { } },
92 { "input", "Input", ATRACE_TAG_INPUT, { } },
93 { "view", "View System", ATRACE_TAG_VIEW, { } },
94 { "webview", "WebView", ATRACE_TAG_WEBVIEW, { } },
95 { "wm", "Window Manager", ATRACE_TAG_WINDOW_MANAGER, { } },
96 { "am", "Activity Manager", ATRACE_TAG_ACTIVITY_MANAGER, { } },
Patrick Auchter70ec2942014-09-30 15:38:30 -050097 { "sm", "Sync Manager", ATRACE_TAG_SYNC_MANAGER, { } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -070098 { "audio", "Audio", ATRACE_TAG_AUDIO, { } },
99 { "video", "Video", ATRACE_TAG_VIDEO, { } },
100 { "camera", "Camera", ATRACE_TAG_CAMERA, { } },
101 { "hal", "Hardware Modules", ATRACE_TAG_HAL, { } },
Jeff Brown3200b0b2014-08-14 19:24:47 -0700102 { "app", "Application", ATRACE_TAG_APP, { } },
Dianne Hackborn9380d782013-04-12 14:52:35 -0700103 { "res", "Resource Loading", ATRACE_TAG_RESOURCES, { } },
Jamie Genniseff2e8d2013-05-07 15:20:39 -0700104 { "dalvik", "Dalvik VM", ATRACE_TAG_DALVIK, { } },
Tim Murrayf0f28412013-05-23 14:39:42 -0700105 { "rs", "RenderScript", ATRACE_TAG_RS, { } },
Brigid Smith750aa972014-05-28 14:23:24 -0700106 { "bionic", "Bionic C Library", ATRACE_TAG_BIONIC, { } },
Jeff Brown3200b0b2014-08-14 19:24:47 -0700107 { "power", "Power Management", ATRACE_TAG_POWER, { } },
Todd Kennedy01e111b2015-07-31 14:36:20 -0700108 { "pm", "Package Manager", ATRACE_TAG_PACKAGE_MANAGER, { } },
Yasuhiro Matsuda7cc49772015-07-01 01:46:25 +0900109 { "ss", "System Server", ATRACE_TAG_SYSTEM_SERVER, { } },
Greg Hackmannbbd7d992014-12-01 14:43:34 -0800110 { "database", "Database", ATRACE_TAG_DATABASE, { } },
Felipe Leme0f97c1d2016-09-07 11:33:26 -0700111 { "network", "Network", ATRACE_TAG_NETWORK, { } },
Josh Gao468b4cb2016-11-29 10:55:21 -0800112 { "adb", "ADB", ATRACE_TAG_ADB, { } },
sergeyvdb404152016-05-02 19:26:07 -0700113 { k_coreServiceCategory, "Core services", 0, { } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700114 { "sched", "CPU Scheduling", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800115 { REQ, "events/sched/sched_switch/enable" },
116 { REQ, "events/sched/sched_wakeup/enable" },
117 { OPT, "events/sched/sched_blocked_reason/enable" },
118 { OPT, "events/sched/sched_cpu_hotplug/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800119 } },
Dan Willemsenf440d392014-04-11 15:44:09 -0700120 { "irq", "IRQ Events", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800121 { REQ, "events/irq/enable" },
122 { OPT, "events/ipi/enable" },
Dan Willemsenf440d392014-04-11 15:44:09 -0700123 } },
Michael Wrightab54f682016-08-18 19:56:43 +0100124 { "i2c", "I2C Events", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800125 { REQ, "events/i2c/enable" },
126 { REQ, "events/i2c/i2c_read/enable" },
127 { REQ, "events/i2c/i2c_write/enable" },
128 { REQ, "events/i2c/i2c_result/enable" },
129 { REQ, "events/i2c/i2c_reply/enable" },
130 { OPT, "events/i2c/smbus_read/enable" },
131 { OPT, "events/i2c/smbus_write/enable" },
132 { OPT, "events/i2c/smbus_result/enable" },
133 { OPT, "events/i2c/smbus_reply/enable" },
Michael Wrightab54f682016-08-18 19:56:43 +0100134 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700135 { "freq", "CPU Frequency", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800136 { REQ, "events/power/cpu_frequency/enable" },
137 { OPT, "events/power/clock_set_rate/enable" },
138 { OPT, "events/power/cpu_frequency_limits/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800139 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700140 { "membus", "Memory Bus Utilization", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800141 { REQ, "events/memory_bus/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800142 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700143 { "idle", "CPU Idle", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800144 { REQ, "events/power/cpu_idle/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800145 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700146 { "disk", "Disk I/O", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800147 { OPT, "events/f2fs/f2fs_sync_file_enter/enable" },
148 { OPT, "events/f2fs/f2fs_sync_file_exit/enable" },
149 { OPT, "events/f2fs/f2fs_write_begin/enable" },
150 { OPT, "events/f2fs/f2fs_write_end/enable" },
151 { OPT, "events/ext4/ext4_da_write_begin/enable" },
152 { OPT, "events/ext4/ext4_da_write_end/enable" },
153 { OPT, "events/ext4/ext4_sync_file_enter/enable" },
154 { OPT, "events/ext4/ext4_sync_file_exit/enable" },
155 { REQ, "events/block/block_rq_issue/enable" },
156 { REQ, "events/block/block_rq_complete/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800157 } },
Ken Sumralld3fa5612013-07-03 12:32:03 -0700158 { "mmc", "eMMC commands", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800159 { REQ, "events/mmc/enable" },
Ken Sumralld3fa5612013-07-03 12:32:03 -0700160 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700161 { "load", "CPU Load", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800162 { REQ, "events/cpufreq_interactive/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800163 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700164 { "sync", "Synchronization", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800165 { REQ, "events/sync/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800166 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700167 { "workq", "Kernel Workqueues", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800168 { REQ, "events/workqueue/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800169 } },
Colin Cross580407f2014-08-18 15:22:13 -0700170 { "memreclaim", "Kernel Memory Reclaim", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800171 { REQ, "events/vmscan/mm_vmscan_direct_reclaim_begin/enable" },
172 { REQ, "events/vmscan/mm_vmscan_direct_reclaim_end/enable" },
173 { REQ, "events/vmscan/mm_vmscan_kswapd_wake/enable" },
174 { REQ, "events/vmscan/mm_vmscan_kswapd_sleep/enable" },
Colin Cross580407f2014-08-18 15:22:13 -0700175 } },
Aaron Schulmanc2c6ecd2015-02-25 08:37:09 -0800176 { "regulators", "Voltage and Current Regulators", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800177 { REQ, "events/regulator/enable" },
Aaron Schulmanc2c6ecd2015-02-25 08:37:09 -0800178 } },
Scott Bauerae473362015-06-08 16:32:36 -0700179 { "binder_driver", "Binder Kernel driver", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800180 { REQ, "events/binder/binder_transaction/enable" },
181 { REQ, "events/binder/binder_transaction_received/enable" },
Scott Bauerae473362015-06-08 16:32:36 -0700182 } },
183 { "binder_lock", "Binder global lock trace", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800184 { REQ, "events/binder/binder_lock/enable" },
185 { REQ, "events/binder/binder_locked/enable" },
186 { REQ, "events/binder/binder_unlock/enable" },
Scott Bauerae473362015-06-08 16:32:36 -0700187 } },
Martijn Coenen70481612015-10-23 13:57:05 +0200188 { "pagecache", "Page cache", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800189 { REQ, "events/filemap/enable" },
Martijn Coenen70481612015-10-23 13:57:05 +0200190 } },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800191};
192
193/* Command line options */
194static int g_traceDurationSeconds = 5;
195static bool g_traceOverwrite = false;
196static int g_traceBufferSizeKB = 2048;
197static bool g_compress = false;
198static bool g_nohup = false;
199static int g_initialSleepSecs = 0;
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900200static const char* g_categoriesFile = NULL;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700201static const char* g_kernelTraceFuncs = NULL;
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700202static const char* g_debugAppCmdLine = "";
John Reck40b26b42016-03-30 09:44:36 -0700203static const char* g_outputFile = nullptr;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800204
205/* Global state */
206static bool g_traceAborted = false;
207static bool g_categoryEnables[NELEM(k_categories)] = {};
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800208static std::string g_traceFolder;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800209
210/* Sys file paths */
211static const char* k_traceClockPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800212 "trace_clock";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800213
214static const char* k_traceBufferSizePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800215 "buffer_size_kb";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800216
217static const char* k_tracingOverwriteEnablePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800218 "options/overwrite";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800219
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700220static const char* k_currentTracerPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800221 "current_tracer";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700222
223static const char* k_printTgidPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800224 "options/print-tgid";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700225
226static const char* k_funcgraphAbsTimePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800227 "options/funcgraph-abstime";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700228
229static const char* k_funcgraphCpuPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800230 "options/funcgraph-cpu";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700231
232static const char* k_funcgraphProcPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800233 "options/funcgraph-proc";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700234
235static const char* k_funcgraphFlatPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800236 "options/funcgraph-flat";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700237
238static const char* k_funcgraphDurationPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800239 "options/funcgraph-duration";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700240
241static const char* k_ftraceFilterPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800242 "set_ftrace_filter";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700243
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800244static const char* k_tracingOnPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800245 "tracing_on";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800246
247static const char* k_tracePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800248 "trace";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800249
Martijn Coenend9535872015-11-26 10:00:55 +0100250static const char* k_traceStreamPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800251 "trace_pipe";
Martijn Coenend9535872015-11-26 10:00:55 +0100252
John Reck469a1942015-03-26 15:31:35 -0700253static const char* k_traceMarkerPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800254 "trace_marker";
John Reck469a1942015-03-26 15:31:35 -0700255
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800256// Check whether a file exists.
257static bool fileExists(const char* filename) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800258 return access((g_traceFolder + filename).c_str(), F_OK) != -1;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800259}
260
261// Check whether a file is writable.
262static bool fileIsWritable(const char* filename) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800263 return access((g_traceFolder + filename).c_str(), W_OK) != -1;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800264}
265
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700266// Truncate a file.
267static bool truncateFile(const char* path)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800268{
Jamie Gennis43122e72013-03-21 14:06:31 -0700269 // This uses creat rather than truncate because some of the debug kernel
270 // device nodes (e.g. k_ftraceFilterPath) currently aren't changed by
271 // calls to truncate, but they are cleared by calls to creat.
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800272 int traceFD = creat((g_traceFolder + path).c_str(), 0);
Jamie Gennis43122e72013-03-21 14:06:31 -0700273 if (traceFD == -1) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800274 fprintf(stderr, "error truncating %s: %s (%d)\n", (g_traceFolder + path).c_str(),
Jamie Gennis43122e72013-03-21 14:06:31 -0700275 strerror(errno), errno);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700276 return false;
277 }
278
Jamie Gennis43122e72013-03-21 14:06:31 -0700279 close(traceFD);
280
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700281 return true;
282}
283
284static bool _writeStr(const char* filename, const char* str, int flags)
285{
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800286 std::string fullFilename = g_traceFolder + filename;
287 int fd = open(fullFilename.c_str(), flags);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800288 if (fd == -1) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800289 fprintf(stderr, "error opening %s: %s (%d)\n", fullFilename.c_str(),
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800290 strerror(errno), errno);
291 return false;
292 }
293
294 bool ok = true;
295 ssize_t len = strlen(str);
296 if (write(fd, str, len) != len) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800297 fprintf(stderr, "error writing to %s: %s (%d)\n", fullFilename.c_str(),
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800298 strerror(errno), errno);
299 ok = false;
300 }
301
302 close(fd);
303
304 return ok;
305}
306
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700307// Write a string to a file, returning true if the write was successful.
308static bool writeStr(const char* filename, const char* str)
309{
310 return _writeStr(filename, str, O_WRONLY);
311}
312
313// Append a string to a file, returning true if the write was successful.
314static bool appendStr(const char* filename, const char* str)
315{
316 return _writeStr(filename, str, O_APPEND|O_WRONLY);
317}
318
John Reck469a1942015-03-26 15:31:35 -0700319static void writeClockSyncMarker()
320{
321 char buffer[128];
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200322 int len = 0;
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800323 int fd = open((g_traceFolder + k_traceMarkerPath).c_str(), O_WRONLY);
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200324 if (fd == -1) {
325 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceMarkerPath,
326 strerror(errno), errno);
327 return;
328 }
John Reck469a1942015-03-26 15:31:35 -0700329 float now_in_seconds = systemTime(CLOCK_MONOTONIC) / 1000000000.0f;
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200330
331 len = snprintf(buffer, 128, "trace_event_clock_sync: parent_ts=%f\n", now_in_seconds);
332 if (write(fd, buffer, len) != len) {
333 fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
334 }
335
336 int64_t realtime_in_ms = systemTime(CLOCK_REALTIME) / 1000000;
337 len = snprintf(buffer, 128, "trace_event_clock_sync: realtime_ts=%" PRId64 "\n", realtime_in_ms);
338 if (write(fd, buffer, len) != len) {
339 fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
340 }
341
342 close(fd);
John Reck469a1942015-03-26 15:31:35 -0700343}
344
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800345// Enable or disable a kernel option by writing a "1" or a "0" into a /sys
346// file.
347static bool setKernelOptionEnable(const char* filename, bool enable)
348{
349 return writeStr(filename, enable ? "1" : "0");
350}
351
352// Check whether the category is supported on the device with the current
353// rootness. A category is supported only if all its required /sys/ files are
354// writable and if enabling the category will enable one or more tracing tags
355// or /sys/ files.
356static bool isCategorySupported(const TracingCategory& category)
357{
sergeyvdb404152016-05-02 19:26:07 -0700358 if (strcmp(category.name, k_coreServiceCategory) == 0) {
359 char value[PROPERTY_VALUE_MAX];
360 property_get(k_coreServicesProp, value, "");
361 return strlen(value) != 0;
362 }
363
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800364 bool ok = category.tags != 0;
365 for (int i = 0; i < MAX_SYS_FILES; i++) {
366 const char* path = category.sysfiles[i].path;
367 bool req = category.sysfiles[i].required == REQ;
368 if (path != NULL) {
369 if (req) {
370 if (!fileIsWritable(path)) {
371 return false;
372 } else {
373 ok = true;
374 }
375 } else {
376 ok |= fileIsWritable(path);
377 }
378 }
379 }
380 return ok;
381}
382
383// Check whether the category would be supported on the device if the user
384// were root. This function assumes that root is able to write to any file
385// that exists. It performs the same logic as isCategorySupported, but it
386// uses file existance rather than writability in the /sys/ file checks.
387static bool isCategorySupportedForRoot(const TracingCategory& category)
388{
389 bool ok = category.tags != 0;
390 for (int i = 0; i < MAX_SYS_FILES; i++) {
391 const char* path = category.sysfiles[i].path;
392 bool req = category.sysfiles[i].required == REQ;
393 if (path != NULL) {
394 if (req) {
395 if (!fileExists(path)) {
396 return false;
397 } else {
398 ok = true;
399 }
400 } else {
401 ok |= fileExists(path);
402 }
403 }
404 }
405 return ok;
406}
407
408// Enable or disable overwriting of the kernel trace buffers. Disabling this
409// will cause tracing to stop once the trace buffers have filled up.
410static bool setTraceOverwriteEnable(bool enable)
411{
412 return setKernelOptionEnable(k_tracingOverwriteEnablePath, enable);
413}
414
415// Enable or disable kernel tracing.
416static bool setTracingEnabled(bool enable)
417{
418 return setKernelOptionEnable(k_tracingOnPath, enable);
419}
420
421// Clear the contents of the kernel trace.
422static bool clearTrace()
423{
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700424 return truncateFile(k_tracePath);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800425}
426
427// Set the size of the kernel's trace buffer in kilobytes.
428static bool setTraceBufferSizeKB(int size)
429{
430 char str[32] = "1";
431 int len;
432 if (size < 1) {
433 size = 1;
434 }
435 snprintf(str, 32, "%d", size);
436 return writeStr(k_traceBufferSizePath, str);
437}
438
Colin Crossb1ce49b2014-08-20 14:28:47 -0700439// Read the trace_clock sysfs file and return true if it matches the requested
440// value. The trace_clock file format is:
441// local [global] counter uptime perf
442static bool isTraceClock(const char *mode)
443{
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800444 int fd = open((g_traceFolder + k_traceClockPath).c_str(), O_RDONLY);
Colin Crossb1ce49b2014-08-20 14:28:47 -0700445 if (fd == -1) {
446 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceClockPath,
447 strerror(errno), errno);
448 return false;
449 }
450
451 char buf[4097];
452 ssize_t n = read(fd, buf, 4096);
453 close(fd);
454 if (n == -1) {
455 fprintf(stderr, "error reading %s: %s (%d)\n", k_traceClockPath,
456 strerror(errno), errno);
457 return false;
458 }
459 buf[n] = '\0';
460
461 char *start = strchr(buf, '[');
462 if (start == NULL) {
463 return false;
464 }
465 start++;
466
467 char *end = strchr(start, ']');
468 if (end == NULL) {
469 return false;
470 }
471 *end = '\0';
472
473 return strcmp(mode, start) == 0;
474}
475
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800476// Enable or disable the kernel's use of the global clock. Disabling the global
477// clock will result in the kernel using a per-CPU local clock.
Colin Crossb1ce49b2014-08-20 14:28:47 -0700478// Any write to the trace_clock sysfs file will reset the buffer, so only
479// update it if the requested value is not the current value.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800480static bool setGlobalClockEnable(bool enable)
481{
Colin Crossb1ce49b2014-08-20 14:28:47 -0700482 const char *clock = enable ? "global" : "local";
483
484 if (isTraceClock(clock)) {
485 return true;
486 }
487
488 return writeStr(k_traceClockPath, clock);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800489}
490
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700491static bool setPrintTgidEnableIfPresent(bool enable)
492{
493 if (fileExists(k_printTgidPath)) {
494 return setKernelOptionEnable(k_printTgidPath, enable);
495 }
496 return true;
497}
498
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800499// Poke all the binder-enabled processes in the system to get them to re-read
500// their system properties.
501static bool pokeBinderServices()
502{
503 sp<IServiceManager> sm = defaultServiceManager();
504 Vector<String16> services = sm->listServices();
505 for (size_t i = 0; i < services.size(); i++) {
506 sp<IBinder> obj = sm->checkService(services[i]);
507 if (obj != NULL) {
508 Parcel data;
509 if (obj->transact(IBinder::SYSPROPS_TRANSACTION, data,
510 NULL, 0) != OK) {
511 if (false) {
512 // XXX: For some reason this fails on tablets trying to
513 // poke the "phone" service. It's not clear whether some
514 // are expected to fail.
515 String8 svc(services[i]);
516 fprintf(stderr, "error poking binder service %s\n",
517 svc.string());
518 return false;
519 }
520 }
521 }
522 }
523 return true;
524}
525
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100526// Poke all the HAL processes in the system to get them to re-read
527// their system properties.
528static void pokeHalServices()
529{
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100530 using ::android::hidl::base::V1_0::IBase;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100531 using ::android::hidl::manager::V1_0::IServiceManager;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100532 using ::android::hardware::hidl_string;
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100533 using ::android::hardware::Return;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100534
535 sp<IServiceManager> sm = ::android::hardware::defaultServiceManager();
Steven Morelanda42866b2016-12-12 15:18:06 -0800536
537 if (sm == nullptr) {
538 fprintf(stderr, "failed to get IServiceManager to poke hal services\n");
539 return;
540 }
541
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800542 auto listRet = sm->list([&](const auto &interfaces) {
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100543 for (size_t i = 0; i < interfaces.size(); i++) {
544 string fqInstanceName = interfaces[i];
545 string::size_type n = fqInstanceName.find("/");
546 if (n == std::string::npos || interfaces[i].size() == n+1)
547 continue;
548 hidl_string fqInterfaceName = fqInstanceName.substr(0, n);
549 hidl_string instanceName = fqInstanceName.substr(n+1, std::string::npos);
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100550 Return<sp<IBase>> interfaceRet = sm->get(fqInterfaceName, instanceName);
551 if (!interfaceRet.isOk()) {
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800552 fprintf(stderr, "failed to get service %s: %s\n",
553 fqInstanceName.c_str(),
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100554 interfaceRet.description().c_str());
555 continue;
556 }
557 sp<IBase> interface = interfaceRet;
558 auto notifyRet = interface->notifySyspropsChanged();
559 if (!notifyRet.isOk()) {
560 fprintf(stderr, "failed to notifySyspropsChanged on service %s: %s\n",
561 fqInstanceName.c_str(),
562 notifyRet.description().c_str());
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800563 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100564 }
565 });
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800566 if (!listRet.isOk()) {
Martijn Coenen64d54eb2017-01-12 17:16:31 +0100567 // TODO(b/34242478) fix this when we determine the correct ACL
568 //fprintf(stderr, "failed to list services: %s\n", listRet.description().c_str());
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800569 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100570}
571
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800572// Set the trace tags that userland tracing uses, and poke the running
573// processes to pick up the new value.
574static bool setTagsProperty(uint64_t tags)
575{
sergeyv4144eff2016-04-28 11:40:04 -0700576 char buf[PROPERTY_VALUE_MAX];
577 snprintf(buf, sizeof(buf), "%#" PRIx64, tags);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800578 if (property_set(k_traceTagsProperty, buf) < 0) {
579 fprintf(stderr, "error setting trace tags system property\n");
580 return false;
581 }
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700582 return true;
583}
584
sergeyv4144eff2016-04-28 11:40:04 -0700585static void clearAppProperties()
586{
587 char buf[PROPERTY_KEY_MAX];
588 for (int i = 0; i < MAX_PACKAGES; i++) {
589 snprintf(buf, sizeof(buf), k_traceAppsPropertyTemplate, i);
590 if (property_set(buf, "") < 0) {
591 fprintf(stderr, "failed to clear system property: %s\n", buf);
592 }
593 }
594 if (property_set(k_traceAppsNumberProperty, "") < 0) {
595 fprintf(stderr, "failed to clear system property: %s",
596 k_traceAppsNumberProperty);
597 }
598}
599
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700600// Set the system property that indicates which apps should perform
601// application-level tracing.
Dan Austin497951c2016-05-31 13:27:03 -0700602static bool setAppCmdlineProperty(char* cmdline)
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700603{
sergeyv4144eff2016-04-28 11:40:04 -0700604 char buf[PROPERTY_KEY_MAX];
605 int i = 0;
Dan Austin497951c2016-05-31 13:27:03 -0700606 char* start = cmdline;
sergeyv4144eff2016-04-28 11:40:04 -0700607 while (start != NULL) {
608 if (i == MAX_PACKAGES) {
609 fprintf(stderr, "error: only 16 packages could be traced at once\n");
610 clearAppProperties();
611 return false;
612 }
613 char* end = strchr(start, ',');
614 if (end != NULL) {
615 *end = '\0';
616 end++;
617 }
618 snprintf(buf, sizeof(buf), k_traceAppsPropertyTemplate, i);
619 if (property_set(buf, start) < 0) {
620 fprintf(stderr, "error setting trace app %d property to %s\n", i, buf);
621 clearAppProperties();
622 return false;
623 }
624 start = end;
625 i++;
626 }
627
628 snprintf(buf, sizeof(buf), "%d", i);
629 if (property_set(k_traceAppsNumberProperty, buf) < 0) {
630 fprintf(stderr, "error setting trace app number property to %s\n", buf);
631 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700632 return false;
633 }
634 return true;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800635}
636
637// Disable all /sys/ enable files.
638static bool disableKernelTraceEvents() {
639 bool ok = true;
640 for (int i = 0; i < NELEM(k_categories); i++) {
641 const TracingCategory &c = k_categories[i];
642 for (int j = 0; j < MAX_SYS_FILES; j++) {
643 const char* path = c.sysfiles[j].path;
644 if (path != NULL && fileIsWritable(path)) {
645 ok &= setKernelOptionEnable(path, false);
646 }
647 }
648 }
649 return ok;
650}
651
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700652// Verify that the comma separated list of functions are being traced by the
653// kernel.
654static bool verifyKernelTraceFuncs(const char* funcs)
655{
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100656 std::string buf;
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800657 if (!android::base::ReadFileToString(g_traceFolder + k_ftraceFilterPath, &buf)) {
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100658 fprintf(stderr, "error opening %s: %s (%d)\n", k_ftraceFilterPath,
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700659 strerror(errno), errno);
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100660 return false;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700661 }
662
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100663 String8 funcList = String8::format("\n%s",buf.c_str());
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700664
665 // Make sure that every function listed in funcs is in the list we just
Thomas Buhota2c22872016-01-27 09:44:31 +0100666 // read from the kernel, except for wildcard inputs.
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700667 bool ok = true;
668 char* myFuncs = strdup(funcs);
669 char* func = strtok(myFuncs, ",");
670 while (func) {
Thomas Buhota2c22872016-01-27 09:44:31 +0100671 if (!strchr(func, '*')) {
672 String8 fancyFunc = String8::format("\n%s\n", func);
673 bool found = funcList.find(fancyFunc.string(), 0) >= 0;
674 if (!found || func[0] == '\0') {
675 fprintf(stderr, "error: \"%s\" is not a valid kernel function "
676 "to trace.\n", func);
677 ok = false;
678 }
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700679 }
680 func = strtok(NULL, ",");
681 }
682 free(myFuncs);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700683 return ok;
684}
685
686// Set the comma separated list of functions that the kernel is to trace.
687static bool setKernelTraceFuncs(const char* funcs)
688{
689 bool ok = true;
690
691 if (funcs == NULL || funcs[0] == '\0') {
692 // Disable kernel function tracing.
Jamie Gennis6f6f3f72013-03-27 15:50:30 -0700693 if (fileIsWritable(k_currentTracerPath)) {
694 ok &= writeStr(k_currentTracerPath, "nop");
695 }
696 if (fileIsWritable(k_ftraceFilterPath)) {
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700697 ok &= truncateFile(k_ftraceFilterPath);
698 }
699 } else {
700 // Enable kernel function tracing.
701 ok &= writeStr(k_currentTracerPath, "function_graph");
702 ok &= setKernelOptionEnable(k_funcgraphAbsTimePath, true);
703 ok &= setKernelOptionEnable(k_funcgraphCpuPath, true);
704 ok &= setKernelOptionEnable(k_funcgraphProcPath, true);
705 ok &= setKernelOptionEnable(k_funcgraphFlatPath, true);
706
707 // Set the requested filter functions.
708 ok &= truncateFile(k_ftraceFilterPath);
709 char* myFuncs = strdup(funcs);
710 char* func = strtok(myFuncs, ",");
711 while (func) {
712 ok &= appendStr(k_ftraceFilterPath, func);
713 func = strtok(NULL, ",");
714 }
715 free(myFuncs);
716
717 // Verify that the set functions are being traced.
718 if (ok) {
719 ok &= verifyKernelTraceFuncs(funcs);
720 }
721 }
722
723 return ok;
724}
725
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900726static bool setCategoryEnable(const char* name, bool enable)
727{
728 for (int i = 0; i < NELEM(k_categories); i++) {
729 const TracingCategory& c = k_categories[i];
730 if (strcmp(name, c.name) == 0) {
731 if (isCategorySupported(c)) {
732 g_categoryEnables[i] = enable;
733 return true;
734 } else {
735 if (isCategorySupportedForRoot(c)) {
736 fprintf(stderr, "error: category \"%s\" requires root "
737 "privileges.\n", name);
738 } else {
739 fprintf(stderr, "error: category \"%s\" is not supported "
740 "on this device.\n", name);
741 }
742 return false;
743 }
744 }
745 }
746 fprintf(stderr, "error: unknown tracing category \"%s\"\n", name);
747 return false;
748}
749
750static bool setCategoriesEnableFromFile(const char* categories_file)
751{
752 if (!categories_file) {
753 return true;
754 }
755 Tokenizer* tokenizer = NULL;
756 if (Tokenizer::open(String8(categories_file), &tokenizer) != NO_ERROR) {
757 return false;
758 }
759 bool ok = true;
760 while (!tokenizer->isEol()) {
761 String8 token = tokenizer->nextToken(" ");
762 if (token.isEmpty()) {
763 tokenizer->skipDelimiters(" ");
764 continue;
765 }
766 ok &= setCategoryEnable(token.string(), true);
767 }
768 delete tokenizer;
769 return ok;
770}
771
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700772// Set all the kernel tracing settings to the desired state for this trace
773// capture.
774static bool setUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800775{
776 bool ok = true;
777
778 // Set up the tracing options.
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900779 ok &= setCategoriesEnableFromFile(g_categoriesFile);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800780 ok &= setTraceOverwriteEnable(g_traceOverwrite);
781 ok &= setTraceBufferSizeKB(g_traceBufferSizeKB);
782 ok &= setGlobalClockEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700783 ok &= setPrintTgidEnableIfPresent(true);
784 ok &= setKernelTraceFuncs(g_kernelTraceFuncs);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800785
786 // Set up the tags property.
787 uint64_t tags = 0;
788 for (int i = 0; i < NELEM(k_categories); i++) {
789 if (g_categoryEnables[i]) {
790 const TracingCategory &c = k_categories[i];
791 tags |= c.tags;
792 }
793 }
794 ok &= setTagsProperty(tags);
sergeyvdb404152016-05-02 19:26:07 -0700795
796 bool coreServicesTagEnabled = false;
797 for (int i = 0; i < NELEM(k_categories); i++) {
798 if (strcmp(k_categories[i].name, k_coreServiceCategory) == 0) {
799 coreServicesTagEnabled = g_categoryEnables[i];
800 }
801 }
802
803 std::string packageList(g_debugAppCmdLine);
804 if (coreServicesTagEnabled) {
805 char value[PROPERTY_VALUE_MAX];
806 property_get(k_coreServicesProp, value, "");
807 if (!packageList.empty()) {
808 packageList += ",";
809 }
810 packageList += value;
811 }
Dan Austin497951c2016-05-31 13:27:03 -0700812 ok &= setAppCmdlineProperty(&packageList[0]);
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700813 ok &= pokeBinderServices();
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100814 pokeHalServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800815
816 // Disable all the sysfs enables. This is done as a separate loop from
817 // the enables to allow the same enable to exist in multiple categories.
818 ok &= disableKernelTraceEvents();
819
820 // Enable all the sysfs enables that are in an enabled category.
821 for (int i = 0; i < NELEM(k_categories); i++) {
822 if (g_categoryEnables[i]) {
823 const TracingCategory &c = k_categories[i];
824 for (int j = 0; j < MAX_SYS_FILES; j++) {
825 const char* path = c.sysfiles[j].path;
826 bool required = c.sysfiles[j].required == REQ;
827 if (path != NULL) {
828 if (fileIsWritable(path)) {
829 ok &= setKernelOptionEnable(path, true);
830 } else if (required) {
831 fprintf(stderr, "error writing file %s\n", path);
832 ok = false;
833 }
834 }
835 }
836 }
837 }
838
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800839 return ok;
840}
841
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700842// Reset all the kernel tracing settings to their default state.
843static void cleanUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800844{
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800845 // Disable all tracing that we're able to.
846 disableKernelTraceEvents();
847
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700848 // Reset the system properties.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800849 setTagsProperty(0);
sergeyv4144eff2016-04-28 11:40:04 -0700850 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700851 pokeBinderServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800852
853 // Set the options back to their defaults.
854 setTraceOverwriteEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700855 setTraceBufferSizeKB(1);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800856 setGlobalClockEnable(false);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700857 setPrintTgidEnableIfPresent(false);
858 setKernelTraceFuncs(NULL);
859}
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800860
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700861
862// Enable tracing in the kernel.
863static bool startTrace()
864{
865 return setTracingEnabled(true);
866}
867
868// Disable tracing in the kernel.
869static void stopTrace()
870{
871 setTracingEnabled(false);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800872}
873
Martijn Coenend9535872015-11-26 10:00:55 +0100874// Read data from the tracing pipe and forward to stdout
875static void streamTrace()
876{
877 char trace_data[4096];
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800878 int traceFD = open((g_traceFolder + k_traceStreamPath).c_str(), O_RDWR);
Martijn Coenend9535872015-11-26 10:00:55 +0100879 if (traceFD == -1) {
880 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceStreamPath,
881 strerror(errno), errno);
882 return;
883 }
884 while (!g_traceAborted) {
885 ssize_t bytes_read = read(traceFD, trace_data, 4096);
886 if (bytes_read > 0) {
887 write(STDOUT_FILENO, trace_data, bytes_read);
888 fflush(stdout);
889 } else {
890 if (!g_traceAborted) {
891 fprintf(stderr, "read returned %zd bytes err %d (%s)\n",
892 bytes_read, errno, strerror(errno));
893 }
894 break;
895 }
896 }
897}
898
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800899// Read the current kernel trace and write it to stdout.
John Reck40b26b42016-03-30 09:44:36 -0700900static void dumpTrace(int outFd)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800901{
John Reck6c8ac922016-03-28 11:25:30 -0700902 ALOGI("Dumping trace");
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800903 int traceFD = open((g_traceFolder + k_tracePath).c_str(), O_RDWR);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800904 if (traceFD == -1) {
905 fprintf(stderr, "error opening %s: %s (%d)\n", k_tracePath,
906 strerror(errno), errno);
907 return;
908 }
909
910 if (g_compress) {
911 z_stream zs;
Elliott Hughes3da5d232015-01-25 08:35:20 -0800912 memset(&zs, 0, sizeof(zs));
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700913
914 int result = deflateInit(&zs, Z_DEFAULT_COMPRESSION);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800915 if (result != Z_OK) {
916 fprintf(stderr, "error initializing zlib: %d\n", result);
917 close(traceFD);
918 return;
919 }
920
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700921 constexpr size_t bufSize = 64*1024;
922 std::unique_ptr<uint8_t> in(new uint8_t[bufSize]);
923 std::unique_ptr<uint8_t> out(new uint8_t[bufSize]);
924 if (!in || !out) {
925 fprintf(stderr, "couldn't allocate buffers\n");
926 close(traceFD);
927 return;
928 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800929
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700930 int flush = Z_NO_FLUSH;
931
932 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800933 zs.avail_out = bufSize;
934
935 do {
936
937 if (zs.avail_in == 0) {
938 // More input is needed.
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700939 result = read(traceFD, in.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800940 if (result < 0) {
941 fprintf(stderr, "error reading trace: %s (%d)\n",
942 strerror(errno), errno);
943 result = Z_STREAM_END;
944 break;
945 } else if (result == 0) {
946 flush = Z_FINISH;
947 } else {
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700948 zs.next_in = reinterpret_cast<Bytef*>(in.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800949 zs.avail_in = result;
950 }
951 }
952
953 if (zs.avail_out == 0) {
954 // Need to write the output.
Elliott Hughesb59e2962016-07-22 09:00:59 -0700955 result = write(outFd, out.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800956 if ((size_t)result < bufSize) {
957 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
958 strerror(errno), errno);
959 result = Z_STREAM_END; // skip deflate error message
960 zs.avail_out = bufSize; // skip the final write
961 break;
962 }
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700963 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800964 zs.avail_out = bufSize;
965 }
966
967 } while ((result = deflate(&zs, flush)) == Z_OK);
968
969 if (result != Z_STREAM_END) {
970 fprintf(stderr, "error deflating trace: %s\n", zs.msg);
971 }
972
973 if (zs.avail_out < bufSize) {
974 size_t bytes = bufSize - zs.avail_out;
Elliott Hughesb59e2962016-07-22 09:00:59 -0700975 result = write(outFd, out.get(), bytes);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800976 if ((size_t)result < bytes) {
977 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
978 strerror(errno), errno);
979 }
980 }
981
982 result = deflateEnd(&zs);
983 if (result != Z_OK) {
984 fprintf(stderr, "error cleaning up zlib: %d\n", result);
985 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800986 } else {
987 ssize_t sent = 0;
John Reck40b26b42016-03-30 09:44:36 -0700988 while ((sent = sendfile(outFd, traceFD, NULL, 64*1024*1024)) > 0);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800989 if (sent == -1) {
990 fprintf(stderr, "error dumping trace: %s (%d)\n", strerror(errno),
991 errno);
992 }
993 }
994
995 close(traceFD);
996}
997
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -0700998static void handleSignal(int /*signo*/)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800999{
1000 if (!g_nohup) {
1001 g_traceAborted = true;
1002 }
1003}
1004
1005static void registerSigHandler()
1006{
1007 struct sigaction sa;
1008 sigemptyset(&sa.sa_mask);
1009 sa.sa_flags = 0;
1010 sa.sa_handler = handleSignal;
1011 sigaction(SIGHUP, &sa, NULL);
1012 sigaction(SIGINT, &sa, NULL);
1013 sigaction(SIGQUIT, &sa, NULL);
1014 sigaction(SIGTERM, &sa, NULL);
1015}
1016
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001017static void listSupportedCategories()
1018{
1019 for (int i = 0; i < NELEM(k_categories); i++) {
1020 const TracingCategory& c = k_categories[i];
1021 if (isCategorySupported(c)) {
1022 printf(" %10s - %s\n", c.name, c.longname);
1023 }
1024 }
1025}
1026
1027// Print the command usage help to stderr.
1028static void showHelp(const char *cmd)
1029{
1030 fprintf(stderr, "usage: %s [options] [categories...]\n", cmd);
1031 fprintf(stderr, "options include:\n"
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001032 " -a appname enable app-level tracing for a comma "
1033 "separated list of cmdlines\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001034 " -b N use a trace buffer size of N KB\n"
1035 " -c trace into a circular buffer\n"
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001036 " -f filename use the categories written in a file as space-separated\n"
1037 " values in a line\n"
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001038 " -k fname,... trace the listed kernel functions\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001039 " -n ignore signals\n"
1040 " -s N sleep for N seconds before tracing [default 0]\n"
Elliott Hughesf884a062016-07-22 09:38:44 -07001041 " -t N trace for N seconds [default 5]\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001042 " -z compress the trace dump\n"
1043 " --async_start start circular trace and return immediatly\n"
1044 " --async_dump dump the current contents of circular trace buffer\n"
1045 " --async_stop stop tracing and dump the current contents of circular\n"
1046 " trace buffer\n"
Martijn Coenend9535872015-11-26 10:00:55 +01001047 " --stream stream trace to stdout as it enters the trace buffer\n"
1048 " Note: this can take significant CPU time, and is best\n"
1049 " used for measuring things that are not affected by\n"
1050 " CPU performance, like pagecache usage.\n"
Jamie Gennis92573f12012-12-07 16:29:03 -08001051 " --list_categories\n"
1052 " list the available tracing categories\n"
John Reck40b26b42016-03-30 09:44:36 -07001053 " -o filename write the trace to the specified file instead\n"
1054 " of stdout.\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001055 );
1056}
1057
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001058bool findTraceFiles()
1059{
1060 static const std::string debugfs_path = "/sys/kernel/debug/tracing/";
1061 static const std::string tracefs_path = "/sys/kernel/tracing/";
1062 static const std::string trace_file = "trace_marker";
1063
1064 bool tracefs = access((tracefs_path + trace_file).c_str(), F_OK) != -1;
1065 bool debugfs = access((debugfs_path + trace_file).c_str(), F_OK) != -1;
1066
1067 if (!tracefs && !debugfs) {
1068 fprintf(stderr, "Error: Did not find trace folder\n");
1069 return false;
1070 }
1071
1072 if (tracefs) {
1073 g_traceFolder = tracefs_path;
1074 } else {
1075 g_traceFolder = debugfs_path;
1076 }
1077
1078 return true;
1079}
1080
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001081int main(int argc, char **argv)
1082{
1083 bool async = false;
1084 bool traceStart = true;
1085 bool traceStop = true;
1086 bool traceDump = true;
Martijn Coenend9535872015-11-26 10:00:55 +01001087 bool traceStream = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001088
1089 if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
1090 showHelp(argv[0]);
1091 exit(0);
1092 }
1093
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001094 if (!findTraceFiles()) {
1095 fprintf(stderr, "No trace folder found\n");
1096 exit(-1);
1097 }
1098
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001099 for (;;) {
1100 int ret;
1101 int option_index = 0;
1102 static struct option long_options[] = {
1103 {"async_start", no_argument, 0, 0 },
1104 {"async_stop", no_argument, 0, 0 },
1105 {"async_dump", no_argument, 0, 0 },
1106 {"list_categories", no_argument, 0, 0 },
Martijn Coenend9535872015-11-26 10:00:55 +01001107 {"stream", no_argument, 0, 0 },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001108 { 0, 0, 0, 0 }
1109 };
1110
John Reck40b26b42016-03-30 09:44:36 -07001111 ret = getopt_long(argc, argv, "a:b:cf:k:ns:t:zo:",
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001112 long_options, &option_index);
1113
1114 if (ret < 0) {
1115 for (int i = optind; i < argc; i++) {
1116 if (!setCategoryEnable(argv[i], true)) {
1117 fprintf(stderr, "error enabling tracing category \"%s\"\n", argv[i]);
1118 exit(1);
1119 }
1120 }
1121 break;
1122 }
1123
1124 switch(ret) {
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001125 case 'a':
1126 g_debugAppCmdLine = optarg;
1127 break;
1128
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001129 case 'b':
1130 g_traceBufferSizeKB = atoi(optarg);
1131 break;
1132
1133 case 'c':
1134 g_traceOverwrite = true;
1135 break;
1136
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001137 case 'f':
1138 g_categoriesFile = optarg;
1139 break;
1140
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001141 case 'k':
1142 g_kernelTraceFuncs = optarg;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001143 break;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001144
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001145 case 'n':
1146 g_nohup = true;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001147 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001148
1149 case 's':
1150 g_initialSleepSecs = atoi(optarg);
1151 break;
1152
1153 case 't':
1154 g_traceDurationSeconds = atoi(optarg);
1155 break;
1156
1157 case 'z':
1158 g_compress = true;
1159 break;
1160
John Reck40b26b42016-03-30 09:44:36 -07001161 case 'o':
1162 g_outputFile = optarg;
1163 break;
1164
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001165 case 0:
1166 if (!strcmp(long_options[option_index].name, "async_start")) {
1167 async = true;
1168 traceStop = false;
1169 traceDump = false;
1170 g_traceOverwrite = true;
1171 } else if (!strcmp(long_options[option_index].name, "async_stop")) {
1172 async = true;
John Reck4ba2b632015-05-15 10:00:34 -07001173 traceStart = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001174 } else if (!strcmp(long_options[option_index].name, "async_dump")) {
1175 async = true;
1176 traceStart = false;
1177 traceStop = false;
Martijn Coenend9535872015-11-26 10:00:55 +01001178 } else if (!strcmp(long_options[option_index].name, "stream")) {
1179 traceStream = true;
1180 traceDump = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001181 } else if (!strcmp(long_options[option_index].name, "list_categories")) {
1182 listSupportedCategories();
1183 exit(0);
1184 }
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001185 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001186
1187 default:
1188 fprintf(stderr, "\n");
1189 showHelp(argv[0]);
1190 exit(-1);
1191 break;
1192 }
1193 }
1194
1195 registerSigHandler();
1196
1197 if (g_initialSleepSecs > 0) {
1198 sleep(g_initialSleepSecs);
1199 }
1200
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001201 bool ok = true;
1202 ok &= setUpTrace();
1203 ok &= startTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001204
1205 if (ok && traceStart) {
Martijn Coenend9535872015-11-26 10:00:55 +01001206 if (!traceStream) {
1207 printf("capturing trace...");
1208 fflush(stdout);
1209 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001210
1211 // We clear the trace after starting it because tracing gets enabled for
1212 // each CPU individually in the kernel. Having the beginning of the trace
1213 // contain entries from only one CPU can cause "begin" entries without a
1214 // matching "end" entry to show up if a task gets migrated from one CPU to
1215 // another.
1216 ok = clearTrace();
1217
Martijn Coenen0bcd97a2015-07-15 14:25:23 +02001218 writeClockSyncMarker();
Martijn Coenend9535872015-11-26 10:00:55 +01001219 if (ok && !async && !traceStream) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001220 // Sleep to allow the trace to be captured.
1221 struct timespec timeLeft;
1222 timeLeft.tv_sec = g_traceDurationSeconds;
1223 timeLeft.tv_nsec = 0;
1224 do {
1225 if (g_traceAborted) {
1226 break;
1227 }
1228 } while (nanosleep(&timeLeft, &timeLeft) == -1 && errno == EINTR);
1229 }
Martijn Coenend9535872015-11-26 10:00:55 +01001230
1231 if (traceStream) {
1232 streamTrace();
1233 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001234 }
1235
1236 // Stop the trace and restore the default settings.
1237 if (traceStop)
1238 stopTrace();
1239
1240 if (ok && traceDump) {
1241 if (!g_traceAborted) {
John Reck40b26b42016-03-30 09:44:36 -07001242 printf(" done\n");
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001243 fflush(stdout);
John Reck40b26b42016-03-30 09:44:36 -07001244 int outFd = STDOUT_FILENO;
1245 if (g_outputFile) {
1246 outFd = open(g_outputFile, O_WRONLY | O_CREAT);
1247 }
1248 if (outFd == -1) {
1249 printf("Failed to open '%s', err=%d", g_outputFile, errno);
1250 } else {
1251 dprintf(outFd, "TRACE:\n");
1252 dumpTrace(outFd);
1253 if (g_outputFile) {
1254 close(outFd);
1255 }
1256 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001257 } else {
1258 printf("\ntrace aborted.\n");
1259 fflush(stdout);
1260 }
1261 clearTrace();
1262 } else if (!ok) {
1263 fprintf(stderr, "unable to start tracing\n");
1264 }
1265
1266 // Reset the trace buffer size to 1.
1267 if (traceStop)
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001268 cleanUpTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001269
1270 return g_traceAborted ? 1 : 0;
1271}