refactor(profiler): add RAII step scope for service-wide timeline

docs/locales/zh_CN/LC_MESSAGES/references/profiling.po

@@ -59,19 +59,22 @@ msgstr ""
 
 #: ../../references/profiling.md:23
 msgid "Service-Wide Timeline"
-msgstr ""
+msgstr "服务级 Timeline"
 
 #: ../../references/profiling.md:25
 msgid ""
 "You may use start arg `--gen_timeline_sync` or specify env "
-"`GEN_TIMELINE_SYNC=1` to enable service level timeline profiling. When "
-"this option is used, every model request would generate a profiling "
-"timeline."
+"`GEN_TIMELINE_SYNC=1` to enable service level timeline profiling. This "
+"captures a window of inference engine steps and saves the trace as a "
+"perfetto-compatible JSON file."
 msgstr ""
+"可以使用启动参数 `--gen_timeline_sync` 或环境变量 "
+"`GEN_TIMELINE_SYNC=1` 开启服务级 timeline profiling。该方式会采集一段推理 "
+"engine step 窗口，并将 trace 保存为 perfetto 兼容的 JSON 文件。"
 
 #: ../../references/profiling.md:27
 msgid "How to visualize timeline"
-msgstr ""
+msgstr "如何可视化 timeline"
 
 #: ../../references/profiling.md:29
 msgid ""

docs/references/profiling.md

@@ -22,7 +22,7 @@ The generated timeline json file is located at the workdir where you started rtp
 
 ### Service-Wide Timeline
 
-You may use start arg `--gen_timeline_sync` or specify env `GEN_TIMELINE_SYNC=1` to enable service level timeline profiling. When this option is used, every model request would generate a profiling timeline.
+You may use start arg `--gen_timeline_sync` or specify env `GEN_TIMELINE_SYNC=1` to enable service level timeline profiling. This captures a window of inference engine steps and saves the trace as a perfetto-compatible JSON file.
 
 ### How to visualize timeline
 

rtp_llm/cpp/config/ConfigModules.cc

@@ -144,6 +144,9 @@ std::string ProfilingDebugLoggingConfig::to_string() const {
         << "ft_core_dump_on_exception: " << ft_core_dump_on_exception << "\n"
         << "ft_alog_conf_path: " << ft_alog_conf_path << "\n"
         << "gen_timeline_sync: " << gen_timeline_sync << "\n"
+        << "timeline_start_step: " << timeline_start_step << "\n"
+        << "timeline_num_steps: " << timeline_num_steps << "\n"
+        << "timeline_trace_name: " << timeline_trace_name << "\n"
         << "torch_cuda_profiler_dir: " << torch_cuda_profiler_dir << "\n"
         << "log_file_backup_count: " << log_file_backup_count << "\n"
         << "debug_load_server: " << debug_load_server << "\n"

rtp_llm/cpp/config/ConfigModules.h

@@ -200,6 +200,9 @@ struct ProfilingDebugLoggingConfig {
     bool        ft_core_dump_on_exception = false;
     std::string ft_alog_conf_path         = "";
     bool        gen_timeline_sync         = false;
+    int         timeline_start_step       = 0;
+    int         timeline_num_steps        = 3;
+    std::string timeline_trace_name       = "profiler";
     std::string torch_cuda_profiler_dir   = "";
     int         log_file_backup_count     = 16;
     bool        debug_load_server         = false;

rtp_llm/cpp/embedding_engine/EmbeddingEngine.cc

@@ -29,6 +29,7 @@ EmbeddingEngine::EmbeddingEngine(const EngineInitParams& params, py::object hand
     executor_.reset(new EmbeddingExecutor(params, handler));
     scheduler_.reset(
         new EmbeddingScheduler(model_config_, concurrency_config, params.runtime_config, metrics_reporter_));
+    step_profiler_.configureFromConfig(params.profiling_debug_logging_config);
 
     (void)startLoop();
 }
@@ -103,29 +104,32 @@ absl::Status EmbeddingEngine::step() {
         RTP_LLM_LOG_INFO("no query run and sleep");
         return absl::OkStatus();
     }
-    step_profiler_.tick();
-    try {
-        auto status = executor_->process(streams);
-        if (!status.ok()) {
+    {
+        [[maybe_unused]] auto profile_step = step_profiler_.stepScope();
+        try {
+            auto status = executor_->process(streams);
+            if (!status.ok()) {
+                for (auto& stream : streams) {
+                    stream->setError(status.ToString());
+                    RTP_LLM_LOG_WARNING("error_stream_info: length: %d, exception: %s",
+                                        stream->inputLength(),
+                                        status.ToString().c_str());
+                }
+            }
+        } catch (const exception& e) {
+            std::string error_msg = e.what();
+            RTP_LLM_LOG_WARNING("run engine failed, stream size: %d, error: %s", streams.size(), error_msg.c_str());
             for (auto& stream : streams) {
-                stream->setError(status.ToString());
-                RTP_LLM_LOG_WARNING(
-                    "error_stream_info: length: %d, exception: %s", stream->inputLength(), status.ToString().c_str());
+                stream->setError(error_msg);
+                RTP_LLM_LOG_WARNING("error_stream_info: length: %d", stream->inputLength());
+            }
+            if (error_msg.find("CUDA Driver error") != string::npos || error_msg.find("CUDA error") != string::npos) {
+                RTP_LLM_LOG_ERROR("detect CUDA error, do abort");
+                abort();
             }
         }
-    } catch (const exception& e) {
-        std::string error_msg = e.what();
-        RTP_LLM_LOG_WARNING("run engine failed, stream size: %d, error: %s", streams.size(), error_msg.c_str());
-        for (auto& stream : streams) {
-            stream->setError(error_msg);
-            RTP_LLM_LOG_WARNING("error_stream_info: length: %d", stream->inputLength());
-        }
-        if (error_msg.find("CUDA Driver error") != string::npos || error_msg.find("CUDA error") != string::npos) {
-            RTP_LLM_LOG_ERROR("detect CUDA error, do abort");
-            abort();
-        }
+        cudaSyncAndCheck();
     }
-    cudaSyncAndCheck();
     return absl::OkStatus();
 }
 

rtp_llm/cpp/engine_base/TorchProfiler.cc

@@ -1,4 +1,5 @@
 #include "rtp_llm/cpp/engine_base/TorchProfiler.h"
+#include "rtp_llm/cpp/config/ConfigModules.h"
 #include "rtp_llm/cpp/utils/Logger.h"
 #include "autil/TimeUtility.h"
 #include <string>
@@ -91,6 +92,20 @@ void ProfilerSaveWorker::run() {
 StepWindowProfiler::StepWindowProfiler(const std::string& default_output_dir, int world_rank):
     default_output_dir_(default_output_dir.empty() ? "." : default_output_dir), world_rank_(world_rank) {}
 
+StepWindowProfiler::StepScope::StepScope(StepWindowProfiler& profiler): profiler_(profiler) {
+    profiler_.beginStep();
+}
+
+StepWindowProfiler::StepScope::~StepScope() {
+    try {
+        profiler_.endStep();
+    } catch (const std::exception& e) {
+        RTP_LLM_LOG_ERROR("timeline profiler endStep failed: %s", e.what());
+    } catch (...) {
+        RTP_LLM_LOG_ERROR("timeline profiler endStep failed with unknown exception");
+    }
+}
+
 void StepWindowProfiler::configure(bool enable, const std::string& trace_name, int start_step, int num_steps) {
     // First-come-first-served: if a profiling session is already active, ignore new requests
     // to prevent concurrent requests from repeatedly restarting the profiler.
@@ -114,7 +129,14 @@ void StepWindowProfiler::configure(bool enable, const std::string& trace_name, i
                      trace_name.c_str());
 }
 
-void StepWindowProfiler::tick() {
+void StepWindowProfiler::configureFromConfig(const ProfilingDebugLoggingConfig& cfg) {
+    if (!cfg.gen_timeline_sync) {
+        return;
+    }
+    configure(true, cfg.timeline_trace_name, cfg.timeline_start_step, cfg.timeline_num_steps);
+}
+
+void StepWindowProfiler::beginStep() {
     // Fast path: no profiling active and no profiler to clean up — zero cost
     if (!enabled_.load(std::memory_order_relaxed) && !has_profiler_.load(std::memory_order_relaxed)) {
         return;
@@ -166,6 +188,22 @@ void StepWindowProfiler::tick() {
                          prefix.c_str(),
                          start_step_.load(),
                          num_steps_.load());
+    }
+}
+
+void StepWindowProfiler::endStep() {
+    // Fast path: no profiling active and no profiler to clean up — zero cost
+    if (!enabled_.load(std::memory_order_relaxed) && !has_profiler_.load(std::memory_order_relaxed)) {
+        return;
+    }
+
+    if (!enabled_.load(std::memory_order_relaxed)) {
+        stopProfiler("disabled");
+        return;
+    }
+
+    std::lock_guard<std::mutex> lock(mu_);
+    if (!profiler_) {
         return;
     }
 

rtp_llm/cpp/engine_base/TorchProfiler.h

@@ -13,6 +13,8 @@ namespace rtp_llm {
 
 namespace tpi = torch::profiler::impl;
 
+struct ProfilingDebugLoggingConfig;
+
 // Low-level profiler wrapper around Kineto.
 // IMPORTANT: start() and stop() MUST be called on the same thread (Kineto thread-affinity).
 class TorchProfile {
@@ -68,44 +70,66 @@ class ProfilerSaveWorker {
 };
 
 // Step-window profiler controlled via API (sglang-style).
-// Thread-safe: configure() is called from gRPC thread, tick() from engine loop thread.
-// The actual TorchProfile start/stop happens only inside tick(), satisfying Kineto thread-affinity.
+// Thread-safe: configure() is called from gRPC thread, stepScope() from engine loop thread.
+// The actual TorchProfile start/stop happens only inside engine step callbacks, satisfying Kineto thread-affinity.
 // Trace export is done asynchronously on a background thread to avoid blocking inference.
 class StepWindowProfiler {
 public:
+    // RAII guard that brackets a single engine step. Construct with stepScope() before
+    // process(), destruction after process() advances the profiler state machine.
+    // Strictly scope-bound: not movable, not copyable.
+    class StepScope {
+    public:
+        explicit StepScope(StepWindowProfiler& profiler);
+        ~StepScope();
+        StepScope(const StepScope&)            = delete;
+        StepScope& operator=(const StepScope&) = delete;
+        StepScope(StepScope&&)                 = delete;
+        StepScope& operator=(StepScope&&)      = delete;
+
+    private:
+        StepWindowProfiler& profiler_;
+    };
+
     explicit StepWindowProfiler(const std::string& default_output_dir = "", int world_rank = 0);
     ~StepWindowProfiler();
 
     // Configure a profiling session. Safe to call from any thread (sets atomic state).
-    // The actual profiler start happens inside tick() (on the engine loop thread),
-    // satisfying Kineto thread-affinity. If a session is already active, this is a no-op
-    // (first-come-first-served).
-    //
-    // For in-step capture: the engine loop can call configure(start_step=0) and then
-    // tick() BEFORE process() to start the profiler before the work runs.
+    // The actual profiler start happens inside the next stepScope() (on the engine loop
+    // thread), satisfying Kineto thread-affinity. If a session is already active, this is
+    // a no-op (first-come-first-served).
     void configure(bool enable, const std::string& trace_name, int start_step, int num_steps);
 
-    // Called once per engine step() on the engine loop thread.
-    // Handles start/stop of the underlying TorchProfile based on step counts.
-    void tick();
+    // Convenience overload: enable service-wide timeline profiling from config.
+    // No-op if cfg.gen_timeline_sync is false.
+    void configureFromConfig(const ProfilingDebugLoggingConfig& cfg);
+
+    // Returns an RAII scope that wraps a single engine step.
+    StepScope stepScope() {
+        return StepScope(*this);
+    }
 
     bool enabled() const {
         return enabled_.load(std::memory_order_relaxed);
     }
 
 private:
+    friend class StepScope;
+
+    void beginStep();
+    void endStep();
     void stopProfiler(const char* reason);
 
     std::string default_output_dir_;
 
-    // Atomic state set by configure(), read by tick()
+    // Atomic state set by configure(), read by beginStep()/endStep()
     std::atomic<bool> enabled_{false};
     std::atomic<bool> reconfigure_{false};
     std::atomic<bool> has_profiler_{false};
     std::atomic<int>  start_step_{0};
     std::atomic<int>  num_steps_{0};
 
-    // State managed exclusively on the engine loop thread (inside tick/shutdown)
+    // State managed exclusively on the engine loop thread (inside begin/end/shutdown)
     std::mutex                    mu_;
     std::string                   trace_name_;
     std::shared_ptr<TorchProfile> profiler_;

rtp_llm/cpp/normal_engine/NormalEngine.cc

@@ -112,6 +112,7 @@ NormalEngine::NormalEngine(const EngineInitParams&                       params,
     releaseHostMemoryCache();
 
     initScheduler();
+    step_profiler_.configureFromConfig(profiling_debug_logging_config);
     (void)startLoop();
 }
 
@@ -461,31 +462,24 @@ absl::Status NormalEngine::step() {
     int64_t      step_begin_time_us = autil::TimeUtility::currentTimeInMicroSeconds();
     absl::Status status             = absl::OkStatus();
 
-    // If any stream in this batch requested gen_timeline AND no profiling session is
-    // already active, configure + tick BEFORE process() so the profiler is up before
-    // the actual work runs. This guarantees the trace captures THIS step's work, not
-    // the next step's. If a session is already active (e.g. external StartProfile RPC),
-    // skip — first-come-first-served.
+    // Per-request timeline: if any stream requested gen_timeline and no session is
+    // active yet, configure the profiler so the next stepScope() captures THIS step.
     if (!step_profiler_.enabled()) {
         for (const auto& stream : streams) {
             if (stream && stream->genTimeline()) {
                 const auto& cfg = stream->generateConfig();
                 step_profiler_.configure(true, cfg->profile_trace_name, 0, cfg->profile_step);
-                step_profiler_.tick();  // start profiler now (start_step=0)
                 break;
             }
         }
     }
 
     {
+        [[maybe_unused]] auto profile_step = step_profiler_.stepScope();
         RTP_LLM_PROFILE_SCOPE_DYNAMIC("engine.normal.execute(stream_size=%zu)", streams.size());
         status = executor_->process(streams);
     }
 
-    // tick profiler after process() to count this step (and stop when num_steps reached).
-    // All TP ranks synchronize inside process() via NCCL, so stop happens at aligned points.
-    step_profiler_.tick();
-
     // report step metrics
     if (parallelism_config.tp_rank == 0) {
         RTP_LLM_PROFILE_SCOPE("engine.normal.report_metrics_work");

rtp_llm/cpp/pybind/ConfigInit.cc

@@ -510,6 +510,9 @@ PYBIND11_MODULE(libth_transformer_config, m) {
         .def_readwrite("ft_core_dump_on_exception", &ProfilingDebugLoggingConfig::ft_core_dump_on_exception)
         .def_readwrite("ft_alog_conf_path", &ProfilingDebugLoggingConfig::ft_alog_conf_path)
         .def_readwrite("gen_timeline_sync", &ProfilingDebugLoggingConfig::gen_timeline_sync)
+        .def_readwrite("timeline_start_step", &ProfilingDebugLoggingConfig::timeline_start_step)
+        .def_readwrite("timeline_num_steps", &ProfilingDebugLoggingConfig::timeline_num_steps)
+        .def_readwrite("timeline_trace_name", &ProfilingDebugLoggingConfig::timeline_trace_name)
         .def_readwrite("torch_cuda_profiler_dir", &ProfilingDebugLoggingConfig::torch_cuda_profiler_dir)
         .def_readwrite("log_file_backup_count", &ProfilingDebugLoggingConfig::log_file_backup_count)
         .def_readwrite("debug_load_server", &ProfilingDebugLoggingConfig::debug_load_server)
@@ -525,6 +528,9 @@ PYBIND11_MODULE(libth_transformer_config, m) {
                                       self.ft_core_dump_on_exception,
                                       self.ft_alog_conf_path,
                                       self.gen_timeline_sync,
+                                      self.timeline_start_step,
+                                      self.timeline_num_steps,
+                                      self.timeline_trace_name,
                                       self.torch_cuda_profiler_dir,
                                       self.log_file_backup_count,
                                       self.debug_load_server,
@@ -534,7 +540,7 @@ PYBIND11_MODULE(libth_transformer_config, m) {
                                       self.check_nan);
             },
             [](py::tuple t) {
-                if (t.size() != 12)
+                if (t.size() != 12 && t.size() != 15)
                     throw std::runtime_error("Invalid state!");
 
                 ProfilingDebugLoggingConfig c;
@@ -544,13 +550,26 @@ PYBIND11_MODULE(libth_transformer_config, m) {
                     c.ft_core_dump_on_exception = t[2].cast<bool>();
                     c.ft_alog_conf_path         = t[3].cast<std::string>();
                     c.gen_timeline_sync         = t[4].cast<bool>();
-                    c.torch_cuda_profiler_dir   = t[5].cast<std::string>();
-                    c.log_file_backup_count     = t[6].cast<int>();
-                    c.debug_load_server         = t[7].cast<bool>();
-                    c.hack_layer_num            = t[8].cast<int>();
-                    c.debug_start_fake_process  = t[9].cast<bool>();
-                    c.enable_detail_log         = t[10].cast<bool>();
-                    c.check_nan                 = t[11].cast<bool>();
+                    if (t.size() == 12) {
+                        c.torch_cuda_profiler_dir  = t[5].cast<std::string>();
+                        c.log_file_backup_count    = t[6].cast<int>();
+                        c.debug_load_server        = t[7].cast<bool>();
+                        c.hack_layer_num           = t[8].cast<int>();
+                        c.debug_start_fake_process = t[9].cast<bool>();
+                        c.enable_detail_log        = t[10].cast<bool>();
+                        c.check_nan                = t[11].cast<bool>();
+                    } else {
+                        c.timeline_start_step      = t[5].cast<int>();
+                        c.timeline_num_steps       = t[6].cast<int>();
+                        c.timeline_trace_name      = t[7].cast<std::string>();
+                        c.torch_cuda_profiler_dir  = t[8].cast<std::string>();
+                        c.log_file_backup_count    = t[9].cast<int>();
+                        c.debug_load_server        = t[10].cast<bool>();
+                        c.hack_layer_num           = t[11].cast<int>();
+                        c.debug_start_fake_process = t[12].cast<bool>();
+                        c.enable_detail_log        = t[13].cast<bool>();
+                        c.check_nan                = t[14].cast<bool>();
+                    }
                 } catch (const std::exception& e) {
                     throw std::runtime_error(std::string("ProfilingDebugLoggingConfig unpickle error: ") + e.what());
                 }

rtp_llm/ops/libth_transformer_config.pyi

@@ -1150,6 +1150,9 @@ class ProfilingDebugLoggingConfig:
     gen_timeline_sync: bool
     hack_layer_num: int
     log_file_backup_count: int
+    timeline_num_steps: int
+    timeline_start_step: int
+    timeline_trace_name: str
     torch_cuda_profiler_dir: str
     trace_memory: bool
     def __getstate__(self) -> tuple: