Hacktoberfest 2026: những issue maintainer đã đánh dấu cho tháng Mười, đang mở và phù hợp người mới. Xem issue Hacktoberfest

Background sub-agent stream failures end the turn without a failure status

Đang mở
#4,911 0 bình luận 0 reaction 0 người được giao Xem trên GitHub

Chưa có ai nhận issue này.

Đánh giá

Độ khó
4/5
Thời gian dự kiến
3-5 ngày
Mức phù hợp với người mới
45/100
Loại issue
Lỗi
Độ rõ ràng
Khá rõ ràng
Mức độ hoạt động
Sôi nổi
Công nghệ
python
Lĩnh vực
cli

Hướng nghiên cứu

Start with repro_4911.py and run its success, sse-cut, and chunk-cut modes against the background task entry point. Trace how truncated model streams are retried and how the background sub-agent result is reported to its parent; done means stream failures produce a failure status instead of normal completion or idle notification.

Do mô hình lập chỉ mục viết ra từ nội dung của issue.

Mô tả

triage

Type: Bug

Copilot CLI Version: 1.0.84-5 (also observed on 1.0.81-0 and 1.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 task against a loopback provider. success completes normally; sse-cut omits response.completed; chunk-cut abandons the chunked body after a valid stream prefix.

Running it
$Cli = 'C:\path\to\1.0.84-5\copilot.exe'
$Payload = 'C:\path\to\pkg\win32-x64\1.0.84-5'
foreach ($Mode in 'success', 'sse-cut', 'chunk-cut') {
    $Work = Join-Path $env:TEMP ('repro-4911-' + [guid]::NewGuid())
    python .\repro_4911.py --binary $Cli --payload-dir $Payload `
        --work $Work --mode $Mode --pin-embedded --expect-version 1.0.84-5
}

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.py
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())

The originally observed workflow was:

  1. Start a background sub-agent on a long, tool-heavy task.
  2. A model response stream terminates early.
  3. Compare the session.error with the following completion/idle notification.
Actual Behaviour

The failing turn reports:

Execution failed: Failed to get response from the AI model; retried 5 times (total retry wait time: 5.00 seconds) Last error: Responses stream ended without a completed response (request ...)
Path Last error Reported total retry wait
Responses Responses stream ended without a completed response 5.00 s
Anthropic messages stream ended without producing a Message with role=assistant 6.00 s
Native HTTP unexpected EOF during chunk size line 5.00 s

The wait figure is not the total request duration.

Reproducer results
Loaded payload Success control Both fault modes Persisted child terminal event on failure
1.0.84-5 Completed 6 requests; 5 retries / 5.00 s reported wait subagent.completed
1.0.86-2 Completed 6 requests; 5 retries / 5.00 s reported wait subagent.failed

Both faults produce the reported strings verbatim: Responses stream ended without a completed response and Failed 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:

When (UTC) Model Reported
2026-09-19 00:33:02 claude-opus-5 retried 5 times, 5.00 s total retry wait
2026-09-19 01:01:19 claude-opus-5 retried 5 times, 5.00 s total retry wait
2026-09-21 00:26:37 gpt-6-astra retried 5 times, 5.00 s total retry wait

Each 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.completed event 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
  1. Propagate the failure and its error through the sub-agent completion path.
  2. Use configurable backoff for retryable stream failures, without replaying already completed tool actions.
Notes
  • Related: #1013 and #1372 reported an older stream-completion error. This report adds the retry-wait values and the background sub-agent completion behaviour.
  • The reproducer injects a client-side stream fault; it is not the original upstream cause. The parent reply is scripted, stdout terminal events varied across identical runs, so no exit-code or regression claim is made, and published v1.0.86 was not tested.
  • The failed turn did not produce a usable final response. This does not mean earlier tool changes were rolled back or lost.
Impact

Long background work can stop without a usable final response while the parent receives an ordinary completion/idle signal.

Ngôn ngữ chính
Shell
Star
11.2k
Fork
1.9k
Merge trung bình
14 giờ 16 phút
Pull request đã merge (30 ngày)
6

Hướng dẫn đóng góp

Mở hướng dẫn đóng góp

Bắt đầu từ đâu

  1. Đọc hết issue, rồi đọc hướng dẫn đóng góp của dự án.
  2. Bình luận trên issue rằng bạn sẽ nhận — tránh hai người làm cùng một việc.
  3. Fork repository và làm thay đổi trên một nhánh.
  4. Mở pull request có tham chiếu số hiệu của issue.

Issue khác của github/copilot-cli

Tất cả issue của github/copilot-cli

Issue tương tự

Thêm issue về Shell/Bash

Nhận issue mới trong hộp thư của bạn

Bản tóm tắt ngắn những issue GitHub phù hợp với người mới.