Skip to content

Commit 6e53b68

Browse files
committed
fix(qwen35): populate result.prefill_s/decode_s so daemon log telemetry is real
Daemon's bare-prompt and RESTORE success path printed ok N=24237 gen=128 prefill_s=0.000 decode_s=0.000 decode_tok_s=128000000000.0 because GenerateResult.prefill_s/decode_s were never populated by Qwen35Backend::generate() or restore_and_generate(). The format-string math then printed nonsense (128 / 1e-9 = 1.28e11 tok/s). Time both phases with std::chrono::steady_clock, store on result, so the daemon log shows real numbers and downstream tools (server.py log parsers, bench-style metric scrapers) get truthful values.
1 parent 350bfcb commit 6e53b68

1 file changed

Lines changed: 12 additions & 0 deletions

File tree

dflash/src/qwen35/qwen35_backend.cpp

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -321,18 +321,24 @@ GenerateResult Qwen35Backend::generate(const GenerateRequest & req,
321321
reset_target_cache(cache_);
322322

323323
// Prefill
324+
auto t_prefill_start = std::chrono::steady_clock::now();
324325
const int committed = do_prefill(req.prompt, io, req.snap_pos, req.snap_slot);
325326
if (committed < 0) {
326327
result.error = "prefill";
327328
return result;
328329
}
330+
auto t_prefill_end = std::chrono::steady_clock::now();
331+
result.prefill_s = std::chrono::duration<double>(t_prefill_end - t_prefill_start).count();
329332

330333
// Decode (speculative)
331334
if (req.n_gen > 0) {
335+
auto t_decode_start = std::chrono::steady_clock::now();
332336
if (!do_spec_decode(committed, req.n_gen, result.tokens, io)) {
333337
result.error = "decode";
334338
return result;
335339
}
340+
result.decode_s = std::chrono::duration<double>(
341+
std::chrono::steady_clock::now() - t_decode_start).count();
336342
}
337343

338344
result.ok = true;
@@ -368,12 +374,15 @@ GenerateResult Qwen35Backend::restore_and_generate(int slot,
368374
int committed = snap_pos;
369375
const int prompt_len = (int)req.prompt.size();
370376
if (prompt_len > snap_pos) {
377+
auto t_prefill_start = std::chrono::steady_clock::now();
371378
std::vector<int32_t> delta(req.prompt.begin() + snap_pos, req.prompt.end());
372379
committed = do_prefill(delta, io, req.snap_pos, req.snap_slot, /*kv_offset=*/snap_pos);
373380
if (committed < 0) {
374381
result.error = "prefill";
375382
return result;
376383
}
384+
result.prefill_s = std::chrono::duration<double>(
385+
std::chrono::steady_clock::now() - t_prefill_start).count();
377386
} else if (prompt_len > 0 && prompt_len < snap_pos) {
378387
// Cached more than the request — should never happen in practice.
379388
result.error = "snapshot_longer_than_prompt";
@@ -383,10 +392,13 @@ GenerateResult Qwen35Backend::restore_and_generate(int slot,
383392

384393
// Decode
385394
if (req.n_gen > 0) {
395+
auto t_decode_start = std::chrono::steady_clock::now();
386396
if (!do_spec_decode(committed, req.n_gen, result.tokens, io)) {
387397
result.error = "decode";
388398
return result;
389399
}
400+
result.decode_s = std::chrono::duration<double>(
401+
std::chrono::steady_clock::now() - t_decode_start).count();
390402
}
391403

392404
result.ok = true;

0 commit comments

Comments
 (0)