fix(cli): stop reporting hook waits and status changes that never happened - #1039
fix(cli): stop reporting hook waits and status changes that never happened#1039kirkbrauer wants to merge 2 commits into
Conversation
…pened Attaching to a lease that is already LEASE_READY printed "Waiting for beforeLease hook to complete..." followed by "Status changed: None -> LEASE_READY" — neither of which happened. The message was emitted before the status monitor's first poll had returned, and the monitor treated its first observation as a transition from nothing. Settle the current status first and announce the wait only when there is one, and log the first observation at debug level, keeping INFO for genuine transitions. Signed-off-by: Kirk Brauer <kirkebrauer@gmail.com>
kirkbrauer
added
bug
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Pro Plus Run ID: 📒 Files selected for processing (4)
Included review availability: Your plan provides up to 2 included reviews per hour; 1 remains after this review. 📝 WalkthroughWalkthroughThe status monitor now reports when its first observation completes. The shell uses this signal before waiting for beforeLease hook target states and applies a shared 300-second deadline. ChangesBeforeLease observation flow
Estimated code review effort: 3 (Moderate) | ~20 minutes Merge Risk: ⚪ Minimal · up to This PR corrects misleading hook-wait and status-change messages without introducing an actionable merge-blocking risk; it is ready to merge after normal checks and review. Sequence Diagram(s)sequenceDiagram
participant Shell
participant StatusMonitor
participant GetStatusRPC
Shell->>StatusMonitor: wait_for_first_observation
StatusMonitor->>GetStatusRPC: request first status
GetStatusRPC-->>StatusMonitor: status response
StatusMonitor-->>Shell: current status and observation result
Shell->>StatusMonitor: wait for hook target status when needed
Suggested reviewers: Poem
🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✨ Finishing Touches 💡 1📝 Generate docstrings 💡
🧪 Generate unit tests (beta)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
| HOOK_TIMEOUT = 300.0 | ||
| HOOK_PROBE_TIMEOUT = 2.0 |
There was a problem hiding this comment.
Rename to private _HOOK_TIMEOUT: float = 300.0 and _HOOK_PROBE_TIMEOUT: float = 2.0?
The hook wait settled the exporter's status with a 2s probe before deciding whether to announce it was waiting. That is a wall-clock guess: on a slow or distant link — the far side of the planet over a satellite uplink, say — the first GetStatus answer can take longer than the probe, and the announcement comes back, which is the bug this was meant to fix. StatusMonitor now sets an event once it has processed its first GetStatus answer, and wait_for_first_observation waits on that. The caller waits for the fact rather than for a duration, so the behaviour no longer depends on latency and HOOK_PROBE_TIMEOUT is gone. The event is also set when GetStatus is unsupported, and when the poll loop exits without ever getting an answer, so a waiter is never left sitting out its timeout for an observation that is not coming. The overall 300s budget is unchanged, now tracked as a deadline. Also make the constants private and typed, per review. Assisted-by: Claude Signed-off-by: Kirk Brauer <kirkebrauer@gmail.com>
| await monitor.wait_for_first_observation(timeout=_HOOK_TIMEOUT) | ||
| result = monitor.current_status if monitor.current_status in targets else None | ||
|
|
||
| if result is None and not monitor.connection_lost: | ||
| logger.info("Waiting for beforeLease hook to complete...") | ||
| result = await monitor.wait_for_any_of( | ||
| targets, timeout=max(0.0, deadline - anyio.current_time()) | ||
| ) |
There was a problem hiding this comment.
The return value of await monitor.wait_for_first_observation(timeout=_HOOK_TIMEOUT) is not captured. What if GetStatus stays UNAVAILABLE for the entire timeout budget?
There was a problem hiding this comment.
Good catch. Tracing through the code, here's the concrete scenario:
wait_for_first_observation()returnsTrue(a status was observed), but the return value is discarded.- The observed status is
UNAVAILABLE— not intargets, soresult = None. UNAVAILABLEsetsmonitor.connection_lost = True, so theif result is None and not monitor.connection_lostguard isFalse— thewait_for_any_ofcall is skipped entirely.- Execution falls through to the existing
elif result is Noneblock (line 349), which checksmonitor.connection_lost(True) and silently returns 0, as if the lease expired gracefully.
So if GetStatus stays UNAVAILABLE for the full timeout budget, the shell exits successfully instead of raising an error — the user gets no indication that the exporter never became ready.
There was a problem hiding this comment.
IDK, since this is mostly aesthetic. I'd propose that we leave this alone, and eventually tackle it when we have a FSM in rust , python or whatever :D
WDYT?
There was a problem hiding this comment.
Is the FSM work scheduled already or somewhere deeply nested in the backlog? I think if we implement the FSM soonish, its okay to leave it as is.
| async def test_releases_waiters_when_the_monitor_stops(self) -> None: | ||
| """A stopped monitor will never observe anything, so waiters must not | ||
| sit out their whole timeout.""" | ||
| stub = MockExporterStub([AioRpcError(StatusCode.UNAVAILABLE, None, None)]) |
There was a problem hiding this comment.
Consider using create_mock_rpc_error(StatusCode.UNAVAILABLE) for consistency.
3 participants
jmp shellannounced "waiting for beforeLease hook" before the status monitor had polled even once, so attaching to an already-ready lease reported a wait that was not happening. The monitor then logged its first observation as a transition, so a lease that had been in the same state all along looked like it had just changed.Waits for the first observation before reporting, and logs that first one at debug level rather than as a change.