intel / intel/llm-scaler

GLM-4.7-Flash instance is crashed

Open
#364 3 comments 0 reactions 1 assignee Claimed by @montaguelhz View on GitHub
Dominant language
C++
Stars
529
Forks
80
Avg merge
9h 7m
Merged PRs (30d)
38

Description

Description
----
The GLM-4.7-Flash model instance encountered a sudden system crash, what are the root causes, and what strategies can be employed to enhance system stability and resilience?

docker iamge: **llm-scaler-vllm:0.14.0-b8**

Bootup Command
----
```
VLLM_ALLOW_LONG_MAX_MODEL_LEN=1 \
VLLM_WORKER_MULTIPROC_METHOD=spawn \
vllm serve \
--model /llm/models/GLM-4.7-Flash \
--served-model-name glm-4.7-flash \
--dtype=float16 \
--enforce-eager \
--port 8000 \
--host 0.0.0.0 \
--trust-remote-code \
--disable-sliding-window \
--gpu-memory-util=0.9 \
--max-num-batched-tokens=8192 \
--disable-log-requests \
--max-model-len=45312 \
--quantization fp8 \
--block-size 64 \
-tp=4
```

Log Output
----
```
(APIServer pid=2406) INFO 04-14 22:34:43 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 47.0 tokens/s, Running: 2 reqs, Waiting: 0 reqs, GPU KV cache usage: 14.3%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 22:34:53 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 47.0 tokens/s, Running: 2 reqs, Waiting: 0 reqs, GPU KV cache usage: 15.2%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 22:35:03 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 47.0 tokens/s, Running: 2 reqs, Waiting: 0 reqs, GPU KV cache usage: 16.1%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 22:35:13 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 41.3 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 8.4%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 22:35:23 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 24.2 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 8.9%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 22:35:33 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 24.1 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 9.4%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 22:35:43 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 24.2 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 9.7%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 22:35:53 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 24.1 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 10.2%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 22:36:03 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 24.1 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 10.7%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 22:36:13 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 5.3 tokens/s, Running: 0 reqs, Waiting: 0 reqs, GPU KV cache usage: 0.0%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 22:36:23 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 0.0 tokens/s, Running: 0 reqs, Waiting: 0 reqs, GPU KV cache usage: 0.0%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO: 10.223.52.154:1385 - "POST /v1/chat/completions HTTP/1.1" 200 OK
(APIServer pid=2406) INFO 04-14 23:00:03 [loggers.py:257] Engine 000: Avg prompt throughput: 4.2 tokens/s, Avg generation throughput: 14.2 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 0.4%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 23:00:13 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 26.8 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 1.0%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 23:00:23 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 26.6 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 1.4%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 23:00:33 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 19.7 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 1.8%, Prefix cache hit rate: 0.6%
(APIServer pid=2406) INFO 04-14 23:00:44 [loggers.py:257] Engine 000: Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 0.0 tokens/s, Running: 1 reqs, Waiting: 0 reqs, GPU KV cache usage: 1.8%, Prefix cache hit rate: 0.6%
(EngineCore_DP0 pid=2674) INFO 04-14 23:01:33 [shm_broadcast.py:542] No available shared memory broadcast block found in 60 seconds. This typically happens when some processes are hanging or doing some time-consuming work (e.g. compilation, weight/kv cache quantization).
(EngineCore_DP0 pid=2674) INFO 04-14 23:02:37 [shm_broadcast.py:542] No available shared memory broadcast block found in 60 seconds. This typically happens when some processes are hanging or doing some time-consuming work (e.g. compilation, weight/kv cache quantization).
(EngineCore_DP0 pid=2674) INFO 04-14 23:04:22 [shm_broadcast.py:542] No available shared memory broadcast block found in 60 seconds. This typically happens when some processes are hanging or doing some time-consuming work (e.g. compilation, weight/kv cache quantization).
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [dump_input.py:72] Dumping input data for V1 LLM engine (v0.14.1.dev0+gb17039bcc.d20260227) with config: model='/llm/models/GLM-4.7-Flash', speculative_config=None, tokenizer='/llm/models/GLM-4.7-Flash', skip_tokenizer_init=False, tokenizer_mode=auto, revision=None, tokenizer_revision=None, trust_remote_code=True, dtype=torch.float16, max_seq_len=45312, download_dir=None, load_format=auto, tensor_parallel_size=4, pipeline_parallel_size=1, data_parallel_size=1, disable_custom_all_reduce=True, quantization=fp8, enforce_eager=True, enable_return_routed_experts=False, kv_cache_dtype=auto, device_config=xpu, structured_outputs_config=StructuredOutputsConfig(backend='auto', disable_fallback=False, disable_any_whitespace=False, disable_additional_properties=False, reasoning_parser='', reasoning_parser_plugin='', enable_in_reasoning=False), observability_config=ObservabilityConfig(show_hidden_metrics_for_version=None, otlp_traces_endpoint=None, collect_detailed_traces=None, kv_cache_metrics=False, kv_cache_metrics_sample=0.01, cudagraph_metrics=False, enable_layerwise_nvtx_tracing=False, enable_mfu_metrics=False, enable_mm_processor_stats=False, enable_logging_iteration_details=False), seed=0, served_model_name=glm-4.7-flash, enable_prefix_caching=True, enable_chunked_prefill=True, pooler_config=None, compilation_config={'level': None, 'mode': , 'debug_dump_path': None, 'cache_dir': '', 'compile_cache_save_format': 'binary', 'backend': 'inductor', 'custom_ops': ['all'], 'splitting_ops': [], 'compile_mm_encoder': False, 'compile_sizes': [], 'compile_ranges_split_points': [8192], 'inductor_compile_config': {'enable_auto_functionalized_v2': False, 'combo_kernels': True, 'benchmark_combo_kernel': True}, 'inductor_passes': {}, 'cudagraph_mode': , 'cudagraph_num_of_warmups': 0, 'cudagraph_capture_sizes': None, 'cudagraph_copy_inputs': False, 'cudagraph_specialize_lora': True, 'use_inductor_graph_partition': False, 'pass_config': {'fuse_norm_quant': False, 'fuse_act_quant': False, 'fuse_attn_quant': False, 'eliminate_noops': False, 'enable_sp': False, 'fuse_gemm_comms': False, 'fuse_allreduce_rms': False}, 'max_cudagraph_capture_size': None, 'dynamic_shapes_config': {'type': , 'evaluate_guards': False, 'assume_32_bit_indexing': True}, 'local_cache_dir': None},
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [dump_input.py:79] Dumping scheduler output for model execution: SchedulerOutput(scheduled_new_reqs=[], scheduled_cached_reqs=CachedRequestData(req_ids=['chatcmpl-848b6a84b1092ef8-838be54b'],resumed_req_ids=set(),new_token_ids_lens=[],all_token_ids_lens={},new_block_ids=[None],num_computed_tokens=[914],num_output_tokens=[873]), num_scheduled_tokens={chatcmpl-848b6a84b1092ef8-838be54b: 1}, total_num_scheduled_tokens=1, scheduled_spec_decode_tokens={}, scheduled_encoder_inputs={}, num_common_prefix_blocks=[15], finished_req_ids=[], free_encoder_mm_hashes=[], preempted_req_ids=[], has_structured_output_requests=false, pending_structured_output_tokens=false, num_invalid_spec_tokens=null, kv_connector_metadata=null, ec_connector_metadata=null)
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [dump_input.py:81] Dumping scheduler stats: SchedulerStats(num_running_reqs=1, num_waiting_reqs=0, step_counter=0, current_wave=0, kv_cache_usage=0.01800720288115243, prefix_cache_stats=PrefixCacheStats(reset=False, requests=0, queries=0, hits=0, preempted_requests=0, preempted_queries=0, preempted_hits=0), connector_prefix_cache_stats=None, kv_cache_eviction_events=[], spec_decoding_stats=None, kv_connector_stats=None, waiting_lora_adapters={}, running_lora_adapters={}, cudagraph_stats=None, perf_stats=None)
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] EngineCore encountered a fatal error.
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] Traceback (most recent call last):
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/executor/multiproc_executor.py", line 336, in get_response
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] status, result = mq.dequeue(
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] ^^^^^^^^^^^
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/local/lib/python3.12/dist-packages/vllm/distributed/device_communicators/shm_broadcast.py", line 616, in dequeue
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] with self.acquire_read(timeout, cancel, indefinite) as buf:
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/lib/python3.12/contextlib.py", line 137, in __enter__
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] return next(self.gen)
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] ^^^^^^^^^^^^^^
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/local/lib/python3.12/dist-packages/vllm/distributed/device_communicators/shm_broadcast.py", line 536, in acquire_read
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] raise TimeoutError
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] TimeoutError
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938]
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] The above exception was the direct cause of the following exception:
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938]
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] Traceback (most recent call last):
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/engine/core.py", line 929, in run_engine_core
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] engine_core.run_busy_loop()
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/engine/core.py", line 956, in run_busy_loop
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] self._process_engine_step()
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/engine/core.py", line 989, in _process_engine_step
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] outputs, model_executed = self.step_fn()
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] ^^^^^^^^^^^^^^
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/engine/core.py", line 388, in step
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] model_output = future.result()
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] ^^^^^^^^^^^^^^^
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/executor/multiproc_executor.py", line 80, in result
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] return super().result()
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] ^^^^^^^^^^^^^^^^
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/lib/python3.12/concurrent/futures/_base.py", line 449, in result
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] return self.__get_result()
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] ^^^^^^^^^^^^^^^^^^^
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/lib/python3.12/concurrent/futures/_base.py", line 401, in __get_result
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] raise self._exception
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/executor/multiproc_executor.py", line 84, in wait_for_response
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] response = self.aggregate(get_response())
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] ^^^^^^^^^^^^^^
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/executor/multiproc_executor.py", line 340, in get_response
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] raise TimeoutError(f"RPC call to {method} timed out.") from e
(EngineCore_DP0 pid=2674) ERROR 04-14 23:32:27 [core.py:938] TimeoutError: RPC call to execute_model timed out.
(Worker_TP2 pid=2938) INFO 04-14 23:32:27 [multiproc_executor.py:707] Parent process exited, terminating worker
(APIServer pid=2406) ERROR 04-14 23:32:27 [async_llm.py:546] AsyncLLM output_handler failed.
(APIServer pid=2406) ERROR 04-14 23:32:27 [async_llm.py:546] Traceback (most recent call last):
(APIServer pid=2406) ERROR 04-14 23:32:27 [async_llm.py:546] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/engine/async_llm.py", line 502, in output_handler
(APIServer pid=2406) ERROR 04-14 23:32:27 [async_llm.py:546] outputs = await engine_core.get_output_async()
(APIServer pid=2406) ERROR 04-14 23:32:27 [async_llm.py:546] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
(APIServer pid=2406) ERROR 04-14 23:32:27 [async_llm.py:546] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/engine/core_client.py", line 899, in get_output_async
(APIServer pid=2406) ERROR 04-14 23:32:27 [async_llm.py:546] raise self._format_exception(outputs) from None
(APIServer pid=2406) ERROR 04-14 23:32:27 [async_llm.py:546] vllm.v1.engine.exceptions.EngineDeadError: EngineCore encountered an issue. See stack trace (above) for the root cause.
(Worker_TP3 pid=2939) INFO 04-14 23:32:27 [multiproc_executor.py:707] Parent process exited, terminating worker
(Worker_TP1 pid=2937) INFO 04-14 23:32:27 [multiproc_executor.py:707] Parent process exited, terminating worker
(Worker_TP0 pid=2936) INFO 04-14 23:32:27 [multiproc_executor.py:707] Parent process exited, terminating worker
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] Error in chat completion stream generator.
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] Traceback (most recent call last):
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] File "/usr/local/lib/python3.12/dist-packages/vllm/entrypoints/openai/serving_chat.py", line 715, in chat_completion_stream_generator
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] async for res in result_generator:
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/engine/async_llm.py", line 437, in generate
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] out = q.get_nowait() or await q.get()
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] ^^^^^^^^^^^^^
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/engine/output_processor.py", line 77, in get
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] raise output
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/engine/async_llm.py", line 502, in output_handler
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] outputs = await engine_core.get_output_async()
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] File "/usr/local/lib/python3.12/dist-packages/vllm/v1/engine/core_client.py", line 899, in get_output_async
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] raise self._format_exception(outputs) from None
(APIServer pid=2406) ERROR 04-14 23:32:27 [serving_chat.py:1343] vllm.v1.engine.exceptions.EngineDeadError: EngineCore encountered an issue. See stack trace (above) for the root cause.
(APIServer pid=2406) INFO: Shutting down
(APIServer pid=2406) INFO: Waiting for application shutdown.
(APIServer pid=2406) INFO: Application shutdown complete.
(APIServer pid=2406) INFO: Finished server process [2406]
/usr/lib/python3.12/multiprocessing/resource_tracker.py:254: UserWarning: resource_tracker: There appear to be 3 leaked semaphore objects to clean up at shutdown
warnings.warn('resource_tracker: There appear to be %d '
/usr/lib/python3.12/multiprocessing/resource_tracker.py:254: UserWarning: resource_tracker: There appear to be 1 leaked shared_memory objects to clean up at shutdown
warnings.warn('resource_tracker: There appear to be %d '
```

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.