blob: 8758516a4d8c4ee6d76b92cc8686889f8d604b51 [file] [log] [blame]
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001/*
2 * Copyright (C) 2012 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
Paul Lawrence2cd93cc2017-01-17 09:50:18 -080017#define LOG_TAG "atrace"
John Reck40b26b42016-03-30 09:44:36 -070018
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080019#include <errno.h>
20#include <fcntl.h>
21#include <getopt.h>
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -070022#include <inttypes.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080023#include <signal.h>
24#include <stdarg.h>
25#include <stdbool.h>
26#include <stdio.h>
27#include <stdlib.h>
Elliott Hughes3da5d232015-01-25 08:35:20 -080028#include <string.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080029#include <sys/sendfile.h>
30#include <time.h>
Martijn Coenend9535872015-11-26 10:00:55 +010031#include <unistd.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080032#include <zlib.h>
33
Carmen Jacksonea826792017-05-05 11:42:32 -070034#include <fstream>
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
45#include <utils/String8.h>
John Reck469a1942015-03-26 15:31:35 -070046#include <utils/Timers.h>
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +090047#include <utils/Tokenizer.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080048#include <utils/Trace.h>
Stephane Gasparinid8419c22016-03-02 13:45:15 +010049#include <android-base/file.h>
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080050
51using namespace android;
52
Martijn Coenenee9b97e2016-11-16 16:00:26 +010053using std::string;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -080054#define NELEM(x) ((int) (sizeof(x) / sizeof((x)[0])))
55
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, {
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800186 { REQ, "events/binder/binder_lock/enable" },
187 { REQ, "events/binder/binder_locked/enable" },
188 { REQ, "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;
209static bool g_categoryEnables[NELEM(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) {
364 char value[PROPERTY_VALUE_MAX];
365 property_get(k_coreServicesProp, value, "");
366 return strlen(value) != 0;
367 }
368
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800369 bool ok = category.tags != 0;
370 for (int i = 0; i < MAX_SYS_FILES; i++) {
371 const char* path = category.sysfiles[i].path;
372 bool req = category.sysfiles[i].required == REQ;
373 if (path != NULL) {
374 if (req) {
375 if (!fileIsWritable(path)) {
376 return false;
377 } else {
378 ok = true;
379 }
380 } else {
381 ok |= fileIsWritable(path);
382 }
383 }
384 }
385 return ok;
386}
387
388// Check whether the category would be supported on the device if the user
389// were root. This function assumes that root is able to write to any file
390// that exists. It performs the same logic as isCategorySupported, but it
Fabien Sanglardb5c95472016-06-08 11:40:12 -0700391// uses file existence rather than writability in the /sys/ file checks.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800392static bool isCategorySupportedForRoot(const TracingCategory& category)
393{
394 bool ok = category.tags != 0;
395 for (int i = 0; i < MAX_SYS_FILES; i++) {
396 const char* path = category.sysfiles[i].path;
397 bool req = category.sysfiles[i].required == REQ;
398 if (path != NULL) {
399 if (req) {
400 if (!fileExists(path)) {
401 return false;
402 } else {
403 ok = true;
404 }
405 } else {
406 ok |= fileExists(path);
407 }
408 }
409 }
410 return ok;
411}
412
413// Enable or disable overwriting of the kernel trace buffers. Disabling this
414// will cause tracing to stop once the trace buffers have filled up.
415static bool setTraceOverwriteEnable(bool enable)
416{
417 return setKernelOptionEnable(k_tracingOverwriteEnablePath, enable);
418}
419
420// Enable or disable kernel tracing.
421static bool setTracingEnabled(bool enable)
422{
423 return setKernelOptionEnable(k_tracingOnPath, enable);
424}
425
426// Clear the contents of the kernel trace.
427static bool clearTrace()
428{
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700429 return truncateFile(k_tracePath);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800430}
431
432// Set the size of the kernel's trace buffer in kilobytes.
433static bool setTraceBufferSizeKB(int size)
434{
435 char str[32] = "1";
436 int len;
437 if (size < 1) {
438 size = 1;
439 }
440 snprintf(str, 32, "%d", size);
441 return writeStr(k_traceBufferSizePath, str);
442}
443
Joel Fernandesefb73a92017-06-02 10:19:28 -0700444// Set the default size of cmdline hashtable
445static bool setCmdlineSize()
446{
Joel Fernandes9351f722017-06-06 12:20:29 -0700447 if (fileExists(k_traceCmdlineSizePath)) {
448 return writeStr(k_traceCmdlineSizePath, "8192");
449 }
450 return true;
Joel Fernandesefb73a92017-06-02 10:19:28 -0700451}
452
Carmen Jacksonea826792017-05-05 11:42:32 -0700453// Set the clock to the best available option while tracing. Use 'boot' if it's
454// available; otherwise, use 'mono'. If neither are available use 'global'.
Colin Crossb1ce49b2014-08-20 14:28:47 -0700455// Any write to the trace_clock sysfs file will reset the buffer, so only
456// update it if the requested value is not the current value.
Carmen Jacksonea826792017-05-05 11:42:32 -0700457static bool setClock()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800458{
Carmen Jacksonea826792017-05-05 11:42:32 -0700459 std::ifstream clockFile((g_traceFolder + k_traceClockPath).c_str(), O_RDONLY);
460 std::string clockStr((std::istreambuf_iterator<char>(clockFile)),
461 std::istreambuf_iterator<char>());
Colin Crossb1ce49b2014-08-20 14:28:47 -0700462
Carmen Jacksonea826792017-05-05 11:42:32 -0700463 std::string newClock;
464 if (clockStr.find("boot") != std::string::npos) {
465 newClock = "boot";
466 } else if (clockStr.find("mono") != std::string::npos) {
467 newClock = "mono";
468 } else {
469 newClock = "global";
Colin Crossb1ce49b2014-08-20 14:28:47 -0700470 }
471
Carmen Jacksonea826792017-05-05 11:42:32 -0700472 size_t begin = clockStr.find("[") + 1;
473 size_t end = clockStr.find("]");
474 if (newClock.compare(0, std::string::npos, clockStr, begin, end-begin) == 0) {
475 return true;
476 }
477 return writeStr(k_traceClockPath, newClock.c_str());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800478}
479
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700480static bool setPrintTgidEnableIfPresent(bool enable)
481{
482 if (fileExists(k_printTgidPath)) {
483 return setKernelOptionEnable(k_printTgidPath, enable);
484 }
485 return true;
486}
487
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800488// Poke all the binder-enabled processes in the system to get them to re-read
489// their system properties.
490static bool pokeBinderServices()
491{
492 sp<IServiceManager> sm = defaultServiceManager();
493 Vector<String16> services = sm->listServices();
494 for (size_t i = 0; i < services.size(); i++) {
495 sp<IBinder> obj = sm->checkService(services[i]);
496 if (obj != NULL) {
497 Parcel data;
498 if (obj->transact(IBinder::SYSPROPS_TRANSACTION, data,
499 NULL, 0) != OK) {
500 if (false) {
501 // XXX: For some reason this fails on tablets trying to
502 // poke the "phone" service. It's not clear whether some
503 // are expected to fail.
504 String8 svc(services[i]);
505 fprintf(stderr, "error poking binder service %s\n",
506 svc.string());
507 return false;
508 }
509 }
510 }
511 }
512 return true;
513}
514
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100515// Poke all the HAL processes in the system to get them to re-read
516// their system properties.
517static void pokeHalServices()
518{
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100519 using ::android::hidl::base::V1_0::IBase;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100520 using ::android::hidl::manager::V1_0::IServiceManager;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100521 using ::android::hardware::hidl_string;
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100522 using ::android::hardware::Return;
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100523
524 sp<IServiceManager> sm = ::android::hardware::defaultServiceManager();
Steven Morelanda42866b2016-12-12 15:18:06 -0800525
526 if (sm == nullptr) {
527 fprintf(stderr, "failed to get IServiceManager to poke hal services\n");
528 return;
529 }
530
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800531 auto listRet = sm->list([&](const auto &interfaces) {
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100532 for (size_t i = 0; i < interfaces.size(); i++) {
533 string fqInstanceName = interfaces[i];
534 string::size_type n = fqInstanceName.find("/");
535 if (n == std::string::npos || interfaces[i].size() == n+1)
536 continue;
537 hidl_string fqInterfaceName = fqInstanceName.substr(0, n);
538 hidl_string instanceName = fqInstanceName.substr(n+1, std::string::npos);
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100539 Return<sp<IBase>> interfaceRet = sm->get(fqInterfaceName, instanceName);
540 if (!interfaceRet.isOk()) {
Martijn Coenen1e4a7fb2017-02-17 14:57:38 +0100541 // ignore
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100542 continue;
543 }
Carmen Jackson73206122017-04-18 15:37:57 -0700544
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100545 sp<IBase> interface = interfaceRet;
Carmen Jackson73206122017-04-18 15:37:57 -0700546 if (interface == nullptr) {
547 // ignore
548 continue;
549 }
550
Martijn Coenenf6ac8482017-01-02 15:17:11 +0100551 auto notifyRet = interface->notifySyspropsChanged();
552 if (!notifyRet.isOk()) {
Martijn Coenen1e4a7fb2017-02-17 14:57:38 +0100553 // ignore
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800554 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100555 }
556 });
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800557 if (!listRet.isOk()) {
Martijn Coenen64d54eb2017-01-12 17:16:31 +0100558 // TODO(b/34242478) fix this when we determine the correct ACL
559 //fprintf(stderr, "failed to list services: %s\n", listRet.description().c_str());
Yifan Hong8cf4ed12016-11-30 17:28:58 -0800560 }
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100561}
562
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800563// Set the trace tags that userland tracing uses, and poke the running
564// processes to pick up the new value.
565static bool setTagsProperty(uint64_t tags)
566{
sergeyv4144eff2016-04-28 11:40:04 -0700567 char buf[PROPERTY_VALUE_MAX];
568 snprintf(buf, sizeof(buf), "%#" PRIx64, tags);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800569 if (property_set(k_traceTagsProperty, buf) < 0) {
570 fprintf(stderr, "error setting trace tags system property\n");
571 return false;
572 }
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700573 return true;
574}
575
sergeyv4144eff2016-04-28 11:40:04 -0700576static void clearAppProperties()
577{
578 char buf[PROPERTY_KEY_MAX];
579 for (int i = 0; i < MAX_PACKAGES; i++) {
580 snprintf(buf, sizeof(buf), k_traceAppsPropertyTemplate, i);
581 if (property_set(buf, "") < 0) {
582 fprintf(stderr, "failed to clear system property: %s\n", buf);
583 }
584 }
585 if (property_set(k_traceAppsNumberProperty, "") < 0) {
586 fprintf(stderr, "failed to clear system property: %s",
587 k_traceAppsNumberProperty);
588 }
589}
590
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700591// Set the system property that indicates which apps should perform
592// application-level tracing.
Dan Austin09a79872016-05-31 13:27:03 -0700593static bool setAppCmdlineProperty(char* cmdline)
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700594{
sergeyv4144eff2016-04-28 11:40:04 -0700595 char buf[PROPERTY_KEY_MAX];
596 int i = 0;
Dan Austin09a79872016-05-31 13:27:03 -0700597 char* start = cmdline;
sergeyv4144eff2016-04-28 11:40:04 -0700598 while (start != NULL) {
599 if (i == MAX_PACKAGES) {
600 fprintf(stderr, "error: only 16 packages could be traced at once\n");
601 clearAppProperties();
602 return false;
603 }
604 char* end = strchr(start, ',');
605 if (end != NULL) {
606 *end = '\0';
607 end++;
608 }
609 snprintf(buf, sizeof(buf), k_traceAppsPropertyTemplate, i);
610 if (property_set(buf, start) < 0) {
611 fprintf(stderr, "error setting trace app %d property to %s\n", i, buf);
612 clearAppProperties();
613 return false;
614 }
615 start = end;
616 i++;
617 }
618
619 snprintf(buf, sizeof(buf), "%d", i);
620 if (property_set(k_traceAppsNumberProperty, buf) < 0) {
621 fprintf(stderr, "error setting trace app number property to %s\n", buf);
622 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700623 return false;
624 }
625 return true;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800626}
627
628// Disable all /sys/ enable files.
629static bool disableKernelTraceEvents() {
630 bool ok = true;
631 for (int i = 0; i < NELEM(k_categories); i++) {
632 const TracingCategory &c = k_categories[i];
633 for (int j = 0; j < MAX_SYS_FILES; j++) {
634 const char* path = c.sysfiles[j].path;
635 if (path != NULL && fileIsWritable(path)) {
636 ok &= setKernelOptionEnable(path, false);
637 }
638 }
639 }
640 return ok;
641}
642
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700643// Verify that the comma separated list of functions are being traced by the
644// kernel.
645static bool verifyKernelTraceFuncs(const char* funcs)
646{
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100647 std::string buf;
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800648 if (!android::base::ReadFileToString(g_traceFolder + k_ftraceFilterPath, &buf)) {
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100649 fprintf(stderr, "error opening %s: %s (%d)\n", k_ftraceFilterPath,
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700650 strerror(errno), errno);
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100651 return false;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700652 }
653
Stephane Gasparinid8419c22016-03-02 13:45:15 +0100654 String8 funcList = String8::format("\n%s",buf.c_str());
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700655
656 // Make sure that every function listed in funcs is in the list we just
Thomas Buhota2c22872016-01-27 09:44:31 +0100657 // read from the kernel, except for wildcard inputs.
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700658 bool ok = true;
659 char* myFuncs = strdup(funcs);
660 char* func = strtok(myFuncs, ",");
661 while (func) {
Thomas Buhota2c22872016-01-27 09:44:31 +0100662 if (!strchr(func, '*')) {
663 String8 fancyFunc = String8::format("\n%s\n", func);
664 bool found = funcList.find(fancyFunc.string(), 0) >= 0;
665 if (!found || func[0] == '\0') {
666 fprintf(stderr, "error: \"%s\" is not a valid kernel function "
667 "to trace.\n", func);
668 ok = false;
669 }
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700670 }
671 func = strtok(NULL, ",");
672 }
673 free(myFuncs);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700674 return ok;
675}
676
677// Set the comma separated list of functions that the kernel is to trace.
678static bool setKernelTraceFuncs(const char* funcs)
679{
680 bool ok = true;
681
682 if (funcs == NULL || funcs[0] == '\0') {
683 // Disable kernel function tracing.
Jamie Gennis6f6f3f72013-03-27 15:50:30 -0700684 if (fileIsWritable(k_currentTracerPath)) {
685 ok &= writeStr(k_currentTracerPath, "nop");
686 }
687 if (fileIsWritable(k_ftraceFilterPath)) {
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700688 ok &= truncateFile(k_ftraceFilterPath);
689 }
690 } else {
691 // Enable kernel function tracing.
692 ok &= writeStr(k_currentTracerPath, "function_graph");
693 ok &= setKernelOptionEnable(k_funcgraphAbsTimePath, true);
694 ok &= setKernelOptionEnable(k_funcgraphCpuPath, true);
695 ok &= setKernelOptionEnable(k_funcgraphProcPath, true);
696 ok &= setKernelOptionEnable(k_funcgraphFlatPath, true);
697
698 // Set the requested filter functions.
699 ok &= truncateFile(k_ftraceFilterPath);
700 char* myFuncs = strdup(funcs);
701 char* func = strtok(myFuncs, ",");
702 while (func) {
703 ok &= appendStr(k_ftraceFilterPath, func);
704 func = strtok(NULL, ",");
705 }
706 free(myFuncs);
707
708 // Verify that the set functions are being traced.
709 if (ok) {
710 ok &= verifyKernelTraceFuncs(funcs);
711 }
712 }
713
714 return ok;
715}
716
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900717static bool setCategoryEnable(const char* name, bool enable)
718{
719 for (int i = 0; i < NELEM(k_categories); i++) {
720 const TracingCategory& c = k_categories[i];
721 if (strcmp(name, c.name) == 0) {
722 if (isCategorySupported(c)) {
723 g_categoryEnables[i] = enable;
724 return true;
725 } else {
726 if (isCategorySupportedForRoot(c)) {
727 fprintf(stderr, "error: category \"%s\" requires root "
728 "privileges.\n", name);
729 } else {
730 fprintf(stderr, "error: category \"%s\" is not supported "
731 "on this device.\n", name);
732 }
733 return false;
734 }
735 }
736 }
737 fprintf(stderr, "error: unknown tracing category \"%s\"\n", name);
738 return false;
739}
740
741static bool setCategoriesEnableFromFile(const char* categories_file)
742{
743 if (!categories_file) {
744 return true;
745 }
746 Tokenizer* tokenizer = NULL;
747 if (Tokenizer::open(String8(categories_file), &tokenizer) != NO_ERROR) {
748 return false;
749 }
750 bool ok = true;
751 while (!tokenizer->isEol()) {
752 String8 token = tokenizer->nextToken(" ");
753 if (token.isEmpty()) {
754 tokenizer->skipDelimiters(" ");
755 continue;
756 }
757 ok &= setCategoryEnable(token.string(), true);
758 }
759 delete tokenizer;
760 return ok;
761}
762
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700763// Set all the kernel tracing settings to the desired state for this trace
764// capture.
765static bool setUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800766{
767 bool ok = true;
768
769 // Set up the tracing options.
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +0900770 ok &= setCategoriesEnableFromFile(g_categoriesFile);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800771 ok &= setTraceOverwriteEnable(g_traceOverwrite);
772 ok &= setTraceBufferSizeKB(g_traceBufferSizeKB);
Joel Fernandesefb73a92017-06-02 10:19:28 -0700773 ok &= setCmdlineSize();
Carmen Jacksonea826792017-05-05 11:42:32 -0700774 ok &= setClock();
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700775 ok &= setPrintTgidEnableIfPresent(true);
776 ok &= setKernelTraceFuncs(g_kernelTraceFuncs);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800777
778 // Set up the tags property.
779 uint64_t tags = 0;
780 for (int i = 0; i < NELEM(k_categories); i++) {
781 if (g_categoryEnables[i]) {
782 const TracingCategory &c = k_categories[i];
783 tags |= c.tags;
784 }
785 }
786 ok &= setTagsProperty(tags);
sergeyvdb404152016-05-02 19:26:07 -0700787
788 bool coreServicesTagEnabled = false;
789 for (int i = 0; i < NELEM(k_categories); i++) {
790 if (strcmp(k_categories[i].name, k_coreServiceCategory) == 0) {
791 coreServicesTagEnabled = g_categoryEnables[i];
792 }
793 }
794
795 std::string packageList(g_debugAppCmdLine);
796 if (coreServicesTagEnabled) {
797 char value[PROPERTY_VALUE_MAX];
798 property_get(k_coreServicesProp, value, "");
799 if (!packageList.empty()) {
800 packageList += ",";
801 }
802 packageList += value;
803 }
Dan Austin09a79872016-05-31 13:27:03 -0700804 ok &= setAppCmdlineProperty(&packageList[0]);
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700805 ok &= pokeBinderServices();
Martijn Coenenee9b97e2016-11-16 16:00:26 +0100806 pokeHalServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800807
808 // Disable all the sysfs enables. This is done as a separate loop from
809 // the enables to allow the same enable to exist in multiple categories.
810 ok &= disableKernelTraceEvents();
811
812 // Enable all the sysfs enables that are in an enabled category.
813 for (int i = 0; i < NELEM(k_categories); i++) {
814 if (g_categoryEnables[i]) {
815 const TracingCategory &c = k_categories[i];
816 for (int j = 0; j < MAX_SYS_FILES; j++) {
817 const char* path = c.sysfiles[j].path;
818 bool required = c.sysfiles[j].required == REQ;
819 if (path != NULL) {
820 if (fileIsWritable(path)) {
821 ok &= setKernelOptionEnable(path, true);
822 } else if (required) {
823 fprintf(stderr, "error writing file %s\n", path);
824 ok = false;
825 }
826 }
827 }
828 }
829 }
830
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800831 return ok;
832}
833
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700834// Reset all the kernel tracing settings to their default state.
835static void cleanUpTrace()
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800836{
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800837 // Disable all tracing that we're able to.
838 disableKernelTraceEvents();
839
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700840 // Reset the system properties.
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800841 setTagsProperty(0);
sergeyv4144eff2016-04-28 11:40:04 -0700842 clearAppProperties();
Jamie Gennisf7f29c82013-03-27 15:50:58 -0700843 pokeBinderServices();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800844
845 // Set the options back to their defaults.
846 setTraceOverwriteEnable(true);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700847 setTraceBufferSizeKB(1);
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700848 setPrintTgidEnableIfPresent(false);
849 setKernelTraceFuncs(NULL);
850}
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800851
Jamie Gennise9b8cfb2013-03-12 16:00:10 -0700852
853// Enable tracing in the kernel.
854static bool startTrace()
855{
856 return setTracingEnabled(true);
857}
858
859// Disable tracing in the kernel.
860static void stopTrace()
861{
862 setTracingEnabled(false);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800863}
864
Martijn Coenend9535872015-11-26 10:00:55 +0100865// Read data from the tracing pipe and forward to stdout
866static void streamTrace()
867{
868 char trace_data[4096];
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800869 int traceFD = open((g_traceFolder + k_traceStreamPath).c_str(), O_RDWR);
Martijn Coenend9535872015-11-26 10:00:55 +0100870 if (traceFD == -1) {
871 fprintf(stderr, "error opening %s: %s (%d)\n", k_traceStreamPath,
872 strerror(errno), errno);
873 return;
874 }
875 while (!g_traceAborted) {
876 ssize_t bytes_read = read(traceFD, trace_data, 4096);
877 if (bytes_read > 0) {
878 write(STDOUT_FILENO, trace_data, bytes_read);
879 fflush(stdout);
880 } else {
881 if (!g_traceAborted) {
882 fprintf(stderr, "read returned %zd bytes err %d (%s)\n",
883 bytes_read, errno, strerror(errno));
884 }
885 break;
886 }
887 }
888}
889
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800890// Read the current kernel trace and write it to stdout.
John Reck40b26b42016-03-30 09:44:36 -0700891static void dumpTrace(int outFd)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800892{
John Reck6c8ac922016-03-28 11:25:30 -0700893 ALOGI("Dumping trace");
Paul Lawrence2cd93cc2017-01-17 09:50:18 -0800894 int traceFD = open((g_traceFolder + k_tracePath).c_str(), O_RDWR);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800895 if (traceFD == -1) {
896 fprintf(stderr, "error opening %s: %s (%d)\n", k_tracePath,
897 strerror(errno), errno);
898 return;
899 }
900
901 if (g_compress) {
902 z_stream zs;
Elliott Hughes3da5d232015-01-25 08:35:20 -0800903 memset(&zs, 0, sizeof(zs));
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700904
905 int result = deflateInit(&zs, Z_DEFAULT_COMPRESSION);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800906 if (result != Z_OK) {
907 fprintf(stderr, "error initializing zlib: %d\n", result);
908 close(traceFD);
909 return;
910 }
911
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700912 constexpr size_t bufSize = 64*1024;
913 std::unique_ptr<uint8_t> in(new uint8_t[bufSize]);
914 std::unique_ptr<uint8_t> out(new uint8_t[bufSize]);
915 if (!in || !out) {
916 fprintf(stderr, "couldn't allocate buffers\n");
917 close(traceFD);
918 return;
919 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800920
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700921 int flush = Z_NO_FLUSH;
922
923 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800924 zs.avail_out = bufSize;
925
926 do {
927
928 if (zs.avail_in == 0) {
929 // More input is needed.
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700930 result = read(traceFD, in.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800931 if (result < 0) {
932 fprintf(stderr, "error reading trace: %s (%d)\n",
933 strerror(errno), errno);
934 result = Z_STREAM_END;
935 break;
936 } else if (result == 0) {
937 flush = Z_FINISH;
938 } else {
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700939 zs.next_in = reinterpret_cast<Bytef*>(in.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800940 zs.avail_in = result;
941 }
942 }
943
944 if (zs.avail_out == 0) {
945 // Need to write the output.
Elliott Hughesb59e2962016-07-22 09:00:59 -0700946 result = write(outFd, out.get(), bufSize);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800947 if ((size_t)result < bufSize) {
948 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
949 strerror(errno), errno);
950 result = Z_STREAM_END; // skip deflate error message
951 zs.avail_out = bufSize; // skip the final write
952 break;
953 }
Elliott Hughesa252f4d2016-07-21 17:12:15 -0700954 zs.next_out = reinterpret_cast<Bytef*>(out.get());
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800955 zs.avail_out = bufSize;
956 }
957
958 } while ((result = deflate(&zs, flush)) == Z_OK);
959
960 if (result != Z_STREAM_END) {
961 fprintf(stderr, "error deflating trace: %s\n", zs.msg);
962 }
963
964 if (zs.avail_out < bufSize) {
965 size_t bytes = bufSize - zs.avail_out;
Elliott Hughesb59e2962016-07-22 09:00:59 -0700966 result = write(outFd, out.get(), bytes);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800967 if ((size_t)result < bytes) {
968 fprintf(stderr, "error writing deflated trace: %s (%d)\n",
969 strerror(errno), errno);
970 }
971 }
972
973 result = deflateEnd(&zs);
974 if (result != Z_OK) {
975 fprintf(stderr, "error cleaning up zlib: %d\n", result);
976 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800977 } else {
978 ssize_t sent = 0;
John Reck40b26b42016-03-30 09:44:36 -0700979 while ((sent = sendfile(outFd, traceFD, NULL, 64*1024*1024)) > 0);
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800980 if (sent == -1) {
981 fprintf(stderr, "error dumping trace: %s (%d)\n", strerror(errno),
982 errno);
983 }
984 }
985
986 close(traceFD);
987}
988
Mark Salyzyn92dc3fc2014-03-12 13:12:44 -0700989static void handleSignal(int /*signo*/)
Jamie Gennis6eea6fb2012-12-07 14:03:07 -0800990{
991 if (!g_nohup) {
992 g_traceAborted = true;
993 }
994}
995
996static void registerSigHandler()
997{
998 struct sigaction sa;
999 sigemptyset(&sa.sa_mask);
1000 sa.sa_flags = 0;
1001 sa.sa_handler = handleSignal;
1002 sigaction(SIGHUP, &sa, NULL);
1003 sigaction(SIGINT, &sa, NULL);
1004 sigaction(SIGQUIT, &sa, NULL);
1005 sigaction(SIGTERM, &sa, NULL);
1006}
1007
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001008static void listSupportedCategories()
1009{
1010 for (int i = 0; i < NELEM(k_categories); i++) {
1011 const TracingCategory& c = k_categories[i];
1012 if (isCategorySupported(c)) {
1013 printf(" %10s - %s\n", c.name, c.longname);
1014 }
1015 }
1016}
1017
1018// Print the command usage help to stderr.
1019static void showHelp(const char *cmd)
1020{
1021 fprintf(stderr, "usage: %s [options] [categories...]\n", cmd);
1022 fprintf(stderr, "options include:\n"
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001023 " -a appname enable app-level tracing for a comma "
1024 "separated list of cmdlines\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001025 " -b N use a trace buffer size of N KB\n"
1026 " -c trace into a circular buffer\n"
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001027 " -f filename use the categories written in a file as space-separated\n"
1028 " values in a line\n"
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001029 " -k fname,... trace the listed kernel functions\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001030 " -n ignore signals\n"
1031 " -s N sleep for N seconds before tracing [default 0]\n"
Fabien Sanglardb5c95472016-06-08 11:40:12 -07001032 " -t N trace for N seconds [default 5]\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001033 " -z compress the trace dump\n"
Fabien Sanglardb5c95472016-06-08 11:40:12 -07001034 " --async_start start circular trace and return immediately\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001035 " --async_dump dump the current contents of circular trace buffer\n"
1036 " --async_stop stop tracing and dump the current contents of circular\n"
1037 " trace buffer\n"
Martijn Coenend9535872015-11-26 10:00:55 +01001038 " --stream stream trace to stdout as it enters the trace buffer\n"
1039 " Note: this can take significant CPU time, and is best\n"
1040 " used for measuring things that are not affected by\n"
1041 " CPU performance, like pagecache usage.\n"
Jamie Gennis92573f12012-12-07 16:29:03 -08001042 " --list_categories\n"
1043 " list the available tracing categories\n"
John Reck40b26b42016-03-30 09:44:36 -07001044 " -o filename write the trace to the specified file instead\n"
1045 " of stdout.\n"
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001046 );
1047}
1048
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001049bool findTraceFiles()
1050{
1051 static const std::string debugfs_path = "/sys/kernel/debug/tracing/";
1052 static const std::string tracefs_path = "/sys/kernel/tracing/";
1053 static const std::string trace_file = "trace_marker";
1054
1055 bool tracefs = access((tracefs_path + trace_file).c_str(), F_OK) != -1;
1056 bool debugfs = access((debugfs_path + trace_file).c_str(), F_OK) != -1;
1057
1058 if (!tracefs && !debugfs) {
1059 fprintf(stderr, "Error: Did not find trace folder\n");
1060 return false;
1061 }
1062
1063 if (tracefs) {
1064 g_traceFolder = tracefs_path;
1065 } else {
1066 g_traceFolder = debugfs_path;
1067 }
1068
1069 return true;
1070}
1071
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001072int main(int argc, char **argv)
1073{
1074 bool async = false;
1075 bool traceStart = true;
1076 bool traceStop = true;
1077 bool traceDump = true;
Martijn Coenend9535872015-11-26 10:00:55 +01001078 bool traceStream = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001079
1080 if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
1081 showHelp(argv[0]);
1082 exit(0);
1083 }
1084
Paul Lawrence2cd93cc2017-01-17 09:50:18 -08001085 if (!findTraceFiles()) {
1086 fprintf(stderr, "No trace folder found\n");
1087 exit(-1);
1088 }
1089
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001090 for (;;) {
1091 int ret;
1092 int option_index = 0;
1093 static struct option long_options[] = {
1094 {"async_start", no_argument, 0, 0 },
1095 {"async_stop", no_argument, 0, 0 },
1096 {"async_dump", no_argument, 0, 0 },
1097 {"list_categories", no_argument, 0, 0 },
Martijn Coenend9535872015-11-26 10:00:55 +01001098 {"stream", no_argument, 0, 0 },
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001099 { 0, 0, 0, 0 }
1100 };
1101
John Reck40b26b42016-03-30 09:44:36 -07001102 ret = getopt_long(argc, argv, "a:b:cf:k:ns:t:zo:",
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001103 long_options, &option_index);
1104
1105 if (ret < 0) {
1106 for (int i = optind; i < argc; i++) {
1107 if (!setCategoryEnable(argv[i], true)) {
1108 fprintf(stderr, "error enabling tracing category \"%s\"\n", argv[i]);
1109 exit(1);
1110 }
1111 }
1112 break;
1113 }
1114
1115 switch(ret) {
Jamie Gennisf7f29c82013-03-27 15:50:58 -07001116 case 'a':
1117 g_debugAppCmdLine = optarg;
1118 break;
1119
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001120 case 'b':
1121 g_traceBufferSizeKB = atoi(optarg);
1122 break;
1123
1124 case 'c':
1125 g_traceOverwrite = true;
1126 break;
1127
Yasuhiro Matsuda46c51fb2015-06-29 19:20:39 +09001128 case 'f':
1129 g_categoriesFile = optarg;
1130 break;
1131
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001132 case 'k':
1133 g_kernelTraceFuncs = optarg;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001134 break;
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001135
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001136 case 'n':
1137 g_nohup = true;
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001138 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001139
1140 case 's':
1141 g_initialSleepSecs = atoi(optarg);
1142 break;
1143
1144 case 't':
1145 g_traceDurationSeconds = atoi(optarg);
1146 break;
1147
1148 case 'z':
1149 g_compress = true;
1150 break;
1151
John Reck40b26b42016-03-30 09:44:36 -07001152 case 'o':
1153 g_outputFile = optarg;
1154 break;
1155
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001156 case 0:
1157 if (!strcmp(long_options[option_index].name, "async_start")) {
1158 async = true;
1159 traceStop = false;
1160 traceDump = false;
1161 g_traceOverwrite = true;
1162 } else if (!strcmp(long_options[option_index].name, "async_stop")) {
1163 async = true;
John Reck4ba2b632015-05-15 10:00:34 -07001164 traceStart = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001165 } else if (!strcmp(long_options[option_index].name, "async_dump")) {
1166 async = true;
1167 traceStart = false;
1168 traceStop = false;
Martijn Coenend9535872015-11-26 10:00:55 +01001169 } else if (!strcmp(long_options[option_index].name, "stream")) {
1170 traceStream = true;
1171 traceDump = false;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001172 } else if (!strcmp(long_options[option_index].name, "list_categories")) {
1173 listSupportedCategories();
1174 exit(0);
1175 }
Jamie Gennis6f6f3f72013-03-27 15:50:30 -07001176 break;
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001177
1178 default:
1179 fprintf(stderr, "\n");
1180 showHelp(argv[0]);
1181 exit(-1);
1182 break;
1183 }
1184 }
1185
1186 registerSigHandler();
1187
1188 if (g_initialSleepSecs > 0) {
1189 sleep(g_initialSleepSecs);
1190 }
1191
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001192 bool ok = true;
1193 ok &= setUpTrace();
1194 ok &= startTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001195
1196 if (ok && traceStart) {
Martijn Coenend9535872015-11-26 10:00:55 +01001197 if (!traceStream) {
1198 printf("capturing trace...");
1199 fflush(stdout);
1200 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001201
1202 // We clear the trace after starting it because tracing gets enabled for
1203 // each CPU individually in the kernel. Having the beginning of the trace
1204 // contain entries from only one CPU can cause "begin" entries without a
1205 // matching "end" entry to show up if a task gets migrated from one CPU to
1206 // another.
1207 ok = clearTrace();
1208
Martijn Coenen0bcd97a2015-07-15 14:25:23 +02001209 writeClockSyncMarker();
Martijn Coenend9535872015-11-26 10:00:55 +01001210 if (ok && !async && !traceStream) {
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001211 // Sleep to allow the trace to be captured.
1212 struct timespec timeLeft;
1213 timeLeft.tv_sec = g_traceDurationSeconds;
1214 timeLeft.tv_nsec = 0;
1215 do {
1216 if (g_traceAborted) {
1217 break;
1218 }
1219 } while (nanosleep(&timeLeft, &timeLeft) == -1 && errno == EINTR);
1220 }
Martijn Coenend9535872015-11-26 10:00:55 +01001221
1222 if (traceStream) {
1223 streamTrace();
1224 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001225 }
1226
1227 // Stop the trace and restore the default settings.
1228 if (traceStop)
1229 stopTrace();
1230
1231 if (ok && traceDump) {
1232 if (!g_traceAborted) {
John Reck40b26b42016-03-30 09:44:36 -07001233 printf(" done\n");
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001234 fflush(stdout);
John Reck40b26b42016-03-30 09:44:36 -07001235 int outFd = STDOUT_FILENO;
1236 if (g_outputFile) {
Martijn Coenenc5791982017-02-22 09:25:31 +01001237 outFd = open(g_outputFile, O_WRONLY | O_CREAT | O_TRUNC, 0644);
John Reck40b26b42016-03-30 09:44:36 -07001238 }
1239 if (outFd == -1) {
1240 printf("Failed to open '%s', err=%d", g_outputFile, errno);
1241 } else {
1242 dprintf(outFd, "TRACE:\n");
1243 dumpTrace(outFd);
1244 if (g_outputFile) {
1245 close(outFd);
1246 }
1247 }
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001248 } else {
1249 printf("\ntrace aborted.\n");
1250 fflush(stdout);
1251 }
1252 clearTrace();
1253 } else if (!ok) {
1254 fprintf(stderr, "unable to start tracing\n");
1255 }
1256
1257 // Reset the trace buffer size to 1.
1258 if (traceStop)
Jamie Gennise9b8cfb2013-03-12 16:00:10 -07001259 cleanUpTrace();
Jamie Gennis6eea6fb2012-12-07 14:03:07 -08001260
1261 return g_traceAborted ? 1 : 0;
1262}