blob: ce0caede26d4293e79feedaeeaae41290cb1d34b [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()) {
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800555 fprintf(stderr, "failed to get service %s: %s\n",
556 fqInstanceName.c_str(),
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100557 interfaceRet.description().c_str());
558 continue;
559 }
560 sp<IBase> interface = interfaceRet;
561 auto notifyRet = interface->notifySyspropsChanged();
562 if (!notifyRet.isOk()) {
563 fprintf(stderr, "failed to notifySyspropsChanged on service %s: %s\n",
564 fqInstanceName.c_str(),
565 notifyRet.description().c_str());
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800566 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100567 }
568 });
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800569 if (!listRet.isOk()) {
Martijn Coenen64d54eb2017-01-12 17:16:31 +0100570 // TODO(b/34242478) fix this when we determine the correct ACL
571 //fprintf(stderr, "failed to list services: %s\n", listRet.description().c_str());
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800572 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100573}
574
Corey Tabaka213feb32017-01-13 23:46:55 -0800575// Sends the sysprop_change message to the service at fpath, so it re-reads its
576// system properties. Returns 0 on success or a negated errno code on failure.
577static int pokeOnePDXService(const char *fpath, const struct stat * /*sb*/,
578 int typeflag, struct FTW * /*ftwbuf*/)
579{
580 const bool kIgnoreErrors = true;
581
582 if (typeflag == FTW_F) {
583 int error;
584 auto utility = ServiceUtility::Create(fpath, &error);
585 if (!utility) {
586 if (error != -ECONNREFUSED) {
587 ALOGE("pokeOnePDXService: Failed to open %s, %s.", fpath,
588 strerror(-error));
589 }
590 return kIgnoreErrors ? 0 : error;
591 }
592
593 auto status = utility->ReloadSystemProperties();
594 if (!status) {
595 ALOGE("pokeOnePDXService: Failed to send sysprop change to %s, "
596 "error %d, %s.", fpath, status.error(),
597 status.GetErrorMessage().c_str());
598 return kIgnoreErrors ? 0 : -status.error();
599 }
600 }
601
602 return 0;
603}
604
605// Pokes all the PDX processes in the system to get them to re-read
606// their system properties. Returns true on success, false on failure.
607static bool pokePDXServices()
608{
609 const int kMaxDepth = 16;
610 const int result = nftw(ServiceUtility::GetRootEndpointPath().c_str(),
611 pokeOnePDXService, kMaxDepth, FTW_PHYS);
612 return result == 0 ? true : false;
613}
614
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800615// Set the trace tags that userland tracing uses, and poke the running
616// processes to pick up the new value.
617static bool setTagsProperty(uint64_t tags)
618{
sergeyv4144eff2016-04-28 11:40:04 -0700619 char buf[PROPERTY_VALUE_MAX];
620 snprintf(buf, sizeof(buf), "%#" PRIx64, tags);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800621 if (property_set(k_traceTagsProperty, buf) < 0) {
622 fprintf(stderr, "error setting trace tags system property\n");
623 return false;
624 }
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700625 return true;
626}
627
sergeyv4144eff2016-04-28 11:40:04 -0700628static void clearAppProperties()
629{
630 char buf[PROPERTY_KEY_MAX];
631 for (int i = 0; i < MAX_PACKAGES; i++) {
632 snprintf(buf, sizeof(buf), k_traceAppsPropertyTemplate, i);
633 if (property_set(buf, "") < 0) {
634 fprintf(stderr, "failed to clear system property: %s\n", buf);
635 }
636 }
637 if (property_set(k_traceAppsNumberProperty, "") < 0) {
638 fprintf(stderr, "failed to clear system property: %s",
639 k_traceAppsNumberProperty);
640 }
641}
642
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700643// Set the system property that indicates which apps should perform
644// application-level tracing.
Dan Austin09a79872016-05-31 13:27:03 -0700645static bool setAppCmdlineProperty(char* cmdline)
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700646{
sergeyv4144eff2016-04-28 11:40:04 -0700647 char buf[PROPERTY_KEY_MAX];
648 int i = 0;
Dan Austin09a79872016-05-31 13:27:03 -0700649 char* start = cmdline;
sergeyv4144eff2016-04-28 11:40:04 -0700650 while (start != NULL) {
651 if (i == MAX_PACKAGES) {
652 fprintf(stderr, "error: only 16 packages could be traced at once\n");
653 clearAppProperties();
654 return false;
655 }
656 char* end = strchr(start, ',');
657 if (end != NULL) {
658 *end = '\0';
659 end++;
660 }
661 snprintf(buf, sizeof(buf), k_traceAppsPropertyTemplate, i);
662 if (property_set(buf, start) < 0) {
663 fprintf(stderr, "error setting trace app %d property to %s\n", i, buf);
664 clearAppProperties();
665 return false;
666 }
667 start = end;
668 i++;
669 }
670
671 snprintf(buf, sizeof(buf), "%d", i);
672 if (property_set(k_traceAppsNumberProperty, buf) < 0) {
673 fprintf(stderr, "error setting trace app number property to %s\n", buf);
674 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700675 return false;
676 }
677 return true;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800678}
679
680// Disable all /sys/ enable files.
681static bool disableKernelTraceEvents() {
682 bool ok = true;
683 for (int i = 0; i < NELEM(k_categories); i++) {
684 const TracingCategory &c = k_categories[i];
685 for (int j = 0; j < MAX_SYS_FILES; j++) {
686 const char* path = c.sysfiles[j].path;
687 if (path != NULL && fileIsWritable(path)) {
688 ok &= setKernelOptionEnable(path, false);
689 }
690 }
691 }
692 return ok;
693}
694
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700695// Verify that the comma separated list of functions are being traced by the
696// kernel.
697static bool verifyKernelTraceFuncs(const char* funcs)
698{
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100699 std::string buf;
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800700 if (!android::base::ReadFileToString(g_traceFolder + k_ftraceFilterPath, &buf)) {
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100701 fprintf(stderr, "error opening %s: %s (%d)\n", k_ftraceFilterPath,
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700702 strerror(errno), errno);
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100703 return false;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700704 }
705
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100706 String8 funcList = String8::format("\n%s",buf.c_str());
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700707
708 // Make sure that every function listed in funcs is in the list we just
Thomas Buhota2c22872016-01-27 09:44:31 +0100709 // read from the kernel, except for wildcard inputs.
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700710 bool ok = true;
711 char* myFuncs = strdup(funcs);
712 char* func = strtok(myFuncs, ",");
713 while (func) {
Thomas Buhota2c22872016-01-27 09:44:31 +0100714 if (!strchr(func, '*')) {
715 String8 fancyFunc = String8::format("\n%s\n", func);
716 bool found = funcList.find(fancyFunc.string(), 0) >= 0;
717 if (!found || func[0] == '\0') {
718 fprintf(stderr, "error: \"%s\" is not a valid kernel function "
719 "to trace.\n", func);
720 ok = false;
721 }
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700722 }
723 func = strtok(NULL, ",");
724 }
725 free(myFuncs);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700726 return ok;
727}
728
729// Set the comma separated list of functions that the kernel is to trace.
730static bool setKernelTraceFuncs(const char* funcs)
731{
732 bool ok = true;
733
734 if (funcs == NULL || funcs[0] == '\0') {
735 // Disable kernel function tracing.
Jamie Gennis6f6f3f72013-03-27 15:50:30 -0700736 if (fileIsWritable(k_currentTracerPath)) {
737 ok &= writeStr(k_currentTracerPath, "nop");
738 }
739 if (fileIsWritable(k_ftraceFilterPath)) {
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700740 ok &= truncateFile(k_ftraceFilterPath);
741 }
742 } else {
743 // Enable kernel function tracing.
744 ok &= writeStr(k_currentTracerPath, "function_graph");
745 ok &= setKernelOptionEnable(k_funcgraphAbsTimePath, true);
746 ok &= setKernelOptionEnable(k_funcgraphCpuPath, true);
747 ok &= setKernelOptionEnable(k_funcgraphProcPath, true);
748 ok &= setKernelOptionEnable(k_funcgraphFlatPath, true);
749
750 // Set the requested filter functions.
751 ok &= truncateFile(k_ftraceFilterPath);
752 char* myFuncs = strdup(funcs);
753 char* func = strtok(myFuncs, ",");
754 while (func) {
755 ok &= appendStr(k_ftraceFilterPath, func);
756 func = strtok(NULL, ",");
757 }
758 free(myFuncs);
759
760 // Verify that the set functions are being traced.
761 if (ok) {
762 ok &= verifyKernelTraceFuncs(funcs);
763 }
764 }
765
766 return ok;
767}
768
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900769static bool setCategoryEnable(const char* name, bool enable)
770{
771 for (int i = 0; i < NELEM(k_categories); i++) {
772 const TracingCategory& c = k_categories[i];
773 if (strcmp(name, c.name) == 0) {
774 if (isCategorySupported(c)) {
775 g_categoryEnables[i] = enable;
776 return true;
777 } else {
778 if (isCategorySupportedForRoot(c)) {
779 fprintf(stderr, "error: category \"%s\" requires root "
780 "privileges.\n", name);
781 } else {
782 fprintf(stderr, "error: category \"%s\" is not supported "
783 "on this device.\n", name);
784 }
785 return false;
786 }
787 }
788 }
789 fprintf(stderr, "error: unknown tracing category \"%s\"\n", name);
790 return false;
791}
792
793static bool setCategoriesEnableFromFile(const char* categories_file)
794{
795 if (!categories_file) {
796 return true;
797 }
798 Tokenizer* tokenizer = NULL;
799 if (Tokenizer::open(String8(categories_file), &tokenizer) != NO_ERROR) {
800 return false;
801 }
802 bool ok = true;
803 while (!tokenizer->isEol()) {
804 String8 token = tokenizer->nextToken(" ");
805 if (token.isEmpty()) {
806 tokenizer->skipDelimiters(" ");
807 continue;
808 }
809 ok &= setCategoryEnable(token.string(), true);
810 }
811 delete tokenizer;
812 return ok;
813}
814
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700815// Set all the kernel tracing settings to the desired state for this trace
816// capture.
817static bool setUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800818{
819 bool ok = true;
820
821 // Set up the tracing options.
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900822 ok &= setCategoriesEnableFromFile(g_categoriesFile);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800823 ok &= setTraceOverwriteEnable(g_traceOverwrite);
824 ok &= setTraceBufferSizeKB(g_traceBufferSizeKB);
825 ok &= setGlobalClockEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700826 ok &= setPrintTgidEnableIfPresent(true);
827 ok &= setKernelTraceFuncs(g_kernelTraceFuncs);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800828
829 // Set up the tags property.
830 uint64_t tags = 0;
831 for (int i = 0; i < NELEM(k_categories); i++) {
832 if (g_categoryEnables[i]) {
833 const TracingCategory &c = k_categories[i];
834 tags |= c.tags;
835 }
836 }
837 ok &= setTagsProperty(tags);
sergeyvdb404152016-05-02 19:26:07 -0700838
839 bool coreServicesTagEnabled = false;
840 for (int i = 0; i < NELEM(k_categories); i++) {
841 if (strcmp(k_categories[i].name, k_coreServiceCategory) == 0) {
842 coreServicesTagEnabled = g_categoryEnables[i];
843 }
844 }
845
846 std::string packageList(g_debugAppCmdLine);
847 if (coreServicesTagEnabled) {
848 char value[PROPERTY_VALUE_MAX];
849 property_get(k_coreServicesProp, value, "");
850 if (!packageList.empty()) {
851 packageList += ",";
852 }
853 packageList += value;
854 }
Dan Austin09a79872016-05-31 13:27:03 -0700855 ok &= setAppCmdlineProperty(&packageList[0]);
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700856 ok &= pokeBinderServices();
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100857 pokeHalServices();
Corey Tabaka213feb32017-01-13 23:46:55 -0800858 ok &= pokePDXServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800859
860 // Disable all the sysfs enables. This is done as a separate loop from
861 // the enables to allow the same enable to exist in multiple categories.
862 ok &= disableKernelTraceEvents();
863
864 // Enable all the sysfs enables that are in an enabled category.
865 for (int i = 0; i < NELEM(k_categories); i++) {
866 if (g_categoryEnables[i]) {
867 const TracingCategory &c = k_categories[i];
868 for (int j = 0; j < MAX_SYS_FILES; j++) {
869 const char* path = c.sysfiles[j].path;
870 bool required = c.sysfiles[j].required == REQ;
871 if (path != NULL) {
872 if (fileIsWritable(path)) {
873 ok &= setKernelOptionEnable(path, true);
874 } else if (required) {
875 fprintf(stderr, "error writing file %s\n", path);
876 ok = false;
877 }
878 }
879 }
880 }
881 }
882
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800883 return ok;
884}
885
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700886// Reset all the kernel tracing settings to their default state.
887static void cleanUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800888{
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800889 // Disable all tracing that we're able to.
890 disableKernelTraceEvents();
891
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700892 // Reset the system properties.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800893 setTagsProperty(0);
sergeyv4144eff2016-04-28 11:40:04 -0700894 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700895 pokeBinderServices();
Corey Tabaka213feb32017-01-13 23:46:55 -0800896 pokePDXServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800897
898 // Set the options back to their defaults.
899 setTraceOverwriteEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700900 setTraceBufferSizeKB(1);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800901 setGlobalClockEnable(false);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700902 setPrintTgidEnableIfPresent(false);
903 setKernelTraceFuncs(NULL);
904}
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800905
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700906
907// Enable tracing in the kernel.
908static bool startTrace()
909{
910 return setTracingEnabled(true);
911}
912
913// Disable tracing in the kernel.
914static void stopTrace()
915{
916 setTracingEnabled(false);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800917}
918
Martijn Coenend9535872015-11-26 10:00:55 +0100919// Read data from the tracing pipe and forward to stdout
920static void streamTrace()
921{
922 char trace_data[4096];
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800923 int traceFD = open((g_traceFolder + k_traceStreamPath).c_str(), O_RDWR);
Martijn Coenend9535872015-11-26 10:00:55 +0100924 if (traceFD == -1) {
925 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceStreamPath,
926 strerror(errno), errno);
927 return;
928 }
929 while (!g_traceAborted) {
930 ssize_t bytes_read = read(traceFD, trace_data, 4096);
931 if (bytes_read > 0) {
932 write(STDOUT_FILENO, trace_data, bytes_read);
933 fflush(stdout);
934 } else {
935 if (!g_traceAborted) {
936 fprintf(stderr, "read returned %zd bytes err %d (%s)\n",
937 bytes_read, errno, strerror(errno));
938 }
939 break;
940 }
941 }
942}
943
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800944// Read the current kernel trace and write it to stdout.
John Reck40b26b42016-03-30 09:44:36 -0700945static void dumpTrace(int outFd)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800946{
John Reck6c8ac922016-03-28 11:25:30 -0700947 ALOGI("Dumping trace");
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800948 int traceFD = open((g_traceFolder + k_tracePath).c_str(), O_RDWR);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800949 if (traceFD == -1) {
950 fprintf(stderr, "error opening %s: %s (%d)\n", k_tracePath,
951 strerror(errno), errno);
952 return;
953 }
954
955 if (g_compress) {
956 z_stream zs;
Elliott Hughes3da5d232015-01-25 08:35:20 -0800957 memset(&zs, 0, sizeof(zs));
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700958
959 int result = deflateInit(&zs, Z_DEFAULT_COMPRESSION);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800960 if (result != Z_OK) {
961 fprintf(stderr, "error initializing zlib: %d\n", result);
962 close(traceFD);
963 return;
964 }
965
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700966 constexpr size_t bufSize = 64*1024;
967 std::unique_ptr<uint8_t> in(new uint8_t[bufSize]);
968 std::unique_ptr<uint8_t> out(new uint8_t[bufSize]);
969 if (!in || !out) {
970 fprintf(stderr, "couldn't allocate buffers\n");
971 close(traceFD);
972 return;
973 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800974
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700975 int flush = Z_NO_FLUSH;
976
977 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800978 zs.avail_out = bufSize;
979
980 do {
981
982 if (zs.avail_in == 0) {
983 // More input is needed.
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700984 result = read(traceFD, in.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800985 if (result < 0) {
986 fprintf(stderr, "error reading trace: %s (%d)\n",
987 strerror(errno), errno);
988 result = Z_STREAM_END;
989 break;
990 } else if (result == 0) {
991 flush = Z_FINISH;
992 } else {
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700993 zs.next_in = reinterpret_cast<Bytef*>(in.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800994 zs.avail_in = result;
995 }
996 }
997
998 if (zs.avail_out == 0) {
999 // Need to write the output.
Elliott Hughesb59e2962016-07-22 09:00:59 -07001000 result = write(outFd, out.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001001 if ((size_t)result < bufSize) {
1002 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
1003 strerror(errno), errno);
1004 result = Z_STREAM_END; // skip deflate error message
1005 zs.avail_out = bufSize; // skip the final write
1006 break;
1007 }
Elliott Hughesa252f4d2016-07-21 17:12:15 -07001008 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001009 zs.avail_out = bufSize;
1010 }
1011
1012 } while ((result = deflate(&zs, flush)) == Z_OK);
1013
1014 if (result != Z_STREAM_END) {
1015 fprintf(stderr, "error deflating trace: %s\n", zs.msg);
1016 }
1017
1018 if (zs.avail_out < bufSize) {
1019 size_t bytes = bufSize - zs.avail_out;
Elliott Hughesb59e2962016-07-22 09:00:59 -07001020 result = write(outFd, out.get(), bytes);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001021 if ((size_t)result < bytes) {
1022 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
1023 strerror(errno), errno);
1024 }
1025 }
1026
1027 result = deflateEnd(&zs);
1028 if (result != Z_OK) {
1029 fprintf(stderr, "error cleaning up zlib: %d\n", result);
1030 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001031 } else {
1032 ssize_t sent = 0;
John Reck40b26b42016-03-30 09:44:36 -07001033 while ((sent = sendfile(outFd, traceFD, NULL, 64*1024*1024)) > 0);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001034 if (sent == -1) {
1035 fprintf(stderr, "error dumping trace: %s (%d)\n", strerror(errno),
1036 errno);
1037 }
1038 }
1039
1040 close(traceFD);
1041}
1042
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -07001043static void handleSignal(int /*signo*/)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001044{
1045 if (!g_nohup) {
1046 g_traceAborted = true;
1047 }
1048}
1049
1050static void registerSigHandler()
1051{
1052 struct sigaction sa;
1053 sigemptyset(&sa.sa_mask);
1054 sa.sa_flags = 0;
1055 sa.sa_handler = handleSignal;
1056 sigaction(SIGHUP, &sa, NULL);
1057 sigaction(SIGINT, &sa, NULL);
1058 sigaction(SIGQUIT, &sa, NULL);
1059 sigaction(SIGTERM, &sa, NULL);
1060}
1061
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001062static void listSupportedCategories()
1063{
1064 for (int i = 0; i < NELEM(k_categories); i++) {
1065 const TracingCategory& c = k_categories[i];
1066 if (isCategorySupported(c)) {
1067 printf(" %10s - %s\n", c.name, c.longname);
1068 }
1069 }
1070}
1071
1072// Print the command usage help to stderr.
1073static void showHelp(const char *cmd)
1074{
1075 fprintf(stderr, "usage: %s [options] [categories...]\n", cmd);
1076 fprintf(stderr, "options include:\n"
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001077 " -a appname enable app-level tracing for a comma "
1078 "separated list of cmdlines\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001079 " -b N use a trace buffer size of N KB\n"
1080 " -c trace into a circular buffer\n"
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001081 " -f filename use the categories written in a file as space-separated\n"
1082 " values in a line\n"
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001083 " -k fname,... trace the listed kernel functions\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001084 " -n ignore signals\n"
1085 " -s N sleep for N seconds before tracing [default 0]\n"
Fabien Sanglardb5c95472016-06-08 11:40:12 -07001086 " -t N trace for N seconds [default 5]\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001087 " -z compress the trace dump\n"
Fabien Sanglardb5c95472016-06-08 11:40:12 -07001088 " --async_start start circular trace and return immediately\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001089 " --async_dump dump the current contents of circular trace buffer\n"
1090 " --async_stop stop tracing and dump the current contents of circular\n"
1091 " trace buffer\n"
Martijn Coenend9535872015-11-26 10:00:55 +01001092 " --stream stream trace to stdout as it enters the trace buffer\n"
1093 " Note: this can take significant CPU time, and is best\n"
1094 " used for measuring things that are not affected by\n"
1095 " CPU performance, like pagecache usage.\n"
Jamie Gennis92573f12012-12-07 16:29:03 -08001096 " --list_categories\n"
1097 " list the available tracing categories\n"
John Reck40b26b42016-03-30 09:44:36 -07001098 " -o filename write the trace to the specified file instead\n"
1099 " of stdout.\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001100 );
1101}
1102
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001103bool findTraceFiles()
1104{
1105 static const std::string debugfs_path = "/sys/kernel/debug/tracing/";
1106 static const std::string tracefs_path = "/sys/kernel/tracing/";
1107 static const std::string trace_file = "trace_marker";
1108
1109 bool tracefs = access((tracefs_path + trace_file).c_str(), F_OK) != -1;
1110 bool debugfs = access((debugfs_path + trace_file).c_str(), F_OK) != -1;
1111
1112 if (!tracefs && !debugfs) {
1113 fprintf(stderr, "Error: Did not find trace folder\n");
1114 return false;
1115 }
1116
1117 if (tracefs) {
1118 g_traceFolder = tracefs_path;
1119 } else {
1120 g_traceFolder = debugfs_path;
1121 }
1122
1123 return true;
1124}
1125
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001126int main(int argc, char **argv)
1127{
1128 bool async = false;
1129 bool traceStart = true;
1130 bool traceStop = true;
1131 bool traceDump = true;
Martijn Coenend9535872015-11-26 10:00:55 +01001132 bool traceStream = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001133
1134 if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
1135 showHelp(argv[0]);
1136 exit(0);
1137 }
1138
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001139 if (!findTraceFiles()) {
1140 fprintf(stderr, "No trace folder found\n");
1141 exit(-1);
1142 }
1143
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001144 for (;;) {
1145 int ret;
1146 int option_index = 0;
1147 static struct option long_options[] = {
1148 {"async_start", no_argument, 0, 0 },
1149 {"async_stop", no_argument, 0, 0 },
1150 {"async_dump", no_argument, 0, 0 },
1151 {"list_categories", no_argument, 0, 0 },
Martijn Coenend9535872015-11-26 10:00:55 +01001152 {"stream", no_argument, 0, 0 },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001153 { 0, 0, 0, 0 }
1154 };
1155
John Reck40b26b42016-03-30 09:44:36 -07001156 ret = getopt_long(argc, argv, "a:b:cf:k:ns:t:zo:",
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001157 long_options, &option_index);
1158
1159 if (ret < 0) {
1160 for (int i = optind; i < argc; i++) {
1161 if (!setCategoryEnable(argv[i], true)) {
1162 fprintf(stderr, "error enabling tracing category \"%s\"\n", argv[i]);
1163 exit(1);
1164 }
1165 }
1166 break;
1167 }
1168
1169 switch(ret) {
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001170 case 'a':
1171 g_debugAppCmdLine = optarg;
1172 break;
1173
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001174 case 'b':
1175 g_traceBufferSizeKB = atoi(optarg);
1176 break;
1177
1178 case 'c':
1179 g_traceOverwrite = true;
1180 break;
1181
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001182 case 'f':
1183 g_categoriesFile = optarg;
1184 break;
1185
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001186 case 'k':
1187 g_kernelTraceFuncs = optarg;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001188 break;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001189
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001190 case 'n':
1191 g_nohup = true;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001192 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001193
1194 case 's':
1195 g_initialSleepSecs = atoi(optarg);
1196 break;
1197
1198 case 't':
1199 g_traceDurationSeconds = atoi(optarg);
1200 break;
1201
1202 case 'z':
1203 g_compress = true;
1204 break;
1205
John Reck40b26b42016-03-30 09:44:36 -07001206 case 'o':
1207 g_outputFile = optarg;
1208 break;
1209
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001210 case 0:
1211 if (!strcmp(long_options[option_index].name, "async_start")) {
1212 async = true;
1213 traceStop = false;
1214 traceDump = false;
1215 g_traceOverwrite = true;
1216 } else if (!strcmp(long_options[option_index].name, "async_stop")) {
1217 async = true;
John Reck4ba2b632015-05-15 10:00:34 -07001218 traceStart = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001219 } else if (!strcmp(long_options[option_index].name, "async_dump")) {
1220 async = true;
1221 traceStart = false;
1222 traceStop = false;
Martijn Coenend9535872015-11-26 10:00:55 +01001223 } else if (!strcmp(long_options[option_index].name, "stream")) {
1224 traceStream = true;
1225 traceDump = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001226 } else if (!strcmp(long_options[option_index].name, "list_categories")) {
1227 listSupportedCategories();
1228 exit(0);
1229 }
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001230 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001231
1232 default:
1233 fprintf(stderr, "\n");
1234 showHelp(argv[0]);
1235 exit(-1);
1236 break;
1237 }
1238 }
1239
1240 registerSigHandler();
1241
1242 if (g_initialSleepSecs > 0) {
1243 sleep(g_initialSleepSecs);
1244 }
1245
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001246 bool ok = true;
1247 ok &= setUpTrace();
1248 ok &= startTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001249
1250 if (ok && traceStart) {
Martijn Coenend9535872015-11-26 10:00:55 +01001251 if (!traceStream) {
1252 printf("capturing trace...");
1253 fflush(stdout);
1254 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001255
1256 // We clear the trace after starting it because tracing gets enabled for
1257 // each CPU individually in the kernel. Having the beginning of the trace
1258 // contain entries from only one CPU can cause "begin" entries without a
1259 // matching "end" entry to show up if a task gets migrated from one CPU to
1260 // another.
1261 ok = clearTrace();
1262
Martijn Coenen0bcd97a2015-07-15 14:25:23 +02001263 writeClockSyncMarker();
Martijn Coenend9535872015-11-26 10:00:55 +01001264 if (ok && !async && !traceStream) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001265 // Sleep to allow the trace to be captured.
1266 struct timespec timeLeft;
1267 timeLeft.tv_sec = g_traceDurationSeconds;
1268 timeLeft.tv_nsec = 0;
1269 do {
1270 if (g_traceAborted) {
1271 break;
1272 }
1273 } while (nanosleep(&timeLeft, &timeLeft) == -1 && errno == EINTR);
1274 }
Martijn Coenend9535872015-11-26 10:00:55 +01001275
1276 if (traceStream) {
1277 streamTrace();
1278 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001279 }
1280
1281 // Stop the trace and restore the default settings.
1282 if (traceStop)
1283 stopTrace();
1284
1285 if (ok && traceDump) {
1286 if (!g_traceAborted) {
John Reck40b26b42016-03-30 09:44:36 -07001287 printf(" done\n");
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001288 fflush(stdout);
John Reck40b26b42016-03-30 09:44:36 -07001289 int outFd = STDOUT_FILENO;
1290 if (g_outputFile) {
George Burgess IV48443342016-05-04 19:42:00 -07001291 outFd = open(g_outputFile, O_WRONLY | O_CREAT, 0644);
John Reck40b26b42016-03-30 09:44:36 -07001292 }
1293 if (outFd == -1) {
1294 printf("Failed to open '%s', err=%d", g_outputFile, errno);
1295 } else {
1296 dprintf(outFd, "TRACE:\n");
1297 dumpTrace(outFd);
1298 if (g_outputFile) {
1299 close(outFd);
1300 }
1301 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001302 } else {
1303 printf("\ntrace aborted.\n");
1304 fflush(stdout);
1305 }
1306 clearTrace();
1307 } else if (!ok) {
1308 fprintf(stderr, "unable to start tracing\n");
1309 }
1310
1311 // Reset the trace buffer size to 1.
1312 if (traceStop)
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001313 cleanUpTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001314
1315 return g_traceAborted ? 1 : 0;
1316}