[XRay][compiler-rt] Add APIs for processing logs in memory

[dberris]

Summary

This change adds APIs to allow logging implementations to provide a
function for iterating through in-memory buffers (if they hold in-memory
buffers) and a way for users to generically deal with these buffers
in-process. These APIs are:

• xray_log_set_buffer_iterator(...) and xray_log_remove_buffer_iterator(): installs and removes an iterator function that takes an XRayBuffer and yields the next one.
• __xray_log_process_buffers(...): takes a function pointer that can take a mode identifier (string) and an XRayBuffer to process this data as they see fit.

The intent is to have the FDR mode implementation's buffers be
available through this __xray_log_process_buffers(...) API, so that
they can be streamed from memory instead of flushed to disk (useful for
getting the data to a network, or doing in-process analysis).

Basic mode logging will not support this mechanism as it's designed to
write the data mostly to disk.

Future implementations will may depend on this API as well, to allow for
programmatically working through the XRay buffers exposed to the
users in some fashion.

[dberris]

Adding @echristo as additional reviewer.

[dberris]

Ping?

[kpw]

Mostly looks good, but I think you should consider making the buffer iterator interface part of XRayLogImpl or some other mechanism to associate it with a logging mode.

Iterating the buffers is going to be tightly coupled to the impl that already manages the buffers.

compiler-rt/include/xray/xray_log_interface.h

241

I would change "currently installed" to "currently selected". Multiple nodes may be registered (installed) but only one selected.

276

Nit: XRayBUffer -> XRayBuffer

309–320

Should __xray_log_set_buffer_iterator be part of XRayLogImpl? A suitable default would simply return the empty XRayBuffer.

Since exposing the buffers is tightly coupled to the requirements of the handler, it is odd that it must be registered separately and can't be pinned to a mode.

compiler-rt/lib/xray/xray_log_interface.cc

166

Isn't it enough to check Buffer.Data != nullptr?

If for some reason, an implementation maintains valid pointers to zero size buffers, that implementation is crummy, but there's no good reason to skip the rest of the buffers in the iterator.

compiler-rt/test/xray/TestCases/Linux/logging-modes.cc

78 ↗

(On Diff #134992)

Why not be more specific and assert it's equal to 1 exactly?

[dberris]

• fixup: Rebase and address comments

[dberris]

In D43495#1019473, @kpw wrote:

Mostly looks good, but I think you should consider making the buffer iterator interface part of XRayLogImpl or some other mechanism to associate it with a logging mode.

Iterating the buffers is going to be tightly coupled to the impl that already manages the buffers.

That makes sense, but I'm trying really hard to not change the ABI for the XRay APIs here -- changing the XRayLogImpl struct will be an ABI break, and we don't have an ABI versioning check implemented yet.

In the meantime, the suggestion is to make the installation of the log processing handler(s) be done in the initialisation of the log implementations. This would allow log implementations to tightly control what the functionality for iterating and processing the data would be.

compiler-rt/include/xray/xray_log_interface.h

309–320

It should be, but changing it would be an ABI break. We're not quite ready to do that yet at this point.

compiler-rt/lib/xray/xray_log_interface.cc

166

Good catch, thanks, Keith!

[kpw]

Good point about preserving the size and structure of XRayLogImpl for ABI compatibility. Piper monorepo has lulled me into a false sense of security!

compiler-rt/include/xray/xray_log_interface.h

 ///   // after we've finalized the log. Some implementations may not actually
 ///   // have anything to log (it might keep the data in memory, or periodically
 ///   // be logging the data anyway).
 ///   auto flush_status = __xray_log_flushLog();
 ///   if (flush_status != XRayLogFlushStatus::XRAY_LOG_FLUSHED) {
 ///     // deal with the error here, if it is an error.
 ///   }
 ///
+///   // Alternatively, we can go through the buffers ourselves without
+///   // relying on the implementations' flushing semantics (if the
+///   // implementation supports exporting this data directly).
+///   auto MyBufferProcessor = +[](const char* mode, XRayBuffer buffer) {
+///     // Check the "mode" to see if it's something we know how to handle...
+///     // and/or do something with an XRayBuffer instance.
+///   };
+///   auto process_status = __xray_log_process_buffers(MyBufferProcessor);
+///   if (process_status != XRayLogFlushStatus::XRAY_LOG_FLUSHED) {
+///     // deal with the error here, if it is an error.
+///   }
 ///
 /// NOTE: Before calling __xray_patch() again, consider re-initializing the
 /// implementation first. Some implementations might stay in an "off" state when
 /// they are finalized, while some might be in an invalid/unknown state.
 ///
 #ifndef XRAY_XRAY_LOG_INTERFACE_H
 #define XRAY_XRAY_LOG_INTERFACE_H
 

 /// __xray_log_set_log_impl(...).
 ///
 /// Returns:
 ///   - XRAY_REGISTRATION_OK on success.
 ///   - XRAY_MODE_NOT_FOUND if there is no implementation associated with Mode;
 ///     does not update the currently installed implementation.
 XRayLogRegisterStatus __xray_log_select_mode(const char *Mode);
 
+/// Returns an identifier for the currently selected XRay mode chosen through
+/// the __xray_log_select_mode(...) function call. Returns nullptr if there is
+/// no currently installed mode.
+const char *__xray_log_get_current_mode();
+
 /// This function removes the currently installed implementation. It will also
 /// uninstall any handlers that have been previously installed. It does NOT
 /// unpatch the instrumentation sleds.
 ///
 /// NOTE: This function does NOT attempt to finalize the currently installed
 /// implementation. Use with caution.
 ///
 /// It is guaranteed safe to call this function in the following states:

 /// Invokes the installed implementation finalization routine. See
 /// XRayLogInitStatus for what the return values mean.
 XRayLogInitStatus __xray_log_finalize();
 
 /// Invokes the install implementation log flushing routine. See
 /// XRayLogFlushStatus for what the return values mean.
 XRayLogFlushStatus __xray_log_flushLog();
 
+/// An XRayBuffer represents a section of memory which can be treated by log
+/// processing functions as bytes stored in the logging implementation's
+/// buffers.
+struct XRayBuffer {
+  const void *Data;
+  size_t Size;
+};
+
+/// Registers an iterator function which takes an XRayBuffer argument, then
+/// returns another XRayBuffer function representing the next buffer. When the
+/// Iterator function returns an empty XRayBuffer (Data = nullptr, Size = 0),
+/// this signifies the end of the buffers.
+///
+/// The first invocation of this Iterator function will always take an empty
+/// XRayBuffer (Data = nullptr, Size = 0).
+void __xray_log_set_buffer_iterator(XRayBuffer (*Iterator)(XRayBuffer));
+
+/// Removes the currently registered buffer iterator function.
+void __xray_log_remove_buffer_iterator();
+
+/// Invokes the provided handler to process data maintained by the logging
+/// handler. This API will be provided raw access to the data available in
+/// memory from the logging implementation. The callback function must:
+///
+/// 1) Not modify the data, to avoid running into undefined behaviour.
+///
+/// 2) Either know the data layout, or treat the data as raw bytes for later
+///    interpretation.
+///
+/// This API is best used in place of the `__xray_log_flushLog()` implementation
+/// above to enable the caller to provide an alternative means of extracting the
+/// data from the XRay implementation.
+///
+/// Implementations MUST then provide:
+///
+/// 1) A function that will return an XRayBuffer. Functions that return an
+///    "empty" XRayBuffer signifies that there are no more buffers to be
+///    processed. This function should be registered through the
+///    `__xray_log_set_buffer_iterator(...)` function.
+///
+/// 2) Its own means of converting data it holds in memory into an XRayBuffer
+///    structure.
+///
+/// See XRayLogFlushStatus for what the return values mean.
+///
+XRayLogFlushStatus __xray_log_process_buffers(void (*Processor)(const char *,
+                                                                XRayBuffer));
+
 } // extern "C"
 
 namespace __xray {
 
 /// Options used by the LLVM XRay FDR logging implementation.
 struct FDRLoggingOptions {
   bool ReportErrors = false;
   int Fd = -1;

compiler-rt/lib/xray/xray_log_interface.cc

 #include "xray/xray_log_interface.h"
 
 #include "sanitizer_common/sanitizer_allocator_internal.h"
 #include "sanitizer_common/sanitizer_atomic.h"
 #include "sanitizer_common/sanitizer_mutex.h"
 #include "xray/xray_interface.h"
 #include "xray_defs.h"
 
-__sanitizer::SpinMutex XRayImplMutex;
-XRayLogImpl CurrentXRayImpl{nullptr, nullptr, nullptr, nullptr};
-XRayLogImpl *GlobalXRayImpl = nullptr;
+namespace __xray {
+static __sanitizer::SpinMutex XRayImplMutex;
+static XRayLogImpl CurrentXRayImpl{nullptr, nullptr, nullptr, nullptr};
+static XRayLogImpl *GlobalXRayImpl = nullptr;
+
+// This is the default implementation of a buffer iterator, which always yields
+// a null buffer.
+XRayBuffer NullBufferIterator(XRayBuffer) XRAY_NEVER_INSTRUMENT {
+  return {nullptr, 0};
+}
+
+// This is the global function responsible for iterating through given buffers.
+__sanitizer::atomic_uintptr_t XRayBufferIterator{
+    reinterpret_cast<uintptr_t>(&NullBufferIterator)};
 
 // We use a linked list of Mode to XRayLogImpl mappings. This is a linked list
 // when it should be a map because we're avoiding having to depend on C++
 // standard library data structures at this level of the implementation.
 struct ModeImpl {
   ModeImpl *Next;
   const char *Mode;
   XRayLogImpl Impl;
 };
 
-ModeImpl SentinelModeImpl{
+static ModeImpl SentinelModeImpl{
     nullptr, nullptr, {nullptr, nullptr, nullptr, nullptr}};
-ModeImpl *ModeImpls = &SentinelModeImpl;
+static ModeImpl *ModeImpls = &SentinelModeImpl;
+static const ModeImpl *CurrentMode = nullptr;
+
+} // namespace __xray
+
+using namespace __xray;
+
+void __xray_log_set_buffer_iterator(XRayBuffer (*Iterator)(XRayBuffer))
+    XRAY_NEVER_INSTRUMENT {
+  __sanitizer::atomic_store(&__xray::XRayBufferIterator,
+                            reinterpret_cast<uintptr_t>(Iterator),
+                            __sanitizer::memory_order_release);
+}
+
+void __xray_log_remove_buffer_iterator() XRAY_NEVER_INSTRUMENT {
+  __xray_log_set_buffer_iterator(&NullBufferIterator);
+}
 
 XRayLogRegisterStatus
 __xray_log_register_mode(const char *Mode,
                          XRayLogImpl Impl) XRAY_NEVER_INSTRUMENT {
   if (Impl.flush_log == nullptr || Impl.handle_arg0 == nullptr ||
       Impl.log_finalize == nullptr || Impl.log_init == nullptr)
     return XRayLogRegisterStatus::XRAY_INCOMPLETE_IMPL;
 
__xray_log_register_mode(const char *Mode,
   return XRayLogRegisterStatus::XRAY_REGISTRATION_OK;
 }
 
 XRayLogRegisterStatus
 __xray_log_select_mode(const char *Mode) XRAY_NEVER_INSTRUMENT {
   __sanitizer::SpinMutexLock Guard(&XRayImplMutex);
   for (ModeImpl *it = ModeImpls; it != &SentinelModeImpl; it = it->Next) {
     if (!__sanitizer::internal_strcmp(Mode, it->Mode)) {
+      CurrentMode = it;
       CurrentXRayImpl = it->Impl;
       GlobalXRayImpl = &CurrentXRayImpl;
       __xray_set_handler(it->Impl.handle_arg0);
       return XRayLogRegisterStatus::XRAY_REGISTRATION_OK;
     }
   }
   return XRayLogRegisterStatus::XRAY_MODE_NOT_FOUND;
 }
 
+const char *__xray_log_get_current_mode() XRAY_NEVER_INSTRUMENT {
+  __sanitizer::SpinMutexLock Guard(&XRayImplMutex);
+  if (CurrentMode != nullptr)
+    return CurrentMode->Mode;
+  return nullptr;
+}
+
 void __xray_set_log_impl(XRayLogImpl Impl) XRAY_NEVER_INSTRUMENT {
   if (Impl.log_init == nullptr || Impl.log_finalize == nullptr ||
       Impl.handle_arg0 == nullptr || Impl.flush_log == nullptr) {
     __sanitizer::SpinMutexLock Guard(&XRayImplMutex);
     GlobalXRayImpl = nullptr;
+    CurrentMode = nullptr;
     __xray_remove_handler();
     __xray_remove_handler_arg1();
     return;
   }
 
   __sanitizer::SpinMutexLock Guard(&XRayImplMutex);
   CurrentXRayImpl = Impl;
   GlobalXRayImpl = &CurrentXRayImpl;

 }
 
 XRayLogFlushStatus __xray_log_flushLog() XRAY_NEVER_INSTRUMENT {
   __sanitizer::SpinMutexLock Guard(&XRayImplMutex);
   if (!GlobalXRayImpl)
     return XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
   return GlobalXRayImpl->flush_log();
 }
+
+XRayLogFlushStatus __xray_log_process_buffers(
+    void (*Processor)(const char *, XRayBuffer)) XRAY_NEVER_INSTRUMENT {
+  // We want to make sure that there will be no changes to the global state for
+  // the log by synchronising on the XRayBufferIteratorMutex.
+  if (!GlobalXRayImpl)
+    return XRayLogFlushStatus::XRAY_LOG_NOT_FLUSHING;
+  auto Iterator = reinterpret_cast<XRayBuffer (*)(XRayBuffer)>(
+      atomic_load(&XRayBufferIterator, __sanitizer::memory_order_acquire));
+  auto Buffer = (*Iterator)(XRayBuffer{nullptr, 0});
+  auto Mode = CurrentMode ? CurrentMode->Mode : nullptr;
+  while (Buffer.Data != nullptr) {
+    (*Processor)(Mode, Buffer);
+    Buffer = (*Iterator)(Buffer);
+  }
+  return XRayLogFlushStatus::XRAY_LOG_FLUSHED;
+}

compiler-rt/test/xray/TestCases/Posix/logging-modes.cc

 // Check that we can install an implementation associated with a mode.
 //
 // RUN: %clangxx_xray -std=c++11 %s -o %t
 // RUN: %run %t | FileCheck %s
 //
 // UNSUPPORTED: target-is-mips64,target-is-mips64el
 
 #include "xray/xray_interface.h"
 #include "xray/xray_log_interface.h"
 #include <cassert>
 #include <cstdio>
+#include <string>
 
 [[clang::xray_never_instrument]] void printing_handler(int32_t fid,
                                                        XRayEntryType) {
   thread_local volatile bool printing = false;
   if (printing)
     return;
   printing = true;
   std::printf("printing %d\n", fid);
   printing = false;
 }
 
+[[clang::xray_never_instrument]] XRayBuffer next_buffer(XRayBuffer buffer) {
+  static const char data[10] = {};
+  static const XRayBuffer first_and_last{data, 10};
+  if (buffer.Data == nullptr)
+    return first_and_last;
+  if (buffer.Data == first_and_last.Data)
+    return XRayBuffer{nullptr, 0};
+  assert(false && "Invalid buffer provided.");
+}
+
 [[clang::xray_never_instrument]] XRayLogInitStatus
 printing_init(size_t, size_t, void *, size_t) {
+  __xray_log_set_buffer_iterator(next_buffer);
   return XRayLogInitStatus::XRAY_LOG_INITIALIZED;
 }
 
 [[clang::xray_never_instrument]] XRayLogInitStatus printing_finalize() {
   return XRayLogInitStatus::XRAY_LOG_FINALIZED;
 }
 
 [[clang::xray_never_instrument]] XRayLogFlushStatus printing_flush_log() {
+  __xray_log_remove_buffer_iterator();
   return XRayLogFlushStatus::XRAY_LOG_FLUSHED;
 }
 
 [[clang::xray_always_instrument]] void callme() { std::printf("called me!\n"); }
 
+static auto buffer_counter = 0;
+
+void process_buffer(const char *, XRayBuffer) { ++buffer_counter; }
+
 static bool unused = [] {
   assert(__xray_log_register_mode("custom",
                                   {printing_init, printing_finalize,
                                    printing_handler, printing_flush_log}) ==
          XRayLogRegisterStatus::XRAY_REGISTRATION_OK);
   return true;
 }();
 
 int main(int argc, char **argv) {
   assert(__xray_log_select_mode("custom") ==
          XRayLogRegisterStatus::XRAY_REGISTRATION_OK);
+  assert(__xray_log_get_current_mode() != nullptr);
+  std::string current_mode = __xray_log_get_current_mode();
+  assert(current_mode == "custom");
   assert(__xray_patch() == XRayPatchingStatus::SUCCESS);
   assert(__xray_log_init(0, 0, nullptr, 0) ==
          XRayLogInitStatus::XRAY_LOG_INITIALIZED);
   // CHECK: printing {{.*}}
   callme(); // CHECK: called me!
   // CHECK: printing {{.*}}
   assert(__xray_log_finalize() == XRayLogInitStatus::XRAY_LOG_FINALIZED);
+  assert(__xray_log_process_buffers(process_buffer) ==
+         XRayLogFlushStatus::XRAY_LOG_FLUSHED);
+  assert(buffer_counter == 1);
   assert(__xray_log_flushLog() == XRayLogFlushStatus::XRAY_LOG_FLUSHED);
   assert(__xray_log_select_mode("not-found") ==
          XRayLogRegisterStatus::XRAY_MODE_NOT_FOUND);
 }