Public/llama.cpp
1
0
Fork 0
mirror of https://github.com/ggml-org/llama.cpp.git synced 2026-09-18 16:55:05 +02:00
Code Issues Packages Projects Releases Wiki Activity

more accurate batch metrics tracking

Browse Source
This commit is contained in:
Xuan Son Nguyen
2026-08-12 13:25:43 +02:00
parent 20ce126733
commit 372ea5734d
3 changed files with 90 additions and 39 deletions
Download Patch File Download Diff File Expand all files Collapse all files
tools/server/server-common.h
+48 -11
View File
@@ -381,12 +381,15 @@ struct server_slot_stats {
}
return (t_prompt_last - t_start) / 1000.0;
}
double t_gen_ms() const {
int64_t t_gen_us() const {
if (t_gen_last == 0) {
return 0.0; // the generation is not started yet
return 0; // the generation is not started yet
}
// clamp to 1 us, the first token can land in the same us as t_prompt_last
return std::max<int64_t>(1, t_gen_last - t_prompt_last) / 1000.0;
return std::max<int64_t>(1, t_gen_last - t_prompt_last);
}
double t_gen_ms() const {
return t_gen_us() / 1000.0;
}
// number of decode steps spent on generation
@@ -427,18 +430,18 @@ struct server_metrics {
struct bucket {
uint64_t count = 0; // number of tokens
uint64_t steps = 0; // number of decode steps, differs from count for generation
uint64_t time = 0; // in milliseconds
uint64_t steps = 0; // for generation, this excludes first generated token (logits from prompt batch)
uint64_t time = 0; // in microseconds
// the rate uses the decode steps, so that free tokens do not inflate it
// the rate uses the decode steps, so that "free" tokens do not inflate it
double n_per_second() const {
return time > 0 ? (double) steps / (double) time * 1e3 : 0.0;
return time > 0 ? (double) steps / (double) time * 1e6 : 0.0;
}
void add(uint64_t n, uint64_t n_steps, double t_ms) {
void add(uint64_t n, uint64_t n_steps, uint64_t t_us) {
count += n;
steps += n_steps;
time += (uint64_t) t_ms;
time += t_us;
}
};
@@ -460,6 +463,12 @@ struct server_metrics {
uint64_t n_draft_verif_steps = 0; // Total draft token verification steps by the target model
std::vector<uint64_t> n_accepted_per_pos; // Accepted tokens per draft position
// these are internal counters to track batch processing
// llama_decode() is async, so we queue the counting until sync()
int64_t t_decode_start = 0; // start of the last submitted decode
int64_t t_prompt_start = 0; // start of the oldest queued prompt decode
uint64_t n_prompt_queued = 0;
void init() {
t_start = ggml_time_us();
}
@@ -469,8 +478,36 @@ struct server_metrics {
predict_bucket = {};
}
// these are implemented in server-context.cpp
void on_prompt_eval(const server_slot & slot);
void add_prompt(uint64_t n_tokens, uint64_t t_us) {
prompt .add(n_tokens, n_tokens, t_us);
prompt_bucket.add(n_tokens, n_tokens, t_us);
}
void on_decode_start() {
t_decode_start = ggml_time_us();
}
// the batch is submitted, but its compute may not be done yet
void queue_prompt(uint64_t n_tokens) {
if (n_tokens == 0) {
return;
}
if (n_prompt_queued == 0) {
t_prompt_start = t_decode_start;
}
n_prompt_queued += n_tokens;
}
// call only after the context is synchronized, otherwise the time is meaningless
void flush_prompt() {
if (n_prompt_queued == 0) {
return;
}
add_prompt(n_prompt_queued, ggml_time_us() - t_prompt_start);
n_prompt_queued = 0;
}
// this is implemented in server-context.cpp
void on_prediction(const server_slot & slot);
};
tools/server/server-context.cpp
+38 -24
View File
@@ -784,26 +784,13 @@ struct server_slot {
// server_metrics
//
void server_metrics::on_prompt_eval(const server_slot & slot) {
const double t_ms = slot.stats.t_prompt_ms();
// every prompt token needs one decode step
const uint64_t n = slot.stats.n_prompt_processed;
prompt .add(n, n, t_ms);
prompt_bucket.add(n, n, t_ms);
n_tokens_max = std::max(n_tokens_max, (uint64_t) slot.prompt.n_tokens());
}
void server_metrics::on_prediction(const server_slot & slot) {
const double t_ms = slot.stats.t_gen_ms();
const uint64_t t_us = slot.stats.t_gen_us();
const uint64_t n = slot.stats.n_predict;
const uint64_t n_steps = slot.stats.n_gen_steps();
predict .add(n, n_steps, t_ms);
predict_bucket.add(n, n_steps, t_ms);
predict .add(n, n_steps, t_us);
predict_bucket.add(n, n_steps, t_us);
n_draft_tokens += slot.stats.n_draft_tokens;
n_draft_accepted += slot.stats.n_draft_accepted;
@@ -3398,6 +3385,7 @@ private:
}
// process the mtmd chunk
auto t_now = ggml_time_us();
size_t n_tokens_out = 0;
int32_t res = slot.process_mtmd_chunk(cur_token_idx, n_tokens_out);
if (res != 0) {
@@ -3406,8 +3394,10 @@ private:
slot.release();
return; // the slot is done, skip it entirely
}
auto t_elapsed = ggml_time_us() - t_now;
// process_mtmd_chunk runs its own encode/decode, so we update stats right away
metrics.add_prompt(n_tokens_out, t_elapsed);
slot.stats.n_prompt_processed += n_tokens_out;
slot.stats.update_prompt_last();
@@ -3550,6 +3540,8 @@ private:
bool decode(int32_t & n_batch, int32_t off, llama_batch & batch_view) {
SRV_DBG("n_batch (effective) = %d, off = %d\n", n_batch, off);
metrics_pre_decode();
if (batch.size() == 0) {
SRV_WRN("%s", "no tokens to decode\n");
@@ -3611,6 +3603,9 @@ private:
// stop, do not retry with smaller batch size
throw std::runtime_error(err);
}
} else {
// success, apply batch metrics
metrics_post_decode(off, n_batch_tokens);
}
// retry with half the batch size to try to find a free slot in the KV cache
@@ -3621,9 +3616,6 @@ private:
SRV_WRN("failed to find free space in the KV cache, retrying with smaller batch size, off = %d, n_batch = %d, ret = %d\n", off, n_batch, ret);
return false; // retry with the updated n_batch
} else {
// note: retried decodes are not counted, the metrics only cover evaluated batches
metrics_on_decoded(off, batch_view.n_tokens);
}
// TODO: avoid restoring the draft context and re-evaluating the drafted tokens when not needed [TAG_SPEC_AVOID_DRAFT_REEVAL]
@@ -3753,7 +3745,6 @@ private:
slot.stats.update_prompt_last();
slot.t_print_last = t_now;
slot.n_decoded_last = 0;
metrics.on_prompt_eval(slot);
}
slot.stats.update_gen_last();
@@ -3913,8 +3904,15 @@ private:
return server_response_reader(queue_tasks, queue_results, HTTP_POLLING_SECONDS);
}
//
// metrics helpers
void metrics_on_decoded(int32_t off, int32_t n_tokens) {
//
void metrics_pre_decode() {
metrics.on_decode_start();
}
void metrics_post_decode(int32_t off, int32_t n_tokens) {
metrics.n_decode++;
for (const auto & slot : slots) {
if (slot.is_processing()) {
@@ -3922,13 +3920,29 @@ private:
}
metrics.n_tokens_max = std::max(metrics.n_tokens_max, (uint64_t) slot.prompt.n_tokens());
}
// apply enqueued prompt tokens stats from batch
// apply enqueued prompt tokens stats
uint64_t n_prompt_tokens = 0;
bool has_output = false;
for (int i = off; i < off + n_tokens; ++i) {
const auto & t = batch.tokens[i];
auto & slot = slots[t.id_slot];
if (t.is_prompt) {
n_prompt_tokens++;
slot.stats.n_prompt_processed++;
}
has_output |= t.output;
// note: generated tokens will be handled after sampling
}
metrics.queue_prompt(n_prompt_tokens);
if (has_output) {
// sync if we have at least one output in batch
// so that we can calculate the timings correctly
llama_synchronize(ctx_tgt);
metrics.flush_prompt();
}
}
};
@@ -4379,7 +4393,7 @@ void server_routes::init_routes() {
}, {
{"name", "prompt_seconds_total"},
{"help", "Prompt process time"},
{"value", res_task->prompt.time / 1.e3}
{"value", res_task->prompt.time / 1.e6}
}, {
{"name", "tokens_predicted_total"},
{"help", "Number of generation tokens processed."},
@@ -4387,7 +4401,7 @@ void server_routes::init_routes() {
}, {
{"name", "tokens_predicted_seconds_total"},
{"help", "Predict process time"},
{"value", res_task->predict.time / 1.e3}
{"value", res_task->predict.time / 1.e6}
}, {
{"name", "n_decode_total"},
{"help", "Total number of llama_decode() calls"},
tools/server/server-task.cpp
+4 -4
View File
@@ -1518,16 +1518,16 @@ json server_task_result_metrics::to_json() {
{ "t_start", t_start },
{ "n_prompt_tokens_processed_total", prompt.count },
{ "t_tokens_generation_total", predict.time },
{ "t_tokens_generation_total", predict.time / 1e3 },
{ "n_tokens_predicted_total", predict.count },
{ "t_prompt_processing_total", prompt.time },
{ "t_prompt_processing_total", prompt.time / 1e3 },
{ "n_tokens_max", n_tokens_max },
{ "n_prompt_tokens_processed", prompt_bucket.count },
{ "t_prompt_processing", prompt_bucket.time },
{ "t_prompt_processing", prompt_bucket.time / 1e3 },
{ "n_tokens_predicted", predict_bucket.count },
{ "t_tokens_generation", predict_bucket.time },
{ "t_tokens_generation", predict_bucket.time / 1e3 },
{ "n_decode_total", n_decode },
{ "n_busy_slots_total", n_busy_slots },