Collect wall time and cpu time samples in the same trace.

Summary: Register new providers and create entries for CPU_STACK_SAMPLE and WALL_STACK_SAMPLE.

Reviewed By: BurntBrunch

Differential Revision: D32139331

fbshipit-source-id: 9e4cb70ad99e61bd6df145c80a62a99a0b253560

Author: Kui-Feng Lee

cpp/codegen/config/android.py

@@ -141,6 +141,8 @@
     "GPU_MEMORY_FREE",
     "THREAD_START",
     "THREAD_FINISH",
+    "CPU_STACK_SAMPLE",
+    "WALL_STACK_SAMPLE",
 ]
 
 STACK_FRAME_ENTRIES = frozenset(

cpp/generated/EntryType.cpp

@@ -1,4 +1,4 @@
-// @generated SignedSource<<b7eff2c1a5e497eb7eea5b61ad2d8f5f>>
+// @generated SignedSource<<390e60e658a65e09e8228eae35f255b4>>
 
 #include <stdexcept>
 #include <profilo/entries/EntryType.h>
@@ -123,6 +123,8 @@ const char* to_string(EntryType type) {
     case EntryType::GPU_MEMORY_FREE: return "GPU_MEMORY_FREE";
     case EntryType::THREAD_START: return "THREAD_START";
     case EntryType::THREAD_FINISH: return "THREAD_FINISH";
+    case EntryType::CPU_STACK_SAMPLE: return "CPU_STACK_SAMPLE";
+    case EntryType::WALL_STACK_SAMPLE: return "WALL_STACK_SAMPLE";
     default: throw std::invalid_argument("Unknown entry type");
   }
 }

cpp/generated/EntryType.h

@@ -1,4 +1,4 @@
-// @generated SignedSource<<a688ba6c4918a6c66ba16a8f17dc12d4>>
+// @generated SignedSource<<f0679634001e78402be9dd5db5850900>>
 
 #pragma once
 
@@ -120,6 +120,8 @@ enum class EntryType {
   GPU_MEMORY_FREE = 111,
   THREAD_START = 112,
   THREAD_FINISH = 113,
+  CPU_STACK_SAMPLE = 114,
+  WALL_STACK_SAMPLE = 115,
 };
 
 

cpp/generated/EntryType.java

@@ -1,4 +1,4 @@
-// @generated SignedSource<<be259938f014b5fcd2b16c3412960680>>
+// @generated SignedSource<<5e4debd0d0a6279e0d17129e294db714>>
 
 package com.facebook.profilo.entries;
 
@@ -118,6 +118,8 @@ public class EntryType {
   public static final int GPU_MEMORY_FREE = 111;
   public static final int THREAD_START = 112;
   public static final int THREAD_FINISH = 113;
+  public static final int CPU_STACK_SAMPLE = 114;
+  public static final int WALL_STACK_SAMPLE = 115;
 
   public static final String[] NAMES = {
     "UNKNOWN_TYPE",
@@ -234,5 +236,7 @@ public class EntryType {
     "GPU_MEMORY_FREE",
     "THREAD_START",
     "THREAD_FINISH",
+    "CPU_STACK_SAMPLE",
+    "WALL_STACK_SAMPLE",
   };
 }

cpp/profiler/SamplingProfiler.cpp

@@ -38,6 +38,7 @@
 #include <profilo/profiler/ExternalTracer.h>
 #include <profilo/profiler/JavaBaseTracer.h>
 #include <profilo/profiler/Retcode.h>
+#include <profilo/profiler/ThreadTimer.h>
 
 #include <profilo/LogEntry.h>
 #include <profilo/TraceProviders.h>
@@ -192,6 +193,8 @@ void SamplingProfiler::UnwindStackHandler(
         state.errStackOverflows.fetch_add(1);
       }
 
+      slot.timerType = ThreadTimer::decodeType(siginfo->si_value.sival_int);
+
       // Ignore TRACER_DISABLED errors for now and free the slot.
       // TODO T42938550
       if (StackCollectionRetcode::TRACER_DISABLED == ret) {
@@ -288,6 +291,20 @@ void SamplingProfiler::unregisterSignalHandlers() {
   signal_handlers_.sigsegv->Disable();
 }
 
+static int32_t
+logTimerType(StackSlot& slot, int32_t tid, MultiBufferLogger& logger) {
+  auto type = slot.timerType == ThreadTimer::Type::CpuTime
+      ? EntryType::CPU_STACK_SAMPLE
+      : EntryType::WALL_STACK_SAMPLE;
+  auto id = logger.write(StandardEntry{
+      .type = type,
+      .timestamp = slot.time,
+      .tid = tid,
+  });
+
+  return id;
+}
+
 void SamplingProfiler::flushStackTraces(
     std::unordered_set<uint64_t>& loggedFramesSet) {
   int processedCount = 0;
@@ -308,6 +325,8 @@ void SamplingProfiler::flushStackTraces(
       auto& tracer = state_.tracersMap[slot.profilerType];
       auto tid = slotStateCombo >> 16;
 
+      logTimerType(slot, tid, logger);
+
       if (StackCollectionRetcode::SUCCESS == slotState) {
         tracer->flushStack(logger, slot.frames, slot.depth, tid, slot.time);
       } else {
@@ -429,6 +448,7 @@ bool SamplingProfiler::startProfilingTimers() {
   state_.timerManager.reset(new TimerManager(
       state_.threadDetectIntervalMs,
       state_.samplingRateMs,
+      state_.cpuClockModeEnabled,
       state_.wallClockModeEnabled,
       state_.wallClockModeEnabled ? state_.whitelist : nullptr));
   state_.timerManager->start();
@@ -445,6 +465,7 @@ bool SamplingProfiler::startProfiling(
     int requested_tracers,
     int sampling_rate_ms,
     int thread_detect_interval_ms,
+    bool cpu_clock_mode_enabled,
     bool wall_clock_mode_enabled) {
   if (state_.isProfiling) {
     throw std::logic_error("startProfiling called while already profiling");
@@ -467,6 +488,7 @@ bool SamplingProfiler::startProfiling(
   }
 
   state_.samplingRateMs = sampling_rate_ms;
+  state_.cpuClockModeEnabled = cpu_clock_mode_enabled;
   state_.wallClockModeEnabled = wall_clock_mode_enabled;
   state_.threadDetectIntervalMs = thread_detect_interval_ms;
 

cpp/profiler/SamplingProfiler.h

@@ -67,6 +67,7 @@ struct StackSlot {
   int64_t time;
   sigjmp_buf sig_jmp_buf;
   uint32_t profilerType;
+  ThreadTimer::Type timerType;
   int64_t frames[MAX_STACK_DEPTH]; // frame pointer addresses
   char const* method_names[MAX_STACK_DEPTH];
   char const* class_descriptors[MAX_STACK_DEPTH];
@@ -106,6 +107,7 @@ struct ProfileState {
   std::atomic_bool isLoggerLoopDone;
 
   // Config parameters
+  bool cpuClockModeEnabled;
   bool wallClockModeEnabled;
   int threadDetectIntervalMs;
   int samplingRateMs;
@@ -146,6 +148,7 @@ class SamplingProfiler {
       int requested_providers,
       int sampling_rate_ms,
       int thread_detect_interval_ms,
+      bool cpu_clock_mode_enabled,
       bool wall_clock_mode_enabled);
 
   void addToWhitelist(int targetThread);

cpp/profiler/ThreadTimer.cpp

@@ -22,6 +22,7 @@
 #include <fb/log.h>
 #include <profilo/util/common.h>
 #include <random>
+#include <stdexcept>
 #include <system_error>
 
 namespace facebook {
@@ -76,7 +77,9 @@ bool createThreadTimer(
   sigev.sigev_notify = SIGEV_THREAD_ID;
   sigev.sigev_signo = SIGPROF;
   sigev._sigev_un._tid = ktid; /* ID of kernel thread to signal */
-  sigev.sigev_value.sival_ptr = nullptr;
+  sigev.sigev_value.sival_int = ThreadTimer::encodeType(
+      wallClockModeEnabled ? ThreadTimer::Type::WallTime
+                           : ThreadTimer::Type::CpuTime);
   if (timer_create(clockid, &sigev, timerId) != 0) {
     return false;
   }
@@ -136,14 +139,9 @@ itimerval getInitialItimerval(int samplingRateMs) {
   return tv;
 }
 
-ThreadTimer::ThreadTimer(
-    int32_t tid,
-    int samplingRateMs,
-    bool wallClockModeEnabled)
-    : tid_(tid),
-      samplingRateMs_(samplingRateMs),
-      wallClockModeEnabled_(wallClockModeEnabled) {
-  if (!createThreadTimer(tid_, &timerId_, wallClockModeEnabled_)) {
+ThreadTimer::ThreadTimer(int32_t tid, int samplingRateMs, Type timerType)
+    : tid_(tid), samplingRateMs_(samplingRateMs), timerType_(timerType) {
+  if (!createThreadTimer(tid_, &timerId_, timerType == Type::WallTime)) {
     // e.g. tid died
     throw std::system_error(errno, std::system_category(), "createThreadTimer");
   }
@@ -161,6 +159,23 @@ ThreadTimer::~ThreadTimer() {
   deleteThreadTimer(timerId_);
 }
 
+long ThreadTimer::typeSeed = 0;
+
+ThreadTimer::Type ThreadTimer::decodeType(long salted) {
+  auto type = static_cast<Type>(salted ^ typeSeed);
+  if (type != Type::CpuTime && type != Type::WallTime) {
+    throw std::runtime_error("invalid timer type");
+  }
+  return type;
+}
+
+long ThreadTimer::encodeType(Type type) {
+  while (typeSeed == 0) {
+    typeSeed = rand();
+  }
+  return static_cast<long>(type) ^ typeSeed;
+}
+
 } // namespace profiler
 } // namespace profilo
 } // namespace facebook

cpp/profiler/ThreadTimer.h

@@ -31,25 +31,32 @@ static const timer_t INVALID_TIMER_ID =
 
 class ThreadTimer {
  public:
-  explicit ThreadTimer(
-      int32_t tid,
-      int samplingRateMs,
-      bool wallClockModeEnabled);
+  enum class Type {
+    CpuTime = 1,
+    WallTime,
+  };
+
+  explicit ThreadTimer(int32_t tid, int samplingRateMs, Type timerType);
   ~ThreadTimer();
 
   ThreadTimer(const ThreadTimer&) = delete;
   ThreadTimer& operator=(const ThreadTimer&) = delete;
   ThreadTimer(ThreadTimer&& other) noexcept // move constructor
       : tid_(other.tid_),
         samplingRateMs_(other.samplingRateMs_),
-        wallClockModeEnabled_(other.wallClockModeEnabled_),
+        timerType_(other.timerType_),
         timerId_(std::exchange(other.timerId_, INVALID_TIMER_ID)) {}
 
+  static Type decodeType(long salted);
+
+  static long encodeType(Type type);
+
  private:
   int32_t tid_;
   int samplingRateMs_;
-  bool wallClockModeEnabled_;
+  Type timerType_;
   timer_t timerId_;
+  static long typeSeed;
 };
 
 } // namespace profiler

cpp/profiler/TimerManager.cpp

@@ -96,15 +96,20 @@ void TimerManager::updateThreadTimers() {
       continue;
     }
     try {
-      bool ok =
-          state_.threadTimers
-              .emplace(
-                  tid,
-                  ThreadTimer(
-                      tid, state_.samplingRateMs, state_.wallClockModeEnabled))
-              .second;
-      if (!ok) {
-        FBLOGE("state_.threadTimers.insert failed");
+      std::vector<ThreadTimer> timers;
+      if (state_.cpuClockModeEnabled) {
+        timers.emplace_back(ThreadTimer(
+            tid, state_.samplingRateMs, ThreadTimer::Type::CpuTime));
+      }
+      if (state_.wallClockModeEnabled) {
+        timers.emplace_back(ThreadTimer(
+            tid, state_.samplingRateMs, ThreadTimer::Type::WallTime));
+      }
+      if (timers.size() > 0) {
+        bool ok = state_.threadTimers.emplace(tid, std::move(timers)).second;
+        if (!ok) {
+          FBLOGE("state_.threadTimers.insert failed");
+        }
       }
     } catch (const std::system_error& e) {
       // thread may have ended
@@ -153,10 +158,12 @@ void TimerManager::threadDetectLoop() {
 TimerManager::TimerManager(
     int threadDetectIntervalMs,
     int samplingRateMs,
+    bool cpuClockModeEnabled,
     bool wallClockModeEnabled,
     std::shared_ptr<Whitelist> whitelist) {
   state_.threadDetectIntervalMs = threadDetectIntervalMs;
   state_.samplingRateMs = samplingRateMs;
+  state_.cpuClockModeEnabled = cpuClockModeEnabled;
   state_.wallClockModeEnabled = wallClockModeEnabled;
   state_.whitelist = whitelist;
 

cpp/profiler/TimerManager.h

@@ -31,6 +31,7 @@
 #include <unordered_map>
 #include <unordered_set>
 #include <utility>
+#include <vector>
 
 namespace facebook {
 namespace profilo {
@@ -41,6 +42,7 @@ struct Whitelist;
 struct TimerManagerState {
   int threadDetectIntervalMs;
   int samplingRateMs;
+  bool cpuClockModeEnabled;
   bool wallClockModeEnabled;
 
   // whitelist is optional; use null for "all threads"
@@ -49,14 +51,15 @@ struct TimerManagerState {
   std::thread threadDetectThread;
   sem_t threadDetectSem;
   std::atomic_bool isThreadDetectLoopDone;
-  std::unordered_map<pid_t, ThreadTimer> threadTimers;
+  std::unordered_map<pid_t, std::vector<ThreadTimer>> threadTimers;
 };
 
 class TimerManager {
  public:
   explicit TimerManager(
       int threadDetectIntervalMs,
       int samplingRateMs,
+      bool cpuClockModeEnabled,
       bool wallClockModeEnabled,
       std::shared_ptr<Whitelist> whitelist);
   ~TimerManager() = default;

cpp/profiler/jni.cpp

@@ -158,11 +158,13 @@ static jboolean nativeStartProfiling(
     jint requested_tracers,
     jint sampling_rate_ms,
     jint thread_detect_interval_ms,
+    jboolean cpu_clock_mode,
     jboolean wall_clock_mode) {
   return SamplingProfiler::getInstance().startProfiling(
       requested_tracers,
       sampling_rate_ms,
       thread_detect_interval_ms,
+      cpu_clock_mode,
       wall_clock_mode);
 }