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 64 bool EnsureDir(const std::string& path) { 65 return mkdir(path.c_str(), 0755) != -1 || errno == EEXIST; 66 } 67 68 bool EnsureFile(const std::string& path) { 69 return base::OpenFile(path, O_RDONLY | O_CREAT, 0644).get() != -1; 70 } 71 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 81 std::string GetPerfettoPath() { 82 std::string config = GetConfigPath(); 83 if (config == "") 84 return ""; 85 return config + "/perfetto"; 86 } 87 88 std::string GetHistoryPath() { 89 std::string perfetto = GetPerfettoPath(); 90 if (perfetto == "") 91 return ""; 92 return perfetto + "/.trace_processor_shell_history"; 93 } 94 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 109 void FreeLine(char* line) { 110 linenoiseHistoryAdd(line); 111 linenoiseHistorySave(GetHistoryPath().c_str()); 112 linenoiseFree(line); 113 } 114 115 char* GetLine(const char* prompt) { 116 return linenoise(prompt); 117 } 118 119 #else 120 121 void SetupLineEditor() {} 122 123 void FreeLine(char* line) { 124 delete[] line; 125 } 126 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 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 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 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 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 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 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 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 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 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 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 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 640 int main(int argc, char** argv) { 641 return perfetto::trace_processor::TraceProcessorMain(argc, argv); 642 } 643