Skip to content

test: e2e JSONL log verification for request tracing - #7817

Merged
nnshah1 merged 2 commits into
mainfrom
nnshah1/DIS-1643-pr4-e2e-tests-v2
Apr 7, 2026
Merged

test: e2e JSONL log verification for request tracing#7817
nnshah1 merged 2 commits into
mainfrom
nnshah1/DIS-1643-pr4-e2e-tests-v2

Conversation

@nnshah1

@nnshah1 nnshah1 commented Apr 2, 2026

Copy link
Copy Markdown
Contributor

Summary

E2e JSONL log verification tests for DIS-1643 request tracing infrastructure, plus two Rust fixes discovered during test development.

Rust fixes

  • DistributedTraceIdLayer: Inherit x_request_id and request_id from parent span context in child spans. Without this, transport headers didn't include x-request-id, so workers never received it.
  • InflightGuard: Capture Span::current() at creation and enter() it in Drop. Preserves span context on "request completed" logs even when the guard outlives the span (streaming cancellation).

Tests (11 tests)

  • Aggregated: unary success (with token metrics + worker ID propagation), streaming success (with ttft/itl metrics), 404 error, invalid UUID warning, request ID propagation (frontend↔worker trace_id + x_request_id correlation), client cancellation, worker crash
  • Disaggregated: streaming success (prefill+decode), unary success, prefill crash, decode crash

Infrastructure

  • Adds extra_env and extra_args to MockerWorkerProcess (matching DynamoFrontendProcess pattern)
  • Tests use x-request-id (standard header) instead of deprecated x-dynamo-request-id
  • Asserts both x_request_id and request_id propagate to worker logs

Test plan

  • All 11 tests pass locally (pytest -n auto, 27s)
  • cargo clippy --workspace -- -D warnings clean
  • cargo test --workspace passes
  • CI checks pass

🤖 Generated with Claude Code

@nnshah1
nnshah1 requested a review from a team as a code owner April 2, 2026 15:44
@nnshah1
nnshah1 requested a review from a team April 2, 2026 15:44
@github-actions github-actions Bot added the test label Apr 2, 2026
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr3-metrics-capture branch from 2f3ed0a to fca4c36 Compare April 2, 2026 16:41
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from d741543 to 0dcd8f2 Compare April 2, 2026 16:41
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr3-metrics-capture branch from fca4c36 to 62a203a Compare April 2, 2026 16:48
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from 0dcd8f2 to 067da02 Compare April 2, 2026 16:48
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from 067da02 to 758aa13 Compare April 2, 2026 17:09
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr3-metrics-capture branch from 62a203a to 6f37eb1 Compare April 2, 2026 17:09
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from 758aa13 to 63e585a Compare April 2, 2026 17:17
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr3-metrics-capture branch from 6f37eb1 to 2eef2a8 Compare April 2, 2026 17:17
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from 63e585a to d62cafc Compare April 2, 2026 17:20
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr3-metrics-capture branch from 2eef2a8 to 1b49ccf Compare April 2, 2026 17:20
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from d62cafc to 4af5883 Compare April 2, 2026 17:26
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr3-metrics-capture branch from 1b49ccf to 40374d3 Compare April 2, 2026 17:26
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from 4af5883 to b69ffd0 Compare April 2, 2026 17:35
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr3-metrics-capture branch from 40374d3 to a9ddded Compare April 2, 2026 17:35
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr3-metrics-capture branch from a9ddded to 5c3d4f7 Compare April 2, 2026 19:12
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from b69ffd0 to 29e1ada Compare April 2, 2026 19:12
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr3-metrics-capture branch from 5c3d4f7 to d6edb5c Compare April 2, 2026 19:50
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from 29e1ada to 733c66b Compare April 2, 2026 19:50
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from 43f0d20 to 986e801 Compare April 2, 2026 23:50
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr2-lifecycle-and-metrics branch 3 times, most recently from 7448dfa to c458b00 Compare April 3, 2026 00:54
Base automatically changed from nnshah1/DIS-1643-pr2-lifecycle-and-metrics to main April 3, 2026 01:38
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from 986e801 to d13b3f4 Compare April 3, 2026 22:46
@coderabbitai

coderabbitai Bot commented Apr 3, 2026

Copy link
Copy Markdown
Contributor

Walkthrough

A new E2E test module is added that validates JSONL request tracing logs across frontend and worker processes, including helpers for parsing logs, fixtures for various service configurations (aggregated, disaggregated, with crash scenarios), and comprehensive test cases covering success paths, error handling, trace correlation, cancellation, and worker crash scenarios.

Changes

Cohort / File(s) Summary
Request Tracing Log Tests
tests/frontend/test_request_tracing_logs.py
New test module with helper functions for JSONL log parsing and request sending, a JsonlMockerWorkerProcess subclass for JSONL-enabled workers, four pytest fixtures for aggregated/disaggregated service configurations with optional crash simulation, and eleven test functions validating request lifecycle logging, error handling, trace ID propagation, streaming behavior, cancellation, and worker crash scenarios.

Estimated code review effort

🎯 4 (Complex) | ⏱️ ~50 minutes

🚥 Pre-merge checks | ✅ 3
✅ Passed checks (3 passed)
Check name Status Explanation
Title check ✅ Passed The PR title clearly and accurately summarizes the main change: adding end-to-end tests that verify JSONL log output for request tracing functionality.
Docstring Coverage ✅ Passed Docstring coverage is 86.96% which is sufficient. The required threshold is 80.00%.
Description check ✅ Passed The PR description provides a clear summary of the changes, test coverage, and testing approach, and addresses most key elements expected in the template.

✏️ Tip: You can configure your own custom pre-merge checks in the settings.


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.

❤️ Share

Comment @coderabbitai help to get the list of available commands and usage tips.

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Actionable comments posted: 5

🧹 Nitpick comments (3)
tests/frontend/test_request_tracing_logs.py (3)

78-85: Consider using ManagedProcess.read_logs() instead of custom helper.

ManagedProcess already provides a read_logs() method (see context snippet 4) that handles the same logic with additional error handling. This would reduce code duplication.

Proposed simplification
-def read_log_file(process) -> str:
-    """Read the log file from a ManagedProcess."""
-    log_path = process.log_path
-    if log_path and os.path.exists(log_path):
-        with open(log_path, "r", encoding="utf-8", errors="ignore") as f:
-            return f.read()
-    return ""
+def read_log_file(process: ManagedProcess) -> str:
+    """Read the log file from a ManagedProcess."""
+    return process.read_logs()
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@tests/frontend/test_request_tracing_logs.py` around lines 78 - 85, The helper
function read_log_file duplicates logic already provided by
ManagedProcess.read_logs(); replace usages of read_log_file with calling
process.read_logs() and remove the read_log_file function to avoid duplication;
ensure any callers expecting a string continue to work
(ManagedProcess.read_logs() returns the same log string and includes extra error
handling) and update imports/tests if needed to reference
ManagedProcess.read_logs() directly.

247-249: Consider using num_system_ports fixture to request additional ports.

The manual allocate_port()/deallocate_port() pattern works, but the guidelines suggest using dynamo_dynamic_ports for port allocation. You could use the num_system_ports fixture (indirectly via parametrize or fixture override) to get 2 system ports from dynamo_dynamic_ports.system_ports instead of manual allocation.

However, the current approach is functionally correct and properly cleans up.

Also applies to: 288-289

🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@tests/frontend/test_request_tracing_logs.py` around lines 247 - 249, Replace
the manual allocate_port/deallocate_port pattern with the test fixture-driven
allocation: stop calling allocate_port()/deallocate_port() for
decode_system_port and instead request two system ports via the num_system_ports
fixture so the test uses dynamo_dynamic_ports.system_ports; update references to
decode_system_port to use the second entry from
dynamo_dynamic_ports.system_ports and remove manual cleanup (deallocate_port)
since the fixture handles lifecycle. Ensure you modify the test function
signature or parametrize to accept num_system_ports (or dynamo_dynamic_ports)
and adjust any other occurrences (lines around decode_system_port and the
similar allocation at 288-289) to use the fixture-provided ports.

235-290: Consider consolidating duplicate disaggregated fixtures.

tracing_services_disagg and tracing_services_disagg_slow are nearly identical, differing only in speedup_ratio. Per pytest guidelines, avoid duplicated test infrastructure. Consider using parametrization or a factory fixture.

Example consolidation
def _create_disagg_fixture(request, ports, speedup_ratio=100):
    """Factory for disaggregated service fixtures."""
    jsonl_env = {"DYN_LOGGING_JSONL": "1", "DYN_LOG": "info"}
    decode_system_port = allocate_port(8200)
    
    try:
        with DynamoFrontendProcess(...) as frontend_process:
            with JsonlMockerWorkerProcess(..., speedup_ratio=speedup_ratio, ...) as prefill_worker:
                with JsonlMockerWorkerProcess(..., speedup_ratio=speedup_ratio, ...) as decode_worker:
                    wait_for_http_completions_ready(...)
                    yield {...}
    finally:
        deallocate_port(decode_system_port)


`@pytest.fixture`(scope="function")
def tracing_services_disagg(request, runtime_services_dynamic_ports, dynamo_dynamic_ports, predownload_tokenizers):
    yield from _create_disagg_fixture(request, dynamo_dynamic_ports, speedup_ratio=100)


`@pytest.fixture`(scope="function") 
def tracing_services_disagg_slow(request, runtime_services_dynamic_ports, dynamo_dynamic_ports, predownload_tokenizers):
    yield from _create_disagg_fixture(request, dynamo_dynamic_ports, speedup_ratio=0.1)

Also applies to: 686-737

🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@tests/frontend/test_request_tracing_logs.py` around lines 235 - 290, The two
fixtures tracing_services_disagg and tracing_services_disagg_slow are nearly
identical; refactor by extracting a factory helper (e.g.,
_create_disagg_fixture) that accepts speedup_ratio and shared params, move the
common jsonl_env, allocate_port/ deallocate_port logic and the nested
DynamoFrontendProcess/JsonlMockerWorkerProcess setup into that helper, and have
both fixtures simply yield from _create_disagg_fixture(request,
dynamo_dynamic_ports, speedup_ratio=<100 or 0.1>); ensure you pass speedup_ratio
through to the JsonlMockerWorkerProcess instantiations and keep
wait_for_http_completions_ready and returned dict keys unchanged.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.

Inline comments:
In `@tests/frontend/test_request_tracing_logs.py`:
- Around line 36-42: The module-level pytest markers (pytestmark list) lack a
timeout; add a pytest.mark.timeout(...) entry to that pytestmark list (the
pytestmark variable in this test module) to bound tests that perform
sleeps/network calls—e.g., append pytest.mark.timeout(300) or an appropriate
seconds value to pytestmark so all tests in
tests/frontend/test_request_tracing_logs.py get an overall timeout and cannot
hang CI.
- Around line 760-779: Replace the blanket "except Exception: pass" in the
try/except that wraps requests.post(...) and resp.iter_lines() with catching
requests-specific exceptions (e.g., requests.exceptions.RequestException or more
specific subclasses like Timeout, ConnectionError) so you only swallow expected
network/request errors; update the except clause to catch
requests.exceptions.RequestException and handle/clean up appropriately (for
example, ensure resp is closed if present or re-raise/unittest-fail) referencing
the requests.post call and resp.iter_lines usage in
tests/frontend/test_request_tracing_logs.py.
- Line 591: Move the `import threading` statement to the top-level imports of
the module (with the other imports around the module header) and remove the
local `import threading` occurrences inside the test functions (the three places
where `threading` is currently imported locally). Update only the import
placements—do not change any uses of `threading` within the test functions.
- Around line 1-3: Pre-commit hook failures: run the formatter and autofixers on
tests/frontend/test_request_tracing_logs.py (e.g., ruff format and ruff check
--fix, then black) and fix any blind/bare exception catches inside that test
file by replacing bare "except:" handlers with explicit exception types (or use
"except Exception as e"), log or assert the exception where appropriate, and
avoid swallowing errors silently so ruff no longer flags them; ensure the file
is formatted by black afterward.
- Around line 477-498: Replace the blanket "except Exception: pass" around the
requests.post/resp.iter_lines block with a handler for
requests.exceptions.RequestException (e.g., "except
requests.exceptions.RequestException as e:") and log the error (using the
test/module logger or logging.exception) so failures are visible; keep the
resp.close() behavior as needed and ensure requests is imported so the specific
exception class is available.

---

Nitpick comments:
In `@tests/frontend/test_request_tracing_logs.py`:
- Around line 78-85: The helper function read_log_file duplicates logic already
provided by ManagedProcess.read_logs(); replace usages of read_log_file with
calling process.read_logs() and remove the read_log_file function to avoid
duplication; ensure any callers expecting a string continue to work
(ManagedProcess.read_logs() returns the same log string and includes extra error
handling) and update imports/tests if needed to reference
ManagedProcess.read_logs() directly.
- Around line 247-249: Replace the manual allocate_port/deallocate_port pattern
with the test fixture-driven allocation: stop calling
allocate_port()/deallocate_port() for decode_system_port and instead request two
system ports via the num_system_ports fixture so the test uses
dynamo_dynamic_ports.system_ports; update references to decode_system_port to
use the second entry from dynamo_dynamic_ports.system_ports and remove manual
cleanup (deallocate_port) since the fixture handles lifecycle. Ensure you modify
the test function signature or parametrize to accept num_system_ports (or
dynamo_dynamic_ports) and adjust any other occurrences (lines around
decode_system_port and the similar allocation at 288-289) to use the
fixture-provided ports.
- Around line 235-290: The two fixtures tracing_services_disagg and
tracing_services_disagg_slow are nearly identical; refactor by extracting a
factory helper (e.g., _create_disagg_fixture) that accepts speedup_ratio and
shared params, move the common jsonl_env, allocate_port/ deallocate_port logic
and the nested DynamoFrontendProcess/JsonlMockerWorkerProcess setup into that
helper, and have both fixtures simply yield from _create_disagg_fixture(request,
dynamo_dynamic_ports, speedup_ratio=<100 or 0.1>); ensure you pass speedup_ratio
through to the JsonlMockerWorkerProcess instantiations and keep
wait_for_http_completions_ready and returned dict keys unchanged.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: CHILL

Plan: Pro

Run ID: bafeb052-b4fe-4466-8b19-2770f3e508c2

📥 Commits

Reviewing files that changed from the base of the PR and between c08034e and d13b3f4.

📒 Files selected for processing (1)
  • tests/frontend/test_request_tracing_logs.py

Comment thread tests/frontend/test_request_tracing_logs.py
Comment thread tests/frontend/test_request_tracing_logs.py
Comment thread tests/frontend/test_request_tracing_logs.py
Comment thread tests/frontend/test_request_tracing_logs.py Outdated
Comment thread tests/frontend/test_request_tracing_logs.py
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from d13b3f4 to 145f124 Compare April 3, 2026 23:30
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from 145f124 to c7500ba Compare April 3, 2026 23:44
@nnshah1
nnshah1 force-pushed the nnshah1/DIS-1643-pr4-e2e-tests-v2 branch from c7500ba to db659ff Compare April 6, 2026 17:20
11 parallel tests covering aggregated/disaggregated deployments,
unary/streaming, error handling, cancellation, and frontend-worker
trace correlation. Verifies "request received", "http response sent",
and "request completed" lifecycle logs with structured fields.

Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com>
Comment thread lib/llm/src/http/service/metrics.rs

@jh-nv jh-nv left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

LGTM. Thanks.

Comment thread tests/frontend/test_request_tracing_logs.py Outdated
Comment thread tests/frontend/test_request_tracing_logs.py Outdated
…n InflightGuard

Two fixes for request ID propagation:

1. DistributedTraceIdLayer now inherits x_request_id and request_id from
   parent spans when the child doesn't set them. This ensures
   inject_trace_headers_into_map includes x-request-id in transport
   headers even when called from child spans.

2. InflightGuard captures the current span at creation and enters it in
   Drop. This preserves span context (trace_id, x_request_id, etc.) on
   the "request completed" log even when the guard outlives the span
   (e.g. streaming responses where the guard drops after client disconnect).

Co-Authored-By: Claude Opus 4.6 (1M context) <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

frontend `python -m dynamo.frontend` and `dynamo-run in=http|text|grpc` size/XL test

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants