[XRay] [compiler-rt] make sure single threaded programs get traced too

[pelikan]

Summary

When the XRay user calls the API to finish writing the log, the thread
which is calling the API still hasn't finished and therefore won't get
its trace written. Add a test for only the main thread to check this.

[dberris]

lib/xray/xray_fdr_logging.cc

119–127 ↗

(On Diff #117478)

Shouldn't this happen before we write out the data instead, so we don't need to do a special write here?

test/xray/TestCases/Linux/fdr-single-thread.cc

2 ↗

(On Diff #117478)

Consider breaking these up with slashes:

// RUN: ... \
// RUN:     ... \
// RUN:     ...

[pelikan]

break up RUN: lines in the test

lib/xray/xray_fdr_logging.cc

119–127 ↗

(On Diff #117478)

That write will only be triggered if the second member of the tuple is true, which may or may not be the case. Hence the explicit write in an "if this thread needs it".

(Your question makes sense and I had it like that at first. It didn't work, though.)

test/xray/TestCases/Linux/fdr-single-thread.cc

2 ↗

(On Diff #117478)

I've also removed the "TRACE" thing when there's a perfectly sensible default.

[dberris]

LGTM

compiler-rt/trunk/lib/xray/xray_fdr_logging.cc

XRayLogFlushStatus fdrLoggingFlush() XRAY_NEVER_INSTRUMENT {
 
   LocalBQ->apply([&](const BufferQueue::Buffer &B) {
     uint64_t BufferSize = B.Size;
     if (BufferSize > 0) {
       retryingWriteAll(Fd, reinterpret_cast<char *>(B.Buffer),
                        reinterpret_cast<char *>(B.Buffer) + B.Size);
     }
   });
+
+  // The buffer for this particular thread would have been finalised after
+  // we've written everything to disk, and we'd lose the thread's trace.
+  auto &TLD = __xray::__xray_fdr_internal::getThreadLocalData();
+  if (TLD.Buffer.Buffer != nullptr) {
+    __xray::__xray_fdr_internal::writeEOBMetadata();
+    auto Start = reinterpret_cast<char *>(TLD.Buffer.Buffer);
+    retryingWriteAll(Fd, Start, Start + TLD.Buffer.Size);
+  }
+
   __sanitizer::atomic_store(&LogFlushStatus,
                             XRayLogFlushStatus::XRAY_LOG_FLUSHED,
                             __sanitizer::memory_order_release);
   return XRayLogFlushStatus::XRAY_LOG_FLUSHED;
 }
 
 XRayLogInitStatus fdrLoggingFinalize() XRAY_NEVER_INSTRUMENT {
   s32 CurrentStatus = XRayLogInitStatus::XRAY_LOG_INITIALIZED;

compiler-rt/trunk/test/xray/TestCases/Linux/fdr-single-thread.cc

+// RUN: %clangxx_xray -g -std=c++11 %s -o %t
+// RUN: XRAY_OPTIONS=XRAY_OPTIONS="verbosity=1 patch_premain=true \
+// RUN:   xray_naive_log=false xray_fdr_log=true \
+// RUN:   xray_fdr_log_func_duration_threshold_us=0 \
+// RUN:   xray_logfile_base=fdr-logging-1thr-" %run %t 2>&1
+// RUN: %llvm_xray convert --output-format=yaml --symbolize --instr_map=%t \
+// RUN:   "`ls fdr-logging-1thr-* | head -n1`" | FileCheck %s
+// RUN: rm fdr-logging-1thr-*
+//
+// REQUIRES: x86_64-linux
+
+#include "xray/xray_log_interface.h"
+#include <cassert>
+
+constexpr auto kBufferSize = 16384;
+constexpr auto kBufferMax = 10;
+
+[[clang::xray_always_instrument]] void __attribute__((noinline)) fn() { }
+
+int main(int argc, char *argv[]) {
+  using namespace __xray;
+  FDRLoggingOptions Opts;
+
+  auto status = __xray_log_init(kBufferSize, kBufferMax, &Opts, sizeof(Opts));
+  assert(status == XRayLogInitStatus::XRAY_LOG_INITIALIZED);
+
+  __xray_patch();
+  fn();
+  __xray_unpatch();
+  assert(__xray_log_finalize() == XRAY_LOG_FINALIZED);
+  assert(__xray_log_flushLog() == XRAY_LOG_FLUSHED);
+  return 0;
+}
+
+// CHECK: records:
+// CHECK-NEXT: - { type: 0, func-id: [[FID1:[0-9]+]], function: {{.*fn.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-enter, tsc: {{[0-9]+}} }
+// CHECK-NEXT: - { type: 0, func-id: [[FID1:[0-9]+]], function: {{.*fn.*}}, cpu: {{.*}}, thread: [[THREAD1:[0-9]+]], kind: function-exit, tsc: {{[0-9]+}} }