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 <aio.h>
18 #include <fcntl.h>
19 #include <inttypes.h>
20 #include <stdio.h>
21 #include <sys/stat.h>
22 #include <unistd.h>
23
24 #include <functional>
25 #include <iostream>
26 #include <vector>
27
28 #include "perfetto/base/build_config.h"
29 #include "perfetto/base/logging.h"
30 #include "perfetto/base/scoped_file.h"
31 #include "perfetto/base/string_splitter.h"
32 #include "perfetto/base/time.h"
33 #include "perfetto/trace_processor/trace_processor.h"
34
35 #if PERFETTO_BUILDFLAG(PERFETTO_OS_LINUX) || \
36 PERFETTO_BUILDFLAG(PERFETTO_OS_ANDROID) || \
37 PERFETTO_BUILDFLAG(PERFETTO_OS_MACOSX)
38 #define PERFETTO_HAS_SIGNAL_H() 1
39 #else
40 #define PERFETTO_HAS_SIGNAL_H() 0
41 #endif
42
43 #if PERFETTO_BUILDFLAG(PERFETTO_STANDALONE_BUILD)
44 #include <linenoise.h>
45 #include <pwd.h>
46 #include <sys/types.h>
47 #include "perfetto_version.gen.h"
48 #else
49 #define PERFETTO_GET_GIT_REVISION() "unknown"
50 #endif
51
52 #if PERFETTO_HAS_SIGNAL_H()
53 #include <signal.h>
54 #endif
55
56 namespace perfetto {
57 namespace trace_processor {
58
59 namespace {
60 TraceProcessor* g_tp;
61
62 #if PERFETTO_BUILDFLAG(PERFETTO_STANDALONE_BUILD)
63
EnsureDir(const std::string & path)64 bool EnsureDir(const std::string& path) {
65 return mkdir(path.c_str(), 0755) != -1 || errno == EEXIST;
66 }
67
EnsureFile(const std::string & path)68 bool EnsureFile(const std::string& path) {
69 return base::OpenFile(path, O_RDONLY | O_CREAT, 0644).get() != -1;
70 }
71
GetConfigPath()72 std::string GetConfigPath() {
73 const char* homedir = getenv("HOME");
74 if (homedir == nullptr)
75 homedir = getpwuid(getuid())->pw_dir;
76 if (homedir == nullptr)
77 return "";
78 return std::string(homedir) + "/.config";
79 }
80
GetPerfettoPath()81 std::string GetPerfettoPath() {
82 std::string config = GetConfigPath();
83 if (config == "")
84 return "";
85 return config + "/perfetto";
86 }
87
GetHistoryPath()88 std::string GetHistoryPath() {
89 std::string perfetto = GetPerfettoPath();
90 if (perfetto == "")
91 return "";
92 return perfetto + "/.trace_processor_shell_history";
93 }
94
SetupLineEditor()95 void SetupLineEditor() {
96 linenoiseSetMultiLine(true);
97 linenoiseHistorySetMaxLen(1000);
98
99 bool success = GetHistoryPath() != "";
100 success = success && EnsureDir(GetConfigPath());
101 success = success && EnsureDir(GetPerfettoPath());
102 success = success && EnsureFile(GetHistoryPath());
103 success = success && linenoiseHistoryLoad(GetHistoryPath().c_str()) != -1;
104 if (!success) {
105 PERFETTO_PLOG("Could not load history from %s", GetHistoryPath().c_str());
106 }
107 }
108
FreeLine(char * line)109 void FreeLine(char* line) {
110 linenoiseHistoryAdd(line);
111 linenoiseHistorySave(GetHistoryPath().c_str());
112 linenoiseFree(line);
113 }
114
GetLine(const char * prompt)115 char* GetLine(const char* prompt) {
116 return linenoise(prompt);
117 }
118
119 #else
120
SetupLineEditor()121 void SetupLineEditor() {}
122
FreeLine(char * line)123 void FreeLine(char* line) {
124 delete[] line;
125 }
126
GetLine(const char * prompt)127 char* GetLine(const char* prompt) {
128 printf("\r%80s\r%s", "", prompt);
129 fflush(stdout);
130 char* line = new char[1024];
131 if (!fgets(line, 1024 - 1, stdin)) {
132 FreeLine(line);
133 return nullptr;
134 }
135 if (strlen(line) > 0)
136 line[strlen(line) - 1] = 0;
137 return line;
138 }
139
140 #endif
141
PrintStats()142 bool PrintStats() {
143 auto it = g_tp->ExecuteQuery(
144 "SELECT name, idx, source, value from stats "
145 "where severity = 'error' and value > 0");
146
147 bool first = true;
148 for (uint32_t rows = 0; it.Next(); rows++) {
149 if (first) {
150 fprintf(stderr, "Error stats for this trace:\n");
151
152 for (uint32_t i = 0; i < it.ColumnCount(); i++)
153 fprintf(stderr, "%40s ", it.GetColumName(i).c_str());
154 fprintf(stderr, "\n");
155
156 for (uint32_t i = 0; i < it.ColumnCount(); i++)
157 fprintf(stderr, "%40s ", "----------------------------------------");
158 fprintf(stderr, "\n");
159
160 first = false;
161 }
162
163 for (uint32_t c = 0; c < it.ColumnCount(); c++) {
164 auto value = it.Get(c);
165 switch (value.type) {
166 case SqlValue::Type::kNull:
167 fprintf(stderr, "%-40.40s", "[NULL]");
168 break;
169 case SqlValue::Type::kDouble:
170 fprintf(stderr, "%40f", value.double_value);
171 break;
172 case SqlValue::Type::kLong:
173 fprintf(stderr, "%40" PRIi64, value.long_value);
174 break;
175 case SqlValue::Type::kString:
176 fprintf(stderr, "%-40.40s", value.string_value);
177 break;
178 }
179 fprintf(stderr, " ");
180 }
181 fprintf(stderr, "\n");
182 }
183
184 if (base::Optional<std::string> opt_error = it.GetLastError()) {
185 PERFETTO_ELOG("Error while iterating stats %s", opt_error->c_str());
186 return false;
187 }
188 return true;
189 }
190
ExportTraceToDatabase(const std::string & output_name)191 int ExportTraceToDatabase(const std::string& output_name) {
192 PERFETTO_CHECK(output_name.find("'") == std::string::npos);
193 {
194 base::ScopedFile fd(base::OpenFile(output_name, O_CREAT | O_RDWR, 0600));
195 if (!fd) {
196 PERFETTO_PLOG("Failed to create file: %s", output_name.c_str());
197 return 1;
198 }
199 int res = ftruncate(fd.get(), 0);
200 PERFETTO_CHECK(res == 0);
201 }
202
203 std::string attach_sql =
204 "ATTACH DATABASE '" + output_name + "' AS perfetto_export";
205 auto attach_it = g_tp->ExecuteQuery(attach_sql);
206 bool attach_has_more = attach_it.Next();
207 PERFETTO_DCHECK(!attach_has_more);
208 if (base::Optional<std::string> opt_error = attach_it.GetLastError()) {
209 PERFETTO_ELOG("SQLite error: %s", opt_error->c_str());
210 return 1;
211 }
212
213 auto tables_it = g_tp->ExecuteQuery(
214 "SELECT name FROM perfetto_tables UNION "
215 "SELECT name FROM sqlite_master WHERE type='table'");
216 for (uint32_t rows = 0; tables_it.Next(); rows++) {
217 std::string table_name = tables_it.Get(0).string_value;
218 PERFETTO_CHECK(table_name.find("'") == std::string::npos);
219 std::string export_sql = "CREATE TABLE perfetto_export." + table_name +
220 " AS SELECT * FROM " + table_name;
221
222 auto export_it = g_tp->ExecuteQuery(export_sql);
223 bool export_has_more = export_it.Next();
224 PERFETTO_DCHECK(!export_has_more);
225 if (base::Optional<std::string> opt_error = export_it.GetLastError()) {
226 PERFETTO_ELOG("SQLite error: %s", opt_error->c_str());
227 return 1;
228 }
229 }
230 if (base::Optional<std::string> opt_error = tables_it.GetLastError()) {
231 PERFETTO_ELOG("SQLite error: %s", opt_error->c_str());
232 return 1;
233 }
234
235 auto detach_it = g_tp->ExecuteQuery("DETACH DATABASE perfetto_export");
236 bool detach_has_more = attach_it.Next();
237 PERFETTO_DCHECK(!detach_has_more);
238 if (base::Optional<std::string> opt_error = detach_it.GetLastError()) {
239 PERFETTO_ELOG("SQLite error: %s", opt_error->c_str());
240 return 1;
241 }
242 return 0;
243 }
244
RunMetrics(const std::vector<std::string> & metric_names)245 int RunMetrics(const std::vector<std::string>& metric_names) {
246 std::vector<uint8_t> metric_result;
247 int res = g_tp->ComputeMetric(metric_names, &metric_result);
248 if (res) {
249 PERFETTO_ELOG("Error when computing metrics");
250 return 1;
251 }
252 fwrite(metric_result.data(), sizeof(uint8_t), metric_result.size(), stdout);
253 return 0;
254 }
255
PrintQueryResultInteractively(TraceProcessor::Iterator * it,base::TimeNanos t_start)256 void PrintQueryResultInteractively(TraceProcessor::Iterator* it,
257 base::TimeNanos t_start) {
258 base::TimeNanos t_end = t_start;
259 for (uint32_t rows = 0; it->Next(); rows++) {
260 if (rows % 32 == 0) {
261 if (rows > 0) {
262 fprintf(stderr, "...\nType 'q' to stop, Enter for more records: ");
263 fflush(stderr);
264 char input[32];
265 if (!fgets(input, sizeof(input) - 1, stdin))
266 exit(0);
267 if (input[0] == 'q')
268 break;
269 } else {
270 t_end = base::GetWallTimeNs();
271 }
272 for (uint32_t i = 0; i < it->ColumnCount(); i++)
273 printf("%20s ", it->GetColumName(i).c_str());
274 printf("\n");
275
276 for (uint32_t i = 0; i < it->ColumnCount(); i++)
277 printf("%20s ", "--------------------");
278 printf("\n");
279 }
280
281 for (uint32_t c = 0; c < it->ColumnCount(); c++) {
282 auto value = it->Get(c);
283 switch (value.type) {
284 case SqlValue::Type::kNull:
285 printf("%-20.20s", "[NULL]");
286 break;
287 case SqlValue::Type::kDouble:
288 printf("%20f", value.double_value);
289 break;
290 case SqlValue::Type::kLong:
291 printf("%20" PRIi64, value.long_value);
292 break;
293 case SqlValue::Type::kString:
294 printf("%-20.20s", value.string_value);
295 break;
296 }
297 printf(" ");
298 }
299 printf("\n");
300 }
301
302 if (base::Optional<std::string> opt_error = it->GetLastError()) {
303 PERFETTO_ELOG("SQLite error: %s", opt_error->c_str());
304 }
305 printf("\nQuery executed in %.3f ms\n\n", (t_end - t_start).count() / 1E6);
306 }
307
PrintShellUsage()308 void PrintShellUsage() {
309 PERFETTO_ELOG(
310 "Available commands:\n"
311 ".quit, .q Exit the shell.\n"
312 ".help This text.\n"
313 ".dump FILE Export the trace as a sqlite database.\n");
314 }
315
StartInteractiveShell()316 int StartInteractiveShell() {
317 SetupLineEditor();
318
319 for (;;) {
320 char* line = GetLine("> ");
321 if (!line)
322 break;
323 if (strcmp(line, "") == 0)
324 continue;
325 if (line[0] == '.') {
326 char command[32] = {};
327 char arg[1024] = {};
328 sscanf(line + 1, "%31s %1023s", command, arg);
329 if (strcmp(command, "quit") == 0 || strcmp(command, "q") == 0) {
330 break;
331 } else if (strcmp(command, "help") == 0) {
332 PrintShellUsage();
333 } else if (strcmp(command, "dump") == 0 && strlen(arg)) {
334 if (ExportTraceToDatabase(arg) != 0)
335 PERFETTO_ELOG("Database export failed");
336 } else {
337 PrintShellUsage();
338 }
339 continue;
340 }
341
342 base::TimeNanos t_start = base::GetWallTimeNs();
343 auto it = g_tp->ExecuteQuery(line);
344 PrintQueryResultInteractively(&it, t_start);
345
346 FreeLine(line);
347 }
348 return 0;
349 }
350
PrintQueryResultAsCsv(TraceProcessor::Iterator * it,FILE * output)351 void PrintQueryResultAsCsv(TraceProcessor::Iterator* it, FILE* output) {
352 for (uint32_t c = 0; c < it->ColumnCount(); c++) {
353 if (c > 0)
354 fprintf(output, ",");
355 fprintf(output, "\"%s\"", it->GetColumName(c).c_str());
356 }
357 fprintf(output, "\n");
358
359 for (uint32_t rows = 0; it->Next(); rows++) {
360 for (uint32_t c = 0; c < it->ColumnCount(); c++) {
361 if (c > 0)
362 fprintf(output, ",");
363
364 auto value = it->Get(c);
365 switch (value.type) {
366 case SqlValue::Type::kNull:
367 fprintf(output, "\"%s\"", "[NULL]");
368 break;
369 case SqlValue::Type::kDouble:
370 fprintf(output, "%f", value.double_value);
371 break;
372 case SqlValue::Type::kLong:
373 fprintf(output, "%" PRIi64, value.long_value);
374 break;
375 case SqlValue::Type::kString:
376 fprintf(output, "\"%s\"", value.string_value);
377 break;
378 }
379 }
380 fprintf(output, "\n");
381 }
382 }
383
LoadQueries(FILE * input,std::vector<std::string> * output)384 bool LoadQueries(FILE* input, std::vector<std::string>* output) {
385 char buffer[4096];
386 while (!feof(input) && !ferror(input)) {
387 std::string sql_query;
388 while (fgets(buffer, sizeof(buffer), input)) {
389 if (strncmp(buffer, "\n", sizeof(buffer)) == 0)
390 break;
391 sql_query.append(buffer);
392 }
393 if (sql_query.back() == '\n')
394 sql_query.resize(sql_query.size() - 1);
395
396 // If we have a new line at the end of the file or an extra new line
397 // somewhere in the file, we'll end up with an empty query which we should
398 // just ignore.
399 if (sql_query.empty())
400 continue;
401
402 output->push_back(sql_query);
403 }
404 if (ferror(input)) {
405 PERFETTO_ELOG("Error reading query file");
406 return false;
407 }
408 return true;
409 }
410
RunQueryAndPrintResult(const std::vector<std::string> queries,FILE * output)411 bool RunQueryAndPrintResult(const std::vector<std::string> queries,
412 FILE* output) {
413 bool is_first_query = true;
414 bool is_query_error = false;
415 bool has_output = false;
416 for (const auto& sql_query : queries) {
417 // Add an extra newline separator between query results.
418 if (!is_first_query)
419 fprintf(output, "\n");
420 is_first_query = false;
421
422 PERFETTO_ILOG("Executing query: %s", sql_query.c_str());
423
424 auto it = g_tp->ExecuteQuery(sql_query);
425 if (base::Optional<std::string> opt_error = it.GetLastError()) {
426 PERFETTO_ELOG("SQLite error: %s", opt_error->c_str());
427 is_query_error = true;
428 break;
429 }
430 if (it.ColumnCount() == 0) {
431 bool it_has_more = it.Next();
432 PERFETTO_DCHECK(!it_has_more);
433 continue;
434 }
435
436 if (has_output) {
437 PERFETTO_ELOG(
438 "More than one query generated result rows. This is "
439 "unsupported.");
440 is_query_error = true;
441 break;
442 }
443 PrintQueryResultAsCsv(&it, output);
444 has_output = true;
445 }
446 return !is_query_error;
447 }
448
PrintUsage(char ** argv)449 void PrintUsage(char** argv) {
450 PERFETTO_ELOG(
451 "Interactive trace processor shell.\n"
452 "Usage: %s [OPTIONS] trace_file.pb\n\n"
453 "Options:\n"
454 " -d Enable virtual table debugging.\n"
455 " -s FILE Read and execute contents of file before "
456 "launching an interactive shell.\n"
457 " -q FILE Read and execute an SQL query from a file.\n"
458 " -e FILE Export the trace into a SQLite database.\n"
459 " --run-metrics x,y,z Runs a comma separated list of metrics and "
460 "prints the result as a TraceMetrics proto to stdout.\n",
461 argv[0]);
462 }
463
TraceProcessorMain(int argc,char ** argv)464 int TraceProcessorMain(int argc, char** argv) {
465 if (argc < 2) {
466 PrintUsage(argv);
467 return 1;
468 }
469 const char* trace_file_path = nullptr;
470 const char* query_file_path = nullptr;
471 const char* sqlite_file_path = nullptr;
472 const char* metric_names = nullptr;
473 bool launch_shell = true;
474 for (int i = 1; i < argc; i++) {
475 if (strcmp(argv[i], "-v") == 0 || strcmp(argv[i], "--version") == 0) {
476 printf("%s\n", PERFETTO_GET_GIT_REVISION());
477 exit(0);
478 }
479 if (strcmp(argv[i], "-d") == 0) {
480 EnableSQLiteVtableDebugging();
481 continue;
482 }
483 if (strcmp(argv[i], "-q") == 0 || strcmp(argv[i], "-s") == 0) {
484 launch_shell = strcmp(argv[i], "-s") == 0;
485 if (++i == argc) {
486 PrintUsage(argv);
487 return 1;
488 }
489 query_file_path = argv[i];
490 continue;
491 } else if (strcmp(argv[i], "-e") == 0) {
492 if (++i == argc) {
493 PrintUsage(argv);
494 return 1;
495 }
496 sqlite_file_path = argv[i];
497 continue;
498 } else if (strcmp(argv[i], "--run-metrics") == 0) {
499 if (++i == argc) {
500 PrintUsage(argv);
501 return 1;
502 }
503 metric_names = argv[i];
504 continue;
505 } else if (strcmp(argv[i], "-h") == 0 || strcmp(argv[i], "--help") == 0) {
506 PrintUsage(argv);
507 return 0;
508 } else if (argv[i][0] == '-') {
509 PERFETTO_ELOG("Unknown option: %s", argv[i]);
510 return 1;
511 }
512 trace_file_path = argv[i];
513 }
514
515 if (trace_file_path == nullptr) {
516 PrintUsage(argv);
517 return 1;
518 }
519
520 // Load the trace file into the trace processor.
521 Config config;
522 std::unique_ptr<TraceProcessor> tp = TraceProcessor::CreateInstance(config);
523 base::ScopedFile fd(base::OpenFile(trace_file_path, O_RDONLY));
524 if (!fd) {
525 PERFETTO_ELOG("Could not open trace file (path: %s)", trace_file_path);
526 return 1;
527 }
528
529 // Load the trace in chunks using async IO. We create a simple pipeline where,
530 // at each iteration, we parse the current chunk and asynchronously start
531 // reading the next chunk.
532
533 // 1MB chunk size seems the best tradeoff on a MacBook Pro 2013 - i7 2.8 GHz.
534 constexpr size_t kChunkSize = 1024 * 1024;
535 struct aiocb cb {};
536 cb.aio_nbytes = kChunkSize;
537 cb.aio_fildes = *fd;
538
539 std::unique_ptr<uint8_t[]> aio_buf(new uint8_t[kChunkSize]);
540 #if defined(MEMORY_SANITIZER)
541 // Just initialize the memory to make the memory sanitizer happy as it
542 // cannot track aio calls below.
543 memset(aio_buf.get(), 0, kChunkSize);
544 #endif
545 cb.aio_buf = aio_buf.get();
546
547 PERFETTO_CHECK(aio_read(&cb) == 0);
548 struct aiocb* aio_list[1] = {&cb};
549
550 uint64_t file_size = 0;
551 auto t_load_start = base::GetWallTimeMs();
552 for (int i = 0;; i++) {
553 if (i % 128 == 0)
554 fprintf(stderr, "\rLoading trace: %.2f MB\r", file_size / 1E6);
555
556 // Block waiting for the pending read to complete.
557 PERFETTO_CHECK(aio_suspend(aio_list, 1, nullptr) == 0);
558 auto rsize = aio_return(&cb);
559 if (rsize <= 0)
560 break;
561 file_size += static_cast<uint64_t>(rsize);
562
563 // Take ownership of the completed buffer and enqueue a new async read
564 // with a fresh buffer.
565 std::unique_ptr<uint8_t[]> buf(std::move(aio_buf));
566 aio_buf.reset(new uint8_t[kChunkSize]);
567 #if defined(MEMORY_SANITIZER)
568 // Just initialize the memory to make the memory sanitizer happy as it
569 // cannot track aio calls below.
570 memset(aio_buf.get(), 0, kChunkSize);
571 #endif
572 cb.aio_buf = aio_buf.get();
573 cb.aio_offset += rsize;
574 PERFETTO_CHECK(aio_read(&cb) == 0);
575
576 // Parse the completed buffer while the async read is in-flight.
577 tp->Parse(std::move(buf), static_cast<size_t>(rsize));
578 }
579 tp->NotifyEndOfFile();
580 double t_load = (base::GetWallTimeMs() - t_load_start).count() / 1E3;
581 double size_mb = file_size / 1E6;
582 PERFETTO_ILOG("Trace loaded: %.2f MB (%.1f MB/s)", size_mb, size_mb / t_load);
583 g_tp = tp.get();
584
585 #if PERFETTO_HAS_SIGNAL_H()
586 signal(SIGINT, [](int) { g_tp->InterruptQuery(); });
587 #endif
588
589 // Print out the stats to stderr for the trace.
590 if (!PrintStats()) {
591 return 1;
592 }
593
594 // First, see if we have some metrics to run. If we do, just run them and
595 // return.
596 if (metric_names) {
597 std::vector<std::string> metrics;
598 for (base::StringSplitter ss(metric_names, ','); ss.Next();) {
599 metrics.emplace_back(ss.cur_token());
600 }
601 return RunMetrics(std::move(metrics));
602 }
603
604 // If we were given a query file, load contents
605 std::vector<std::string> queries;
606 if (query_file_path) {
607 base::ScopedFstream file(fopen(query_file_path, "r"));
608 if (!file) {
609 PERFETTO_ELOG("Could not open query file (path: %s)", query_file_path);
610 return 1;
611 }
612 if (!LoadQueries(file.get(), &queries)) {
613 return 1;
614 }
615 }
616
617 if (!RunQueryAndPrintResult(queries, stdout)) {
618 return 1;
619 }
620
621 // After this we can dump the database and exit if needed.
622 if (sqlite_file_path) {
623 return ExportTraceToDatabase(sqlite_file_path);
624 }
625
626 // If we ran an automated query, exit.
627 if (!launch_shell) {
628 return 0;
629 }
630
631 // Otherwise start an interactive shell.
632 return StartInteractiveShell();
633 }
634
635 } // namespace
636
637 } // namespace trace_processor
638 } // namespace perfetto
639
main(int argc,char ** argv)640 int main(int argc, char** argv) {
641 return perfetto::trace_processor::TraceProcessorMain(argc, argv);
642 }
643