vllm-server.log

INFO 08-11 15:40:40 [__init__.py:52] Available plugins for group vllm.platform_plugins:
INFO 08-11 15:40:40 [__init__.py:54] - metal -> vllm_metal:register
INFO 08-11 15:40:40 [__init__.py:66] Loading plugin metal
INFO 08-11 15:40:53 [__init__.py:237] Platform plugin metal is activated
INFO 08-11 15:41:01 [importing.py:88] Triton not installed or not compatible; certain GPU-related functions will not be available.
(APIServer pid=57834) INFO 08-11 15:41:06 [api_utils.py:345] 
(APIServer pid=57834) INFO 08-11 15:41:06 [api_utils.py:345]        █     █     █▄   ▄█
(APIServer pid=57834) INFO 08-11 15:41:06 [api_utils.py:345]  ▄▄ ▄█ █     █     █ ▀▄▀ █  version 0.27.0
(APIServer pid=57834) INFO 08-11 15:41:06 [api_utils.py:345]   █▄█▀ █     █     █     █  model   mlx-community/Qwen3-4B-Instruct-2507-4bit
(APIServer pid=57834) INFO 08-11 15:41:06 [api_utils.py:345]    ▀▀  ▀▀▀▀▀ ▀▀▀▀▀ ▀     ▀
(APIServer pid=57834) INFO 08-11 15:41:06 [api_utils.py:345] 
(APIServer pid=57834) INFO 08-11 15:41:06 [api_utils.py:273] non-default args: {'model_tag': 'mlx-community/Qwen3-4B-Instruct-2507-4bit', 'host': '127.0.0.1', 'model': 'mlx-community/Qwen3-4B-Instruct-2507-4bit', 'max_model_len': 4096, 'served_model_name': ['qwen3-4b-local']}
(APIServer pid=57834) WARNING 08-11 15:41:06 [system_utils.py:299] Found ulimit of 2048 and failed to automatically increase with error current limit exceeds maximum limit. This can cause fd limit errors like `OSError: [Errno 24] Too many open files`. Consider increasing with ulimit -n
(APIServer pid=57834) Warning: You are sending unauthenticated requests to the HF Hub. Please set a HF_TOKEN to enable higher rate limits and faster downloads.
(APIServer pid=57834) INFO 08-11 15:42:01 [model.py:645] Resolved architecture: Qwen3ForCausalLM
(APIServer pid=57834) INFO 08-11 15:42:01 [model.py:1883] Using max model len 4096
(APIServer pid=57834) INFO 08-11 15:42:04 [kernel.py:306] Final IR op priority after setting platform defaults: IrOpPriorityConfig(rms_norm=['native'], fused_add_rms_norm=['native'])
(APIServer pid=57834) INFO 08-11 15:42:04 [platform.py:680] Metal: chunked prefill enabled (paged attention), max_num_batched_tokens=2048
(APIServer pid=57834) INFO 08-11 15:42:04 [platform.py:794] Metal memory: 51.5GB total, 23.2GB available
(APIServer pid=57834) WARNING 08-11 15:42:04 [vllm.py:609] Model Runner V2 requires Triton; using the V1 model runner instead.
INFO 08-11 15:42:19 [__init__.py:52] Available plugins for group vllm.platform_plugins:
INFO 08-11 15:42:19 [__init__.py:54] - metal -> vllm_metal:register
INFO 08-11 15:42:19 [__init__.py:66] Loading plugin metal
INFO 08-11 15:42:25 [__init__.py:237] Platform plugin metal is activated
INFO 08-11 15:42:27 [importing.py:88] Triton not installed or not compatible; certain GPU-related functions will not be available.
(EngineCore pid=62731) INFO 08-11 15:42:29 [core.py:121] Initializing a V1 LLM engine (v0.27.0) with config: model='mlx-community/Qwen3-4B-Instruct-2507-4bit', speculative_config=None, tokenizer='mlx-community/Qwen3-4B-Instruct-2507-4bit', skip_tokenizer_init=False, tokenizer_mode=auto, revision=None, tokenizer_revision=None, trust_remote_code=False, dtype=torch.bfloat16, max_seq_len=4096, download_dir=None, load_format=auto, tensor_parallel_size=1, pipeline_parallel_size=1, data_parallel_size=1, decode_context_parallel_size=1, dcp_comm_backend=ag_rs, disable_custom_all_reduce=True, quantization=None, quantization_config=None, enforce_eager=False, enable_return_routed_experts=False, kv_cache_dtype=auto, device_config=cpu, structured_outputs_config=StructuredOutputsConfig(backend='auto', 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, jit_monitor_mode='warn', jit_monitor_verbose=False), seed=0, served_model_name=qwen3-4b-local, enable_prefix_caching=True, enable_chunked_prefill=True, pooler_config=None, compilation_config={'mode': <CompilationMode.VLLM_COMPILE: 3>, 'debug_dump_path': None, 'cache_dir': '', 'compile_cache_save_format': 'binary', 'backend': 'inductor', 'custom_ops': ['none'], 'ir_enable_torch_wrap': True, 'splitting_ops': ['vllm::unified_attention_with_output', 'vllm::unified_mla_attention_with_output', 'vllm::mamba_mixer2', 'vllm::mamba_mixer', 'vllm::short_conv', 'vllm::linear_attention', 'vllm::qwen_gdn_attention_core', 'vllm::gdn_attention_core_xpu', 'vllm::olmo_hybrid_gdn_full_forward', 'vllm::sparse_attn_indexer', 'vllm::rocm_aiter_sparse_attn_indexer', 'vllm::deepseek_v4_attention', 'vllm::hpc_rope_norm_forward', 'vllm::unified_kv_cache_update', 'vllm::unified_mla_kv_cache_update'], 'compile_mm_encoder': False, 'cudagraph_mm_encoder': False, 'encoder_cudagraph_token_budgets': [], 'encoder_cudagraph_max_vision_items_per_batch': 0, 'encoder_cudagraph_max_frames_per_batch': None, 'compile_sizes': None, 'compile_ranges_endpoints': [2048], 'inductor_compile_config': {'enable_auto_functionalized_v2': False, 'combo_kernels': True, 'benchmark_combo_kernel': True}, 'inductor_passes': {}, 'cudagraph_mode': <CUDAGraphMode.NONE: 0>, '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, 'enable_sp': False, 'fuse_gemm_comms': False, 'fuse_allreduce_rms': False, 'enable_qk_norm_rope_fusion': False, 'fuse_rope_kvcache_cat_mla': False, 'fuse_act_padding': False, 'fuse_qk_norm_rope_kvcache': False}, 'max_cudagraph_capture_size': None, 'dynamic_shapes_config': {'type': <DynamicShapesType.BACKED: 'backed'>, 'evaluate_guards': False, 'assume_32_bit_indexing': False}, 'local_cache_dir': None, 'fast_moe_cold_start': False, 'static_all_moe_layers': []}, kernel_config=KernelConfig(ir_op_priority=IrOpPriorityConfig(rms_norm=['native'], fused_add_rms_norm=['native']), enable_flashinfer_autotune=True, enable_cutedsl_warmup=True, enable_jit_warmup=True, enable_bf16x3_router_gemm=False, moe_backend='auto', linear_backend='auto')
(EngineCore pid=62731) INFO 08-11 15:42:30 [worker.py:125] MLX device set to: Device(gpu, 0)
mx.metal.device_info is deprecated and will be removed in a future version. Use mx.device_info instead.
(EngineCore pid=62731) INFO 08-11 15:42:30 [utils.py:72] Set Metal wired_limit to 37.4 GB
(EngineCore pid=62731) INFO 08-11 15:42:30 [worker.py:133] PyTorch device set to: mps
(EngineCore pid=62731) INFO 08-11 15:42:30 [parallel_state.py:1640] world_size=1 rank=0 local_rank=0 distributed_init_method=tcp://100.82.67.172:56310 backend=gloo
[W811 15:42:32.060975000 ProcessGroupGloo.cpp:555] Warning: Unable to resolve hostname to a (local) address. Using the loopback address as fallback. Manually set the network interface to bind to with GLOO_SOCKET_IFNAME. (function operator())
(EngineCore pid=62731) INFO 08-11 15:42:32 [parallel_state.py:1977] rank 0 in world size 1 is assigned as DP rank 0, PP rank 0, PCP rank 0, TP rank 0, EP rank N/A, EPLB rank N/A
(EngineCore pid=62731) Warning: You are sending unauthenticated requests to the HF Hub. Please set a HF_TOKEN to enable higher rate limits and faster downloads.
(EngineCore pid=62731) 
Fetching 11 files:   0%|          | 0/11 [00:00<?, ?it/s]
Fetching 11 files:  91%|█████████ | 10/11 [00:00<00:00, 16.66it/s]
Fetching 11 files:  91%|█████████ | 10/11 [00:20<00:00, 16.66it/s]
Fetching 11 files: 100%|██████████| 11/11 [01:42<00:00, 12.73s/it]
Fetching 11 files: 100%|██████████| 11/11 [01:42<00:00,  9.27s/it]
(EngineCore pid=62731) INFO 08-11 15:44:18 [model_lifecycle.py:229] MLX-LM model loaded in 103.96s: mlx-community/Qwen3-4B-Instruct-2507-4bit
(EngineCore pid=62731) INFO 08-11 15:44:20 [cache_policy.py:1175] Paged attention: VLLM_METAL_MEMORY_FRACTION=auto, using --gpu-memory-utilization=0.92
(EngineCore pid=62731) INFO 08-11 15:44:20 [cache_policy.py:935] Paged attention memory breakdown: metal_limit=40.20GB, fraction=0.92, usable_metal=36.98GB, model_memory=2.26GB, overhead=0.92GB, kv_budget=33.80GB, per_block_bytes=2359296, num_blocks=14328, max_tokens_cached=229248
(EngineCore pid=62731) INFO 08-11 15:44:23 [kv_cache.py:268] KV cache: 33804.0 MB (36 layers, 14328 blocks, 16 tokens/block)
(EngineCore pid=62731) INFO 08-11 15:44:24 [cache_policy.py:965] Paged attention enabled: 36 layers patched, 14328 blocks allocated (block_size=16, mla=False, turboquant=False, k_quant=N/A)
(EngineCore pid=62731) INFO 08-11 15:44:24 [cache_policy.py:1006] Paged attention: reporting MPS cache capacity (14328 blocks × 2359296 bytes = 33.80 GB)
(EngineCore pid=62731) INFO 08-11 15:44:24 [kv_cache_utils.py:2235] GPU KV cache size: 229,248 tokens
(EngineCore pid=62731) INFO 08-11 15:44:24 [kv_cache_utils.py:2236] Maximum concurrency for 4,096 tokens per request: 55.97x
(EngineCore pid=62731) INFO 08-11 15:44:24 [cache_policy.py:461] KV cache config received: 14328 blocks (MLX manages cache internally)
(EngineCore pid=62731) INFO 08-11 15:44:24 [model_runner.py:859] Warming up model...
(EngineCore pid=62731) INFO 08-11 15:44:24 [model_runner.py:863] Model warm-up complete
(EngineCore pid=62731) INFO 08-11 15:44:25 [__init__.py:258] Warming up v2 paged-attention Metal kernels...
(EngineCore pid=62731) INFO 08-11 15:44:26 [__init__.py:239] Native paged-attention Metal kernels loaded
(EngineCore pid=62731) INFO 08-11 15:44:26 [__init__.py:266] Paged-attention Metal kernel warm-up complete
(EngineCore pid=62731) INFO 08-11 15:44:26 [core.py:348] init engine (profile, create kv cache, warmup model) took 7.52 s (compilation: 1.93 s)
(EngineCore pid=62731) WARNING 08-11 15:44:30 [vllm.py:609] Model Runner V2 requires Triton; using the V1 model runner instead.
(EngineCore pid=62731) INFO 08-11 15:44:30 [kernel.py:306] Final IR op priority after setting platform defaults: IrOpPriorityConfig(rms_norm=['native'], fused_add_rms_norm=['native'])
(EngineCore pid=62731) INFO 08-11 15:44:30 [platform.py:680] Metal: chunked prefill enabled (paged attention), max_num_batched_tokens=2048
(EngineCore pid=62731) INFO 08-11 15:44:31 [platform.py:794] Metal memory: 51.5GB total, 6.0GB available
(APIServer pid=57834) INFO 08-11 15:44:31 [api_server.py:678] Supported tasks: ['generate']
(APIServer pid=57834) INFO 08-11 15:44:38 [hf.py:540] Detected the chat template content format to be 'string'. You can set `--chat-template-content-format` to override this.
(APIServer pid=57834) WARNING 08-11 15:44:38 [model.py:1637] Default vLLM sampling parameters have been overridden by the model's `generation_config.json`: `{'temperature': 0.7, 'top_k': 20, 'top_p': 0.8}`. If this is not intended, please relaunch vLLM instance with `--generation-config vllm`.
(APIServer pid=57834) INFO 08-11 15:44:41 [api_server.py:682] Starting vLLM server on http://127.0.0.1:8000
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:37] Available routes are:
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /openapi.json, Methods: HEAD, GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /docs, Methods: HEAD, GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /docs/oauth2-redirect, Methods: HEAD, GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /redoc, Methods: HEAD, GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /load, Methods: GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /version, Methods: GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /health, Methods: GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /metrics, Methods: GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /tokenize, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /detokenize, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/models, Methods: GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /ping, Methods: GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /ping, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /invocations, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/chat/completions, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/chat/completions/batch, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/responses, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/responses/{response_id}, Methods: GET
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/responses/{response_id}/cancel, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/completions, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/messages, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/messages/count_tokens, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /generative_scoring, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /scale_elastic_ep, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /is_scaling_elastic_ep, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/chat/completions/render, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/completions/render, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/chat/completions/derender, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /v1/completions/derender, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:41 [launcher.py:46] Route: /inference/v1/generate, Methods: POST
(APIServer pid=57834) INFO 08-11 15:44:43 [launcher.py:99] API server: waiting for HTTP server to start
(APIServer pid=57834) INFO:     Started server process [57834]
(APIServer pid=57834) INFO:     Waiting for application startup.
(APIServer pid=57834) INFO:     Application startup complete.
(APIServer pid=57834) INFO 08-11 15:44:43 [launcher.py:105] API server: HTTP server started
(APIServer pid=57834) INFO:     127.0.0.1:56583 - "GET /health HTTP/1.1" 200 OK
(APIServer pid=57834) INFO:     127.0.0.1:56589 - "GET /v1/models HTTP/1.1" 200 OK
(APIServer pid=57834) INFO:     127.0.0.1:56612 - "POST /v1/chat/completions HTTP/1.1" 200 OK
(APIServer pid=57834) INFO 08-11 15:45:43 [loggers.py:310] Engine 000: Avg prompt throughput: 2.5 tokens/s, Avg generation throughput: 4.5 tokens/s, Running: 0 reqs, Waiting: 0 reqs, GPU KV cache usage: 0.0%, Prefix cache hit rate: 0.0%
(APIServer pid=57834) INFO 08-11 15:45:53 [loggers.py:310] 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.0%