Description:
I am making use of the latest commit of ThunderAgent (7ddc861). I encountered an issue where the upstream http client times out waiting for a chunk while streaming a response back, from the vllm backend. We continue to notice this issue despite increasing the TOOL_ORCH_STREAM_READ_TIMEOUT_S environment variable. This issue was observed with both the baseline (vllm) as well as thunderagent. The KV cache usage remains low when the timeout actually occurs (<80%)
The request succeeds in a next retry, however we wish to understand why this issue occurs as this causes a drop in the throughput.
Experiment: ToolOrchestra(HLE)-Qwen3-8B. We have used gpt-5-nano answering tool calls, gpt-5 for reasoning and gpt-5-mini for search. Hardware used: 2x A100 80GB HBM
To replicate, find the attached launch scripts, below launch command and the error log (with the error alone from eval.log).
Launch command:
METHOD=baseline CONCURRENCY=24 \
EVAL_TIMEOUT_MIN=30 WINDOW_START_SEC=300 WINDOW_END_SEC=1500 bash run_single_setting.sh
Launch Scripts
#!/usr/bin/env bash
set -euo pipefail
# Run a single HLE setting with metrics collection.
# Defaults: thunderagent + concurrency=48 + 2h30 window (10–130min).
SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)"
REPO_DIR="${SCRIPT_DIR}"
if [[ ! -f "${REPO_DIR}/setup_envs.sh" ]]; then
echo "ERROR: setup_envs.sh not found. Copy setup_envs.sh_example and fill in paths/keys." >&2
exit 1
fi
set +u
source "${REPO_DIR}/setup_envs.sh"
set -u
METHOD="${METHOD:-thunderagent}"
CONCURRENCY="${CONCURRENCY:-48}"
EVAL_TIMEOUT_MIN="${EVAL_TIMEOUT_MIN:-150}"
WINDOW_START_SEC="${WINDOW_START_SEC:-600}"
WINDOW_END_SEC="${WINDOW_END_SEC:-7800}"
EXAMPLE_PATH="${EXAMPLE_PATH:-}"
EXAMPLE_ARG=()
if [[ -n "${EXAMPLE_PATH}" ]]; then
EXAMPLE_ARG=(--example-path "${EXAMPLE_PATH}")
fi
if [[ -z "${THUNDERAGENT_ROOT:-}" ]]; then
echo "ERROR: THUNDERAGENT_ROOT is not set (set it in setup_envs.sh)." >&2
exit 1
fi
bash "${REPO_DIR}/evaluation/launch_hle_inference.sh" \
--method "${METHOD}" \
--concurrency "${CONCURRENCY}" \
--eval-timeout-min "${EVAL_TIMEOUT_MIN}" \
--window-start-sec "${WINDOW_START_SEC}" \
--window-end-sec "${WINDOW_END_SEC}" \
--thunderagent-root "${THUNDERAGENT_ROOT}" \
"${EXAMPLE_ARG[@]}"
#!/usr/bin/env bash
set -euo pipefail
usage() {
cat <<'USAGE'
Usage:
bash evaluation/launch_hle_inference.sh --method <baseline|continuum|thunderagent> --concurrency <C> \
[--ckpt <CKPT_DIR>] [--index-dir <INDEX_DIR>] [options]
Required:
--method baseline | continuum | thunderagent
--concurrency HLE concurrency (eval batch size)
--ckpt Orchestrator-8B checkpoint path (or set CKPT_DIR env)
--index-dir Directory containing eval.index + eval.jsonl (or set INDEX_DIR env)
Common options:
--example-path Path to hle.jsonl (default: evaluation/hle.jsonl)
--output-dir Output directory (default: evaluation/outputs/hle_local_YYYYMMDD_HHMMSS)
--log-dir Log directory (default: evaluation/logs/hle_local_YYYYMMDD_HHMMSS)
--model-config Model config JSON path (default: evaluation/model_configs/hle_local_router.json)
--model-name Served model name (default: --ckpt)
--model-type Orchestrator model type (default: Qwen/Qwen3-8B)
--orchestrator-gpu GPU for vLLM (default: 0)
--retrieval-gpu GPU for retriever (default: 1)
--backend-port vLLM backend port (default: 8100)
--router-port ThunderAgent router port (default: 8000)
--retrieval-port Retriever port (default: 1401)
--vllm-env Conda env for baseline/thunderagent (default: vllm1)
--cont-env Conda env for continuum (default: vllm-continuum)
--router-env Conda env for ThunderAgent router (default: vllm1)
--retriever-env Conda env for retriever (default: retriever-clean)
--conda-sh Path to conda.sh (default: /root/miniconda3/etc/profile.d/conda.sh)
--max-rounds Max rounds per task (default: 50)
--log-level HLE log level (default: DEBUG)
--vllm-log-level vLLM log level via env (default: INFO; DEBUG makes the
hermes tool parser log per streamed token and starves the
API server event loop -> client read timeouts)
--router-profile Enable ThunderAgent profiling
--eval-timeout-min Timeout minutes for eval (default: 0 = no timeout)
--window-start-sec Active window start offset in seconds (default: 600)
--window-end-sec Active window end offset in seconds (default: 7800)
--sample-interval-sec Metrics sampling interval seconds (default: 2)
--thunderagent-root Path to ThunderAgent repo (default: /workspace/ThunderAgent or $THUNDERAGENT_ROOT)
USAGE
}
METHOD=""
CONCURRENCY=""
CKPT_DIR="${CKPT_DIR:-}"
INDEX_DIR="${INDEX_DIR:-}"
EXAMPLE_PATH=""
OUTPUT_DIR=""
LOG_DIR=""
MODEL_CONFIG=""
MODEL_NAME=""
MODEL_TYPE="Qwen/Qwen3-8B"
ORCH_GPU=0
RET_GPU=1
BACKEND_PORT=8100
ROUTER_PORT=8000
RETRIEVAL_PORT=1401
VLLM_ENV="vllm1"
CONT_ENV="vllm-continuum"
ROUTER_ENV="vllm1"
RETRIEVER_ENV="retriever-clean"
CONDA_SH="/root/miniconda3/etc/profile.d/conda.sh"
MAX_ROUNDS=50
LOG_LEVEL="DEBUG"
# Must stay at INFO: at DEBUG, vllm's hermes tool parser emits ~8 log records per
# streamed token (several dumping the whole accumulated arguments dict), which
# blocks the API server asyncio loop and stalls in-flight SSE streams.
VLLM_LOG_LEVEL="INFO"
ROUTER_PROFILE=0
THUNDERAGENT_ROOT="${THUNDERAGENT_ROOT:-/workspace/ThunderAgent}"
EVAL_TIMEOUT_MIN=0
WINDOW_START_SEC=600
WINDOW_END_SEC=7800
SAMPLE_INTERVAL_SEC=1
while [[ $# -gt 0 ]]; do
case "$1" in
--method) METHOD="$2"; shift 2 ;;
--concurrency) CONCURRENCY="$2"; shift 2 ;;
--ckpt) CKPT_DIR="$2"; shift 2 ;;
--index-dir) INDEX_DIR="$2"; shift 2 ;;
--example-path) EXAMPLE_PATH="$2"; shift 2 ;;
--output-dir) OUTPUT_DIR="$2"; shift 2 ;;
--log-dir) LOG_DIR="$2"; shift 2 ;;
--model-config) MODEL_CONFIG="$2"; shift 2 ;;
--model-name) MODEL_NAME="$2"; shift 2 ;;
--model-type) MODEL_TYPE="$2"; shift 2 ;;
--orchestrator-gpu) ORCH_GPU="$2"; shift 2 ;;
--retrieval-gpu) RET_GPU="$2"; shift 2 ;;
--backend-port) BACKEND_PORT="$2"; shift 2 ;;
--router-port) ROUTER_PORT="$2"; shift 2 ;;
--retrieval-port) RETRIEVAL_PORT="$2"; shift 2 ;;
--vllm-env) VLLM_ENV="$2"; shift 2 ;;
--cont-env) CONT_ENV="$2"; shift 2 ;;
--router-env) ROUTER_ENV="$2"; shift 2 ;;
--retriever-env) RETRIEVER_ENV="$2"; shift 2 ;;
--conda-sh) CONDA_SH="$2"; shift 2 ;;
--max-rounds) MAX_ROUNDS="$2"; shift 2 ;;
--log-level) LOG_LEVEL="$2"; shift 2 ;;
--vllm-log-level) VLLM_LOG_LEVEL="$2"; shift 2 ;;
--router-profile) ROUTER_PROFILE=1; shift 1 ;;
--eval-timeout-min) EVAL_TIMEOUT_MIN="$2"; shift 2 ;;
--window-start-sec) WINDOW_START_SEC="$2"; shift 2 ;;
--window-end-sec) WINDOW_END_SEC="$2"; shift 2 ;;
--sample-interval-sec) SAMPLE_INTERVAL_SEC="$2"; shift 2 ;;
--thunderagent-root) THUNDERAGENT_ROOT="$2"; shift 2 ;;
-h|--help) usage; exit 0 ;;
*) echo "Unknown arg: $1"; usage; exit 1 ;;
esac
done
if [[ -z "$METHOD" || -z "$CONCURRENCY" || -z "$CKPT_DIR" || -z "$INDEX_DIR" ]]; then
usage
echo ""
echo "ERROR: --method and --concurrency are required."
echo " --ckpt/--index-dir can be provided via args or env (CKPT_DIR, INDEX_DIR)."
exit 1
fi
if [[ ! -f "$CONDA_SH" ]]; then
echo "ERROR: conda.sh not found at $CONDA_SH (set --conda-sh)"
exit 1
fi
if [[ ! -d "$THUNDERAGENT_ROOT" ]]; then
echo "ERROR: ThunderAgent repo not found at $THUNDERAGENT_ROOT (set --thunderagent-root or THUNDERAGENT_ROOT)"
exit 1
fi
REPO_ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)"
EVAL_DIR="${REPO_ROOT}/evaluation"
if [[ -z "$EXAMPLE_PATH" ]]; then
EXAMPLE_PATH="${EVAL_DIR}/hle.jsonl"
fi
if [[ -z "$OUTPUT_DIR" ]]; then
OUTPUT_DIR="${EVAL_DIR}/outputs/hle_local_$(date +%Y%m%d_%H%M%S)"
fi
if [[ -z "$LOG_DIR" ]]; then
LOG_DIR="${EVAL_DIR}/logs/hle_local_$(date +%Y%m%d_%H%M%S)"
fi
if [[ -z "$MODEL_CONFIG" ]]; then
MODEL_CONFIG="${EVAL_DIR}/model_configs/hle_local_router.json"
fi
if [[ -z "$MODEL_NAME" ]]; then
MODEL_NAME="${CKPT_DIR}"
fi
case "$METHOD" in
baseline)
ROUTER_MODE="default"
VLLM_ENV_SELECTED="$VLLM_ENV"
VLLM_ARGS=()
;;
continuum)
ROUTER_MODE="default"
VLLM_ENV_SELECTED="$CONT_ENV"
VLLM_ARGS=(--scheduling-policy continuum)
;;
thunderagent)
ROUTER_MODE="tr"
VLLM_ENV_SELECTED="$VLLM_ENV"
VLLM_ARGS=()
;;
*)
echo "ERROR: invalid --method '$METHOD'"
usage
exit 1
;;
esac
mkdir -p "$(dirname "$MODEL_CONFIG")" "$OUTPUT_DIR" "$LOG_DIR"
MODEL_NAME_ENV="${MODEL_NAME}" \
MODEL_CONFIG_ENV="${MODEL_CONFIG}" \
RETRIEVAL_PORT_ENV="${RETRIEVAL_PORT}" \
ROUTER_PORT_ENV="${ROUTER_PORT}" \
python - <<'PY'
import json
import os
model_name = os.environ["MODEL_NAME_ENV"]
model_config_path = os.environ["MODEL_CONFIG_ENV"]
retrieval_port = os.environ["RETRIEVAL_PORT_ENV"]
router_port = os.environ["ROUTER_PORT_ENV"]
cfg = {
"retrieval": [{"ip_addr": "127.0.0.1", "port": str(retrieval_port)}],
"Qwen/Qwen2.5-Math-72B-Instruct": [],
"Qwen/Qwen3-32B": [],
"Qwen/Qwen2.5-Math-7B-Instruct": [],
"meta-llama/Llama-3.3-70B-Instruct": [],
model_name: [{"ip_addr": "127.0.0.1", "port": str(router_port)}],
"Qwen/Qwen2.5-Coder-32B-Instruct": [],
"vllm_model_config_path": model_config_path,
}
with open(model_config_path, "w", encoding="utf-8") as f:
json.dump(cfg, f, indent=2)
print(f"Wrote model_config: {model_config_path}")
PY
kill_tree() {
# kill a PID and all its descendants (background subshells don't get their
# own process group here, so plain `kill $PID` misses grandchildren like the
# actual `vllm serve` / retriever / router processes).
local pid="$1"
[[ -z "$pid" ]] && return 0
local child
for child in $(pgrep -P "$pid" 2>/dev/null || true); do
kill_tree "$child"
done
kill "$pid" >/dev/null 2>&1 || true
}
cleanup() {
echo "Stopping background processes..."
[[ -n "${RETRIEVER_PID:-}" ]] && kill_tree "${RETRIEVER_PID}"
[[ -n "${VLLM_PID:-}" ]] && kill_tree "${VLLM_PID}"
[[ -n "${ROUTER_PID:-}" ]] && kill_tree "${ROUTER_PID}"
[[ -n "${SAMPLER_PID:-}" ]] && kill_tree "${SAMPLER_PID}"
[[ -n "${GPU_SAMPLER_PID:-}" ]] && kill_tree "${GPU_SAMPLER_PID}"
}
trap cleanup EXIT
echo "Starting retriever on GPU ${RET_GPU} (env=${RETRIEVER_ENV})..."
(
source "$CONDA_SH"
conda activate "$RETRIEVER_ENV"
export INDEX_DIR="${INDEX_DIR}"
CUDA_VISIBLE_DEVICES="${RET_GPU}" \
python "${EVAL_DIR}/retrieval_hle.py" \
--port "${RETRIEVAL_PORT}" \
--new_cache_dir "${EVAL_DIR}/cache/hle" \
--example_id_file "${EVAL_DIR}/examples.json"
) >"${LOG_DIR}/retrieval.log" 2>&1 &
RETRIEVER_PID=$!
echo "Starting vLLM backend on GPU ${ORCH_GPU} (env=${VLLM_ENV_SELECTED})..."
(
source "$CONDA_SH"
conda activate "$VLLM_ENV_SELECTED"
CUDA_VISIBLE_DEVICES="${ORCH_GPU}" \
VLLM_LOGGING_LEVEL="${VLLM_LOG_LEVEL}" \
vllm serve "${CKPT_DIR}" \
--port "${BACKEND_PORT}" \
--served-model-name "${MODEL_NAME}" \
--enable-prefix-caching \
--enable-prompt-tokens-details \
--enable-force-include-usage \
--enable-auto-tool-choice \
--tool-call-parser hermes \
"${VLLM_ARGS[@]}"
) >"${LOG_DIR}/vllm_backend.log" 2>&1 &
VLLM_PID=$!
echo "Waiting for vLLM backend health (up to 30 min)..."
VLLM_READY=0
for _ in $(seq 1 1800); do
if curl -sf [http://127.0.0.1:${BACKEND_PORT}/health](http://127.0.0.1:$%7bBACKEND_PORT%7d/health) >/dev/null 2>&1; then
VLLM_READY=1
break
fi
sleep 1
done
if [[ "$VLLM_READY" -ne 1 ]]; then
echo "ERROR: vLLM backend did not become ready within 30 minutes."
exit 1
fi
echo "Starting ThunderAgent router (mode=${ROUTER_MODE}, env=${ROUTER_ENV})..."
(
source "$CONDA_SH"
conda activate "$ROUTER_ENV"
export PYTHONPATH="${THUNDERAGENT_ROOT}:${PYTHONPATH:-}"
python -m ThunderAgent \
--host 0.0.0.0 \
--port "${ROUTER_PORT}" \
--backends [http://127.0.0.1:${BACKEND_PORT}](http://127.0.0.1:$%7bBACKEND_PORT%7d) \
--router "${ROUTER_MODE}" \
--metrics \
$( [[ "${ROUTER_PROFILE}" -eq 1 ]] && echo "--profile" )
) >"${LOG_DIR}/router.log" 2>&1 &
ROUTER_PID=$!
echo "Waiting for router health..."
for _ in $(seq 1 60); do
if curl -sf [http://127.0.0.1:${ROUTER_PORT}/health](http://127.0.0.1:$%7bROUTER_PORT%7d/health) >/dev/null 2>&1; then
echo "Router is healthy."
break
fi
sleep 2
done
sleep 1
export ROUTER_URL=[http://127.0.0.1:${ROUTER_PORT}](http://127.0.0.1:$%7bROUTER_PORT%7d)
export HLE_LOG_LEVEL="${LOG_LEVEL}"
export HLE_LOG_STREAM="1"
export TOOL_ORCH_USAGE_LOG_PATH="${OUTPUT_DIR}/orchestrator_usage.jsonl"
export TOOL_ORCH_LLM_LOG_PATH="${OUTPUT_DIR}/orchestrator_llm.jsonl"
# Widened to survive inter-chunk gaps / retry cycles under ~20+ concurrent streams (see LLM_CALL.py).
export TOOL_ORCH_STREAM_READ_TIMEOUT_S="600"
export TOOL_ORCH_CALL_TIMEOUT_S="600"
METRICS_CSV="${OUTPUT_DIR}/prefix_cache_timeseries.csv"
GPU_UTIL_CSV="${OUTPUT_DIR}/gpu_sm_util_timeseries.csv"
WINDOW_SUMMARY_JSON="${OUTPUT_DIR}/window_summary.json"
STEPS_SUMMARY_JSON="${OUTPUT_DIR}/steps_summary.json"
TOOL_TIME_SUMMARY_JSON="${OUTPUT_DIR}/tool_time_summary.json"
COMBINED_SUMMARY_JSON="${OUTPUT_DIR}/combined_summary.json"
EVAL_LOG="${LOG_DIR}/eval.log"
echo "Starting /metrics sampler (interval=${SAMPLE_INTERVAL_SEC}s) on port ${BACKEND_PORT}..."
SAMPLER_PID=""
if [[ -f "${REPO_ROOT}/scripts/hle_preexp/kv_prefix_cache_hit_sampler.sh" ]]; then
bash "${REPO_ROOT}/scripts/hle_preexp/kv_prefix_cache_hit_sampler.sh" \
[http://127.0.0.1:${BACKEND_PORT}/metrics](http://127.0.0.1:$%7bBACKEND_PORT%7d/metrics) \
"${METRICS_CSV}" \
"${SAMPLE_INTERVAL_SEC}" \
> "${LOG_DIR}/metrics_sampler.log" 2>&1 &
SAMPLER_PID=$!
else
echo "WARNING: skipping /metrics sampler; not found: ${REPO_ROOT}/scripts/hle_preexp/kv_prefix_cache_hit_sampler.sh" | tee "${LOG_DIR}/metrics_sampler.log"
fi
echo "Starting GPU SM sampler (interval=${SAMPLE_INTERVAL_SEC}s) gpu_index=${ORCH_GPU}..."
GPU_SAMPLER_PID=""
if [[ -f "${REPO_ROOT}/scripts/preexp/gpu_sm_util_sampler.py" ]]; then
(
source "$CONDA_SH"
conda activate "$VLLM_ENV_SELECTED"
python "${REPO_ROOT}/scripts/preexp/gpu_sm_util_sampler.py" \
--out-csv "${GPU_UTIL_CSV}" \
--gpu-index "${ORCH_GPU}" \
--interval-sec "${SAMPLE_INTERVAL_SEC}"
) > "${LOG_DIR}/gpu_sm_sampler.log" 2>&1 &
GPU_SAMPLER_PID=$!
else
echo "WARNING: skipping GPU SM sampler; not found: ${REPO_ROOT}/scripts/preexp/gpu_sm_util_sampler.py" | tee "${LOG_DIR}/gpu_sm_sampler.log"
fi
echo "Starting eval (concurrency=${CONCURRENCY})..."
set +e
(
source "$CONDA_SH"
conda activate "$VLLM_ENV_SELECTED"
cd "${EVAL_DIR}"
if [[ "${EVAL_TIMEOUT_MIN}" -gt 0 ]]; then
timeout --signal=TERM --kill-after=30s "${EVAL_TIMEOUT_MIN}m" \
python "${EVAL_DIR}/eval_hle_local.py" \
--model_name "${MODEL_NAME}" \
--output_dir "${OUTPUT_DIR}" \
--model_config "${MODEL_CONFIG}" \
--max_rounds "${MAX_ROUNDS}" \
--model_type "${MODEL_TYPE}" \
--example_path "${EXAMPLE_PATH}" \
--concurrency "${CONCURRENCY}" \
--log_level "${LOG_LEVEL}"
else
python "${EVAL_DIR}/eval_hle_local.py" \
--model_name "${MODEL_NAME}" \
--output_dir "${OUTPUT_DIR}" \
--model_config "${MODEL_CONFIG}" \
--max_rounds "${MAX_ROUNDS}" \
--model_type "${MODEL_TYPE}" \
--example_path "${EXAMPLE_PATH}" \
--concurrency "${CONCURRENCY}" \
--log_level "${LOG_LEVEL}"
fi
) 2>&1 | tee -a "${EVAL_LOG}"
EVAL_RC=${PIPESTATUS[0]}
set -e
echo "[eval] exit_code=${EVAL_RC} (timeout=124 if hit)"
echo "[summarize] computing window stats (${WINDOW_START_SEC}..${WINDOW_END_SEC})..."
if [[ -f "${REPO_ROOT}/scripts/hle_preexp/summarize_hle_prefix_cache_window.py" ]]; then
python "${REPO_ROOT}/scripts/hle_preexp/summarize_hle_prefix_cache_window.py" \
--metrics-csv "${METRICS_CSV}" \
--usage-jsonl "${TOOL_ORCH_USAGE_LOG_PATH}" \
--eval-log "${EVAL_LOG}" \
--start-offset-sec "${WINDOW_START_SEC}" \
--end-offset-sec "${WINDOW_END_SEC}" \
--windows "${WINDOW_START_SEC}:${WINDOW_END_SEC}" \
--out-json "${WINDOW_SUMMARY_JSON}" \
>/dev/null 2>&1 || true
else
echo "WARNING: skipping window summary; not found: ${REPO_ROOT}/scripts/hle_preexp/summarize_hle_prefix_cache_window.py"
fi
if [[ -f "${REPO_ROOT}/scripts/preexp/summarize_steps_per_sec_window.py" ]]; then
python "${REPO_ROOT}/scripts/preexp/summarize_steps_per_sec_window.py" \
--usage-jsonl "${TOOL_ORCH_USAGE_LOG_PATH}" \
--eval-log "${EVAL_LOG}" \
--start-offset-sec "${WINDOW_START_SEC}" \
--end-offset-sec "${WINDOW_END_SEC}" \
> "${STEPS_SUMMARY_JSON}" 2>/dev/null || true
else
echo "WARNING: skipping steps summary; not found: ${REPO_ROOT}/scripts/preexp/summarize_steps_per_sec_window.py"
fi
if [[ -f "${REPO_ROOT}/scripts/preexp/summarize_tool_time_window.py" ]]; then
python "${REPO_ROOT}/scripts/preexp/summarize_tool_time_window.py" \
--eval-log "${EVAL_LOG}" \
--usage-jsonl "${TOOL_ORCH_USAGE_LOG_PATH}" \
--start-offset-sec "${WINDOW_START_SEC}" \
--end-offset-sec "${WINDOW_END_SEC}" \
--out-json "${TOOL_TIME_SUMMARY_JSON}" \
>/dev/null 2>&1 || true
else
echo "WARNING: skipping tool time summary; not found: ${REPO_ROOT}/scripts/preexp/summarize_tool_time_window.py"
fi
WINDOW_SUMMARY_JSON="${WINDOW_SUMMARY_JSON}" STEPS_SUMMARY_JSON="${STEPS_SUMMARY_JSON}" METRICS_CSV="${METRICS_CSV}" \
TOOL_ORCH_USAGE_LOG_PATH="${TOOL_ORCH_USAGE_LOG_PATH}" GPU_UTIL_CSV="${GPU_UTIL_CSV}" \
TOOL_TIME_SUMMARY_JSON="${TOOL_TIME_SUMMARY_JSON}" \
EXP_METHOD="${METHOD}" EXP_CONCURRENCY="${CONCURRENCY}" EXP_ROUTER_MODE="${ROUTER_MODE}" \
python - <<'PY' > "${COMBINED_SUMMARY_JSON}"
import json, os
from pathlib import Path
summary = {}
steps = {}
tool_time = {}
sp = Path(os.environ["WINDOW_SUMMARY_JSON"])
tp = Path(os.environ["STEPS_SUMMARY_JSON"])
ttp = Path(os.environ["TOOL_TIME_SUMMARY_JSON"])
if sp.exists():
try:
summary = json.loads(sp.read_text(encoding="utf-8"))
except Exception:
summary = {}
if tp.exists():
try:
steps = json.loads(tp.read_text(encoding="utf-8"))
except Exception:
steps = {}
if ttp.exists():
try:
tool_time = json.loads(ttp.read_text(encoding="utf-8"))
except Exception:
tool_time = {}
out = {
"experiment": {
"method": os.environ.get("EXP_METHOD"),
"concurrency": int(os.environ["EXP_CONCURRENCY"]),
"router_mode": os.environ.get("EXP_ROUTER_MODE"),
},
"ok": bool(summary.get("ok")),
"t0_first_request_unix": summary.get("t0_first_request_unix"),
"t0_first_request_iso": summary.get("t0_first_request_iso"),
"windows": summary.get("windows"),
"steps": steps,
"tool_time": tool_time,
"paths": {
"metrics_csv": os.environ.get("METRICS_CSV"),
"usage_jsonl": os.environ.get("TOOL_ORCH_USAGE_LOG_PATH"),
"gpu_util_csv": os.environ.get("GPU_UTIL_CSV"),
"tool_time_summary_json": os.environ.get("TOOL_TIME_SUMMARY_JSON"),
},
}
print(json.dumps(out, ensure_ascii=False, indent=2))
PY
Below error log for the above experiment ->
DEBUG: vLLM stream complete (took 98.57s, ttft 0.13s) req_id=d5420c2a-3961-4b44-8225-aee67d3736b2
[PROFILE] 2026-08-14 09:35:41.674 task=6715fde1a0465674e6f0bd5a thread=[23055282956032](tel:23055282956032) type=llm_call step=4 eid=12 model=/tmp/models/Nemotron-Orchestrator-8B backend=vllm duration_ms=98576.16 toolorchestra_vllm_infer_ms=98573.40 toolorchestra_vllm_prefill_ms=130.17 toolorchestra_vllm_decode_ms=98443.24 toolorchestra_vllm_prefill_len=1048 toolorchestra_vllm_decode_len=2602
DEBUG: Calling OpenAI model=gpt-5-mini req_id=7c385ef2-8a05-47ee-99d6-16e98f367571
DEBUG: vLLM stream complete (took 26.44s, ttft 0.14s) req_id=2be6e364-b14d-4af4-ba8a-3fedd0f26a18
[PROFILE] 2026-08-14 09:35:47.411 task=66ed5e6a1d24f687ee9b06d1 thread=[23055268165376](tel:23055268165376) type=llm_call step=3 eid=19 model=/tmp/models/Nemotron-Orchestrator-8B backend=vllm duration_ms=26439.41 toolorchestra_vllm_infer_ms=26437.29 toolorchestra_vllm_prefill_ms=140.66 toolorchestra_vllm_decode_ms=26296.62 toolorchestra_vllm_prefill_len=1197 toolorchestra_vllm_decode_len=593
DEBUG: Calling OpenAI model=gpt-5-mini req_id=942ba6d0-788b-4dd9-bd0f-bc61041a4d45
DEBUG: OpenAI request successful req_id=7c385ef2-8a05-47ee-99d6-16e98f367571
[PROFILE] 2026-08-14 09:36:18.697 task=6715fde1a0465674e6f0bd5a thread=[23053563066112](tel:23053563066112) type=tool_call step=4 eid=12 tool=search model=gpt-5-mini duration_ms=37021.52 search_backend=local_only search_local_hits=48 search_tavily_hits=0
[PROFILE] 2026-08-14 09:36:18.702 task=6715fde1a0465674e6f0bd5a thread=[23055282956032](tel:23055282956032) type=step_complete step=4 eid=12 ts_unix=1786700178.70 step=4 job_id=hle:6715fde1a0465674e6f0bd5a:2ece106e tool=search
DEBUG: Calling vLLM at http://127.0.0.1:8100/v1/chat/completions (model=/tmp/models/Nemotron-Orchestrator-8B) req_id=ed503aa6-3fcf-4efb-a808-02a44c21813c
DEBUG: vLLM streaming create kwargs: model=/tmp/models/Nemotron-Orchestrator-8B, messages=2 messages, max_tokens=12000, temperature=1, stream=True, send_tools_to_vllm=True, extra_body={'program_id': 'hle:6715fde1a0465674e6f0bd5a:2ece106e', 'job_id': 'hle:6715fde1a0465674e6f0bd5a:2ece106e', 'is_last_step': False}
DEBUG: vLLM stream complete (took 231.32s, ttft 2.30s) req_id=d6e21f96-73aa-4fb2-859c-1daacd403228
[PROFILE] 2026-08-14 09:36:30.930 task=6724ea8ca36a8ef783edc2e3 thread=[23055308171008](tel:23055308171008) type=llm_call step=3 eid=0 model=/tmp/models/Nemotron-Orchestrator-8B backend=vllm duration_ms=231319.56 toolorchestra_vllm_infer_ms=231315.77 toolorchestra_vllm_prefill_ms=2299.91 toolorchestra_vllm_decode_ms=229015.86 toolorchestra_vllm_prefill_len=17483 toolorchestra_vllm_decode_len=5776
DEBUG: Calling OpenAI model=gpt-5-mini req_id=a440c797-ec21-4380-9817-3b0cd2cf3ad1
Error calling vLLM: timed out
Traceback (most recent call last):
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpx/_transports/default.py", line 101, in map_httpcore_exceptions
yield
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpx/_transports/default.py", line 127, in __iter__
for part in self._httpcore_stream:
^^^^^^^^^^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpcore/_sync/connection_pool.py", line 407, in __iter__
raise exc from None
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpcore/_sync/connection_pool.py", line 403, in __iter__
for part in self._stream:
^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpcore/_sync/http11.py", line 342, in __iter__
raise exc
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpcore/_sync/http11.py", line 334, in __iter__
for chunk in self._connection._receive_response_body(**kwargs):
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpcore/_sync/http11.py", line 203, in _receive_response_body
event = self._receive_event(timeout=timeout)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpcore/_sync/http11.py", line 217, in _receive_event
data = self._network_stream.read(
^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpcore/_backends/sync.py", line 126, in read
with map_exceptions(exc_map):
^^^^^^^^^^^^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/contextlib.py", line 158, in __exit__
self.gen.throw(value)
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpcore/_exceptions.py", line 14, in map_exceptions
raise to_exc(exc) from exc
httpcore.ReadTimeout: timed out
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
File "/tmp/work/ThunderAgent/examples/inference/ToolOrchestra/LLM_CALL.py", line 907, in get_llm_response
for chunk in stream:
^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/openai/_streaming.py", line 49, in __iter__
for item in self._iterator:
^^^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/openai/_streaming.py", line 62, in __stream__
for sse in iterator:
^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/openai/_streaming.py", line 53, in _iter_events
yield from self._decoder.iter_bytes(self.response.iter_bytes())
File "/tmp/envs/vllm1/lib/python3.12/site-packages/openai/_streaming.py", line 297, in iter_bytes
for chunk in self._iter_chunks(iterator):
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/openai/_streaming.py", line 308, in _iter_chunks
for chunk in iterator:
^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpx/_models.py", line 897, in iter_bytes
for raw_bytes in self.iter_raw():
^^^^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpx/_models.py", line 951, in iter_raw
for raw_stream_bytes in self.stream:
^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpx/_client.py", line 153, in __iter__
for chunk in self._stream:
^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpx/_transports/default.py", line 126, in __iter__
with map_httpcore_exceptions():
^^^^^^^^^^^^^^^^^^^^^^^^^
File "/tmp/envs/vllm1/lib/python3.12/contextlib.py", line 158, in __exit__
self.gen.throw(value)
File "/tmp/envs/vllm1/lib/python3.12/site-packages/httpx/_transports/default.py", line 118, in map_httpcore_exceptions
raise mapped_exc(message) from exc
httpx.ReadTimeout: timed out
Retry 1/5 in 5 seconds...
DEBUG: vLLM stream complete (took 135.36s, ttft 0.62s) req_id=69daf842-9c97-49da-9b67-18f560089bc9
[PROFILE] 2026-08-14 09:37:02.056 task=672f8cf367988656535c9b1a thread=[23055287158528](tel:23055287158528) type=llm_call step=3 eid=10 model=/tmp/models/Nemotron-Orchestrator-8B backend=vllm duration_ms=135361.77 toolorchestra_vllm_infer_ms=135357.69 toolorchestra_vllm_prefill_ms=619.19 toolorchestra_vllm_decode_ms=134738.50 toolorchestra_vllm_prefill_len=20084 toolorchestra_vllm_decode_len=3219
DEBUG: Calling vLLM at http://127.0.0.1:8100/v1/chat/completions (model=/tmp/models/Nemotron-Orchestrator-8B) req_id=b644714f-fba0-4003-8235-931459e0218f
DEBUG: vLLM streaming create kwargs: model=/tmp/models/Nemotron-Orchestrator-8B, messages=2 messages, max_tokens=12000, temperature=1, stream=True, send_tools_to_vllm=True, extra_body={'program_id': 'hle:67171b0d0111e9837cad75b8:d2056a81', 'job_id': 'hle:67171b0d0111e9837cad75b8:d2056a81', 'is_last_step': False}
DEBUG: vLLM stream complete (took 315.96s, ttft 0.52s) req_id=de63c320-de2e-4d05-bf65-d0c8e0e02f0a
[PROFILE] 2026-08-14 09:37:06.844 task=67d317cab57b67a3417a4969 thread=[23055276635904](tel:23055276635904) type=llm_call step=3 eid=15 model=/tmp/models/Nemotron-Orchestrator-8B backend=vllm duration_ms=316035.32 toolorchestra_vllm_infer_ms=315961.76 toolorchestra_vllm_prefill_ms=518.33 toolorchestra_vllm_decode_ms=315443.42 toolorchestra_vllm_prefill_len=19424 toolorchestra_vllm_decode_len=7851
DEBUG: Calling OpenAI model=gpt-5-mini req_id=09ada409-4995-4f4b-8ef2-fb2a1833e8d7
DEBUG: Calling OpenAI model=gpt-5-mini req_id=82cc0636-8da5-4545-bc2e-afcff2bebf9e
Description:
I am making use of the latest commit of ThunderAgent (7ddc861). I encountered an issue where the upstream http client times out waiting for a chunk while streaming a response back, from the vllm backend. We continue to notice this issue despite increasing the
TOOL_ORCH_STREAM_READ_TIMEOUT_Senvironment variable. This issue was observed with both the baseline (vllm) as well as thunderagent. The KV cache usage remains low when the timeout actually occurs (<80%)The request succeeds in a next retry, however we wish to understand why this issue occurs as this causes a drop in the throughput.
Experiment: ToolOrchestra(HLE)-Qwen3-8B. We have used gpt-5-nano answering tool calls, gpt-5 for reasoning and gpt-5-mini for search. Hardware used: 2x A100 80GB HBM
To replicate, find the attached launch scripts, below launch command and the error log (with the error alone from eval.log).
Launch command:
Launch Scripts
Below error log for the above experiment ->