chore: add ability to identify fibers that run too long (#414)

Added fiber_run_warning_threshold_ms flag plus a method that can change the threshold at runtime.

Signed-off-by: Roman Gershman <[email protected]>

Author: romange

util/fibers/detail/fiber_interface.cc

@@ -16,6 +16,9 @@ ABSL_FLAG(uint32_t, fiber_safety_margin, 1024,
           "If > 0, ensures the stack each fiber has at least this margin. "
           "The check is done at fiber destruction time.");
 
+ABSL_FLAG(uint32_t, fiber_run_warning_threshold_ms, 0,
+          "If greater than 0, will warn if a fiber runs longer than this threshold. ");
+
 namespace util {
 namespace fb2 {
 using namespace std;
@@ -61,14 +64,13 @@ class MainFiberImpl final : public FiberInterface {
 mutex g_scheduler_lock;
 
 TL_FiberInitializer* g_fiber_thread_list = nullptr;
-uint64_t g_tsc_cycles_per_ms = 0;
+uint64_t g_tsc_cycles_per_ms = 0, g_ts_cycles_warn_threshold = -1;
 
 }  // namespace
 
 PMR_NS::memory_resource* default_stack_resource = nullptr;
 size_t default_stack_size = 64 * 1024;
 
-
 __thread FiberInterface::TL FiberInterface::tl;
 
 // Per thread initialization structure.
@@ -111,6 +113,9 @@ TL_FiberInitializer::TL_FiberInitializer() noexcept : sched(nullptr) {
   g_fiber_thread_list = this;
   if (g_tsc_cycles_per_ms == 0) {
     g_tsc_cycles_per_ms = CycleClock::Frequency() / 1000;
+    uint32_t warn_ms = absl::GetFlag(FLAGS_fiber_run_warning_threshold_ms);
+    if (warn_ms)
+      g_ts_cycles_warn_threshold = g_tsc_cycles_per_ms * warn_ms;
     VLOG(1) << "TSC Frequency : " << g_tsc_cycles_per_ms << "/ms";
   }
 }
@@ -401,12 +406,16 @@ FiberInterface* FiberInterface::SwitchSetup() {
     fb_initializer.switch_delay_cycles += (tsc - cpu_tsc_);
 
     // to_suspend points to the fiber that is active and is going to be suspended.
-    uint64_t delta_cycles = tsc - to_suspend->cpu_tsc_;
-    if (delta_cycles > g_tsc_cycles_per_ms) {
+    uint64_t active_cycles = tsc - to_suspend->cpu_tsc_;
+    if (active_cycles > g_tsc_cycles_per_ms) {
       fb_initializer.long_runtime_cnt++;
 
-      // improves precision, instead of "delta_cycles / (g_tsc_cycles_per_ms / 1000)"
-      fb_initializer.long_runtime_usec += (delta_cycles * 1000) / g_tsc_cycles_per_ms;
+      // improves precision, instead of "active_cycles / (g_tsc_cycles_per_ms / 1000)"
+      fb_initializer.long_runtime_usec += (active_cycles * 1000) / g_tsc_cycles_per_ms;
+      if (active_cycles >= g_ts_cycles_warn_threshold && to_suspend->type() == WORKER) {
+        LOG_EVERY_T(WARNING, 1) << "Fiber " << to_suspend->name() << " ran for "
+                     << (active_cycles / g_tsc_cycles_per_ms) << " ms";
+      }
     }
   }
 
@@ -473,6 +482,10 @@ uint64_t FiberLongRunSumUsec() noexcept {
   return detail::FbInitializer().long_runtime_usec;
 }
 
+void SetFiberLongRunWarningThreshold(uint32_t warn_ms) {
+  detail::g_ts_cycles_warn_threshold = warn_ms == 0 ? -1 : detail::g_tsc_cycles_per_ms * warn_ms;
+}
+
 size_t WorkerFibersStackSize() {
   return detail::FbInitializer().sched->worker_stack_size();
 }

util/fibers/fibers.h

@@ -131,6 +131,8 @@ uint64_t FiberLongRunCnt() noexcept;
 // Exposes total duration of fibers running for a "long" time (longer than 1ms).
 uint64_t FiberLongRunSumUsec() noexcept;
 
+void SetFiberLongRunWarningThreshold(uint32_t warn_ms);
+
 // Injects a custom memory resource for stack allocation. Can be called only once.
 // It is advised to call this function when a program starts.
 void SetDefaultStackResource(PMR_NS::memory_resource* mr, size_t default_size = 64 * 1024);