Performance: Context holds SynchronizedSpan directly, not via HashMap #1268

shaun-cox · 2023-09-13T16:22:22Z

Changes

Add the span field below:

pub struct Context {
    pub(super) span: Option<Arc<SynchronizedSpan>>,
    entries: HashMap<TypeId, Arc<dyn Any + Sync + Send>, BuildHasherDefault<IdHasher>>,
}

so that current span manipulation doesn't have to traverse the expensive HashMap and then get dispatched with virtual function calls.

Further, this keeps the HashMap empty for the common case of just having a span in context and no other types (like baggage).

I get that the opentelemetry specification is trying to be general with its view that Context is extensible and can hold anything, but there comes a real performance penalty for handling everything through that abstraction.

Results of cargo bench -p opentelemetry_sdk --bench context:

context/has_active_span/in-cx/alt
                        time:   [3.5772 ns 3.5806 ns 3.5842 ns]
                        thrpt:  [279.01 Melem/s 279.28 Melem/s 279.55 Melem/s]
                 change:
                        time:   [-47.017% -46.850% -46.708%] (p = 0.00 < 0.05)
                        thrpt:  [+87.646% +88.145% +88.739%]
                        Performance has improved.
context/is_sampled/in-cx/alt
                        time:   [5.0980 ns 5.1075 ns 5.1170 ns]
                        thrpt:  [195.43 Melem/s 195.79 Melem/s 196.15 Melem/s]
                 change:
                        time:   [-41.439% -41.320% -41.208%] (p = 0.00 < 0.05)
                        thrpt:  [+70.091% +70.414% +70.762%]
                        Performance has improved.
context/is_recording/in-cx/alt
                        time:   [5.3604 ns 5.3951 ns 5.4407 ns]
                        thrpt:  [183.80 Melem/s 185.35 Melem/s 186.55 Melem/s]
                 change:
                        time:   [-41.657% -41.417% -41.156%] (p = 0.00 < 0.05)
                        thrpt:  [+69.940% +70.698% +71.399%]
                        Performance has improved.
context/has_active_span/in-cx/spec
                        time:   [12.958 ns 12.988 ns 13.022 ns]
                        thrpt:  [76.791 Melem/s 76.995 Melem/s 77.174 Melem/s]
                 change:
                        time:   [-63.146% -63.063% -62.980%] (p = 0.00 < 0.05)
                        thrpt:  [+170.12% +170.73% +171.34%]
                        Performance has improved.
context/is_sampled/in-cx/spec
                        time:   [12.826 ns 12.843 ns 12.859 ns]
                        thrpt:  [77.764 Melem/s 77.865 Melem/s 77.967 Melem/s]
                 change:
                        time:   [-64.729% -64.672% -64.614%] (p = 0.00 < 0.05)
                        thrpt:  [+182.60% +183.06% +183.52%]
                        Performance has improved.
context/is_recording/in-cx/spec
                        time:   [13.718 ns 13.738 ns 13.756 ns]
                        thrpt:  [72.693 Melem/s 72.791 Melem/s 72.895 Melem/s]
                 change:
                        time:   [-62.407% -62.337% -62.271%] (p = 0.00 < 0.05)
                        thrpt:  [+165.05% +165.51% +166.01%]
                        Performance has improved.

Results of taskset -c 2,4 cargo bench -p opentelemetry-contrib --features="api" --bench new_span:

new_span/if_parent_sampled/in-cx/alt
                        time:   [433.95 ns 434.37 ns 434.78 ns]
                        thrpt:  [2.3000 Melem/s 2.3022 Melem/s 2.3044 Melem/s]
                 change:
                        time:   [-14.018% -13.813% -13.610%] (p = 0.00 < 0.05)
                        thrpt:  [+15.754% +16.026% +16.303%]
                        Performance has improved.
new_span/if_recording/in-cx/alt
                        time:   [9.5467 ns 9.5592 ns 9.5732 ns]
                        thrpt:  [104.46 Melem/s 104.61 Melem/s 104.75 Melem/s]
                 change:
                        time:   [-35.364% -35.131% -34.908%] (p = 0.00 < 0.05)
                        thrpt:  [+53.629% +54.157% +54.712%]
                        Performance has improved.
new_span/if_parent_sampled/in-cx/spec
                        time:   [414.49 ns 415.72 ns 417.35 ns]
                        thrpt:  [2.3961 Melem/s 2.4055 Melem/s 2.4126 Melem/s]
                 change:
                        time:   [-28.958% -25.772% -22.597%] (p = 0.00 < 0.05)
                        thrpt:  [+29.194% +34.720% +40.762%]
                        Performance has improved.
new_span/if_recording/in-cx/spec
                        time:   [15.837 ns 15.855 ns 15.877 ns]
                        thrpt:  [62.986 Melem/s 63.071 Melem/s 63.144 Melem/s]
                 change:
                        time:   [-58.590% -58.485% -58.383%] (p = 0.00 < 0.05)
                        thrpt:  [+140.29% +140.88% +141.49%]
                        Performance has improved.
new_span/if_parent_sampled/no-cx/alt
                        time:   [8.9579 ns 8.9766 ns 8.9966 ns]
                        thrpt:  [111.15 Melem/s 111.40 Melem/s 111.63 Melem/s]
                 change:
                        time:   [-13.891% -13.651% -13.425%] (p = 0.00 < 0.05)
                        thrpt:  [+15.507% +15.809% +16.131%]
                        Performance has improved.
new_span/if_recording/no-cx/alt
                        time:   [9.3771 ns 9.3938 ns 9.4134 ns]
                        thrpt:  [106.23 Melem/s 106.45 Melem/s 106.64 Melem/s]
                 change:
                        time:   [-15.247% -14.984% -14.692%] (p = 0.00 < 0.05)
                        thrpt:  [+17.222% +17.625% +17.990%]
                        Performance has improved.
new_span/if_parent_sampled/no-cx/spec
                        time:   [183.31 ns 183.63 ns 183.97 ns]
                        thrpt:  [5.4358 Melem/s 5.4458 Melem/s 5.4553 Melem/s]
                 change:
                        time:   [-9.4343% -9.0523% -8.7467%] (p = 0.00 < 0.05)
                        thrpt:  [+9.5851% +9.9533% +10.417%]
                        Performance has improved.
new_span/if_recording/no-cx/spec
                        time:   [11.159 ns 11.173 ns 11.189 ns]
                        thrpt:  [89.371 Melem/s 89.499 Melem/s 89.613 Melem/s]
                 change:
                        time:   [+8.9201% +9.2451% +9.5566%] (p = 0.00 < 0.05)
                        thrpt:  [-8.7230% -8.4627% -8.1896%]
                        Performance has regressed.
new_span/if_parent_sampled/no-sdk/alt
                        time:   [9.0222 ns 9.0478 ns 9.0743 ns]
                        thrpt:  [110.20 Melem/s 110.52 Melem/s 110.84 Melem/s]
                 change:
                        time:   [-12.113% -11.890% -11.642%] (p = 0.00 < 0.05)
                        thrpt:  [+13.175% +13.495% +13.783%]
                        Performance has improved.
new_span/if_recording/no-sdk/alt
                        time:   [9.3513 ns 9.3604 ns 9.3705 ns]
                        thrpt:  [106.72 Melem/s 106.83 Melem/s 106.94 Melem/s]
                 change:
                        time:   [-14.874% -14.721% -14.550%] (p = 0.00 < 0.05)
                        thrpt:  [+17.028% +17.262% +17.473%]
                        Performance has improved.
new_span/if_parent_sampled/no-sdk/spec
                        time:   [91.612 ns 91.722 ns 91.841 ns]
                        thrpt:  [10.888 Melem/s 10.902 Melem/s 10.916 Melem/s]
                 change:
                        time:   [-19.732% -19.562% -19.389%] (p = 0.00 < 0.05)
                        thrpt:  [+24.052% +24.319% +24.583%]
                        Performance has improved.
new_span/if_recording/no-sdk/spec
                        time:   [11.179 ns 11.195 ns 11.214 ns]
                        thrpt:  [89.175 Melem/s 89.324 Melem/s 89.456 Melem/s]
                 change:
                        time:   [+8.9043% +9.0850% +9.2879%] (p = 0.00 < 0.05)
                        thrpt:  [-8.4985% -8.3284% -8.1762%]
                        Performance has regressed.

Merge requirement checklist

CONTRIBUTING guidelines followed
Appropriate CHANGELOG.md files updated for non-trivial, user-facing changes

jtescher · 2023-09-13T16:27:48Z

Looks good, always nice to be able to do perf improvements without breaking api changes too 👍 what numbers are you seeing for the diff?

cijothomas · 2023-09-13T16:58:54Z

TraceContext, Baggage, and some to fix this, would be common use-case for context. If we can make these 3 top-level fields instead of putting in map/dictionary, that'd be awesome.

shaun-cox · 2023-09-13T17:20:37Z

Looks good, always nice to be able to do perf improvements without breaking api changes too 👍 what numbers are you seeing for the diff?

From 70% to 170% speedup in checking context for active span, or is sampled or is recording.
Up to 58% reduction in conditional span creation time (140% speedup) when creating a child span only if currently recording. Pasted results in the PR comment above.

codecov · 2023-09-13T19:05:37Z

Codecov Report

Patch coverage is 100.0% of modified lines.

Files Changed	Coverage
opentelemetry/src/trace/mod.rs	`ø`
opentelemetry/src/context.rs	`100.0%`
opentelemetry/src/trace/context.rs	`100.0%`

📢 Thoughts on this report? Let us know!.

djc

Note, this would be a bit easier to review if you squashed the changes for the span field into a single commit and had a separate commit that takes care of the Span imports.

What's the rationale for moving from per-module to per-crate imports? Is that converging on a common style or diverging from it?

opentelemetry/src/context.rs

shaun-cox · 2023-09-14T11:27:51Z

What's the rationale for moving from per-module to per-crate imports? Is that converging on a common style or diverging from it?

I thought I was moving to the common style, as its what's offered by auto-complete/rust-analyzer when adding new imports. I can revert if I didn't understand the current style tho...

shaun-cox · 2023-09-14T12:42:12Z

@djc, should be easier to review now. (Sorry, I thought I had squashed my two commits previously, but didn't.)

- lookup on TypeId and downcasting isn't necesary - Context::with_value and current_with_value are more efficient as they no longer clone and overwrite the entry in the map which represens the current span

shaun-cox changed the title ~~Context holds SynchronizedSpan directly, not via HashMap~~ Performance: Context holds SynchronizedSpan directly, not via HashMap Sep 13, 2023

shaun-cox marked this pull request as ready for review September 13, 2023 19:15

shaun-cox requested a review from a team September 13, 2023 19:15

shaun-cox mentioned this pull request Sep 13, 2023

Performance: By using const over static, improve noop span creation performance another 10% #1270

Merged

4 tasks

djc reviewed Sep 14, 2023

View reviewed changes

opentelemetry/src/context.rs Outdated Show resolved Hide resolved

shaun-cox force-pushed the context_field_for_span branch 2 times, most recently from f6b3031 to e381565 Compare September 14, 2023 12:41

shaun-cox requested a review from djc September 14, 2023 15:13

djc approved these changes Sep 14, 2023

View reviewed changes

Context holds SynchronizedSpan directly, not via HashMap

6e4ae4c

- lookup on TypeId and downcasting isn't necesary - Context::with_value and current_with_value are more efficient as they no longer clone and overwrite the entry in the map which represens the current span

shaun-cox force-pushed the context_field_for_span branch from e381565 to 6e4ae4c Compare September 15, 2023 12:42

TommyCpp approved these changes Sep 21, 2023

View reviewed changes

TommyCpp merged commit ab9972f into open-telemetry:main Sep 21, 2023
12 checks passed

shaun-cox deleted the context_field_for_span branch September 21, 2023 11:35

cijothomas mentioned this pull request Feb 23, 2024

Overview of Major blockers for GA/Stable Release #1572

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Performance: Context holds SynchronizedSpan directly, not via HashMap #1268

Performance: Context holds SynchronizedSpan directly, not via HashMap #1268

shaun-cox commented Sep 13, 2023 •

edited

Loading

jtescher commented Sep 13, 2023

cijothomas commented Sep 13, 2023

shaun-cox commented Sep 13, 2023

codecov bot commented Sep 13, 2023 •

edited

Loading

djc left a comment

shaun-cox commented Sep 14, 2023

shaun-cox commented Sep 14, 2023

Performance: Context holds SynchronizedSpan directly, not via HashMap #1268

Performance: Context holds SynchronizedSpan directly, not via HashMap #1268

Conversation

shaun-cox commented Sep 13, 2023 • edited Loading

Changes

Merge requirement checklist

jtescher commented Sep 13, 2023

cijothomas commented Sep 13, 2023

shaun-cox commented Sep 13, 2023

codecov bot commented Sep 13, 2023 • edited Loading

Codecov Report

djc left a comment

Choose a reason for hiding this comment

shaun-cox commented Sep 14, 2023

shaun-cox commented Sep 14, 2023

shaun-cox commented Sep 13, 2023 •

edited

Loading

codecov bot commented Sep 13, 2023 •

edited

Loading