Skip to content

Perf: avoid repeated orchestration-history scans for tracing - #788

Open
Bernd Verst (berndverst) wants to merge 9 commits into
mainfrom
berndverst-fix-trace-history-scan-perf
Open

Perf: avoid repeated orchestration-history scans for tracing#788
Bernd Verst (berndverst) wants to merge 9 commits into
mainfrom
berndverst-fix-trace-history-scan-perf

Conversation

@berndverst

@berndverst Bernd Verst (berndverst) commented Jul 24, 2026

Copy link
Copy Markdown
Member

Summary

OnRunOrchestratorAsync in src/Worker/Grpc/GrpcDurableTaskWorker.Processor.cs scanned orchestration history to correlate tracing events unconditionally, and rescanned the full past-events list for every qualifying new event to find the originating TaskScheduled/SubOrchestrationInstanceCreated event — O(new events × past events), even when no tracing listener was registered.

This is a precise, internal-only performance fix:

  • Added TraceHelper.HasListeners, backed by ActivitySource.HasListeners(), and gated tracing-correlation work behind it so history is not scanned when no listener is registered.
  • Replaced the LINQ Concat scan for ExecutionStarted with a single-pass local function.
  • Added TraceHistoryEventLookup, which pre-registers only correlation IDs referenced by the current work item's new events, then resolves both scheduling-event types in one lazy history scan. Repeated lookups remain O(1), total correlation work is O(past events + new events), and temporary index storage is O(unique correlation IDs in the current work item), not O(all scheduling events in history).
  • Enforced the history invariant that each looked-up scheduling event type has a one-to-one event-ID mapping. Duplicate TaskScheduled or SubOrchestrationInstanceCreated IDs now throw a diagnostic InvalidOperationException instead of silently selecting an ambiguous event. With tracing enabled, the invalid work item is abandoned through the existing error path; valid histories are unaffected.

No public API or replay-output changes. For valid orchestration histories, trace output and orchestration behavior are unchanged.

Tests

  • TraceHistoryEventLookupTests: duplicate-ID invariant failures for both correlation types, no-match behavior, event-type filtering, empty input, completed and failed correlation events, lazy construction, one-pass mixed indexing, requested-ID-only storage, and per-ID/type duplicate isolation.
  • GrpcDurableTaskWorkerTests:
    • Proves the no-listener path invokes neither lookup by completing invalid duplicate-ID history that would throw if indexed.
    • Proves the listener-enabled path abandons duplicate-ID history and never invokes the completion RPC.
  • TracingIntegrationTests.HistoryEventLookupCorrelatesDistinctScheduledOperations: runs through the real in-process sidecar with two distinctly named activities and a sub-orchestration, then verifies exact client-span correlation for both indexes.
  • Full Worker.Grpc.Tests: 165/165 passed.
  • Full Grpc.IntegrationTests: 169/169 passed.
  • Worker.Grpc builds across netstandard2.0, net6.0, net8.0, and net10.0 with no errors.

Fixes #769

OnRunOrchestratorAsync previously scanned orchestration history to
correlate tracing events unconditionally, and for every qualifying
new event it rescanned the full past-events list to find the
originating TaskScheduled/SubOrchestrationInstanceCreated event -
O(new events x past events) work, even when no tracing listener was
registered.

- Add TraceHelper.HasListeners, a cheap check backed by
  ActivitySource.HasListeners(), and gate all tracing-correlation
  work in OnRunOrchestratorAsync behind it so nothing is scanned when
  no listener is registered.
- Replace the LINQ Concat-based scan for the ExecutionStarted event
  with a single-pass local function.
- Add TraceHistoryEventLookup, which builds one dictionary index per
  work item (built lazily, once) for O(1) repeated lookups instead of
  rescanning PastEvents per new event, while preserving the exact
  original first-wins (SubOrchestrationInstanceCreated) and last-wins
  (TaskScheduled) semantics for duplicate event IDs.

No public API changes; trace output, error handling, and replay
determinism are unaffected.

Adds regression tests for the no-listener fast path, first/last-wins
correlation semantics end-to-end, and direct unit tests for
TraceHistoryEventLookup.

Fixes #769

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot-Session: 9c538f3e-308d-48a3-af7f-b3baf90e97b2
Copilot AI lite review requested due to automatic review settings July 24, 2026 22:16
Comment thread src/Worker/Grpc/GrpcDurableTaskWorker.Processor.cs

Copilot AI 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.

Pull request overview

Improves the gRPC worker’s tracing correlation performance by avoiding unnecessary orchestration-history scans when tracing is disabled and by indexing past history events for O(1) correlation lookups when tracing is enabled. This aligns with the SDK’s goal of keeping worker-side orchestration processing efficient, especially for long-running instances with large histories.

Changes:

  • Added a cheap listener check (TraceHelper.HasListeners) and gated trace-correlation work in OnRunOrchestratorAsync behind it.
  • Replaced repeated past-history scans with a per-work-item indexed lookup (TraceHistoryEventLookup) that preserves prior first/last-wins semantics for duplicate event IDs.
  • Added unit and worker-level tests covering listener/no-listener behavior and duplicate-ID correlation semantics.

Reviewed changes

Copilot reviewed 5 out of 5 changed files in this pull request and generated no comments.

Show a summary per file
File Description
test/Worker/Grpc.Tests/TraceHistoryEventLookupTests.cs Adds focused unit tests for the new indexed lookup, including duplicate-ID first/last-wins semantics and filtering by event type.
test/Worker/Grpc.Tests/GrpcDurableTaskWorkerTests.cs Adds end-to-end worker tests for the no-listener fast path and for correlation semantics under a real ActivityListener.
src/Worker/Grpc/GrpcDurableTaskWorker.Processor.cs Gates tracing correlation behind HasListeners, replaces LINQ concat scan with a single-pass helper, and uses the indexed lookup for repeated correlation.
src/Shared/Grpc/Tracing/TraceHistoryEventLookup.cs Introduces a lazily-built, cached dictionary index for past events to avoid O(N×M) repeated scans.
src/Shared/Grpc/Tracing/TraceHelper.cs Exposes HasListeners backed by ActivitySource.HasListeners() to allow callers to skip trace-correlation work when tracing is disabled.

Copilot AI review requested due to automatic review settings July 27, 2026 18:37

Copilot AI 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.

Pull request overview

Copilot reviewed 5 out of 5 changed files in this pull request and generated no new comments.

@berndverst

Copy link
Copy Markdown
Member Author

Quantitative performance impact

I compared live head d223fc2 with its merge base in a focused Release/.NET 10 harness on Windows x64 (AMD EPYC 7763). It used the actual TraceHistoryEventLookup/TraceHelper.HasListeners code and the exact old lookup algorithm. Activity creation, the rest of worker execution, and gRPC were excluded, so these are correlation-stage measurements rather than fleet-wide orchestration averages.

Let H be past-event count and N_t/N_s qualifying task/sub-orchestration completion counts.

Path Old past-event inspections New work
No tracing listener execution-start search + up to N_t*H + sum(sub match positions) one HasListeners() check; zero history enumeration
Listener, task completions N_t*H one H-event task index + N_t dictionary lookups
Listener, sub-orchestration completions sum(sub match positions) one H-event sub index + N_s dictionary lookups

Representative, best, and adverse cases

“Representative” below means a selected ordinary shape, not production telemetry.

Case Listener / shape Correlation latency, old -> new Allocation/work item Interpretation
Average-style representative Off; H=100, 5 task completions 4.40 us -> ~6 ns 1,056 -> 0 B The history work is eliminated; the new value is near harness overhead, so the ratio is not meaningful
Listener-on ordinary task case H=100, 5 task completions 4.38 -> 2.00 us (-54.3%) 1,056 -> 4,704 B (+3,648 B) Faster CPU path, higher temporary allocation
Listener-on ordinary mixed case H=100, 3 task + 3 early sub matches 2.55 -> 3.43 us (~+34.5%) 1,024 -> 4,280 B (+3,256 B) Small/early-match histories can regress
Best measured large replay Off; H=10,000, 1,000 task completions 79.8 ms -> near harness overhead 160,256 -> 0 B Removes the entire quadratic correlation scan
Listener-on large fan-out H=10,000, 1,000 task completions 80.46 ms -> 333.5 us (-99.585%, ~241x) 160,256 -> 451,592 B (+291,336 B) Large CPU/latency gain traded for a temporary index
Listener-on mixed fan-out H=10,000, 500 task + 500 sub completions 36.98 ms -> 490.7 us (-98.673%, ~75x) 128,256 -> 431,438 B (+303,182 B) Same tradeoff with two lazy indexes
Constructed adverse case Listener on; one sub match at position 2 of H=10,000 166 ns -> 95.7 us (~576x as long) 352 -> 296 B Old FirstOrDefault stops at event 2; new code builds the full lazy index

The no-listener ~6 ns figures are close to benchmark-harness cost and should be read as “the scan was removed,” not as a credible millions-of-operations throughput claim.

Memory and GC

The lazy indexes reference existing events; they do not copy protobuf messages. On this x64 runtime, estimated incremental dictionary storage while live is approximately 28-56 B per unique indexed ID, including capacity slack/array headers but excluding the existing event objects.

  • 50 task entries: about 2.7 KiB retained, 4.7 KiB cumulatively allocated
  • 5,000 task entries: about 236 KiB retained, 452 KiB allocated
  • Two 3,333-entry indexes: about 227 KiB retained, 431 KiB allocated

Thus:

  • No listener: both scan CPU and correlation allocations fall to zero.
  • Listener + repeated lookups: CPU falls from O(N*H) to O(H+N), but temporary memory becomes O(unique history IDs).
  • Listener + one early sub lookup: CPU can regress from O(1) expected early exit to O(H) index construction.
  • A listener that samples every activity out still makes HasListeners() true and pays indexing costs.

Whole-worker throughput interpretation

Correlation-stage speedup does not translate directly to orchestration throughput. Using Amdahl's law:

  • If the old correlation work is 10% of turn CPU and the new path removes it, modeled turn throughput improves by about 11.1%.
  • If a large fan-out replay spends 50% of turn CPU in old correlation scans and that work becomes negligible, the modeled ceiling is about 2x turn throughput.

Those are sensitivity examples. Actual gains require telemetry for listener prevalence and the distributions of H, qualifying new events, event mix, and match positions.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
Copilot-Session: 01dc5b7c-c742-45b7-ae8c-5cda9bcfbd2c
Copilot AI review requested due to automatic review settings August 4, 2026 19:50

Copilot AI 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.

Pull request overview

Copilot reviewed 5 out of 5 changed files in this pull request and generated no new comments.

Comment thread src/Shared/Grpc/Tracing/TraceHistoryEventLookup.cs Outdated
Comment thread src/Shared/Grpc/Tracing/TraceHistoryEventLookup.cs Outdated
Comment thread src/Shared/Grpc/Tracing/TraceHistoryEventLookup.cs Outdated
Comment thread test/Worker/Grpc.Tests/GrpcDurableTaskWorkerTests.cs Outdated
Comment thread test/Worker/Grpc.Tests/GrpcDurableTaskWorkerTests.cs Outdated
Comment thread test/Worker/Grpc.Tests/GrpcDurableTaskWorkerTests.cs
Comment thread test/Worker/Grpc.Tests/TraceHistoryEventLookupTests.cs Outdated
Comment thread test/Worker/Grpc.Tests/TraceHistoryEventLookupTests.cs Outdated
Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>

Copilot-Session: 01dc5b7c-c742-45b7-ae8c-5cda9bcfbd2c
Copilot AI review requested due to automatic review settings August 13, 2026 01:58

Copilot AI 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.

Pull request overview

Copilot reviewed 6 out of 6 changed files in this pull request and generated 1 comment.

Suppressed comments (3)

test/Worker/Grpc.Tests/TraceHistoryEventLookupTests.cs:47

  • This test currently asserts that duplicate SubOrchestrationInstanceCreated event IDs throw, but the prior linear scan behavior (and the PR description) expects first-wins semantics for duplicate IDs to preserve correlation behavior.
        act.Should().Throw<InvalidOperationException>()
            .WithMessage("*'SubOrchestrationInstanceCreated'*event ID '2'*");
    }

test/Worker/Grpc.Tests/TraceHistoryEventLookupTests.cs:28

  • These tests currently assert that duplicate event IDs throw. Per the original implementation (TaskScheduled = last-wins, SubOrchestrationInstanceCreated = first-wins) and the PR description, duplicates should be tolerated with defined first/last-wins behavior rather than causing failures during tracing correlation.

This issue also appears on line 45 of the same file.

        act.Should().Throw<InvalidOperationException>()
            .WithMessage("*'TaskScheduled'*event ID '1'*");
    }

test/Worker/Grpc.Tests/GrpcDurableTaskWorkerTests.cs:377

  • These two tests rely on TraceHistoryEventLookup throwing on duplicate event IDs (and assert the work item is abandoned when a listener is registered). That behavior conflicts with the stated goal of preserving the original duplicate-ID correlation semantics (TaskScheduled last-wins, SubOrchestrationInstanceCreated first-wins). If duplicate IDs are expected to be tolerated, these tests should be reworked to validate the no-listener fast path without depending on duplicate-ID exceptions, and the listener-enabled path should validate the preserved first/last-wins correlation rather than abandonment.
        // Arrange: duplicate event IDs cause TraceHistoryEventLookup to throw when it builds an index. If this
        // invalid history still completes, the no-listener fast path did not invoke either lookup method.
        TraceHelper.HasListeners.Should().BeFalse();

Comment thread src/Shared/Grpc/Tracing/TraceHistoryEventLookup.cs Outdated
Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>

Copilot-Session: 01dc5b7c-c742-45b7-ae8c-5cda9bcfbd2c
Copilot AI review requested due to automatic review settings August 13, 2026 02:24

Copilot AI 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.

Pull request overview

Copilot reviewed 6 out of 6 changed files in this pull request and generated no new comments.

Suppressed comments (1)

test/Grpc.IntegrationTests/TracingIntegrationTests.cs:97

  • This new test is named/positioned as validating span correlation, but the assertions only check that client Activities with specific OperationName values exist. That doesn’t actually validate the correlation behavior the PR is changing (i.e., that the server activity/sub-orchestration spans are parented to the correct client scheduled spans, and that the two scheduled operations remain distinct). Strengthen the assertions to check ParentSpanId relationships (similar to the other tests in this file) so the test fails if the history lookup mis-correlates events.
        // Assert
        metadata.RuntimeStatus.Should().Be(OrchestrationRuntimeStatus.Completed);
        activities.Should().ContainSingle(
            activity => activity.Kind == ActivityKind.Client
                && activity.Source.Name == CoreActivitySourceName

Bernd Verst added 2 commits August 12, 2026 19:33
Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>

Copilot-Session: 01dc5b7c-c742-45b7-ae8c-5cda9bcfbd2c
Copilot AI review requested due to automatic review settings August 13, 2026 03:05
@berndverst

Copy link
Copy Markdown
Member Author

Updated quantitative impact after demand-shaped indexing

This supersedes the listener-on index measurements in my earlier comment. Head 3830a05 now pre-registers only correlation IDs referenced by the current work item's NewEvents, scans PastEvents once for both scheduling-event types, and retains only those requested IDs.

I measured the old repeated-scan algorithm, the prior full-history index, and the current demand-shaped index in a focused Release/.NET 10 harness on Windows x64 (AMD EPYC 7763), using real protobuf HistoryEvent objects. These numbers isolate correlation work; they are not whole-worker throughput measurements.

Scenario Shape Old repeated scan Prior full index Current demand-shaped index Current vs old
Average-style task case H=100, 50 scheduled tasks, 5 completions 3.160 us / 832 B 1.377 us / 4,736 B 0.793 us / 616 B -74.9% latency, -26.0% allocation, ~4.0x correlation throughput
Average-style mixed case H=100, 33 task + 33 sub events, 3 lookups each 2.516 us / 1,024 B 1.845 us / 4,344 B 0.888 us / 648 B -64.7% latency, -36.7% allocation, ~2.8x throughput
Best listener-on fan-in H=10,000, 5,000 scheduled tasks, 1,000 completions 54.33 ms / 160,034 B 147.1 us / 451,641 B 80.1 us / 102,368 B -99.853% latency, -36.0% allocation, ~678x throughput
Large mixed fan-in H=10,000, 3,333 task + 3,333 sub events, 500 lookups each 35.57 ms / 160,066 B 210.4 us / 431,611 B 91.1 us / 96,408 B -99.744% latency, -39.8% allocation, ~390x throughput
Constructed worst case listener on; one sub match at position 2 of H=10,000 89.8 ns / 184 B 35.67 us / 320 B 39.00 us / 352 B ~434x latency, +168 B

Compared with the prior full index, the current large task case reduces index latency another 45.5% and allocation 77.3%; the large mixed case reduces latency 56.7% and allocation 77.7%. Storage is now O(unique correlation IDs in NewEvents) rather than O(all scheduling IDs in PastEvents).

The no-listener path is unchanged from the earlier measurement: it performs one HasListeners() check and zero tracing-history enumeration or correlation allocation. The earlier representative no-listener case (H=100, 5 task completions) fell from 4.40 us and 1,056 B to approximately harness overhead and 0 B; the large no-listener replay (H=10,000, 1,000 completions) removes roughly 79.8 ms of correlation work.

The constructed single-early-sub case remains the adverse boundary. The old FirstOrDefault could return at position 2, while the reviewer-requested one-to-one invariant requires scanning the applicable history to detect a later duplicate and fail rather than silently selecting one. That O(H) validation cost cannot retain the old early-exit complexity while also guaranteeing duplicate detection. The current design removes the avoidable all-history storage and keeps that cost confined to listener-enabled tracing.

Reciprocal latency is used only as a correlation-stage throughput proxy. Whole-worker gains depend on the fraction of turn CPU previously spent in tracing correlation, listener prevalence, history sizes, and completion-batch distributions.

Copilot AI 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.

Pull request overview

Copilot reviewed 6 out of 6 changed files in this pull request and generated no new comments.

Copilot AI review requested due to automatic review settings August 13, 2026 03:09

Copilot AI 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.

Pull request overview

Copilot reviewed 6 out of 6 changed files in this pull request and generated no new comments.

Comment thread src/Shared/Grpc/Tracing/TraceHistoryEventLookup.cs Fixed
Comment thread src/Shared/Grpc/Tracing/TraceHistoryEventLookup.cs Fixed
Comment thread test/Worker/Grpc.Tests/TraceHistoryEventLookupTests.cs Fixed
Comment thread test/Worker/Grpc.Tests/TraceHistoryEventLookupTests.cs Fixed
Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>

Copilot-Session: 01dc5b7c-c742-45b7-ae8c-5cda9bcfbd2c
Copilot AI review requested due to automatic review settings August 13, 2026 03:18

Copilot AI 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.

Pull request overview

Copilot reviewed 6 out of 6 changed files in this pull request and generated no new comments.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Performance: avoid repeated orchestration-history scans for tracing

3 participants