[Bug] Hash prefix cache cold-hit-miss sequence can crash Qwen3-14B prefill with 507018

[zmnobug]

Diagnosis

pypto-serving / Qwen3-14B NPU prefill runtime - a hash prefix-cache cold-hit-miss sequence can schedule a later full-prefill miss into non-initial physical KV pages and crash with 507018. This is not unique to the radix prefix-cache lookup path.

Description

A Qwen3-14B serving process using the default hash prefix-cache backend can reproduce the same 507018 failure observed while validating radix prefix caching.

Reproduction sequence:

1. Start Qwen3-14B serving with --prefix-cache-backend hash.
2. Run a cold/hit/miss probe with one repeated-prefix round.
3. The cold request succeeds.
4. The second request hits one cached prefix page and succeeds.
5. The third request is a different-prefix miss, but it is scheduled as one 262-token full prefill with physical KV pages [3, 4, 5].
6. The prefill runtime fails with aclrtSynchronizeStreamWithTimeout (AICPU) failed: 507018, and the HTTP request returns 500.

Important control checks:

• A fresh service receiving only the same 262-token miss request succeeds.
• A fresh service running only cold -> miss also succeeds.
• The failure is reproducible with cold -> hit -> miss.
• The failed third request has hit_pages=0, so this is not a wrong prefix-cache hit.
• A radix-side workaround that caps radix prefill chunks to two pages avoids this specific trigger shape, but the underlying hash-path failure still indicates a prefill/runtime stability issue.

Command or Request

Start service:

task-submit --device 2 --max-time 0 --run \
"PATH=/usr/local/bin/ptoas-bin:\$PATH PTOAS_ROOT=/usr/local/bin/ptoas-bin \
PYTHONUNBUFFERED=1 \
PYPTO_PREFIX_CACHE_DEBUG=1 \
PTO2_RING_HEAP=2147483648 PTO2_RING_TASK_WINDOW=1048576 PTO2_RING_DEP_POOL=1048576 \
<PYTHON> -m python.cli.main \
  --model <QWEN3_14B_MODEL_DIR> \
  --backend npu \
  --platform a2a3 \
  --device 2 \
  --max-model-len 512 \
  --max-new-tokens 2 \
  --prefix-cache-backend hash \
  --port 8899 \
  --show-startup-logs"

Run probe:

python test_radix_hit.py --rounds 1 --prefix-repeat 28 --max-model-len 512 --max-tokens 2

Minimal repro script:

import json
import time
import urllib.request

URL = "http://127.0.0.1:8899/v1/completions"
REPEAT = 28


def post(label, prompt):
    payload = {
        "prompt": prompt,
        "max_tokens": 2,
        "temperature": 0.0,
    }
    req = urllib.request.Request(
        URL,
        data=json.dumps(payload).encode("utf-8"),
        headers={"Content-Type": "application/json"},
        method="POST",
    )
    start = time.perf_counter()
    with urllib.request.urlopen(req, timeout=600) as resp:
        body = resp.read().decode("utf-8")
    print(label, round(time.perf_counter() - start, 3), body)


hit_prefix = (
    "Probe round 1. "
    + "Huawei is a leading global technology company. " * REPEAT
)
miss_prefix = (
    "Probe round 1 miss. "
    + "The Forbidden City is an ancient imperial palace. " * REPEAT
)

post("cold", hit_prefix + " First answer:")
post("hit", hit_prefix + " Second answer:")
post("miss", miss_prefix + " Third answer:")

Observed client output from the full probe:

cold-1        5.320s finish=length   chars= 10 text=' Huawei is'
hit-1         0.582s finish=length   chars= 10 text=' Huawei is'
miss-1        HTTP 500 Internal Server Error

The local validation script test_radix_hit.py contains the same sequence plus tokenizer/page accounting and summary output. The minimal script above is enough to reproduce the failure.

Environment

Component	Version
pypto-serving	107db2d plus local prefix-cache/radix validation branch
pypto-lib	3ef4931
pypto	0.1.0
simpler	0.1.0
ptoas	0.46
CANN	9.0.0 inferred from runtime path
torch / torch-npu	torch 2.6.0+cpu, torch-npu 2.6.0.post2

Host Platform

Linux (aarch64)

Device / Platform

Ascend NPU, a2a3, reproduced on device 2.

Model

Qwen3-14B

Logs

[prefix_cache] backend=hash event=match request=cmpl-63a4aa1d model=Qwen3-14B prompt_tokens=233 hit_tokens=0 hit_pages=0 lookup_ms=0.009
[prefix_cache] backend=hash event=schedule request=cmpl-63a4aa1d model=Qwen3-14B scheduled_prefill_tokens=233 computed_tokens=0 cached_pages=0 allocated_pages=2 block_ids=[0, 1]
[timing] prefill: fused 40 layers, 5157.89 ms
[prefix_cache] backend=hash event=insert request=cmpl-63a4aa1d model=Qwen3-14B total_tokens=128 pages=1 inserted_pages=1 insert_ms=0.007

[prefix_cache] backend=hash event=match request=cmpl-2189b6d7 model=Qwen3-14B prompt_tokens=233 hit_tokens=128 hit_pages=1 lookup_ms=0.013
[prefix_cache] backend=hash event=schedule request=cmpl-2189b6d7 model=Qwen3-14B scheduled_prefill_tokens=105 computed_tokens=128 cached_pages=1 allocated_pages=1 block_ids=[0, 2]
[timing] prefill: fused 40 layers, 455.50 ms

[prefix_cache] backend=hash event=match request=cmpl-7ec638fc model=Qwen3-14B prompt_tokens=262 hit_tokens=0 hit_pages=0 lookup_ms=0.007
[prefix_cache] backend=hash event=schedule request=cmpl-7ec638fc model=Qwen3-14B scheduled_prefill_tokens=262 computed_tokens=0 cached_pages=0 allocated_pages=3 block_ids=[3, 4, 5]
[ERROR] sync_run_streams: aclrtSynchronizeStreamWithTimeout (AICPU) failed: 507018
[WARN] recover_device_or_mark_unusable: AICore error 507018: device drained via aclrtSynchronizeDeviceWithTimeout
[ERROR] validate_runtime_impl: PTO2 runtime failed: orch_error_code=2 sched_error_code=0 runtime_status=-2
RuntimeError: run_prepared failed with code 507018

Additional Context

The failure appears tied to a specific serving/runtime state rather than the prompt alone. The same 262-token miss can succeed on a fresh service, but fails after a prior prefix-cache hit when the next miss is scheduled as a 3-page full prefill using physical pages [3, 4, 5].

This should be investigated independently from radix prefix-cache correctness, because the same failure is reproducible through the hash backend.