[AUTO-INF-4] Flaky test: uko_indexer_watcher_steps.py debounce wait uses patched time.sleep — debounce never fires in CI #10295

New issue

Open

opened 2026-04-18 08:16:07 +00:00 by HAL9000 · 0 comments

HAL9000 commented

2026-04-18 08:16:07 +00:00

Owner

Metadata

Field	Value
Branch	`fix/auto-inf-4-uko-indexer-debounce-sleep`
Commit Message	`fix(tests): replace patched time.sleep with _original_sleep in uko_indexer_watcher debounce step`
Milestone	v3.5.0
Parent Epic	—

Background and Context

features/steps/uko_indexer_watcher_steps.py contains a step definition that waits for a debounce timer to fire before asserting callback counts:

@when("idx we wait {secs} seconds for debounce")
def step_fw_wait(context: Any, secs: str) -> None:
    time.sleep(float(secs))

The features/environment.py before_all hook installs a fast-sleep patch (_install_fast_sleep_patch) that caps time.sleep() at 10 ms globally:

_MAX_SLEEP = 0.01  # 10 ms cap

def _capped_sleep(seconds: float) -> None:
    time._original_sleep(min(seconds, _MAX_SLEEP))

time.sleep = _capped_sleep

The UKO indexer feature file (features/uko_indexer.feature) calls this step with debounce wait values of 0.2 seconds (200 ms):

And idx we wait 0.2 seconds for debounce

The ResourceFileWatcher is configured with debounce=0.05 (50 ms) or debounce=0.1 (100 ms). The debounce timer fires after the configured debounce period. However, because time.sleep(0.2) is capped to 10 ms by the fast-sleep patch, the step returns after only 10 ms — before the 50–200 ms debounce timer has fired.

This causes the subsequent assertion idx the on_change callback should have fired exactly N times to fail intermittently (or consistently) because the callback has not yet been invoked when the assertion runs.

Affected scenarios in features/uko_indexer.feature:

Scenario: Callback errors do not crash the watcher (line ~541) — waits 0.2s for debounce 0.05
Scenario: Unwatched file changes are ignored (line ~566) — waits 0.2s for debounce 0.05
Scenario: Directory events are ignored by the watcher (line ~574) — waits 0.2s for debounce 0.05

Root cause: The step uses the module-level time.sleep reference, which is replaced by the fast-sleep patch. It should use time._original_sleep (the un-patched version) to allow real wall-clock time to elapse for debounce timers.

Correct pattern (already used in other timing-sensitive steps):

# From features/steps/mcp_lifecycle_steps.py (line 211):
original_sleep = getattr(time, "_original_sleep", time.sleep)
original_sleep(secs)

# From features/steps/skill_refresh_steps.py (line 241):
_sleep = getattr(time, "_original_sleep", time.sleep)
_sleep(seconds)

Impact

Intermittent CI failures in unit_tests job: debounce-dependent assertions fail when the fast-sleep patch prevents the debounce timer from firing before the assertion runs.
Affected feature: features/uko_indexer.feature — file-watching scenarios tagged @file-watching.
Related to P0 blocker: Issue #2850 (unit_tests CI job failing after ~6m45s) — timing-dependent test failures contribute to CI instability.

Expected Behavior

The debounce wait step should use the un-patched time._original_sleep so that real wall-clock time elapses and the debounce timer fires before the assertion runs.

Acceptance Criteria

features/steps/uko_indexer_watcher_steps.py step_fw_wait uses getattr(time, "_original_sleep", time.sleep) instead of bare time.sleep
All @file-watching scenarios in features/uko_indexer.feature pass consistently in parallel test runs
nox -s unit_tests passes without intermittent failures in the UKO indexer file-watching scenarios
Coverage remains >= 97%

Subtasks

Update step_fw_wait in features/steps/uko_indexer_watcher_steps.py to use _real_sleep = getattr(time, "_original_sleep", time.sleep) and call _real_sleep(float(secs))
Verify all @file-watching scenarios pass in nox -s unit_tests
Run nox (all default sessions), fix any errors
Verify coverage >= 97% via nox -s coverage_report

Definition of Done

This issue is complete when:

All subtasks above are completed and checked off.
A Git commit is created where the first line of the commit message matches the Commit Message in Metadata exactly, followed by a blank line, then additional details.
The commit is pushed to the remote on the branch matching the Branch in Metadata exactly.
The commit is submitted as a pull request to master, reviewed, and merged before this issue is marked done.

Duplicate Check

Check	Query	Result
1. Open issues keyword search	`uko_indexer`, `debounce`, `file-watching`, `ResourceFileWatcher`	No existing issues found covering this specific debounce sleep pattern
2. Cross-area search	`[AUTO-INF-*]` issues (#10245, #10244, #10241, #10250)	None address uko_indexer_watcher_steps.py debounce timing
3. Closed issues search	`debounce`, `uko_indexer`, `file watcher`, `sleep patch`	No closed issues found covering this pattern (pages 1–10 searched)
4. Similar proposals	Issue #10245 ([AUTO-INF-6]) covers module-level ULID generation — different issue. Issue #7087 covers tempfile.mktemp() race — different issue.	No overlap with this specific debounce sleep issue
5. Uncertainty check	This is a specific, well-defined bug: `time.sleep(0.2)` is capped to 10ms by the fast-sleep patch, but the debounce timer needs 50–200ms to fire. Confident this is a new, distinct issue.	Not a duplicate

Automated by CleverAgents Bot
Agent: new-issue-creator

## Metadata | Field | Value | |---|---| | **Branch** | `fix/auto-inf-4-uko-indexer-debounce-sleep` | | **Commit Message** | `fix(tests): replace patched time.sleep with _original_sleep in uko_indexer_watcher debounce step` | | **Milestone** | v3.5.0 | | **Parent Epic** | — | --- ## Background and Context `features/steps/uko_indexer_watcher_steps.py` contains a step definition that waits for a debounce timer to fire before asserting callback counts: ```python @when("idx we wait {secs} seconds for debounce") def step_fw_wait(context: Any, secs: str) -> None: time.sleep(float(secs)) ``` The `features/environment.py` `before_all` hook installs a **fast-sleep patch** (`_install_fast_sleep_patch`) that caps `time.sleep()` at **10 ms** globally: ```python _MAX_SLEEP = 0.01 # 10 ms cap def _capped_sleep(seconds: float) -> None: time._original_sleep(min(seconds, _MAX_SLEEP)) time.sleep = _capped_sleep ``` The UKO indexer feature file (`features/uko_indexer.feature`) calls this step with debounce wait values of **0.2 seconds** (200 ms): ```gherkin And idx we wait 0.2 seconds for debounce ``` The `ResourceFileWatcher` is configured with `debounce=0.05` (50 ms) or `debounce=0.1` (100 ms). The debounce timer fires after the configured debounce period. However, because `time.sleep(0.2)` is capped to 10 ms by the fast-sleep patch, the step returns after only 10 ms — **before the 50–200 ms debounce timer has fired**. This causes the subsequent assertion `idx the on_change callback should have fired exactly N times` to fail intermittently (or consistently) because the callback has not yet been invoked when the assertion runs. **Affected scenarios in `features/uko_indexer.feature`:** - `Scenario: Callback errors do not crash the watcher` (line ~541) — waits 0.2s for debounce 0.05 - `Scenario: Unwatched file changes are ignored` (line ~566) — waits 0.2s for debounce 0.05 - `Scenario: Directory events are ignored by the watcher` (line ~574) — waits 0.2s for debounce 0.05 **Root cause:** The step uses the module-level `time.sleep` reference, which is replaced by the fast-sleep patch. It should use `time._original_sleep` (the un-patched version) to allow real wall-clock time to elapse for debounce timers. **Correct pattern** (already used in other timing-sensitive steps): ```python # From features/steps/mcp_lifecycle_steps.py (line 211): original_sleep = getattr(time, "_original_sleep", time.sleep) original_sleep(secs) # From features/steps/skill_refresh_steps.py (line 241): _sleep = getattr(time, "_original_sleep", time.sleep) _sleep(seconds) ``` --- ## Impact - **Intermittent CI failures** in `unit_tests` job: debounce-dependent assertions fail when the fast-sleep patch prevents the debounce timer from firing before the assertion runs. - **Affected feature**: `features/uko_indexer.feature` — file-watching scenarios tagged `@file-watching`. - **Related to P0 blocker**: Issue #2850 (`unit_tests` CI job failing after ~6m45s) — timing-dependent test failures contribute to CI instability. --- ## Expected Behavior The debounce wait step should use the un-patched `time._original_sleep` so that real wall-clock time elapses and the debounce timer fires before the assertion runs. --- ## Acceptance Criteria - [ ] `features/steps/uko_indexer_watcher_steps.py` `step_fw_wait` uses `getattr(time, "_original_sleep", time.sleep)` instead of bare `time.sleep` - [ ] All `@file-watching` scenarios in `features/uko_indexer.feature` pass consistently in parallel test runs - [ ] `nox -s unit_tests` passes without intermittent failures in the UKO indexer file-watching scenarios - [ ] Coverage remains >= 97% --- ## Subtasks - [ ] Update `step_fw_wait` in `features/steps/uko_indexer_watcher_steps.py` to use `_real_sleep = getattr(time, "_original_sleep", time.sleep)` and call `_real_sleep(float(secs))` - [ ] Verify all `@file-watching` scenarios pass in `nox -s unit_tests` - [ ] Run `nox` (all default sessions), fix any errors - [ ] Verify coverage >= 97% via `nox -s coverage_report` --- ## Definition of Done This issue is complete when: - All subtasks above are completed and checked off. - A Git commit is created where the **first line** of the commit message matches the Commit Message in Metadata exactly, followed by a blank line, then additional details. - The commit is pushed to the remote on the branch matching the **Branch** in Metadata exactly. - The commit is submitted as a **pull request** to `master`, reviewed, and **merged** before this issue is marked done. --- ### Duplicate Check | Check | Query | Result | |-------|-------|--------| | 1. Open issues keyword search | `uko_indexer`, `debounce`, `file-watching`, `ResourceFileWatcher` | No existing issues found covering this specific debounce sleep pattern | | 2. Cross-area search | `[AUTO-INF-*]` issues (#10245, #10244, #10241, #10250) | None address uko_indexer_watcher_steps.py debounce timing | | 3. Closed issues search | `debounce`, `uko_indexer`, `file watcher`, `sleep patch` | No closed issues found covering this pattern (pages 1–10 searched) | | 4. Similar proposals | Issue #10245 ([AUTO-INF-6]) covers module-level ULID generation — different issue. Issue #7087 covers tempfile.mktemp() race — different issue. | No overlap with this specific debounce sleep issue | | 5. Uncertainty check | This is a specific, well-defined bug: `time.sleep(0.2)` is capped to 10ms by the fast-sleep patch, but the debounce timer needs 50–200ms to fire. Confident this is a new, distinct issue. | Not a duplicate | --- **Automated by CleverAgents Bot** Agent: new-issue-creator

HAL9000 added the

labels

2026-04-18 08:21:20 +00:00

HAL9000 referenced this issue

2026-04-18 08:26:53 +00:00

[AUTO-INF-4] Flaky test: devcontainer_health_check_steps.py thread-startup waits use patched time.sleep — thread may not be ready in CI #10301