r"""Copilot CLI: cutting a background sub-agent's model stream burns 5 retries in ~5s.
Runs a real background sub-agent through the native `task` tool against a
loopback BYOK provider, then cuts the sub-agent's own Responses stream. The
fixture makes no outbound requests and no credential is supplied; whether the
CLI's own startup helpers touch the network is not measured here.
python repro_4911.py --binary <copilot.exe> --payload-dir <pkg/win32-x64/VER>
--work <fresh dir> --mode sse-cut --expect-version VER --pin-embedded
"""
import argparse
import ctypes
import http.server
import json
import os
import pathlib
import re
import shutil
import subprocess
import sys
import threading
import time
import uuid
MARK_ROOT = 'REPRO4911ROOT'
MARK_TASK = 'REPRO4911TASK'
CHILD_PROMPT = 'Reply with exactly CHILD-OK. Do not call any tool. ' + MARK_TASK
MODES = ('success', 'sse-cut', 'chunk-cut')
TOOL = 'task'
INTERNAL_TOOLS = {'read_agent'}
VALID = ('completed', 'model-request-failed')
RETRY = re.compile(r'retried\s+(\d+)\s+times\s*\(total retry wait time:\s*'
r'([0-9.]+)\s*seconds?\)', re.I)
PRELOAD_JS = r"""const fs = require('node:fs'), path = require('node:path');
const capture = () => {
const versions = new Set();
for (const m of process.report.getReport().sharedObjects || []) {
const hit = /[\\/]pkg[\\/][^\\/]+[\\/]([0-9][0-9.-]*)[\\/]/.exec(m);
if (hit) versions.add(hit[1]);
}
fs.writeFileSync(path.join(process.env.REPRO_INFO_DIR, 'runtime.json'),
JSON.stringify({node: process.version, loaded: [...versions].sort()}));
if (versions.size) clearInterval(timer);
};
const timer = setInterval(capture, 1000);
timer.unref();
process.once('exit', capture);
"""
class Memory(ctypes.Structure):
_fields_ = [('length', ctypes.c_ulong), ('load', ctypes.c_ulong),
('totalPhys', ctypes.c_ulonglong), ('freePhys', ctypes.c_ulonglong),
('totalPage', ctypes.c_ulonglong), ('freePage', ctypes.c_ulonglong),
('totalVirt', ctypes.c_ulonglong), ('freeVirt', ctypes.c_ulonglong),
('freeExt', ctypes.c_ulonglong)]
def headroom():
status = Memory()
status.length = ctypes.sizeof(status)
ctypes.WinDLL('kernel32').GlobalMemoryStatusEx(ctypes.byref(status))
return status.freePhys / (1 << 30), status.freePage / (1 << 30)
class Handler(http.server.BaseHTTPRequestHandler):
protocol_version = 'HTTP/1.1'
def log_message(self, *args):
return
def do_GET(self):
raw = json.dumps({'object': 'list',
'data': [{'id': self.server.model, 'object': 'model'}]}).encode()
self.send_response(200)
self.send_header('Content-Type', 'application/json')
self.send_header('Content-Length', str(len(raw)))
self.end_headers()
self.wfile.write(raw)
def do_POST(self):
length = int(self.headers.get('Content-Length') or 0)
if length > 32 << 20:
self.send_error(413)
return
body = self.rfile.read(length).decode('utf-8', 'replace')
role = self.role(body)
with self.server.lock:
turn = sum(1 for call in self.server.calls if call['role'] == role)
entry = {'role': role, 'start': time.monotonic(), 'tools': self.tools(body)}
self.server.calls.append(entry)
action = self.action(role, turn)
self.emit(action)
entry['end'] = time.monotonic()
def role(self, body):
"""Role comes from the request itself, not from call ordering.
The operator prompt carries the root marker; the sub-agent prompt the
parent hands to `task` carries only the task marker.
"""
if MARK_ROOT in body:
return 'parent'
if MARK_TASK in body:
return 'subagent'
return 'utility'
def tools(self, body):
try:
payload = json.loads(body)
except ValueError:
return []
names = [((tool.get('function') or tool).get('name'))
for tool in payload.get('tools') or [] if isinstance(tool, dict)]
return sorted({name for name in names if name})
def action(self, role, turn):
if role == 'parent':
return 'tool_call' if turn == 0 else 'text'
if role == 'subagent' and self.server.mode != 'success':
return self.server.mode
return 'text'
def chunk(self, name, payload):
payload['type'] = name
with self.server.lock:
self.server.sequence += 1
payload['sequence_number'] = self.server.sequence
raw = ('event: %s\ndata: %s\n\n' % (name, json.dumps(payload))).encode()
self.wfile.write(b'%X\r\n' % len(raw) + raw + b'\r\n')
self.wfile.flush()
def emit(self, action):
self.send_response(200)
self.send_header('Content-Type', 'text/event-stream')
self.send_header('Transfer-Encoding', 'chunked')
self.end_headers()
response_id = 'resp_' + uuid.uuid4().hex[:12]
self.chunk('response.created',
{'response': {'id': response_id, 'status': 'in_progress',
'model': self.server.model, 'output': []}})
item = ('fc_' if action == 'tool_call' else 'msg_') + uuid.uuid4().hex[:12]
if action == 'tool_call':
output = self.tool_call_item(item)
else:
output = self.message_item(item, action)
if output is None:
return
self.chunk('response.completed',
{'response': {'id': response_id, 'status': 'completed',
'model': self.server.model, 'output': [output]}})
self.end_body()
def tool_call_item(self, item):
arguments = json.dumps({'name': 'repro-child', 'agent_type': 'general-purpose',
'description': 'Repro background child',
'mode': 'background', 'prompt': CHILD_PROMPT})
call = {'id': item, 'type': 'function_call', 'status': 'completed',
'name': TOOL, 'arguments': arguments,
'call_id': 'call_' + uuid.uuid4().hex[:12]}
self.chunk('response.output_item.added',
{'output_index': 0, 'item': dict(call, status='in_progress',
arguments='')})
self.chunk('response.function_call_arguments.delta',
{'item_id': item, 'output_index': 0, 'delta': arguments})
self.chunk('response.function_call_arguments.done',
{'item_id': item, 'output_index': 0, 'arguments': arguments})
self.chunk('response.output_item.done', {'output_index': 0, 'item': call})
return call
def message_item(self, item, action):
"""Emit a valid SSE prefix, then either finish or cut."""
text = 'CHILD-PARTIAL' if action in ('sse-cut', 'chunk-cut') else 'CHILD-OK'
part = {'type': 'output_text', 'text': '', 'annotations': []}
self.chunk('response.output_item.added',
{'output_index': 0, 'item': {'id': item, 'type': 'message',
'status': 'in_progress',
'role': 'assistant', 'content': []}})
self.chunk('response.content_part.added',
{'item_id': item, 'output_index': 0, 'content_index': 0,
'part': part})
self.chunk('response.output_text.delta',
{'item_id': item, 'output_index': 0, 'content_index': 0,
'delta': text})
if action == 'chunk-cut':
self.close_connection = True
self.connection.close()
return None
if action == 'sse-cut':
self.end_body()
return None
done = dict(part, text=text)
self.chunk('response.output_text.done',
{'item_id': item, 'output_index': 0, 'content_index': 0,
'text': text})
self.chunk('response.content_part.done',
{'item_id': item, 'output_index': 0, 'content_index': 0,
'part': done})
message = {'id': item, 'type': 'message', 'status': 'completed',
'role': 'assistant', 'content': [done]}
self.chunk('response.output_item.done', {'output_index': 0, 'item': message})
return message
def end_body(self):
self.wfile.write(b'0\r\n\r\n')
self.wfile.flush()
class Server(http.server.ThreadingHTTPServer):
daemon_threads = True
def handle_error(self, request, address):
if not issubclass(sys.exc_info()[0], OSError):
super().handle_error(request, address)
def collect(case):
"""Merge both event streams, de-duplicating mirrored executions by call id."""
sources, executions, errors = {}, {}, []
retry, malformed, truncated = {}, 0, False
files = [('stdout', case / 'stdout.jsonl')]
files += [('session', path) for path in
sorted((case / 'home' / 'session-state').glob('*/events.jsonl'))]
for label, path in files:
if not path.is_file():
continue
counts = sources.setdefault(label, {})
budget = 64 << 20
for line in path.read_text(encoding='utf-8', errors='replace').splitlines():
budget -= len(line)
if budget < 0:
truncated = True
break
if not line.strip():
continue
try:
event = json.loads(line)
except ValueError:
malformed += 1
continue
kind, data = event.get('type'), event.get('data')
if not isinstance(kind, str):
malformed += 1
continue
counts[kind] = counts.get(kind, 0) + 1
if not isinstance(data, dict):
continue
if kind == 'tool.execution_start':
name = data.get('toolName') or data.get('name') or '?'
key = data.get('toolCallId') or '%s#%d' % (name, len(executions))
executions[key] = name
message = message_of(data)
if not message:
continue
if kind.endswith('error') or kind.endswith('failed'):
errors.append((label, kind, message))
hit = RETRY.search(message)
if hit and not retry:
retry = {'retries': int(hit.group(1)), 'sleep': float(hit.group(2))}
tools = {}
for name in executions.values():
tools[name] = tools.get(name, 0) + 1
return {'sources': sources, 'tools': tools, 'errors': errors, 'retry': retry,
'malformed': malformed, 'truncated': truncated}
def message_of(data):
direct = data.get('message')
if isinstance(direct, str):
return direct
nested = data.get('error')
if isinstance(nested, str):
return nested
if isinstance(nested, dict) and isinstance(nested.get('message'), str):
return nested['message']
return ''
def terminal(counts):
for name in ('subagent.failed', 'subagent.completed'):
if counts.get(name):
return name
return 'started-only' if counts.get('subagent.started') else 'none'
def classify(calls, events, runtime, expect, guard, timed_out):
"""Guard, damage and isolation failures are never a reproduction."""
session = events['sources'].get('session', {})
advertised = {name for call in calls for name in call['tools']}
if guard:
return guard
if timed_out:
return 'timeout'
if not calls:
return 'startup-failed'
if events['malformed'] or events['truncated']:
return 'invalid-event-evidence'
if not runtime.get('loaded'):
return 'invalid-runtime-evidence'
if expect and runtime['loaded'] != [expect]:
return 'invalid-runtime-version'
if advertised - {TOOL}:
return 'invalid-tool-surface'
if set(events['tools']) - {TOOL} - INTERNAL_TOOLS:
return 'invalid-tool-call'
if not [call for call in calls if call['role'] == 'subagent']:
return 'no-subagent-request'
if not session.get('subagent.started'):
return 'no-subagent-started'
if events['retry']:
return 'model-request-failed'
if terminal(session) != 'subagent.completed':
return 'no-terminal-event'
return 'completed'
def build_command(launcher, preload, case, model, pin):
command = [
str(launcher),
'--node-options=' + subprocess.list2cmdline(['--require', str(preload)]),
'--no-custom-instructions', '--disable-builtin-mcps', '--no-ask-user',
'--no-remote', '--no-remote-export', '--no-color',
'--available-tools', TOOL,
'--deny-tool', 'shell,write,read,url,memory,fetch', '--allow-all-tools',
'--model', model, '--log-dir', str(case / 'logs'),
'--output-format', 'json', '-C', str(case / 'work'),
'-p', 'Call the task tool exactly once with the given arguments. ' + MARK_ROOT,
]
if pin:
command.append('--no-auto-update')
return command
def build_env(case, work, base, model, pin):
keep = ('SYSTEMROOT', 'WINDIR', 'COMSPEC', 'PATH', 'PATHEXT', 'PROGRAMFILES',
'PROGRAMFILES(X86)', 'PROCESSOR_ARCHITECTURE', 'NUMBER_OF_PROCESSORS')
env = {name: os.environ[name] for name in keep if name in os.environ}
env.update({
'COPILOT_HOME': str(case / 'home'), 'COPILOT_CACHE_HOME': str(work / 'cache'),
'COPILOT_AUTO_UPDATE': 'false' if pin else 'true',
'COPILOT_OFFLINE': 'true', 'COPILOT_OTEL_ENABLED': 'false',
'COPILOT_PROVIDER_BASE_URL': base, 'COPILOT_PROVIDER_TYPE': 'openai',
'COPILOT_PROVIDER_WIRE_API': 'responses',
'COPILOT_PROVIDER_MODEL_ID': model, 'COPILOT_PROVIDER_WIRE_MODEL': model,
'REPRO_INFO_DIR': str(case / 'info'), 'HOME': str(case / 'profile'),
'USERPROFILE': str(case / 'profile'), 'APPDATA': str(case / 'appdata'),
'LOCALAPPDATA': str(case / 'local'), 'TEMP': str(case / 'temp'),
'TMP': str(case / 'temp'), 'NO_COLOR': '1',
})
return env
def run_child(command, env, case, timeout, cap_bytes):
started, guard, timed_out, child = time.monotonic(), '', False, None
try:
with (case / 'stdout.jsonl').open('wb') as out:
with (case / 'stderr.txt').open('wb') as err:
child = subprocess.Popen(command, env=env, cwd=case / 'work',
stdout=out, stderr=err,
stdin=subprocess.DEVNULL)
while child.poll() is None:
physical, commit = headroom()
if time.monotonic() - started > timeout:
timed_out = True
break
if physical < 8 or commit < 10:
guard = 'guard-memory-floor'
break
if (case / 'stdout.jsonl').stat().st_size > cap_bytes:
guard = 'guard-output-cap'
break
time.sleep(0.5)
finally:
if child and child.poll() is None:
child.kill()
child.wait(timeout=30)
return child.returncode if child else None, guard, timed_out
def main(argv=None):
parser = argparse.ArgumentParser(description=__doc__)
parser.add_argument('--binary', required=True)
parser.add_argument('--payload-dir', required=True)
parser.add_argument('--work', required=True, help='fresh directory, never reused')
parser.add_argument('--mode', default='sse-cut', choices=MODES)
parser.add_argument('--model', default='gpt-5.4')
parser.add_argument('--expect-version', default='')
parser.add_argument('--pin-embedded', action='store_true')
parser.add_argument('--timeout', type=float, default=180.0)
parser.add_argument('--max-output-mib', type=float, default=512.0)
args = parser.parse_args(argv)
physical, commit = headroom()
if physical < 8 or commit < 10:
print('blocked: need 8 GiB physical and 10 GiB commit, have %.1f / %.1f'
% (physical, commit))
return 3
work = pathlib.Path(args.work).resolve()
if work.exists():
print('refusing to reuse %s; pass a fresh directory' % work)
return 2
payload = pathlib.Path(args.payload_dir).resolve()
case = work / args.mode
for name in ('home', 'profile', 'appdata', 'local', 'temp', 'logs', 'work', 'info'):
(case / name).mkdir(parents=True)
launcher = work / 'launcher' / pathlib.Path(args.binary).name
launcher.parent.mkdir()
shutil.copyfile(args.binary, launcher)
shutil.copytree(payload, work / 'cache' / 'pkg' / 'win32-x64' / payload.name)
preload = work / 'preload.cjs'
preload.write_text(PRELOAD_JS, encoding='utf-8')
server = Server(('127.0.0.1', 0), Handler)
server.model, server.mode = args.model, args.mode
server.calls, server.lock, server.sequence = [], threading.Lock(), 0
threading.Thread(target=server.serve_forever, daemon=True).start()
base = 'http://127.0.0.1:%d/v1' % server.server_address[1]
try:
code, guard, timed_out = run_child(
build_command(launcher, preload, case, args.model, args.pin_embedded),
build_env(case, work, base, args.model, args.pin_embedded),
case, args.timeout, args.max_output_mib * (1 << 20))
finally:
server.shutdown()
server.server_close()
calls = [call for call in server.calls if 'end' in call]
info = case / 'info' / 'runtime.json'
runtime = json.loads(info.read_text(encoding='utf-8')) if info.is_file() else {}
events = collect(case)
outcome = classify(calls, events, runtime, args.expect_version, guard, timed_out)
child_calls = [call for call in calls if call['role'] == 'subagent']
gaps = [round(child_calls[at]['start'] - child_calls[at - 1]['end'], 3)
for at in range(1, len(child_calls))]
session = events['sources'].get('session', {})
stdout = events['sources'].get('stdout', {})
rows = [
('mode', args.mode),
('loaded payload (modules)', ','.join(runtime.get('loaded') or []) or '?'),
('node', runtime.get('node', '?')),
('outcome', outcome),
('process exit code', code),
('child outbound attempts', len(child_calls)),
('child inter-request gaps', ', '.join(str(gap) for gap in gaps) or '-'),
('reported retries', events['retry'].get('retries', '-')),
('reported retry sleep', events['retry'].get('sleep', '-')),
('advertised tools', sorted({name for call in calls for name in call['tools']})),
('executed tools (dedup)', events['tools'] or '-'),
('subagent.started', session.get('subagent.started', 0)),
('terminal event: stdout', terminal(stdout)),
('terminal event: session', terminal(session)),
('session.error: stdout', stdout.get('session.error', 0)),
('session.error: session', session.get('session.error', 0)),
]
print()
for label, value in rows:
print('%-26s %s' % (label, value))
for label, kind, text in events['errors'][:3]:
print('error [%s] %s: %s' % (label, kind, text[:150]))
print('%-26s %s' % ('artifacts', case))
return 0 if outcome in VALID else 1
if __name__ == '__main__':
raise SystemExit(main())
Type: Bug
Copilot CLI Version:
1.0.84-5(also observed on1.0.81-0and1.0.79-9)OS Version: Windows 11 x64
Model:
gpt-6-astra(also observed on an Anthropic model)Summary
When a model stream ends early, the CLI reports five retries with 5-6 seconds of total retry wait, then stops the background sub-agent's turn. The parent receives a normal completion/idle notification without a failure status.
Found five occurrences in local session history, all on background sub-agent turns.
Steps to Reproduce
The script below reproduces both errors through a real background
taskagainst a loopback provider.successcompletes normally;sse-cutomitsresponse.completed;chunk-cutabandons the chunked body after a valid stream prefix.Running it
No credentials or hosted model are used. The script isolates state, copies the launcher, verifies tool availability and stops below 8 GiB physical or 10 GiB commit headroom. CLI startup network activity was not measured. For
1.0.86-2, I used the older launcher with that payload and omitted--pin-embedded.repro_4911.pyThe originally observed workflow was:
session.errorwith the following completion/idle notification.Actual Behaviour
The failing turn reports:
Responses stream ended without a completed responsestream ended without producing a Message with role=assistantunexpected EOF during chunk size lineThe wait figure is not the total request duration.
Reproducer results
1.0.84-5subagent.completed1.0.86-2subagent.failedBoth faults produce the reported strings verbatim:
Responses stream ended without a completed responseandFailed native model HTTP request: ... unexpected EOF during chunk size line.Measured inter-request gaps were about 1.01-1.03 seconds, not direct measurements of sleep. Versions were checked from loaded native modules.
Observed in practice
The same failure has surfaced three times in my own hosted sessions since 2026-09-17, in the top-level session rather than a sub-agent:
claude-opus-5claude-opus-5gpt-6-astraEach is 6 outbound attempts. It is not specific to one model, and the reported 5.00 s total wait matches the roughly 1 s inter-request gaps the script measures.
The inspected
subagent.completedevent contains usage and timing fields, but no success/error field. In one case it arrived 14 seconds after the error, following 57 minutes and 231 tool calls. In another, the agent went idle less than a second after the error.Expected Behaviour
Notes
v1.0.86was not tested.Impact
Long background work can stop without a usable final response while the parent receives an ordinary completion/idle signal.