Eval bug: server: unnecessary prompt re-processing with Jamba models #14625
Description
Name and Version
I am using commit 0b885577 (earlier today at the time of posting).
llama-server --versionggml_cuda_init: GGML_CUDA_FORCE_MMQ: no
ggml_cuda_init: GGML_CUDA_FORCE_CUBLAS: no
ggml_cuda_init: found 1 CUDA devices:
Device 0: NVIDIA GeForce RTX 4060 Ti, compute capability 8.9, VMM: yes
version: 5866 (0b885577)
built with cc (Debian 12.2.0-14+deb12u1) 12.2.0 for x86_64-linux-gnu
Operating systems
Linux
GGML backends
CUDA
Hardware
OS: Debian GNU/Linux 12 (bookworm) x86_64
Host: B650M C V2-Y1 -CF
Kernel: 6.1.0-35-amd64
CPU: AMD Ryzen 7 7700X (16) @ 4.500GHz
GPU: NVIDIA GeForce RTX 4060 Ti 16GB
GPU: AMD ATI 13:00.0 Raphael
Memory: 934MiB / 63435MiB
Models
Problem description & steps to reproduce
After clicking the "re-generate" button in the llama-server webui I see this in the console:
slot update_slots: id 0 | task 3977 | new prompt, n_ctx_slot = 262144, n_keep = 0, n_prompt_tokens = 100496
slot update_slots: id 0 | task 3977 | n_past = 100496, cache_tokens.size() = 103296, seq_id = 0, pos_min = 103295, n_swa = 0
slot update_slots: id 0 | task 3977 | forcing full prompt re-processing due to lack of cache data (likely due to SWA, see https://github.com/ggml-org/llama.cpp/pull/13194#issuecomment-2868343055)
slot update_slots: id 0 | task 3977 | kv cache rm [0, end)
The KV cache is cleared and the model re-processes the entire context (in this case, 100k tokens!) even though it shouldn't have to because it only needs to restart from where the last generation started.
I think this is a bug because I don't think it really needs to re-process the context at this point.
I suspect that the check on this line is incorrect for Jamba models (which do not use SWA).
First Bad Commit
I assume the problem has been present since Jamba support was added recently in 4a5686da (ref #7531)
Relevant log output
llama-server --host 192.168.68.66 --port 20480 -m /opt/workspace/gguf/AI21-Jamba-Mini-1.7-Q8_0.gguf -b 4096 -ub 1024 -c 262144 -fa -ngl 999 -ot "blk\.(31|30)\.=CUDA0" -ot "exps=CPU" --jinjaggml_cuda_init: GGML_CUDA_FORCE_MMQ: no
ggml_cuda_init: GGML_CUDA_FORCE_CUBLAS: no
ggml_cuda_init: found 1 CUDA devices:
Device 0: NVIDIA GeForce RTX 4060 Ti, compute capability 8.9, VMM: yes
build: 5866 (0b885577) with cc (Debian 12.2.0-14+deb12u1) 12.2.0 for x86_64-linux-gnu
system info: n_threads = 8, n_threads_batch = 8, total_threads = 16
system_info: n_threads = 8 (n_threads_batch = 8) / 16 | CUDA : ARCHS = 890 | USE_GRAPHS = 1 | PEER_MAX_BATCH_SIZE = 128 | CPU : SSE3 = 1 | SSSE3 = 1 | AVX = 1 | AVX2 = 1 | F16C = 1 | FMA = 1 | BMI2 = 1 | AVX512 = 1 | AVX512_VBMI = 1 | AVX512_VNNI = 1 | AVX512_BF16 = 1 | LLAMAFILE = 1 | OPENMP = 1 | REPACK = 1 |
main: binding port with default address family
main: HTTP server is listening, hostname: 192.168.68.66, port: 20480, http threads: 15
main: loading model
srv load_model: loading model '/opt/workspace/gguf/AI21-Jamba-Mini-1.7-Q8_0.gguf'
llama_model_load_from_file_impl: using device CUDA0 (NVIDIA GeForce RTX 4060 Ti) - 15956 MiB free
llama_model_loader: loaded meta data with 37 key-value pairs and 531 tensors from /opt/workspace/gguf/AI21-Jamba-Mini-1.7-Q8_0.gguf (version GGUF V3 (latest))
llama_model_loader: Dumping metadata keys/values. Note: KV overrides do not apply in this output.
llama_model_loader: - kv 0: general.architecture str = jamba
llama_model_loader: - kv 1: general.type str = model
llama_model_loader: - kv 2: general.name str = AI21-Jamba-Mini-1.7
llama_model_loader: - kv 3: general.version str = 1.7
llama_model_loader: - kv 4: general.basename str = AI21-Jamba
llama_model_loader: - kv 5: general.size_label str = Mini
llama_model_loader: - kv 6: general.license str = other
llama_model_loader: - kv 7: general.license.name str = jamba-open-model-license
llama_model_loader: - kv 8: general.license.link str = https://www.ai21.com/jamba-open-model...
llama_model_loader: - kv 9: jamba.block_count u32 = 32
llama_model_loader: - kv 10: jamba.context_length u32 = 262144
llama_model_loader: - kv 11: jamba.embedding_length u32 = 4096
llama_model_loader: - kv 12: jamba.feed_forward_length u32 = 14336
llama_model_loader: - kv 13: jamba.attention.head_count u32 = 32
llama_model_loader: - kv 14: jamba.attention.head_count_kv arr[i32,32] = [0, 0, 0, 0, 8, 0, 0, 0, 0, 0, 0, 0, ...
llama_model_loader: - kv 15: jamba.ssm.conv_kernel u32 = 4
llama_model_loader: - kv 16: jamba.ssm.inner_size u32 = 8192
llama_model_loader: - kv 17: jamba.ssm.state_size u32 = 16
llama_model_loader: - kv 18: jamba.ssm.time_step_rank u32 = 256
llama_model_loader: - kv 19: jamba.attention.layer_norm_rms_epsilon f32 = 0.000001
llama_model_loader: - kv 20: jamba.expert_count u32 = 16
llama_model_loader: - kv 21: jamba.expert_used_count u32 = 2
llama_model_loader: - kv 22: tokenizer.ggml.model str = llama
llama_model_loader: - kv 23: tokenizer.ggml.pre str = default
llama_model_loader: - kv 24: tokenizer.ggml.tokens arr[str,65536] = ["<|pad|>", "<|startoftext|>", "<|end...
llama_model_loader: - kv 25: tokenizer.ggml.scores arr[f32,65536] = [-1000.000000, -1000.000000, -1000.00...
llama_model_loader: - kv 26: tokenizer.ggml.token_type arr[i32,65536] = [3, 3, 3, 3, 3, 3, 3, 3, 3, 3, 3, 3, ...
llama_model_loader: - kv 27: tokenizer.ggml.bos_token_id u32 = 1
llama_model_loader: - kv 28: tokenizer.ggml.eos_token_id u32 = 2
llama_model_loader: - kv 29: tokenizer.ggml.unknown_token_id u32 = 3
llama_model_loader: - kv 30: tokenizer.ggml.padding_token_id u32 = 0
llama_model_loader: - kv 31: tokenizer.ggml.add_bos_token bool = true
llama_model_loader: - kv 32: tokenizer.ggml.add_sep_token bool = false
llama_model_loader: - kv 33: tokenizer.ggml.add_eos_token bool = false
llama_model_loader: - kv 34: tokenizer.chat_template str = {# Variables #}\n{% set ns = namespace...
llama_model_loader: - kv 35: general.quantization_version u32 = 2
llama_model_loader: - kv 36: general.file_type u32 = 7
llama_model_loader: - type f32: 305 tensors
llama_model_loader: - type q8_0: 226 tensors
print_info: file format = GGUF V3 (latest)
print_info: file type = Q8_0
print_info: file size = 51.05 GiB (8.50 BPW)
load: special tokens cache size = 1543
load: token to piece cache size = 0.4034 MB
print_info: arch = jamba
print_info: vocab_only = 0
print_info: n_ctx_train = 262144
print_info: n_embd = 4096
print_info: n_layer = 32
print_info: n_head = 32
print_info: n_head_kv = [0, 0, 0, 0, 8, 0, 0, 0, 0, 0, 0, 0, 8, 0, 0, 0, 0, 0, 0, 0, 8, 0, 0, 0, 0, 0, 0, 0, 8, 0, 0, 0]
print_info: n_rot = 128
print_info: n_swa = 0
print_info: is_swa_any = 0
print_info: n_embd_head_k = 128
print_info: n_embd_head_v = 128
print_info: n_gqa = [0, 0, 0, 0, 4, 0, 0, 0, 0, 0, 0, 0, 4, 0, 0, 0, 0, 0, 0, 0, 4, 0, 0, 0, 0, 0, 0, 0, 4, 0, 0, 0]
print_info: n_embd_k_gqa = [0, 0, 0, 0, 1024, 0, 0, 0, 0, 0, 0, 0, 1024, 0, 0, 0, 0, 0, 0, 0, 1024, 0, 0, 0, 0, 0, 0, 0, 1024, 0, 0, 0]
print_info: n_embd_v_gqa = [0, 0, 0, 0, 1024, 0, 0, 0, 0, 0, 0, 0, 1024, 0, 0, 0, 0, 0, 0, 0, 1024, 0, 0, 0, 0, 0, 0, 0, 1024, 0, 0, 0]
print_info: f_norm_eps = 0.0e+00
print_info: f_norm_rms_eps = 1.0e-06
print_info: f_clamp_kqv = 0.0e+00
print_info: f_max_alibi_bias = 0.0e+00
print_info: f_logit_scale = 0.0e+00
print_info: f_attn_scale = 0.0e+00
print_info: n_ff = 14336
print_info: n_expert = 16
print_info: n_expert_used = 2
print_info: causal attn = 1
print_info: pooling type = 0
print_info: rope type = -1
print_info: rope scaling = linear
print_info: freq_base_train = 10000.0
print_info: freq_scale_train = 1
print_info: n_ctx_orig_yarn = 262144
print_info: rope_finetuned = unknown
print_info: ssm_d_conv = 4
print_info: ssm_d_inner = 8192
print_info: ssm_d_state = 16
print_info: ssm_dt_rank = 256
print_info: ssm_n_group = 0
print_info: ssm_dt_b_c_rms = 0
print_info: model type = ?B
print_info: model params = 51.57 B
print_info: general.name = AI21-Jamba-Mini-1.7
print_info: vocab type = SPM
print_info: n_vocab = 65536
print_info: n_merges = 0
print_info: BOS token = 1 '<|startoftext|>'
print_info: EOS token = 2 '<|endoftext|>'
print_info: EOT token = 2 '<|endoftext|>'
print_info: UNK token = 3 '<|unk|>'
print_info: PAD token = 0 '<|pad|>'
print_info: LF token = 1554 '<0x0A>'
print_info: EOG token = 2 '<|endoftext|>'
print_info: max token length = 96
load_tensors: loading model tensors, this can take a while... (mmap = true)
load_tensors: offloading 32 repeating layers to GPU
load_tensors: offloading output layer to GPU
load_tensors: offloaded 33/33 layers to GPU
load_tensors: CUDA0 model buffer size = 9161.62 MiB
load_tensors: CPU_Mapped model buffer size = 48645.07 MiB
.............................................................
llama_context: constructing llama_context
llama_context: n_seq_max = 1
llama_context: n_ctx = 262144
llama_context: n_ctx_per_seq = 262144
llama_context: n_batch = 4096
llama_context: n_ubatch = 1024
llama_context: causal_attn = 1
llama_context: flash_attn = 1
llama_context: freq_base = 10000.0
llama_context: freq_scale = 1
llama_context: CUDA_Host output buffer size = 0.25 MiB
llama_kv_cache_unified: CUDA0 KV buffer size = 4096.00 MiB
llama_kv_cache_unified: size = 4096.00 MiB (262144 cells, 4 layers, 1 seqs), K (f16): 2048.00 MiB, V (f16): 2048.00 MiB
llama_kv_cache_unified: LLAMA_SET_ROWS=0, using old ggml_cpy() method for backwards compatibility
llama_memory_recurrent: CUDA0 RS buffer size = 16.62 MiB
llama_memory_recurrent: size = 16.62 MiB ( 1 cells, 32 layers, 1 seqs), R (f32): 2.62 MiB, S (f32): 14.00 MiB
llama_context: CUDA0 compute buffer size = 2328.09 MiB
llama_context: CUDA_Host compute buffer size = 1040.01 MiB
llama_context: graph nodes = 2123
llama_context: graph splits = 48 (with bs=1024), 33 (with bs=1)
common_init_from_params: setting dry_penalty_last_n to ctx_size = 262144
common_init_from_params: warming up the model with an empty run - please wait ... (--no-warmup to disable)
srv init: initializing slots, n_slots = 1
slot init: id 0 | task -1 | new slot n_ctx_slot = 262144
main: model loaded
main: chat template, chat_template: {# Variables #}
{% set ns = namespace(message_count=0, is_last_checked_defined=False) %}
{##}
{% set bom_str = bom_str or "<|bom|>" %}
{% set eom_str = eom_str or "<|eom|>" %}
{% set default_system_message = default_system_message or "" %}
{##}
{% set documents_prefix = "<documents>" %}
{% set documents_suffix = "</documents>" %}
{% set tool_definitions_prefix = "<tool_definitions>" %}
{% set tool_definitions_suffix = "</tool_definitions>" %}
{% set active_modes_prefix = "<active_output_modes>" %}
{% set active_modes_suffix = "</active_output_modes>" %}
{##}
{% set tool_calls_prefix = "<tool_calls>" %}
{% set tool_calls_suffix = "</tool_calls>" %}
{% set citations_prefix = "<citations>" %}
{% set citations_suffix = "</citations>" %}
{##}
{% if add_generation_prompt is not defined %}
{% set add_generation_prompt = True %}
{% endif %}
{% set role_to_predict = role_to_predict or "assistant" %}
{% if messages|length > 0 and messages[0].role == "system" %}
{% set system_message = messages[0].content %}
{% set loop_messages = messages[1:] %}
{% else %}
{% set system_message = default_system_message %}
{% set loop_messages = messages %}
{% endif %}
{##}
{##}
{# Macros #}
{% macro handle_tool_definitions(tools) %}
{{- tool_definitions_prefix -}}
{{- "\n# Tools" -}}
{{- "\n\n## Functions" -}}
{% for tool in tools %}
{% set _ = is_param_set(tool, field="type") %}
{% set is_tool_type_set = ns.is_last_checked_defined %}
{% if is_tool_type_set %}
{% if tool.type == "function" %}
{% set tool = tool.function %}
{% else %}
{{ raise_exception("Currently, the only supported tool type is `function`") }}
{% endif %}
{% endif %}
{{- "\n\n" + (tool|tojson(indent=2)) -}}
{% endfor %}
{{- "\n" + tool_definitions_suffix -}}
{% endmacro %}
{##}
{% macro handle_first_system_message(system_message, tools) %}
{{- bom_str + handle_role("system") -}}
{% set _ = is_param_set(system_message) %}
{% set is_system_message_set = ns.is_last_checked_defined %}
{% if is_system_message_set %}
{{- system_message -}}
{% endif %}
{% set _ = is_param_set(tools, check_length=True) %}
{% set is_tools_set = ns.is_last_checked_defined %}
{% if is_tools_set %}
{% if system_message %}
{{- "\n\n" -}}
{% endif %}
{{- handle_tool_definitions(tools) -}}
{% endif %}
{% set ns.message_count = ns.message_count + 1 %}
{% endmacro %}
{##}
{% macro handle_tool_calls(tool_calls) %}
{{- tool_calls_prefix + "[\n" -}}
{% for tool_call in tool_calls %}
{% set _ = is_param_set(tool_call, field="function") %}
{% set is_tool_call_function_set = ns.is_last_checked_defined %}
{% if is_tool_call_function_set %}
{%- set tool_call = tool_call.function %}
{%- endif %}
{% set arguments = tool_call.arguments %}
{% if arguments is not string %}
{%- set arguments = arguments|tojson -%}
{%- endif %}
{{ "{\"name\": \"" + tool_call.name + "\", \"arguments\": " + arguments + "}" -}}
{% if not loop.last %}
{{- "," }}
{% endif %}
{% endfor %}
{{- "\n]" + tool_calls_suffix -}}
{% endmacro %}
{##}
{% macro handle_documents(documents) %}
{{- documents_prefix -}}
{{- "\n# Documents" -}}
{{- "\n\nYou can use the following documents for reference:" -}}
{% for doc in documents %}
{{- "\n\n## Document ID: " + loop.index0|string -}}
{% set _ = is_param_set(doc, field="title") %}
{% set is_doc_title_set = ns.is_last_checked_defined %}
{% if is_doc_title_set %}
{{- "\nTitle: " + doc.title -}}
{% endif %}
{% for key, value in doc.items() %}
{% if key not in ["title", "text"] %}
{{- "\n" + key|title + ": " + value|string -}}
{% endif %}
{% endfor %}
{{- "\nText: " + doc.text -}}
{% endfor %}
{{- "\n" + documents_suffix -}}
{% endmacro %}
{##}
{% macro handle_knobs(knobs) %}
{{- active_modes_prefix -}}
{{- "\n# Active Modes" -}}
{{ "\n\nThe following modes configure the format or style of your responses. You should adhere to all currently" -}}
{{ " active modes simultaneously." -}}
{% if knobs.citation_mode == "fast" %}
{{- "\n\n## Citation Mode" -}}
{{- "\n\nProvide a list of references only for the documents you base your response on. Format your response" -}}
{{ " with the original answer followed by a citation section. Use this template:" -}}
{{ " `{answer}" + citations_prefix + "DOCUMENT_IDS" + citations_suffix + "`, where DOCUMENT_IDS are the relevant document numbers" -}}
{{ " (e.g. [2, 5, 9]), or [] if the answer cannot be supported by the provided documents." -}}
{% endif %}
{% if knobs.response_format == "json_object" %}
{{- "\n\n## JSON Mode" -}}
{{ "\n\nProvide your response in JSON format. Adhere strictly to any schema given by the user." -}}
{{ " If an appropriate JSON format exists, use it without modification." -}}
{% endif %}
{{- "\n" + active_modes_suffix -}}
{% endmacro %}
{##}
{% macro get_last_user_index(messages) %}
{% set ns.last_user_index = 0 %}
{% for message in messages %}
{% if message.role == 'user' %}
{% set ns.last_user_index = loop.index0 %}
{% endif %}
{% endfor %}
{{- ns.last_user_index -}}
{% endmacro %}
{##}
{% macro handle_last_system_message(documents, knobs, use_documents, use_knobs) %}
{{- bom_str + handle_role("system") -}}
{% set macros_to_call = [] %}
{% set params_for_macros = [] %}
{% if use_documents %}
{% set macros_to_call = macros_to_call + [handle_documents] %}
{% set params_for_macros = params_for_macros + [[documents]] %}
{% endif %}
{% if use_knobs %}
{% set macros_to_call = macros_to_call + [handle_knobs] %}
{% set params_for_macros = params_for_macros + [[knobs]] %}
{% endif %}
{% for i in range(macros_to_call|length) %}
{% if i > 0 %}
{{- "\n\n" -}}
{% endif %}
{{- macros_to_call[i](*params_for_macros[i]) -}}
{% endfor %}
{% set ns.message_count = ns.message_count + 1 %}
{% endmacro %}
{##}
{% macro handle_role(role, add_space=True) %}
{{- "<|" + role + "|>" -}}
{% if add_space %}
{{- " " -}}
{% endif %}
{% endmacro %}
{##}
{% macro is_param_set(param, field=none, check_length=False) %}
{% if field is not none %}
{% if field in param %}
{% set param = param[field] %}
{% else %}
{% set param = none %}
{% endif %}
{% endif %}
{% set is_defined = param is defined and param is not none %}
{% if check_length %}
{% set ns.is_last_checked_defined = is_defined and param|length > 0 %}
{% else %}
{% set ns.is_last_checked_defined = is_defined %}
{% endif %}
{% endmacro %}
{##}
{##}
{# Template #}
{% if bos_token is defined and bos_token is not none %}
{{- bos_token -}}
{% endif %}
{% set _ = is_param_set(system_message) %}
{% set is_system_message_set = ns.is_last_checked_defined %}
{% set _ = is_param_set(tools, check_length=True) %}
{% set is_tools_set = ns.is_last_checked_defined %}
{% set has_system_message = (is_system_message_set or is_tools_set) %}
{% if has_system_message %}
{{- handle_first_system_message(system_message, tools) -}}
{% endif %}
{% set last_user_index = get_last_user_index(loop_messages)|int %}
{% for message in loop_messages %}
{% if loop.index0 == last_user_index %}
{% set _ = is_param_set(documents, check_length=True) %}
{% set use_documents = ns.is_last_checked_defined %}
{% set _ = is_param_set(knobs) %}
{% set use_knobs = ns.is_last_checked_defined and knobs.is_set %}
{% set add_last_system_message = use_documents or use_knobs %}
{% if add_last_system_message %}
{% if ns.message_count > 0 %}
{{- eom_str -}}
{% endif %}
{{- handle_last_system_message(documents, knobs, use_documents, use_knobs) -}}
{% endif %}
{% endif %}
{% set role = message.role %}
{% set _ = is_param_set(message, field="name") %}
{% set is_message_name_set = ns.is_last_checked_defined %}
{% if is_message_name_set %}
{% set message_prefix = handle_role(role) + "(" + message.name + ")" %}
{% else %}
{% set message_prefix = handle_role(role) %}
{% endif %}
{% set content = (message.content or "") %}
{% if content is not string %}
{% set content = content|tojson %}
{% endif %}
{% if ns.message_count > 0 %}
{{- eom_str -}}
{% endif %}
{{- bom_str + message_prefix + content -}}
{% set _ = is_param_set(message, field="tool_calls", check_length=True) %}
{% set is_tool_calls_set = ns.is_last_checked_defined %}
{% if role == "assistant" and is_tool_calls_set %}
{{- handle_tool_calls(message.tool_calls) -}}
{% endif %}
{% set _ = is_param_set(message, field="citations", check_length=False) %}
{% set is_citations_set = ns.is_last_checked_defined %}
{% if role == "assistant" and is_citations_set and knobs.is_set and knobs.citation_mode != "off" %}
{{- citations_prefix + message.citations|map(attribute="document_id")|list|string + citations_suffix -}}
{% endif %}
{% set ns.message_count = ns.message_count + 1 %}
{% endfor %}
{% if add_generation_prompt %}
{% if ns.message_count > 0 %}
{{- eom_str -}}
{% endif %}
{{- bom_str + handle_role(role_to_predict, add_space=False) -}}
{% set _ = is_param_set(generation_preamble) %}
{% set is_generation_preamble_set = ns.is_last_checked_defined %}
{% if is_generation_preamble_set and generation_preamble.strip() != "" %}
{{- " " + generation_preamble -}}
{% endif %}
{% set ns.message_count = ns.message_count + 1 %}
{% else %}
{% if ns.message_count > 0 %}
{{- eom_str -}}
{% endif %}
{% endif %}
, example_format: '<|bom|><|system|> You are a helpful assistant<|eom|><|bom|><|user|> Hello<|eom|><|bom|><|assistant|> Hi there<|eom|><|bom|><|user|> How are you?<|eom|><|bom|><|assistant|>'
main: server is listening on http://192.168.68.66:20480 - starting the main loop
srv update_slots: all slots are idle
srv params_from_: Chat format: Content-only
slot launch_slot_: id 0 | task 0 | processing task
slot update_slots: id 0 | task 0 | new prompt, n_ctx_slot = 262144, n_keep = 0, n_prompt_tokens = 93
slot update_slots: id 0 | task 0 | kv cache rm [0, end)
slot update_slots: id 0 | task 0 | prompt processing progress, n_past = 93, n_tokens = 93, progress = 1.000000
slot update_slots: id 0 | task 0 | prompt done, n_past = 93, n_tokens = 93
slot release: id 0 | task 0 | stop processing: n_past = 342, truncated = 0
slot print_timing: id 0 | task 0 |
prompt eval time = 3747.68 ms / 93 tokens ( 40.30 ms per token, 24.82 tokens per second)
eval time = 29913.91 ms / 250 tokens ( 119.66 ms per token, 8.36 tokens per second)
total time = 33661.60 ms / 343 tokens
srv update_slots: all slots are idle
srv log_server_r: request: POST /v1/chat/completions 192.168.68.64 200
srv params_from_: Chat format: Content-only
slot launch_slot_: id 0 | task 251 | processing task
slot update_slots: id 0 | task 251 | new prompt, n_ctx_slot = 262144, n_keep = 0, n_prompt_tokens = 99583
slot update_slots: id 0 | task 251 | n_past = 19, cache_tokens.size() = 342, seq_id = 0, pos_min = 341, n_swa = 0
slot update_slots: id 0 | task 251 | forcing full prompt re-processing due to lack of cache data (likely due to SWA, see https://github.com/ggml-org/llama.cpp/pull/13194#issuecomment-2868343055)
slot update_slots: id 0 | task 251 | kv cache rm [0, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 4096, n_tokens = 4096, progress = 0.041132
slot update_slots: id 0 | task 251 | kv cache rm [4096, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 8192, n_tokens = 4096, progress = 0.082263
slot update_slots: id 0 | task 251 | kv cache rm [8192, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 12288, n_tokens = 4096, progress = 0.123395
slot update_slots: id 0 | task 251 | kv cache rm [12288, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 16384, n_tokens = 4096, progress = 0.164526
slot update_slots: id 0 | task 251 | kv cache rm [16384, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 20480, n_tokens = 4096, progress = 0.205658
slot update_slots: id 0 | task 251 | kv cache rm [20480, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 24576, n_tokens = 4096, progress = 0.246789
slot update_slots: id 0 | task 251 | kv cache rm [24576, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 28672, n_tokens = 4096, progress = 0.287921
slot update_slots: id 0 | task 251 | kv cache rm [28672, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 32768, n_tokens = 4096, progress = 0.329052
slot update_slots: id 0 | task 251 | kv cache rm [32768, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 36864, n_tokens = 4096, progress = 0.370184
slot update_slots: id 0 | task 251 | kv cache rm [36864, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 40960, n_tokens = 4096, progress = 0.411315
slot update_slots: id 0 | task 251 | kv cache rm [40960, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 45056, n_tokens = 4096, progress = 0.452447
slot update_slots: id 0 | task 251 | kv cache rm [45056, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 49152, n_tokens = 4096, progress = 0.493578
slot update_slots: id 0 | task 251 | kv cache rm [49152, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 53248, n_tokens = 4096, progress = 0.534710
slot update_slots: id 0 | task 251 | kv cache rm [53248, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 57344, n_tokens = 4096, progress = 0.575841
slot update_slots: id 0 | task 251 | kv cache rm [57344, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 61440, n_tokens = 4096, progress = 0.616973
slot update_slots: id 0 | task 251 | kv cache rm [61440, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 65536, n_tokens = 4096, progress = 0.658104
slot update_slots: id 0 | task 251 | kv cache rm [65536, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 69632, n_tokens = 4096, progress = 0.699236
slot update_slots: id 0 | task 251 | kv cache rm [69632, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 73728, n_tokens = 4096, progress = 0.740367
slot update_slots: id 0 | task 251 | kv cache rm [73728, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 77824, n_tokens = 4096, progress = 0.781499
slot update_slots: id 0 | task 251 | kv cache rm [77824, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 81920, n_tokens = 4096, progress = 0.822630
slot update_slots: id 0 | task 251 | kv cache rm [81920, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 86016, n_tokens = 4096, progress = 0.863762
slot update_slots: id 0 | task 251 | kv cache rm [86016, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 90112, n_tokens = 4096, progress = 0.904893
slot update_slots: id 0 | task 251 | kv cache rm [90112, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 94208, n_tokens = 4096, progress = 0.946025
slot update_slots: id 0 | task 251 | kv cache rm [94208, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 98304, n_tokens = 4096, progress = 0.987156
slot update_slots: id 0 | task 251 | kv cache rm [98304, end)
slot update_slots: id 0 | task 251 | prompt processing progress, n_past = 99583, n_tokens = 1279, progress = 1.000000
slot update_slots: id 0 | task 251 | prompt done, n_past = 99583, n_tokens = 1279
slot release: id 0 | task 251 | stop processing: n_past = 100457, truncated = 0
slot print_timing: id 0 | task 251 |
prompt eval time = 425671.13 ms / 99583 tokens ( 4.27 ms per token, 233.94 tokens per second)
eval time = 113963.09 ms / 875 tokens ( 130.24 ms per token, 7.68 tokens per second)
total time = 539634.21 ms / 100458 tokens
srv update_slots: all slots are idle
srv log_server_r: request: POST /v1/chat/completions 192.168.68.64 200
srv params_from_: Chat format: Content-only
slot launch_slot_: id 0 | task 1151 | processing task
slot update_slots: id 0 | task 1151 | new prompt, n_ctx_slot = 262144, n_keep = 0, n_prompt_tokens = 100496
slot update_slots: id 0 | task 1151 | n_past = 99583, cache_tokens.size() = 100457, seq_id = 0, pos_min = 100456, n_swa = 0
slot update_slots: id 0 | task 1151 | forcing full prompt re-processing due to lack of cache data (likely due to SWA, see https://github.com/ggml-org/llama.cpp/pull/13194#issuecomment-2868343055)
slot update_slots: id 0 | task 1151 | kv cache rm [0, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 4096, n_tokens = 4096, progress = 0.040758
slot update_slots: id 0 | task 1151 | kv cache rm [4096, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 8192, n_tokens = 4096, progress = 0.081516
slot update_slots: id 0 | task 1151 | kv cache rm [8192, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 12288, n_tokens = 4096, progress = 0.122274
slot update_slots: id 0 | task 1151 | kv cache rm [12288, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 16384, n_tokens = 4096, progress = 0.163031
slot update_slots: id 0 | task 1151 | kv cache rm [16384, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 20480, n_tokens = 4096, progress = 0.203789
slot update_slots: id 0 | task 1151 | kv cache rm [20480, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 24576, n_tokens = 4096, progress = 0.244547
slot update_slots: id 0 | task 1151 | kv cache rm [24576, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 28672, n_tokens = 4096, progress = 0.285305
slot update_slots: id 0 | task 1151 | kv cache rm [28672, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 32768, n_tokens = 4096, progress = 0.326063
slot update_slots: id 0 | task 1151 | kv cache rm [32768, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 36864, n_tokens = 4096, progress = 0.366821
slot update_slots: id 0 | task 1151 | kv cache rm [36864, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 40960, n_tokens = 4096, progress = 0.407578
slot update_slots: id 0 | task 1151 | kv cache rm [40960, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 45056, n_tokens = 4096, progress = 0.448336
slot update_slots: id 0 | task 1151 | kv cache rm [45056, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 49152, n_tokens = 4096, progress = 0.489094
slot update_slots: id 0 | task 1151 | kv cache rm [49152, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 53248, n_tokens = 4096, progress = 0.529852
slot update_slots: id 0 | task 1151 | kv cache rm [53248, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 57344, n_tokens = 4096, progress = 0.570610
slot update_slots: id 0 | task 1151 | kv cache rm [57344, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 61440, n_tokens = 4096, progress = 0.611368
slot update_slots: id 0 | task 1151 | kv cache rm [61440, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 65536, n_tokens = 4096, progress = 0.652125
slot update_slots: id 0 | task 1151 | kv cache rm [65536, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 69632, n_tokens = 4096, progress = 0.692883
slot update_slots: id 0 | task 1151 | kv cache rm [69632, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 73728, n_tokens = 4096, progress = 0.733641
slot update_slots: id 0 | task 1151 | kv cache rm [73728, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 77824, n_tokens = 4096, progress = 0.774399
slot update_slots: id 0 | task 1151 | kv cache rm [77824, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 81920, n_tokens = 4096, progress = 0.815157
slot update_slots: id 0 | task 1151 | kv cache rm [81920, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 86016, n_tokens = 4096, progress = 0.855915
slot update_slots: id 0 | task 1151 | kv cache rm [86016, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 90112, n_tokens = 4096, progress = 0.896672
slot update_slots: id 0 | task 1151 | kv cache rm [90112, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 94208, n_tokens = 4096, progress = 0.937430
slot update_slots: id 0 | task 1151 | kv cache rm [94208, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 98304, n_tokens = 4096, progress = 0.978188
slot update_slots: id 0 | task 1151 | kv cache rm [98304, end)
slot update_slots: id 0 | task 1151 | prompt processing progress, n_past = 100496, n_tokens = 2192, progress = 1.000000
slot update_slots: id 0 | task 1151 | prompt done, n_past = 100496, n_tokens = 2192
slot release: id 0 | task 1151 | stop processing: n_past = 103296, truncated = 0
slot print_timing: id 0 | task 1151 |
prompt eval time = 430513.91 ms / 100496 tokens ( 4.28 ms per token, 233.43 tokens per second)
eval time = 365531.49 ms / 2801 tokens ( 130.50 ms per token, 7.66 tokens per second)
total time = 796045.40 ms / 103297 tokens
srv update_slots: all slots are idle
srv log_server_r: request: POST /v1/chat/completions 192.168.68.64 200
srv params_from_: Chat format: Content-only
slot launch_slot_: id 0 | task 3977 | processing task
slot update_slots: id 0 | task 3977 | new prompt, n_ctx_slot = 262144, n_keep = 0, n_prompt_tokens = 100496
slot update_slots: id 0 | task 3977 | n_past = 100496, cache_tokens.size() = 103296, seq_id = 0, pos_min = 103295, n_swa = 0
slot update_slots: id 0 | task 3977 | forcing full prompt re-processing due to lack of cache data (likely due to SWA, see https://github.com/ggml-org/llama.cpp/pull/13194#issuecomment-2868343055)
slot update_slots: id 0 | task 3977 | kv cache rm [0, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 4096, n_tokens = 4096, progress = 0.040758
slot update_slots: id 0 | task 3977 | kv cache rm [4096, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 8192, n_tokens = 4096, progress = 0.081516
slot update_slots: id 0 | task 3977 | kv cache rm [8192, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 12288, n_tokens = 4096, progress = 0.122274
slot update_slots: id 0 | task 3977 | kv cache rm [12288, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 16384, n_tokens = 4096, progress = 0.163031
slot update_slots: id 0 | task 3977 | kv cache rm [16384, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 20480, n_tokens = 4096, progress = 0.203789
slot update_slots: id 0 | task 3977 | kv cache rm [20480, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 24576, n_tokens = 4096, progress = 0.244547
slot update_slots: id 0 | task 3977 | kv cache rm [24576, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 28672, n_tokens = 4096, progress = 0.285305
slot update_slots: id 0 | task 3977 | kv cache rm [28672, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 32768, n_tokens = 4096, progress = 0.326063
slot update_slots: id 0 | task 3977 | kv cache rm [32768, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 36864, n_tokens = 4096, progress = 0.366821
slot update_slots: id 0 | task 3977 | kv cache rm [36864, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 40960, n_tokens = 4096, progress = 0.407578
slot update_slots: id 0 | task 3977 | kv cache rm [40960, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 45056, n_tokens = 4096, progress = 0.448336
slot update_slots: id 0 | task 3977 | kv cache rm [45056, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 49152, n_tokens = 4096, progress = 0.489094
slot update_slots: id 0 | task 3977 | kv cache rm [49152, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 53248, n_tokens = 4096, progress = 0.529852
slot update_slots: id 0 | task 3977 | kv cache rm [53248, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 57344, n_tokens = 4096, progress = 0.570610
slot update_slots: id 0 | task 3977 | kv cache rm [57344, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 61440, n_tokens = 4096, progress = 0.611368
slot update_slots: id 0 | task 3977 | kv cache rm [61440, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 65536, n_tokens = 4096, progress = 0.652125
slot update_slots: id 0 | task 3977 | kv cache rm [65536, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 69632, n_tokens = 4096, progress = 0.692883
slot update_slots: id 0 | task 3977 | kv cache rm [69632, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 73728, n_tokens = 4096, progress = 0.733641
slot update_slots: id 0 | task 3977 | kv cache rm [73728, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 77824, n_tokens = 4096, progress = 0.774399
slot update_slots: id 0 | task 3977 | kv cache rm [77824, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 81920, n_tokens = 4096, progress = 0.815157
slot update_slots: id 0 | task 3977 | kv cache rm [81920, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 86016, n_tokens = 4096, progress = 0.855915
slot update_slots: id 0 | task 3977 | kv cache rm [86016, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 90112, n_tokens = 4096, progress = 0.896672
slot update_slots: id 0 | task 3977 | kv cache rm [90112, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 94208, n_tokens = 4096, progress = 0.937430
slot update_slots: id 0 | task 3977 | kv cache rm [94208, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 98304, n_tokens = 4096, progress = 0.978188
slot update_slots: id 0 | task 3977 | kv cache rm [98304, end)
slot update_slots: id 0 | task 3977 | prompt processing progress, n_past = 100496, n_tokens = 2192, progress = 1.000000
slot update_slots: id 0 | task 3977 | prompt done, n_past = 100496, n_tokens = 2192
slot release: id 0 | task 3977 | stop processing: n_past = 102636, truncated = 0
slot print_timing: id 0 | task 3977 |
prompt eval time = 430566.11 ms / 100496 tokens ( 4.28 ms per token, 233.40 tokens per second)
eval time = 279356.42 ms / 2141 tokens ( 130.48 ms per token, 7.66 tokens per second)
total time = 709922.53 ms / 102637 tokens
srv update_slots: all slots are idle
srv log_server_r: request: POST /v1/chat/completions 192.168.68.64 200
^Csrv operator(): operator(): cleaning up before exit...