diff --git a/Agent.md b/Agent.md index 60e5ba94..cf5a0440 100644 --- a/Agent.md +++ b/Agent.md @@ -118,7 +118,7 @@ Community needs voiced in HN agent-UI discussions map directly to EMRG's design: pkill -f "emrg.server"; rm -f ~/.emrg/emrgd.port; python -m emrg ``` -Python: `uv run pytest tests/ -v` (871) — import check: `uv run python -c "from emrg.client.app import run_client"` +Python: `uv run pytest tests/ -v` (875) — import check: `uv run python -c "from emrg.client.app import run_client"` GUI: `cd emrg/gui && npm test` (257: 45 daemon_client + 19 conn-manager + 22 app-commands + 129 renderer smoke + 16 i18n + 7 integration + 3 commands + 7 build-config + 7 gui-state + 2 tool-group) — syntax: `node --check main.js preload.js daemon_client.js renderer/js/*.js` CI: `uv run pytest` (ubuntu + **windows-2025 matrix** — Windows pytest 回归在 PR CI 即失败，v0.2.29 教训 #725) + GUI tests + **actionlint workflow lint** (`rhysd/actionlint@v1.7.12` gate, #444 — workflow 解析错误在 PR CI 即失败，如 `if:` secrets 上下文) Re-trigger: `scripts/re-trigger-ci.sh [branch]` (workflow_dispatch, #527 — 替代空 commit 重触发：Actions outage 会整段丢弃 push 事件，dispatch 走 API 路径不受影响) diff --git a/emrg/server/llm.py b/emrg/server/llm.py index 651de208..be6284d7 100644 --- a/emrg/server/llm.py +++ b/emrg/server/llm.py @@ -137,8 +137,13 @@ async def chat( last_error = None for attempt in range(MAX_RETRIES + 1): - logger.debug("LLM request: url=%s model=%s (attempt %d/%d)", - _redact_text(url), self.config.model, attempt + 1, MAX_RETRIES + 1) + # First attempt is the normal path — log nothing (rant + # 2026-08-17T14:27:39: 1/4 on every request is noise); retries + # already log via the "transient error ... retrying" warning, + # this debug line only adds the attempt counter for retries. + if attempt > 0: + logger.debug("LLM request: url=%s model=%s (attempt %d/%d)", + _redact_text(url), self.config.model, attempt + 1, MAX_RETRIES + 1) resp = await client.post(url, headers=headers, json=payload) @@ -236,7 +241,10 @@ async def chat_stream( last_error = None for attempt in range(MAX_RETRIES + 1): - logger.debug("LLM stream attempt %d/%d", attempt + 1, MAX_RETRIES + 1) + # First attempt silent (rant 2026-08-17T14:27:39) — the retrying + # warning already logs the retry; this adds the attempt counter. + if attempt > 0: + logger.debug("LLM stream attempt %d/%d", attempt + 1, MAX_RETRIES + 1) # Reset accumulators before each attempt content_parts[:] = [] tc_by_index.clear() diff --git a/tests/test_llm.py b/tests/test_llm.py index f34f0841..69488a1f 100644 --- a/tests/test_llm.py +++ b/tests/test_llm.py @@ -207,6 +207,7 @@ def __init__(self, status_code: int, content: bytes, headers=None): self.status_code = status_code self.content = content self.headers = headers or {} + self.text = content.decode("utf-8", "replace") class _FakeHttpClient: @@ -267,4 +268,148 @@ def test_chat_malformed_body_exhausts_retries(monkeypatch, client): client._client = fake with pytest.raises(RuntimeError, match="unparseable"): asyncio.run(client.chat([{"role": "user", "content": "hi"}])) - assert fake.calls == 4 # 1 initial + 3 retries + + +class _FakeStreamResponse: + def __init__(self, status_code: int): + self.status_code = status_code + + async def __aenter__(self): + return self + + async def __aexit__(self, *exc): + return False + + async def aread(self): + return b"stream body" + + +class _FakeStreamClient: + def __init__(self, responses): + self.responses = list(responses) + self.calls = 0 + + def stream(self, method, url, headers=None, json=None): + self.calls += 1 + return self.responses.pop(0) + + +def _drain_stream(client, fake) -> list[str]: + """Run one chat_stream call to exhaustion, returning accumulated chunks.""" + import asyncio + parts: list[str] = [] + + async def _run(): + async for chunk in client.chat_stream([{"role": "user", "content": "hi"}]): + if chunk.get("content"): + parts.append(chunk["content"]) + + asyncio.run(_run()) + return parts + + +def test_first_attempt_silent_no_retry(monkeypatch, client, caplog): + """First-attempt (normal) requests log NO attempt line (rant + 2026-08-17T14:27:39) — 1/4 on every request was noise.""" + import logging + import asyncio + caplog.set_level(logging.DEBUG, logger="emrg.server.llm") + body = b'{"choices": [{"message": {"content": "ok"}}]}' + fake = _FakeHttpClient([_FakeResponse(200, body)]) + client._client = fake + asyncio.run(client.chat([{"role": "user", "content": "hi"}])) + assert fake.calls == 1 + # no attempt counter for the first attempt + assert "attempt 1/4" not in caplog.text + assert "LLM request: url=" not in caplog.text + assert "LLM stream attempt" not in caplog.text + + +def test_retry_logs_attempt_counter(monkeypatch, client, caplog): + """Retries DO log the attempt counter (attempt 2/4+) alongside the + existing transient-error warning — the retry path stays traceable.""" + import logging + import asyncio + _patch_fast_sleep(monkeypatch) + caplog.set_level(logging.DEBUG, logger="emrg.server.llm") + good = b'{"choices": [{"message": {"content": "recovered"}}]}' + fake = _FakeHttpClient([ + _FakeResponse(500, b"boom"), + _FakeResponse(200, good), + ]) + client._client = fake + asyncio.run(client.chat([{"role": "user", "content": "hi"}])) + assert fake.calls == 2 + # first attempt silent; retry logs the attempt counter + transient warning + assert "attempt 1/4" not in caplog.text + assert "LLM transient error 500" in caplog.text + assert "attempt 2/4" in caplog.text + + +def test_stream_first_attempt_silent(monkeypatch, client, caplog): + """chat_stream's first attempt is also silent (rant 2026-08-17T14:27:39).""" + import logging + _patch_fast_sleep(monkeypatch) + caplog.set_level(logging.DEBUG, logger="emrg.server.llm") + + class _GoodStream: + status_code = 200 + headers = {} + + async def __aenter__(self): + return self + + async def __aexit__(self, *exc): + return False + + async def aiter_lines(self): + import json + for obj in ( + {"choices": [{"delta": {"content": "hi"}}]}, + {"choices": [{"delta": {}, "finish_reason": "stop"}]}, + ): + yield "data: " + json.dumps(obj) + + fake = _FakeStreamClient([_GoodStream()]) + client._client = fake + parts = _drain_stream(client, fake) + assert parts == ["hi"] + assert fake.calls == 1 + assert "LLM stream attempt" not in caplog.text + + +def test_stream_retry_logs_attempt_counter(monkeypatch, client, caplog): + """chat_stream retry logs the attempt counter (attempt 2/4).""" + import logging + _patch_fast_sleep(monkeypatch) + caplog.set_level(logging.DEBUG, logger="emrg.server.llm") + + class _GoodStream: + status_code = 200 + headers = {} + + async def __aenter__(self): + return self + + async def __aexit__(self, *exc): + return False + + async def aiter_lines(self): + import json + for obj in ( + {"choices": [{"delta": {"content": "hi"}}]}, + {"choices": [{"delta": {}, "finish_reason": "stop"}]}, + ): + yield "data: " + json.dumps(obj) + + fake = _FakeStreamClient([ + _FakeStreamResponse(500), # first attempt → retry + _GoodStream(), # second attempt → success + ]) + client._client = fake + parts = _drain_stream(client, fake) + assert parts == ["hi"] + assert fake.calls == 2 + assert "LLM stream attempt 2/4" in caplog.text + assert "attempt 1/4" not in caplog.text + assert "LLM stream transient error 500" in caplog.text