Skip to content
Original file line number Diff line number Diff line change
@@ -0,0 +1,50 @@
# PRD: BUG-T20 — Session Timeline can show negative duration due to incorrect entry ordering

## Objective
Eliminate negative or inverted session durations in the Session Timeline by ensuring session detection always runs on timestamp-ascending audit entries, regardless of upstream ordering.

## Background
`detect_sessions()` expects chronologically ascending entries. Some server paths currently pass newest-first arrays (or mixed ordering) into session detection, which can invert `started_at`/`ended_at` boundaries and produce impossible negative durations.

## Deliverables
- Normalize audit entry ordering before session detection in the Web UI backend session path.
- Add defensive ordering behavior at the session computation layer so callers cannot accidentally produce invalid durations.
- Add regression tests that cover newest-first and mixed-order inputs and assert non-negative durations and stable latest-event semantics.
- Document the fix and verification evidence in the validation report.

## Dependencies
- `src/mcpbridge_wrapper/webui/sessions.py`
- `src/mcpbridge_wrapper/webui/server.py`
- Existing Web UI test suites under `tests/unit/webui/` and `tests/integration/webui/`

## Acceptance Criteria
- [ ] Session detection produces non-negative duration for newest-first and mixed-order entries.
- [ ] `/api/sessions` and websocket session payloads expose monotonic session boundaries (`started_at <= ended_at`).
- [ ] Regression tests fail before the fix and pass after the fix.
- [ ] Required quality gates pass: `PYTHONPATH=src pytest`, `ruff check src/`, `mypy src/`, `PYTHONPATH=src pytest --cov` (coverage >= 90%).

## Validation Plan
1. Add/extend unit tests around session detection ordering assumptions.
2. Add/extend server-level tests to validate `/api/sessions` behavior with descending/mixed audit entries.
3. Run required quality gates and record outcomes in `SPECS/INPROGRESS/BUG-T20_Validation_Report.md`.
4. Confirm no regressions to previous BUG-T19 multi-process consistency behavior.

## Implementation Plan
### Phase 1: Defensive ordering in session detection
- Enforce timestamp-ascending ordering inside session computation to make ordering contract explicit and robust.
- Preserve output ordering expected by dashboard consumers.

### Phase 2: Server integration correctness
- Ensure all server paths that compute sessions use the normalized entry order.
- Keep payload shape unchanged.

### Phase 3: Regression coverage
- Add tests for descending/mixed input ordering and non-negative duration guarantees.
- Add server-level test asserting API session ordering and duration correctness.

---
**Planned:** 2026-02-25

---
**Archived:** 2026-02-25
**Verdict:** PASS
Original file line number Diff line number Diff line change
@@ -0,0 +1,38 @@
# Validation Report: BUG-T20

## Task
Session Timeline can show negative duration due to incorrect entry ordering.

## Implementation Summary
- Added defensive timestamp ordering in `detect_sessions()` so session grouping always runs on ascending timestamps, regardless of caller input order.
- Added robust timestamp parsing helper reuse in session extraction to keep boundary and tool timestamps consistent.
- Added unit regression coverage in `tests/unit/webui/test_sessions.py` for newest-first and mixed-order inputs, asserting non-negative durations and correct tool ordering.
- Added server/API regression coverage in `tests/unit/webui/test_server.py` for mixed-order audit rows, ensuring monotonic session boundaries and correct latest-event placement.

## Quality Gates

### 1) `PYTHONPATH=src pytest`
- Result: PASS
- Evidence: `651 passed, 5 skipped`

### 2) `ruff check src/`
- Result: PASS
- Evidence: `All checks passed!`

### 3) `mypy src/`
- Result: PASS
- Evidence: `Success: no issues found in 18 source files`

### 4) `PYTHONPATH=src pytest --cov`
- Result: PASS
- Evidence:
- `651 passed, 5 skipped`
- `Required test coverage of 90.0% reached`
- `Total coverage: 91.33%`

## Manual Validation Notes
- Verified reverse-ordered and mixed-ordered inputs now produce session windows where `start <= end`.
- Confirmed session tool lists are chronologically ordered, so timeline "latest event" aligns with the final tool entry in each session.

## Verdict
PASS
6 changes: 5 additions & 1 deletion SPECS/ARCHIVE/INDEX.md
Original file line number Diff line number Diff line change
@@ -1,11 +1,12 @@
# mcpbridge-wrapper Tasks Archive

**Last Updated:** 2026-02-25 (BUG-T19_Audit_Log_and_Session_Timeline_are_inconsistent_with_tool_charts_in_multi_process_runs)
**Last Updated:** 2026-02-25 (BUG-T20_Session_Timeline_can_show_negative_duration_due_to_incorrect_entry_ordering)

## Archived Tasks

| Task ID | Folder | Archived | Verdict |
|---------|--------|----------|---------|
| BUG-T20 | [BUG-T20_Session_Timeline_can_show_negative_duration_due_to_incorrect_entry_ordering/](BUG-T20_Session_Timeline_can_show_negative_duration_due_to_incorrect_entry_ordering/) | 2026-02-25 | PASS |
| BUG-T19 | [BUG-T19_Audit_Log_and_Session_Timeline_are_inconsistent_with_tool_charts_in_multi_process_runs/](BUG-T19_Audit_Log_and_Session_Timeline_are_inconsistent_with_tool_charts_in_multi_process_runs/) | 2026-02-25 | PASS |
| BUG-T13 | [BUG-T13_Per-Tool_Latency_Statistics_does_not_show_params_when_capture_params_is_false/](BUG-T13_Per-Tool_Latency_Statistics_does_not_show_params_when_capture_params_is_false/) | 2026-02-25 | PASS |
| BUG-T11 | [BUG-T11_Chart_Request_Timeline_never_shows_actual_events/](BUG-T11_Chart_Request_Timeline_never_shows_actual_events/) | 2026-02-25 | PASS |
Expand Down Expand Up @@ -252,6 +253,7 @@
| [REVIEW_bug_t18_workplan_entry.md](_Historical/REVIEW_bug_t18_workplan_entry.md) | Review report for BUG-T18 |
| [REVIEW_bug_t17_audit_log_rows_stay_unfolded.md](_Historical/REVIEW_bug_t17_audit_log_rows_stay_unfolded.md) | Review report for BUG-T17 |
| [REVIEW_bug_t14_latency_rows.md](_Historical/REVIEW_bug_t14_latency_rows.md) | Review report for BUG-T14 |
| [REVIEW_bug_t20_session_timeline_ordering.md](_Historical/REVIEW_bug_t20_session_timeline_ordering.md) | Review report for BUG-T20 |
| [REVIEW_bug_t19_audit_session_consistency.md](_Historical/REVIEW_bug_t19_audit_session_consistency.md) | Review report for BUG-T19 |
| [REVIEW_bug_t13_capture_params_hint.md](_Historical/REVIEW_bug_t13_capture_params_hint.md) | Review report for BUG-T13 |
| [REVIEW_bug_t11_request_timeline.md](_Historical/REVIEW_bug_t11_request_timeline.md) | Review report for BUG-T11 |
Expand All @@ -263,6 +265,8 @@

| Date | Task ID | Action |
|------|---------|--------|
| 2026-02-25 | BUG-T20 | Archived REVIEW_bug_t20_session_timeline_ordering report |
| 2026-02-25 | BUG-T20 | Archived Session_Timeline_can_show_negative_duration_due_to_incorrect_entry_ordering (PASS) |
| 2026-02-25 | BUG-T19 | Archived REVIEW_bug_t19_audit_session_consistency report |
| 2026-02-25 | BUG-T19 | Archived Audit_Log_and_Session_Timeline_are_inconsistent_with_tool_charts_in_multi_process_runs (PASS) |
| 2026-02-25 | BUG-T13 | Archived REVIEW_bug_t13_capture_params_hint report |
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
## REVIEW REPORT — BUG-T20 Session Timeline Ordering

**Scope:** `origin/main..HEAD`
**Files:** 8

### Summary Verdict
- [x] Approve
- [ ] Approve with comments
- [ ] Request changes
- [ ] Block

### Critical Issues
- None.

### Secondary Issues
- None.

### Architectural Notes
- Session ordering normalization is now enforced at the session computation layer (`detect_sessions`), not only at API-call sites, reducing the chance of future regressions from caller-side ordering assumptions.
- Existing API/websocket sorting behavior remains compatible and now benefits from defense in depth.

### Tests
- `PYTHONPATH=src pytest` → PASS (`651 passed, 5 skipped`)
- `ruff check src/` → PASS
- `mypy src/` → PASS
- `PYTHONPATH=src pytest --cov` → PASS (`Total coverage: 91.33%`, threshold 90%)

### Next Steps
- FOLLOW-UP skipped: no actionable review findings to add as new workplan tasks.
4 changes: 2 additions & 2 deletions SPECS/INPROGRESS/next.md
Original file line number Diff line number Diff line change
Expand Up @@ -2,12 +2,12 @@

## Recently Archived

- **BUG-T20** — Session Timeline can show negative duration due to incorrect entry ordering (2026-02-25, PASS)
- **BUG-T19** — Audit Log and Session Timeline are inconsistent with tool charts in multi-process runs (2026-02-25, PASS)
- **BUG-T13** — Per-Tool Latency Statistics does not show params when `capture_params` is false (2026-02-25, PASS)
- **BUG-T11** — Chart Request Timeline never shows actual events (2026-02-25, PASS)

## Suggested Next Tasks

- BUG-T20 — Session Timeline can show negative duration due to incorrect entry ordering
- BUG-T18 — Error Breakdown widget must be full width streatched
- BUG-T4 — Repeated Xcode permission prompts for each short-lived MCP client process
- BUG-T1 — Kimi CLI MCP Connection Failure
11 changes: 6 additions & 5 deletions SPECS/Workplan.md
Original file line number Diff line number Diff line change
Expand Up @@ -1680,9 +1680,10 @@ Use export endpoints (`/api/audit/export/json` or `/api/audit/export/csv`) for a

### BUG-T20: Session Timeline can show negative duration due to incorrect entry ordering
- **Type:** Bug / Web UI / Session Analytics
- **Status:** 🔴 Open
- **Status:** ✅ Fixed (2026-02-25)
- **Priority:** P1
- **Discovered:** 2026-02-20
- **Completed:** 2026-02-25
- **Component:** Session detection path (`webui/server.py`, `webui/sessions.py`)
- **Affected Clients:** All clients using Session Timeline
- **Affected Surface:** Session Timeline duration and ordering
Expand All @@ -1703,10 +1704,10 @@ Session start/end ordering appears inverted.
None.

#### Resolution Path
- [ ] Normalize session input ordering to ascending timestamps before calling `detect_sessions()`
- [ ] Add defensive sorting (or contract enforcement) in session computation path
- [ ] Add regression test asserting non-negative session duration for mixed/newest-first inputs
- [ ] Validate timeline rendering shows monotonic ordering and correct latest event after reconnect/activity
- [x] Normalize session input ordering to ascending timestamps before calling `detect_sessions()`
- [x] Add defensive sorting (or contract enforcement) in session computation path
- [x] Add regression test asserting non-negative session duration for mixed/newest-first inputs
- [x] Validate timeline rendering shows monotonic ordering and correct latest event after reconnect/activity

#### Related Items
- **BUG-T19** — Shared audit/session consistency issue may amplify session timeline staleness
Expand Down
24 changes: 17 additions & 7 deletions src/mcpbridge_wrapper/webui/sessions.py
Original file line number Diff line number Diff line change
Expand Up @@ -8,16 +8,24 @@
from typing import Any, Dict, List


def _entry_timestamp(entry: Dict[str, Any]) -> float:
"""Parse a session entry timestamp for deterministic ordering."""
try:
return float(entry.get("timestamp", 0.0))
except (TypeError, ValueError):
return 0.0


def detect_sessions(
entries: List[Dict[str, Any]],
gap_seconds: float = 300.0,
) -> List[Dict[str, Any]]:
"""Group sorted audit entries into sessions by idle gap.
"""Group audit entries into sessions by idle gap.

A session is a contiguous run of tool calls where no consecutive pair
is separated by more than ``gap_seconds``. Entries must already be
sorted by ``timestamp`` ascending; unsorted input produces undefined
groupings.
is separated by more than ``gap_seconds``. Inputs are normalized to
``timestamp`` ascending order before grouping to ensure stable,
non-negative session boundaries even when callers pass newest-first rows.

Args:
entries: List of audit log entry dicts. Each entry must have a
Expand Down Expand Up @@ -54,12 +62,14 @@ def detect_sessions(
if not entries:
return []

ordered_entries = sorted(entries, key=_entry_timestamp)

sessions: List[Dict[str, Any]] = []
current_tools: List[Dict[str, Any]] = []
prev_ts: float = 0.0

for entry in entries:
ts = float(entry.get("timestamp", 0.0))
for entry in ordered_entries:
ts = _entry_timestamp(entry)

# Start a new session if this is not the first entry and the gap is too large.
if current_tools and (ts - prev_ts) > gap_seconds:
Expand All @@ -81,7 +91,7 @@ def _extract_tool(entry: Dict[str, Any]) -> Dict[str, Any]:
return {
"request_id": entry.get("request_id"),
"tool": entry.get("tool", ""),
"timestamp": float(entry.get("timestamp", 0.0)),
"timestamp": _entry_timestamp(entry),
"timestamp_iso": entry.get("timestamp_iso", ""),
"latency_ms": entry.get("latency_ms"),
"error": entry.get("error"),
Expand Down
51 changes: 51 additions & 0 deletions tests/unit/webui/test_server.py
Original file line number Diff line number Diff line change
Expand Up @@ -174,6 +174,57 @@ def test_sessions_endpoint_sorts_entries_chronologically(self, client, audit, mo
assert session["end"] == 200.0
assert [t["request_id"] for t in session["tools"]] == ["req-1", "req-2"]

def test_sessions_endpoint_handles_mixed_order_and_preserves_latest_event(
self, client, audit, monkeypatch
):
"""Sessions API yields monotonic boundaries for mixed-order audit rows."""
mixed_entries = [
{
"timestamp": 600.0,
"timestamp_iso": "2026-02-25T10:10:00Z",
"tool": "NewestInFirstSession",
"request_id": "req-3",
"direction": "response",
},
{
"timestamp": 100.0,
"timestamp_iso": "2026-02-25T10:01:40Z",
"tool": "OldestInFirstSession",
"request_id": "req-1",
"direction": "response",
},
{
"timestamp": 350.0,
"timestamp_iso": "2026-02-25T10:05:50Z",
"tool": "MiddleInFirstSession",
"request_id": "req-2",
"direction": "response",
},
{
"timestamp": 1400.0,
"timestamp_iso": "2026-02-25T10:23:20Z",
"tool": "OnlyInSecondSession",
"request_id": "req-4",
"direction": "response",
},
]

monkeypatch.setattr(audit, "get_entries", lambda *args, **kwargs: mixed_entries)

response = client.get("/api/sessions?limit=4&gap_seconds=300")
assert response.status_code == 200
sessions = response.json()["sessions"]
assert len(sessions) == 2

first, second = sessions
assert first["start"] == 100.0
assert first["end"] == 600.0
assert [t["request_id"] for t in first["tools"]] == ["req-1", "req-2", "req-3"]
assert second["start"] == 1400.0
assert second["end"] == 1400.0
assert second["tools"][-1]["request_id"] == "req-4"
assert all(session["start"] <= session["end"] for session in sessions)

def test_export_audit_json(self, client, audit):
"""Test exporting audit as JSON."""
audit.log("XcodeRead")
Expand Down
32 changes: 32 additions & 0 deletions tests/unit/webui/test_sessions.py
Original file line number Diff line number Diff line change
Expand Up @@ -100,6 +100,38 @@ def test_multiple_sessions_start_end(self):
assert result[1]["end"] == 2100.0


class TestDetectSessionsInputOrdering:
"""Input ordering is normalized to protect session boundaries."""

def test_newest_first_input_yields_non_negative_duration(self):
entries = [_entry(200.0, req_id="req-2"), _entry(100.0, req_id="req-1")]
result = detect_sessions(entries, gap_seconds=300)

assert len(result) == 1
session = result[0]
assert session["start"] == 100.0
assert session["end"] == 200.0
assert session["start"] <= session["end"]
assert [tool["request_id"] for tool in session["tools"]] == ["req-1", "req-2"]

def test_mixed_order_input_still_splits_by_gap_correctly(self):
entries = [
_entry(300.0, req_id="req-3"),
_entry(100.0, req_id="req-1"),
_entry(250.0, req_id="req-2"),
_entry(900.0, req_id="req-4"),
]
result = detect_sessions(entries, gap_seconds=300)

assert len(result) == 2
assert result[0]["start"] == 100.0
assert result[0]["end"] == 300.0
assert [tool["request_id"] for tool in result[0]["tools"]] == ["req-1", "req-2", "req-3"]
assert result[1]["start"] == 900.0
assert result[1]["end"] == 900.0
assert all(session["start"] <= session["end"] for session in result)


class TestDetectSessionsZeroGap:
"""Zero gap puts every call in its own session."""

Expand Down