diff --git a/src/cactus_rt/cyclic_thread.cc b/src/cactus_rt/cyclic_thread.cc index 6c41e4e..d560e94 100644 --- a/src/cactus_rt/cyclic_thread.cc +++ b/src/cactus_rt/cyclic_thread.cc @@ -37,29 +37,42 @@ void CyclicThread::Run() noexcept { loop_latency = loop_end - loop_start; TrackLatency(wakeup_latency, loop_latency); - if (tracer_config.trace_overrun && static_cast(wakeup_latency + loop_latency) >= period_ns_) { - Tracer().InstantEvent("LoopOverrun", "cactusrt"); - - LOG_WARNING_LIMIT( - std::chrono::milliseconds(100), - this->Logger(), - "At least 1 loop overrun detected in the last 100ms: latency ({}ns) > period ({}ns)", - loop_latency, - period_ns_ - ); + if (static_cast(wakeup_latency + loop_latency) >= period_ns_) { + if (tracer_config.trace_overrun) { + Tracer().InstantEvent("LoopOverrun", "cactusrt", loop_end); + + LOG_WARNING_LIMIT( + std::chrono::milliseconds(100), + this->Logger(), + "At least 1 loop overrun detected in the last 100ms: wakeup latency ({}ns) + loop latency ({}ns) > period ({}ns)", + wakeup_latency, + loop_latency, + period_ns_ + ); + } + // Loop has overrun - reset next wakeup time to now to ensure only one wakeup latency trace event is emitted + clock_gettime(CLOCK_MONOTONIC, &next_wakeup_time_); + next_wakeup_time_ns = next_wakeup_time_.tv_sec * 1'000'000'000 + next_wakeup_time_.tv_nsec; + } else { + next_wakeup_time_ = AddTimespecByNs(next_wakeup_time_, static_cast(period_ns_)); + next_wakeup_time_ns = next_wakeup_time_.tv_sec * 1'000'000'000 + next_wakeup_time_.tv_nsec; } if (should_stop) { break; } - next_wakeup_time_ = AddTimespecByNs(next_wakeup_time_, static_cast(period_ns_)); - next_wakeup_time_ns = next_wakeup_time_.tv_sec * 1'000'000'000 + next_wakeup_time_.tv_nsec; + if (tracer_config.trace_sleep) { + Tracer().StartSpan("Sleep", "cactusrt", loop_end); + } + + // TODO: maybe track busy wait latency? That feature is not even enabled. + this->Config().scheduler->Sleep(next_wakeup_time_); - { - auto span = Tracer().WithSpan("Sleep", "cactusrt", tracer_config.trace_sleep); - // TODO: maybe track busy wait latency? That feature is not even enabled. - this->Config().scheduler->Sleep(next_wakeup_time_); + if (tracer_config.trace_sleep) { + // Ideally this should be next iteration's loop_start, but that may cause readability and runtime performance challenges + // Thus, the end of the sleep event may be after the end of the wakeup event by a small amount + Tracer().EndSpan(NowNs()); } } }