fix(chat): treat absent client timeout as no deadline, not expired - #185
Conversation
All three code sites match the proposal's documented line numbers (no drift since the proposal was written): - app.py:1710 unguarded check in _prepare_chat_context - app.py:4652-4655 if-x-else-0 coercion in _parse_chat_request - app.py:2156 guarded streaming twin Arithmetic check for (sent, timeout) triples confirms the bug reproduces in all three cases (now ≈ 1785650932): (None, None) → s=0, t=0, now-s=1785650932 > 0 → True (1769900000000, None) → s=1769900000, t=0, now-s=15750932 > 0 → True (None, 600000) → s=0, t=600, now-s=1785650932 > 600 → True Ralph-Task: 1.1, 1.2 — confirm premise on current tree
Creates tests/unit/test_chat_timeout_guard.py with the module docstring and stub-self wrapper matching the pattern in test_chat_refresh_context.py. No test cases yet; those follow in tasks 2.2–2.4. Ralph-Task: 2.1 Create tests/unit/test_chat_timeout_guard.py with stub wrapper
Before this fix, `_prepare_chat_context` ran an unguarded comparison:
if server_received_msg_ts.timestamp() - client_sent_msg_ts > client_timeout:
return None, 408
When both fields are absent (coerced to 0 by `_parse_chat_request`), elapsed
time is ~now.timestamp() >> 0, so the check always fires and every request
without explicit timing is rejected with 408.
Observed failures before the fix (tasks 2.2 and 2.3):
FAILED test_both_absent_does_not_return_408 - assert 408 != 408
FAILED test_timeout_only_does_not_return_408 - assert 408 != 408
FAILED test_timestamp_only_does_not_return_408 - assert 408 != 408
The fix wraps the comparison in `if client_sent_msg_ts and client_timeout and ...`,
matching the streaming twin at app.py:2156 (`if client_timeout and ...`).
Cross-reference comments added at both sites noting the shared convention and the
deliberate baseline difference (client send time vs stream_start_time).
The refresh-context test _prepare() docstring is updated to describe the timing
pair as a valid in-window deadline rather than a workaround for a live defect.
Gate: 1577 passed, diff coverage on app.py 100%, black --check clean.
Ralph-Task: 2.2 add failing test for both fields absent (+ 2.3, 2.4, 3.1, 3.2, 3.3, 4.1 completed in same commit — gate requires green before commit)
Change the Required column for client_sent_msg_ts and client_timeout from "yes, in practice" to "no", and rewrite both descriptions to focus on what the fields are for (latency accounting and declaring a deadline the server honours when supplied) rather than rejection for omission. Ralph-Task: 5.1 In docs/docs/api_reference.md, change the Required column for client_sent_msg_ts and client_timeout from yes, in practice to no, and rewrite both descriptions
The "how the rejection reaches you differs by endpoint" sub-section from the warning admonition is now embedded in the streaming endpoint's own error-channel warning, replacing the stale "described above" reference. Reworded from bug-framing to explicit-deadline-framing: the 408 is what the server reports when the caller *did* supply both timing fields and the deadline has elapsed. [streamerr] is retained because the relocated paragraph still uses it. Ralph-Task: 5.2 Before deleting the warning admonition, lift out the "How the rejection reaches you differs by endpoint" sub-section and relocate it to the streaming endpoint's own section.
The "look optional and are not" framing, the three-row reproduction table, the unguarded comparison snippet, and the bug-tracker paragraph in the warning admonition are all artefacts of a now-fixed defect. The "how rejection reaches you" sub-section was already relocated to the streaming endpoint's section (task 5.2). Remove the remainder. The link definitions ([parse], [check], [streamerr], [stream]) remain for now — task 5.4 audits which are still in use before removing any. Ralph-Task: 5.3 Delete the rest of the admonition
The admonition deleted in the previous commit owned four reference-link definitions. [streamerr] is still used by the relocated streaming-error sub-section, so it is kept. [parse], [check], and [stream] are now defined but never referenced, so they are removed. Verified with a regex scan: no dangling uses, no orphaned definitions remain on the page. Ralph-Task: 5.4 Clean up the reference-link definitions the admonition owned (`[parse]`, `[check]`, `[streamerr]`, `[stream]`)
The introductory paragraph before the runnable curl example said `client_sent_msg_ts` "has to be generated as you send", implying the field is required. Since the fix landed both timing fields are optional; the paragraph now says so and explains that when both ARE present the timestamp must be fresh — a stale literal plus a live client_timeout is an already-expired deadline and returns 408. The curl example and shape template themselves were already correct: both retain the two optional fields and the example uses date +%s000 rather than a literal, so a reader who copies it directly always sends a live timestamp. Ralph-Task: 5.5 Check the runnable curl example and shape template
…equired The POST /api/get_chat_response_stream section described the body as including "the two required timing fields". After task 5.1 marked both fields optional in the request table, this cross-reference became inconsistent. Change to "the two optional timing fields". Grepped the full docs/ tree for remaining "required"/"408" claims against client_sent_msg_ts and client_timeout — this was the only remaining instance. Ralph-Task: 5.6 Grep the whole docs/ tree for any other claim that the timing fields are required or that omitting them yields 408, and correct anything found.
|
@codex review |
|
Harness follow-up filed as #186 — installs the |
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 9b0980be54
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| client_sent_msg_ts | ||
| and client_timeout |
There was a problem hiding this comment.
For a streaming request that supplies client_timeout but omits client_sent_msg_ts, this new guard allows the request through as having no declared deadline, but the later check at app.py:2170 still uses the nonzero timeout and emits 408 once the stream exceeds it. This contradicts the new timeout-only contract and makes the same payload behave differently between the streaming and non-streaming endpoints; propagate whether both fields were supplied to the streaming check, or disable that check when the timestamp is absent too.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Verified this against both call sites, and it splits: the description is accurate, the proposed remedy would introduce the bug it is trying to prevent. Not fixing the code; fixed the documentation gap underneath it and added the test that was missing.
Why the two guards differ on purpose. They enforce different deadlines from different baselines:
_prepare_chat_context(app.py:1715) asks "had the client already given up before we started?" — it measuresserver_received_msg_ts - client_sent_msg_ts. With noclient_sent_msg_tsthere is no baseline, and the comparison would run from the Unix epoch and reject every request. Hence both fields required.- the in-stream check (
app.py:2170) asks "has this stream outrun the client's budget?" — it measures fromstream_start_time, a server-side clock. A declaredclient_timeoutis fully enforceable there with no client timestamp at all.
So client_sent_msg_ts being absent doesn't mean "no declared deadline" — it means one specific deadline is unmeasurable. The client did declare a timeout. Applying the suggested change ("disable that check when the timestamp is absent too") would silently discard a budget the caller explicitly asked the server to honour, which collides with this change's own second requirement, "An explicitly-supplied client deadline is still enforced".
The spec added by this PR also rules on it directly — specs/chat-api-request-contract/spec.md:64-79 requires each check to carry a comment naming its twin and recording "that the differing baselines are deliberate, not a bug to be 'fixed' by making them identical". Both comments were already there; they were what the review read as a contradiction.
What was genuinely missing, now fixed.
- The behaviour was untested, which is why "make them consistent" looked harmless.
tests/unit/test_chat_timeout_guard.pycovered only_prepare_chat_context; nothing exercised the in-stream guard.TestTheInStreamCheckNeedsOnlyTheTimeout(2f2c5729) drivesChatWrapper.streamwithclient_timeout=600andclient_sent_msg_ts=0and asserts the in-band 408 event still arrives, plus the converse for a falsey timeout. I confirmed it discriminates by applying your suggested condition verbatim — that test fails, the other six pass — then reverted. - The docs never mentioned the second deadline. The
client_timeoutrow said only that the deadline applies "when both this andclient_sent_msg_tsare supplied", so a reader would reasonably conclude a loneclient_timeoutdoes nothing. It now states that the streaming endpoint additionally caps the stream from the moment it opens, and that a loneclient_timeoutstill ends an over-long stream. That is the asymmetry you identified, documented rather than removed.
On "the same payload behaves differently between the streaming and non-streaming endpoints": true, and inherent rather than introduced here. The non-streaming endpoint has no in-flight phase to bound — it returns one response — so it has no equivalent check to run, before or after this PR.
| response is constructed. **How that rejection reaches you differs by endpoint:** on | ||
| `POST /api/get_chat_response` it is a real **HTTP 408** with `{"error": ...}`; here it | ||
| arrives as **HTTP 200** followed by the in-band event | ||
| `{"type": "error", "status": 408, "message": ...}` ([`app.py:2075`][streamerr]). A |
There was a problem hiding this comment.
The nine inserted lines before the streaming handler shift every subsequent app.py line anchor, but this relocated timeout documentation retains the old anchors. For example, [streamerr] still targets line 2075, which now contains the is_refresh argument rather than the error event now at line 2084; the other references after this insertion are similarly displaced, so readers following the API reference no longer reach the code supporting its claims.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Confirmed and fixed in 6fbfb90c. The scale was larger than the example suggested: 28 of the 30 link definitions were stale, plus ~25 inline prose refs.
Rather than shift by hand I rebuilt the old→new line map with difflib.SequenceMatcher against origin/dev's app.py and applied it, asserting for every anchor that the target line's text is byte-identical to what it was before the change. Two distinct shifts, matching the two insertions: +9 for anchors between the deadline guard and the streaming loop, +14 below the loop. [ovrimport] (L1645) and [refreshguard] (L1694) sit above the first insertion and correctly did not move.
[streamerr] is exactly as you described — L2075 → L2084, which is again the yield { of the error event.
Worth flagging one trap: a naive content match resolves [thinkgate2] wrongly. Its old target L2414 still contains if include_tool_steps: in the new file — because [thinkgate]'s target moved into L2414. The correct target is L2428. The diff-based map gets this right; a search-and-replace would not have.
Two things I did not change, deliberately:
- The
openspec/changes/fix-issue-175-.../artifacts. They cite pre-change lines (app.py:1710,app.py:2156,app.py:4654-4655) while describing where the defect was. Rewriting those to post-change numbers would make the "before" narrative describe code that never looked like that. Say the word if you'd rather they were repointed. - The anchors' underlying fragility. Filed as Make the api_reference.md app.py line anchors self-verifying #190 instead. Relevant here: PR fix(chat): redirect unauthenticated browser requests to login #184 inserts lines at ~
app.py:3506, so whichever of fix(chat): redirect unauthenticated browser requests to login #184 and fix(chat): treat absent client timeout as no deadline, not expired #185 merges second re-stales[clientid](L4802),[evmeta](L4819) and[streamopen](L4846). This is the second drift since fix(chat): correct last_message docstring to nested pair shape #159 introduced the anchors, and hand-repair does not converge on a file two branches are both editing. Make the api_reference.md app.py line anchors self-verifying #190 carries the options and the policy question (a strict guard makes every line-shiftingapp.pychange a docs change too).
Also repointed the two cross-reference comments this PR added — they named app.py:2156 and app.py:1710, the pre-change locations of the very lines they were inserted next to — and the same stale anchor in the test module's docstring.
the nine lines added before the streaming handler moved every later anchor by 9 or 14 lines, so 28 of 30 link definitions and the prose refs pointed at the wrong code. the two new cross-reference comments named pre-change lines as well.
nothing covered the streaming check, so making the two guards identical would have looked harmless. this fails if the timestamp is required there.
the check sits in the consume loop, so it bounds a slow stream but not a provider that stalls before yielding. the row claimed a cap it does not deliver; #191 tracks making it one. anchors repointed for the 3 added lines.
|
Review round 1 — reviewed
On the P2. The description is right, the proposed remedy would introduce a bug. The two guards measure different deadlines from different baselines: On the P3, larger than the example suggested: 28 of 30 link definitions were stale, plus ~25 prose refs. Repointed via a
|
|
Review round 2 — reviewed One finding, no inline thread to reply in, so the reasoning is here.
The finding is correct. The check sits in the body of Two things it gets wrong about scope, worth recording so the next reader doesn't re-litigate them:
Where the review landed a hit on my own round-1 work: the docs row I added said
|
|
@codex review |
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 625a204308
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| if ( | ||
| client_sent_msg_ts | ||
| and client_timeout | ||
| and server_received_msg_ts.timestamp() - client_sent_msg_ts > client_timeout |
There was a problem hiding this comment.
When a request omits client_sent_msg_ts, this new guard allows it to complete while _parse_chat_request still represents the missing value as 0; both completion paths then convert that sentinel with datetime.fromtimestamp(0) and persist it (app.py:2549-2555 and app.py:4758-4761). Consequently, every newly accepted timestamp-less request records 1970-01-01 as its actual send time, corrupting the latency data that the API reference says this field supplies. Preserve the absence through timing persistence—such as by making the column nullable, skipping the timing row, or recording an explicit server-side fallback—instead of storing the epoch as a real measurement.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
PARTIAL — the mechanism is real and this PR is what makes it reachable, but two of the three remedies you offer are worse than the status quo and the third cannot ship here. Specified the sentinel instead, and deferred the schema fix to #193.
Verified, all three sites. _parse_chat_request coerces the absent field at app.py:4680, and both completion paths convert and persist it — app.py:2550 (streaming, via insert_timing under if message_ids:) and app.py:4767 (non-streaming). datetime.fromtimestamp(0, tz=timezone.utc) is 1970-01-01T00:00:00Z, and the row is written.
And it is genuinely new, not pre-existing. On dev the guard is unconditional:
app.py:1711 if server_received_msg_ts.timestamp() - client_sent_msg_ts > client_timeout:
With either field absent both operands are 0, so now - 0 > 0 is true and the request 408s. Both entry points route through _prepare_chat_context, and both return before persistence on a non-None error code — so no timestamp-less request has ever reached insert_timing through these endpoints. Accepting them is exactly what exposes the epoch. That makes it this PR's to answer, and I'm not claiming otherwise.
One claim narrowed. No shipped consumer computes latency from the column. src/cli/templates/grafana/archi-default-dashboard.json keys off server_received_msg_ts and msg_duration only, and msg_duration is server_response_msg_ts - server_received_msg_ts (app.py:1519) — this column appears in neither. So the damage is bounded to the raw column rather than to anything currently plotted. Real, but smaller than "corrupting the latency data".
Why not each of your three remedies:
- Make the column nullable — the correct end state, and it cannot ship here.
timing.client_sent_msg_tsisTIMESTAMPTZ NOT NULL(src/cli/templates/init.sql:476), so writingNoneraisesNotNullViolation; in the non-streaming path thatinsert_timingcall is outside thetry, so a legal request would 500. It needs a migration, and last_modified migration is never applied to existing deployments (ingest then silently no-ops) #180 records that migrations are not applied to existing deployments — so the code change would land while the schema change didn't, converting a data-quality defect into an outage. Filed as Make timing.client_sent_msg_ts nullable so an absent send time is NULL, not the epoch #193, explicitly blocked on last_modified migration is never applied to existing deployments (ingest then silently no-ops) #180. - Skip the timing row — trades ten real measurements for one absent field. The nine server-side milestones plus
msg_durationare precisely what the dashboards plot; dropping the row blinds them for every request from an uninstrumented API client. - Record an explicit server-side fallback — the worst of the three.
server_received_msg_tsin that slot reads as a genuinely instantaneous client→server hop, and no query can tell it apart from a real fast request. That is the silent-corruption shape this repo has been removing elsewhere — Make ImportError during provider construction emit a warning instead of silently using the default model #178, merging in parallel, exists to stop a failure looking like a success.
What landed instead. Within the existing schema there are exactly two options that keep the row, and neither can express "unknown" — so the honest move is to make the epoch a specified sentinel rather than an accident of a falsey-coalesce:
5872eb1b— a spec requirement ("A timing row records an absent client send time as a specified sentinel") that mandates the epoch, forbids a server-side substitute by name, and requires the value be documented; plustests/unit/test_chat_timing_persistence.py, three tests including one asserting the sentinel is notserver_received_msg_tsand one proving a supplied value is not flattened to it.30ca86da— the request-body table now states that omitting the field stores1970-01-01T00:00:00Zmeaning "the client declared no send time", and tells callers to exclude it when computing client→server latency.
These are characterization tests, not TDD — no behaviour changed, so there was no red step to earn. #193 has the red test waiting: flip test_the_absent_send_time_is_the_epoch_and_not_a_server_side_substitute and the implementation follows.
Gate on 0365a07d: 1667 passed, 1 xfailed, diff coverage 100%.
…tinel Merging dev brought PR #184's app.py delta, which shifted all 30 anchors this branch had just repaired; retargeted by content-mapping every anchor against 625a204 and asserting each target line is byte-identical. Also documents what the timing row stores when the client supplies no send time.
A request omitting client_sent_msg_ts now completes, so it reaches insert_timing for the first time. The column is TIMESTAMPTZ NOT NULL, so specify the epoch as the sentinel rather than leaving it an accident of the falsey-coalesce, and prove a supplied value is not flattened to it. Nullable column deferred behind #180.
…behind Round 1 moved the link definitions but left 14 of the visible [`app.py:nnn`] numbers at base numbering, so the page displayed one line and linked to another. Repaired per reference from whichever revision it was last correct at, content- verified, plus the range form a single-number pattern skips.
|
Review round 3 — reviewed Round 2's re-request landed a verdict at 09:00Z, after the 04:00 unattended pass had exited. Worked on demand.
The P2 splits. The mechanism is real and this PR is what makes it reachable — on Two findings I raised against my own earlier round. Merging
|
|
@codex review |
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 0365a07de6
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| - [x] 6.1 Run `bash scripts/gate.sh` **bare** — no pipe, no redirect, since redirecting it | ||
| trips the harness protected-path guard and reads as a failure that is not one. It must | ||
| pass format, lint and tests. |
There was a problem hiding this comment.
I checked the added verification plan and the commit's Verification section; they record the unit gate, diff coverage, and OpenSpec validation, but no end-to-end request against a named running service or corresponding logs/events. Because this changes two public endpoint paths, stubbed method tests cannot confirm that the deployed service imports this workspace code or that omission survives route parsing and persistence; run at least one timestamp-less request against the active deployment and record the observed non-streaming response or streaming events.
AGENTS.md reference: AGENTS.md:L43-L45
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
PARTIAL — the gap is real and I closed the part that is closable from here; the deployed-instance part is a human step, and I have written the exact commands rather than hand-waving at it.
Agreed on the premise. The existing tests drive _prepare_chat_context and stream with stubbed collaborators, so they prove the guard's logic and nothing about two seams that sit outside it: whether an omitted JSON key survives decoding into the value the guard sees, and whether the handler wiring carries that value through to persistence.
What I closed. tests/unit/test_chat_timing_field_validation.py runs the real _parse_chat_request against a real JSON body inside a Flask request context, then the real handler, stubbing only the pipeline and the database. So a body with neither timing field is decoded by production code, reaches self.chat(...) as 0/0, and insert_timing is asserted to have been called with the epoch sentinel and a later server_response_msg_ts. Route parsing → handler → persistence wiring is now covered by an automated test.
What I cannot close, and why it is not stubbornness. The deployment installs the package non-editable (pip install .), so the running service does not contain this branch and will not until it is redeployed — a request against it today exercises dev, and would "pass" while telling us nothing about this change. Redeploying the live dev chat service for an unmerged PR is a human decision, not something a review pass should do on its own initiative, and deploy/** is outside this PR's scope besides. This is the same class as the finding on #184 that ended in "no commit can close this."
For whoever merges — against an auth-disabled instance, or with a session cookie:
H='Content-Type: application/json'
B='http://localhost:7861' # or the dev host
# 1. both timing fields omitted -> expect HTTP 200 and a response body (was 408)
curl -sS -D- -o- $B/api/get_chat_response -H "$H" \
-d '{"last_message":[["User","how do I submit a job?"]],"client_id":"verify-175"}'
# 2. client_timeout only, no timestamp -> expect 200, not 408
curl -sS -D- -o- $B/api/get_chat_response -H "$H" \
-d '{"last_message":[["User","hi"]],"client_id":"verify-175","client_timeout":600000}'
# 3. streaming, both omitted -> expect NDJSON ending in a "final" event, no 408
curl -sS -N $B/api/get_chat_response_stream -H "$H" \
-d '{"last_message":[["User","hi"]],"client_id":"verify-175"}'
# 4. unrepresentable timestamp -> expect 400 naming client_sent_msg_ts, no generation
curl -sS -D- -o- $B/api/get_chat_response -H "$H" \
-d '{"last_message":[["User","hi"]],"client_id":"verify-175","client_sent_msg_ts":-100000000000000000000}'
# 5. the row it wrote: epoch in client_sent_msg_ts, every other column a real time
psql "$ARCHI_DSN" -c "select message_id, client_sent_msg_ts, server_received_msg_ts, msg_duration
from timing order by message_id desc limit 3;"Expected: 1–3 answer, 4 is 400, and 5 shows 1970-01-01 00:00:00+00 for requests 1–3 with plausible values in every other column. If auth is enabled the calls need a session cookie first (POST /login) — otherwise they return 401/302 and prove nothing about the handler, which is precisely the trap the #184 finding fell into.
Recorded as unchecked task 6b.4 in tasks.md so it does not disappear into a thread.
| - [ ] 6.4 Run `openspec validate fix-issue-175-optional-client-timeout --strict` and confirm it | ||
| passes. |
There was a problem hiding this comment.
The commit message says the strict OpenSpec validation passed on the host, yet task 6.4 remains unchecked. The repository's OpenSpec verification workflow interprets every - [ ] task as a critical incompleteness and the archive workflow warns before proceeding, so leaving this stale checkbox makes an implemented change appear unfinished; mark the task complete now that the stated validation has succeeded.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
VALID — fixed in 8a1344a1. Both 6.4 and 6.5 had in fact been done and I left the boxes unticked: openspec validate fix-issue-175-optional-client-timeout --strict passes, and the branch is pushed with an open PR carrying closes #175. Ticked.
One deliberate exception, so the archive warning keeps meaning something: the new 6b.4 is unchecked on purpose. It is the live-deployment validation from your P1 in this same round, which is a real open task for a human rather than a stale box — see that thread for why it cannot be closed from here. If every box were ticked, that requirement would silently vanish; leaving it open is the point.
| client_sent_msg_ts | ||
| and client_timeout | ||
| and server_received_msg_ts.timestamp() - client_sent_msg_ts > client_timeout |
There was a problem hiding this comment.
When a caller supplies a sufficiently old integer timestamp, such as client_sent_msg_ts=-100000000000000000000, while omitting client_timeout, this new condition skips the only early rejection and runs the full pipeline. Both completion paths then call datetime.fromtimestamp (app.py:2550 and app.py:4767), which raises OSError for that value, so the non-streaming route returns 500 and the streaming operation fails only after doing the expensive generation work; previously the unguarded comparison returned 408 before invoking the pipeline. Validate that a supplied timestamp is representable before treating the missing timeout as disabling the deadline.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
VALID — fixed in 8a1344a1. Reproduced at the route level, and it is worse than described on the streaming side.
Reproduced. New tests drive the real _parse_chat_request against a real JSON body. Before the fix, client_sent_msg_ts=-100000000000000000000 with no client_timeout gives:
OSError: [Errno 75] Value too large for defined data type
One correction to the streaming half. You describe it as failing "only after doing the expensive generation work" — on that route the caller has also already been told it succeeded. The raise happens inside _event_stream, after the response object is returned, so the pre-fix test observed <Response streamed [200 OK]> and the failure lands mid-stream. That is a worse shape than the non-streaming 500.
And the range has three exception families, not one. Measured on this platform, py3.11:
client_sent_msg_ts (ms) |
raises |
|---|---|
-100000000000000000000 |
OSError [Errno 75] — beyond time_t |
-62135596801000 |
ValueError: year 0 is out of range |
253402300800000 |
ValueError: year 10000 is out of range |
10**30 |
OverflowError: timestamp out of range for platform time_t |
So a hardcoded bound would have to track three failure modes and stay in sync with datetime's platform-dependent limits. The guard is therefore the conversion itself — check_client_sent_msg_ts attempts datetime.fromtimestamp(seconds, tz=timezone.utc) and converts any of the three into InvalidClientTimestamp. It cannot disagree with the two sites it protects about where the boundary is, because it performs the same operation.
Not all of it is new, though. The negative case is this PR's doing, as you say. The positive overflow is not: on dev, now - 1e27 > timeout is false, so the unconditional check never fired for it either and dev crashes the same way today. One check closes both.
Why 400 rather than restoring 408 or treating it as absent. 408 says "you were late"; a value outside the representable range is not late, it is malformed — same class as the last_message shape check that already returns 400. And treating it as absent would silently record the epoch sentinel for what is really a client bug, which is the failure mode #178 exists to remove. So: check_client_sent_msg_ts lives in request_validation.py next to parse_last_message, and both handlers call it inside the same try that already produces the 400 — which is before self.chat(...), so nothing is generated and no conversation row is written.
Tests: tests/unit/test_chat_timing_field_validation.py — all four values × both routes, asserting 400 and that the pipeline was never called, plus a representable-timestamp case proving the guard rejects only what cannot be converted.
Gate on 8a1344a1: 1677 passed, 1 xfailed, diff coverage 100% on 16 changed lines.
| events = self._run(monkeypatch, 0, 0) | ||
|
|
||
| assert not any( | ||
| event.get("type") == "error" and event.get("status") == 408 | ||
| for event in events |
There was a problem hiding this comment.
In the client_timeout=0 case, the stubbed pipeline output is a SimpleNamespace without the .get() method that stream() calls at app.py:2531, so this helper actually finishes with an in-band 500 error. The assertion checks only that the error is not 408, allowing the test named “lets the stream run” to pass while the stream crashes; use an output implementing the production interface and assert that a final event, rather than any error event, is emitted.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
VALID — fixed in f629bffd. Reproduced exactly as described, and this was a test my own round-1 pass added, so the miss is mine.
What that test actually did. Running the helper and printing every event, pre-fix:
Failed to stream response: 'types.SimpleNamespace' object has no attribute 'get'
File ".../app.py", line 2531, in stream
last_output.get("source_documents", []) if last_output else []
AttributeError: 'types.SimpleNamespace' object has no attribute 'get'
{'type': 'error', 'status': 500, 'message': 'server error; see chat logs for message'}
One event, and it is a 500. The stream named "lets the stream run" never ran.
Fixed both halves. _FakeOutput now implements the two members stream reads off an output — .metadata and .get — and the assertion is the whole event sequence rather than the absence of one status:
assert [event.get("type") for event in events] == ["chunk", "final"]
assert not any(event.get("type") == "error" for event in events)Verified it discriminates. Restored the old SimpleNamespace stub and re-ran that single test: 1 failed. Then restored the fix: 7 passed. So the assertion now fails for the reason it is supposed to catch.
The general shape is worth naming, because it will recur in this file: an assertion phrased as "no 408" passes for every failure that is not a 408 — including the ones that mean the code under test was never reached. A negative assertion about one status is not a substitute for a positive assertion about the outcome. The sibling test in the same class (test_timeout_without_a_timestamp_still_ends_the_stream_with_408) is safe because it asserts a specific terminal event; this one was not.
Gate on 8a1344a1: 1677 passed, 1 xfailed.
The stub output was a SimpleNamespace with no .get, so finalization raised and the stream ended in an in-band 500 -- while the assertion, phrased as "no 408", passed anyway. Give the stub the production interface and assert the sequence is chunk then final. Verified it discriminates by restoring the old stub.
The unconditional deadline check used to screen absurd timestamps out by accident. Making it conditional lets them reach datetime.fromtimestamp at persistence time, where they raise OSError/OverflowError/ValueError -- a 500 after generation on the non-streaming route, and a mid-stream failure after HTTP 200 on the streaming one. Screen at both handlers before the pipeline, by attempting the conversion rather than hardcoding a range so the guard cannot disagree with the sites it protects.
|
Review round 4 — reviewed
Two of these were defects in my own earlier rounds, and both were the same mistake in different clothes — asserting the absence of one failure instead of the presence of the outcome. The no-timeout stream test checked "no 408" and passed while the stream died of an The out-of-range timestamp is the substantive one. Reproduced at the route level; the range has three exception families (
|
|
@codex review |
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 8a1344a199
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| # Screened here, not at the deadline check: an unrepresentable timestamp used | ||
| # to be caught by the unconditional 408 and now would raise from | ||
| # datetime.fromtimestamp at persistence time, after generation. | ||
| check_client_sent_msg_ts(client_sent_msg_ts) |
There was a problem hiding this comment.
For a valid JSON integer large enough to overflow float conversion, such as a 1,001-digit client_sent_msg_ts, _parse_chat_request raises OverflowError at client_sent_msg_ts / 1000 before either newly added validation call is reached. Both endpoints therefore return 500 instead of the newly documented 400 for an unrepresentable integer timestamp; validate the raw millisecond value or catch overflow during normalization before invoking the pipeline.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
VALID — fixed in 26c86686. This is a hole in the round-4 fix, not an independent finding: I put the range check after the division, and the division is the thing that raises.
Confirmed.
>>> int("9" * 1001) / 1000
OverflowError: integer division result too large for a floatRaised inside _parse_chat_request, which both handlers call before entering the try that produces the 400 — so an uncaught 500 on a well-formed JSON body, and on the streaming route the caller gets the 500 in place of the documented 400.
Restructured rather than patched. The lesson is that normalizing and validating cannot be separated when the normalization is itself failable, so they now happen in one guarded step: parse_client_sent_msg_ts and parse_client_timeout in request_validation.py own the ms→s division and the range check, raising InvalidClientTiming; _parse_chat_request calls them; and the handlers wrap the parse call. The second check I added in round 4 is gone — one place owns turning payload timing into usable seconds or refusing it. (InvalidClientTimestamp renamed to InvalidClientTiming accordingly; it never merged, so the rename is free.)
Two extensions past what you flagged, both the same defect class:
client_timeoutis divided identically and was equally exposed. It needs no range check — it is only compared against an elapsed interval, so any magnitude a float holds is meaningful — butparse_client_timeoutguards the division. Your report named onlyclient_sent_msg_ts.TypeError, not justOverflowError. A quoted number ("client_sent_msg_ts": "1700000000000") or any non-numeric JSON value hitsunsupported operand type(s) for /. That one is pre-existing ondev, not introduced here, but it is the same 500 from the same line and the same guard closes it. Returning 400 is right: the API documents these as JSON numbers.
Tests: TestNormalizationItselfCannotRaise — 5 values × both routes, all previously 500s, each asserting 400, that the error names the offending field, and that the pipeline was never invoked; plus a normal-timeout case asserting 600000 still arrives as 600.0.
Separately, and worse: your review made me re-check the anchors and the round-4 commit had staled all of them. 8a1344a1 added lines to both handlers and I did not re-map the page — all 31 definitions and 43 inline numbers were wrong, with [sentinel] pointing at a blank line. Repaired in 21457787 and audited: no dangling uses, no orphaned definitions, no definition on a blank line, and exactly the four intended second citations.
That is the third hand-repair of this page in this PR (round 1 moved definitions and left the prose; round 3 mis-referenced two range forms; round 4 forgot to re-map after changing app.py). Three different mistakes, one cause: nothing checks these anchors, so the only detector is a reviewer noticing. #190 is that check, and it should land before this page is edited again.
Gate on 21457787: 1688 passed, 1 xfailed, diff coverage 100% on 36 changed lines. openspec validate … --strict passes.
A range check placed after the division never runs when the division is what raises: a 1001-digit JSON integer overflows float, and a quoted number is a TypeError, so both endpoints returned 500 instead of the documented 400. Normalization and validation now happen in one guarded step, and client_timeout gets the same treatment -- it needs no range check but is divided identically.
|
Review round 5 — terminal: handed to a human at the round bound. Reviewed
Round 4 put the range check after the ms→s division, and the division is what raises:
Why this stops hereRound 5 is past the 4-round bound, and I worked it anyway because the finding was a defect in round 4's own fix rather than new ground. It stops now, on a specific signal rather than a counter: #190 is that missing check. It should land before this page is edited again — including before this PR merges, if the merge order puts #188 first and re-stales these numbers a fourth time. Everything found across five rounds has a disposition. Next verdict goes to a human, not another fix cycle. |
#185 merged (dd3fb6b) and rewrote the same page, so 17 hunks conflicted. Took dev throughout -- 'ours' still carried the required-timing-fields warning #185 deliberately deleted, so keeping it would have reverted a merged fix -- then re-applied this PR's two deltas (drop the ImportError row and its [ovrimport] definition) and retargeted every anchor against the merged app.py. Neither side's numbers were right: they belong to the merged tree, which is neither parent. app.py auto-merged; the deletion survives and #185's new code is intact.
1 participant
Closes #175.
Why this PR is opened late
The implementation for #175 completed and went green during the 2026-08-02 02:00 nightly
run, but the loop halted one task short of opening its PR: the task list included an
openspec validate … --strictstep, and theopenspecCLI exists on the host but notinside the loop container. The loop can neither run nor skip a verification step, so it
recorded a blocker and stopped — correct behaviour, wrong environment. The issue was parked
needs-humanand ten green commits sat on a branch with no PR.Nothing was wrong with the fix. Re-verified on the current
devtonight before opening this:1577 passed, 1 xfailed, diff coverage 100%, no conflicts. See the harness note at the
bottom.
The bug
/api/get_chat_responseand/api/get_chat_response_streamreturned HTTP408to anycaller that omitted
client_sent_msg_tsorclient_timeout. Both fields are coerced to0,then compared with an unguarded:
which is true on every request. The streaming loop asks the same question with a guard
(
if client_timeout and ...), so two sites in one file disagreed about whatclient_timeout == 0means — and the unguarded one runs first.Every in-repo client sends both fields, so this was invisible in normal operation and would
bite only a new integrator building from the published contract. Found by a Codex P1 review
on #159.
What changed
ChatWrapper._prepare_chat_context: an absent client deadlinenow means "no deadline" rather than "already expired". Both a falsey
client_timeoutand afalsey
client_sent_msg_tsdisable the check — a timeout with no send time has no baselineto measure from.
client_timeoutstill returns408._prepare_chat_context's body (tests/unit/test_chat_timeout_guard.py).they cannot silently drift apart again. The differing baselines are deliberate:
_prepare_chat_contextmeasures total in-flight time fromclient_sent_msg_ts, thestreaming check bounds the streaming phase from
stream_start_time.docs/docs/api_reference.md: both fields returned to optional in the request-body table,dropping the "required in practice" warning added by fix(chat): correct last_message docstring to nested pair shape #159.
Explicitly out of scope: changing
_parse_chat_request'sif x else 0coercion.Verification
passed, 1 xfailed.
100% (1 line).
fix-issue-175-optional-client-timeoutvalidates--strict(run on the host — this is theexact step that could not run in the container).
Harness follow-up (not part of this PR)
The Ralph loop
container lacks the
openspecCLI, so any change whose task list includes anopenspec validatestep will halt the same way, just before opening its PR. Nothing checksthat a task's commands are executable where that task will run. Worth fixing at the image
level rather than by omitting the step from future task lists.