Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
53 changes: 51 additions & 2 deletions openviking/session/session.py
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
import inspect
import json
import re
import time
from dataclasses import dataclass, field
from datetime import datetime, timezone
from typing import TYPE_CHECKING, Any, Awaitable, Callable, Dict, List, Literal, Optional
Expand Down Expand Up @@ -68,6 +69,7 @@
logger = get_logger(__name__)

_ARCHIVE_WAIT_POLL_SECONDS = 0.1
_ARCHIVE_WAIT_TIMEOUT_SECONDS = 1800.0
_PHASE2_QUEUE_WAIT_TIMEOUT_SECONDS = 1800.0
_MEMORY_EXTRACTION_MAX_RETRIES = 3
_MEMORY_EXTRACTION_RETRY_BASE_DELAY_SECONDS = 1.0
Expand Down Expand Up @@ -3743,11 +3745,32 @@ def _archive_index_from_uri(archive_uri: str) -> int:
raise ValueError(f"Invalid archive URI: {archive_uri}")
return int(match.group(1))

async def _wait_for_previous_archive_done(self, archive_index: int) -> bool:
"""Wait until every earlier archive reaches a terminal state."""
async def _wait_for_previous_archive_done(
self,
archive_index: int,
timeout: float = _ARCHIVE_WAIT_TIMEOUT_SECONDS,
) -> bool:
"""Wait until every earlier archive reaches a terminal state.

The wait is bounded: an earlier archive can stay pending forever when
its Phase 1 completed (``phase1.status=ready``) but the matching queue
item was lost (process crash, upgrade, or a historical enqueue bug).
Such an orphan is invisible from here, so after ``timeout`` seconds of
polling the still-pending predecessors are marked terminally failed and
a ``TimeoutError`` is raised. The caller's failure path then writes the
current archive's ``.failed.json`` and fails the task, so the worker
slot is released instead of being wedged forever; the next commit
replays the raw messages of every failed archive through the existing
``_prepare_phase2_archive_messages`` roll-forward, so no data is lost.

Raises:
TimeoutError: earlier archives were still pending after ``timeout``
seconds; they have been marked failed for later raw replay.
"""
if archive_index <= 1 or not self._viking_fs:
return True

deadline = time.monotonic() + timeout
while True:
earlier_states = [
state for state in await self._scan_archive_states() if state.index < archive_index
Expand Down Expand Up @@ -3775,6 +3798,32 @@ async def _wait_for_previous_archive_done(self, archive_index: int) -> bool:
reconciled = True
if reconciled:
continue
if time.monotonic() >= deadline:
stuck_ids = [state.archive_id for state in pending_states]
for state in pending_states:
logger.error(
"Archive %s stayed pending for over %.0fs while blocking "
"archive_%03d Phase 2; its queue item is presumed lost. "
"Marking it failed so its raw messages replay into a "
"later commit.",
state.archive_id,
timeout,
archive_index,
)
await self._write_failed_marker(

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[Bug] (blocking)

The timeout treats "still pending when this waiter's local 1,800-second deadline expires" as proof that every predecessor's QueueFS owner is gone, but those states are not equivalent.

I traced the decision domain through _wait_for_previous_archive_done(), _scan_archive_states(), the four-way SessionCommit worker, _run_memory_extraction(), and TaskWorkIndex. At this point the code has checked archive markers and phase1.status; it has not checked whether the predecessor queue item or asyncio task is still active, nor an expired heartbeat or lease. The code path permits a legitimate predecessor to remain active past a later waiter's 1,800-second deadline: extraction runs before a separate wait_for_request(..., timeout=1800) wait, and there is no overall Phase 2 deadline that proves the owner dead.

Measured in a focused harness: I invoked the real PR-head implementation of _wait_for_previous_archive_done() with archives 001–003 reported as pending and recorded its marker writes. When archive 004's deadline elapsed, this branch wrote phase2_wait_timeout to all three predecessors. The added test covers only a predecessor with no simulated live owner.

Inferred from the call chain, not observed with a real concurrent QueueManager: if one of those predecessors is still executing, it does not re-check .failed.json after passing this wait and can later write .done. Before that happens, another commit can observe the failed marker and roll the same raw messages forward. That creates a window for contradictory terminal markers and duplicate concurrent extraction.

I do not have production duration measurements and did not run a real four-worker concurrency reproduction. The correctness issue does not depend on this being common, though: a timeout by itself is not an owner-death proof. Please gate predecessor mutation on an authoritative liveness signal—for example, an archive-to-task/work mapping combined with absent QueueFS/TaskWorkIndex ownership, or an expired heartbeat/lease. Without such a signal, the timeout should fail only the waiter rather than rewriting predecessor state.

state.archive_uri,
stage="phase2_wait_timeout",
error=(
f"Archive stayed pending for over {timeout:.0f}s; "
"its Phase 2 queue item is presumed lost"
),
)
raise TimeoutError(

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[Bug] (blocking)

When a predecessor really is orphaned, this path changes the archive marker but does not terminate that predecessor's own task record.

I traced the lifecycle domain through the persisted Phase 1 queue_message, this timeout branch, _run_memory_extraction()'s exception handler, and TaskTracker. The predecessor's task ID is available in its Phase 1 metadata, but this helper only writes the predecessor's .failed.json and raises. The exception handler then calls tracker.fail(task_id, ...) with the current waiting archive's task ID. There is no corresponding transition for the predecessor task that was just declared lost.

Concrete example: archive 001's queue item is lost and archive 002 times out waiting for it. The filesystem reports archive 001 as failed, while the task API can still report task 001 as pending/running; only task 002 becomes failed. Active task states have no TTL-based cleanup, so this split can persist indefinitely even though the queue slot was released.

Measured in a focused runtime harness: using the real timeout method and a real TaskTracker, the resulting statuses were archive_001: pending and archive_002: failed. This harness did not run a real QueueManager, but the task transition itself follows the production exception path directly.

Once predecessor ownership has been authoritatively determined to be lost, please reconcile its persisted task ID as failed as part of the same recovery transition, and add an integration assertion for both truths: the predecessor archive is failed and its original task record is terminal. Otherwise this PR unblocks queue consumption but leaves the orphan task permanently non-terminal.

f"Timed out after {timeout:.0f}s waiting for earlier archives "
f"{stuck_ids} to finish before archive_{archive_index:03d} "
"Phase 2; they were marked failed for raw replay by a later "
"commit"
)
await asyncio.sleep(_ARCHIVE_WAIT_POLL_SECONDS)

async def _prepare_phase2_archive_messages(
Expand Down
39 changes: 39 additions & 0 deletions tests/session/test_session_retention_integration.py
Original file line number Diff line number Diff line change
Expand Up @@ -357,6 +357,45 @@ async def test_phase2_waits_for_all_earlier_pending_archives(
assert await asyncio.wait_for(waiter, timeout=0.5)


async def test_phase2_wait_times_out_and_fails_orphaned_pending_archive(
client: AsyncOpenViking,
monkeypatch,
):
"""A pending predecessor whose queue item was lost must not stall forever.

After the bounded wait expires, the orphan is marked terminally failed for
raw replay and the current commit fails cleanly instead of wedging its
worker slot (see #3396).
"""
session = client.session(session_id="phase2_wait_timeout_orphan_test")
await session.ensure_exists()
first_uri = await _write_archive(
session,
1,
[_text_message("u1", "user", "orphaned pending one")],
)
monkeypatch.setattr("openviking.session.session._ARCHIVE_WAIT_POLL_SECONDS", 0.01)

with pytest.raises(TimeoutError, match="archive_001"):
await asyncio.wait_for(
session._wait_for_previous_archive_done(2, timeout=0.05),
timeout=2.0,
)

failed = json.loads(
await session._viking_fs.read_file(f"{first_uri}/.failed.json", ctx=session.ctx)
)
assert failed["stage"] == "phase2_wait_timeout"
states = {state.archive_id: state.state for state in await session._scan_archive_states()}
assert states["archive_001"] == "failed"

# The next commit's wait now sees only terminal predecessors and proceeds.
assert await asyncio.wait_for(
session._wait_for_previous_archive_done(2, timeout=0.05),
timeout=2.0,
)


async def test_missing_previous_archive_directory_does_not_block_phase2(
client: AsyncOpenViking,
):
Expand Down