Tool Call Errors

#2
by cgelias - opened

Trying to use this with claude code and it fails to launch any tool calls
FunctionTool' object has no attribute 'function'

This is on HGX B200 and vllm/vllm-openai:hy3 image. Any thoughts? Am I doing something wrong?

(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] Error in extracting tool call from response.
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] Traceback (most recent call last):
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] File "/usr/local/lib/python3.12/dist-packages/vllm/tool_parsers/hy_v3_tool_parser.py", line 353, in _extract_tool_calls
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] parsed_value = HYV3ToolParser._parse_value(
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] File "/usr/local/lib/python3.12/dist-packages/vllm/tool_parsers/hy_v3_tool_parser.py", line 219, in _parse_value
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] arg_schema = HYV3ToolParser._get_arg_schema(function_name, arg_key, tools)
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] File "/usr/local/lib/python3.12/dist-packages/vllm/tool_parsers/hy_v3_tool_parser.py", line 93, in _get_arg_schema
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] if tool.function.name == function_name:
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] ^^^^^^^^^^^^^
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] File "/usr/local/lib/python3.12/dist-packages/pydantic/main.py", line 1042, in getattr
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] raise AttributeError(f'{type(self).name!r} object has no attribute {item!r}')
(APIServer pid=1) ERROR 07-11 13:58:42 [hy_v3_tool_parser.py:368] AttributeError: 'FunctionTool' object has no attribute 'function'

Startup Log incl. config
Starting vllm:
(APIServer pid=1) INFO 07-11 12:34:38 [api_utils.py:339]
(APIServer pid=1) INFO 07-11 12:34:38 [api_utils.py:339] █ █ █▄ ▄█
(APIServer pid=1) INFO 07-11 12:34:38 [api_utils.py:339] ▄▄ ▄█ █ █ █ ▀▄▀ █ version 0.23.1rc1.dev796+g95a248fae
(APIServer pid=1) INFO 07-11 12:34:38 [api_utils.py:339] █▄█▀ █ █ █ █ model cyankiwi/Hy3-AWQ-NVFP4
(APIServer pid=1) INFO 07-11 12:34:38 [api_utils.py:339] ▀▀ ▀▀▀▀▀ ▀▀▀▀▀ ▀ ▀
(APIServer pid=1) INFO 07-11 12:34:38 [api_utils.py:339]
(APIServer pid=1) INFO 07-11 12:34:38 [api_utils.py:273] non-default args: {'model_tag': 'None', 'enable_auto_tool_choice': True, 'tool_call_parser': 'hy_v3', 'model': 'cyankiwi/Hy3-AWQ-NVFP4', 'trust_remote_code': True, 'max_model_len': 262144, 'served_model_name': ['Hy3'], 'download_dir': '/data/vllm/download', 'reasoning_parser': 'hy_v3', 'tensor_parallel_size': 2, 'gpu_memory_utilization': 0.9, 'kv_cache_dtype': 'fp8', 'enable_prefix_caching': True, 'max_num_batched_tokens': 42000, 'max_num_seqs': 16, 'enable_chunked_prefill': True, 'speculative_config': {'method': 'mtp', 'num_speculative_tokens': 2}}
(APIServer pid=1) WARNING 07-11 12:34:38 [envs.py:2035] Unknown vLLM environment variable detected: VLLM_BUILD_URL
(APIServer pid=1) WARNING 07-11 12:34:38 [envs.py:2035] Unknown vLLM environment variable detected: VLLM_IMAGE_TAG
(APIServer pid=1) WARNING 07-11 12:34:38 [envs.py:2035] Unknown vLLM environment variable detected: VLLM_BUILD_PIPELINE
(APIServer pid=1) WARNING 07-11 12:34:38 [envs.py:2035] Unknown vLLM environment variable detected: VLLM_BUILD_COMMIT
(APIServer pid=1) INFO 07-11 12:36:03 [model.py:606] Resolved architecture: HYV3ForCausalLM
(APIServer pid=1) INFO 07-11 12:36:03 [model.py:1736] Using max model len 262144
(APIServer pid=1) INFO 07-11 12:36:09 [cache.py:286] Using fp8 data type to store kv cache. It reduces the GPU memory footprint and boosts the performance. Meanwhile, it may cause accuracy drop without a proper scaling factor
(APIServer pid=1) INFO 07-11 12:36:21 [model.py:606] Resolved architecture: HYV3MTPModel
(APIServer pid=1) INFO 07-11 12:36:21 [model.py:1736] Using max model len 262144
(APIServer pid=1) WARNING 07-11 12:36:21 [speculative.py:809] Enabling num_speculative_tokens > 1 will run multiple times of forward on same MTP layer,which may result in lower acceptance rate
(APIServer pid=1) INFO 07-11 12:36:21 [scheduler.py:252] Chunked prefill is enabled with max_num_batched_tokens=42000.
(APIServer pid=1) INFO 07-11 12:36:22 [vllm.py:1042] Asynchronous scheduling is enabled.
(APIServer pid=1) INFO 07-11 12:36:22 [kernel.py:291] Final IR op priority after setting platform defaults: IrOpPriorityConfig(rms_norm=['native'], fused_add_rms_norm=['native'])
(APIServer pid=1) INFO 07-11 12:36:25 [compilation.py:312] Enabled custom fusions: act_quant, allreduce_rms
(EngineCore pid=2220) INFO 07-11 12:36:43 [core.py:114] Initializing a V1 LLM engine (v0.23.1rc1.dev796+g95a248fae) with config: model='cyankiwi/Hy3-AWQ-NVFP4', speculative_config=SpeculativeConfig(method='mtp', model='cyankiwi/Hy3-AWQ-NVFP4', num_spec_tokens=2), tokenizer='cyankiwi/Hy3-AWQ-NVFP4', skip_tokenizer_init=False, tokenizer_mode=auto, revision=None, tokenizer_revision=None, trust_remote_code=True, dtype=torch.bfloat16, max_seq_len=262144, download_dir='/data/vllm/download', load_format=auto, tensor_parallel_size=2, pipeline_parallel_size=1, data_parallel_size=1, decode_context_parallel_size=1, dcp_comm_backend=ag_rs, disable_custom_all_reduce=False, quantization=compressed-tensors, quantization_config=None, enforce_eager=False, enable_return_routed_experts=False, kv_cache_dtype=fp8, device_config=cuda, structured_outputs_config=StructuredOutputsConfig(backend='auto', disable_any_whitespace=False, disable_additional_properties=False, reasoning_parser='hy_v3', 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=Hy3, 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::plamo2_mamba_mixer', 'vllm::qwen_gdn_attention_core', 'vllm::gdn_attention_core_xpu', 'vllm::olmo_hybrid_gdn_full_forward', 'vllm::kda_attention', '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': [], 'compile_ranges_endpoints': [8192, 42000], 'inductor_compile_config': {'enable_auto_functionalized_v2': False, 'size_asserts': False, 'alignment_asserts': False, 'scalar_asserts': False, 'combo_kernels': True, 'benchmark_combo_kernel': True}, 'inductor_passes': {}, 'cudagraph_mode': <CUDAGraphMode.FULL_AND_PIECEWISE: (2, 1)>, 'cudagraph_num_of_warmups': 1, 'cudagraph_capture_sizes': [1, 2, 4, 8, 16, 24, 32, 40, 48, 56, 64, 72, 80, 88, 96], 'cudagraph_copy_inputs': False, 'cudagraph_specialize_lora': True, 'use_inductor_graph_partition': False, 'pass_config': {'fuse_norm_quant': False, 'fuse_act_quant': True, 'fuse_attn_quant': False, 'enable_sp': False, 'fuse_gemm_comms': False, 'fuse_allreduce_rms': True, 'fuse_rope_kvcache_cat_mla': False, 'fuse_act_padding': False}, 'max_cudagraph_capture_size': 96, '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, moe_backend='auto', linear_backend='auto')
(EngineCore pid=2220) WARNING 07-11 12:36:43 [multiproc_executor.py:1067] Reducing Torch parallelism from 96 threads to 1 to avoid unnecessary CPU contention. Set OMP_NUM_THREADS in the external environment to tune this value as needed.
(EngineCore pid=2220) INFO 07-11 12:36:43 [multiproc_executor.py:140] DP group leader: node_rank=0, node_rank_within_dp=0, master_addr=127.0.0.1, mq_connect_ip=172.18.0.10 (local), world_size=2, local_world_size=2
(Worker pid=2420) INFO 07-11 12:36:54 [parallel_state.py:1588] world_size=2 rank=0 local_rank=0 distributed_init_method=tcp://127.0.0.1:50125 backend=nccl
(Worker pid=2425) INFO 07-11 12:37:01 [parallel_state.py:1588] world_size=2 rank=1 local_rank=1 distributed_init_method=tcp://127.0.0.1:50125 backend=nccl
(Worker pid=2420) INFO 07-11 12:37:01 [pynccl.py:113] vLLM is using nccl==2.28.9
(Worker pid=2420) INFO 07-11 12:37:03 [cuda_communicator.py:246] Using ['CUSTOM', 'SYMM_MEM', 'PYNCCL'] all-reduce backends (in dispatch order) for group 'tp:0' out of potential backends: ['NCCL_SYMM_MEM', 'QUICK_REDUCE', 'FLASHINFER', 'CUSTOM', 'SYMM_MEM', 'PYNCCL'].
(Worker pid=2420) INFO 07-11 12:37:04 [cuda_communicator.py:246] Using ['PYNCCL'] all-reduce backends (in dispatch order) for group 'ep:0' out of potential backends: ['NCCL_SYMM_MEM', 'QUICK_REDUCE', 'FLASHINFER', 'CUSTOM', 'SYMM_MEM', 'PYNCCL'].
(Worker pid=2420) INFO 07-11 12:37:04 [parallel_state.py:1923] rank 0 in world size 2 is assigned as DP rank 0, PP rank 0, PCP rank 0, TP rank 0, EP rank 0, EPLB rank N/A
(Worker pid=2420) INFO 07-11 12:37:05 [topk_topp_sampler.py:55] Using FlashInfer for top-p & top-k sampling.
(Worker pid=2425) WARNING 07-11 12:37:05 [init.py:204] min_p and logit_bias parameters won't work with speculative decoding.
(Worker pid=2420) WARNING 07-11 12:37:05 [init.py:204] min_p and logit_bias parameters won't work with speculative decoding.
(Worker_TP0 pid=2420) INFO 07-11 12:37:06 [gpu_model_runner.py:5171] Starting to load model cyankiwi/Hy3-AWQ-NVFP4...
(Worker_TP1 pid=2425) INFO 07-11 12:37:06 [selector.py:138] Using HND KV cache layout for FLASHINFER backend.
(Worker_TP0 pid=2420) INFO 07-11 12:37:06 [cuda.py:476] Using FLASHINFER attention backend out of potential backends: ['FLASHINFER', 'TRITON_ATTN'].
(Worker_TP0 pid=2420) INFO 07-11 12:37:06 [selector.py:138] Using HND KV cache layout for FLASHINFER backend.
(Worker_TP0 pid=2420) INFO 07-11 12:37:06 [deep_gemm.py:175] deep_gemm not found in site-packages, trying vendored vllm.third_party.deep_gemm
(Worker_TP0 pid=2420) INFO 07-11 12:37:06 [deep_gemm.py:202] DeepGEMM PDL enabled on vllm.third_party.deep_gemm.
(Worker_TP0 pid=2420) INFO 07-11 12:37:06 [deep_gemm.py:120] DeepGEMM E8M0 enabled on current platform.
(Worker_TP0 pid=2420) INFO 07-11 12:37:06 [init.py:946] Using FlashInferCuteDslNvFp4LinearKernel for NVFP4 GEMM
(Worker_TP0 pid=2420) INFO 07-11 12:37:07 [nvfp4.py:270] Using 'FLASHINFER_TRTLLM' NvFp4 MoE backend out of potential backends: ['FLASHINFER_TRTLLM', 'FLASHINFER_CUTEDSL', 'FLASHINFER_CUTEDSL_BATCHED', 'FLASHINFER_CUTLASS', 'VLLM_CUTLASS', 'MARLIN', 'EMULATION'].
(Worker_TP0 pid=2420) INFO 07-11 13:13:03 [weight_utils.py:530] Time spent downloading weights for cyankiwi/Hy3-AWQ-NVFP4: 2152.099301 seconds
(Worker_TP0 pid=2420) INFO 07-11 13:13:04 [weight_utils.py:849] Filesystem type for checkpoints: BTRFS. Checkpoint size: 165.30 GiB. Available RAM: 1707.14 GiB.
(Worker_TP0 pid=2420) INFO 07-11 13:13:04 [weight_utils.py:872] Auto-prefetch is disabled because the filesystem (BTRFS) is not a recognized network FS (NFS/Lustre). If you want to force prefetching, start vLLM with --safetensors-load-strategy=prefetch.
Loading safetensors checkpoint shards: 0% Completed | 0/34 [00:00<?, ?it/s]
Loading safetensors checkpoint shards: 3% Completed | 1/34 [00:27<15:10, 27.59s/it]
Loading safetensors checkpoint shards: 6% Completed | 2/34 [00:39<09:48, 18.39s/it]
Loading safetensors checkpoint shards: 9% Completed | 3/34 [00:43<06:00, 11.61s/it]
Loading safetensors checkpoint shards: 12% Completed | 4/34 [00:46<04:12, 8.42s/it]
Loading safetensors checkpoint shards: 15% Completed | 5/34 [00:50<03:13, 6.67s/it]
Loading safetensors checkpoint shards: 18% Completed | 6/34 [00:53<02:38, 5.67s/it]
(Worker_TP1 pid=2425) INFO 07-11 13:14:01 [kernel.py:291] Final IR op priority after setting platform defaults: IrOpPriorityConfig(rms_norm=['native'], fused_add_rms_norm=['native'])
(Worker_TP1 pid=2425) WARNING 07-11 13:14:01 [vllm.py:2269] torch.compile is turned on, but the model cyankiwi/Hy3-AWQ-NVFP4 does not support it. Please open an issue on GitHub if you want it to be supported.
Loading safetensors checkpoint shards: 21% Completed | 7/34 [00:57<02:15, 5.03s/it]
Loading safetensors checkpoint shards: 24% Completed | 8/34 [01:01<01:58, 4.57s/it]
(Worker_TP1 pid=2425) INFO 07-11 13:14:07 [llm_base_proposer.py:1466] Detected MTP model. Sharing target model embedding weights with the draft model.
(Worker_TP1 pid=2425) INFO 07-11 13:14:07 [llm_base_proposer.py:1542] Detected MTP model. Sharing target model lm_head weights with the draft model.
(Worker_TP1 pid=2425) INFO 07-11 13:14:07 [llm_base_proposer.py:1566] Shared target model lm_head with MTP shared_head.head.
Loading safetensors checkpoint shards: 26% Completed | 9/34 [01:05<01:48, 4.35s/it]
Loading safetensors checkpoint shards: 29% Completed | 10/34 [01:36<05:05, 12.72s/it]
Loading safetensors checkpoint shards: 32% Completed | 11/34 [01:47<04:39, 12.15s/it]
Loading safetensors checkpoint shards: 35% Completed | 12/34 [01:50<03:29, 9.54s/it]
Loading safetensors checkpoint shards: 38% Completed | 13/34 [01:54<02:42, 7.75s/it]
Loading safetensors checkpoint shards: 41% Completed | 14/34 [01:58<02:10, 6.51s/it]
Loading safetensors checkpoint shards: 44% Completed | 15/34 [02:01<01:47, 5.63s/it]
Loading safetensors checkpoint shards: 47% Completed | 16/34 [02:05<01:30, 5.01s/it]
Loading safetensors checkpoint shards: 50% Completed | 17/34 [02:09<01:18, 4.60s/it]
Loading safetensors checkpoint shards: 53% Completed | 18/34 [02:12<01:09, 4.31s/it]
Loading safetensors checkpoint shards: 56% Completed | 19/34 [02:39<02:45, 11.06s/it]
Loading safetensors checkpoint shards: 59% Completed | 20/34 [02:54<02:52, 12.34s/it]
Loading safetensors checkpoint shards: 62% Completed | 21/34 [02:58<02:06, 9.72s/it]
Loading safetensors checkpoint shards: 65% Completed | 22/34 [03:02<01:34, 7.90s/it]
Loading safetensors checkpoint shards: 68% Completed | 23/34 [03:05<01:12, 6.60s/it]
Loading safetensors checkpoint shards: 71% Completed | 24/34 [03:09<00:57, 5.71s/it]
Loading safetensors checkpoint shards: 74% Completed | 25/34 [03:12<00:45, 5.09s/it]
Loading safetensors checkpoint shards: 76% Completed | 26/34 [03:16<00:37, 4.65s/it]
Loading safetensors checkpoint shards: 79% Completed | 27/34 [03:20<00:30, 4.32s/it]
Loading safetensors checkpoint shards: 82% Completed | 28/34 [03:32<00:39, 6.64s/it]
Loading safetensors checkpoint shards: 85% Completed | 29/34 [03:41<00:37, 7.45s/it]
Loading safetensors checkpoint shards: 88% Completed | 30/34 [03:45<00:25, 6.27s/it]
Loading safetensors checkpoint shards: 91% Completed | 31/34 [03:48<00:16, 5.46s/it]
Loading safetensors checkpoint shards: 94% Completed | 32/34 [03:50<00:09, 4.54s/it]
Loading safetensors checkpoint shards: 100% Completed | 34/34 [03:50<00:00, 6.79s/it]
(Worker_TP0 pid=2420)
(Worker_TP0 pid=2420) INFO 07-11 13:16:55 [default_loader.py:430] Loading weights took 231.04 seconds
(Worker_TP0 pid=2420) INFO 07-11 13:16:55 [nvfp4.py:482] Using MoEPrepareAndFinalizeNoDPEPMonolithic
(Worker_TP0 pid=2420) INFO 07-11 13:16:59 [gpu_model_runner.py:5195] Loading drafter model...
(Worker_TP0 pid=2420) INFO 07-11 13:16:59 [vllm.py:1042] Asynchronous scheduling is enabled.
(Worker_TP0 pid=2420) INFO 07-11 13:16:59 [kernel.py:291] Final IR op priority after setting platform defaults: IrOpPriorityConfig(rms_norm=['native'], fused_add_rms_norm=['native'])
(Worker_TP0 pid=2420) INFO 07-11 13:16:59 [compilation.py:312] Enabled custom fusions: act_quant, allreduce_rms
(Worker_TP0 pid=2420) INFO 07-11 13:16:59 [unquantized.py:260] Using FlashInfer TRTLLM Unquantized MoE backend out of potential backends: ['FlashInfer TRTLLM', 'FlashInfer CUTLASS', 'TRITON', 'BATCHED_TRITON'].
(Worker_TP0 pid=2420) WARNING 07-11 13:16:59 [vllm.py:2269] torch.compile is turned on, but the model cyankiwi/Hy3-AWQ-NVFP4 does not support it. Please open an issue on GitHub if you want it to be supported.
(Worker_TP0 pid=2420) INFO 07-11 13:17:00 [weight_utils.py:849] Filesystem type for checkpoints: BTRFS. Checkpoint size: 165.30 GiB. Available RAM: 1768.40 GiB.
Loading safetensors checkpoint shards: 0% Completed | 0/34 [00:00<?, ?it/s]
Loading safetensors checkpoint shards: 3% Completed | 1/34 [00:01<00:49, 1.51s/it]
Loading safetensors checkpoint shards: 6% Completed | 2/34 [00:01<00:24, 1.28it/s]
Loading safetensors checkpoint shards: 12% Completed | 4/34 [00:01<00:09, 3.06it/s]
Loading safetensors checkpoint shards: 18% Completed | 6/34 [00:01<00:05, 5.07it/s]
Loading safetensors checkpoint shards: 24% Completed | 8/34 [00:02<00:03, 7.19it/s]
Loading safetensors checkpoint shards: 29% Completed | 10/34 [00:03<00:06, 3.86it/s]
Loading safetensors checkpoint shards: 35% Completed | 12/34 [00:03<00:04, 4.56it/s]
Loading safetensors checkpoint shards: 41% Completed | 14/34 [00:03<00:03, 6.08it/s]
Loading safetensors checkpoint shards: 47% Completed | 16/34 [00:03<00:02, 7.75it/s]
Loading safetensors checkpoint shards: 53% Completed | 18/34 [00:03<00:01, 9.52it/s]
Loading safetensors checkpoint shards: 59% Completed | 20/34 [00:04<00:03, 4.11it/s]
Loading safetensors checkpoint shards: 65% Completed | 22/34 [00:04<00:02, 5.34it/s]
Loading safetensors checkpoint shards: 71% Completed | 24/34 [00:04<00:01, 6.84it/s]
Loading safetensors checkpoint shards: 76% Completed | 26/34 [00:05<00:00, 8.50it/s]
Loading safetensors checkpoint shards: 82% Completed | 28/34 [00:05<00:00, 7.31it/s]
Loading safetensors checkpoint shards: 88% Completed | 30/34 [00:05<00:00, 7.56it/s]
Loading safetensors checkpoint shards: 94% Completed | 32/34 [00:06<00:00, 4.58it/s]
Loading safetensors checkpoint shards: 97% Completed | 33/34 [00:08<00:00, 1.73it/s]
Loading safetensors checkpoint shards: 100% Completed | 34/34 [00:09<00:00, 1.95it/s]
Loading safetensors checkpoint shards: 100% Completed | 34/34 [00:09<00:00, 3.77it/s]
(Worker_TP0 pid=2420)
(Worker_TP0 pid=2420) INFO 07-11 13:17:09 [default_loader.py:430] Loading weights took 9.03 seconds
(Worker_TP0 pid=2420) INFO 07-11 13:17:09 [unquantized.py:332] Using MoEPrepareAndFinalizeNoDPEPMonolithic
(Worker_TP0 pid=2420) INFO 07-11 13:17:09 [llm_base_proposer.py:1466] Detected MTP model. Sharing target model embedding weights with the draft model.
(Worker_TP0 pid=2420) INFO 07-11 13:17:09 [llm_base_proposer.py:1542] Detected MTP model. Sharing target model lm_head weights with the draft model.
(Worker_TP0 pid=2420) INFO 07-11 13:17:09 [llm_base_proposer.py:1566] Shared target model lm_head with MTP shared_head.head.
(Worker_TP0 pid=2420) INFO 07-11 13:17:12 [gpu_model_runner.py:5268] Model loading took 82.99 GiB memory and 2403.132936 seconds
(Worker_TP0 pid=2420) INFO 07-11 13:17:12 [utils.py:90] _KV_CACHE_LAYOUT_OVERRIDE variable detected. Setting KV cache layout to HND.
(Worker_TP0 pid=2420) INFO 07-11 13:17:47 [backends.py:1089] Using cache directory: /root/.cache/vllm/torch_compile_cache/fe846add00/rank_0_0/backbone for vLLM's torch.compile
(Worker_TP0 pid=2420) INFO 07-11 13:17:47 [backends.py:1148] Dynamo bytecode transform time: 34.96 s
(Worker_TP0 pid=2420) INFO 07-11 13:17:47 [flashinfer_all_reduce.py:119] Auto-selected flashinfer allreduce backend: mnnvl
(Worker_TP0 pid=2420) /usr/local/lib/python3.12/dist-packages/torch/distributed/c10d_logger.py:83: UserWarning: barrier(): using the device under current context. You can specify device_id in init_process_group to mute this warning.
(Worker_TP0 pid=2420) return func(*args, **kwargs)
[rank0]:[W711 13:17:47.407601915 ProcessGroupNCCL.cpp:5188] Guessing device ID based on global rank. This can cause a hang if rank to GPU mapping is heterogeneous. You can specify device_id in init_process_group()
(Worker_TP0 pid=2420) INFO 07-11 13:17:48 [flashinfer_all_reduce.py:168] Initialized FlashInfer Allreduce norm fusion workspace with backend=mnnvl
(Worker_TP0 pid=2420) INFO 07-11 13:17:48 [flashinfer_all_reduce.py:216] Initialized FlashInfer Allreduce norm quantization fusion workspace with backend=trtllm
(EngineCore pid=2220) INFO 07-11 13:18:13 [shm_broadcast.py:705] 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).
(Worker_TP0 pid=2420) INFO 07-11 13:18:18 [backends.py:378] Cache the graph of compile range (1, 8192) for later use
(Worker_TP0 pid=2420) INFO 07-11 13:18:23 [backends.py:378] Cache the graph of compile range (8193, 42000) for later use
(Worker_TP0 pid=2420) /usr/local/lib/python3.12/dist-packages/torch/_inductor/compile_fx.py:322: UserWarning: TensorFloat32 tensor cores for float32 matrix multiplication available but not enabled. Consider setting torch.set_float32_matmul_precision('high') for better performance.
(Worker_TP0 pid=2420) warnings.warn(
(Worker_TP1 pid=2425) /usr/local/lib/python3.12/dist-packages/torch/_inductor/compile_fx.py:322: UserWarning: TensorFloat32 tensor cores for float32 matrix multiplication available but not enabled. Consider setting torch.set_float32_matmul_precision('high') for better performance.
(Worker_TP1 pid=2425) warnings.warn(
(Worker_TP0 pid=2420) INFO 07-11 13:19:04 [backends.py:393] Compiling a graph for compile range (1, 8192) takes 45.78 s
(Worker_TP0 pid=2420) INFO 07-11 13:19:07 [backends.py:393] Compiling a graph for compile range (8193, 42000) takes 48.45 s
(EngineCore pid=2220) INFO 07-11 13:19:13 [shm_broadcast.py:705] 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).
(Worker_TP0 pid=2420) INFO 07-11 13:19:30 [decorators.py:708] saved AOT compiled function to /root/.cache/vllm/torch_compile_cache/torch_aot_compile/452004cd9e22f540f74bcc5eabf0e797305e2c2169ccf897416cb88e16665f95/rank_0_0/model
(Worker_TP0 pid=2420) INFO 07-11 13:19:30 [monitor.py:53] torch.compile took 137.86 s in total
(Worker_TP0 pid=2420) INFO 07-11 13:19:50 [monitor.py:81] Initial profiling/warmup run took 19.47 s
(Worker_TP1 pid=2425) 2026-07-11 13:19:52,414 - WARNING - core.py:2942 - flashinfer.jit: the single torch.Tensor return type is deprecated and will be replaced with List[torch.Tensor] in the v0.8.0.
(Worker_TP0 pid=2420) 2026-07-11 13:19:52,415 - WARNING - core.py:2942 - flashinfer.jit: the single torch.Tensor return type is deprecated and will be replaced with List[torch.Tensor] in the v0.8.0.
(Worker_TP0 pid=2420) INFO 07-11 13:20:01 [flashinfer.py:780] FlashInfer resolved query dtypes: prefill=torch.float8_e4m3fn, decode=torch.float8_e4m3fn, decode_backend=trtllm-gen, kv_cache_dtype=torch.float8_e4m3fn, arch=sm100
(Worker_TP0 pid=2420) INFO 07-11 13:20:01 [gpu_model_runner.py:6496] Profiling CUDA graph memory: PIECEWISE=14 (largest=96), FULL=8 (largest=48)
(Worker_TP1 pid=2425) INFO 07-11 13:20:03 [gpu_model_runner.py:6496] Profiling CUDA graph memory: PIECEWISE=14 (largest=96), FULL=8 (largest=48)
(Worker_TP0 pid=2420) INFO 07-11 13:20:11 [flashinfer.py:477] Using TRTLLM attention (query is quantized).
(Worker_TP1 pid=2425) INFO 07-11 13:20:12 [custom_all_reduce.py:213] Registering 4 cuda graph addresses
(Worker_TP0 pid=2420) INFO 07-11 13:20:13 [custom_all_reduce.py:213] Registering 4 cuda graph addresses
(EngineCore pid=2220) INFO 07-11 13:20:13 [shm_broadcast.py:705] 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).
(Worker_TP1 pid=2425) INFO 07-11 13:20:14 [gpu_model_runner.py:6601] Estimated CUDA graph memory: 0.84 GiB total
(Worker_TP1 pid=2425) INFO 07-11 13:20:14 [gpu_worker.py:553] CUDA graph memory profiling is enabled (default since v0.21.0). The current --gpu-memory-utilization=0.9000 is equivalent to --gpu-memory-utilization=0.8953 without CUDA graph memory profiling. To maintain the same effective KV cache size as before, increase --gpu-memory-utilization to 0.9047. To disable, set VLLM_MEMORY_PROFILER_ESTIMATE_CUDAGRAPHS=0.
(Worker_TP0 pid=2420) INFO 07-11 13:20:14 [gpu_model_runner.py:6601] Estimated CUDA graph memory: 0.83 GiB total
(Worker_TP0 pid=2420) INFO 07-11 13:20:14 [gpu_worker.py:538] Available KV cache memory: 68.44 GiB
(Worker_TP0 pid=2420) INFO 07-11 13:20:14 [gpu_worker.py:553] CUDA graph memory profiling is enabled (default since v0.21.0). The current --gpu-memory-utilization=0.9000 is equivalent to --gpu-memory-utilization=0.8953 without CUDA graph memory profiling. To maintain the same effective KV cache size as before, increase --gpu-memory-utilization to 0.9047. To disable, set VLLM_MEMORY_PROFILER_ESTIMATE_CUDAGRAPHS=0.
(EngineCore pid=2220) INFO 07-11 13:20:14 [kv_cache_utils.py:2146] GPU KV cache size: 885,712 tokens
(EngineCore pid=2220) INFO 07-11 13:20:14 [kv_cache_utils.py:2147] Maximum concurrency for 262,144 tokens per request: 3.38x
(Worker_TP0 pid=2420) INFO 07-11 13:20:14 [gpu_worker.py:752] Compile and warming up model for size 42000
(Worker_TP1 pid=2425) INFO 07-11 13:20:14 [gpu_worker.py:752] Compile and warming up model for size 42000
(Worker_TP0 pid=2420) 2026-07-11 13:20:16,774 - INFO - autotuner.py:651 - flashinfer.jit: [Autotuner]: Autotuning process starts ...
(Worker_TP0 pid=2420) INFO 07-11 13:20:16 [kernel_warmup.py:177] Using FlashInfer autotune cache file: /root/.cache/vllm/flashinfer_autotune_cache/0.6.13/100a/08036a23555ca8fcfad2a6b87268955a0170e7b486f32baa51dc1f059f05ed24/autotune_configs.json
(EngineCore pid=2220) INFO 07-11 13:21:15 [shm_broadcast.py:705] 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 pid=2220) INFO 07-11 13:22:16 [shm_broadcast.py:705] 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 pid=2220) INFO 07-11 13:23:16 [shm_broadcast.py:705] 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 pid=2220) INFO 07-11 13:24:16 [shm_broadcast.py:705] 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 pid=2220) INFO 07-11 13:25:16 [shm_broadcast.py:705] 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 pid=2220) INFO 07-11 13:26:16 [shm_broadcast.py:705] 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 pid=2220) INFO 07-11 13:27:16 [shm_broadcast.py:705] 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 pid=2220) INFO 07-11 13:28:16 [shm_broadcast.py:705] 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).
[AutoTuner]: Tuning fp4_gemm: 100%|██████████| 24/24 [08:09<00:00, 20.42s/profile]
(EngineCore pid=2220) INFO 07-11 13:29:16 [shm_broadcast.py:705] 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).
[AutoTuner]: Tuning fp4_gemm: 100%|██████████| 24/24 [01:01<00:00, 2.56s/profile]
(EngineCore pid=2220) INFO 07-11 13:30:16 [shm_broadcast.py:705] 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 pid=2220) INFO 07-11 13:31:16 [shm_broadcast.py:705] 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 pid=2220) INFO 07-11 13:32:16 [shm_broadcast.py:705] 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).
[AutoTuner]: Tuning flashinfer::trtllm_fp4_block_scale_moe: 100%|██████████| 21/21 [03:18<00:00, 9.43s/profile]
(EngineCore pid=2220) INFO 07-11 13:33:16 [shm_broadcast.py:705] 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 pid=2220) INFO 07-11 13:34:16 [shm_broadcast.py:705] 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).
[AutoTuner]: Tuning flashinfer::trtllm_bf16_moe: 100%|██████████| 21/21 [01:25<00:00, 4.09s/profile]
(Worker_TP0 pid=2420) 2026-07-11 13:34:17,885 - INFO - autotuner.py:674 - flashinfer.jit: [Autotuner]: Autotuning process ends
(Worker_TP0 pid=2420) 2026-07-11 13:34:17,914 - INFO - autotuner.py:1808 - flashinfer.jit: [Autotuner]: Saved 90 configs to /root/.cache/vllm/flashinfer_autotune_cache/0.6.13/100a/08036a23555ca8fcfad2a6b87268955a0170e7b486f32baa51dc1f059f05ed24/autotune_configs.json (90 new, 0 from previous config)
(Worker_TP0 pid=2420) 2026-07-11 13:34:17,958 - INFO - autotuner.py:1899 - flashinfer.jit: [Autotuner]: Loaded 90 configs from /root/.cache/vllm/flashinfer_autotune_cache/0.6.13/100a/08036a23555ca8fcfad2a6b87268955a0170e7b486f32baa51dc1f059f05ed24/autotune_configs.json
(Worker_TP0 pid=2420) INFO 07-11 13:34:17 [kernel_warmup.py:216] FlashInfer autotune cache loaded on rank 0 from /root/.cache/vllm/flashinfer_autotune_cache/0.6.13/100a/08036a23555ca8fcfad2a6b87268955a0170e7b486f32baa51dc1f059f05ed24/autotune_configs.json.
(Worker_TP0 pid=2420) INFO 07-11 13:34:17 [kernel_warmup.py:118] Warming up FlashInfer attention.
(Worker_TP1 pid=2425) 2026-07-11 13:34:17,969 - INFO - autotuner.py:1899 - flashinfer.jit: [Autotuner]: Loaded 90 configs from /root/.cache/vllm/flashinfer_autotune_cache/0.6.13/100a/08036a23555ca8fcfad2a6b87268955a0170e7b486f32baa51dc1f059f05ed24/autotune_configs.json
(Worker_TP1 pid=2425) INFO 07-11 13:34:17 [kernel_warmup.py:216] FlashInfer autotune cache loaded on rank 1 from /root/.cache/vllm/flashinfer_autotune_cache/0.6.13/100a/08036a23555ca8fcfad2a6b87268955a0170e7b486f32baa51dc1f059f05ed24/autotune_configs.json.
(Worker_TP1 pid=2425) INFO 07-11 13:34:17 [kernel_warmup.py:118] Warming up FlashInfer attention.
(Worker_TP1 pid=2425) 2026-07-11 13:34:18,111 - INFO - autotuner.py:1009 - flashinfer.jit: [Autotuner]: Config cache hit for fp4_gemm (runner=CuteDSLFp4GemmRunner, source=config file)
(Worker_TP1 pid=2425) 2026-07-11 13:34:25,501 - INFO - autotuner.py:1009 - flashinfer.jit: [Autotuner]: Config cache hit for flashinfer::trtllm_fp4_block_scale_moe (runner=MoERunner, source=config file)
(Worker_TP1 pid=2425) 2026-07-11 13:34:25,735 - INFO - autotuner.py:1009 - flashinfer.jit: [Autotuner]: Config cache hit for flashinfer::trtllm_bf16_moe (runner=MoERunner, source=config file)
(Worker_TP1 pid=2425) INFO 07-11 13:34:25 [cutedsl_warmup.py:97] Skipping CuTeDSL warmup because no compile units were requested.
(Worker_TP0 pid=2420) INFO 07-11 13:34:25 [cutedsl_warmup.py:97] Skipping CuTeDSL warmup because no compile units were requested.
Capturing CUDA graphs (mixed prefill-decode, PIECEWISE): 100%|██████████| 14/14 [00:37<00:00, 2.68s/it]
(Worker_TP1 pid=2425) INFO 07-11 13:35:08 [custom_all_reduce.py:213] Registering 22 cuda graph addresses
Capturing CUDA graphs (decode, FULL): 100%|██████████| 8/8 [00:04<00:00, 1.90it/s]
(Worker_TP0 pid=2420) INFO 07-11 13:35:08 [custom_all_reduce.py:213] Registering 22 cuda graph addresses
(Worker_TP0 pid=2420) INFO 07-11 13:35:08 [gpu_model_runner.py:6669] Graph capturing finished in 43 secs, took 0.51 GiB
(Worker_TP0 pid=2420) INFO 07-11 13:35:08 [gpu_worker.py:771] CUDA graph pool memory: 0.51 GiB (actual), 0.83 GiB (estimated), difference: 0.32 GiB (62.8%).
(Worker_TP1 pid=2425) INFO 07-11 13:35:08 [gpu_worker.py:771] CUDA graph pool memory: 0.51 GiB (actual), 0.84 GiB (estimated), difference: 0.34 GiB (66.2%).
(Worker_TP1 pid=2425) INFO 07-11 13:35:08 [jit_monitor.py:72] Kernel JIT monitor activated; monitored JIT compilations during inference will use mode=warn.
(Worker_TP0 pid=2420) INFO 07-11 13:35:08 [jit_monitor.py:72] Kernel JIT monitor activated; monitored JIT compilations during inference will use mode=warn.
(EngineCore pid=2220) INFO 07-11 13:35:09 [core.py:337] init engine (profile, create kv cache, warmup model) took 1076.81 s (compilation: 143.22 s)
(EngineCore pid=2220) INFO 07-11 13:35:12 [vllm.py:1042] Asynchronous scheduling is enabled.
(EngineCore pid=2220) INFO 07-11 13:35:12 [kernel.py:291] Final IR op priority after setting platform defaults: IrOpPriorityConfig(rms_norm=['native'], fused_add_rms_norm=['native'])
(EngineCore pid=2220) INFO 07-11 13:35:12 [compilation.py:312] Enabled custom fusions: act_quant, allreduce_rms
(APIServer pid=1) INFO 07-11 13:35:12 [api_server.py:611] Supported tasks: ['generate']
(APIServer pid=1) INFO 07-11 13:35:14 [parser_manager.py:37] "auto" tool choice has been enabled.
(APIServer pid=1) WARNING 07-11 13:35:14 [model.py:1488] Default vLLM sampling parameters have been overridden by the model's generation_config.json: {'temperature': 0.9, 'top_k': -1, 'top_p': 1}. If this is not intended, please relaunch vLLM instance with --generation-config vllm.
(APIServer pid=1) INFO 07-11 13:35:17 [hf.py:548] Detected the chat template content format to be 'openai'. You can set --chat-template-content-format to override this.
(APIServer pid=1) INFO 07-11 13:35:17 [api_server.py:615] Starting vLLM server on http://0.0.0.0:8000
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:37] Available routes are:
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /openapi.json, Methods: HEAD, GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /docs, Methods: HEAD, GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /docs/oauth2-redirect, Methods: HEAD, GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /redoc, Methods: HEAD, GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /load, Methods: GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /version, Methods: GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /health, Methods: GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /metrics, Methods: GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /tokenize, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /detokenize, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/models, Methods: GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /ping, Methods: GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /ping, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /invocations, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/chat/completions, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/chat/completions/batch, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/responses, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/responses/{response_id}, Methods: GET
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/responses/{response_id}/cancel, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/completions, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/messages, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/messages/count_tokens, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /generative_scoring, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /scale_elastic_ep, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /is_scaling_elastic_ep, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/chat/completions/render, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/completions/render, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/chat/completions/derender, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /v1/completions/derender, Methods: POST
(APIServer pid=1) INFO 07-11 13:35:17 [launcher.py:46] Route: /inference/v1/generate, Methods: POST
(APIServer pid=1) INFO: Started server process [1]
(APIServer pid=1) INFO: Waiting for application startup.
(APIServer pid=1) INFO: Application startup complete.
(APIServer pid=1) INFO: 10.0.97.249:40314 - "GET /metrics HTTP/1.1" 200 OK

Sign up or log in to comment