spikerj/spikersoft-issues
1
0
Fork 0
Code Issues 196 Pull Requests Actions Packages Projects Releases Wiki Activity

Epic: End-to-end trace + log correlation for the art_pipe native-microservice integration (Jaeger + Seq) #428

New Issue
Open
opened 2026-07-06 02:25:34 +00:00 by spikerj · 2 comments
spikerj commented 2026-07-06 02:25:34 +00:00
Owner
Copy Link
Copy Source

Goal

Full, connected observability for a ProArt asset from API submit → RabbitMQ → ArtPipeProcessor orchestration → the Python art_pipe generation worker → back, in both Jaeger (traces) and Seq (logs) — the same bar every native SpikerSoft microservice meets. Any code absorbed into the ecosystem as a native microservice must be end-to-end traceable.

Current state (verified)

Traced & context-propagated (✅): API command → RabbitMQ (traceparent in headers) → ArtPipeStageConsumer extracts context via ActivityHelper.StartActivityFromRabbitMQMessage(...) → orchestrator/GPU-lease/dispatch. ArtPipeProcessor wires .WithSerilog() (Seq http://seq:5341) + .WithTelemetry() (OTLP http://jaeger:4317, SampleRatio 1.0).

Trace breaks at the .NET→Python seam (❌):

  • No traceparent crosses into the worker. SubprocessArtPipeStageExecutor.ApplyWorkerEnvironment sets PYTHONPATH/PYTHONUNBUFFERED/BLENDER_BIN only; the stdin job spec carries job_id but no trace/span id.
  • art_pipe has zero OpenTelemetry — the actual generation work (concept/modeling/texturing/rigging/animation/export/enrichment, model inference, Blender render) emits no spans. In Jaeger it's one opaque ProcessArtAssetStage span.
  • art_pipe doesn't log to Seq — logging_config.py writes a local logs/debug.log with thread-local asset_id/job_id context. Correlation across the seam is currently by asset_id/job_id only, never by trace_id.

Reference implementation (reuse this — don't reinvent)

spikersoft-backend/SpikerSoft.EventHandlers.ImageDescription.Python/image_description_service.py (and Trellis3D.Python) already do .NET↔Python OTel correlation "and back":

  • OTel SDK: TracerProvider + Resource(SERVICE_NAME=...) + BatchSpanProcessor + OTLPSpanExporter(endpoint=JAEGER_ENDPOINT, insecure=True), default http://jaeger:4317.
  • Extract: _extract_trace_context(properties) reads traceparent/tracestate; rebuild parent via TraceContextTextMapPropagator().extract(carrier=...); start_as_current_span(..., context=parent_context).
  • Onward hop: _inject_workflow_trace_context(...) re-injects traceparent into the next request.

Known gotchas already solved there (carry them over):

  1. "invalid parent span" race — default BatchSpanProcessor 5000ms schedule delay makes the Python child span export before the .NET parent lands in Jaeger. Fix: short schedule delay (~1s), as they did.
  2. traceparent header arrives as bytes — decode utf-8 before use.
  3. Metrics are disabled (Jaeger OTLP = traces only).

Key difference for art_pipe (design note)

The precedent's carrier is RabbitMQ message headers. art_pipe is not a bus consumer — the ArtPipeProcessor spawns python -m artpipe.worker --serve and streams jobs over stdin/stdout (resident serve mode, #368). So the trace-context carrier must be the per-job stdin spec JSON (add a _traceparent field) and/or the subprocess TRACEPARENT env var — per job, not per process (the resident worker serves many jobs across its lifetime; each must start a fresh span from that job's context).

Workstreams (sub-issues)

  1. .NET side — inject W3C traceparent into the worker (stdin spec + env) and add a per-stage child span. (self-contained, backend-mergeable; no-op until #2 consumes it)
  2. art_pipe — add OTel SDK + OTLP exporter, extract parent context from the job spec, span-per-stage/model-call; reuse the BatchSpanProcessor fast-export fix.
  3. art_pipe logs → Seq — ship worker logs to Seq (CLEF) and/or stamp trace_id into the log context for trace↔log correlation.

Acceptance criteria

  • A single Jaeger trace for one asset spans API → bus → ArtPipeProcessor → each art_pipe stage/model call as child spans, correctly parented (no orphans/invalid-parent).
  • Seq shows the .NET orchestration logs and art_pipe worker logs for that asset, correlated by trace_id (not just asset_id).
  • Works in both executor modes (subprocess + resident serve).

Refs #346 (ProArt epic), #368 (resident serve), #348 (GPU worker), #389 (ArtStudioMetrics). Precedent: ImageDescription.Python / Trellis3D.Python.

## Goal Full, connected observability for a ProArt asset from **API submit → RabbitMQ → ArtPipeProcessor orchestration → the Python `art_pipe` generation worker → back**, in **both Jaeger (traces) and Seq (logs)** — the same bar every native SpikerSoft microservice meets. Any code absorbed into the ecosystem as a native microservice must be end-to-end traceable. ## Current state (verified) **Traced & context-propagated (✅):** API command → RabbitMQ (`traceparent` in headers) → `ArtPipeStageConsumer` extracts context via `ActivityHelper.StartActivityFromRabbitMQMessage(...)` → orchestrator/GPU-lease/dispatch. ArtPipeProcessor wires `.WithSerilog()` (Seq `http://seq:5341`) + `.WithTelemetry()` (OTLP `http://jaeger:4317`, `SampleRatio 1.0`). **Trace breaks at the .NET→Python seam (❌):** - No `traceparent` crosses into the worker. `SubprocessArtPipeStageExecutor.ApplyWorkerEnvironment` sets `PYTHONPATH/PYTHONUNBUFFERED/BLENDER_BIN` only; the stdin job spec carries `job_id` but no trace/span id. - `art_pipe` has **zero OpenTelemetry** — the actual generation work (concept/modeling/texturing/rigging/animation/export/enrichment, model inference, Blender render) emits **no spans**. In Jaeger it's one opaque `ProcessArtAssetStage` span. - `art_pipe` **doesn't log to Seq** — `logging_config.py` writes a local `logs/debug.log` with thread-local `asset_id/job_id` context. Correlation across the seam is currently by `asset_id/job_id` only, never by `trace_id`. ## Reference implementation (reuse this — don't reinvent) `spikersoft-backend/SpikerSoft.EventHandlers.ImageDescription.Python/image_description_service.py` (and `Trellis3D.Python`) already do .NET↔Python OTel correlation "and back": - OTel SDK: `TracerProvider` + `Resource(SERVICE_NAME=...)` + `BatchSpanProcessor` + `OTLPSpanExporter(endpoint=JAEGER_ENDPOINT, insecure=True)`, default `http://jaeger:4317`. - Extract: `_extract_trace_context(properties)` reads `traceparent`/`tracestate`; rebuild parent via `TraceContextTextMapPropagator().extract(carrier=...)`; `start_as_current_span(..., context=parent_context)`. - Onward hop: `_inject_workflow_trace_context(...)` re-injects `traceparent` into the next request. **Known gotchas already solved there (carry them over):** 1. **"invalid parent span" race** — default `BatchSpanProcessor` 5000ms schedule delay makes the Python child span export *before* the .NET parent lands in Jaeger. Fix: short schedule delay (~1s), as they did. 2. `traceparent` header arrives as `bytes` — decode utf-8 before use. 3. Metrics are disabled (Jaeger OTLP = traces only). ## Key difference for art_pipe (design note) The precedent's carrier is **RabbitMQ message headers**. `art_pipe` is **not** a bus consumer — the ArtPipeProcessor spawns `python -m artpipe.worker --serve` and streams jobs over **stdin/stdout** (resident serve mode, #368). So the trace-context carrier must be the **per-job stdin spec JSON** (add a `_traceparent` field) and/or the subprocess `TRACEPARENT` env var — **per job, not per process** (the resident worker serves many jobs across its lifetime; each must start a fresh span from that job's context). ## Workstreams (sub-issues) 1. **.NET side** — inject W3C `traceparent` into the worker (stdin spec + env) and add a per-stage child span. _(self-contained, backend-mergeable; no-op until #2 consumes it)_ 2. **art_pipe** — add OTel SDK + OTLP exporter, extract parent context from the job spec, span-per-stage/model-call; reuse the BatchSpanProcessor fast-export fix. 3. **art_pipe logs → Seq** — ship worker logs to Seq (CLEF) and/or stamp `trace_id` into the log context for trace↔log correlation. ## Acceptance criteria - A single Jaeger trace for one asset spans API → bus → ArtPipeProcessor → **each art_pipe stage/model call** as child spans, correctly parented (no orphans/invalid-parent). - Seq shows the .NET orchestration logs **and** art_pipe worker logs for that asset, correlated by `trace_id` (not just `asset_id`). - Works in both executor modes (subprocess + resident serve). Refs #346 (ProArt epic), #368 (resident serve), #348 (GPU worker), #389 (ArtStudioMetrics). Precedent: ImageDescription.Python / Trellis3D.Python.
spikerj commented 2026-07-06 02:26:53 +00:00
Author
Owner
Copy Link
Copy Source

Workstreams filed:

  • #429 — .NET: propagate W3C traceparent into the worker + per-stage child span (start here; self-contained, backend-mergeable)
  • #430 — art_pipe: OpenTelemetry spans with parent-context extraction from the job spec (depends on #429)
  • #431 — art_pipe: ship worker logs to Seq + stamp trace_id (complements #430)

Execution order: #429 → #430 → #431. #429 is additive and inert until #430 consumes the context, so it can merge on its own without changing runtime behavior.

Workstreams filed: - **#429** — .NET: propagate W3C `traceparent` into the worker + per-stage child span _(start here; self-contained, backend-mergeable)_ - **#430** — art_pipe: OpenTelemetry spans with parent-context extraction from the job spec _(depends on #429)_ - **#431** — art_pipe: ship worker logs to Seq + stamp `trace_id` _(complements #430)_ Execution order: #429 → #430 → #431. #429 is additive and inert until #430 consumes the context, so it can merge on its own without changing runtime behavior.
spikerj commented 2026-07-08 04:29:29 +00:00
Author
Owner
Copy Link
Copy Source

Status roll-up — Python correlation is wired end-to-end

  • ✅ #430 — art_pipe worker OTel spans (per-job CONSUMER span re-parented from the injected _traceparent, nested model.run/preprocess). Merged (artpipe PR #7).
  • ✅ #431 — worker structured logs → Seq (stdlib CLEF over urllib), trace_id/span_id stamped from the active span. Merged (artpipe PR #8).
  • ✅ #459 — .NET ArtPipeProcessor now propagates JAEGER_ENDPOINT/SEQ_URL/SEQ_API_KEY into the worker subprocess. Merged (backend PR #183).
  • ⏳ #460 — install opentelemetry-sdk into the per-model venvs so span export actually fires. Decision-gated (which venvs / opt-in flag), so parked for a call.

Net effect on next deploy: #431's Seq log↔trace correlation activates immediately (stdlib-only — SEQ_URL alone is enough). #430's Jaeger spans are fully wired and primed; they start exporting the moment #460 lands the OTel packages in the venvs. So the epic is functionally complete except for that one venv-packaging decision.

## Status roll-up — Python correlation is wired end-to-end - ✅ **#430** — art_pipe worker OTel spans (per-job CONSUMER span re-parented from the injected `_traceparent`, nested `model.run`/`preprocess`). Merged (artpipe PR #7). - ✅ **#431** — worker structured logs → Seq (stdlib CLEF over `urllib`), `trace_id`/`span_id` stamped from the active span. Merged (artpipe PR #8). - ✅ **#459** — .NET `ArtPipeProcessor` now propagates `JAEGER_ENDPOINT`/`SEQ_URL`/`SEQ_API_KEY` into the worker subprocess. Merged (backend PR #183). - ⏳ **#460** — install `opentelemetry-sdk` into the per-model venvs so span export actually fires. **Decision-gated** (which venvs / opt-in flag), so parked for a call. **Net effect on next deploy:** #431's Seq log↔trace correlation activates immediately (stdlib-only — `SEQ_URL` alone is enough). #430's Jaeger spans are fully wired and primed; they start exporting the moment #460 lands the OTel packages in the venvs. So the epic is functionally complete except for that one venv-packaging decision.
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
agentic
Actionable surfaced by the agentic architecture & security review
 bug
Something is not working
 duplicate
This issue or pull request already exists
 enhancement
New feature
 help wanted
Need some help
 invalid
Something is wrong
 question
More information is needed
 sonarqube
Code quality issue surfaced by SonarQube (bug / code smell)
 wontfix
This won't be fixed
No labels
Milestone
No items
No Milestone
Projects
Clear projects
No projects
Assignees
Clear assignees
spikerj (Joseph Spiker)
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: spikerj/spikersoft-issues#428