Don't use suspend all scope when dumping low overhead traces

We used to use SuspendAll scope when dumping the low overhead traces for
all methods. It is better to use Checkpoints instead of suspend all
scope. Dumping data is reasonably large and suspending all threads for
that long could cause timeouts and ANRs.

Bug: 352518093
Test: Manual testing

Change-Id: I42af633f776a56e162bafaa14b25b881697b7362

2 files changed, 64 insertions, 123 deletions

diff --git a/runtime/trace_profile.cc b/runtime/trace_profile.cc
index 5768022dc2..2fcf475b80 100644
--- a/runtime/trace_profile.cc
+++ b/runtime/trace_profile.cc
@@ -315,10 +315,10 @@ void TraceProfiler::StopLocked() {
   trace_data_ = nullptr;
 }
 
-uint8_t* TraceProfiler::DumpBuffer(uint32_t thread_id,
-                                   uintptr_t* method_trace_entries,
-                                   uint8_t* buffer,
-                                   std::unordered_set<ArtMethod*>& methods) {
+size_t TraceProfiler::DumpBuffer(uint32_t thread_id,
+                                 uintptr_t* method_trace_entries,
+                                 uint8_t* buffer,
+                                 std::unordered_set<ArtMethod*>& methods) {
   // Encode header at the end once we compute the number of records.
   uint8_t* curr_buffer_ptr = buffer + kAlwaysOnTraceHeaderSize;
 
@@ -362,7 +362,7 @@ uint8_t* TraceProfiler::DumpBuffer(uint32_t thread_id,
   buffer[0] = kEntryHeaderV2;
   Append4LE(buffer + 1, thread_id);
   Append3LE(buffer + 5, num_records);
-  return curr_buffer_ptr;
+  return curr_buffer_ptr - buffer;
 }
 
 void TraceProfiler::Dump(int fd) {
@@ -372,7 +372,8 @@ void TraceProfiler::Dump(int fd) {
   }
 
   std::unique_ptr<File> trace_file(new File(fd, /*check_usage=*/true));
-  Dump(std::move(trace_file));
+  std::ostringstream os;
+  Dump(std::move(trace_file), os);
 }
 
 void TraceProfiler::Dump(const char* filename) {
@@ -387,80 +388,39 @@ void TraceProfiler::Dump(const char* filename) {
     return;
   }
 
-  Dump(std::move(trace_file));
+  std::ostringstream os;
+  Dump(std::move(trace_file), os);
 }
 
-void TraceProfiler::Dump(std::unique_ptr<File>&& trace_file) {
+void TraceProfiler::Dump(std::unique_ptr<File>&& trace_file, std::ostringstream& os) {
   MutexLock mu(Thread::Current(), *Locks::trace_lock_);
   if (!profile_in_progress_) {
-    LOG(ERROR) << "No Profile in progress. Nothing to dump.";
+    if (trace_file != nullptr && !trace_file->Close()) {
+      PLOG(WARNING) << "Failed to close file.";
+    }
     return;
   }
 
-  if (trace_data_->GetTraceType() == LowOverheadTraceType::kAllMethods) {
-    DumpTrace(std::move(trace_file));
-  } else {
-    DumpLongRunningMethods(std::move(trace_file));
-  }
-}
-
-void TraceProfiler::DumpTrace(std::unique_ptr<File>&& trace_file) {
   Thread* self = Thread::Current();
-  std::unordered_set<ArtMethod*> traced_methods;
-  std::unordered_map<size_t, std::string> traced_threads;
-  uint8_t* buffer_ptr = new uint8_t[kBufSizeForEncodedData];
-  uint8_t* curr_buffer_ptr = buffer_ptr;
-
-  // Add a header for the trace: 4-bits of magic value and 2-bits for the version.
-  Append4LE(curr_buffer_ptr, kProfileMagicValue);
-  Append2LE(curr_buffer_ptr + 4, /*trace_version=*/ 1);
-  curr_buffer_ptr += 6;
-
-  ScopedSuspendAll ssa(__FUNCTION__);
-  MutexLock tl(self, *Locks::thread_list_lock_);
-  for (Thread* thread : Runtime::Current()->GetThreadList()->GetList()) {
-    auto method_trace_entries = thread->GetMethodTraceBuffer();
-    if (method_trace_entries == nullptr) {
-      continue;
-    }
-
-    std::string thread_name;
-    thread->GetThreadName(thread_name);
-    traced_threads.emplace(thread->GetTid(), thread_name);
+  // Collect long running methods from all the threads;
+  Runtime* runtime = Runtime::Current();
 
-    size_t offset = curr_buffer_ptr - buffer_ptr;
-    if (offset >= kMinBufSizeForEncodedData) {
-      if (!trace_file->WriteFully(buffer_ptr, offset)) {
-        PLOG(WARNING) << "Failed streaming a tracing event.";
-      }
-      curr_buffer_ptr = buffer_ptr;
-    }
-    curr_buffer_ptr =
-        DumpBuffer(thread->GetTid(), method_trace_entries, curr_buffer_ptr, traced_methods);
-    // Reset the buffer and continue profiling. We need to set the buffer to
-    // zeroes, since we use a circular buffer and detect empty entries by
-    // checking for zeroes.
-    memset(method_trace_entries, 0, kAlwaysOnTraceBufSize * sizeof(uintptr_t));
-    // Reset the current pointer.
-    thread->SetMethodTraceBufferCurrentEntry(kAlwaysOnTraceBufSize);
-  }
-
-  // Write any remaining data to file and close the file.
-  if (curr_buffer_ptr != buffer_ptr) {
-    if (!trace_file->WriteFully(buffer_ptr, curr_buffer_ptr - buffer_ptr)) {
-      PLOG(WARNING) << "Failed streaming a tracing event.";
-    }
+  TraceDumpCheckpoint checkpoint(trace_data_, trace_file);
+  size_t threads_running_checkpoint = runtime->GetThreadList()->RunCheckpoint(&checkpoint);
+  if (threads_running_checkpoint != 0) {
+    checkpoint.WaitForThreadsToRunThroughCheckpoint(threads_running_checkpoint);
   }
 
-  std::ostringstream os;
-  DumpThreadMethodInfo(traced_threads, traced_methods, os);
-  std::string info = os.str();
-  if (!trace_file->WriteFully(info.c_str(), info.length())) {
-    PLOG(WARNING) << "Failed writing information to file";
-  }
+  trace_data_->DumpData(os);
+  if (trace_file != nullptr) {
+    std::string info = os.str();
+    if (!trace_file->WriteFully(info.c_str(), info.length())) {
+      PLOG(WARNING) << "Failed writing information to file";
+    }
 
-  if (!trace_file->Close()) {
-    PLOG(WARNING) << "Failed to close file.";
+    if (!trace_file->Close()) {
+      PLOG(WARNING) << "Failed to close file.";
+    }
   }
 }
 
@@ -595,25 +555,32 @@ std::string TraceProfiler::GetLongRunningMethodsString() {
     return std::string();
   }
 
-  MutexLock mu(Thread::Current(), *Locks::trace_lock_);
-  if (!profile_in_progress_) {
-    return std::string();
-  }
-
-  return GetLongRunningMethodsStringLocked();
+  std::ostringstream os;
+  Dump(std::unique_ptr<File>(), os);
+  return os.str();
 }
 
 void TraceDumpCheckpoint::Run(Thread* thread) {
   auto method_trace_entries = thread->GetMethodTraceBuffer();
   if (method_trace_entries != nullptr) {
     std::unordered_set<ArtMethod*> traced_methods;
-    uintptr_t* method_trace_curr_ptr = *(thread->GetTraceBufferCurrEntryPtr());
-    std::ostringstream os;
-    TraceProfiler::DumpLongRunningMethodBuffer(
-        thread->GetTid(), method_trace_entries, method_trace_curr_ptr, traced_methods, os);
+    if (trace_data_->GetTraceType() == LowOverheadTraceType::kLongRunningMethods) {
+      uintptr_t* method_trace_curr_ptr = *(thread->GetTraceBufferCurrEntryPtr());
+      std::ostringstream os;
+      TraceProfiler::DumpLongRunningMethodBuffer(
+          thread->GetTid(), method_trace_entries, method_trace_curr_ptr, traced_methods, os);
+      trace_data_->AppendToLongRunningMethods(os.str());
+    } else {
+      std::unique_ptr<uint8_t> buffer_ptr(new uint8_t[kBufSizeForEncodedData]);
+      size_t num_bytes = TraceProfiler::DumpBuffer(
+          thread->GetTid(), method_trace_entries, buffer_ptr.get(), traced_methods);
+      MutexLock mu(Thread::Current(), trace_file_lock_);
+      if (!trace_file_->WriteFully(buffer_ptr.get(), num_bytes)) {
+        PLOG(WARNING) << "Failed streaming a tracing event.";
+      }
+    }
     trace_data_->AddTracedThread(thread);
     trace_data_->AddTracedMethods(traced_methods);
-    trace_data_->AppendToLongRunningMethods(os.str());
   }
   barrier_.Pass(Thread::Current());
 }
@@ -624,21 +591,6 @@ void TraceDumpCheckpoint::WaitForThreadsToRunThroughCheckpoint(size_t threads_ru
   barrier_.Increment(self, threads_running_checkpoint);
 }
 
-std::string TraceProfiler::GetLongRunningMethodsStringLocked() {
-  Thread* self = Thread::Current();
-  std::ostringstream os;
-  // Collect long running methods from all the threads;
-  Runtime* runtime = Runtime::Current();
-  TraceDumpCheckpoint checkpoint(trace_data_);
-  size_t threads_running_checkpoint = runtime->GetThreadList()->RunCheckpoint(&checkpoint);
-  if (threads_running_checkpoint != 0) {
-    checkpoint.WaitForThreadsToRunThroughCheckpoint(threads_running_checkpoint);
-  }
-
-  trace_data_->DumpData(os);
-  return os.str();
-}
-
 void TraceData::DumpData(std::ostringstream& os) {
   MutexLock mu(Thread::Current(), trace_data_lock_);
   if (long_running_methods_.length() > 0) {
@@ -652,15 +604,4 @@ void TraceData::DumpData(std::ostringstream& os) {
   }
 }
 
-void TraceProfiler::DumpLongRunningMethods(std::unique_ptr<File>&& trace_file) {
-  std::string info = GetLongRunningMethodsStringLocked();
-  if (!trace_file->WriteFully(info.c_str(), info.length())) {
-    PLOG(WARNING) << "Failed writing information to file";
-  }
-
-  if (!trace_file->Close()) {
-    PLOG(WARNING) << "Failed to close file.";
-  }
-}
-
 }  // namespace art
diff --git a/runtime/trace_profile.h b/runtime/trace_profile.h
index 6b6588fb3f..24883b217e 100644
--- a/runtime/trace_profile.h
+++ b/runtime/trace_profile.h
@@ -107,7 +107,11 @@ class TraceData {
 
 class TraceDumpCheckpoint final : public Closure {
  public:
-  explicit TraceDumpCheckpoint(TraceData* trace_data) : barrier_(0), trace_data_(trace_data) {}
+  TraceDumpCheckpoint(TraceData* trace_data, const std::unique_ptr<File>& trace_file)
+      : barrier_(0),
+        trace_data_(trace_data),
+        trace_file_(trace_file),
+        trace_file_lock_("trace file lock", LockLevel::kGenericBottomLock) {}
 
   void Run(Thread* thread) override REQUIRES_SHARED(Locks::mutator_lock_);
   void WaitForThreadsToRunThroughCheckpoint(size_t threads_running_checkpoint);
@@ -118,6 +122,13 @@ class TraceDumpCheckpoint final : public Closure {
 
   // Trace data to record the data from each thread.
   TraceData* trace_data_;
+
+  // Trace file to flush the data.
+  const std::unique_ptr<File>& trace_file_ GUARDED_BY(trace_file_lock_);
+
+  // Lock to synchronize access to trace_file_. We need to write the data of
+  // each thread as a block so we hold a lock while flushing the data.
+  Mutex trace_file_lock_;
 };
 
 // This class implements low-overhead tracing. This feature is available only when
@@ -172,31 +183,20 @@ class TraceProfiler {
   static void Start(LowOverheadTraceType trace_type, uint64_t trace_duration_ns);
 
   // Dumps the tracing data into the specified trace_file
-  static void Dump(std::unique_ptr<File>&& trace_file);
+  static void Dump(std::unique_ptr<File>&& trace_file, std::ostringstream& os);
 
   // Stops tracing.
   static void StopLocked() REQUIRES(Locks::trace_lock_);
 
-  // Returns the information about long running methods as a string. Used both by Dump
-  // and GetLongRunningMethodsString.
-  static std::string GetLongRunningMethodsStringLocked() REQUIRES(Locks::trace_lock_);
-
-  // Dumps the events from all threads into the trace_file.
-  static void DumpTrace(std::unique_ptr<File>&& trace_file) REQUIRES(Locks::trace_lock_);
-
-  // Dumps the long running methods from all threads into the trace_file.
-  static void DumpLongRunningMethods(std::unique_ptr<File>&& trace_file)
-      REQUIRES(Locks::trace_lock_);
-
   // This method goes over all the events in the thread_buffer and stores the encoded event in the
-  // buffer. It returns the pointer to the next free entry in the buffer.
+  // buffer. It returns the number of bytes written into the buffer.
   // This also records the ArtMethods from the events in the thread_buffer in a set. This set is
   // used to dump the information about the methods once buffers from all threads have been
   // processed.
-  static uint8_t* DumpBuffer(uint32_t thread_id,
-                             uintptr_t* thread_buffer,
-                             uint8_t* buffer /* out */,
-                             std::unordered_set<ArtMethod*>& methods /* out */);
+  static size_t DumpBuffer(uint32_t thread_id,
+                           uintptr_t* thread_buffer,
+                           uint8_t* buffer /* out */,
+                           std::unordered_set<ArtMethod*>& methods /* out */);
 
   // Dumps all the events in the buffer into the file. Also records the ArtMethods from the events
   // which is then used to record information about these methods.