[aapt2] Fix and optimize tracing

- Make it log the tags for both begin and end events, otherwise
  visualizations can't calculate the duration

- Wrap the whole file in a JSON array to make Perfetto open it

- Switch the whole thing off when not enabled, don't waste
  cycles on adding events.

Bug: 294025081
Test: manual tracing run
Change-Id: I42d0fa5518190783c4d58a644f783ac6e7dcd1a3

2 files changed, 98 insertions, 67 deletions

diff --git a/tools/aapt2/trace/TraceBuffer.cpp b/tools/aapt2/trace/TraceBuffer.cpp
index da5373936306..fab2df383e3f 100644
--- a/tools/aapt2/trace/TraceBuffer.cpp
+++ b/tools/aapt2/trace/TraceBuffer.cpp
@@ -36,13 +36,14 @@ constexpr char kBegin = 'B';
 constexpr char kEnd = 'E';
 
 struct TracePoint {
+  char type;
   pid_t tid;
   int64_t time;
   std::string tag;
-  char type;
 };
 
 std::vector<TracePoint> traces;
+bool enabled = true;
 
 int64_t GetTime() noexcept {
   auto now = std::chrono::steady_clock::now();
@@ -51,34 +52,39 @@ int64_t GetTime() noexcept {
 
 } // namespace anonymous
 
-void AddWithTime(const std::string& tag, char type, int64_t time) noexcept {
-  TracePoint t = {getpid(), time, tag, type};
-  traces.emplace_back(t);
+void AddWithTime(std::string tag, char type, int64_t time) noexcept {
+  TracePoint t = {type, getpid(), time, std::move(tag)};
+  traces.emplace_back(std::move(t));
 }
 
-void Add(const std::string& tag, char type) noexcept {
-  AddWithTime(tag, type, GetTime());
+void Add(std::string tag, char type) noexcept {
+  AddWithTime(std::move(tag), type, GetTime());
 }
 
-
-
-
 void Flush(const std::string& basePath) {
-  TRACE_CALL();
   if (basePath.empty()) {
     return;
   }
+  BeginTrace(__func__);  // We can't do much here, only record that it happened.
 
-  std::stringstream s;
+  std::ostringstream s;
   s << basePath << aapt::file::sDirSep << "report_aapt2_" << getpid() << ".json";
   FILE* f = android::base::utf8::fopen(s.str().c_str(), "a");
   if (f == nullptr) {
     return;
   }
 
+  // Wrap the trace in a JSON array [] to make Chrome/Perfetto UI handle it.
+  char delimiter = '[';
   for(const TracePoint& trace : traces) {
-    fprintf(f, "{\"ts\" : \"%" PRIu64 "\", \"ph\" : \"%c\", \"tid\" : \"%d\" , \"pid\" : \"%d\", "
-            "\"name\" : \"%s\" },\n", trace.time, trace.type, 0, trace.tid, trace.tag.c_str());
+    fprintf(f,
+            "%c{\"ts\" : \"%" PRIu64
+            "\", \"ph\" : \"%c\", \"tid\" : \"%d\" , \"pid\" : \"%d\", \"name\" : \"%s\" }\n",
+            delimiter, trace.time, trace.type, 0, trace.tid, trace.tag.c_str());
+    delimiter = ',';
+  }
+  if (!traces.empty()) {
+    fprintf(f, "]");
   }
   fclose(f);
   traces.clear();
@@ -86,66 +92,82 @@ void Flush(const std::string& basePath) {
 
 } // namespace tracebuffer
 
-void BeginTrace(const std::string& tag) {
-  tracebuffer::Add(tag, tracebuffer::kBegin);
+void BeginTrace(std::string tag) {
+  if (!tracebuffer::enabled) return;
+  tracebuffer::Add(std::move(tag), tracebuffer::kBegin);
+}
+
+void EndTrace(std::string tag) {
+  if (!tracebuffer::enabled) return;
+  tracebuffer::Add(std::move(tag), tracebuffer::kEnd);
 }
 
-void EndTrace() {
-  tracebuffer::Add("", tracebuffer::kEnd);
+bool Trace::enable(bool value) {
+  return tracebuffer::enabled = value;
 }
 
-Trace::Trace(const std::string& tag) {
-  tracebuffer::Add(tag, tracebuffer::kBegin);
+Trace::Trace(const char* tag) {
+  if (!tracebuffer::enabled) return;
+  tag_.assign(tag);
+  tracebuffer::Add(tag_, tracebuffer::kBegin);
 }
 
-Trace::Trace(const std::string& tag, const std::vector<android::StringPiece>& args) {
-  std::stringstream s;
+Trace::Trace(std::string tag) : tag_(std::move(tag)) {
+  if (!tracebuffer::enabled) return;
+  tracebuffer::Add(tag_, tracebuffer::kBegin);
+}
+
+template <class SpanOfStrings>
+std::string makeTag(std::string_view tag, const SpanOfStrings& args) {
+  std::ostringstream s;
   s << tag;
-  s << " ";
-  for (auto& arg : args) {
-    s << arg;
-    s << " ";
+  if (!args.empty()) {
+    for (const auto& arg : args) {
+      s << ' ';
+      s << arg;
+    }
   }
-  tracebuffer::Add(s.str(), tracebuffer::kBegin);
+  return std::move(s).str();
+}
+
+Trace::Trace(std::string_view tag, const std::vector<android::StringPiece>& args) {
+  if (!tracebuffer::enabled) return;
+  tag_ = makeTag(tag, args);
+  tracebuffer::Add(tag_, tracebuffer::kBegin);
 }
 
 Trace::~Trace() {
-  tracebuffer::Add("", tracebuffer::kEnd);
+  if (!tracebuffer::enabled) return;
+  tracebuffer::Add(std::move(tag_), tracebuffer::kEnd);
 }
 
-FlushTrace::FlushTrace(const std::string& basepath, const std::string& tag)
-    : basepath_(basepath)  {
-  tracebuffer::Add(tag, tracebuffer::kBegin);
+FlushTrace::FlushTrace(std::string_view basepath, std::string_view tag) {
+  if (!Trace::enable(!basepath.empty())) return;
+  basepath_.assign(basepath);
+  tag_.assign(tag);
+  tracebuffer::Add(tag_, tracebuffer::kBegin);
 }
 
-FlushTrace::FlushTrace(const std::string& basepath, const std::string& tag,
-    const std::vector<android::StringPiece>& args) : basepath_(basepath) {
-  std::stringstream s;
-  s << tag;
-  s << " ";
-  for (auto& arg : args) {
-    s << arg;
-    s << " ";
-  }
-  tracebuffer::Add(s.str(), tracebuffer::kBegin);
+FlushTrace::FlushTrace(std::string_view basepath, std::string_view tag,
+                       const std::vector<android::StringPiece>& args) {
+  if (!Trace::enable(!basepath.empty())) return;
+  basepath_.assign(basepath);
+  tag_ = makeTag(tag, args);
+  tracebuffer::Add(tag_, tracebuffer::kBegin);
 }
 
-FlushTrace::FlushTrace(const std::string& basepath, const std::string& tag,
-    const std::vector<std::string>& args) : basepath_(basepath){
-  std::stringstream s;
-  s << tag;
-  s << " ";
-  for (auto& arg : args) {
-    s << arg;
-    s << " ";
-  }
-  tracebuffer::Add(s.str(), tracebuffer::kBegin);
+FlushTrace::FlushTrace(std::string_view basepath, std::string_view tag,
+                       const std::vector<std::string>& args) {
+  if (!Trace::enable(!basepath.empty())) return;
+  basepath_.assign(basepath);
+  tag_ = makeTag(tag, args);
+  tracebuffer::Add(tag_, tracebuffer::kBegin);
 }
 
 FlushTrace::~FlushTrace() {
-  tracebuffer::Add("", tracebuffer::kEnd);
+  if (!tracebuffer::enabled) return;
+  tracebuffer::Add(tag_, tracebuffer::kEnd);
   tracebuffer::Flush(basepath_);
 }
 
-} // namespace aapt
-
+}  // namespace aapt
diff --git a/tools/aapt2/trace/TraceBuffer.h b/tools/aapt2/trace/TraceBuffer.h
index ba751dd72f41..f0333d1fe071 100644
--- a/tools/aapt2/trace/TraceBuffer.h
+++ b/tools/aapt2/trace/TraceBuffer.h
@@ -17,41 +17,50 @@
 #ifndef AAPT_TRACEBUFFER_H
 #define AAPT_TRACEBUFFER_H
 
+#include <androidfw/StringPiece.h>
+
 #include <string>
+#include <string_view>
 #include <vector>
 
-#include <androidfw/StringPiece.h>
-
 namespace aapt {
 
 // Record timestamps for beginning and end of a task and generate systrace json fragments.
 // This is an in-process ftrace which has the advantage of being platform independent.
 // These methods are NOT thread-safe since aapt2 is not multi-threaded.
 
-// Convenience RIAA object to automatically finish an event when object goes out of scope.
+// Convenience RAII object to automatically finish an event when object goes out of scope.
 class Trace {
 public:
-  Trace(const std::string& tag);
-  Trace(const std::string& tag, const std::vector<android::StringPiece>& args);
-  ~Trace();
+ Trace(const char* tag);
+ Trace(std::string tag);
+ Trace(std::string_view tag, const std::vector<android::StringPiece>& args);
+ ~Trace();
+
+ static bool enable(bool value = true);
+
+private:
+ std::string tag_;
 };
 
 // Manual markers.
-void BeginTrace(const std::string& tag);
-void EndTrace();
+void BeginTrace(std::string tag);
+void EndTrace(std::string tag);
 
 // A main trace is required to flush events to disk. Events are formatted in systrace
 // json format.
 class FlushTrace {
 public:
-  explicit FlushTrace(const std::string& basepath, const std::string& tag);
-  explicit FlushTrace(const std::string& basepath, const std::string& tag,
-      const std::vector<android::StringPiece>& args);
-  explicit FlushTrace(const std::string& basepath, const std::string& tag,
-      const std::vector<std::string>& args);
-  ~FlushTrace();
+ explicit FlushTrace(std::string_view basepath, std::string_view tag);
+ explicit FlushTrace(std::string_view basepath, std::string_view tag,
+                     const std::vector<android::StringPiece>& args);
+ explicit FlushTrace(std::string_view basepath, std::string_view tag,
+                     const std::vector<std::string>& args);
+ ~FlushTrace();
+
 private:
   std::string basepath_;
+  std::string tag_;
 };
 
 #define TRACE_CALL() Trace __t(__func__)