blob: 05e1615b85bbcc0b7b133b7eecee4e276859c510 [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 Wright43fb6782016-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 Wright43fb6782016-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
Fabien Sanglardb5c95472016-06-08 11:40:12 -0700386// uses file existence rather than writability in the /sys/ file checks.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800387static 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()) {
Martijn Coenen1e4a7fb2017-02-17 14:57:38 +0100552 // ignore
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100553 continue;
554 }
555 sp<IBase> interface = interfaceRet;
556 auto notifyRet = interface->notifySyspropsChanged();
557 if (!notifyRet.isOk()) {
Martijn Coenen1e4a7fb2017-02-17 14:57:38 +0100558 // ignore
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800559 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100560 }
561 });
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800562 if (!listRet.isOk()) {
Martijn Coenen64d54eb2017-01-12 17:16:31 +0100563 // TODO(b/34242478) fix this when we determine the correct ACL
564 //fprintf(stderr, "failed to list services: %s\n", listRet.description().c_str());
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800565 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100566}
567
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800568// Set the trace tags that userland tracing uses, and poke the running
569// processes to pick up the new value.
570static bool setTagsProperty(uint64_t tags)
571{
sergeyv4144eff2016-04-28 11:40:04 -0700572 char buf[PROPERTY_VALUE_MAX];
573 snprintf(buf, sizeof(buf), "%#" PRIx64, tags);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800574 if (property_set(k_traceTagsProperty, buf) < 0) {
575 fprintf(stderr, "error setting trace tags system property\n");
576 return false;
577 }
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700578 return true;
579}
580
sergeyv4144eff2016-04-28 11:40:04 -0700581static void clearAppProperties()
582{
583 char buf[PROPERTY_KEY_MAX];
584 for (int i = 0; i < MAX_PACKAGES; i++) {
585 snprintf(buf, sizeof(buf), k_traceAppsPropertyTemplate, i);
586 if (property_set(buf, "") < 0) {
587 fprintf(stderr, "failed to clear system property: %s\n", buf);
588 }
589 }
590 if (property_set(k_traceAppsNumberProperty, "") < 0) {
591 fprintf(stderr, "failed to clear system property: %s",
592 k_traceAppsNumberProperty);
593 }
594}
595
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700596// Set the system property that indicates which apps should perform
597// application-level tracing.
Dan Austin09a79872016-05-31 13:27:03 -0700598static bool setAppCmdlineProperty(char* cmdline)
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700599{
sergeyv4144eff2016-04-28 11:40:04 -0700600 char buf[PROPERTY_KEY_MAX];
601 int i = 0;
Dan Austin09a79872016-05-31 13:27:03 -0700602 char* start = cmdline;
sergeyv4144eff2016-04-28 11:40:04 -0700603 while (start != NULL) {
604 if (i == MAX_PACKAGES) {
605 fprintf(stderr, "error: only 16 packages could be traced at once\n");
606 clearAppProperties();
607 return false;
608 }
609 char* end = strchr(start, ',');
610 if (end != NULL) {
611 *end = '\0';
612 end++;
613 }
614 snprintf(buf, sizeof(buf), k_traceAppsPropertyTemplate, i);
615 if (property_set(buf, start) < 0) {
616 fprintf(stderr, "error setting trace app %d property to %s\n", i, buf);
617 clearAppProperties();
618 return false;
619 }
620 start = end;
621 i++;
622 }
623
624 snprintf(buf, sizeof(buf), "%d", i);
625 if (property_set(k_traceAppsNumberProperty, buf) < 0) {
626 fprintf(stderr, "error setting trace app number property to %s\n", buf);
627 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700628 return false;
629 }
630 return true;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800631}
632
633// Disable all /sys/ enable files.
634static bool disableKernelTraceEvents() {
635 bool ok = true;
636 for (int i = 0; i < NELEM(k_categories); i++) {
637 const TracingCategory &c = k_categories[i];
638 for (int j = 0; j < MAX_SYS_FILES; j++) {
639 const char* path = c.sysfiles[j].path;
640 if (path != NULL && fileIsWritable(path)) {
641 ok &= setKernelOptionEnable(path, false);
642 }
643 }
644 }
645 return ok;
646}
647
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700648// Verify that the comma separated list of functions are being traced by the
649// kernel.
650static bool verifyKernelTraceFuncs(const char* funcs)
651{
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100652 std::string buf;
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800653 if (!android::base::ReadFileToString(g_traceFolder + k_ftraceFilterPath, &buf)) {
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100654 fprintf(stderr, "error opening %s: %s (%d)\n", k_ftraceFilterPath,
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700655 strerror(errno), errno);
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100656 return false;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700657 }
658
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100659 String8 funcList = String8::format("\n%s",buf.c_str());
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700660
661 // Make sure that every function listed in funcs is in the list we just
Thomas Buhota2c22872016-01-27 09:44:31 +0100662 // read from the kernel, except for wildcard inputs.
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700663 bool ok = true;
664 char* myFuncs = strdup(funcs);
665 char* func = strtok(myFuncs, ",");
666 while (func) {
Thomas Buhota2c22872016-01-27 09:44:31 +0100667 if (!strchr(func, '*')) {
668 String8 fancyFunc = String8::format("\n%s\n", func);
669 bool found = funcList.find(fancyFunc.string(), 0) >= 0;
670 if (!found || func[0] == '\0') {
671 fprintf(stderr, "error: \"%s\" is not a valid kernel function "
672 "to trace.\n", func);
673 ok = false;
674 }
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700675 }
676 func = strtok(NULL, ",");
677 }
678 free(myFuncs);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700679 return ok;
680}
681
682// Set the comma separated list of functions that the kernel is to trace.
683static bool setKernelTraceFuncs(const char* funcs)
684{
685 bool ok = true;
686
687 if (funcs == NULL || funcs[0] == '\0') {
688 // Disable kernel function tracing.
Jamie Gennis6f6f3f72013-03-27 15:50:30 -0700689 if (fileIsWritable(k_currentTracerPath)) {
690 ok &= writeStr(k_currentTracerPath, "nop");
691 }
692 if (fileIsWritable(k_ftraceFilterPath)) {
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700693 ok &= truncateFile(k_ftraceFilterPath);
694 }
695 } else {
696 // Enable kernel function tracing.
697 ok &= writeStr(k_currentTracerPath, "function_graph");
698 ok &= setKernelOptionEnable(k_funcgraphAbsTimePath, true);
699 ok &= setKernelOptionEnable(k_funcgraphCpuPath, true);
700 ok &= setKernelOptionEnable(k_funcgraphProcPath, true);
701 ok &= setKernelOptionEnable(k_funcgraphFlatPath, true);
702
703 // Set the requested filter functions.
704 ok &= truncateFile(k_ftraceFilterPath);
705 char* myFuncs = strdup(funcs);
706 char* func = strtok(myFuncs, ",");
707 while (func) {
708 ok &= appendStr(k_ftraceFilterPath, func);
709 func = strtok(NULL, ",");
710 }
711 free(myFuncs);
712
713 // Verify that the set functions are being traced.
714 if (ok) {
715 ok &= verifyKernelTraceFuncs(funcs);
716 }
717 }
718
719 return ok;
720}
721
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900722static bool setCategoryEnable(const char* name, bool enable)
723{
724 for (int i = 0; i < NELEM(k_categories); i++) {
725 const TracingCategory& c = k_categories[i];
726 if (strcmp(name, c.name) == 0) {
727 if (isCategorySupported(c)) {
728 g_categoryEnables[i] = enable;
729 return true;
730 } else {
731 if (isCategorySupportedForRoot(c)) {
732 fprintf(stderr, "error: category \"%s\" requires root "
733 "privileges.\n", name);
734 } else {
735 fprintf(stderr, "error: category \"%s\" is not supported "
736 "on this device.\n", name);
737 }
738 return false;
739 }
740 }
741 }
742 fprintf(stderr, "error: unknown tracing category \"%s\"\n", name);
743 return false;
744}
745
746static bool setCategoriesEnableFromFile(const char* categories_file)
747{
748 if (!categories_file) {
749 return true;
750 }
751 Tokenizer* tokenizer = NULL;
752 if (Tokenizer::open(String8(categories_file), &tokenizer) != NO_ERROR) {
753 return false;
754 }
755 bool ok = true;
756 while (!tokenizer->isEol()) {
757 String8 token = tokenizer->nextToken(" ");
758 if (token.isEmpty()) {
759 tokenizer->skipDelimiters(" ");
760 continue;
761 }
762 ok &= setCategoryEnable(token.string(), true);
763 }
764 delete tokenizer;
765 return ok;
766}
767
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700768// Set all the kernel tracing settings to the desired state for this trace
769// capture.
770static bool setUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800771{
772 bool ok = true;
773
774 // Set up the tracing options.
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900775 ok &= setCategoriesEnableFromFile(g_categoriesFile);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800776 ok &= setTraceOverwriteEnable(g_traceOverwrite);
777 ok &= setTraceBufferSizeKB(g_traceBufferSizeKB);
778 ok &= setGlobalClockEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700779 ok &= setPrintTgidEnableIfPresent(true);
780 ok &= setKernelTraceFuncs(g_kernelTraceFuncs);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800781
782 // Set up the tags property.
783 uint64_t tags = 0;
784 for (int i = 0; i < NELEM(k_categories); i++) {
785 if (g_categoryEnables[i]) {
786 const TracingCategory &c = k_categories[i];
787 tags |= c.tags;
788 }
789 }
790 ok &= setTagsProperty(tags);
sergeyvdb404152016-05-02 19:26:07 -0700791
792 bool coreServicesTagEnabled = false;
793 for (int i = 0; i < NELEM(k_categories); i++) {
794 if (strcmp(k_categories[i].name, k_coreServiceCategory) == 0) {
795 coreServicesTagEnabled = g_categoryEnables[i];
796 }
797 }
798
799 std::string packageList(g_debugAppCmdLine);
800 if (coreServicesTagEnabled) {
801 char value[PROPERTY_VALUE_MAX];
802 property_get(k_coreServicesProp, value, "");
803 if (!packageList.empty()) {
804 packageList += ",";
805 }
806 packageList += value;
807 }
Dan Austin09a79872016-05-31 13:27:03 -0700808 ok &= setAppCmdlineProperty(&packageList[0]);
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700809 ok &= pokeBinderServices();
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100810 pokeHalServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800811
812 // Disable all the sysfs enables. This is done as a separate loop from
813 // the enables to allow the same enable to exist in multiple categories.
814 ok &= disableKernelTraceEvents();
815
816 // Enable all the sysfs enables that are in an enabled category.
817 for (int i = 0; i < NELEM(k_categories); i++) {
818 if (g_categoryEnables[i]) {
819 const TracingCategory &c = k_categories[i];
820 for (int j = 0; j < MAX_SYS_FILES; j++) {
821 const char* path = c.sysfiles[j].path;
822 bool required = c.sysfiles[j].required == REQ;
823 if (path != NULL) {
824 if (fileIsWritable(path)) {
825 ok &= setKernelOptionEnable(path, true);
826 } else if (required) {
827 fprintf(stderr, "error writing file %s\n", path);
828 ok = false;
829 }
830 }
831 }
832 }
833 }
834
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800835 return ok;
836}
837
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700838// Reset all the kernel tracing settings to their default state.
839static void cleanUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800840{
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800841 // Disable all tracing that we're able to.
842 disableKernelTraceEvents();
843
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700844 // Reset the system properties.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800845 setTagsProperty(0);
sergeyv4144eff2016-04-28 11:40:04 -0700846 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700847 pokeBinderServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800848
849 // Set the options back to their defaults.
850 setTraceOverwriteEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700851 setTraceBufferSizeKB(1);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800852 setGlobalClockEnable(false);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700853 setPrintTgidEnableIfPresent(false);
854 setKernelTraceFuncs(NULL);
855}
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800856
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700857
858// Enable tracing in the kernel.
859static bool startTrace()
860{
861 return setTracingEnabled(true);
862}
863
864// Disable tracing in the kernel.
865static void stopTrace()
866{
867 setTracingEnabled(false);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800868}
869
Martijn Coenend9535872015-11-26 10:00:55 +0100870// Read data from the tracing pipe and forward to stdout
871static void streamTrace()
872{
873 char trace_data[4096];
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800874 int traceFD = open((g_traceFolder + k_traceStreamPath).c_str(), O_RDWR);
Martijn Coenend9535872015-11-26 10:00:55 +0100875 if (traceFD == -1) {
876 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceStreamPath,
877 strerror(errno), errno);
878 return;
879 }
880 while (!g_traceAborted) {
881 ssize_t bytes_read = read(traceFD, trace_data, 4096);
882 if (bytes_read > 0) {
883 write(STDOUT_FILENO, trace_data, bytes_read);
884 fflush(stdout);
885 } else {
886 if (!g_traceAborted) {
887 fprintf(stderr, "read returned %zd bytes err %d (%s)\n",
888 bytes_read, errno, strerror(errno));
889 }
890 break;
891 }
892 }
893}
894
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800895// Read the current kernel trace and write it to stdout.
John Reck40b26b42016-03-30 09:44:36 -0700896static void dumpTrace(int outFd)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800897{
John Reck6c8ac922016-03-28 11:25:30 -0700898 ALOGI("Dumping trace");
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800899 int traceFD = open((g_traceFolder + k_tracePath).c_str(), O_RDWR);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800900 if (traceFD == -1) {
901 fprintf(stderr, "error opening %s: %s (%d)\n", k_tracePath,
902 strerror(errno), errno);
903 return;
904 }
905
906 if (g_compress) {
907 z_stream zs;
Elliott Hughes3da5d232015-01-25 08:35:20 -0800908 memset(&zs, 0, sizeof(zs));
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700909
910 int result = deflateInit(&zs, Z_DEFAULT_COMPRESSION);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800911 if (result != Z_OK) {
912 fprintf(stderr, "error initializing zlib: %d\n", result);
913 close(traceFD);
914 return;
915 }
916
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700917 constexpr size_t bufSize = 64*1024;
918 std::unique_ptr<uint8_t> in(new uint8_t[bufSize]);
919 std::unique_ptr<uint8_t> out(new uint8_t[bufSize]);
920 if (!in || !out) {
921 fprintf(stderr, "couldn't allocate buffers\n");
922 close(traceFD);
923 return;
924 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800925
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700926 int flush = Z_NO_FLUSH;
927
928 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800929 zs.avail_out = bufSize;
930
931 do {
932
933 if (zs.avail_in == 0) {
934 // More input is needed.
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700935 result = read(traceFD, in.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800936 if (result < 0) {
937 fprintf(stderr, "error reading trace: %s (%d)\n",
938 strerror(errno), errno);
939 result = Z_STREAM_END;
940 break;
941 } else if (result == 0) {
942 flush = Z_FINISH;
943 } else {
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700944 zs.next_in = reinterpret_cast<Bytef*>(in.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800945 zs.avail_in = result;
946 }
947 }
948
949 if (zs.avail_out == 0) {
950 // Need to write the output.
Elliott Hughesb59e2962016-07-22 09:00:59 -0700951 result = write(outFd, out.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800952 if ((size_t)result < bufSize) {
953 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
954 strerror(errno), errno);
955 result = Z_STREAM_END; // skip deflate error message
956 zs.avail_out = bufSize; // skip the final write
957 break;
958 }
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700959 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800960 zs.avail_out = bufSize;
961 }
962
963 } while ((result = deflate(&zs, flush)) == Z_OK);
964
965 if (result != Z_STREAM_END) {
966 fprintf(stderr, "error deflating trace: %s\n", zs.msg);
967 }
968
969 if (zs.avail_out < bufSize) {
970 size_t bytes = bufSize - zs.avail_out;
Elliott Hughesb59e2962016-07-22 09:00:59 -0700971 result = write(outFd, out.get(), bytes);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800972 if ((size_t)result < bytes) {
973 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
974 strerror(errno), errno);
975 }
976 }
977
978 result = deflateEnd(&zs);
979 if (result != Z_OK) {
980 fprintf(stderr, "error cleaning up zlib: %d\n", result);
981 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800982 } else {
983 ssize_t sent = 0;
John Reck40b26b42016-03-30 09:44:36 -0700984 while ((sent = sendfile(outFd, traceFD, NULL, 64*1024*1024)) > 0);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800985 if (sent == -1) {
986 fprintf(stderr, "error dumping trace: %s (%d)\n", strerror(errno),
987 errno);
988 }
989 }
990
991 close(traceFD);
992}
993
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -0700994static void handleSignal(int /*signo*/)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800995{
996 if (!g_nohup) {
997 g_traceAborted = true;
998 }
999}
1000
1001static void registerSigHandler()
1002{
1003 struct sigaction sa;
1004 sigemptyset(&sa.sa_mask);
1005 sa.sa_flags = 0;
1006 sa.sa_handler = handleSignal;
1007 sigaction(SIGHUP, &sa, NULL);
1008 sigaction(SIGINT, &sa, NULL);
1009 sigaction(SIGQUIT, &sa, NULL);
1010 sigaction(SIGTERM, &sa, NULL);
1011}
1012
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001013static void listSupportedCategories()
1014{
1015 for (int i = 0; i < NELEM(k_categories); i++) {
1016 const TracingCategory& c = k_categories[i];
1017 if (isCategorySupported(c)) {
1018 printf(" %10s - %s\n", c.name, c.longname);
1019 }
1020 }
1021}
1022
1023// Print the command usage help to stderr.
1024static void showHelp(const char *cmd)
1025{
1026 fprintf(stderr, "usage: %s [options] [categories...]\n", cmd);
1027 fprintf(stderr, "options include:\n"
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001028 " -a appname enable app-level tracing for a comma "
1029 "separated list of cmdlines\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001030 " -b N use a trace buffer size of N KB\n"
1031 " -c trace into a circular buffer\n"
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001032 " -f filename use the categories written in a file as space-separated\n"
1033 " values in a line\n"
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001034 " -k fname,... trace the listed kernel functions\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001035 " -n ignore signals\n"
1036 " -s N sleep for N seconds before tracing [default 0]\n"
Fabien Sanglardb5c95472016-06-08 11:40:12 -07001037 " -t N trace for N seconds [default 5]\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001038 " -z compress the trace dump\n"
Fabien Sanglardb5c95472016-06-08 11:40:12 -07001039 " --async_start start circular trace and return immediately\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001040 " --async_dump dump the current contents of circular trace buffer\n"
1041 " --async_stop stop tracing and dump the current contents of circular\n"
1042 " trace buffer\n"
Martijn Coenend9535872015-11-26 10:00:55 +01001043 " --stream stream trace to stdout as it enters the trace buffer\n"
1044 " Note: this can take significant CPU time, and is best\n"
1045 " used for measuring things that are not affected by\n"
1046 " CPU performance, like pagecache usage.\n"
Jamie Gennis92573f12012-12-07 16:29:03 -08001047 " --list_categories\n"
1048 " list the available tracing categories\n"
John Reck40b26b42016-03-30 09:44:36 -07001049 " -o filename write the trace to the specified file instead\n"
1050 " of stdout.\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001051 );
1052}
1053
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001054bool findTraceFiles()
1055{
1056 static const std::string debugfs_path = "/sys/kernel/debug/tracing/";
1057 static const std::string tracefs_path = "/sys/kernel/tracing/";
1058 static const std::string trace_file = "trace_marker";
1059
1060 bool tracefs = access((tracefs_path + trace_file).c_str(), F_OK) != -1;
1061 bool debugfs = access((debugfs_path + trace_file).c_str(), F_OK) != -1;
1062
1063 if (!tracefs && !debugfs) {
1064 fprintf(stderr, "Error: Did not find trace folder\n");
1065 return false;
1066 }
1067
1068 if (tracefs) {
1069 g_traceFolder = tracefs_path;
1070 } else {
1071 g_traceFolder = debugfs_path;
1072 }
1073
1074 return true;
1075}
1076
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001077int main(int argc, char **argv)
1078{
1079 bool async = false;
1080 bool traceStart = true;
1081 bool traceStop = true;
1082 bool traceDump = true;
Martijn Coenend9535872015-11-26 10:00:55 +01001083 bool traceStream = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001084
1085 if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
1086 showHelp(argv[0]);
1087 exit(0);
1088 }
1089
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001090 if (!findTraceFiles()) {
1091 fprintf(stderr, "No trace folder found\n");
1092 exit(-1);
1093 }
1094
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001095 for (;;) {
1096 int ret;
1097 int option_index = 0;
1098 static struct option long_options[] = {
1099 {"async_start", no_argument, 0, 0 },
1100 {"async_stop", no_argument, 0, 0 },
1101 {"async_dump", no_argument, 0, 0 },
1102 {"list_categories", no_argument, 0, 0 },
Martijn Coenend9535872015-11-26 10:00:55 +01001103 {"stream", no_argument, 0, 0 },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001104 { 0, 0, 0, 0 }
1105 };
1106
John Reck40b26b42016-03-30 09:44:36 -07001107 ret = getopt_long(argc, argv, "a:b:cf:k:ns:t:zo:",
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001108 long_options, &option_index);
1109
1110 if (ret < 0) {
1111 for (int i = optind; i < argc; i++) {
1112 if (!setCategoryEnable(argv[i], true)) {
1113 fprintf(stderr, "error enabling tracing category \"%s\"\n", argv[i]);
1114 exit(1);
1115 }
1116 }
1117 break;
1118 }
1119
1120 switch(ret) {
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001121 case 'a':
1122 g_debugAppCmdLine = optarg;
1123 break;
1124
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001125 case 'b':
1126 g_traceBufferSizeKB = atoi(optarg);
1127 break;
1128
1129 case 'c':
1130 g_traceOverwrite = true;
1131 break;
1132
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001133 case 'f':
1134 g_categoriesFile = optarg;
1135 break;
1136
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001137 case 'k':
1138 g_kernelTraceFuncs = optarg;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001139 break;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001140
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001141 case 'n':
1142 g_nohup = true;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001143 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001144
1145 case 's':
1146 g_initialSleepSecs = atoi(optarg);
1147 break;
1148
1149 case 't':
1150 g_traceDurationSeconds = atoi(optarg);
1151 break;
1152
1153 case 'z':
1154 g_compress = true;
1155 break;
1156
John Reck40b26b42016-03-30 09:44:36 -07001157 case 'o':
1158 g_outputFile = optarg;
1159 break;
1160
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001161 case 0:
1162 if (!strcmp(long_options[option_index].name, "async_start")) {
1163 async = true;
1164 traceStop = false;
1165 traceDump = false;
1166 g_traceOverwrite = true;
1167 } else if (!strcmp(long_options[option_index].name, "async_stop")) {
1168 async = true;
John Reck4ba2b632015-05-15 10:00:34 -07001169 traceStart = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001170 } else if (!strcmp(long_options[option_index].name, "async_dump")) {
1171 async = true;
1172 traceStart = false;
1173 traceStop = false;
Martijn Coenend9535872015-11-26 10:00:55 +01001174 } else if (!strcmp(long_options[option_index].name, "stream")) {
1175 traceStream = true;
1176 traceDump = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001177 } else if (!strcmp(long_options[option_index].name, "list_categories")) {
1178 listSupportedCategories();
1179 exit(0);
1180 }
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001181 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001182
1183 default:
1184 fprintf(stderr, "\n");
1185 showHelp(argv[0]);
1186 exit(-1);
1187 break;
1188 }
1189 }
1190
1191 registerSigHandler();
1192
1193 if (g_initialSleepSecs > 0) {
1194 sleep(g_initialSleepSecs);
1195 }
1196
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001197 bool ok = true;
1198 ok &= setUpTrace();
1199 ok &= startTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001200
1201 if (ok && traceStart) {
Martijn Coenend9535872015-11-26 10:00:55 +01001202 if (!traceStream) {
1203 printf("capturing trace...");
1204 fflush(stdout);
1205 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001206
1207 // We clear the trace after starting it because tracing gets enabled for
1208 // each CPU individually in the kernel. Having the beginning of the trace
1209 // contain entries from only one CPU can cause "begin" entries without a
1210 // matching "end" entry to show up if a task gets migrated from one CPU to
1211 // another.
1212 ok = clearTrace();
1213
Martijn Coenen0bcd97a2015-07-15 14:25:23 +02001214 writeClockSyncMarker();
Martijn Coenend9535872015-11-26 10:00:55 +01001215 if (ok && !async && !traceStream) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001216 // Sleep to allow the trace to be captured.
1217 struct timespec timeLeft;
1218 timeLeft.tv_sec = g_traceDurationSeconds;
1219 timeLeft.tv_nsec = 0;
1220 do {
1221 if (g_traceAborted) {
1222 break;
1223 }
1224 } while (nanosleep(&timeLeft, &timeLeft) == -1 && errno == EINTR);
1225 }
Martijn Coenend9535872015-11-26 10:00:55 +01001226
1227 if (traceStream) {
1228 streamTrace();
1229 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001230 }
1231
1232 // Stop the trace and restore the default settings.
1233 if (traceStop)
1234 stopTrace();
1235
1236 if (ok && traceDump) {
1237 if (!g_traceAborted) {
John Reck40b26b42016-03-30 09:44:36 -07001238 printf(" done\n");
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001239 fflush(stdout);
John Reck40b26b42016-03-30 09:44:36 -07001240 int outFd = STDOUT_FILENO;
1241 if (g_outputFile) {
Martijn Coenenc5791982017-02-22 09:25:31 +01001242 outFd = open(g_outputFile, O_WRONLY | O_CREAT | O_TRUNC, 0644);
John Reck40b26b42016-03-30 09:44:36 -07001243 }
1244 if (outFd == -1) {
1245 printf("Failed to open '%s', err=%d", g_outputFile, errno);
1246 } else {
1247 dprintf(outFd, "TRACE:\n");
1248 dumpTrace(outFd);
1249 if (g_outputFile) {
1250 close(outFd);
1251 }
1252 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001253 } else {
1254 printf("\ntrace aborted.\n");
1255 fflush(stdout);
1256 }
1257 clearTrace();
1258 } else if (!ok) {
1259 fprintf(stderr, "unable to start tracing\n");
1260 }
1261
1262 // Reset the trace buffer size to 1.
1263 if (traceStop)
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001264 cleanUpTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001265
1266 return g_traceAborted ? 1 : 0;
1267}