Repository navigation
[Hackathon] fix(create-batch): rounding remaining wait budget down causes premature timeouts #480
Description
Verified against (commit SHA or released version)
988c035 (public main rechecked 2026-10-17; package 0.14.0), Node.js v22.23.2, macOS
Discord Username / User ID
luckyzd.
What does this improvement do?
Preserve the remaining per-test wait budget in test create-batch --run --wait. runBatchRun currently floors the remaining milliseconds to whole seconds before starting its poller, discarding up to almost one second. An ordinary successful trigger can therefore make the command time out a test before the requested budget expires, even when that test completes inside the original budget.
Executed example: with --timeout 2, a 250 ms trigger response, and a run that completes 1.5 seconds after the first trigger attempt, the CLI stops at about 1.25 seconds with status: "timeout", exit 7. Roughly 750 ms of the two-second budget remains. Both a passing and a failing terminal result are missed. The run ID is retained; this report is about the incorrect timeout/verdict, not lost IDs.
This is a Season 4 hackathon issue-first submission. Evidence is an executed offline command-chain reproduction with real timers and documented long-poll behavior, not a hosted-service incident. No malformed responses, transport errors, signal interruption, clock mocking or real credentials are used. A transient rate-limit retry is covered separately; the baseline reproduces using only successful HTTP responses.
Details / implementation notes
Trigger and actual behavior
Use an ordinary valid frontend plan and run:
testsprite test create-batch --plans plans.jsonl --run --wait --timeout 2 --output json- Batch creation succeeds.
- At the start of the trigger attempt, the CLI establishes a per-spec deadline of now + 2000 ms.
- The trigger returns an accepted run ID about 250 ms later. About 1750 ms remains.
Math.floor(rem / 1000) || 1converts that to 1 second. The poller starts a new one-second deadline and requestsGET /runs/run_a?waitSeconds=1.- The run will complete at t=1500 ms. The long poll legitimately returns
runningat about t=1250 ms because its requested one-second window expired. - The shortened poll deadline has now expired, so the CLI exits 7 without observing the terminal result. A follow-up read of the same fixture run returns
passed(orfailed) with a finishedAt inside the original budget.
Actual result, irrelevant fields omitted:
{"results":[{"testId":"a","runId":"run_a","status":"timeout","error":{"code":"UNSUPPORTED","message":"Timed out after 2s waiting for run run_a.","exitCode":7}}]}Expected: retain the original remaining time and observe a terminal result arriving within that budget. Passed should exit 0; failed should exit 1. An actually expired budget must still avoid further dispatch/polling. The same rounding can occur near the end of larger configured budgets; the short test values keep the reproduction quick.
Source and supported contract
runBatchRunsets the per-spec absolute deadline before the first trigger; its comment explicitly includes trigger/retry time in the same budget.- The remaining budget is rounded down at L4713, after the separate
rem <= 0guard. pollRunUntilTerminalconstructs a new deadline from that shortened duration. Its long-poll loop then correctly times out against the wrong budget it received.- The fixture honors
waitSeconds: respond when the run becomes terminal or when the requested long-poll interval expires, returning the latest running row in the latter case. This is the documented poll contract, not a contrived server transition.
The fix should preserve the original remaining deadline rather than restart the full timeout after retry. Passing fractional seconds or an absolute deadline can avoid both truncation and granting an extra second after expiration; final implementation should retain the existing no-poll-after-expiry guard.
Seven executed scenarios
All times below are relative to the member's first trigger request. The fixture delays a successful trigger by 250 ms. Timers and Date.now are real.
| Scenario | Budget | Terminal at | CLI stops at | Actual outcome |
|---|---|---|---|---|
| Fast passed control | 2 s | 0.8 s | ~0.8 s | passed / exit 0 |
| Passed inside original budget | 2 s | 1.5 s | ~1.25 s | timeout / exit 7 |
| Failed inside original budget | 2 s | 1.5 s | ~1.25 s | timeout / exit 7, not failed |
| Larger-budget passed control | 3 s | 1.5 s | ~1.5 s | passed / exit 0 |
| Two members: 0.8 s and 1.5 s, both pass | 2 s each | 0.8 / 1.5 s | ~1.25 s | passed + timeout / exit 1 |
| First trigger 429, real 1 s Retry-After, then accepted | 3 s | 2.5 s | ~2.25 s | timeout / exit 7 |
| Same retry with larger budget | 4 s | 2.5 s | ~2.5 s | passed / exit 0 |
The retry controls also assert that both attempts use the same per-test idempotency key. The script checks every result's test/run association and reads the fixture again after completion to verify the actual terminal status. Product source is unchanged. Build passed; existing test.create-batch-run.spec.ts and poll.spec.ts passed: 97 tests, 2 files, 4.23 seconds. Existing green tests do not cover this fractional remaining-budget case.
Duplicate check
Searched open and closed Issues/PRs for create-batch with timeout/early/deadline, remainingSeconds, Math.floor, throttle+deadline and floor+timeout, and read the related reports/review discussions.
- [Hackathon] fix(poll): a 7-second network blip ends any --wait with exit 10, and a silently dropped connection stalls it for 300s #437 concerns early termination after transport outages and stalled HTTP connections. The baseline here uses only HTTP 200 and obeys long-poll timing.
- [Hackathon] fix(http): retry backoff ignores caller abort signals and overruns test wait --timeout #403 / PR fix(http): honor caller abort signals during retry backoff #406 concern HttpClient retry backoff ignoring an abort signal. No abort or HTTP retry is needed here; the poller is explicitly given a shortened budget.
- [Hackathon] fix(test): batch retry sleep exits on signal before preserving acknowledged IDs #426 concerns process signals during outer retry sleeps discarding receipts. This report uses no signals and retains run IDs.
- PR fix(test): stop run --all --wait from polling queued runs past the shared deadline #130 fixes queued fresh-batch members polling after an expired shared deadline. This is the create-batch per-spec path timing out before its still-live deadline; the existing exhausted-budget guard is already present and must stay.
- PR fix(batch): classify RequestTimeoutError as timeout in --all --wait fan-out #135/fix(batch): classify RequestTimeoutError as timeout in --all --wait fan-out #154 classify RequestTimeoutError in run/rerun fan-outs. No RequestTimeoutError occurs here.
- [Hackathon] create-batch --run without --wait always exits 1 even when every trigger succeeds #161 / PR fix(test): create-batch --run without --wait exits 0 on a fully successful dispatch #267 fix the no-wait queued-success exit code. This requires --wait and does not change no-wait behavior.
No matching fractional-budget report was found. I will wait for maintainer acceptance and assignment before implementation or a PR. AI disclosure: Codex assisted with source review, reproduction and duplicate checking.
Self-contained executable reproduction
Build the pinned checkout with npm ci && npm run build. Save the script below outside the checkout and run node repro.mjs /absolute/path/to/testsprite-cli. It takes about 12 seconds, uses only in-process HTTP fixtures, and prints seven result envelopes and timing/request traces. Assertions capture the affected revision's current behavior, so a successful script exit means that the described behavior and controls were reproduced.
Seven-case real-timer reproduction
import assert from 'node:assert/strict';
import {mkdtemp,writeFile,rm} from 'node:fs/promises';
import {tmpdir} from 'node:os';
import {join,resolve} from 'node:path';
import {pathToFileURL} from 'node:url';
import {createRequire} from 'node:module';
// Offline HTTP fixture with actual timers: emulate documented long polling,
// returning at min(waitSeconds, completion). Commander/client/poller unchanged.
const root=resolve(process.argv[2]??'work/testsprite-cli');
const require=createRequire(join(root,'package.json'));
const {Command}=require('commander');
const {createTestCommand}=await import(pathToFileURL(join(root,'dist/commands/test.js')));
const temp=await mkdtemp(join(tmpdir(),'testsprite-early-timeout-'));
const delay=ms=>new Promise(resolve=>setTimeout(resolve,Math.max(0,ms)));
const json=(body,status=200,headers={})=>new Response(JSON.stringify(body),{status,headers:{'content-type':'application/json',...headers}});
const scenarios=[
{name:'fast-run-control',timeout:2,finishMs:800,verdict:'passed',expectedExit:0},
{name:'budget-not-exhausted-pass',timeout:2,finishMs:1500,verdict:'passed',expectedExit:7},
{name:'budget-not-exhausted-fail',timeout:2,finishMs:1500,verdict:'failed',expectedExit:7},
{name:'larger-budget-control',timeout:3,finishMs:1500,verdict:'passed',expectedExit:0},
{name:'two-member-batch',timeout:2,finishMs:1500,verdict:'passed',count:2,expectedExit:1},
{name:'after-rate-retry',timeout:3,finishMs:2500,verdict:'passed',retry:true,expectedExit:7},
{name:'retry-larger-budget-control',timeout:4,finishMs:2500,verdict:'passed',retry:true,expectedExit:0},
];
const results=[];
try{
for(const s of scenarios){
const ids=s.count===2?['a','b']:['a'];
const plans=join(temp,s.name+'.jsonl');
await writeFile(plans,ids.map(id=>JSON.stringify({projectId:'project',type:'frontend',name:'Case '+id,planSteps:[{type:'action',description:'Open home '+id}]})).join('\n')+'\n');
const stdout=[],stderr=[],trace=[],starts=new Map(),attempts=new Map(),completedAt=new Map();
let exitAt=0;
const deps={env:{TESTSPRITE_API_KEY:'sk-user-offline-fixture',TESTSPRITE_API_URL:'https://mock.example.com'},credentialsPath:join(temp,'absent'),stdout:x=>stdout.push(x),stderr:x=>stderr.push(x),
fetchImpl:async(input,init={})=>{
const u=new URL(typeof input==='string'?input:input.url??input.href);assert.equal(u.hostname,'mock.example.com');
const path=u.pathname.replace('/api/cli/v1',''),method=init.method??'GET';
const event={method,path,query:Object.fromEntries(u.searchParams),at:Date.now()};trace.push(event);
if(path==='/projects/project/env')return json({environments:[{name:'default',url:'https://example.com',isDefault:true,isTemporary:false}]});
if(path==='/tests/batch'&&method==='POST')return json({results:ids.map((id,specIndex)=>({specIndex,testId:id,status:'created'})),summary:{total:ids.length,created:ids.length,failed:0}});
const trigger=/^\/tests\/(a|b)\/runs$/.exec(path);
if(trigger&&method==='POST'){
const id=trigger[1],attempt=(attempts.get(id)??0)+1;attempts.set(id,attempt);
if(!starts.has(id))starts.set(id,Date.now());
event.attempt=attempt;event.idempotencyKey=new Headers(init.headers).get('idempotency-key');
if(s.retry&&attempt===1)return json({error:{code:'RATE_LIMITED',message:'Run trigger rate limit exceeded: 60 triggers per minute per key.',nextAction:'Wait.',requestId:'fixture',details:{retryAfterSeconds:1}}},429,{'retry-after':'1'});
await delay(250);
const finishMs=s.count===2&&id==='a'?800:s.finishMs;
completedAt.set(id,starts.get(id)+finishMs);
return json({runId:'run_'+id,status:'queued',enqueuedAt:new Date(starts.get(id)).toISOString(),codeVersion:'v1',targetUrl:'https://example.com'});
}
const poll=/^\/runs\/run_(a|b)$/.exec(path);
if(poll){
const id=poll[1],start=starts.get(id),finish=completedAt.get(id);
assert.ok(start&&finish);const waitSeconds=Number(u.searchParams.get('waitSeconds')??0);
await delay(Math.min(Math.max(0,finish-Date.now()),waitSeconds*1000));
const terminal=Date.now()>=finish,status=terminal?(s.count===2&&id==='a'?'passed':s.verdict):'running';
event.returnAt=Date.now();event.status=status;
return json({runId:'run_'+id,testId:id,projectId:'project',userId:'fixture',status,source:'cli',createdAt:new Date(start).toISOString(),startedAt:new Date(start+250).toISOString(),finishedAt:terminal?new Date(finish).toISOString():null,codeVersion:'v1',targetUrl:'https://example.com',createdFrom:'cli',failedStepIndex:status==='failed'?0:null,failureKind:status==='failed'?'assertion':null,error:null,videoUrl:null,stepSummary:{total:1,completed:terminal?1:0,passedCount:status==='passed'?1:0,failedCount:status==='failed'?1:0}});
}
throw Error('Unexpected fixture route '+method+' '+path);
}};
const args=['--output','json','test','create-batch','--plans',plans,'--run','--wait','--timeout',String(s.timeout),'--max-concurrency','2'];
let exitCode=0,error;
try{await new Command('testsprite').option('--output <mode>').addCommand(createTestCommand(deps)).parseAsync(args,{from:'user'});}
catch(e){exitCode=e.exitCode??1;error={name:e.name,code:e.code,message:e.message,exitCode:e.exitCode};}
exitAt=Date.now();assert.equal(exitCode,s.expectedExit,s.name+': '+JSON.stringify(error));
const payload=JSON.parse(stdout.join('\n'));assert.equal(payload.results.length,ids.length);
const timings=ids.map(id=>({testId:id,elapsedMs:exitAt-starts.get(id),budgetMs:s.timeout*1000,fixtureCompletionMs:completedAt.get(id)-starts.get(id),remainingAtExitMs:starts.get(id)+s.timeout*1000-exitAt}));
for(const row of payload.results){
assert.equal(row.runId,'run_'+row.testId);
const affected=s.expectedExit!==0&&!(s.count===2&&row.testId==='a');
assert.equal(row.status,affected?'timeout':'passed');
if(affected){const timing=timings.find(t=>t.testId===row.testId);assert.ok(timing.remainingAtExitMs>400,JSON.stringify(timing));assert.ok(timing.elapsedMs<timing.fixtureCompletionMs);assert.ok(timing.fixtureCompletionMs<timing.budgetMs);}
}
if(s.retry){const triggers=trace.filter(x=>x.method==='POST'&&x.path.endsWith('/runs'));assert.equal(triggers.length,2);assert.equal(triggers[0].idempotencyKey,triggers[1].idempotencyKey);}
// Read the same fixture after its real terminal instant, proving the eventual
// status and run ID rather than relying only on a scheduled completion time.
await delay(Math.max(...completedAt.values())-Date.now()+5);
const observed=[];
for(const id of ids){const response=await deps.fetchImpl('https://mock.example.com/api/cli/v1/runs/run_'+id);const row=await response.json();assert.equal(row.status,s.count===2&&id==='a'?'passed':s.verdict);observed.push({runId:row.runId,status:row.status,finishedAt:row.finishedAt});}
results.push({name:s.name,args,exitCode,error,timings,payload,observed,trace,stderr});
}
console.log(JSON.stringify({baseline:'988c0355bb05631e9c6c1785e443937ff2a88c0e',node:process.version,scope:'offline real-timer long-poll fixture, not hosted observation',results},null,2));
}finally{await rm(temp,{recursive:true,force:true});}Confirmations
- I have searched existing issues and this is not a duplicate.
- I have provided my Discord identity above for reward coordination.
Activity
zeshi-du commentedon Oct 20, 2026
Thanks @luckyzd. Confirmed: in
runBatchRunthe remaining budget is floored to whole seconds (1s when under one) before polling, so up to a second of--timeoutis lost, or occasionally overshot. It is a real incorrect timeout, so we're accepting it (low priority).Scope:
Tests: a mock-based test that fails before the fix (run finishing inside the original budget, passed and failed), plus one confirming an expired budget still doesn't poll.
This touches the same function as your #485, so land them together or coordinate order. Don't touch rerun paths or rename anything; the command surface is being restructured. Claim it with /assign.
luckyzd commentedon Oct 20, 2026
/assign
testsprite-hob commentedon Oct 20, 2026
Assigned to @luckyzd. Thanks for taking this on. (1 more slot available.)
Your open assigned issues (2/3):