Repository navigation
docs(claude): record the first-run cutoff clock limitation - #261
bniladridas wants to merge 5 commits into
Conversation
The first-run cutoff compared event times to the local process start, so a local clock more than 60 seconds ahead of the server could drop a live event as replayed history. Read the stream response's HTTP Date header, carry it on FeedFrame.server_time, and replace the local cutoff on the first frame. A missing or unreadable Date header keeps the local fallback. Add regression tests for a clock-ahead unrecognised event, a clock-ahead live message, an old replay that is still suppressed, and Date header parsing and fallback. Fixes Vycari#255. Refs Vycari#122. Signed-off-by: Niladri Das <125604915+bniladridas@users.noreply.github.com>
Vycari ReviewRound 4 on 42d1879. The verdict is the Vycari Review check run, and each open finding is an inline thread. Reply on every P0 and P1 thread: Open: P0 0 · P1 1 · P2 0 · disputed 0 · confirmed fixed 1 · withdrawn 0 Hand-off: Needs the PR's author and the maintainer: 1 P0/P1 finding(s) open with no reply at the round cap (4 of 3). Fix each ( Held at the round cap (needs the PR's author and the maintainer)
Open P0 and P1 findings
P2s, judge's notes and closed findingsJudge's notes The prior finding about a Date header ahead of the clock hiding live messages is fixed: positive offsets are now clipped to zero. One narrow P1 remains, the mirror case: a Date header that lags the server by hours pulls the first-run cutoff back, so old history is pushed to the agent as live messages instead of a backlog summary. Confirmed fixed
|
Codex Review Summary: ✅ CompletedThis comment shows the latest Codex review activity on this pull request.
ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
Codex reacts with 👀 while any review is running, comments if it has suggestions, and reacts with 👍 once all reviews finish with no findings. |
![vycari-review[bot]](https://avatars.githubusercontent.com/u/287278059?s=60&v=4){kind=small}
![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: 08d41734c1
ℹ️ 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".
| self.delay = _WATCH_BACKOFF_START | ||
| self.failures = 0 | ||
| if not self.cutoff_from_server and frame.server_time is not None: | ||
| self.cutoff = frame.server_time - BACKLOG_SLACK |
There was a problem hiding this comment.
If the pre-stream lookups in run() or startup retries take longer than the 60-second slack, this Date is the connection-open time, not the started_at captured by run(). Assigning it directly advances the cutoff, so messages created after process start but before connection time minus the slack are skipped as pre-session history instead of being pushed. Adjust the captured start time for the server/local clock offset rather than substituting the response time.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Fixed in 6802fdc: the first-run cutoff now shifts config.started_at by the measured server_time - local now offset instead of taking the Date as the boundary. test_a_message_posted_while_a_first_run_was_connecting_is_still_pushed uses a 90 second connect delay and asserts a message posted 10 seconds after start is pushed; it is not pushed on the previous head.
The review findings all came from treating the HTTP Date as a replacement for the process-start cutoff: the UTC conversion ran outside the unreadable-date guard, the cutoff moved on resumed sessions too, and using connection time could skip a message posted while the process was starting. The whole parse and conversion are now inside the guard with OverflowError handled, the cutoff only moves on a first run, and it shifts started_at by the measured server/local offset instead of jumping to connect time. Three regression tests cover the overflow, a slow first-run connect, and a resumed session with a message 55 seconds before start; all three fail on the previous head with the source hunks reverted, and the full suite passes at 3351 with coverage 96 against the 88 floor. Signed-off-by: Niladri Das <125604915+bniladridas@users.noreply.github.com>
The round 2 review found the offset had no bounds: a year 9999 Date header moved the cutoff into the future and silently skipped every live message, while a header near year 1 overflowed the cutoff arithmetic. `_server_cutoff` now rejects any Date whose measured offset from the local clock is more than a day, leaving the local cutoff in place, which is the same fallback as an unreadable header. Two tests cover it: the helper returns None for year 1 and year 9999 and still applies a two hour offset, and an end-to-end first run with a year 9999 Date still pushes its live message. Both fail with the source hunk reverted. Full suite 3353 passed, 2 skipped, coverage 96 against the 88 floor. Signed-off-by: Niladri Das <125604915+bniladridas@users.noreply.github.com>
The round 3 review found that the one day bound still accepted a Date up to 20 hours ahead, which moved the first-run cutoff into the future and hid live messages. The HTTP Date can come from an intermediary and nothing guarantees it shares the clock that stamps created_at, so a positive offset is now clipped to zero: the Date may move the cutoff earlier, which fixes a local clock ahead of the server, but never later. Two exact cutoff tests replace the direction only assertion, and an end-to-end first run with a Date 20 hours ahead of a live message fails on 23475dc and passes now. Full suite 3356 passed, 2 skipped; ruff and ty clean. Signed-off-by: Niladri Das <125604915+bniladridas@users.noreply.github.com>
| def _server_cutoff(started_at: datetime, server_time: datetime) -> datetime | None: | ||
| """The first-run cutoff shifted by the server/local offset, or ``None`` when the Date header | ||
| is too far from the local clock to trust (a broken or hostile header, not skew).""" | ||
| offset = server_time - datetime.now(UTC) | ||
| if abs(offset) > MAX_CLOCK_OFFSET: | ||
| return None | ||
| # The HTTP Date can come from an intermediary, and nothing guarantees it shares the clock | ||
| # that stamps created_at. Apply it only when it moves the cutoff earlier: a later boundary | ||
| # can hide a live message, an earlier one can only show more history. | ||
| return started_at + min(offset, timedelta(0)) - BACKLOG_SLACK |
There was a problem hiding this comment.
P1 · VR-9f600427 · A Date header up to a day behind the local clock pushes old retained history as live messages on a first run
On a first run, if the server's Date header runs hours behind its real clock (for example, stamped by a proxy), the cutoff moves back by up to a day. Old retained messages are then pushed to the agent one by one as if live, instead of as a single backlog summary.
Reply Fixed in <sha> or Disputed: with a reason.
Details for agents: evidence, failure scenario, verification, proving test
_server_cutoff accepts any offset within MAX_CLOCK_OFFSET (one day) and applies a negative offset in full (started_at + min(offset, 0) - BACKLOG_SLACK). The PR's own premise is that the HTTP Date may come from an intermediary and need not share the clock that stamps created_at, so nothing distinguishes a Date that is hours behind a correctly-clocked server from a local clock that is ahead. A lagging Date therefore moves the first-run cutoff back by up to 23h. Every retained event with created_at inside that extra window fails the 'created_at < cutoff' test in _handle_event (claude_channel.py:698) and is pushed through _push_message as an individual live notification (or yields a resync for unknown kinds via _is_first_run_history at line 671 returning False). That is the outcome the first-run design forbids: the comment at claude_channel.py:438-440 says a first run must never push every old message, and the backlog summary path (_flush_backlog, lines 488-519) is bypassed.
Evidence: Read claude_channel.py:663-671 (_is_first_run_history), 673-703 (_handle_event; cutoff comparison at 698), 705-727 (_push_message calls _flush_backlog first), 488-519 (_flush_backlog summarises only when skipped is non-empty; first_run summary path), and 438-447 (comment: 'a server that ignored start and replayed its window ... gets the first-run summary, never a push of every old message'). The negative-offset branch in _server_cutoff (line 391) is applied without any lower bound other than MAX_CLOCK_OFFSET. Checked the API client (api_client.py:3442) to confirm the Date is read per connection from the response headers with no check that the Date is fresh. No protection found that stops a Date behind the server from lowering the cutoff; the PR body's invariant only argues that lowering 'can only show more history', which is the harm here, since first-run history is pushed as live messages.
Failure scenario
Local clock is correct. A first run (no cursor file) connects through an intermediary whose cached or skewed Date is 20 hours behind the server clock. _handle_frame (lines 846-854) computes offset = -20h and sets cutoff = started_at - 20h - 60s. The room's retained window holds 15 hours of messages from before the process started. Each of those messages has created_at inside the new window, so _handle_event pushes them as live 'message' notifications one by one instead of the single first-run 'backlog' summary. The user's agent is flooded with stale messages it was told it would not receive, and unknown old events produce spurious 'resync' prompts.
How this was verified (read-only-reasoning)
I read the diff of _server_cutoff and _handle_frame. A negative offset within one day is applied, and nothing separates a lagging Date from local clock skew. I did not open the files, so the _handle_event usage is taken from the candidate's citations. Reachable from: first-run ChannelWorker._handle_frame at claude_channel.py:846-854, on a feed response carrying a Date header.
Proving test
In tests/test_claude_channel.py: first-run _Fake with server_time = _now() - timedelta(hours=20) (Date header 20h behind local), a stream containing _CONNECTED + _scope() + _event(7, message=_MESSAGE, created=_now() - timedelta(hours=3)) + _PING, and run_channel(...). Assert result.kinds() == ['backlog']. On the PR head the cutoff is started - 20h - 60s, the 3-hour-old message is not before it, and the result is ['message']. The existing test test_a_first_run_replay_is_still_suppressed_with_the_server_clock uses a 3-day-old event, which is outside the one-day bound, so it never exercises this window.
lens spec-adversary · symbol _server_cutoff
There was a problem hiding this comment.
Fixed in 335f036: the HTTP Date path is removed. FeedFrame.server_time, _feed_server_time, _server_cutoff, MAX_CLOCK_OFFSET, and the clock-based tests are gone, and the first-run cutoff is back to the local started_at - BACKLOG_SLACK. §7.4 now records the limitation and the server-side timestamp or head-position follow-up. The net diff against main is the §7.4 note.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 42d1879b94
ℹ️ 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".
| def _server_cutoff(started_at: datetime, server_time: datetime) -> datetime | None: | ||
| """The first-run cutoff shifted by the server/local offset, or ``None`` when the Date header | ||
| is too far from the local clock to trust (a broken or hostile header, not skew).""" | ||
| offset = server_time - datetime.now(UTC) |
There was a problem hiding this comment.
On a first run, if the response headers arrive but the first SSE frame is delayed (for example, an intermediary buffers the body; the read timeout permits up to 60 seconds), server_time still reflects stream-open time while datetime.now() is sampled only when _handle_frame consumes that frame. With synchronized clocks, a 50-second delay is misread as 50 seconds of negative skew and moves the cutoff from started_at - 60s to about started_at - 110s, so messages 60–110 seconds before startup are pushed instead of being summarized as backlog. Capture the local time when the response headers are received and use it for this offset.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Fixed in 335f036: the Date path is removed, so there is no local clock sample in the cutoff. _server_cutoff and the first-frame timing are gone; the cutoff is set once from the local process start.
The HTTP Date can come from an intermediary and need not share the clock that stamps created_at. Allowing it to move the first-run cutoff fails in one direction or the other: a Date ahead hides live events, and a Date behind pushes retained history as live. The Date parsing, the frame field, the cutoff helper, and the clock-based tests are removed. The design note in §7.4 records the local cutoff limitation and the server-side timestamp or head-position fix. Refs Vycari#255. Signed-off-by: Niladri Das <125604915+bniladridas@users.noreply.github.com>
bniladridas
changed the title
Human overview
This PR is now a rollback and a design note: it stops the HTTP
Dateheader from moving the first-run cutoff and records why the cutoff stays local. The API has no server clock that shares a basis with the message store'screated_at, and a Date from an intermediary fails in both directions: ahead it hides live events, behind it pushes retained history as live. No runtime behavior changes frommain; the net diff is the §7.4 note. Refs #255 stays open for a server-side timestamp or a head position.AI reviewer
Details for agents: what the diff does, invariants, verification, checklist
What the diff does
main, the only change isplanning/claude-code-channel.md§7.4: the cutoff staysstarted_at - BACKLOG_SLACK, and the note records the skew exposure and the two server-side fixes.FeedFrame.server_time,_feed_server_time, theDateread in_stream_feed,_server_cutoff,MAX_CLOCK_OFFSET,cutoff_from_server, and the clock-based tests are no longer in the final tree. They remain in earlier commits only.main, so the PR changes no/api/v1use, no frame shape, and no output.Review findings addressed
VR-9f600427: a Date behind the local clock moved the cutoff back and pushed retained history as live. The Date correction is removed._server_cutoffsampled the local clock at the first frame rather than at header receipt. There is no clock sample left.VR-22048992: the earlier ahead-Date fix is superseded by removing the Date path, not adjusted again.VR-77e4c028: the year-0001 overflow is unreachable because the parse path is gone.Invariants and why they hold
started_at - BACKLOG_SLACK, local and unchanged. It is computed once at construction and never moved by a frame.created_atis compared across clocks.start=headnever replays, so the limitation applies only to a server that ignoresstart=heador to an explicit--start beginning.Alternatives rejected
Where to look hardest
git diff origin/mainshows only §7.4, while the branch history contains the revert.Verification
uv run ruff format --check: 150 files already formatted.uv run ruff check: All checks passed.uv run ty check src/pepper_cli/: All checks passed.uv run pytest tests/test_claude_channel.py tests/test_api_client_groups.py -q: 190 passed.uv run pytest -n auto -q: 3342 passed, 2 skipped. The count is 14 below the previous head because the clock-based tests are removed.git diff --stat origin/main:planning/claude-code-channel.md, 11 insertions.Deferred work
created_at, or the feed head position on a beginning stream so history can be classified by event id without clocks.Checklist (repo-specific)
uv run ruff format --checkanduv run ruff checkclean (no new lint ignores)uv run ty check src/pepper_cli/cleanuv run pytestpasses (3342 passed, 2 skipped); coverage was not re-run because the diff is docs-only and.claude/maintainerd.jsonis untouched/api/v1use or frame shape changes; the# MIRROR:content is back tomainSKILL.md: N/A, no command or output changehelp/cli.md): N/A, no user-facing change