blob: 14eff03705ecd1bcdcdf0813faaaf5fcb03fc7c2 [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>
Corey Tabaka213feb32017-01-13 23:46:55 -080021#include <ftw.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080022#include <getopt.h>
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -070023#include <inttypes.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080024#include <signal.h>
25#include <stdarg.h>
26#include <stdbool.h>
27#include <stdio.h>
28#include <stdlib.h>
Elliott Hughes3da5d232015-01-25 08:35:20 -080029#include <string.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080030#include <sys/sendfile.h>
31#include <time.h>
Martijn Coenend9535872015-11-26 10:00:55 +010032#include <unistd.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080033#include <zlib.h>
34
Elliott Hughesa252f4d2016-07-21 17:12:15 -070035#include <memory>
36
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080037#include <binder/IBinder.h>
38#include <binder/IServiceManager.h>
39#include <binder/Parcel.h>
40
Martijn Coenenee9b97e2016-11-16 16:00:26 +010041#include <android/hidl/manager/1.0/IServiceManager.h>
42#include <hidl/ServiceManagement.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080043#include <cutils/properties.h>
44
Corey Tabaka213feb32017-01-13 23:46:55 -080045#include <pdx/default_transport/service_utility.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080046#include <utils/String8.h>
John Reck469a1942015-03-26 15:31:35 -070047#include <utils/Timers.h>
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +090048#include <utils/Tokenizer.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080049#include <utils/Trace.h>
Stephane Gasparinid8419c22016-03-02 13:45:15 +010050#include <android-base/file.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080051
52using namespace android;
Corey Tabaka213feb32017-01-13 23:46:55 -080053using pdx::default_transport::ServiceUtility;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080054
Martijn Coenenee9b97e2016-11-16 16:00:26 +010055using std::string;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080056#define NELEM(x) ((int) (sizeof(x) / sizeof((x)[0])))
57
sergeyv4144eff2016-04-28 11:40:04 -070058#define MAX_SYS_FILES 10
59#define MAX_PACKAGES 16
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080060
61const char* k_traceTagsProperty = "debug.atrace.tags.enableflags";
sergeyv4144eff2016-04-28 11:40:04 -070062
63const char* k_traceAppsNumberProperty = "debug.atrace.app_number";
64const char* k_traceAppsPropertyTemplate = "debug.atrace.app_%d";
sergeyvdb404152016-05-02 19:26:07 -070065const char* k_coreServiceCategory = "core_services";
66const char* k_coreServicesProp = "ro.atrace.core.services";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080067
68typedef enum { OPT, REQ } requiredness ;
69
70struct TracingCategory {
71 // The name identifying the category.
72 const char* name;
73
74 // A longer description of the category.
75 const char* longname;
76
77 // The userland tracing tags that the category enables.
78 uint64_t tags;
79
80 // The fname==NULL terminated list of /sys/ files that the category
81 // enables.
82 struct {
83 // Whether the file must be writable in order to enable the tracing
84 // category.
85 requiredness required;
86
87 // The path to the enable file.
88 const char* path;
89 } sysfiles[MAX_SYS_FILES];
90};
91
92/* Tracing categories */
93static const TracingCategory k_categories[] = {
Jamie Gennisb2a89e32013-03-11 19:37:53 -070094 { "gfx", "Graphics", ATRACE_TAG_GRAPHICS, { } },
95 { "input", "Input", ATRACE_TAG_INPUT, { } },
96 { "view", "View System", ATRACE_TAG_VIEW, { } },
97 { "webview", "WebView", ATRACE_TAG_WEBVIEW, { } },
98 { "wm", "Window Manager", ATRACE_TAG_WINDOW_MANAGER, { } },
99 { "am", "Activity Manager", ATRACE_TAG_ACTIVITY_MANAGER, { } },
Patrick Auchter70ec2942014-09-30 15:38:30 -0500100 { "sm", "Sync Manager", ATRACE_TAG_SYNC_MANAGER, { } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700101 { "audio", "Audio", ATRACE_TAG_AUDIO, { } },
102 { "video", "Video", ATRACE_TAG_VIDEO, { } },
103 { "camera", "Camera", ATRACE_TAG_CAMERA, { } },
104 { "hal", "Hardware Modules", ATRACE_TAG_HAL, { } },
Jeff Brown3200b0b2014-08-14 19:24:47 -0700105 { "app", "Application", ATRACE_TAG_APP, { } },
Dianne Hackborn9380d782013-04-12 14:52:35 -0700106 { "res", "Resource Loading", ATRACE_TAG_RESOURCES, { } },
Jamie Genniseff2e8d2013-05-07 15:20:39 -0700107 { "dalvik", "Dalvik VM", ATRACE_TAG_DALVIK, { } },
Tim Murrayf0f28412013-05-23 14:39:42 -0700108 { "rs", "RenderScript", ATRACE_TAG_RS, { } },
Brigid Smith750aa972014-05-28 14:23:24 -0700109 { "bionic", "Bionic C Library", ATRACE_TAG_BIONIC, { } },
Jeff Brown3200b0b2014-08-14 19:24:47 -0700110 { "power", "Power Management", ATRACE_TAG_POWER, { } },
Todd Kennedy01e111b2015-07-31 14:36:20 -0700111 { "pm", "Package Manager", ATRACE_TAG_PACKAGE_MANAGER, { } },
Yasuhiro Matsuda7cc49772015-07-01 01:46:25 +0900112 { "ss", "System Server", ATRACE_TAG_SYSTEM_SERVER, { } },
Greg Hackmannbbd7d992014-12-01 14:43:34 -0800113 { "database", "Database", ATRACE_TAG_DATABASE, { } },
Felipe Leme0f97c1d2016-09-07 11:33:26 -0700114 { "network", "Network", ATRACE_TAG_NETWORK, { } },
Josh Gao468b4cb2016-11-29 10:55:21 -0800115 { "adb", "ADB", ATRACE_TAG_ADB, { } },
sergeyvdb404152016-05-02 19:26:07 -0700116 { k_coreServiceCategory, "Core services", 0, { } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700117 { "sched", "CPU Scheduling", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800118 { REQ, "events/sched/sched_switch/enable" },
119 { REQ, "events/sched/sched_wakeup/enable" },
120 { OPT, "events/sched/sched_blocked_reason/enable" },
121 { OPT, "events/sched/sched_cpu_hotplug/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800122 } },
Dan Willemsenf440d392014-04-11 15:44:09 -0700123 { "irq", "IRQ Events", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800124 { REQ, "events/irq/enable" },
125 { OPT, "events/ipi/enable" },
Dan Willemsenf440d392014-04-11 15:44:09 -0700126 } },
Michael Wright43fb6782016-08-18 19:56:43 +0100127 { "i2c", "I2C Events", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800128 { REQ, "events/i2c/enable" },
129 { REQ, "events/i2c/i2c_read/enable" },
130 { REQ, "events/i2c/i2c_write/enable" },
131 { REQ, "events/i2c/i2c_result/enable" },
132 { REQ, "events/i2c/i2c_reply/enable" },
133 { OPT, "events/i2c/smbus_read/enable" },
134 { OPT, "events/i2c/smbus_write/enable" },
135 { OPT, "events/i2c/smbus_result/enable" },
136 { OPT, "events/i2c/smbus_reply/enable" },
Michael Wright43fb6782016-08-18 19:56:43 +0100137 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700138 { "freq", "CPU Frequency", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800139 { REQ, "events/power/cpu_frequency/enable" },
140 { OPT, "events/power/clock_set_rate/enable" },
141 { OPT, "events/power/cpu_frequency_limits/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800142 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700143 { "membus", "Memory Bus Utilization", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800144 { REQ, "events/memory_bus/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800145 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700146 { "idle", "CPU Idle", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800147 { REQ, "events/power/cpu_idle/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800148 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700149 { "disk", "Disk I/O", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800150 { OPT, "events/f2fs/f2fs_sync_file_enter/enable" },
151 { OPT, "events/f2fs/f2fs_sync_file_exit/enable" },
152 { OPT, "events/f2fs/f2fs_write_begin/enable" },
153 { OPT, "events/f2fs/f2fs_write_end/enable" },
154 { OPT, "events/ext4/ext4_da_write_begin/enable" },
155 { OPT, "events/ext4/ext4_da_write_end/enable" },
156 { OPT, "events/ext4/ext4_sync_file_enter/enable" },
157 { OPT, "events/ext4/ext4_sync_file_exit/enable" },
158 { REQ, "events/block/block_rq_issue/enable" },
159 { REQ, "events/block/block_rq_complete/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800160 } },
Ken Sumralld3fa5612013-07-03 12:32:03 -0700161 { "mmc", "eMMC commands", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800162 { REQ, "events/mmc/enable" },
Ken Sumralld3fa5612013-07-03 12:32:03 -0700163 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700164 { "load", "CPU Load", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800165 { REQ, "events/cpufreq_interactive/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800166 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700167 { "sync", "Synchronization", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800168 { REQ, "events/sync/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800169 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700170 { "workq", "Kernel Workqueues", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800171 { REQ, "events/workqueue/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800172 } },
Colin Cross580407f2014-08-18 15:22:13 -0700173 { "memreclaim", "Kernel Memory Reclaim", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800174 { REQ, "events/vmscan/mm_vmscan_direct_reclaim_begin/enable" },
175 { REQ, "events/vmscan/mm_vmscan_direct_reclaim_end/enable" },
176 { REQ, "events/vmscan/mm_vmscan_kswapd_wake/enable" },
177 { REQ, "events/vmscan/mm_vmscan_kswapd_sleep/enable" },
Colin Cross580407f2014-08-18 15:22:13 -0700178 } },
Aaron Schulmanc2c6ecd2015-02-25 08:37:09 -0800179 { "regulators", "Voltage and Current Regulators", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800180 { REQ, "events/regulator/enable" },
Aaron Schulmanc2c6ecd2015-02-25 08:37:09 -0800181 } },
Scott Bauerae473362015-06-08 16:32:36 -0700182 { "binder_driver", "Binder Kernel driver", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800183 { REQ, "events/binder/binder_transaction/enable" },
184 { REQ, "events/binder/binder_transaction_received/enable" },
Scott Bauerae473362015-06-08 16:32:36 -0700185 } },
186 { "binder_lock", "Binder global lock trace", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800187 { REQ, "events/binder/binder_lock/enable" },
188 { REQ, "events/binder/binder_locked/enable" },
189 { REQ, "events/binder/binder_unlock/enable" },
Scott Bauerae473362015-06-08 16:32:36 -0700190 } },
Martijn Coenen70481612015-10-23 13:57:05 +0200191 { "pagecache", "Page cache", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800192 { REQ, "events/filemap/enable" },
Martijn Coenen70481612015-10-23 13:57:05 +0200193 } },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800194};
195
196/* Command line options */
197static int g_traceDurationSeconds = 5;
198static bool g_traceOverwrite = false;
199static int g_traceBufferSizeKB = 2048;
200static bool g_compress = false;
201static bool g_nohup = false;
202static int g_initialSleepSecs = 0;
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900203static const char* g_categoriesFile = NULL;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700204static const char* g_kernelTraceFuncs = NULL;
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700205static const char* g_debugAppCmdLine = "";
John Reck40b26b42016-03-30 09:44:36 -0700206static const char* g_outputFile = nullptr;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800207
208/* Global state */
209static bool g_traceAborted = false;
210static bool g_categoryEnables[NELEM(k_categories)] = {};
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800211static std::string g_traceFolder;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800212
213/* Sys file paths */
214static const char* k_traceClockPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800215 "trace_clock";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800216
217static const char* k_traceBufferSizePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800218 "buffer_size_kb";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800219
220static const char* k_tracingOverwriteEnablePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800221 "options/overwrite";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800222
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700223static const char* k_currentTracerPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800224 "current_tracer";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700225
226static const char* k_printTgidPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800227 "options/print-tgid";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700228
229static const char* k_funcgraphAbsTimePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800230 "options/funcgraph-abstime";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700231
232static const char* k_funcgraphCpuPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800233 "options/funcgraph-cpu";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700234
235static const char* k_funcgraphProcPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800236 "options/funcgraph-proc";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700237
238static const char* k_funcgraphFlatPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800239 "options/funcgraph-flat";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700240
241static const char* k_funcgraphDurationPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800242 "options/funcgraph-duration";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700243
244static const char* k_ftraceFilterPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800245 "set_ftrace_filter";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700246
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800247static const char* k_tracingOnPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800248 "tracing_on";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800249
250static const char* k_tracePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800251 "trace";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800252
Martijn Coenend9535872015-11-26 10:00:55 +0100253static const char* k_traceStreamPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800254 "trace_pipe";
Martijn Coenend9535872015-11-26 10:00:55 +0100255
John Reck469a1942015-03-26 15:31:35 -0700256static const char* k_traceMarkerPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800257 "trace_marker";
John Reck469a1942015-03-26 15:31:35 -0700258
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800259// Check whether a file exists.
260static bool fileExists(const char* filename) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800261 return access((g_traceFolder + filename).c_str(), F_OK) != -1;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800262}
263
264// Check whether a file is writable.
265static bool fileIsWritable(const char* filename) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800266 return access((g_traceFolder + filename).c_str(), W_OK) != -1;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800267}
268
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700269// Truncate a file.
270static bool truncateFile(const char* path)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800271{
Jamie Gennis43122e72013-03-21 14:06:31 -0700272 // This uses creat rather than truncate because some of the debug kernel
273 // device nodes (e.g. k_ftraceFilterPath) currently aren't changed by
274 // calls to truncate, but they are cleared by calls to creat.
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800275 int traceFD = creat((g_traceFolder + path).c_str(), 0);
Jamie Gennis43122e72013-03-21 14:06:31 -0700276 if (traceFD == -1) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800277 fprintf(stderr, "error truncating %s: %s (%d)\n", (g_traceFolder + path).c_str(),
Jamie Gennis43122e72013-03-21 14:06:31 -0700278 strerror(errno), errno);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700279 return false;
280 }
281
Jamie Gennis43122e72013-03-21 14:06:31 -0700282 close(traceFD);
283
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700284 return true;
285}
286
287static bool _writeStr(const char* filename, const char* str, int flags)
288{
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800289 std::string fullFilename = g_traceFolder + filename;
290 int fd = open(fullFilename.c_str(), flags);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800291 if (fd == -1) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800292 fprintf(stderr, "error opening %s: %s (%d)\n", fullFilename.c_str(),
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800293 strerror(errno), errno);
294 return false;
295 }
296
297 bool ok = true;
298 ssize_t len = strlen(str);
299 if (write(fd, str, len) != len) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800300 fprintf(stderr, "error writing to %s: %s (%d)\n", fullFilename.c_str(),
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800301 strerror(errno), errno);
302 ok = false;
303 }
304
305 close(fd);
306
307 return ok;
308}
309
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700310// Write a string to a file, returning true if the write was successful.
311static bool writeStr(const char* filename, const char* str)
312{
313 return _writeStr(filename, str, O_WRONLY);
314}
315
316// Append a string to a file, returning true if the write was successful.
317static bool appendStr(const char* filename, const char* str)
318{
319 return _writeStr(filename, str, O_APPEND|O_WRONLY);
320}
321
John Reck469a1942015-03-26 15:31:35 -0700322static void writeClockSyncMarker()
323{
324 char buffer[128];
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200325 int len = 0;
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800326 int fd = open((g_traceFolder + k_traceMarkerPath).c_str(), O_WRONLY);
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200327 if (fd == -1) {
328 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceMarkerPath,
329 strerror(errno), errno);
330 return;
331 }
John Reck469a1942015-03-26 15:31:35 -0700332 float now_in_seconds = systemTime(CLOCK_MONOTONIC) / 1000000000.0f;
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200333
334 len = snprintf(buffer, 128, "trace_event_clock_sync: parent_ts=%f\n", now_in_seconds);
335 if (write(fd, buffer, len) != len) {
336 fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
337 }
338
339 int64_t realtime_in_ms = systemTime(CLOCK_REALTIME) / 1000000;
340 len = snprintf(buffer, 128, "trace_event_clock_sync: realtime_ts=%" PRId64 "\n", realtime_in_ms);
341 if (write(fd, buffer, len) != len) {
342 fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
343 }
344
345 close(fd);
John Reck469a1942015-03-26 15:31:35 -0700346}
347
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800348// Enable or disable a kernel option by writing a "1" or a "0" into a /sys
349// file.
350static bool setKernelOptionEnable(const char* filename, bool enable)
351{
352 return writeStr(filename, enable ? "1" : "0");
353}
354
355// Check whether the category is supported on the device with the current
356// rootness. A category is supported only if all its required /sys/ files are
357// writable and if enabling the category will enable one or more tracing tags
358// or /sys/ files.
359static bool isCategorySupported(const TracingCategory& category)
360{
sergeyvdb404152016-05-02 19:26:07 -0700361 if (strcmp(category.name, k_coreServiceCategory) == 0) {
362 char value[PROPERTY_VALUE_MAX];
363 property_get(k_coreServicesProp, value, "");
364 return strlen(value) != 0;
365 }
366
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800367 bool ok = category.tags != 0;
368 for (int i = 0; i < MAX_SYS_FILES; i++) {
369 const char* path = category.sysfiles[i].path;
370 bool req = category.sysfiles[i].required == REQ;
371 if (path != NULL) {
372 if (req) {
373 if (!fileIsWritable(path)) {
374 return false;
375 } else {
376 ok = true;
377 }
378 } else {
379 ok |= fileIsWritable(path);
380 }
381 }
382 }
383 return ok;
384}
385
386// Check whether the category would be supported on the device if the user
387// were root. This function assumes that root is able to write to any file
388// that exists. It performs the same logic as isCategorySupported, but it
Fabien Sanglardb5c95472016-06-08 11:40:12 -0700389// uses file existence rather than writability in the /sys/ file checks.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800390static bool isCategorySupportedForRoot(const TracingCategory& category)
391{
392 bool ok = category.tags != 0;
393 for (int i = 0; i < MAX_SYS_FILES; i++) {
394 const char* path = category.sysfiles[i].path;
395 bool req = category.sysfiles[i].required == REQ;
396 if (path != NULL) {
397 if (req) {
398 if (!fileExists(path)) {
399 return false;
400 } else {
401 ok = true;
402 }
403 } else {
404 ok |= fileExists(path);
405 }
406 }
407 }
408 return ok;
409}
410
411// Enable or disable overwriting of the kernel trace buffers. Disabling this
412// will cause tracing to stop once the trace buffers have filled up.
413static bool setTraceOverwriteEnable(bool enable)
414{
415 return setKernelOptionEnable(k_tracingOverwriteEnablePath, enable);
416}
417
418// Enable or disable kernel tracing.
419static bool setTracingEnabled(bool enable)
420{
421 return setKernelOptionEnable(k_tracingOnPath, enable);
422}
423
424// Clear the contents of the kernel trace.
425static bool clearTrace()
426{
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700427 return truncateFile(k_tracePath);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800428}
429
430// Set the size of the kernel's trace buffer in kilobytes.
431static bool setTraceBufferSizeKB(int size)
432{
433 char str[32] = "1";
434 int len;
435 if (size < 1) {
436 size = 1;
437 }
438 snprintf(str, 32, "%d", size);
439 return writeStr(k_traceBufferSizePath, str);
440}
441
Colin Crossb1ce49b2014-08-20 14:28:47 -0700442// Read the trace_clock sysfs file and return true if it matches the requested
443// value. The trace_clock file format is:
444// local [global] counter uptime perf
445static bool isTraceClock(const char *mode)
446{
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800447 int fd = open((g_traceFolder + k_traceClockPath).c_str(), O_RDONLY);
Colin Crossb1ce49b2014-08-20 14:28:47 -0700448 if (fd == -1) {
449 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceClockPath,
450 strerror(errno), errno);
451 return false;
452 }
453
454 char buf[4097];
455 ssize_t n = read(fd, buf, 4096);
456 close(fd);
457 if (n == -1) {
458 fprintf(stderr, "error reading %s: %s (%d)\n", k_traceClockPath,
459 strerror(errno), errno);
460 return false;
461 }
462 buf[n] = '\0';
463
464 char *start = strchr(buf, '[');
465 if (start == NULL) {
466 return false;
467 }
468 start++;
469
470 char *end = strchr(start, ']');
471 if (end == NULL) {
472 return false;
473 }
474 *end = '\0';
475
476 return strcmp(mode, start) == 0;
477}
478
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800479// Enable or disable the kernel's use of the global clock. Disabling the global
480// clock will result in the kernel using a per-CPU local clock.
Colin Crossb1ce49b2014-08-20 14:28:47 -0700481// Any write to the trace_clock sysfs file will reset the buffer, so only
482// update it if the requested value is not the current value.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800483static bool setGlobalClockEnable(bool enable)
484{
Colin Crossb1ce49b2014-08-20 14:28:47 -0700485 const char *clock = enable ? "global" : "local";
486
487 if (isTraceClock(clock)) {
488 return true;
489 }
490
491 return writeStr(k_traceClockPath, clock);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800492}
493
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700494static bool setPrintTgidEnableIfPresent(bool enable)
495{
496 if (fileExists(k_printTgidPath)) {
497 return setKernelOptionEnable(k_printTgidPath, enable);
498 }
499 return true;
500}
501
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800502// Poke all the binder-enabled processes in the system to get them to re-read
503// their system properties.
504static bool pokeBinderServices()
505{
506 sp<IServiceManager> sm = defaultServiceManager();
507 Vector<String16> services = sm->listServices();
508 for (size_t i = 0; i < services.size(); i++) {
509 sp<IBinder> obj = sm->checkService(services[i]);
510 if (obj != NULL) {
511 Parcel data;
512 if (obj->transact(IBinder::SYSPROPS_TRANSACTION, data,
513 NULL, 0) != OK) {
514 if (false) {
515 // XXX: For some reason this fails on tablets trying to
516 // poke the "phone" service. It's not clear whether some
517 // are expected to fail.
518 String8 svc(services[i]);
519 fprintf(stderr, "error poking binder service %s\n",
520 svc.string());
521 return false;
522 }
523 }
524 }
525 }
526 return true;
527}
528
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100529// Poke all the HAL processes in the system to get them to re-read
530// their system properties.
531static void pokeHalServices()
532{
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100533 using ::android::hidl::base::V1_0::IBase;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100534 using ::android::hidl::manager::V1_0::IServiceManager;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100535 using ::android::hardware::hidl_string;
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100536 using ::android::hardware::Return;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100537
538 sp<IServiceManager> sm = ::android::hardware::defaultServiceManager();
Steven Morelanda42866b2016-12-12 15:18:06 -0800539
540 if (sm == nullptr) {
541 fprintf(stderr, "failed to get IServiceManager to poke hal services\n");
542 return;
543 }
544
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800545 auto listRet = sm->list([&](const auto &interfaces) {
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100546 for (size_t i = 0; i < interfaces.size(); i++) {
547 string fqInstanceName = interfaces[i];
548 string::size_type n = fqInstanceName.find("/");
549 if (n == std::string::npos || interfaces[i].size() == n+1)
550 continue;
551 hidl_string fqInterfaceName = fqInstanceName.substr(0, n);
552 hidl_string instanceName = fqInstanceName.substr(n+1, std::string::npos);
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100553 Return<sp<IBase>> interfaceRet = sm->get(fqInterfaceName, instanceName);
554 if (!interfaceRet.isOk()) {
Martijn Coenen1e4a7fb2017-02-17 14:57:38 +0100555 // ignore
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100556 continue;
557 }
558 sp<IBase> interface = interfaceRet;
559 auto notifyRet = interface->notifySyspropsChanged();
560 if (!notifyRet.isOk()) {
Martijn Coenen1e4a7fb2017-02-17 14:57:38 +0100561 // ignore
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800562 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100563 }
564 });
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800565 if (!listRet.isOk()) {
Martijn Coenen64d54eb2017-01-12 17:16:31 +0100566 // TODO(b/34242478) fix this when we determine the correct ACL
567 //fprintf(stderr, "failed to list services: %s\n", listRet.description().c_str());
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800568 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100569}
570
Corey Tabaka213feb32017-01-13 23:46:55 -0800571// Sends the sysprop_change message to the service at fpath, so it re-reads its
572// system properties. Returns 0 on success or a negated errno code on failure.
573static int pokeOnePDXService(const char *fpath, const struct stat * /*sb*/,
574 int typeflag, struct FTW * /*ftwbuf*/)
575{
576 const bool kIgnoreErrors = true;
577
578 if (typeflag == FTW_F) {
579 int error;
580 auto utility = ServiceUtility::Create(fpath, &error);
581 if (!utility) {
582 if (error != -ECONNREFUSED) {
583 ALOGE("pokeOnePDXService: Failed to open %s, %s.", fpath,
584 strerror(-error));
585 }
586 return kIgnoreErrors ? 0 : error;
587 }
588
589 auto status = utility->ReloadSystemProperties();
590 if (!status) {
591 ALOGE("pokeOnePDXService: Failed to send sysprop change to %s, "
592 "error %d, %s.", fpath, status.error(),
593 status.GetErrorMessage().c_str());
594 return kIgnoreErrors ? 0 : -status.error();
595 }
596 }
597
598 return 0;
599}
600
601// Pokes all the PDX processes in the system to get them to re-read
602// their system properties. Returns true on success, false on failure.
603static bool pokePDXServices()
604{
605 const int kMaxDepth = 16;
606 const int result = nftw(ServiceUtility::GetRootEndpointPath().c_str(),
607 pokeOnePDXService, kMaxDepth, FTW_PHYS);
608 return result == 0 ? true : false;
609}
610
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800611// Set the trace tags that userland tracing uses, and poke the running
612// processes to pick up the new value.
613static bool setTagsProperty(uint64_t tags)
614{
sergeyv4144eff2016-04-28 11:40:04 -0700615 char buf[PROPERTY_VALUE_MAX];
616 snprintf(buf, sizeof(buf), "%#" PRIx64, tags);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800617 if (property_set(k_traceTagsProperty, buf) < 0) {
618 fprintf(stderr, "error setting trace tags system property\n");
619 return false;
620 }
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700621 return true;
622}
623
sergeyv4144eff2016-04-28 11:40:04 -0700624static void clearAppProperties()
625{
626 char buf[PROPERTY_KEY_MAX];
627 for (int i = 0; i < MAX_PACKAGES; i++) {
628 snprintf(buf, sizeof(buf), k_traceAppsPropertyTemplate, i);
629 if (property_set(buf, "") < 0) {
630 fprintf(stderr, "failed to clear system property: %s\n", buf);
631 }
632 }
633 if (property_set(k_traceAppsNumberProperty, "") < 0) {
634 fprintf(stderr, "failed to clear system property: %s",
635 k_traceAppsNumberProperty);
636 }
637}
638
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700639// Set the system property that indicates which apps should perform
640// application-level tracing.
Dan Austin09a79872016-05-31 13:27:03 -0700641static bool setAppCmdlineProperty(char* cmdline)
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700642{
sergeyv4144eff2016-04-28 11:40:04 -0700643 char buf[PROPERTY_KEY_MAX];
644 int i = 0;
Dan Austin09a79872016-05-31 13:27:03 -0700645 char* start = cmdline;
sergeyv4144eff2016-04-28 11:40:04 -0700646 while (start != NULL) {
647 if (i == MAX_PACKAGES) {
648 fprintf(stderr, "error: only 16 packages could be traced at once\n");
649 clearAppProperties();
650 return false;
651 }
652 char* end = strchr(start, ',');
653 if (end != NULL) {
654 *end = '\0';
655 end++;
656 }
657 snprintf(buf, sizeof(buf), k_traceAppsPropertyTemplate, i);
658 if (property_set(buf, start) < 0) {
659 fprintf(stderr, "error setting trace app %d property to %s\n", i, buf);
660 clearAppProperties();
661 return false;
662 }
663 start = end;
664 i++;
665 }
666
667 snprintf(buf, sizeof(buf), "%d", i);
668 if (property_set(k_traceAppsNumberProperty, buf) < 0) {
669 fprintf(stderr, "error setting trace app number property to %s\n", buf);
670 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700671 return false;
672 }
673 return true;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800674}
675
676// Disable all /sys/ enable files.
677static bool disableKernelTraceEvents() {
678 bool ok = true;
679 for (int i = 0; i < NELEM(k_categories); i++) {
680 const TracingCategory &c = k_categories[i];
681 for (int j = 0; j < MAX_SYS_FILES; j++) {
682 const char* path = c.sysfiles[j].path;
683 if (path != NULL && fileIsWritable(path)) {
684 ok &= setKernelOptionEnable(path, false);
685 }
686 }
687 }
688 return ok;
689}
690
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700691// Verify that the comma separated list of functions are being traced by the
692// kernel.
693static bool verifyKernelTraceFuncs(const char* funcs)
694{
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100695 std::string buf;
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800696 if (!android::base::ReadFileToString(g_traceFolder + k_ftraceFilterPath, &buf)) {
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100697 fprintf(stderr, "error opening %s: %s (%d)\n", k_ftraceFilterPath,
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700698 strerror(errno), errno);
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100699 return false;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700700 }
701
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100702 String8 funcList = String8::format("\n%s",buf.c_str());
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700703
704 // Make sure that every function listed in funcs is in the list we just
Thomas Buhota2c22872016-01-27 09:44:31 +0100705 // read from the kernel, except for wildcard inputs.
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700706 bool ok = true;
707 char* myFuncs = strdup(funcs);
708 char* func = strtok(myFuncs, ",");
709 while (func) {
Thomas Buhota2c22872016-01-27 09:44:31 +0100710 if (!strchr(func, '*')) {
711 String8 fancyFunc = String8::format("\n%s\n", func);
712 bool found = funcList.find(fancyFunc.string(), 0) >= 0;
713 if (!found || func[0] == '\0') {
714 fprintf(stderr, "error: \"%s\" is not a valid kernel function "
715 "to trace.\n", func);
716 ok = false;
717 }
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700718 }
719 func = strtok(NULL, ",");
720 }
721 free(myFuncs);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700722 return ok;
723}
724
725// Set the comma separated list of functions that the kernel is to trace.
726static bool setKernelTraceFuncs(const char* funcs)
727{
728 bool ok = true;
729
730 if (funcs == NULL || funcs[0] == '\0') {
731 // Disable kernel function tracing.
Jamie Gennis6f6f3f72013-03-27 15:50:30 -0700732 if (fileIsWritable(k_currentTracerPath)) {
733 ok &= writeStr(k_currentTracerPath, "nop");
734 }
735 if (fileIsWritable(k_ftraceFilterPath)) {
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700736 ok &= truncateFile(k_ftraceFilterPath);
737 }
738 } else {
739 // Enable kernel function tracing.
740 ok &= writeStr(k_currentTracerPath, "function_graph");
741 ok &= setKernelOptionEnable(k_funcgraphAbsTimePath, true);
742 ok &= setKernelOptionEnable(k_funcgraphCpuPath, true);
743 ok &= setKernelOptionEnable(k_funcgraphProcPath, true);
744 ok &= setKernelOptionEnable(k_funcgraphFlatPath, true);
745
746 // Set the requested filter functions.
747 ok &= truncateFile(k_ftraceFilterPath);
748 char* myFuncs = strdup(funcs);
749 char* func = strtok(myFuncs, ",");
750 while (func) {
751 ok &= appendStr(k_ftraceFilterPath, func);
752 func = strtok(NULL, ",");
753 }
754 free(myFuncs);
755
756 // Verify that the set functions are being traced.
757 if (ok) {
758 ok &= verifyKernelTraceFuncs(funcs);
759 }
760 }
761
762 return ok;
763}
764
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900765static bool setCategoryEnable(const char* name, bool enable)
766{
767 for (int i = 0; i < NELEM(k_categories); i++) {
768 const TracingCategory& c = k_categories[i];
769 if (strcmp(name, c.name) == 0) {
770 if (isCategorySupported(c)) {
771 g_categoryEnables[i] = enable;
772 return true;
773 } else {
774 if (isCategorySupportedForRoot(c)) {
775 fprintf(stderr, "error: category \"%s\" requires root "
776 "privileges.\n", name);
777 } else {
778 fprintf(stderr, "error: category \"%s\" is not supported "
779 "on this device.\n", name);
780 }
781 return false;
782 }
783 }
784 }
785 fprintf(stderr, "error: unknown tracing category \"%s\"\n", name);
786 return false;
787}
788
789static bool setCategoriesEnableFromFile(const char* categories_file)
790{
791 if (!categories_file) {
792 return true;
793 }
794 Tokenizer* tokenizer = NULL;
795 if (Tokenizer::open(String8(categories_file), &tokenizer) != NO_ERROR) {
796 return false;
797 }
798 bool ok = true;
799 while (!tokenizer->isEol()) {
800 String8 token = tokenizer->nextToken(" ");
801 if (token.isEmpty()) {
802 tokenizer->skipDelimiters(" ");
803 continue;
804 }
805 ok &= setCategoryEnable(token.string(), true);
806 }
807 delete tokenizer;
808 return ok;
809}
810
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700811// Set all the kernel tracing settings to the desired state for this trace
812// capture.
813static bool setUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800814{
815 bool ok = true;
816
817 // Set up the tracing options.
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900818 ok &= setCategoriesEnableFromFile(g_categoriesFile);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800819 ok &= setTraceOverwriteEnable(g_traceOverwrite);
820 ok &= setTraceBufferSizeKB(g_traceBufferSizeKB);
821 ok &= setGlobalClockEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700822 ok &= setPrintTgidEnableIfPresent(true);
823 ok &= setKernelTraceFuncs(g_kernelTraceFuncs);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800824
825 // Set up the tags property.
826 uint64_t tags = 0;
827 for (int i = 0; i < NELEM(k_categories); i++) {
828 if (g_categoryEnables[i]) {
829 const TracingCategory &c = k_categories[i];
830 tags |= c.tags;
831 }
832 }
833 ok &= setTagsProperty(tags);
sergeyvdb404152016-05-02 19:26:07 -0700834
835 bool coreServicesTagEnabled = false;
836 for (int i = 0; i < NELEM(k_categories); i++) {
837 if (strcmp(k_categories[i].name, k_coreServiceCategory) == 0) {
838 coreServicesTagEnabled = g_categoryEnables[i];
839 }
840 }
841
842 std::string packageList(g_debugAppCmdLine);
843 if (coreServicesTagEnabled) {
844 char value[PROPERTY_VALUE_MAX];
845 property_get(k_coreServicesProp, value, "");
846 if (!packageList.empty()) {
847 packageList += ",";
848 }
849 packageList += value;
850 }
Dan Austin09a79872016-05-31 13:27:03 -0700851 ok &= setAppCmdlineProperty(&packageList[0]);
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700852 ok &= pokeBinderServices();
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100853 pokeHalServices();
Corey Tabaka213feb32017-01-13 23:46:55 -0800854 ok &= pokePDXServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800855
856 // Disable all the sysfs enables. This is done as a separate loop from
857 // the enables to allow the same enable to exist in multiple categories.
858 ok &= disableKernelTraceEvents();
859
860 // Enable all the sysfs enables that are in an enabled category.
861 for (int i = 0; i < NELEM(k_categories); i++) {
862 if (g_categoryEnables[i]) {
863 const TracingCategory &c = k_categories[i];
864 for (int j = 0; j < MAX_SYS_FILES; j++) {
865 const char* path = c.sysfiles[j].path;
866 bool required = c.sysfiles[j].required == REQ;
867 if (path != NULL) {
868 if (fileIsWritable(path)) {
869 ok &= setKernelOptionEnable(path, true);
870 } else if (required) {
871 fprintf(stderr, "error writing file %s\n", path);
872 ok = false;
873 }
874 }
875 }
876 }
877 }
878
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800879 return ok;
880}
881
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700882// Reset all the kernel tracing settings to their default state.
883static void cleanUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800884{
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800885 // Disable all tracing that we're able to.
886 disableKernelTraceEvents();
887
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700888 // Reset the system properties.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800889 setTagsProperty(0);
sergeyv4144eff2016-04-28 11:40:04 -0700890 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700891 pokeBinderServices();
Corey Tabaka213feb32017-01-13 23:46:55 -0800892 pokePDXServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800893
894 // Set the options back to their defaults.
895 setTraceOverwriteEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700896 setTraceBufferSizeKB(1);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800897 setGlobalClockEnable(false);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700898 setPrintTgidEnableIfPresent(false);
899 setKernelTraceFuncs(NULL);
900}
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800901
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700902
903// Enable tracing in the kernel.
904static bool startTrace()
905{
906 return setTracingEnabled(true);
907}
908
909// Disable tracing in the kernel.
910static void stopTrace()
911{
912 setTracingEnabled(false);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800913}
914
Martijn Coenend9535872015-11-26 10:00:55 +0100915// Read data from the tracing pipe and forward to stdout
916static void streamTrace()
917{
918 char trace_data[4096];
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800919 int traceFD = open((g_traceFolder + k_traceStreamPath).c_str(), O_RDWR);
Martijn Coenend9535872015-11-26 10:00:55 +0100920 if (traceFD == -1) {
921 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceStreamPath,
922 strerror(errno), errno);
923 return;
924 }
925 while (!g_traceAborted) {
926 ssize_t bytes_read = read(traceFD, trace_data, 4096);
927 if (bytes_read > 0) {
928 write(STDOUT_FILENO, trace_data, bytes_read);
929 fflush(stdout);
930 } else {
931 if (!g_traceAborted) {
932 fprintf(stderr, "read returned %zd bytes err %d (%s)\n",
933 bytes_read, errno, strerror(errno));
934 }
935 break;
936 }
937 }
938}
939
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800940// Read the current kernel trace and write it to stdout.
John Reck40b26b42016-03-30 09:44:36 -0700941static void dumpTrace(int outFd)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800942{
John Reck6c8ac922016-03-28 11:25:30 -0700943 ALOGI("Dumping trace");
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800944 int traceFD = open((g_traceFolder + k_tracePath).c_str(), O_RDWR);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800945 if (traceFD == -1) {
946 fprintf(stderr, "error opening %s: %s (%d)\n", k_tracePath,
947 strerror(errno), errno);
948 return;
949 }
950
951 if (g_compress) {
952 z_stream zs;
Elliott Hughes3da5d232015-01-25 08:35:20 -0800953 memset(&zs, 0, sizeof(zs));
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700954
955 int result = deflateInit(&zs, Z_DEFAULT_COMPRESSION);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800956 if (result != Z_OK) {
957 fprintf(stderr, "error initializing zlib: %d\n", result);
958 close(traceFD);
959 return;
960 }
961
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700962 constexpr size_t bufSize = 64*1024;
963 std::unique_ptr<uint8_t> in(new uint8_t[bufSize]);
964 std::unique_ptr<uint8_t> out(new uint8_t[bufSize]);
965 if (!in || !out) {
966 fprintf(stderr, "couldn't allocate buffers\n");
967 close(traceFD);
968 return;
969 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800970
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700971 int flush = Z_NO_FLUSH;
972
973 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800974 zs.avail_out = bufSize;
975
976 do {
977
978 if (zs.avail_in == 0) {
979 // More input is needed.
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700980 result = read(traceFD, in.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800981 if (result < 0) {
982 fprintf(stderr, "error reading trace: %s (%d)\n",
983 strerror(errno), errno);
984 result = Z_STREAM_END;
985 break;
986 } else if (result == 0) {
987 flush = Z_FINISH;
988 } else {
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700989 zs.next_in = reinterpret_cast<Bytef*>(in.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800990 zs.avail_in = result;
991 }
992 }
993
994 if (zs.avail_out == 0) {
995 // Need to write the output.
Elliott Hughesb59e2962016-07-22 09:00:59 -0700996 result = write(outFd, out.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800997 if ((size_t)result < bufSize) {
998 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
999 strerror(errno), errno);
1000 result = Z_STREAM_END; // skip deflate error message
1001 zs.avail_out = bufSize; // skip the final write
1002 break;
1003 }
Elliott Hughesa252f4d2016-07-21 17:12:15 -07001004 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001005 zs.avail_out = bufSize;
1006 }
1007
1008 } while ((result = deflate(&zs, flush)) == Z_OK);
1009
1010 if (result != Z_STREAM_END) {
1011 fprintf(stderr, "error deflating trace: %s\n", zs.msg);
1012 }
1013
1014 if (zs.avail_out < bufSize) {
1015 size_t bytes = bufSize - zs.avail_out;
Elliott Hughesb59e2962016-07-22 09:00:59 -07001016 result = write(outFd, out.get(), bytes);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001017 if ((size_t)result < bytes) {
1018 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
1019 strerror(errno), errno);
1020 }
1021 }
1022
1023 result = deflateEnd(&zs);
1024 if (result != Z_OK) {
1025 fprintf(stderr, "error cleaning up zlib: %d\n", result);
1026 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001027 } else {
1028 ssize_t sent = 0;
John Reck40b26b42016-03-30 09:44:36 -07001029 while ((sent = sendfile(outFd, traceFD, NULL, 64*1024*1024)) > 0);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001030 if (sent == -1) {
1031 fprintf(stderr, "error dumping trace: %s (%d)\n", strerror(errno),
1032 errno);
1033 }
1034 }
1035
1036 close(traceFD);
1037}
1038
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -07001039static void handleSignal(int /*signo*/)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001040{
1041 if (!g_nohup) {
1042 g_traceAborted = true;
1043 }
1044}
1045
1046static void registerSigHandler()
1047{
1048 struct sigaction sa;
1049 sigemptyset(&sa.sa_mask);
1050 sa.sa_flags = 0;
1051 sa.sa_handler = handleSignal;
1052 sigaction(SIGHUP, &sa, NULL);
1053 sigaction(SIGINT, &sa, NULL);
1054 sigaction(SIGQUIT, &sa, NULL);
1055 sigaction(SIGTERM, &sa, NULL);
1056}
1057
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001058static void listSupportedCategories()
1059{
1060 for (int i = 0; i < NELEM(k_categories); i++) {
1061 const TracingCategory& c = k_categories[i];
1062 if (isCategorySupported(c)) {
1063 printf(" %10s - %s\n", c.name, c.longname);
1064 }
1065 }
1066}
1067
1068// Print the command usage help to stderr.
1069static void showHelp(const char *cmd)
1070{
1071 fprintf(stderr, "usage: %s [options] [categories...]\n", cmd);
1072 fprintf(stderr, "options include:\n"
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001073 " -a appname enable app-level tracing for a comma "
1074 "separated list of cmdlines\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001075 " -b N use a trace buffer size of N KB\n"
1076 " -c trace into a circular buffer\n"
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001077 " -f filename use the categories written in a file as space-separated\n"
1078 " values in a line\n"
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001079 " -k fname,... trace the listed kernel functions\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001080 " -n ignore signals\n"
1081 " -s N sleep for N seconds before tracing [default 0]\n"
Fabien Sanglardb5c95472016-06-08 11:40:12 -07001082 " -t N trace for N seconds [default 5]\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001083 " -z compress the trace dump\n"
Fabien Sanglardb5c95472016-06-08 11:40:12 -07001084 " --async_start start circular trace and return immediately\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001085 " --async_dump dump the current contents of circular trace buffer\n"
1086 " --async_stop stop tracing and dump the current contents of circular\n"
1087 " trace buffer\n"
Martijn Coenend9535872015-11-26 10:00:55 +01001088 " --stream stream trace to stdout as it enters the trace buffer\n"
1089 " Note: this can take significant CPU time, and is best\n"
1090 " used for measuring things that are not affected by\n"
1091 " CPU performance, like pagecache usage.\n"
Jamie Gennis92573f12012-12-07 16:29:03 -08001092 " --list_categories\n"
1093 " list the available tracing categories\n"
John Reck40b26b42016-03-30 09:44:36 -07001094 " -o filename write the trace to the specified file instead\n"
1095 " of stdout.\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001096 );
1097}
1098
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001099bool findTraceFiles()
1100{
1101 static const std::string debugfs_path = "/sys/kernel/debug/tracing/";
1102 static const std::string tracefs_path = "/sys/kernel/tracing/";
1103 static const std::string trace_file = "trace_marker";
1104
1105 bool tracefs = access((tracefs_path + trace_file).c_str(), F_OK) != -1;
1106 bool debugfs = access((debugfs_path + trace_file).c_str(), F_OK) != -1;
1107
1108 if (!tracefs && !debugfs) {
1109 fprintf(stderr, "Error: Did not find trace folder\n");
1110 return false;
1111 }
1112
1113 if (tracefs) {
1114 g_traceFolder = tracefs_path;
1115 } else {
1116 g_traceFolder = debugfs_path;
1117 }
1118
1119 return true;
1120}
1121
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001122int main(int argc, char **argv)
1123{
1124 bool async = false;
1125 bool traceStart = true;
1126 bool traceStop = true;
1127 bool traceDump = true;
Martijn Coenend9535872015-11-26 10:00:55 +01001128 bool traceStream = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001129
1130 if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
1131 showHelp(argv[0]);
1132 exit(0);
1133 }
1134
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001135 if (!findTraceFiles()) {
1136 fprintf(stderr, "No trace folder found\n");
1137 exit(-1);
1138 }
1139
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001140 for (;;) {
1141 int ret;
1142 int option_index = 0;
1143 static struct option long_options[] = {
1144 {"async_start", no_argument, 0, 0 },
1145 {"async_stop", no_argument, 0, 0 },
1146 {"async_dump", no_argument, 0, 0 },
1147 {"list_categories", no_argument, 0, 0 },
Martijn Coenend9535872015-11-26 10:00:55 +01001148 {"stream", no_argument, 0, 0 },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001149 { 0, 0, 0, 0 }
1150 };
1151
John Reck40b26b42016-03-30 09:44:36 -07001152 ret = getopt_long(argc, argv, "a:b:cf:k:ns:t:zo:",
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001153 long_options, &option_index);
1154
1155 if (ret < 0) {
1156 for (int i = optind; i < argc; i++) {
1157 if (!setCategoryEnable(argv[i], true)) {
1158 fprintf(stderr, "error enabling tracing category \"%s\"\n", argv[i]);
1159 exit(1);
1160 }
1161 }
1162 break;
1163 }
1164
1165 switch(ret) {
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001166 case 'a':
1167 g_debugAppCmdLine = optarg;
1168 break;
1169
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001170 case 'b':
1171 g_traceBufferSizeKB = atoi(optarg);
1172 break;
1173
1174 case 'c':
1175 g_traceOverwrite = true;
1176 break;
1177
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001178 case 'f':
1179 g_categoriesFile = optarg;
1180 break;
1181
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001182 case 'k':
1183 g_kernelTraceFuncs = optarg;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001184 break;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001185
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001186 case 'n':
1187 g_nohup = true;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001188 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001189
1190 case 's':
1191 g_initialSleepSecs = atoi(optarg);
1192 break;
1193
1194 case 't':
1195 g_traceDurationSeconds = atoi(optarg);
1196 break;
1197
1198 case 'z':
1199 g_compress = true;
1200 break;
1201
John Reck40b26b42016-03-30 09:44:36 -07001202 case 'o':
1203 g_outputFile = optarg;
1204 break;
1205
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001206 case 0:
1207 if (!strcmp(long_options[option_index].name, "async_start")) {
1208 async = true;
1209 traceStop = false;
1210 traceDump = false;
1211 g_traceOverwrite = true;
1212 } else if (!strcmp(long_options[option_index].name, "async_stop")) {
1213 async = true;
John Reck4ba2b632015-05-15 10:00:34 -07001214 traceStart = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001215 } else if (!strcmp(long_options[option_index].name, "async_dump")) {
1216 async = true;
1217 traceStart = false;
1218 traceStop = false;
Martijn Coenend9535872015-11-26 10:00:55 +01001219 } else if (!strcmp(long_options[option_index].name, "stream")) {
1220 traceStream = true;
1221 traceDump = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001222 } else if (!strcmp(long_options[option_index].name, "list_categories")) {
1223 listSupportedCategories();
1224 exit(0);
1225 }
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001226 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001227
1228 default:
1229 fprintf(stderr, "\n");
1230 showHelp(argv[0]);
1231 exit(-1);
1232 break;
1233 }
1234 }
1235
1236 registerSigHandler();
1237
1238 if (g_initialSleepSecs > 0) {
1239 sleep(g_initialSleepSecs);
1240 }
1241
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001242 bool ok = true;
1243 ok &= setUpTrace();
1244 ok &= startTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001245
1246 if (ok && traceStart) {
Martijn Coenend9535872015-11-26 10:00:55 +01001247 if (!traceStream) {
1248 printf("capturing trace...");
1249 fflush(stdout);
1250 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001251
1252 // We clear the trace after starting it because tracing gets enabled for
1253 // each CPU individually in the kernel. Having the beginning of the trace
1254 // contain entries from only one CPU can cause "begin" entries without a
1255 // matching "end" entry to show up if a task gets migrated from one CPU to
1256 // another.
1257 ok = clearTrace();
1258
Martijn Coenen0bcd97a2015-07-15 14:25:23 +02001259 writeClockSyncMarker();
Martijn Coenend9535872015-11-26 10:00:55 +01001260 if (ok && !async && !traceStream) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001261 // Sleep to allow the trace to be captured.
1262 struct timespec timeLeft;
1263 timeLeft.tv_sec = g_traceDurationSeconds;
1264 timeLeft.tv_nsec = 0;
1265 do {
1266 if (g_traceAborted) {
1267 break;
1268 }
1269 } while (nanosleep(&timeLeft, &timeLeft) == -1 && errno == EINTR);
1270 }
Martijn Coenend9535872015-11-26 10:00:55 +01001271
1272 if (traceStream) {
1273 streamTrace();
1274 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001275 }
1276
1277 // Stop the trace and restore the default settings.
1278 if (traceStop)
1279 stopTrace();
1280
1281 if (ok && traceDump) {
1282 if (!g_traceAborted) {
John Reck40b26b42016-03-30 09:44:36 -07001283 printf(" done\n");
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001284 fflush(stdout);
John Reck40b26b42016-03-30 09:44:36 -07001285 int outFd = STDOUT_FILENO;
1286 if (g_outputFile) {
Martijn Coenenc5791982017-02-22 09:25:31 +01001287 outFd = open(g_outputFile, O_WRONLY | O_CREAT | O_TRUNC, 0644);
John Reck40b26b42016-03-30 09:44:36 -07001288 }
1289 if (outFd == -1) {
1290 printf("Failed to open '%s', err=%d", g_outputFile, errno);
1291 } else {
1292 dprintf(outFd, "TRACE:\n");
1293 dumpTrace(outFd);
1294 if (g_outputFile) {
1295 close(outFd);
1296 }
1297 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001298 } else {
1299 printf("\ntrace aborted.\n");
1300 fflush(stdout);
1301 }
1302 clearTrace();
1303 } else if (!ok) {
1304 fprintf(stderr, "unable to start tracing\n");
1305 }
1306
1307 // Reset the trace buffer size to 1.
1308 if (traceStop)
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001309 cleanUpTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001310
1311 return g_traceAborted ? 1 : 0;
1312}