blob: a07bfef9ba36adec693c8356984fa110b7e35fbe [file] [log] [blame]
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001/*
2 * Copyright (C) 2012 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
Paul Lawrence2cd93cc2017-01-17 09:50:18 -080017#define LOG_TAG "atrace"
John Reck40b26b42016-03-30 09:44:36 -070018
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080019#include <errno.h>
20#include <fcntl.h>
21#include <getopt.h>
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -070022#include <inttypes.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080023#include <signal.h>
24#include <stdarg.h>
25#include <stdbool.h>
26#include <stdio.h>
27#include <stdlib.h>
Elliott Hughes3da5d232015-01-25 08:35:20 -080028#include <string.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080029#include <time.h>
Martijn Coenend9535872015-11-26 10:00:55 +010030#include <unistd.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080031#include <zlib.h>
32
Carmen Jacksonea826792017-05-05 11:42:32 -070033#include <fstream>
Elliott Hughesa252f4d2016-07-21 17:12:15 -070034#include <memory>
35
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080036#include <binder/IBinder.h>
37#include <binder/IServiceManager.h>
38#include <binder/Parcel.h>
39
Martijn Coenenee9b97e2016-11-16 16:00:26 +010040#include <android/hidl/manager/1.0/IServiceManager.h>
41#include <hidl/ServiceManagement.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080042
43#include <utils/String8.h>
John Reck469a1942015-03-26 15:31:35 -070044#include <utils/Timers.h>
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +090045#include <utils/Tokenizer.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080046#include <utils/Trace.h>
Stephane Gasparinid8419c22016-03-02 13:45:15 +010047#include <android-base/file.h>
Elliott Hughes5fd6ff62017-03-28 14:55:31 -070048#include <android-base/macros.h>
49#include <android-base/properties.h>
50#include <android-base/stringprintf.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080051
52using namespace android;
53
Martijn Coenenee9b97e2016-11-16 16:00:26 +010054using std::string;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080055
sergeyv4144eff2016-04-28 11:40:04 -070056#define MAX_SYS_FILES 10
57#define MAX_PACKAGES 16
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080058
59const char* k_traceTagsProperty = "debug.atrace.tags.enableflags";
sergeyv4144eff2016-04-28 11:40:04 -070060
61const char* k_traceAppsNumberProperty = "debug.atrace.app_number";
62const char* k_traceAppsPropertyTemplate = "debug.atrace.app_%d";
sergeyvdb404152016-05-02 19:26:07 -070063const char* k_coreServiceCategory = "core_services";
64const char* k_coreServicesProp = "ro.atrace.core.services";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080065
66typedef enum { OPT, REQ } requiredness ;
67
68struct TracingCategory {
69 // The name identifying the category.
70 const char* name;
71
72 // A longer description of the category.
73 const char* longname;
74
75 // The userland tracing tags that the category enables.
76 uint64_t tags;
77
78 // The fname==NULL terminated list of /sys/ files that the category
79 // enables.
80 struct {
81 // Whether the file must be writable in order to enable the tracing
82 // category.
83 requiredness required;
84
85 // The path to the enable file.
86 const char* path;
87 } sysfiles[MAX_SYS_FILES];
88};
89
90/* Tracing categories */
91static const TracingCategory k_categories[] = {
Jamie Gennisb2a89e32013-03-11 19:37:53 -070092 { "gfx", "Graphics", ATRACE_TAG_GRAPHICS, { } },
93 { "input", "Input", ATRACE_TAG_INPUT, { } },
94 { "view", "View System", ATRACE_TAG_VIEW, { } },
95 { "webview", "WebView", ATRACE_TAG_WEBVIEW, { } },
96 { "wm", "Window Manager", ATRACE_TAG_WINDOW_MANAGER, { } },
97 { "am", "Activity Manager", ATRACE_TAG_ACTIVITY_MANAGER, { } },
Patrick Auchter70ec2942014-09-30 15:38:30 -050098 { "sm", "Sync Manager", ATRACE_TAG_SYNC_MANAGER, { } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -070099 { "audio", "Audio", ATRACE_TAG_AUDIO, { } },
100 { "video", "Video", ATRACE_TAG_VIDEO, { } },
101 { "camera", "Camera", ATRACE_TAG_CAMERA, { } },
102 { "hal", "Hardware Modules", ATRACE_TAG_HAL, { } },
Jeff Brown3200b0b2014-08-14 19:24:47 -0700103 { "app", "Application", ATRACE_TAG_APP, { } },
Dianne Hackborn9380d782013-04-12 14:52:35 -0700104 { "res", "Resource Loading", ATRACE_TAG_RESOURCES, { } },
Jamie Genniseff2e8d2013-05-07 15:20:39 -0700105 { "dalvik", "Dalvik VM", ATRACE_TAG_DALVIK, { } },
Tim Murrayf0f28412013-05-23 14:39:42 -0700106 { "rs", "RenderScript", ATRACE_TAG_RS, { } },
Brigid Smith750aa972014-05-28 14:23:24 -0700107 { "bionic", "Bionic C Library", ATRACE_TAG_BIONIC, { } },
Jeff Brown3200b0b2014-08-14 19:24:47 -0700108 { "power", "Power Management", ATRACE_TAG_POWER, { } },
Todd Kennedy01e111b2015-07-31 14:36:20 -0700109 { "pm", "Package Manager", ATRACE_TAG_PACKAGE_MANAGER, { } },
Yasuhiro Matsuda7cc49772015-07-01 01:46:25 +0900110 { "ss", "System Server", ATRACE_TAG_SYSTEM_SERVER, { } },
Greg Hackmannbbd7d992014-12-01 14:43:34 -0800111 { "database", "Database", ATRACE_TAG_DATABASE, { } },
Felipe Leme0f97c1d2016-09-07 11:33:26 -0700112 { "network", "Network", ATRACE_TAG_NETWORK, { } },
Josh Gao468b4cb2016-11-29 10:55:21 -0800113 { "adb", "ADB", ATRACE_TAG_ADB, { } },
sergeyvdb404152016-05-02 19:26:07 -0700114 { k_coreServiceCategory, "Core services", 0, { } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700115 { "sched", "CPU Scheduling", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800116 { REQ, "events/sched/sched_switch/enable" },
117 { REQ, "events/sched/sched_wakeup/enable" },
Joel Fernandes237c3632017-06-04 13:05:59 -0700118 { OPT, "events/sched/sched_waking/enable" },
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800119 { OPT, "events/sched/sched_blocked_reason/enable" },
120 { OPT, "events/sched/sched_cpu_hotplug/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800121 } },
Dan Willemsenf440d392014-04-11 15:44:09 -0700122 { "irq", "IRQ Events", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800123 { REQ, "events/irq/enable" },
124 { OPT, "events/ipi/enable" },
Dan Willemsenf440d392014-04-11 15:44:09 -0700125 } },
Michael Wright43fb6782016-08-18 19:56:43 +0100126 { "i2c", "I2C Events", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800127 { REQ, "events/i2c/enable" },
128 { REQ, "events/i2c/i2c_read/enable" },
129 { REQ, "events/i2c/i2c_write/enable" },
130 { REQ, "events/i2c/i2c_result/enable" },
131 { REQ, "events/i2c/i2c_reply/enable" },
132 { OPT, "events/i2c/smbus_read/enable" },
133 { OPT, "events/i2c/smbus_write/enable" },
134 { OPT, "events/i2c/smbus_result/enable" },
135 { OPT, "events/i2c/smbus_reply/enable" },
Michael Wright43fb6782016-08-18 19:56:43 +0100136 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700137 { "freq", "CPU Frequency", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800138 { REQ, "events/power/cpu_frequency/enable" },
139 { OPT, "events/power/clock_set_rate/enable" },
140 { OPT, "events/power/cpu_frequency_limits/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800141 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700142 { "membus", "Memory Bus Utilization", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800143 { REQ, "events/memory_bus/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800144 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700145 { "idle", "CPU Idle", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800146 { REQ, "events/power/cpu_idle/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800147 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700148 { "disk", "Disk I/O", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800149 { OPT, "events/f2fs/f2fs_sync_file_enter/enable" },
150 { OPT, "events/f2fs/f2fs_sync_file_exit/enable" },
151 { OPT, "events/f2fs/f2fs_write_begin/enable" },
152 { OPT, "events/f2fs/f2fs_write_end/enable" },
153 { OPT, "events/ext4/ext4_da_write_begin/enable" },
154 { OPT, "events/ext4/ext4_da_write_end/enable" },
155 { OPT, "events/ext4/ext4_sync_file_enter/enable" },
156 { OPT, "events/ext4/ext4_sync_file_exit/enable" },
157 { REQ, "events/block/block_rq_issue/enable" },
158 { REQ, "events/block/block_rq_complete/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800159 } },
Ken Sumralld3fa5612013-07-03 12:32:03 -0700160 { "mmc", "eMMC commands", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800161 { REQ, "events/mmc/enable" },
Ken Sumralld3fa5612013-07-03 12:32:03 -0700162 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700163 { "load", "CPU Load", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800164 { REQ, "events/cpufreq_interactive/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800165 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700166 { "sync", "Synchronization", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800167 { REQ, "events/sync/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800168 } },
Jamie Gennisb2a89e32013-03-11 19:37:53 -0700169 { "workq", "Kernel Workqueues", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800170 { REQ, "events/workqueue/enable" },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800171 } },
Colin Cross580407f2014-08-18 15:22:13 -0700172 { "memreclaim", "Kernel Memory Reclaim", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800173 { REQ, "events/vmscan/mm_vmscan_direct_reclaim_begin/enable" },
174 { REQ, "events/vmscan/mm_vmscan_direct_reclaim_end/enable" },
175 { REQ, "events/vmscan/mm_vmscan_kswapd_wake/enable" },
176 { REQ, "events/vmscan/mm_vmscan_kswapd_sleep/enable" },
Colin Cross580407f2014-08-18 15:22:13 -0700177 } },
Aaron Schulmanc2c6ecd2015-02-25 08:37:09 -0800178 { "regulators", "Voltage and Current Regulators", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800179 { REQ, "events/regulator/enable" },
Aaron Schulmanc2c6ecd2015-02-25 08:37:09 -0800180 } },
Scott Bauerae473362015-06-08 16:32:36 -0700181 { "binder_driver", "Binder Kernel driver", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800182 { REQ, "events/binder/binder_transaction/enable" },
183 { REQ, "events/binder/binder_transaction_received/enable" },
Scott Bauerae473362015-06-08 16:32:36 -0700184 } },
185 { "binder_lock", "Binder global lock trace", 0, {
Howard Chen4a9dda12017-05-10 16:32:11 +0800186 { OPT, "events/binder/binder_lock/enable" },
187 { OPT, "events/binder/binder_locked/enable" },
188 { OPT, "events/binder/binder_unlock/enable" },
Scott Bauerae473362015-06-08 16:32:36 -0700189 } },
Martijn Coenen70481612015-10-23 13:57:05 +0200190 { "pagecache", "Page cache", 0, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800191 { REQ, "events/filemap/enable" },
Martijn Coenen70481612015-10-23 13:57:05 +0200192 } },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800193};
194
195/* Command line options */
196static int g_traceDurationSeconds = 5;
197static bool g_traceOverwrite = false;
198static int g_traceBufferSizeKB = 2048;
199static bool g_compress = false;
200static bool g_nohup = false;
201static int g_initialSleepSecs = 0;
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900202static const char* g_categoriesFile = NULL;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700203static const char* g_kernelTraceFuncs = NULL;
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700204static const char* g_debugAppCmdLine = "";
John Reck40b26b42016-03-30 09:44:36 -0700205static const char* g_outputFile = nullptr;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800206
207/* Global state */
208static bool g_traceAborted = false;
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700209static bool g_categoryEnables[arraysize(k_categories)] = {};
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800210static std::string g_traceFolder;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800211
212/* Sys file paths */
213static const char* k_traceClockPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800214 "trace_clock";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800215
216static const char* k_traceBufferSizePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800217 "buffer_size_kb";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800218
Joel Fernandesefb73a92017-06-02 10:19:28 -0700219static const char* k_traceCmdlineSizePath =
220 "saved_cmdlines_size";
221
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800222static const char* k_tracingOverwriteEnablePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800223 "options/overwrite";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800224
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700225static const char* k_currentTracerPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800226 "current_tracer";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700227
228static const char* k_printTgidPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800229 "options/print-tgid";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700230
231static const char* k_funcgraphAbsTimePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800232 "options/funcgraph-abstime";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700233
234static const char* k_funcgraphCpuPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800235 "options/funcgraph-cpu";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700236
237static const char* k_funcgraphProcPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800238 "options/funcgraph-proc";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700239
240static const char* k_funcgraphFlatPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800241 "options/funcgraph-flat";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700242
243static const char* k_funcgraphDurationPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800244 "options/funcgraph-duration";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700245
246static const char* k_ftraceFilterPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800247 "set_ftrace_filter";
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700248
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800249static const char* k_tracingOnPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800250 "tracing_on";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800251
252static const char* k_tracePath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800253 "trace";
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800254
Martijn Coenend9535872015-11-26 10:00:55 +0100255static const char* k_traceStreamPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800256 "trace_pipe";
Martijn Coenend9535872015-11-26 10:00:55 +0100257
John Reck469a1942015-03-26 15:31:35 -0700258static const char* k_traceMarkerPath =
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800259 "trace_marker";
John Reck469a1942015-03-26 15:31:35 -0700260
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800261// Check whether a file exists.
262static bool fileExists(const char* filename) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800263 return access((g_traceFolder + filename).c_str(), F_OK) != -1;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800264}
265
266// Check whether a file is writable.
267static bool fileIsWritable(const char* filename) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800268 return access((g_traceFolder + filename).c_str(), W_OK) != -1;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800269}
270
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700271// Truncate a file.
272static bool truncateFile(const char* path)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800273{
Jamie Gennis43122e72013-03-21 14:06:31 -0700274 // This uses creat rather than truncate because some of the debug kernel
275 // device nodes (e.g. k_ftraceFilterPath) currently aren't changed by
276 // calls to truncate, but they are cleared by calls to creat.
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800277 int traceFD = creat((g_traceFolder + path).c_str(), 0);
Jamie Gennis43122e72013-03-21 14:06:31 -0700278 if (traceFD == -1) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800279 fprintf(stderr, "error truncating %s: %s (%d)\n", (g_traceFolder + path).c_str(),
Jamie Gennis43122e72013-03-21 14:06:31 -0700280 strerror(errno), errno);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700281 return false;
282 }
283
Jamie Gennis43122e72013-03-21 14:06:31 -0700284 close(traceFD);
285
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700286 return true;
287}
288
289static bool _writeStr(const char* filename, const char* str, int flags)
290{
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800291 std::string fullFilename = g_traceFolder + filename;
292 int fd = open(fullFilename.c_str(), flags);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800293 if (fd == -1) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800294 fprintf(stderr, "error opening %s: %s (%d)\n", fullFilename.c_str(),
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800295 strerror(errno), errno);
296 return false;
297 }
298
299 bool ok = true;
300 ssize_t len = strlen(str);
301 if (write(fd, str, len) != len) {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800302 fprintf(stderr, "error writing to %s: %s (%d)\n", fullFilename.c_str(),
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800303 strerror(errno), errno);
304 ok = false;
305 }
306
307 close(fd);
308
309 return ok;
310}
311
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700312// Write a string to a file, returning true if the write was successful.
313static bool writeStr(const char* filename, const char* str)
314{
315 return _writeStr(filename, str, O_WRONLY);
316}
317
318// Append a string to a file, returning true if the write was successful.
319static bool appendStr(const char* filename, const char* str)
320{
321 return _writeStr(filename, str, O_APPEND|O_WRONLY);
322}
323
John Reck469a1942015-03-26 15:31:35 -0700324static void writeClockSyncMarker()
325{
326 char buffer[128];
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200327 int len = 0;
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800328 int fd = open((g_traceFolder + k_traceMarkerPath).c_str(), O_WRONLY);
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200329 if (fd == -1) {
330 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceMarkerPath,
331 strerror(errno), errno);
332 return;
333 }
John Reck469a1942015-03-26 15:31:35 -0700334 float now_in_seconds = systemTime(CLOCK_MONOTONIC) / 1000000000.0f;
Martijn Coenen0bcd97a2015-07-15 14:25:23 +0200335
336 len = snprintf(buffer, 128, "trace_event_clock_sync: parent_ts=%f\n", now_in_seconds);
337 if (write(fd, buffer, len) != len) {
338 fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
339 }
340
341 int64_t realtime_in_ms = systemTime(CLOCK_REALTIME) / 1000000;
342 len = snprintf(buffer, 128, "trace_event_clock_sync: realtime_ts=%" PRId64 "\n", realtime_in_ms);
343 if (write(fd, buffer, len) != len) {
344 fprintf(stderr, "error writing clock sync marker %s (%d)\n", strerror(errno), errno);
345 }
346
347 close(fd);
John Reck469a1942015-03-26 15:31:35 -0700348}
349
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800350// Enable or disable a kernel option by writing a "1" or a "0" into a /sys
351// file.
352static bool setKernelOptionEnable(const char* filename, bool enable)
353{
354 return writeStr(filename, enable ? "1" : "0");
355}
356
357// Check whether the category is supported on the device with the current
358// rootness. A category is supported only if all its required /sys/ files are
359// writable and if enabling the category will enable one or more tracing tags
360// or /sys/ files.
361static bool isCategorySupported(const TracingCategory& category)
362{
sergeyvdb404152016-05-02 19:26:07 -0700363 if (strcmp(category.name, k_coreServiceCategory) == 0) {
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700364 return !android::base::GetProperty(k_coreServicesProp, "").empty();
sergeyvdb404152016-05-02 19:26:07 -0700365 }
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 {
Howard Chen4a9dda12017-05-10 16:32:11 +0800379 ok = true;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800380 }
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
Joel Fernandesefb73a92017-06-02 10:19:28 -0700442// Set the default size of cmdline hashtable
443static bool setCmdlineSize()
444{
Joel Fernandes9351f722017-06-06 12:20:29 -0700445 if (fileExists(k_traceCmdlineSizePath)) {
446 return writeStr(k_traceCmdlineSizePath, "8192");
447 }
448 return true;
Joel Fernandesefb73a92017-06-02 10:19:28 -0700449}
450
Carmen Jacksonea826792017-05-05 11:42:32 -0700451// Set the clock to the best available option while tracing. Use 'boot' if it's
452// available; otherwise, use 'mono'. If neither are available use 'global'.
Colin Crossb1ce49b2014-08-20 14:28:47 -0700453// Any write to the trace_clock sysfs file will reset the buffer, so only
454// update it if the requested value is not the current value.
Carmen Jacksonea826792017-05-05 11:42:32 -0700455static bool setClock()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800456{
Carmen Jacksonea826792017-05-05 11:42:32 -0700457 std::ifstream clockFile((g_traceFolder + k_traceClockPath).c_str(), O_RDONLY);
458 std::string clockStr((std::istreambuf_iterator<char>(clockFile)),
459 std::istreambuf_iterator<char>());
Colin Crossb1ce49b2014-08-20 14:28:47 -0700460
Carmen Jacksonea826792017-05-05 11:42:32 -0700461 std::string newClock;
462 if (clockStr.find("boot") != std::string::npos) {
463 newClock = "boot";
464 } else if (clockStr.find("mono") != std::string::npos) {
465 newClock = "mono";
466 } else {
467 newClock = "global";
Colin Crossb1ce49b2014-08-20 14:28:47 -0700468 }
469
Carmen Jacksonea826792017-05-05 11:42:32 -0700470 size_t begin = clockStr.find("[") + 1;
471 size_t end = clockStr.find("]");
472 if (newClock.compare(0, std::string::npos, clockStr, begin, end-begin) == 0) {
473 return true;
474 }
475 return writeStr(k_traceClockPath, newClock.c_str());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800476}
477
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700478static bool setPrintTgidEnableIfPresent(bool enable)
479{
480 if (fileExists(k_printTgidPath)) {
481 return setKernelOptionEnable(k_printTgidPath, enable);
482 }
483 return true;
484}
485
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800486// Poke all the binder-enabled processes in the system to get them to re-read
487// their system properties.
488static bool pokeBinderServices()
489{
490 sp<IServiceManager> sm = defaultServiceManager();
491 Vector<String16> services = sm->listServices();
492 for (size_t i = 0; i < services.size(); i++) {
493 sp<IBinder> obj = sm->checkService(services[i]);
494 if (obj != NULL) {
495 Parcel data;
496 if (obj->transact(IBinder::SYSPROPS_TRANSACTION, data,
497 NULL, 0) != OK) {
498 if (false) {
499 // XXX: For some reason this fails on tablets trying to
500 // poke the "phone" service. It's not clear whether some
501 // are expected to fail.
502 String8 svc(services[i]);
503 fprintf(stderr, "error poking binder service %s\n",
504 svc.string());
505 return false;
506 }
507 }
508 }
509 }
510 return true;
511}
512
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100513// Poke all the HAL processes in the system to get them to re-read
514// their system properties.
515static void pokeHalServices()
516{
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100517 using ::android::hidl::base::V1_0::IBase;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100518 using ::android::hidl::manager::V1_0::IServiceManager;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100519 using ::android::hardware::hidl_string;
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100520 using ::android::hardware::Return;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100521
522 sp<IServiceManager> sm = ::android::hardware::defaultServiceManager();
Steven Morelanda42866b2016-12-12 15:18:06 -0800523
524 if (sm == nullptr) {
525 fprintf(stderr, "failed to get IServiceManager to poke hal services\n");
526 return;
527 }
528
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800529 auto listRet = sm->list([&](const auto &interfaces) {
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100530 for (size_t i = 0; i < interfaces.size(); i++) {
531 string fqInstanceName = interfaces[i];
532 string::size_type n = fqInstanceName.find("/");
533 if (n == std::string::npos || interfaces[i].size() == n+1)
534 continue;
535 hidl_string fqInterfaceName = fqInstanceName.substr(0, n);
536 hidl_string instanceName = fqInstanceName.substr(n+1, std::string::npos);
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100537 Return<sp<IBase>> interfaceRet = sm->get(fqInterfaceName, instanceName);
538 if (!interfaceRet.isOk()) {
Martijn Coenen1e4a7fb2017-02-17 14:57:38 +0100539 // ignore
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100540 continue;
541 }
Carmen Jackson73206122017-04-18 15:37:57 -0700542
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100543 sp<IBase> interface = interfaceRet;
Carmen Jackson73206122017-04-18 15:37:57 -0700544 if (interface == nullptr) {
545 // ignore
546 continue;
547 }
548
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100549 auto notifyRet = interface->notifySyspropsChanged();
550 if (!notifyRet.isOk()) {
Martijn Coenen1e4a7fb2017-02-17 14:57:38 +0100551 // ignore
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800552 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100553 }
554 });
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800555 if (!listRet.isOk()) {
Martijn Coenen64d54eb2017-01-12 17:16:31 +0100556 // TODO(b/34242478) fix this when we determine the correct ACL
557 //fprintf(stderr, "failed to list services: %s\n", listRet.description().c_str());
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800558 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100559}
560
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800561// Set the trace tags that userland tracing uses, and poke the running
562// processes to pick up the new value.
563static bool setTagsProperty(uint64_t tags)
564{
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700565 std::string value = android::base::StringPrintf("%#" PRIx64, tags);
566 if (!android::base::SetProperty(k_traceTagsProperty, value)) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800567 fprintf(stderr, "error setting trace tags system property\n");
568 return false;
569 }
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700570 return true;
571}
572
sergeyv4144eff2016-04-28 11:40:04 -0700573static void clearAppProperties()
574{
sergeyv4144eff2016-04-28 11:40:04 -0700575 for (int i = 0; i < MAX_PACKAGES; i++) {
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700576 std::string key = android::base::StringPrintf(k_traceAppsPropertyTemplate, i);
577 if (!android::base::SetProperty(key, "")) {
578 fprintf(stderr, "failed to clear system property: %s\n", key.c_str());
sergeyv4144eff2016-04-28 11:40:04 -0700579 }
580 }
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700581 if (!android::base::SetProperty(k_traceAppsNumberProperty, "")) {
sergeyv4144eff2016-04-28 11:40:04 -0700582 fprintf(stderr, "failed to clear system property: %s",
583 k_traceAppsNumberProperty);
584 }
585}
586
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700587// Set the system property that indicates which apps should perform
588// application-level tracing.
Dan Austin09a79872016-05-31 13:27:03 -0700589static bool setAppCmdlineProperty(char* cmdline)
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700590{
sergeyv4144eff2016-04-28 11:40:04 -0700591 int i = 0;
Dan Austin09a79872016-05-31 13:27:03 -0700592 char* start = cmdline;
sergeyv4144eff2016-04-28 11:40:04 -0700593 while (start != NULL) {
594 if (i == MAX_PACKAGES) {
595 fprintf(stderr, "error: only 16 packages could be traced at once\n");
596 clearAppProperties();
597 return false;
598 }
599 char* end = strchr(start, ',');
600 if (end != NULL) {
601 *end = '\0';
602 end++;
603 }
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700604 std::string key = android::base::StringPrintf(k_traceAppsPropertyTemplate, i);
605 if (!android::base::SetProperty(key, start)) {
606 fprintf(stderr, "error setting trace app %d property to %s\n", i, key.c_str());
sergeyv4144eff2016-04-28 11:40:04 -0700607 clearAppProperties();
608 return false;
609 }
610 start = end;
611 i++;
612 }
613
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700614 std::string value = android::base::StringPrintf("%d", i);
615 if (!android::base::SetProperty(k_traceAppsNumberProperty, value)) {
616 fprintf(stderr, "error setting trace app number property to %s\n", value.c_str());
sergeyv4144eff2016-04-28 11:40:04 -0700617 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700618 return false;
619 }
620 return true;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800621}
622
623// Disable all /sys/ enable files.
624static bool disableKernelTraceEvents() {
625 bool ok = true;
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700626 for (size_t i = 0; i < arraysize(k_categories); i++) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800627 const TracingCategory &c = k_categories[i];
628 for (int j = 0; j < MAX_SYS_FILES; j++) {
629 const char* path = c.sysfiles[j].path;
630 if (path != NULL && fileIsWritable(path)) {
631 ok &= setKernelOptionEnable(path, false);
632 }
633 }
634 }
635 return ok;
636}
637
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700638// Verify that the comma separated list of functions are being traced by the
639// kernel.
640static bool verifyKernelTraceFuncs(const char* funcs)
641{
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100642 std::string buf;
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800643 if (!android::base::ReadFileToString(g_traceFolder + k_ftraceFilterPath, &buf)) {
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100644 fprintf(stderr, "error opening %s: %s (%d)\n", k_ftraceFilterPath,
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700645 strerror(errno), errno);
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100646 return false;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700647 }
648
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100649 String8 funcList = String8::format("\n%s",buf.c_str());
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700650
651 // Make sure that every function listed in funcs is in the list we just
Thomas Buhota2c22872016-01-27 09:44:31 +0100652 // read from the kernel, except for wildcard inputs.
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700653 bool ok = true;
654 char* myFuncs = strdup(funcs);
655 char* func = strtok(myFuncs, ",");
656 while (func) {
Thomas Buhota2c22872016-01-27 09:44:31 +0100657 if (!strchr(func, '*')) {
658 String8 fancyFunc = String8::format("\n%s\n", func);
659 bool found = funcList.find(fancyFunc.string(), 0) >= 0;
660 if (!found || func[0] == '\0') {
661 fprintf(stderr, "error: \"%s\" is not a valid kernel function "
662 "to trace.\n", func);
663 ok = false;
664 }
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700665 }
666 func = strtok(NULL, ",");
667 }
668 free(myFuncs);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700669 return ok;
670}
671
672// Set the comma separated list of functions that the kernel is to trace.
673static bool setKernelTraceFuncs(const char* funcs)
674{
675 bool ok = true;
676
677 if (funcs == NULL || funcs[0] == '\0') {
678 // Disable kernel function tracing.
Jamie Gennis6f6f3f72013-03-27 15:50:30 -0700679 if (fileIsWritable(k_currentTracerPath)) {
680 ok &= writeStr(k_currentTracerPath, "nop");
681 }
682 if (fileIsWritable(k_ftraceFilterPath)) {
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700683 ok &= truncateFile(k_ftraceFilterPath);
684 }
685 } else {
686 // Enable kernel function tracing.
687 ok &= writeStr(k_currentTracerPath, "function_graph");
688 ok &= setKernelOptionEnable(k_funcgraphAbsTimePath, true);
689 ok &= setKernelOptionEnable(k_funcgraphCpuPath, true);
690 ok &= setKernelOptionEnable(k_funcgraphProcPath, true);
691 ok &= setKernelOptionEnable(k_funcgraphFlatPath, true);
692
693 // Set the requested filter functions.
694 ok &= truncateFile(k_ftraceFilterPath);
695 char* myFuncs = strdup(funcs);
696 char* func = strtok(myFuncs, ",");
697 while (func) {
698 ok &= appendStr(k_ftraceFilterPath, func);
699 func = strtok(NULL, ",");
700 }
701 free(myFuncs);
702
703 // Verify that the set functions are being traced.
704 if (ok) {
705 ok &= verifyKernelTraceFuncs(funcs);
706 }
707 }
708
709 return ok;
710}
711
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900712static bool setCategoryEnable(const char* name, bool enable)
713{
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700714 for (size_t i = 0; i < arraysize(k_categories); i++) {
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900715 const TracingCategory& c = k_categories[i];
716 if (strcmp(name, c.name) == 0) {
717 if (isCategorySupported(c)) {
718 g_categoryEnables[i] = enable;
719 return true;
720 } else {
721 if (isCategorySupportedForRoot(c)) {
722 fprintf(stderr, "error: category \"%s\" requires root "
723 "privileges.\n", name);
724 } else {
725 fprintf(stderr, "error: category \"%s\" is not supported "
726 "on this device.\n", name);
727 }
728 return false;
729 }
730 }
731 }
732 fprintf(stderr, "error: unknown tracing category \"%s\"\n", name);
733 return false;
734}
735
736static bool setCategoriesEnableFromFile(const char* categories_file)
737{
738 if (!categories_file) {
739 return true;
740 }
741 Tokenizer* tokenizer = NULL;
742 if (Tokenizer::open(String8(categories_file), &tokenizer) != NO_ERROR) {
743 return false;
744 }
745 bool ok = true;
746 while (!tokenizer->isEol()) {
747 String8 token = tokenizer->nextToken(" ");
748 if (token.isEmpty()) {
749 tokenizer->skipDelimiters(" ");
750 continue;
751 }
752 ok &= setCategoryEnable(token.string(), true);
753 }
754 delete tokenizer;
755 return ok;
756}
757
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700758// Set all the kernel tracing settings to the desired state for this trace
759// capture.
760static bool setUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800761{
762 bool ok = true;
763
764 // Set up the tracing options.
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900765 ok &= setCategoriesEnableFromFile(g_categoriesFile);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800766 ok &= setTraceOverwriteEnable(g_traceOverwrite);
767 ok &= setTraceBufferSizeKB(g_traceBufferSizeKB);
John Reckba54d5b2017-06-23 09:44:08 -0700768 // TODO: Re-enable after stabilization
769 //ok &= setCmdlineSize();
Carmen Jacksonea826792017-05-05 11:42:32 -0700770 ok &= setClock();
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700771 ok &= setPrintTgidEnableIfPresent(true);
772 ok &= setKernelTraceFuncs(g_kernelTraceFuncs);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800773
774 // Set up the tags property.
775 uint64_t tags = 0;
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700776 for (size_t i = 0; i < arraysize(k_categories); i++) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800777 if (g_categoryEnables[i]) {
778 const TracingCategory &c = k_categories[i];
779 tags |= c.tags;
780 }
781 }
782 ok &= setTagsProperty(tags);
sergeyvdb404152016-05-02 19:26:07 -0700783
784 bool coreServicesTagEnabled = false;
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700785 for (size_t i = 0; i < arraysize(k_categories); i++) {
sergeyvdb404152016-05-02 19:26:07 -0700786 if (strcmp(k_categories[i].name, k_coreServiceCategory) == 0) {
787 coreServicesTagEnabled = g_categoryEnables[i];
788 }
789 }
790
791 std::string packageList(g_debugAppCmdLine);
792 if (coreServicesTagEnabled) {
sergeyvdb404152016-05-02 19:26:07 -0700793 if (!packageList.empty()) {
794 packageList += ",";
795 }
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700796 packageList += android::base::GetProperty(k_coreServicesProp, "");
sergeyvdb404152016-05-02 19:26:07 -0700797 }
Dan Austin09a79872016-05-31 13:27:03 -0700798 ok &= setAppCmdlineProperty(&packageList[0]);
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700799 ok &= pokeBinderServices();
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100800 pokeHalServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800801
802 // Disable all the sysfs enables. This is done as a separate loop from
803 // the enables to allow the same enable to exist in multiple categories.
804 ok &= disableKernelTraceEvents();
805
806 // Enable all the sysfs enables that are in an enabled category.
Elliott Hughes5fd6ff62017-03-28 14:55:31 -0700807 for (size_t i = 0; i < arraysize(k_categories); i++) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800808 if (g_categoryEnables[i]) {
809 const TracingCategory &c = k_categories[i];
810 for (int j = 0; j < MAX_SYS_FILES; j++) {
811 const char* path = c.sysfiles[j].path;
812 bool required = c.sysfiles[j].required == REQ;
813 if (path != NULL) {
814 if (fileIsWritable(path)) {
815 ok &= setKernelOptionEnable(path, true);
816 } else if (required) {
817 fprintf(stderr, "error writing file %s\n", path);
818 ok = false;
819 }
820 }
821 }
822 }
823 }
824
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800825 return ok;
826}
827
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700828// Reset all the kernel tracing settings to their default state.
829static void cleanUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800830{
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800831 // Disable all tracing that we're able to.
832 disableKernelTraceEvents();
833
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700834 // Reset the system properties.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800835 setTagsProperty(0);
sergeyv4144eff2016-04-28 11:40:04 -0700836 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700837 pokeBinderServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800838
839 // Set the options back to their defaults.
840 setTraceOverwriteEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700841 setTraceBufferSizeKB(1);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700842 setPrintTgidEnableIfPresent(false);
843 setKernelTraceFuncs(NULL);
844}
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800845
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700846
847// Enable tracing in the kernel.
848static bool startTrace()
849{
850 return setTracingEnabled(true);
851}
852
853// Disable tracing in the kernel.
854static void stopTrace()
855{
856 setTracingEnabled(false);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800857}
858
Martijn Coenend9535872015-11-26 10:00:55 +0100859// Read data from the tracing pipe and forward to stdout
860static void streamTrace()
861{
862 char trace_data[4096];
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800863 int traceFD = open((g_traceFolder + k_traceStreamPath).c_str(), O_RDWR);
Martijn Coenend9535872015-11-26 10:00:55 +0100864 if (traceFD == -1) {
865 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceStreamPath,
866 strerror(errno), errno);
867 return;
868 }
869 while (!g_traceAborted) {
870 ssize_t bytes_read = read(traceFD, trace_data, 4096);
871 if (bytes_read > 0) {
872 write(STDOUT_FILENO, trace_data, bytes_read);
873 fflush(stdout);
874 } else {
875 if (!g_traceAborted) {
876 fprintf(stderr, "read returned %zd bytes err %d (%s)\n",
877 bytes_read, errno, strerror(errno));
878 }
879 break;
880 }
881 }
882}
883
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800884// Read the current kernel trace and write it to stdout.
John Reck40b26b42016-03-30 09:44:36 -0700885static void dumpTrace(int outFd)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800886{
John Reck6c8ac922016-03-28 11:25:30 -0700887 ALOGI("Dumping trace");
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800888 int traceFD = open((g_traceFolder + k_tracePath).c_str(), O_RDWR);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800889 if (traceFD == -1) {
890 fprintf(stderr, "error opening %s: %s (%d)\n", k_tracePath,
891 strerror(errno), errno);
892 return;
893 }
894
895 if (g_compress) {
896 z_stream zs;
Elliott Hughes3da5d232015-01-25 08:35:20 -0800897 memset(&zs, 0, sizeof(zs));
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700898
899 int result = deflateInit(&zs, Z_DEFAULT_COMPRESSION);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800900 if (result != Z_OK) {
901 fprintf(stderr, "error initializing zlib: %d\n", result);
902 close(traceFD);
903 return;
904 }
905
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700906 constexpr size_t bufSize = 64*1024;
907 std::unique_ptr<uint8_t> in(new uint8_t[bufSize]);
908 std::unique_ptr<uint8_t> out(new uint8_t[bufSize]);
909 if (!in || !out) {
910 fprintf(stderr, "couldn't allocate buffers\n");
911 close(traceFD);
912 return;
913 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800914
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700915 int flush = Z_NO_FLUSH;
916
917 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800918 zs.avail_out = bufSize;
919
920 do {
921
922 if (zs.avail_in == 0) {
923 // More input is needed.
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700924 result = read(traceFD, in.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800925 if (result < 0) {
926 fprintf(stderr, "error reading trace: %s (%d)\n",
927 strerror(errno), errno);
928 result = Z_STREAM_END;
929 break;
930 } else if (result == 0) {
931 flush = Z_FINISH;
932 } else {
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700933 zs.next_in = reinterpret_cast<Bytef*>(in.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800934 zs.avail_in = result;
935 }
936 }
937
938 if (zs.avail_out == 0) {
939 // Need to write the output.
Elliott Hughesb59e2962016-07-22 09:00:59 -0700940 result = write(outFd, out.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800941 if ((size_t)result < bufSize) {
942 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
943 strerror(errno), errno);
944 result = Z_STREAM_END; // skip deflate error message
945 zs.avail_out = bufSize; // skip the final write
946 break;
947 }
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700948 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800949 zs.avail_out = bufSize;
950 }
951
952 } while ((result = deflate(&zs, flush)) == Z_OK);
953
954 if (result != Z_STREAM_END) {
955 fprintf(stderr, "error deflating trace: %s\n", zs.msg);
956 }
957
958 if (zs.avail_out < bufSize) {
959 size_t bytes = bufSize - zs.avail_out;
Elliott Hughesb59e2962016-07-22 09:00:59 -0700960 result = write(outFd, out.get(), bytes);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800961 if ((size_t)result < bytes) {
962 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
963 strerror(errno), errno);
964 }
965 }
966
967 result = deflateEnd(&zs);
968 if (result != Z_OK) {
969 fprintf(stderr, "error cleaning up zlib: %d\n", result);
970 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800971 } else {
Josh Gaod3d36e72017-04-11 15:21:13 -0700972 char buf[4096];
973 ssize_t rc;
974 while ((rc = TEMP_FAILURE_RETRY(read(traceFD, buf, sizeof(buf)))) > 0) {
975 if (!android::base::WriteFully(outFd, buf, rc)) {
976 fprintf(stderr, "error writing trace: %s\n", strerror(errno));
977 break;
978 }
979 }
980 if (rc == -1) {
981 fprintf(stderr, "error dumping trace: %s\n", strerror(errno));
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800982 }
983 }
984
985 close(traceFD);
986}
987
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -0700988static void handleSignal(int /*signo*/)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800989{
990 if (!g_nohup) {
991 g_traceAborted = true;
992 }
993}
994
995static void registerSigHandler()
996{
997 struct sigaction sa;
998 sigemptyset(&sa.sa_mask);
999 sa.sa_flags = 0;
1000 sa.sa_handler = handleSignal;
1001 sigaction(SIGHUP, &sa, NULL);
1002 sigaction(SIGINT, &sa, NULL);
1003 sigaction(SIGQUIT, &sa, NULL);
1004 sigaction(SIGTERM, &sa, NULL);
1005}
1006
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001007static void listSupportedCategories()
1008{
Elliott Hughes5fd6ff62017-03-28 14:55:31 -07001009 for (size_t i = 0; i < arraysize(k_categories); i++) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001010 const TracingCategory& c = k_categories[i];
1011 if (isCategorySupported(c)) {
1012 printf(" %10s - %s\n", c.name, c.longname);
1013 }
1014 }
1015}
1016
1017// Print the command usage help to stderr.
1018static void showHelp(const char *cmd)
1019{
1020 fprintf(stderr, "usage: %s [options] [categories...]\n", cmd);
1021 fprintf(stderr, "options include:\n"
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001022 " -a appname enable app-level tracing for a comma "
1023 "separated list of cmdlines\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001024 " -b N use a trace buffer size of N KB\n"
1025 " -c trace into a circular buffer\n"
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001026 " -f filename use the categories written in a file as space-separated\n"
1027 " values in a line\n"
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001028 " -k fname,... trace the listed kernel functions\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001029 " -n ignore signals\n"
1030 " -s N sleep for N seconds before tracing [default 0]\n"
Fabien Sanglardb5c95472016-06-08 11:40:12 -07001031 " -t N trace for N seconds [default 5]\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001032 " -z compress the trace dump\n"
Fabien Sanglardb5c95472016-06-08 11:40:12 -07001033 " --async_start start circular trace and return immediately\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001034 " --async_dump dump the current contents of circular trace buffer\n"
1035 " --async_stop stop tracing and dump the current contents of circular\n"
1036 " trace buffer\n"
Martijn Coenend9535872015-11-26 10:00:55 +01001037 " --stream stream trace to stdout as it enters the trace buffer\n"
1038 " Note: this can take significant CPU time, and is best\n"
1039 " used for measuring things that are not affected by\n"
1040 " CPU performance, like pagecache usage.\n"
Jamie Gennis92573f12012-12-07 16:29:03 -08001041 " --list_categories\n"
1042 " list the available tracing categories\n"
John Reck40b26b42016-03-30 09:44:36 -07001043 " -o filename write the trace to the specified file instead\n"
1044 " of stdout.\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001045 );
1046}
1047
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001048bool findTraceFiles()
1049{
1050 static const std::string debugfs_path = "/sys/kernel/debug/tracing/";
1051 static const std::string tracefs_path = "/sys/kernel/tracing/";
1052 static const std::string trace_file = "trace_marker";
1053
1054 bool tracefs = access((tracefs_path + trace_file).c_str(), F_OK) != -1;
1055 bool debugfs = access((debugfs_path + trace_file).c_str(), F_OK) != -1;
1056
1057 if (!tracefs && !debugfs) {
1058 fprintf(stderr, "Error: Did not find trace folder\n");
1059 return false;
1060 }
1061
1062 if (tracefs) {
1063 g_traceFolder = tracefs_path;
1064 } else {
1065 g_traceFolder = debugfs_path;
1066 }
1067
1068 return true;
1069}
1070
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001071int main(int argc, char **argv)
1072{
1073 bool async = false;
1074 bool traceStart = true;
1075 bool traceStop = true;
1076 bool traceDump = true;
Martijn Coenend9535872015-11-26 10:00:55 +01001077 bool traceStream = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001078
1079 if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
1080 showHelp(argv[0]);
1081 exit(0);
1082 }
1083
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001084 if (!findTraceFiles()) {
1085 fprintf(stderr, "No trace folder found\n");
1086 exit(-1);
1087 }
1088
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001089 for (;;) {
1090 int ret;
1091 int option_index = 0;
1092 static struct option long_options[] = {
1093 {"async_start", no_argument, 0, 0 },
1094 {"async_stop", no_argument, 0, 0 },
1095 {"async_dump", no_argument, 0, 0 },
1096 {"list_categories", no_argument, 0, 0 },
Martijn Coenend9535872015-11-26 10:00:55 +01001097 {"stream", no_argument, 0, 0 },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001098 { 0, 0, 0, 0 }
1099 };
1100
John Reck40b26b42016-03-30 09:44:36 -07001101 ret = getopt_long(argc, argv, "a:b:cf:k:ns:t:zo:",
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001102 long_options, &option_index);
1103
1104 if (ret < 0) {
1105 for (int i = optind; i < argc; i++) {
1106 if (!setCategoryEnable(argv[i], true)) {
1107 fprintf(stderr, "error enabling tracing category \"%s\"\n", argv[i]);
1108 exit(1);
1109 }
1110 }
1111 break;
1112 }
1113
1114 switch(ret) {
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001115 case 'a':
1116 g_debugAppCmdLine = optarg;
1117 break;
1118
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001119 case 'b':
1120 g_traceBufferSizeKB = atoi(optarg);
1121 break;
1122
1123 case 'c':
1124 g_traceOverwrite = true;
1125 break;
1126
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001127 case 'f':
1128 g_categoriesFile = optarg;
1129 break;
1130
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001131 case 'k':
1132 g_kernelTraceFuncs = optarg;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001133 break;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001134
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001135 case 'n':
1136 g_nohup = true;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001137 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001138
1139 case 's':
1140 g_initialSleepSecs = atoi(optarg);
1141 break;
1142
1143 case 't':
1144 g_traceDurationSeconds = atoi(optarg);
1145 break;
1146
1147 case 'z':
1148 g_compress = true;
1149 break;
1150
John Reck40b26b42016-03-30 09:44:36 -07001151 case 'o':
1152 g_outputFile = optarg;
1153 break;
1154
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001155 case 0:
1156 if (!strcmp(long_options[option_index].name, "async_start")) {
1157 async = true;
1158 traceStop = false;
1159 traceDump = false;
1160 g_traceOverwrite = true;
1161 } else if (!strcmp(long_options[option_index].name, "async_stop")) {
1162 async = true;
John Reck4ba2b632015-05-15 10:00:34 -07001163 traceStart = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001164 } else if (!strcmp(long_options[option_index].name, "async_dump")) {
1165 async = true;
1166 traceStart = false;
1167 traceStop = false;
Martijn Coenend9535872015-11-26 10:00:55 +01001168 } else if (!strcmp(long_options[option_index].name, "stream")) {
1169 traceStream = true;
1170 traceDump = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001171 } else if (!strcmp(long_options[option_index].name, "list_categories")) {
1172 listSupportedCategories();
1173 exit(0);
1174 }
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001175 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001176
1177 default:
1178 fprintf(stderr, "\n");
1179 showHelp(argv[0]);
1180 exit(-1);
1181 break;
1182 }
1183 }
1184
1185 registerSigHandler();
1186
1187 if (g_initialSleepSecs > 0) {
1188 sleep(g_initialSleepSecs);
1189 }
1190
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001191 bool ok = true;
1192 ok &= setUpTrace();
1193 ok &= startTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001194
1195 if (ok && traceStart) {
Martijn Coenend9535872015-11-26 10:00:55 +01001196 if (!traceStream) {
Carmen Jacksonac53e732017-05-02 16:55:33 -07001197 printf("capturing trace...");
Martijn Coenend9535872015-11-26 10:00:55 +01001198 fflush(stdout);
1199 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001200
1201 // We clear the trace after starting it because tracing gets enabled for
1202 // each CPU individually in the kernel. Having the beginning of the trace
1203 // contain entries from only one CPU can cause "begin" entries without a
1204 // matching "end" entry to show up if a task gets migrated from one CPU to
1205 // another.
1206 ok = clearTrace();
1207
Martijn Coenen0bcd97a2015-07-15 14:25:23 +02001208 writeClockSyncMarker();
Martijn Coenend9535872015-11-26 10:00:55 +01001209 if (ok && !async && !traceStream) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001210 // Sleep to allow the trace to be captured.
1211 struct timespec timeLeft;
1212 timeLeft.tv_sec = g_traceDurationSeconds;
1213 timeLeft.tv_nsec = 0;
1214 do {
1215 if (g_traceAborted) {
1216 break;
1217 }
1218 } while (nanosleep(&timeLeft, &timeLeft) == -1 && errno == EINTR);
1219 }
Martijn Coenend9535872015-11-26 10:00:55 +01001220
1221 if (traceStream) {
1222 streamTrace();
1223 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001224 }
1225
1226 // Stop the trace and restore the default settings.
1227 if (traceStop)
1228 stopTrace();
1229
1230 if (ok && traceDump) {
1231 if (!g_traceAborted) {
John Reck40b26b42016-03-30 09:44:36 -07001232 printf(" done\n");
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001233 fflush(stdout);
John Reck40b26b42016-03-30 09:44:36 -07001234 int outFd = STDOUT_FILENO;
1235 if (g_outputFile) {
Martijn Coenenc5791982017-02-22 09:25:31 +01001236 outFd = open(g_outputFile, O_WRONLY | O_CREAT | O_TRUNC, 0644);
John Reck40b26b42016-03-30 09:44:36 -07001237 }
1238 if (outFd == -1) {
1239 printf("Failed to open '%s', err=%d", g_outputFile, errno);
1240 } else {
1241 dprintf(outFd, "TRACE:\n");
1242 dumpTrace(outFd);
1243 if (g_outputFile) {
1244 close(outFd);
1245 }
1246 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001247 } else {
1248 printf("\ntrace aborted.\n");
1249 fflush(stdout);
1250 }
1251 clearTrace();
1252 } else if (!ok) {
1253 fprintf(stderr, "unable to start tracing\n");
1254 }
1255
1256 // Reset the trace buffer size to 1.
1257 if (traceStop)
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001258 cleanUpTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001259
1260 return g_traceAborted ? 1 : 0;
1261}