Add inference metrics + bench script, tune threads/batch for 2-vCPU HF Space, backoff on readiness polling

Dockerfile

@@ -140,6 +140,13 @@ EXPOSE 7860
 # - loads default model at startup
 # - supports /switch-model runtime model change
 # - proxies /v1/chat/completions to active worker
+# Tuned for the free HF Space (~2 vCPU, CPU-only, OpenBLAS build):
+# - MODEL_THREADS matches the vCPU quota; more threads thrash a compute-bound
+#   generation loop (was 4).
+# - MODEL_BATCH/UBATCH sized so the OpenBLAS prompt-eval path actually gets
+#   batches worth multiplying (was 64/32). RAM headroom (~16 GB vs ~5 GB used)
+#   covers the larger compute buffers.
+# Validate any change with tests/bench.py (see PERFORMANCE_REFACTORING_PLAN.md).
 ENV DEFAULT_MODEL=QuantFactory/Qwen2.5-7B-Instruct-GGUF:q4_k_m \
     MANAGER_HOST=0.0.0.0 \
     MANAGER_PORT=7860 \
@@ -149,10 +156,10 @@ ENV DEFAULT_MODEL=QuantFactory/Qwen2.5-7B-Instruct-GGUF:q4_k_m \
     DEFAULT_MAX_TOKENS=2048 \
     MAX_TOKENS_PER_REQUEST=4096 \
     MODEL_N_CTX=8192 \
-    MODEL_THREADS=4 \
+    MODEL_THREADS=2 \
     MODEL_NGL=0 \
-    MODEL_BATCH=64 \
-    MODEL_UBATCH=32
+    MODEL_BATCH=256 \
+    MODEL_UBATCH=128
 
 CMD ["llm-manager"]
 #

config.toml.example

@@ -14,10 +14,13 @@ switch_timeout_sec = 300
 
 [llama]
 n_ctx = 8192
-threads = 4
+# Set threads to the number of vCPUs actually available; oversubscribing
+# slows compute-bound generation. Batch sizes feed the BLAS prompt-eval
+# path — validate changes with tests/bench.py.
+threads = 2
 ngl = 0
-batch = 128
-ubatch = 64
+batch = 256
+ubatch = 128
 
 [auth]
 header = "Authorization"

cpp/model_manager.cpp

@@ -239,6 +239,10 @@ pid_t ModelManager::spawn_worker(const std::string &model, int port) {
 
 bool ModelManager::wait_until_ready(pid_t pid, int port, int timeout_sec) {
     const auto deadline = std::chrono::steady_clock::now() + std::chrono::seconds(timeout_sec);
+    // Exponential backoff: fast detection when the worker comes up (or dies)
+    // quickly, without hammering it during a minutes-long model load.
+    auto poll_interval = std::chrono::milliseconds(100);
+    const auto max_interval = std::chrono::milliseconds(800);
     while (std::chrono::steady_clock::now() < deadline) {
         if (!is_alive(pid)) return false;
         try {
@@ -248,7 +252,8 @@ bool ModelManager::wait_until_ready(pid_t pid, int port, int timeout_sec) {
             if (status == 200) return true;
         } catch (...) {
         }
-        std::this_thread::sleep_for(std::chrono::milliseconds(800));
+        std::this_thread::sleep_for(poll_interval);
+        poll_interval = std::min(poll_interval * 2, max_interval);
     }
     return false;
 }

cpp/runtime_components.cpp

@@ -170,6 +170,49 @@ void MetricsRegistry::observe_queue_wait_ms(int64_t value) {
     queue_wait_samples_.fetch_add(1);
 }
 
+void MetricsRegistry::observe_inference(
+    uint64_t prompt_ms,
+    uint64_t predicted_ms,
+    uint64_t prompt_tokens,
+    uint64_t predicted_tokens) {
+    inference_prompt_ms_total_.fetch_add(prompt_ms);
+    inference_predicted_ms_total_.fetch_add(predicted_ms);
+    inference_prompt_tokens_total_.fetch_add(prompt_tokens);
+    inference_predicted_tokens_total_.fetch_add(predicted_tokens);
+    inference_samples_.fetch_add(1);
+}
+
+// Pull llama-server's timings/usage out of a completion body so /queue/metrics
+// can report real prompt-eval and generation speed (tokens/sec falls out of
+// predicted_tokens_total / predicted_ms_total).
+static void record_inference_metrics(MetricsRegistry &metrics, const std::string &body) {
+    json completion = json::parse(body, nullptr, false);
+    if (completion.is_discarded() || !completion.is_object()) return;
+
+    auto num_or_zero = [](const json &obj, const char *key) -> uint64_t {
+        if (!obj.contains(key) || !obj[key].is_number()) return 0;
+        const double v = obj[key].get<double>();
+        return v > 0 ? static_cast<uint64_t>(v) : 0;
+    };
+
+    uint64_t prompt_ms = 0, predicted_ms = 0, prompt_tokens = 0, predicted_tokens = 0;
+    if (completion.contains("timings") && completion["timings"].is_object()) {
+        const auto &t = completion["timings"];
+        prompt_ms = num_or_zero(t, "prompt_ms");
+        predicted_ms = num_or_zero(t, "predicted_ms");
+        prompt_tokens = num_or_zero(t, "prompt_n");
+        predicted_tokens = num_or_zero(t, "predicted_n");
+    }
+    if (completion.contains("usage") && completion["usage"].is_object()) {
+        const auto &u = completion["usage"];
+        if (prompt_tokens == 0) prompt_tokens = num_or_zero(u, "prompt_tokens");
+        if (predicted_tokens == 0) predicted_tokens = num_or_zero(u, "completion_tokens");
+    }
+
+    if (prompt_ms == 0 && predicted_ms == 0 && prompt_tokens == 0 && predicted_tokens == 0) return;
+    metrics.observe_inference(prompt_ms, predicted_ms, prompt_tokens, predicted_tokens);
+}
+
 std::string MetricsRegistry::render_prometheus(const QueueSnapshot &queue, ModelManager &manager) const {
     std::ostringstream oss;
     oss << "llm_manager_requests_total " << requests_total_.load() << '\n';
@@ -187,6 +230,11 @@ std::string MetricsRegistry::render_prometheus(const QueueSnapshot &queue, Model
     oss << "llm_manager_cancellations_total " << cancellations_total_.load() << '\n';
     oss << "llm_manager_switch_total " << switch_total_.load() << '\n';
     oss << "llm_manager_worker_restarts_total " << worker_restarts_total_.load() << '\n';
+    oss << "llm_manager_inference_prompt_ms_total " << inference_prompt_ms_total_.load() << '\n';
+    oss << "llm_manager_inference_predicted_ms_total " << inference_predicted_ms_total_.load() << '\n';
+    oss << "llm_manager_inference_prompt_tokens_total " << inference_prompt_tokens_total_.load() << '\n';
+    oss << "llm_manager_inference_predicted_tokens_total " << inference_predicted_tokens_total_.load() << '\n';
+    oss << "llm_manager_inference_samples " << inference_samples_.load() << '\n';
     const auto active = manager.active_worker();
     oss << "llm_manager_active_worker " << (active ? 1 : 0) << '\n';
     return oss.str();
@@ -315,6 +363,9 @@ void Scheduler::worker_loop() {
                 registry_.complete(ctx, RequestState::CANCELLED, {499, R"({"error":"Request cancelled"})"});
                 continue;
             }
+            if (status >= 200 && status < 300) {
+                record_inference_metrics(metrics_, body);
+            }
             registry_.complete(ctx, RequestState::DONE, {status, body});
         } catch (const std::exception &e) {
             log_line("request_id=" + ctx->request_id + " scheduler_exception=" + std::string(e.what()));

cpp/runtime_components.h

@@ -73,6 +73,11 @@ public:
     void inc_worker_restarts_total();
     void observe_request_latency_ms(int64_t value);
     void observe_queue_wait_ms(int64_t value);
+    void observe_inference(
+        uint64_t prompt_ms,
+        uint64_t predicted_ms,
+        uint64_t prompt_tokens,
+        uint64_t predicted_tokens);
     std::string render_prometheus(const QueueSnapshot &queue, ModelManager &manager) const;
 
 private:
@@ -87,6 +92,11 @@ private:
     std::atomic<uint64_t> cancellations_total_{0};
     std::atomic<uint64_t> switch_total_{0};
     std::atomic<uint64_t> worker_restarts_total_{0};
+    std::atomic<uint64_t> inference_prompt_ms_total_{0};
+    std::atomic<uint64_t> inference_predicted_ms_total_{0};
+    std::atomic<uint64_t> inference_prompt_tokens_total_{0};
+    std::atomic<uint64_t> inference_predicted_tokens_total_{0};
+    std::atomic<uint64_t> inference_samples_{0};
 };
 
 class PrioritySchedulerQueue {