Skip to content

Commit da3a42d

Browse files
AdamMaguedclaude
andcommitted
fix(codex_engine): warn on non-numeric response ids; correct stream-limit comment (#6, #8)
#6: a JSON-RPC response with a non-numeric id was logged at debug level and silently dropped, leaving the pending future to resolve only via its 60s timeout. Every id we send is one of our own ints (self._next_id), so this only happens on non-conformant server behavior — worth a warning, not routine tracing noise. Left the pending future alone rather than guessing which request it belonged to (forcibly resolving "the" pending future when exactly one is in flight risks failing an unrelated request if the message turns out to be unrelated noise). #8: the comment on the oversized-line ValueError handler in _read_stdout claimed CPython's StreamReader keeps the buffered data around so subsequent readline() calls "drain the oversized line in fragments". That's not what CPython does: per StreamReader.readline()'s own docstring, on overrun the buffer is either trimmed up to and including the next separator it already contains (clean single-line loss) or cleared entirely if no separator has arrived yet (only the latter case can surface a later fragment, and it self-terminates — no draining loop required). Corrected the comment to describe the actual behavior; no functional change, the recovery loop was already correct. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
1 parent 1cf396d commit da3a42d

2 files changed

Lines changed: 57 additions & 6 deletions

File tree

‎codex_engine/app_server.py‎

Lines changed: 32 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -344,11 +344,24 @@ async def _read_stdout(self) -> None:
344344
try:
345345
raw = await proc.stdout.readline()
346346
except ValueError:
347-
# One line exceeded STREAM_LIMIT. The reader keeps the
348-
# buffered data, so subsequent readline() calls drain the
349-
# oversized line in fragments — each fails JSON parsing and
350-
# is skipped. Degrade gracefully instead of killing the
351-
# turn (C1).
347+
# One line exceeded STREAM_LIMIT. Per CPython's
348+
# StreamReader.readline() docs: "if newline was found,
349+
# complete line including newline will be removed from
350+
# internal buffer. Else, internal buffer will be
351+
# cleared." I.e. on overrun the buffer is NOT preserved
352+
# for us to drain in fragments — it is either trimmed up
353+
# to (and including) the next '\n' it already contains
354+
# (oversized line fully discarded, next readline() starts
355+
# clean on whatever follows), or wiped entirely if no
356+
# '\n' had arrived yet (the remaining tail of that same
357+
# line, still incoming from the child process, gets
358+
# re-accumulated from scratch and returned as a short
359+
# fragment on a later readline() — which fails JSON
360+
# parsing below and is skipped same as any other bad
361+
# line). Either way this ValueError handler doesn't need
362+
# to do any draining itself; `continue` and the normal
363+
# per-line JSONDecodeError handling take care of it.
364+
# Degrade gracefully instead of killing the turn (C1).
352365
logger.warning(
353366
"app-server emitted a line longer than %d bytes; skipping it",
354367
STREAM_LIMIT,
@@ -392,7 +405,20 @@ def _dispatch(self, msg: dict) -> None:
392405
try:
393406
key = int(raw_id)
394407
except (TypeError, ValueError):
395-
logger.debug("app-server response with non-numeric id ignored: %r", raw_id)
408+
# Every id we send is one of our own ints (self._next_id), so
409+
# a non-numeric id here means the server echoed something we
410+
# never sent — non-conformant behavior worth knowing about,
411+
# not routine tracing noise (LOW-MEDIUM #6). Left unresolved
412+
# rather than guessed at: forcibly resolving "the" pending
413+
# future (even when exactly one is in flight) risks failing
414+
# an unrelated in-flight request if this message turns out to
415+
# be unrelated noise rather than a mangled response to it —
416+
# the pending future still resolves via its own 60s timeout.
417+
logger.warning(
418+
"app-server response with non-numeric id ignored (protocol "
419+
"mismatch): %r",
420+
raw_id,
421+
)
396422
return
397423
fut = self._pending.pop(key, None)
398424
if fut is None or fut.done():

‎tests/test_app_server_client.py‎

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -194,5 +194,30 @@ def test_check_schema_drift_gate(self):
194194
self.assertIsNone(msg)
195195

196196

197+
class DispatchNonNumericIdTest(unittest.TestCase):
198+
"""LOW-MEDIUM #6: a response with a non-numeric id is protocol-nonconformant
199+
(every id we send is one of our own ints) and must be logged loudly enough
200+
to notice, not buried at debug level."""
201+
202+
def test_non_numeric_response_id_logs_at_warning(self):
203+
client = AppServerClient(_fake_argv())
204+
with self.assertLogs("kim.app_server", level="WARNING") as cm:
205+
client._dispatch({"jsonrpc": "2.0", "id": "not-a-number", "result": {}})
206+
self.assertTrue(
207+
any("non-numeric id" in line for line in cm.output),
208+
cm.output,
209+
)
210+
211+
def test_non_numeric_response_id_does_not_touch_pending(self):
212+
# Must not guess which pending future this belongs to — an
213+
# unrelated in-flight request should still resolve normally via its
214+
# own matching response (or its own timeout), not be hijacked.
215+
client = AppServerClient(_fake_argv())
216+
client._pending[1] = "sentinel" # type: ignore[assignment]
217+
with self.assertLogs("kim.app_server", level="WARNING"):
218+
client._dispatch({"jsonrpc": "2.0", "id": "abc", "result": {}})
219+
self.assertEqual(client._pending[1], "sentinel")
220+
221+
197222
if __name__ == "__main__":
198223
unittest.main()

0 commit comments

Comments
 (0)