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 |
| # Wait for beforeLease hook to complete while logs are streaming | ||
| # This allows hook output to be displayed in real-time | ||
| # Uses non-blocking polling instead of streaming for robustness | ||
| logger.info("Waiting for beforeLease hook to complete...") | ||
| targets = [ExporterStatus.LEASE_READY, ExporterStatus.BEFORE_LEASE_HOOK_FAILED] | ||
|
|
||
| # Wait for LEASE_READY or hook failure using background monitor | ||
| result = await monitor.wait_for_any_of( | ||
| [ExporterStatus.LEASE_READY, ExporterStatus.BEFORE_LEASE_HOOK_FAILED], timeout=300.0 | ||
| ) | ||
| # The monitor reports no status until its first poll, so settle | ||
| # that first: attaching to a lease that is already LEASE_READY | ||
| # must not claim to be waiting on a hook that already ran. | ||
| result = await monitor.wait_for_any_of(targets, timeout=HOOK_PROBE_TIMEOUT) | ||
|
|
||
| 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=HOOK_TIMEOUT - HOOK_PROBE_TIMEOUT | ||
| ) |
There was a problem hiding this comment.
Hmmm, slow networks might not work with 2s delays. I am thinking about max distance and higher latency of some of the newer use-cases (lets say you are on a plane with starlink and need to dial to the other side of the planet)
I wonder if you add a _first_observation_done: asyncio.Event to StatusMonitor.__init__, set it after the first successful GetStatus response is processed, and expose async def wait_for_first_observation(self, timeout) if that might be a better solution. In shell.py, await that instead of relying on the wall-clock probe.
| 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>
2 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.