llama_token token;
llama_pos pos;
bool output;
+ bool is_prompt; // for stats tracking
};
std::vector<token> tokens;
int32_t n_tokens_alloc = 0;
tokens.reserve(n_tokens_alloc);
}
- bool add(int32_t id_slot, llama_token token, llama_pos pos, bool output) {
+ bool add(int32_t id_slot, llama_token token, llama_pos pos, bool output, bool is_prompt) {
GGML_ASSERT(!has_embd); // cannot mix tokens + embd in same batch
GGML_ASSERT(batch.pos != nullptr);
if ((int32_t)tokens.size() >= n_tokens_alloc) {
return false;
}
- tokens.push_back({ id_slot, token, pos, output });
+ tokens.push_back({ id_slot, token, pos, output, is_prompt });
return true;
}
- bool add(int32_t id_slot, const std::vector<float> & embd_in, llama_pos pos, bool output) {
+ bool add(int32_t id_slot, const std::vector<float> & embd_in, llama_pos pos, bool output, bool is_prompt) {
GGML_ASSERT(batch.pos != nullptr);
if ((int32_t)tokens.size() >= n_tokens_alloc) {
return false;
}
- tokens.push_back({ id_slot, LLAMA_TOKEN_NULL, pos, output });
+ tokens.push_back({ id_slot, LLAMA_TOKEN_NULL, pos, output, is_prompt });
has_embd = true;
embd.insert(embd.end(), embd_in.begin(), embd_in.end());
return true;
int64_t t_last_used = -1;
// generation props
- int32_t n_ctx = 0; // context size per slot
- int32_t n_keep = 0;
- int32_t n_decoded = 0;
- int32_t n_remaining = -1;
- int32_t i_batch = -1;
+ int32_t n_ctx = 0; // context size per slot
+ int32_t n_keep = 0;
+ int32_t i_batch = -1;
- int32_t n_prompt_tokens_cache = 0;
- int32_t n_prompt_tokens_processed = 0;
+ // effective generation limit for the current task, -1 means unlimited
+ int32_t n_predict_max = -1;
size_t last_nl_pos = 0;
std::string generated_text;
std::string debug_generated_text;
llama_tokens generated_tokens;
+ size_t n_sent_text = 0; // number of sent text character (i.e. handle partial UTF-8 on streaming)
std::vector<completion_token_output> generated_token_probs;
// corresponding to one token position (size = n_embd)
std::vector<float> inp_embd;
- // stats
- size_t n_sent_text = 0; // number of sent text character
+ server_slot_stats stats;
- // TODO @ngxson : move all metrics to a sub-struct for clarity
- int64_t t_start_process_prompt;
- int64_t t_start_generation;
- int64_t t_print_last = 0;
- int32_t n_decoded_last = 0;
-
- double t_prompt_processing = 0.0; // ms
- double t_token_generation = 0.0; // ms
+ // accepted tokens per draft position
+ // not in server_slot_stats to avoid copying to every task result
+ std::vector<uint64_t> n_accepted_per_pos;
- std::function<void(int /* id_slot */)> callback_on_release;
+ std::function<void(int /* id_slot */)> callback_on_release;
+ std::function<void(const server_slot &)> callback_on_reset; // called before reset()
- // Speculative decoding stats
- int32_t n_draft_total = 0; // Total draft tokens generated
- int32_t n_draft_accepted = 0; // Draft tokens actually accepted
- int32_t n_draft_verif_steps = 0; // Total draft token verification steps by the target model
- std::vector<int32_t> n_accepted_per_pos; // Accepted tokens per draft position
+ // this is for printing timings with slot progress, not part of metrics
+ int64_t t_print_last = 0;
+ int32_t n_gen_last = 0;
void reset() {
SLT_DBG(*this, "%s", "\n");
spec_is_replay = false;
- n_prompt_tokens_cache = 0;
-
last_nl_pos = 0;
generated_text = "";
has_new_line = false;
generated_token_probs.clear();
json_schema = json();
- // clear speculative decoding stats
- n_draft_total = 0;
- n_draft_accepted = 0;
- n_draft_verif_steps = 0;
- n_accepted_per_pos.clear();
-
task_prev = std::move(task);
task.reset();
+ // note: callback_on_reset() must have run before this, see release()
+ stats = {};
+ n_accepted_per_pos.clear();
+
+ n_predict_max = -1;
+
llama_set_sampler(ctx_tgt, id, nullptr);
// clear alora start
&& are_lora_equal(lora, other_slot.lora);
}
- bool has_budget(const common_params & global_params) {
- GGML_ASSERT(task);
-
- if (task->params.n_predict == -1 && global_params.n_predict == -1) {
- return true; // limitless
- }
-
- n_remaining = -1;
-
- if (task->params.n_predict != -1) {
- n_remaining = task->params.n_predict - n_decoded;
- } else if (global_params.n_predict != -1) {
- n_remaining = global_params.n_predict - n_decoded;
- }
+ // returns -1 if the generation is limitless
+ int32_t n_remaining() const {
+ return n_predict_max == -1 ? -1 : n_predict_max - (int32_t) stats.n_gen;
+ }
- return n_remaining > 0; // no budget
+ bool has_budget() const {
+ return n_predict_max == -1 || n_remaining() > 0;
}
bool is_processing() const {
// also, need to leave space for 1 extra token to allow context shifts
int n_draft_max = n_ctx - prompt.n_tokens() - 2;
- if (n_remaining > 0) {
- n_draft_max = std::min(n_draft_max, n_remaining - 1);
+ if (n_remaining() > 0) {
+ n_draft_max = std::min(n_draft_max, n_remaining() - 1);
}
SLT_DBG(*this, "max possible draft: %d\n", n_draft_max);
i_batch = batch.size();
if (!inp_embd.empty()) {
- add_ok &= batch.add(id, inp_embd, prompt.tokens.pos_next(), true);
+ add_ok &= batch.add(id, inp_embd, prompt.tokens.pos_next(), true, false);
} else {
- add_ok &= batch.add(id, sampled, prompt.tokens.pos_next(), true);
+ add_ok &= batch.add(id, sampled, prompt.tokens.pos_next(), true, false);
}
SLT_DBG(*this, "slot decode token, id=%d, n_ctx = %d, n_tokens = %d, truncated = %d\n",
auto pos0 = prompt.tokens.pos_next();
- add_ok &= batch.add(id, sampled, pos0++, true);
+ add_ok &= batch.add(id, sampled, pos0++, true, false);
for (auto token : spec_draft) {
- add_ok &= batch.add(this->id, token, pos0++, true);
+ add_ok &= batch.add(this->id, token, pos0++, true, false);
}
}
SLT_INF(*this, "stop processing: n_tokens = %d, truncated = %d\n", prompt.n_tokens(), truncated);
- t_last_used = ggml_time_us();
- t_token_generation = (ggml_time_us() - t_start_generation) / 1e3;
+ t_last_used = ggml_time_us();
state = SLOT_STATE_IDLE;
prompt_clear();
}
+ callback_on_reset(*this);
+
reset();
callback_on_release(id);
}
}
- result_timings get_timings() const {
- result_timings timings;
- timings.cache_n = n_prompt_tokens_cache;
-
- timings.prompt_n = n_prompt_tokens_processed;
- timings.prompt_ms = t_prompt_processing;
- timings.prompt_per_token_ms = t_prompt_processing / n_prompt_tokens_processed;
- timings.prompt_per_second = 1e3 / t_prompt_processing * n_prompt_tokens_processed;
-
- timings.predicted_n = n_decoded;
- timings.predicted_ms = t_token_generation;
- timings.predicted_per_token_ms = t_token_generation / n_decoded;
- timings.predicted_per_second = 1e3 / t_token_generation * n_decoded;
-
- // Add speculative metrics
- if (n_draft_total > 0) {
- timings.draft_n = n_draft_total;
- timings.draft_n_accepted = n_draft_accepted;
- }
-
- return timings;
- }
-
size_t find_stopping_strings(const std::string & text, const size_t last_token_size, bool is_full_stop) {
GGML_ASSERT(task);
}
void print_timings_tg() {
- if (n_decoded < 100) {
+ if (stats.n_gen < 100) {
return;
}
return;
}
- const double n_gen_second = 1e3 / (t_token_generation) * (n_decoded);
- const double n_gen_second_win = 1e6 / (t_now - t_print_last) * (n_decoded - n_decoded_last);
+ const double n_gen_second = stats.n_gen_tps();
+ const double n_gen_second_win = 1e6 / (t_now - t_print_last) * (stats.n_gen - n_gen_last);
t_print_last = t_now;
- n_decoded_last = n_decoded;
+ n_gen_last = stats.n_gen;
- SLT_INF(*this, "n_decoded = %6d, tg = %6.2f t/s, tg_3s = %6.2f t/s\n", n_decoded, n_gen_second, n_gen_second_win);
+ SLT_INF(*this, "n_gen = %6d, tg = %6.2f t/s, tg_3s = %6.2f t/s\n", (int) stats.n_gen, n_gen_second, n_gen_second_win);
}
void print_timings_pp() const {
- const double n_prompt_second = 1e3 / t_prompt_processing * n_prompt_tokens_processed;
- const double f_progress = (float) prompt.n_tokens() / task->n_tokens();
+ const double t_prompt_total = stats.t_prompt_ms();
- if (t_prompt_processing < 3000.0) {
+ if (t_prompt_total < 3000.0) {
return;
}
+ const double n_prompt_second = stats.n_prompt_tps();
+ const double f_progress = task->n_tokens() > 0 ? (double) prompt.n_tokens() / task->n_tokens() : 0.0;
+
SLT_INF(*this, "prompt processing, n_tokens = %6d, progress = %.2f, t = %6.2f s / %.2f tokens per second\n",
- n_prompt_tokens_processed, f_progress, t_prompt_processing / 1e3, n_prompt_second);
+ (int) stats.n_prompt_processed, f_progress, t_prompt_total / 1e3, n_prompt_second);
}
void print_timings() const {
- const double t_prompt = t_prompt_processing / n_prompt_tokens_processed;
- const double n_prompt_second = 1e3 / t_prompt_processing * n_prompt_tokens_processed;
+ const double t_prompt_total = stats.t_prompt_ms();
+ const double t_gen_total = stats.t_gen_ms();
+
+ const double t_prompt = stats.t_prompt_per_token_ms();
+ const double n_prompt_second = stats.n_prompt_tps();
- const double t_gen = t_token_generation / n_decoded;
- const double n_gen_second = 1e3 / t_token_generation * n_decoded;
+ const double t_gen = stats.t_gen_per_token_ms();
+ const double n_gen_second = stats.n_gen_tps();
SLT_INF(*this,
"prompt eval time = %10.2f ms / %5d tokens (%8.2f ms per token, %8.2f tokens per second)\n",
- t_prompt_processing, n_prompt_tokens_processed, t_prompt, n_prompt_second);
+ t_prompt_total, (int) stats.n_prompt_processed, t_prompt, n_prompt_second);
SLT_INF(*this,
" eval time = %10.2f ms / %5d tokens (%8.2f ms per token, %8.2f tokens per second)\n",
- t_token_generation, n_decoded, t_gen, n_gen_second);
+ t_gen_total, (int) stats.n_gen, t_gen, n_gen_second);
SLT_INF(*this,
" total time = %10.2f ms / %5d tokens\n",
- t_prompt_processing + t_token_generation, n_prompt_tokens_processed + n_decoded);
+ t_prompt_total + t_gen_total, (int) (stats.n_prompt_processed + stats.n_gen));
SLT_INF(*this,
" graphs reused = %10d\n",
llama_perf_context(ctx_tgt).n_reused);
+ const int32_t n_draft_total = stats.n_draft_tokens;
+ const int32_t n_draft_accepted = stats.n_draft_accepted;
+ const int32_t n_draft_verif_steps = stats.n_draft_verif_steps;
+
if (n_draft_total > 0) {
const float draft_ratio = (float) n_draft_accepted / n_draft_total;
const double mean_acc_len = n_draft_verif_steps > 0 ? 1.0 + (double) n_draft_accepted / (double) n_draft_verif_steps : 1.0;
if (ptask) {
res["id_task"] = ptask->id;
res["n_prompt_tokens"] = (int32_t) prompt.tokens.size();
- res["n_prompt_tokens_processed"] = n_prompt_tokens_processed;
- res["n_prompt_tokens_cache"] = n_prompt_tokens_cache;
+ res["n_prompt_tokens_processed"] = stats.n_prompt_processed;
+ res["n_prompt_tokens_cache"] = stats.n_prompt_cached;
res["params"] = ptask->params.to_json(only_metrics);
res["next_token"] = {
{
{"has_next_token", has_next_token},
{"has_new_line", has_new_line},
- {"n_remain", n_remaining},
- {"n_decoded", n_decoded},
+ {"n_remain", n_remaining()},
+ {"n_decoded", stats.n_gen},
}
};
mem.seq_rm(other.id, -1, -1);
mem.seq_cp(id, other.id, -1, -1);
- other.n_decoded = n_decoded;
- other.n_remaining = n_remaining;
- other.i_batch = i_batch;
+ other.i_batch = i_batch;
- other.t_start_process_prompt = t_start_process_prompt;
- other.t_prompt_processing = t_prompt_processing;
- other.n_prompt_tokens_cache = n_prompt_tokens_cache;
- other.n_prompt_tokens_processed = n_prompt_tokens_processed;
+ other.stats = stats;
other.prompt = prompt.clone();
other.init_sampler();
-//
-// server_metrics
-//
-
-struct server_metrics {
- int64_t t_start = 0;
-
- uint64_t n_prompt_tokens_processed_total = 0;
- uint64_t t_prompt_processing_total = 0;
- uint64_t n_tokens_predicted_total = 0;
- uint64_t t_tokens_generation_total = 0;
-
- uint64_t n_tokens_max = 0;
-
- uint64_t n_prompt_tokens_processed = 0;
- uint64_t t_prompt_processing = 0;
-
- uint64_t n_tokens_predicted = 0;
- uint64_t t_tokens_generation = 0;
-
- uint64_t n_decode_total = 0;
- uint64_t n_busy_slots_total = 0;
-
- uint64_t n_draft_tokens_total = 0;
- uint64_t n_draft_accepted_total = 0;
- uint64_t n_draft_verif_steps_total = 0;
- std::vector<uint64_t> n_accepted_per_pos_total;
-
- void init() {
- t_start = ggml_time_us();
- }
-
- void on_prompt_eval(const server_slot & slot) {
- n_prompt_tokens_processed_total += slot.n_prompt_tokens_processed;
- n_prompt_tokens_processed += slot.n_prompt_tokens_processed;
- t_prompt_processing += slot.t_prompt_processing;
- t_prompt_processing_total += slot.t_prompt_processing;
-
- n_tokens_max = std::max(n_tokens_max, (uint64_t) slot.prompt.n_tokens());
- }
-
- void on_prediction(const server_slot & slot) {
- n_tokens_predicted_total += slot.n_decoded;
- n_tokens_predicted += slot.n_decoded;
- t_tokens_generation += slot.t_token_generation;
- t_tokens_generation_total += slot.t_token_generation;
-
- n_draft_tokens_total += slot.n_draft_total;
- n_draft_accepted_total += slot.n_draft_accepted;
- n_draft_verif_steps_total += slot.n_draft_verif_steps;
-
- if (n_accepted_per_pos_total.size() < slot.n_accepted_per_pos.size()) {
- n_accepted_per_pos_total.resize(slot.n_accepted_per_pos.size(), 0);
- }
- for (size_t i = 0; i < slot.n_accepted_per_pos.size(); i++) {
- n_accepted_per_pos_total[i] += slot.n_accepted_per_pos[i];
- }
- }
-
- void on_decoded(const std::vector<server_slot> & slots) {
- n_decode_total++;
- for (const auto & slot : slots) {
- if (slot.is_processing()) {
- n_busy_slots_total++;
- }
- n_tokens_max = std::max(n_tokens_max, (uint64_t) slot.prompt.n_tokens());
- }
- }
-
- void reset_bucket() {
- n_prompt_tokens_processed = 0;
- t_prompt_processing = 0;
- n_tokens_predicted = 0;
- t_tokens_generation = 0;
- }
-};
-
-
//
// server_context_impl (private implementation)
//
server_metrics metrics;
+ // queued prompt stats - llama_decode() is async, so the timing is only valid after a sync
+ // note: kept out of server_metrics, which is copied as-is into the task result
+ 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;
+
json json_ui_settings = json::object();
// Necessary similarity of prompt for slot selection
queue_tasks.pop_deferred_task(id_slot);
};
+ slot.callback_on_reset = [this](const server_slot & slot) {
+ // flush the generated token stats before reset()
+ if (slot.stats.n_gen > 0) {
+ metrics_on_prediction(slot);
+ }
+ };
+
slot.reset();
}
slot.smpl.reset();
}
+ // the per-request limit takes priority over the global one
+ slot.n_predict_max = task.params.n_predict != -1 ? task.params.n_predict : params_base.n_predict;
+
slot.task = std::make_unique<const server_task>(std::move(task));
slot.state = slot.task->is_child()
slot.stop = STOP_TYPE_LIMIT;
slot.has_next_token = false;
- SLT_DBG(slot, "stopped due to running out of context capacity, prompt.n_tokens() = %d, task.n_tokens = %d, n_decoded = %d, n_ctx = %d\n",
- slot.prompt.n_tokens(), slot.task->n_tokens(), slot.n_decoded, slot.n_ctx);
+ SLT_DBG(slot, "stopped due to running out of context capacity, prompt.n_tokens() = %d, task.n_tokens = %d, n_gen = %d, n_ctx = %d\n",
+ slot.prompt.n_tokens(), slot.task->n_tokens(), (int) slot.stats.n_gen, slot.n_ctx);
}
// check the limits
- if (slot.n_decoded > 0 && slot.has_next_token && !slot.has_budget(params_base)) {
+ if (slot.stats.n_gen > 0 && slot.has_next_token && !slot.has_budget()) {
slot.stop = STOP_TYPE_LIMIT;
slot.has_next_token = false;
- SLT_DBG(slot, "stopped by limit, n_decoded = %d, n_predict = %d\n", slot.n_decoded, slot.task->params.n_predict);
+ SLT_DBG(slot, "stopped by limit, n_gen = %d, n_predict = %d\n", (int) slot.stats.n_gen, slot.task->params.n_predict);
}
if (slot.has_new_line) {
// cut the last line
slot.generated_text.erase(pos, std::string::npos);
- SLT_DBG(slot, "stopped by indentation limit, n_decoded = %d, n_indent = %d\n", slot.n_decoded, n_indent);
+ SLT_DBG(slot, "stopped by indentation limit, n_gen = %d, n_indent = %d\n", (int) slot.stats.n_gen, n_indent);
}
}
slot.has_new_line = true;
// if we have seen a new line, we stop after a certain time limit, but only upon another new line
- if (slot.task->params.t_max_predict_ms > 0 && (ggml_time_us() - slot.t_start_generation > 1000.0f*slot.task->params.t_max_predict_ms)) {
+ if (slot.task->params.t_max_predict_ms > 0 && slot.stats.t_gen_ms() > slot.task->params.t_max_predict_ms) {
slot.stop = STOP_TYPE_LIMIT;
slot.has_next_token = false;
- SLT_DBG(slot, "stopped by time limit, n_decoded = %d, t_max_predict_ms = %d ms\n", slot.n_decoded, (int) slot.task->params.t_max_predict_ms);
+ SLT_DBG(slot, "stopped by time limit, n_gen = %d, t_max_predict_ms = %d ms\n", (int) slot.stats.n_gen, (int) slot.task->params.t_max_predict_ms);
}
}
SLT_DBG(slot, "%s", "stopped by EOS\n");
}
- SLT_DBG(slot, "n_decoded = %d, n_remaining = %d, next token: %5d '%s'\n", slot.n_decoded, slot.n_remaining, result.tok, token_str.c_str());
+ SLT_DBG(slot, "n_gen = %d, n_remaining = %d, next token: %5d '%s'\n", (int) slot.stats.n_gen, slot.n_remaining(), result.tok, token_str.c_str());
return slot.has_next_token; // continue
}
if (is_progress) {
res->is_progress = true;
res->progress.total = slot.task->n_tokens();
- res->progress.cache = slot.n_prompt_tokens_cache;
+ res->progress.cache = slot.stats.n_prompt_cached;
res->progress.processed = slot.prompt.tokens.size();
- res->progress.time_ms = (ggml_time_us() - slot.t_start_process_prompt) / 1000;
+ res->progress.time_ms = slot.stats.t_elapsed_us() / 1000;
}
if (is_begin) {
res->is_begin = true;
res->tokens = { tkn.tok };
}
- res->n_decoded = slot.n_decoded;
+ res->n_decoded = slot.stats.n_gen;
res->n_prompt_tokens = slot.task->n_tokens();
- res->n_prompt_tokens_cache = slot.n_prompt_tokens_cache;
+ res->n_prompt_tokens_cache = slot.stats.n_prompt_cached;
res->post_sampling_probs = slot.task->params.post_sampling_probs;
res->verbose = slot.task->params.verbose;
// populate timings if this is final response or timings_per_token is enabled
if (slot.stop != STOP_TYPE_NONE || slot.task->params.timings_per_token) {
- res->timings = slot.get_timings();
+ res->stats = slot.stats;
}
queue_results.send(std::move(res));
res->content = std::move(slot.generated_text);
res->tokens = std::move(slot.generated_tokens);
}
- res->timings = slot.get_timings();
+ res->stats = slot.stats;
res->prompt = slot.task->tokens.detokenize(ctx_tgt, true);
res->response_fields = std::move(slot.task->params.response_fields);
res->truncated = slot.truncated;
- res->n_decoded = slot.n_decoded;
+ res->n_decoded = slot.stats.n_gen;
res->n_prompt_tokens = slot.task->n_tokens();
- res->n_prompt_tokens_cache = slot.n_prompt_tokens_cache;
+ res->n_prompt_tokens_cache = slot.stats.n_prompt_cached;
res->n_tokens_cached = slot.prompt.n_tokens();
res->has_new_line = slot.has_new_line;
res->stopping_word = slot.stopping_word;
res->n_idle_slots = n_idle_slots;
res->n_processing_slots = n_processing_slots;
res->n_tasks_deferred = queue_tasks.queue_tasks_deferred_size();
- res->t_start = metrics.t_start;
-
- res->n_prompt_tokens_processed_total = metrics.n_prompt_tokens_processed_total;
- res->t_prompt_processing_total = metrics.t_prompt_processing_total;
- res->n_tokens_predicted_total = metrics.n_tokens_predicted_total;
- res->t_tokens_generation_total = metrics.t_tokens_generation_total;
-
- res->n_tokens_max = metrics.n_tokens_max;
-
- res->n_prompt_tokens_processed = metrics.n_prompt_tokens_processed;
- res->t_prompt_processing = metrics.t_prompt_processing;
- res->n_tokens_predicted = metrics.n_tokens_predicted;
- res->t_tokens_generation = metrics.t_tokens_generation;
-
- res->n_decode_total = metrics.n_decode_total;
- res->n_busy_slots_total = metrics.n_busy_slots_total;
-
- res->n_draft_tokens_total = metrics.n_draft_tokens_total;
- res->n_draft_accepted_total = metrics.n_draft_accepted_total;
- res->n_draft_verif_steps_total = metrics.n_draft_verif_steps_total;
- res->n_accepted_per_pos_total = metrics.n_accepted_per_pos_total;
+ res->metrics = metrics;
if (task.metrics_reset_bucket) {
metrics.reset_bucket();
if (all_idle) {
SRV_TRC("%s", "all slots are idle\n");
+
+ metrics_flush_idle();
+
return; // skip further processing
} else {
} catch (const std::exception & e) {
SRV_ERR("pre_decode() failed: %s\n", e.what());
abort_all_slots("pre_decode() failed: " + std::string(e.what()));
+
+ // the batch is half-built and not rendered, skip now to avoid UB
+ return;
}
GGML_ASSERT(batch.slot_batched || batch.size() == 0);
auto & draft = slot.spec_draft;
auto & ckpt = slot.spec_ckpt;
- slot.n_draft_total += draft.size();
+ slot.stats.n_draft_tokens += draft.size();
// TODO: avoid restoring the draft context and re-evaluating the drafted tokens when not needed [TAG_SPEC_AVOID_DRAFT_REEVAL]
const bool use_ckpt_dft = ctx_dft_seq_rm_type == COMMON_CONTEXT_SEQ_RM_TYPE_FULL;
// TODO: maybe move branch to outside of this loop in the future
if (slot.state == SLOT_STATE_STARTED) {
- slot.t_start_process_prompt = ggml_time_us();
- slot.t_start_generation = 0;
+ slot.stats.update_prompt_start();
slot.state = SLOT_STATE_PROCESSING_PROMPT;
SLT_WRN(slot, "n_past was set to %d\n", n_past);
}
- slot.n_prompt_tokens_cache = n_past;
- slot.n_prompt_tokens_processed = 0;
+ slot.stats.n_prompt_cached = n_past;
+ slot.stats.n_prompt_processed = 0;
+
+ metrics.add_prompt_cached(n_past);
slot.prompt.tokens.keep_first(n_past);
}
}
- const int64_t t_now = ggml_time_us();
- slot.t_prompt_processing = (t_now - slot.t_start_process_prompt) / 1e3;
+ // note: the prompt timing is advanced in post_decode(), so it does not cover
+ // the tokens added to the batch below
slot.print_timings_pp();
// truncate any tokens that are beyond n_past for this slot
bool has_mtmd = false;
- // check if we should process the image
+ // check if we should process the mtmd chunk
while (true) {
auto cur_token_idx = slot.prompt.n_tokens();
if (
break;
}
- // process the image
+ // process the mtmd chunk
+ // note: it submits its own decode, potentially be async
+ // so the timing is queued and flushed on the next sync
+ metrics_pre_decode();
+
size_t n_tokens_out = 0;
int32_t res = slot.process_mtmd_chunk(cur_token_idx, n_tokens_out);
if (res != 0) {
- SLT_ERR(slot, "failed to process image, res = %d\n", res);
- send_error(slot, "failed to process image", ERROR_TYPE_SERVER);
+ SLT_ERR(slot, "failed to process mtmd chunk, res = %d\n", res);
+ send_error(slot, "failed to process mtmd chunk", ERROR_TYPE_SERVER);
slot.release();
- continue;
+ return; // the slot is done, skip it entirely
}
- slot.n_prompt_tokens_processed += n_tokens_out;
+ metrics_queue_prompt(n_tokens_out);
+ slot.stats.n_prompt_processed += n_tokens_out;
+ slot.stats.update_prompt_last();
- // add the image chunk to cache
+ // add the mtmd chunk to cache
{
const auto & chunk = input_tokens.find_chunk(cur_token_idx);
slot.prompt.tokens.push_back(chunk.get()); // copy
// streaming hook can mirror t_h_nextn into ctx_dft.
add_ok &= batch.add(slot.id,
cur_tok,
- slot.prompt.tokens.pos_next(),
- slot.need_embd());
+ /* pos = */ slot.prompt.tokens.pos_next(),
+ /* output = */ slot.need_embd(),
+ /* is_prompt = */ true);
slot.prompt.tokens.push_back(cur_tok);
- slot.n_prompt_tokens_processed++;
-
// break at the last user message, or at user messages at least min step past the last checkpoint
if (do_checkpoint && spans.is_user_start(slot.prompt.n_tokens())) {
const auto pos = slot.prompt.n_tokens();
// extract the logits only for the last token
batch.set_output(batch.size() - 1, true);
- slot.n_decoded = 0;
- slot.i_batch = batch.size() - 1;
+ slot.stats.n_gen = 0;
+ slot.i_batch = batch.size() - 1;
slot.init_sampler();
} else {
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");
const int ret = llama_decode(ctx_tgt, batch_view);
- metrics.on_decoded(slots);
-
if (ret != 0) {
{
std::string err;
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 {
+ // success, apply batch metrics
+ metrics_post_decode(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]
// here we have synchronized the llama_context (due to the sampling above), so we can do time measurement
const int64_t t_now = ggml_time_us();
- slot.n_decoded += 1;
+ slot.stats.n_gen += 1;
- if (slot.n_decoded == 1) {
- slot.t_start_generation = t_now;
+ if (slot.stats.n_gen == 1) {
+ slot.stats.update_prompt_last();
slot.t_print_last = t_now;
- slot.n_decoded_last = 0;
- slot.t_prompt_processing = (slot.t_start_generation - slot.t_start_process_prompt) / 1e3;
- metrics.on_prompt_eval(slot);
+ slot.n_gen_last = 0;
}
- slot.t_token_generation = std::max<int64_t>(1, t_now - slot.t_start_generation) / 1e3;
+ slot.stats.update_gen_last();
completion_token_output result;
result.tok = id;
// release slot because of stop condition
slot.print_timings();
send_final_response(slot);
- metrics.on_prediction(slot);
slot.release();
return;
slot.spec_draft = std::move(accepted);
}
- const int64_t t_now = ggml_time_us();
-
const auto ids = std::move(slot.spec_draft);
size_t n_accepted = ids.size() - 1;
}
slot.spec_is_replay = false;
- slot.t_token_generation = std::max<int64_t>(1, t_now - slot.t_start_generation) / 1e3;
+ slot.stats.update_gen_last();
// update how many tokens out of those tested were accepted
- slot.n_draft_accepted += n_accepted;
- slot.n_draft_verif_steps += 1;
+ slot.stats.n_draft_accepted += n_accepted;
+ slot.stats.n_draft_verif_steps += 1;
- if (slot.n_accepted_per_pos.empty()) {
- slot.n_accepted_per_pos.resize(common_speculative_n_max(¶ms_base.speculative), 0);
+ auto & n_accepted_per_pos = slot.n_accepted_per_pos;
+ if (n_accepted_per_pos.empty()) {
+ n_accepted_per_pos.resize(common_speculative_n_max(¶ms_base.speculative), 0);
}
- for (size_t i = 0; i < n_accepted && i < slot.n_accepted_per_pos.size(); ++i) {
- slot.n_accepted_per_pos[i]++;
+ for (size_t i = 0; i < n_accepted && i < n_accepted_per_pos.size(); ++i) {
+ n_accepted_per_pos[i]++;
}
// add accepted tokens to the prompt
// TODO: set result.probs
- slot.n_decoded += 1;
+ slot.stats.n_gen += 1;
if (!process_token(result, slot)) {
slot.print_timings();
send_final_response(slot);
- metrics.on_prediction(slot);
slot.release();
return;
server_response_reader get_response_reader() {
return server_response_reader(queue_tasks, queue_results, HTTP_POLLING_SECONDS);
}
+
+ //
+ // metrics helpers
+ //
+
+ // call before submitting a decode, so that the queued prompt stats can be timed
+ void metrics_pre_decode() {
+ t_decode_start = ggml_time_us();
+ }
+
+ // the batch is submitted, but its compute may not be done yet
+ void metrics_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 metrics_flush_prompt() {
+ if (n_prompt_queued == 0) {
+ return;
+ }
+ metrics.add_prompt(n_prompt_queued, ggml_time_us() - t_prompt_start);
+ n_prompt_queued = 0;
+ }
+
+ void metrics_post_decode(int32_t off, int32_t n_tokens) {
+ metrics.n_decode++;
+ for (const auto & slot : slots) {
+ if (slot.is_processing()) {
+ metrics.n_busy_slots++;
+ }
+ metrics.n_tokens_max = std::max(metrics.n_tokens_max, (uint64_t) slot.prompt.n_tokens());
+ }
+
+ // apply enqueued prompt tokens stats
+ // note: a slot can be released before we get here, which clears its stats
+ // the tokens were still computed, counted in the global metrics, not in slot
+ 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];
+
+ has_output |= t.output;
+
+ if (!t.is_prompt) {
+ continue; // generated tokens are handled after sampling
+ }
+
+ n_prompt_tokens++;
+
+ auto & slot = slots[t.id_slot];
+ if (slot.stats.is_set()) {
+ slot.stats.n_prompt_processed++;
+ }
+ }
+
+ 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();
+ }
+
+ // advance the prompt timing of the slots that had tokens in this batch
+ // note: a second pass, it must run after the sync above to reflect the compute
+ const int64_t t_now = ggml_time_us();
+ 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 && slot.stats.is_set()) {
+ slot.stats.set_prompt_last(t_now);
+ }
+ }
+ }
+
+ // flush any queued prompt metrics if all slots are now idle
+ void metrics_flush_idle() {
+ if (n_prompt_queued == 0) {
+ return;
+ }
+
+ llama_synchronize(ctx_tgt);
+ metrics_flush_prompt();
+ }
+
+ void metrics_on_prediction(const server_slot & slot) {
+ const uint64_t t_us = slot.stats.t_gen_us();
+ const uint64_t n = slot.stats.n_gen;
+ const uint64_t n_steps = slot.stats.n_gen_steps();
+
+ metrics.predict .add(n, n_steps, t_us);
+ metrics.predict_bucket.add(n, n_steps, t_us);
+
+ metrics.n_draft_tokens += slot.stats.n_draft_tokens;
+ metrics.n_draft_accepted += slot.stats.n_draft_accepted;
+ metrics.n_draft_verif_steps += slot.stats.n_draft_verif_steps;
+
+ auto & dst = metrics.n_accepted_per_pos;
+ const auto & src = slot.n_accepted_per_pos;
+
+ if (dst.size() < src.size()) {
+ dst.resize(src.size(), 0);
+ }
+ for (size_t i = 0; i < src.size(); i++) {
+ dst[i] += src[i];
+ }
+ }
};
//
{
server_task task(SERVER_TASK_TYPE_METRICS);
task.id = res->rd.get_new_id();
+ // the gauges are averaged over the window between two scrapes
+ task.metrics_reset_bucket = true;
res->rd.post_task(std::move(task), true); // high-priority task
}
return res;
}
- // TODO: get rid of this dynamic_cast
auto res_task = dynamic_cast<server_task_result_metrics*>(result.get());
GGML_ASSERT(res_task != nullptr);
- // metrics definition: https://prometheus.io/docs/practices/naming/#metric-names
- json all_metrics_def = json {
- {"counter", {{
- {"name", "prompt_tokens_total"},
- {"help", "Number of prompt tokens processed."},
- {"value", (uint64_t) res_task->n_prompt_tokens_processed_total}
- }, {
- {"name", "prompt_seconds_total"},
- {"help", "Prompt process time"},
- {"value", (uint64_t) res_task->t_prompt_processing_total / 1.e3}
- }, {
- {"name", "tokens_predicted_total"},
- {"help", "Number of generation tokens processed."},
- {"value", (uint64_t) res_task->n_tokens_predicted_total}
- }, {
- {"name", "tokens_predicted_seconds_total"},
- {"help", "Predict process time"},
- {"value", (uint64_t) res_task->t_tokens_generation_total / 1.e3}
- }, {
- {"name", "n_decode_total"},
- {"help", "Total number of llama_decode() calls"},
- {"value", res_task->n_decode_total}
- }, {
- {"name", "n_tokens_max"},
- {"help", "Largest observed n_tokens."},
- {"value", res_task->n_tokens_max}
- }, {
- {"name", "spec_decode_num_draft_tokens_total"},
- {"help", "Total draft tokens generated"},
- {"value", res_task->n_draft_tokens_total}
- }, {
- {"name", "spec_decode_num_accepted_tokens_total"},
- {"help", "Total draft tokens accepted by the target model"},
- {"value", res_task->n_draft_accepted_total}
- }, {
- {"name", "spec_decode_num_drafts_total"},
- {"help", "Total speculative decoding verification steps"},
- {"value", res_task->n_draft_verif_steps_total}
- }}},
- {"gauge", {{
- {"name", "prompt_tokens_seconds"},
- {"help", "Average prompt throughput in tokens/s."},
- {"value", res_task->n_prompt_tokens_processed ? 1.e3 / res_task->t_prompt_processing * res_task->n_prompt_tokens_processed : 0.}
- },{
- {"name", "predicted_tokens_seconds"},
- {"help", "Average generation throughput in tokens/s."},
- {"value", res_task->n_tokens_predicted ? 1.e3 / res_task->t_tokens_generation * res_task->n_tokens_predicted : 0.}
- },{
- {"name", "requests_processing"},
- {"help", "Number of requests processing."},
- {"value", (uint64_t) res_task->n_processing_slots}
- },{
- {"name", "requests_deferred"},
- {"help", "Number of requests deferred."},
- {"value", (uint64_t) res_task->n_tasks_deferred}
- },{
- {"name", "n_busy_slots_per_decode"},
- {"help", "Average number of busy slots per llama_decode() call"},
- {"value", (float) res_task->n_busy_slots_total / std::max((float) res_task->n_decode_total, 1.f)}
- }}}
- };
-
- std::stringstream prometheus;
-
- for (const auto & el : all_metrics_def.items()) {
- const auto & type = el.key();
- const auto & metrics_def = el.value();
-
- for (const auto & metric_def : metrics_def) {
- const std::string name = metric_def.at("name");
- const std::string help = metric_def.at("help");
-
- auto value = json_value(metric_def, "value", 0.);
- prometheus << "# HELP llamacpp:" << name << " " << help << "\n"
- << "# TYPE llamacpp:" << name << " " << type << "\n"
- << "llamacpp:" << name << " " << value << "\n";
- }
- }
-
- // labeled counter: one time series per draft position
- if (!res_task->n_accepted_per_pos_total.empty()) {
- prometheus << "# HELP llamacpp:spec_decode_num_accepted_tokens_per_pos_total"
- " Accepted tokens per draft position\n"
- << "# TYPE llamacpp:spec_decode_num_accepted_tokens_per_pos_total counter\n";
- for (size_t i = 0; i < res_task->n_accepted_per_pos_total.size(); i++) {
- prometheus << "llamacpp:spec_decode_num_accepted_tokens_per_pos_total{position=\""
- << i << "\"} " << res_task->n_accepted_per_pos_total[i] << "\n";
- }
- }
-
- res->headers["Process-Start-Time-Unix"] = std::to_string(res_task->t_start);
+ res->headers["Process-Start-Time-Unix"] = std::to_string(res_task->metrics.t_start);
res->content_type = "text/plain; version=0.0.4";
res->status = 200;
- res->data = prometheus.str();
+ res->data = res_task->to_metrics();
return res;
};
return res;
}
- // TODO: get rid of this dynamic_cast
auto * res_task = dynamic_cast<server_task_result_metrics*>(result.get());
GGML_ASSERT(res_task != nullptr);
}
}
- res->ok(res_task->slots_data);
+ res->ok(res_task->to_json());
return res;
};
#include "speculative.h"
#include "server-common.h"
+#include <sstream>
+
using json = nlohmann::ordered_json;
//
return chat_msg;
}
-//
-
-// result_timings
-//
-
-json result_timings::to_json() const {
- json base = {
- {"cache_n", cache_n},
-
- {"prompt_n", prompt_n},
- {"prompt_ms", prompt_ms},
- {"prompt_per_token_ms", prompt_per_token_ms},
- {"prompt_per_second", prompt_per_second},
-
- {"predicted_n", predicted_n},
- {"predicted_ms", predicted_ms},
- {"predicted_per_token_ms", predicted_per_token_ms},
- {"predicted_per_second", predicted_per_second},
- };
-
- if (draft_n > 0) {
- base["draft_n"] = draft_n;
- base["draft_n_accepted"] = draft_n_accepted;
- }
-
- return base;
-}
-
//
// result_prompt_progress
//
{"stop_type", stop_type_to_str(stop)},
{"stopping_word", stopping_word},
{"tokens_cached", n_tokens_cached},
- {"timings", timings.to_json()},
+ {"timings", stats.to_json()},
};
if (!stream && !probs_output.empty()) {
res["completion_probabilities"] = completion_token_output::probs_vector_to_json(probs_output, post_sampling_probs);
if (verbose) {
res["__verbose"] = to_json_non_oaicompat();
}
- if (timings.prompt_n >= 0) {
- res.push_back({"timings", timings.to_json()});
+ if (stats.is_set()) {
+ res.push_back({"timings", stats.to_json()});
}
return res;
if (verbose) {
res["__verbose"] = to_json_non_oaicompat();
}
- if (timings.prompt_n >= 0) {
- res.push_back({"timings", timings.to_json()});
+ if (stats.is_set()) {
+ res.push_back({"timings", stats.to_json()});
}
return res;
});
}
- if (timings.prompt_n >= 0) {
- deltas.back().push_back({"timings", timings.to_json()});
+ if (stats.is_set()) {
+ deltas.back().push_back({"timings", stats.to_json()});
}
// extra fields for debugging purposes
}}
});
- if (timings.prompt_n >= 0) {
- server_sent_events.back().at("data").push_back({"timings", timings.to_json()});
+ if (stats.is_set()) {
+ server_sent_events.back().at("data").push_back({"timings", stats.to_json()});
}
return server_sent_events;
{"tokens_evaluated", n_prompt_tokens},
};
// populate the timings object when needed (usually for the last response or with timings_per_token enabled)
- if (timings.prompt_n > 0) {
- res.push_back({"timings", timings.to_json()});
+ if (stats.is_set()) {
+ res.push_back({"timings", stats.to_json()});
}
if (is_progress) {
res.push_back({"prompt_progress", progress.to_json()});
if (verbose) {
res["__verbose"] = to_json_non_oaicompat();
}
- if (timings.prompt_n >= 0) {
- res.push_back({"timings", timings.to_json()});
+ if (stats.is_set()) {
+ res.push_back({"timings", stats.to_json()});
}
if (is_progress) {
res.push_back({"prompt_progress", progress.to_json()});
};
}
- if (timings.prompt_n >= 0) {
- last_json.push_back({"timings", timings.to_json()});
+ if (stats.is_set()) {
+ last_json.push_back({"timings", stats.to_json()});
}
if (is_progress) {
last_json.push_back({"prompt_progress", progress.to_json()});
if (!events.empty()) {
json & data = events.back().at("data");
- if (timings.prompt_n >= 0) {
- data.push_back({"timings", timings.to_json()});
+ if (stats.is_set()) {
+ data.push_back({"timings", stats.to_json()});
}
if (is_progress) {
data.push_back({"prompt_progress", progress.to_json()});
// server_task_result_metrics
//
json server_task_result_metrics::to_json() {
- return json {
- { "idle", n_idle_slots },
- { "processing", n_processing_slots },
- { "deferred", n_tasks_deferred },
- { "t_start", t_start },
+ return slots_data;
+}
- { "n_prompt_tokens_processed_total", n_prompt_tokens_processed_total },
- { "t_tokens_generation_total", t_tokens_generation_total },
- { "n_tokens_predicted_total", n_tokens_predicted_total },
- { "t_prompt_processing_total", t_prompt_processing_total },
+// metrics definition: https://prometheus.io/docs/practices/naming/#metric-names
+std::string server_task_result_metrics::to_metrics() {
+ const std::vector<metric_item> counters = {
+ {
+ "prompt_tokens_total",
+ "Number of prompt tokens processed, excluding cached tokens",
+ (double) metrics.prompt.count
+ }, {
+ "prompt_tokens_cached_total",
+ "Number of prompt tokens reused from the cache",
+ (double) metrics.n_prompt_cached
+ }, {
+ "prompt_seconds_total",
+ "Total time spent processing prompts",
+ metrics.prompt.time / 1.e6
+ }, {
+ "tokens_predicted_total",
+ "Number of generation tokens processed",
+ (double) metrics.predict.count
+ }, {
+ "tokens_predicted_seconds_total",
+ "Total time spent generating tokens",
+ metrics.predict.time / 1.e6
+ }, {
+ "n_decode_total",
+ "Total number of llama_decode() calls, excluding speculative decoding and multimodal decoding",
+ (double) metrics.n_decode
+ }, {
+ "n_tokens_max",
+ "Largest observed sequence length (prompt + generation)",
+ (double) metrics.n_tokens_max
+ }, {
+ "spec_decode_num_draft_tokens_total",
+ "Speculative: Total draft tokens generated",
+ (double) metrics.n_draft_tokens
+ }, {
+ "spec_decode_num_accepted_tokens_total",
+ "Speculative: Total draft tokens accepted by the target model",
+ (double) metrics.n_draft_accepted
+ }, {
+ "spec_decode_num_drafts_total",
+ "Speculative: Total speculative decoding verification steps",
+ (double) metrics.n_draft_verif_steps
+ },
+ };
- { "n_tokens_max", n_tokens_max },
+ const std::vector<metric_item> gauges = {
+ {
+ "prompt_tokens_seconds",
+ "Average prompt throughput in tokens/s",
+ metrics.prompt_bucket.n_per_second()
+ }, {
+ "predicted_tokens_seconds",
+ "Average generation throughput in tokens/s",
+ metrics.predict_bucket.n_per_second()
+ }, {
+ "requests_processing",
+ "Number of requests processing",
+ (double) n_processing_slots
+ }, {
+ "requests_deferred",
+ "Number of requests deferred",
+ (double) n_tasks_deferred
+ }, {
+ "n_busy_slots_per_decode",
+ "Average number of busy slots per llama_decode() call",
+ (double) metrics.n_busy_slots / std::max((double) metrics.n_decode, 1.0)
+ },
+ };
- { "n_prompt_tokens_processed", n_prompt_tokens_processed },
- { "t_prompt_processing", t_prompt_processing },
- { "n_tokens_predicted", n_tokens_predicted },
- { "t_tokens_generation", t_tokens_generation },
+ std::stringstream prometheus;
- { "n_decode_total", n_decode_total },
- { "n_busy_slots_total", n_busy_slots_total },
+ auto add_items = [&prometheus](const char * type, const std::vector<metric_item> & items) {
+ for (const auto & item : items) {
+ prometheus << "# HELP llamacpp:" << item.name << " " << item.description << "\n"
+ << "# TYPE llamacpp:" << item.name << " " << type << "\n"
+ << "llamacpp:" << item.name << " " << item.value << "\n";
+ }
+ };
- { "n_draft_tokens_total", n_draft_tokens_total },
- { "n_draft_accepted_total", n_draft_accepted_total },
- { "n_draft_verif_steps_total", n_draft_verif_steps_total },
- { "n_accepted_per_pos_total", n_accepted_per_pos_total },
+ add_items("counter", counters);
+ add_items("gauge", gauges);
+
+ // labeled counter: one time series per draft position
+ if (!metrics.n_accepted_per_pos.empty()) {
+ prometheus << "# HELP llamacpp:spec_decode_num_accepted_tokens_per_pos_total"
+ " Accepted tokens per draft position\n"
+ << "# TYPE llamacpp:spec_decode_num_accepted_tokens_per_pos_total counter\n";
+ for (size_t i = 0; i < metrics.n_accepted_per_pos.size(); i++) {
+ prometheus << "llamacpp:spec_decode_num_accepted_tokens_per_pos_total{position=\""
+ << i << "\"} " << metrics.n_accepted_per_pos[i] << "\n";
+ }
+ }
- { "slots", slots_data },
- };
+ return prometheus.str();
}
//
--- /dev/null
+import pytest
+from utils import *
+
+server = ServerPreset.tinyllama2()
+
+
+@pytest.fixture(autouse=True)
+def create_server():
+ global server
+ server = ServerPreset.tinyllama2()
+ server.server_metrics = True
+
+
+def fetch_metrics(server: ServerProcess) -> str:
+ """get /metrics as raw prometheus text"""
+ res = server.make_request("GET", "/metrics")
+ assert res.status_code == 200
+ assert "Process-Start-Time-Unix" in res.headers
+ assert isinstance(res.body, str)
+ return res.body
+
+
+def parse_metrics(text: str) -> dict:
+ """parse the prometheus text format into {name: (type, value)}"""
+ out = {}
+ types = {}
+ for line in text.splitlines():
+ if line.startswith("# TYPE "):
+ _, _, name, kind = line.split(" ", 3)
+ types[name] = kind
+ elif line.startswith("llamacpp:") and "{" not in line:
+ name, value = line.split(" ", 1)
+ assert name in types, f"{name} has no # TYPE line"
+ out[name] = (types[name], float(value))
+ return out
+
+
+def test_metrics_disabled():
+ global server
+ server.server_metrics = False
+ server.start()
+ res = server.make_request("GET", "/metrics")
+ assert res.status_code == 501 # ERROR_TYPE_NOT_SUPPORTED
+
+
+def test_metrics_prometheus_format():
+ global server
+ server.start()
+ server.make_request("POST", "/completion", data={"prompt": "I believe", "n_predict": 8})
+
+ text = fetch_metrics(server)
+ metrics = parse_metrics(text)
+
+ expected_counters = [
+ "llamacpp:prompt_tokens_total",
+ "llamacpp:prompt_tokens_cached_total",
+ "llamacpp:prompt_seconds_total",
+ "llamacpp:tokens_predicted_total",
+ "llamacpp:tokens_predicted_seconds_total",
+ "llamacpp:n_decode_total",
+ "llamacpp:n_tokens_max",
+ "llamacpp:spec_decode_num_draft_tokens_total",
+ "llamacpp:spec_decode_num_accepted_tokens_total",
+ "llamacpp:spec_decode_num_drafts_total",
+ ]
+ expected_gauges = [
+ "llamacpp:prompt_tokens_seconds",
+ "llamacpp:predicted_tokens_seconds",
+ "llamacpp:requests_processing",
+ "llamacpp:requests_deferred",
+ "llamacpp:n_busy_slots_per_decode",
+ ]
+
+ for name in expected_counters:
+ assert metrics[name][0] == "counter"
+ for name in expected_gauges:
+ assert metrics[name][0] == "gauge"
+
+ # every metric must carry a help line
+ for name in expected_counters + expected_gauges:
+ assert f"# HELP {name} " in text
+
+ assert metrics["llamacpp:n_decode_total"][1] > 0
+ assert metrics["llamacpp:requests_processing"][1] == 0
+
+
+def test_metrics_prompt_processed_and_cached():
+ global server
+ server.n_slots = 1 # keep the prompt cache on a single slot
+ server.start()
+
+ prompt = "the quick brown fox jumps over the lazy dog"
+
+ n_processed = 0
+ n_cached = 0
+ for _ in range(2):
+ res = server.make_request("POST", "/completion", data={"prompt": prompt, "n_predict": 4})
+ assert res.status_code == 200
+ n_processed += res.body["timings"]["prompt_n"]
+ n_cached += res.body["timings"]["cache_n"]
+
+ # the second request must reuse the prompt of the first one
+ assert n_cached > 0
+
+ metrics = parse_metrics(fetch_metrics(server))
+
+ # cached tokens are counted apart, they cost no decode
+ assert metrics["llamacpp:prompt_tokens_total"][1] == n_processed
+ assert metrics["llamacpp:prompt_tokens_cached_total"][1] == n_cached
+
+
+def test_metrics_predicted_total_matches_requests():
+ global server
+ server.start()
+
+ n_predicted = 0
+ for n_predict in [1, 4, 16]:
+ res = server.make_request("POST", "/completion", data={"prompt": "I believe", "n_predict": n_predict})
+ assert res.status_code == 200
+ n_predicted += res.body["timings"]["predicted_n"]
+
+ metrics = parse_metrics(fetch_metrics(server))
+ assert metrics["llamacpp:tokens_predicted_total"][1] == n_predicted
+
+
+def test_metrics_generation_rate_excludes_first_token():
+ global server
+ server.start()
+
+ # the first token comes from the logits of the last prompt batch, so it costs no decode step
+ res = server.make_request("POST", "/completion", data={"prompt": "I believe", "n_predict": 1})
+ timings = res.body["timings"]
+ assert timings["predicted_n"] == 1
+ assert timings["predicted_per_second"] == 0.0
+ assert timings["predicted_per_token_ms"] == 0.0
+
+ res = server.make_request("POST", "/completion", data={"prompt": "I believe", "n_predict": 16})
+ timings = res.body["timings"]
+ assert timings["predicted_n"] == 16
+ # the rate is over 15 decode steps, not 16 tokens
+ expected = 1e3 / timings["predicted_ms"] * 15
+ assert abs(timings["predicted_per_second"] - expected) < 1e-6
+
+
+@pytest.mark.parametrize("n_predict", [1, 8])
+def test_metrics_timings_are_finite(n_predict: int):
+ global server
+ server.start()
+ res = server.make_request("POST", "/completion", data={"prompt": "I believe", "n_predict": n_predict})
+ timings = res.body["timings"]
+
+ # a null here means the server produced inf or nan
+ for key, value in timings.items():
+ assert value is not None, f"{key} is null"
+ assert value >= 0, f"{key} is negative"
+
+ assert timings["prompt_ms"] > 0
+ assert timings["prompt_per_token_ms"] > 0
+
+
+def test_metrics_timings_on_prompt_progress():
+ global server
+ server.start()
+
+ # a long prompt so that it is split over several batches (n_batch = 32)
+ prompt = "the quick brown fox jumps over the lazy dog " * 8
+ chunks = list(server.make_stream_request("POST", "/completion", data={
+ "prompt": prompt,
+ "n_predict": 4,
+ "stream": True,
+ "timings_per_token": True,
+ "return_progress": True,
+ }))
+
+ progress = [c for c in chunks if "prompt_progress" in c]
+ assert len(progress) > 1 # the prompt did not fit in a single batch
+
+ # the very first update is sent before any prompt token is decoded
+ first = progress[0]["timings"]
+ assert first["prompt_n"] == 0
+ assert first["prompt_ms"] == 0.0
+ assert first["predicted_n"] == 0
+ assert first["predicted_ms"] == 0.0
+
+ # timings must never go backwards, nor report bogus values
+ prompt_ms = 0.0
+ for chunk in progress:
+ timings = chunk["timings"]
+ for key, value in timings.items():
+ assert value is not None, f"{key} is null"
+ assert value >= 0, f"{key} is negative"
+ assert timings["prompt_ms"] >= prompt_ms
+ prompt_ms = timings["prompt_ms"]
+
+ assert prompt_ms > 0
+
+
+def test_metrics_slots_idle_after_completion():
+ global server
+ server.server_slots = True
+ server.start()
+ server.make_request("POST", "/completion", data={"prompt": "I believe", "n_predict": 8})
+
+ res = server.make_request("GET", "/slots")
+ assert res.status_code == 200
+ for slot in res.body:
+ assert slot["is_processing"] is False
+ if "next_token" in slot:
+ # the budget of the finished task must not leak into the idle slot
+ assert slot["next_token"][0]["n_remain"] == -1
+ assert slot["next_token"][0]["n_decoded"] == 0
+
+
+def test_metrics_embedding_prompt_is_counted():
+ global server
+ server = ServerPreset.bert_bge_small()
+ server.server_metrics = True
+ server.start()
+
+ res = server.make_request("POST", "/v1/embeddings", data={"input": ["hello world", "goodbye world"]})
+ assert res.status_code == 200
+
+ # embedding tasks never sample a token, but their prompt still costs a decode
+ metrics = parse_metrics(fetch_metrics(server))
+ assert metrics["llamacpp:prompt_tokens_total"][1] > 0
+ assert metrics["llamacpp:n_decode_total"][1] > 0
+ assert metrics["llamacpp:tokens_predicted_total"][1] == 0
overview / pkg / ggml / sources / llama.cpp / commitdiff