1 /*
2 * Copyright (C) 2018 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
17 #include "src/traceconv/trace_to_systrace.h"
18
19 #include <stdio.h>
20
21 #include <algorithm>
22 #include <cinttypes>
23 #include <functional>
24 #include <map>
25 #include <memory>
26 #include <utility>
27
28 #include "perfetto/base/build_config.h"
29 #include "perfetto/base/logging.h"
30 #include "perfetto/ext/base/string_utils.h"
31 #include "perfetto/ext/base/string_writer.h"
32 #include "perfetto/ext/base/utils.h"
33 #include "perfetto/trace_processor/trace_processor.h"
34 #include "src/traceconv/utils.h"
35
36 namespace perfetto {
37 namespace trace_to_text {
38
39 namespace {
40
41 const char kProcessDumpHeader[] =
42 "\"androidProcessDump\": "
43 "\"PROCESS DUMP\\nUSER PID PPID VSZ RSS WCHAN "
44 "PC S NAME COMM \\n";
45
46 const char kThreadHeader[] = "USER PID TID CMD \\n";
47
48 const char kProcessDumpFooter[] = "\"";
49
50 const char kSystemTraceEvents[] = " \"systemTraceEvents\": \"";
51
52 const char kFtraceHeader[] =
53 "# tracer: nop\n"
54 "#\n"
55 "# entries-in-buffer/entries-written: 30624/30624 #P:4\n"
56 "#\n"
57 "# _-----=> irqs-off\n"
58 "# / _----=> need-resched\n"
59 "# | / _---=> hardirq/softirq\n"
60 "# || / _--=> preempt-depth\n"
61 "# ||| / delay\n"
62 "# TASK-PID TGID CPU# |||| TIMESTAMP FUNCTION\n"
63 "# | | | | |||| | |\n";
64
65 const char kFtraceJsonHeader[] =
66 "# tracer: nop\\n"
67 "#\\n"
68 "# entries-in-buffer/entries-written: 30624/30624 #P:4\\n"
69 "#\\n"
70 "# _-----=> irqs-off\\n"
71 "# / _----=> need-resched\\n"
72 "# | / _---=> hardirq/softirq\\n"
73 "# || / _--=> preempt-depth\\n"
74 "# ||| / delay\\n"
75 "# TASK-PID TGID CPU# |||| TIMESTAMP FUNCTION\\n"
76 "# | | | | |||| | |\\n";
77
78 // The legacy trace viewer requires a clock sync marker to tie ftrace and
79 // userspace clocks together. Trace processor already aligned these clocks, so
80 // we just emit a clock sync for an equality mapping.
81 const char kSystemTraceEventsFooter[] =
82 "\\n<...>-12345 (-----) [000] ...1 0.000000: tracing_mark_write: "
83 "trace_event_clock_sync: parent_ts=0\\n\"";
84
FormatProcess(uint32_t pid,uint32_t ppid,const base::StringView & name,base::StringWriter * writer)85 inline void FormatProcess(uint32_t pid,
86 uint32_t ppid,
87 const base::StringView& name,
88 base::StringWriter* writer) {
89 writer->AppendLiteral("root ");
90 writer->AppendInt(pid);
91 writer->AppendLiteral(" ");
92 writer->AppendInt(ppid);
93 writer->AppendLiteral(" 00000 000 null 0000000000 S ");
94 writer->AppendString(name);
95 writer->AppendLiteral(" null");
96 }
97
FormatThread(uint32_t tid,uint32_t tgid,const base::StringView & name,base::StringWriter * writer)98 inline void FormatThread(uint32_t tid,
99 uint32_t tgid,
100 const base::StringView& name,
101 base::StringWriter* writer) {
102 writer->AppendLiteral("root ");
103 writer->AppendInt(tgid);
104 writer->AppendChar(' ');
105 writer->AppendInt(tid);
106 writer->AppendChar(' ');
107 if (name.empty()) {
108 writer->AppendLiteral("<...>");
109 } else {
110 writer->AppendString(name);
111 }
112 }
113
114 class QueryWriter {
115 public:
QueryWriter(trace_processor::TraceProcessor * tp,TraceWriter * trace_writer)116 QueryWriter(trace_processor::TraceProcessor* tp, TraceWriter* trace_writer)
117 : tp_(tp),
118 buffer_(base::PagedMemory::Allocate(kBufferSize)),
119 global_writer_(static_cast<char*>(buffer_.Get()), kBufferSize),
120 trace_writer_(trace_writer) {}
121
122 template <typename Callback>
RunQuery(const std::string & sql,Callback callback)123 bool RunQuery(const std::string& sql, Callback callback) {
124 char buffer[2048];
125 auto iterator = tp_->ExecuteQuery(sql);
126 for (uint32_t rows = 0; iterator.Next(); rows++) {
127 base::StringWriter line_writer(buffer, base::ArraySize(buffer));
128 callback(&iterator, &line_writer);
129
130 if (global_writer_.pos() + line_writer.pos() >= global_writer_.size()) {
131 fprintf(stderr, "Writing row %" PRIu32 "%c", rows, kProgressChar);
132 auto str = global_writer_.GetStringView();
133 trace_writer_->Write(str.data(), str.size());
134 global_writer_.reset();
135 }
136 global_writer_.AppendStringView(line_writer.GetStringView());
137 }
138
139 // Check if we have an error in the iterator and print if so.
140 auto status = iterator.Status();
141 if (!status.ok()) {
142 PERFETTO_ELOG("Error while writing systrace %s", status.c_message());
143 return false;
144 }
145
146 // Flush any dangling pieces in the global writer.
147 auto str = global_writer_.GetStringView();
148 trace_writer_->Write(str.data(), str.size());
149 global_writer_.reset();
150 return true;
151 }
152
153 private:
154 static constexpr uint32_t kBufferSize = 1024u * 1024u * 16u;
155
156 trace_processor::TraceProcessor* tp_ = nullptr;
157 base::PagedMemory buffer_;
158 base::StringWriter global_writer_;
159 TraceWriter* trace_writer_;
160 };
161
ExtractRawEvents(TraceWriter * trace_writer,QueryWriter & q_writer,bool wrapped_in_json,Keep truncate_keep)162 int ExtractRawEvents(TraceWriter* trace_writer,
163 QueryWriter& q_writer,
164 bool wrapped_in_json,
165 Keep truncate_keep) {
166 using trace_processor::Iterator;
167
168 static const char kRawEventsCountSql[] = "select count(1) from ftrace_event";
169 uint32_t raw_events = 0;
170 auto e_callback = [&raw_events](Iterator* it, base::StringWriter*) {
171 raw_events = static_cast<uint32_t>(it->Get(0).long_value);
172 };
173 if (!q_writer.RunQuery(kRawEventsCountSql, e_callback))
174 return 1;
175
176 if (raw_events == 0) {
177 if (!wrapped_in_json) {
178 // Write out the normal header even if we won't actually have
179 // any events under it.
180 trace_writer->Write(kFtraceHeader);
181 }
182 return 0;
183 }
184
185 fprintf(stderr, "Converting ftrace events%c", kProgressChar);
186 fflush(stderr);
187
188 auto raw_callback = [wrapped_in_json](Iterator* it,
189 base::StringWriter* writer) {
190 const char* line = it->Get(0 /* col */).string_value;
191 if (wrapped_in_json) {
192 for (uint32_t i = 0; line[i] != '\0'; i++) {
193 char c = line[i];
194 switch (c) {
195 case '\n':
196 writer->AppendLiteral("\\n");
197 break;
198 case '\f':
199 writer->AppendLiteral("\\f");
200 break;
201 case '\b':
202 writer->AppendLiteral("\\b");
203 break;
204 case '\r':
205 writer->AppendLiteral("\\r");
206 break;
207 case '\t':
208 writer->AppendLiteral("\\t");
209 break;
210 case '\\':
211 writer->AppendLiteral("\\\\");
212 break;
213 case '"':
214 writer->AppendLiteral("\\\"");
215 break;
216 default:
217 writer->AppendChar(c);
218 break;
219 }
220 }
221 writer->AppendChar('\\');
222 writer->AppendChar('n');
223 } else {
224 writer->AppendString(line);
225 writer->AppendChar('\n');
226 }
227 };
228
229 // An estimate of 130b per ftrace event, allowing some space for the processes
230 // and threads.
231 const uint32_t max_ftrace_events = (140 * 1024 * 1024) / 130;
232
233 static const char kRawEventsQuery[] =
234 "select to_ftrace(id) from ftrace_event";
235
236 // 1. Write the appropriate header for the file type.
237 if (wrapped_in_json) {
238 trace_writer->Write(",\n");
239 trace_writer->Write(kSystemTraceEvents);
240 trace_writer->Write(kFtraceJsonHeader);
241 } else {
242 trace_writer->Write(kFtraceHeader);
243 }
244
245 // 2. Write the actual events.
246 if (truncate_keep == Keep::kEnd && raw_events > max_ftrace_events) {
247 base::StackString<150> end_truncate("%s limit %d offset %d",
248 kRawEventsQuery, max_ftrace_events,
249 raw_events - max_ftrace_events);
250 if (!q_writer.RunQuery(end_truncate.ToStdString(), raw_callback))
251 return 1;
252 } else if (truncate_keep == Keep::kStart) {
253 base::StackString<150> start_truncate("%s limit %d", kRawEventsQuery,
254 max_ftrace_events);
255 if (!q_writer.RunQuery(start_truncate.ToStdString(), raw_callback))
256 return 1;
257 } else {
258 if (!q_writer.RunQuery(kRawEventsQuery, raw_callback))
259 return 1;
260 }
261
262 // 3. Write the footer for JSON.
263 if (wrapped_in_json)
264 trace_writer->Write(kSystemTraceEventsFooter);
265
266 return 0;
267 }
268
269 } // namespace
270
TraceToSystrace(std::istream * input,std::ostream * output,bool ctrace,Keep truncate_keep,bool full_sort)271 int TraceToSystrace(std::istream* input,
272 std::ostream* output,
273 bool ctrace,
274 Keep truncate_keep,
275 bool full_sort) {
276 std::unique_ptr<TraceWriter> trace_writer(
277 ctrace ? new DeflateTraceWriter(output) : new TraceWriter(output));
278
279 trace_processor::Config config;
280 config.sorting_mode = full_sort
281 ? trace_processor::SortingMode::kForceFullSort
282 : trace_processor::SortingMode::kDefaultHeuristics;
283 std::unique_ptr<trace_processor::TraceProcessor> tp =
284 trace_processor::TraceProcessor::CreateInstance(config);
285
286 if (!ReadTraceUnfinalized(tp.get(), input))
287 return 1;
288 tp->NotifyEndOfFile();
289
290 if (ctrace)
291 *output << "TRACE:\n";
292
293 return ExtractSystrace(tp.get(), trace_writer.get(),
294 /*wrapped_in_json=*/false, truncate_keep);
295 }
296
ExtractSystrace(trace_processor::TraceProcessor * tp,TraceWriter * trace_writer,bool wrapped_in_json,Keep truncate_keep)297 int ExtractSystrace(trace_processor::TraceProcessor* tp,
298 TraceWriter* trace_writer,
299 bool wrapped_in_json,
300 Keep truncate_keep) {
301 using trace_processor::Iterator;
302
303 QueryWriter q_writer(tp, trace_writer);
304 if (wrapped_in_json) {
305 trace_writer->Write(kProcessDumpHeader);
306
307 // Write out all the processes in the trace.
308 // TODO(lalitm): change this query to actually use ppid when it is exposed
309 // by the process table.
310 static const char kPSql[] = "select pid, 0 as ppid, name from process";
311 auto p_callback = [](Iterator* it, base::StringWriter* writer) {
312 uint32_t pid = static_cast<uint32_t>(it->Get(0 /* col */).long_value);
313 uint32_t ppid = static_cast<uint32_t>(it->Get(1 /* col */).long_value);
314 const auto& name_col = it->Get(2 /* col */);
315 auto name_view = name_col.type == trace_processor::SqlValue::kString
316 ? base::StringView(name_col.string_value)
317 : base::StringView();
318 FormatProcess(pid, ppid, name_view, writer);
319 };
320 if (!q_writer.RunQuery(kPSql, p_callback))
321 return 1;
322
323 trace_writer->Write(kThreadHeader);
324
325 // Write out all the threads in the trace.
326 static const char kTSql[] =
327 "select tid, COALESCE(upid, 0), thread.name "
328 "from thread left join process using (upid)";
329 auto t_callback = [](Iterator* it, base::StringWriter* writer) {
330 uint32_t tid = static_cast<uint32_t>(it->Get(0 /* col */).long_value);
331 uint32_t tgid = static_cast<uint32_t>(it->Get(1 /* col */).long_value);
332 const auto& name_col = it->Get(2 /* col */);
333 auto name_view = name_col.type == trace_processor::SqlValue::kString
334 ? base::StringView(name_col.string_value)
335 : base::StringView();
336 FormatThread(tid, tgid, name_view, writer);
337 };
338 if (!q_writer.RunQuery(kTSql, t_callback))
339 return 1;
340
341 trace_writer->Write(kProcessDumpFooter);
342 }
343 return ExtractRawEvents(trace_writer, q_writer, wrapped_in_json,
344 truncate_keep);
345 }
346
347 } // namespace trace_to_text
348 } // namespace perfetto
349