diff --git a/CHANGELOG.md b/CHANGELOG.md index f5abb9850..53d046382 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,11 @@ - Added a `Envelope::into_items` method, which returns an iterator over owned [`EnvelopeItem`s](https://docs.rs/sentry/0.46.2/sentry/protocol/enum.EnvelopeItem.html) in the [`Envelope`](https://docs.rs/sentry/0.46.2/sentry/struct.Envelope.html) ([#983](https://github.com/getsentry/sentry-rust/pull/983)). - Expose transport utilities ([#949](https://github.com/getsentry/sentry-rust/pull/949)) +### Fixes + +- Fixed thread corruption bug where `HubSwitchGuard` could be dropped on wrong thread ([#957](https://github.com/getsentry/sentry-rust/pull/957)) + - **Breaking change**: `sentry_core::HubSwitchGuard` is now `!Send`, preventing it from being moved across threads. Code that previously sent the guard to another thread will no longer compile. + ## 0.46.2 ### New Features diff --git a/Cargo.lock b/Cargo.lock index 34a9ffc6c..95b2a7f29 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -233,6 +233,15 @@ dependencies = [ "alloc-no-stdlib", ] +[[package]] +name = "alloca" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e5a7d05ea6aea7e9e64d25b9156ba2fee3fdd659e34e41063cd2fc7cd020d7f4" +dependencies = [ + "cc", +] + [[package]] name = "android_system_properties" version = "0.1.5" @@ -790,7 +799,7 @@ dependencies = [ "cast", "ciborium", "clap", - "criterion-plot", + "criterion-plot 0.5.0", "is-terminal", "itertools 0.10.5", "num-traits", @@ -806,6 +815,31 @@ dependencies = [ "walkdir", ] +[[package]] +name = "criterion" +version = "0.8.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "950046b2aa2492f9a536f5f4f9a3de7b9e2476e575e05bd6c333371add4d98f3" +dependencies = [ + "alloca", + "anes", + "cast", + "ciborium", + "clap", + "criterion-plot 0.8.2", + "itertools 0.13.0", + "num-traits", + "oorandom", + "page_size", + "plotters", + "rayon", + "regex", + "serde", + "serde_json", + "tinytemplate", + "walkdir", +] + [[package]] name = "criterion-plot" version = "0.5.0" @@ -816,6 +850,16 @@ dependencies = [ "itertools 0.10.5", ] +[[package]] +name = "criterion-plot" +version = "0.8.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d8d80a2f4f5b554395e47b5d8305bc3d27813bacb73493eb1001e8f76dae29ea" +dependencies = [ + "cast", + "itertools 0.13.0", +] + [[package]] name = "critical-section" version = "1.2.0" @@ -2719,6 +2763,16 @@ dependencies = [ "windows-sys 0.61.2", ] +[[package]] +name = "page_size" +version = "0.6.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "30d5b2194ed13191c1999ae0704b7839fb18384fa22e49b57eeaa97d79ce40da" +dependencies = [ + "libc", + "winapi", +] + [[package]] name = "parking_lot" version = "0.12.5" @@ -3479,7 +3533,7 @@ name = "sentry-core" version = "0.46.2" dependencies = [ "anyhow", - "criterion", + "criterion 0.5.1", "futures", "log", "rand 0.9.2", @@ -3569,6 +3623,7 @@ name = "sentry-tracing" version = "0.46.2" dependencies = [ "bitflags 2.11.0", + "criterion 0.8.2", "log", "sentry", "sentry-backtrace", diff --git a/docs/2026-02-24-tracing-hub-forking-benchmark-setup.md b/docs/2026-02-24-tracing-hub-forking-benchmark-setup.md new file mode 100644 index 000000000..bce68232d --- /dev/null +++ b/docs/2026-02-24-tracing-hub-forking-benchmark-setup.md @@ -0,0 +1,53 @@ +# Tracing hub-forking benchmark setup + +## What was added + +- `sentry-tracing/Cargo.toml` + - Added dev dependency: `criterion = "0.8.2"` + - Added bench target: + - `[[bench]]` + - `name = "tracing_layer_perf"` + - `harness = false` + +- `sentry-tracing/benches/tracing_layer_perf.rs` + - Criterion benchmarks for: + - `enter_exit_existing_span` + - `create_enter_exit_close_span` + - `reenter_same_span_depth2` + - `cross_thread_shared_span` + - Each scenario runs in: + - `sentry_active` + - `tracing_only_control` + +- `scripts/bench/compare-tracing-perf-master-vs-head.sh` + - Automates `origin/master` vs current branch comparison + - Creates/reuses a master worktree at `target/bench-worktrees/tracing-perf-master` + - Reuses current checkout as head candidate + - Runs identical `cargo bench` commands on both + - Saves artifacts to `target/bench-compare//` + - Produces: + - raw logs + - commands used + - summary markdown table with deltas + +## How to run + +Full profile (default): + +```bash +scripts/bench/compare-tracing-perf-master-vs-head.sh +``` + +Reduced profile: + +```bash +scripts/bench/compare-tracing-perf-master-vs-head.sh --reduced +``` + +## Output + +Artifacts are written to: + +- `target/bench-compare//summary.md` +- `target/bench-compare//commands.txt` +- `target/bench-compare//raw/` diff --git a/scripts/bench/compare-tracing-perf-master-vs-head.sh b/scripts/bench/compare-tracing-perf-master-vs-head.sh new file mode 100755 index 000000000..d84d91013 --- /dev/null +++ b/scripts/bench/compare-tracing-perf-master-vs-head.sh @@ -0,0 +1,160 @@ +#!/usr/bin/env bash +set -euo pipefail + +profile="full" +if [[ "${1:-}" == "--reduced" ]]; then + profile="reduced" +fi + +if [[ "$profile" == "full" ]]; then + sample_size=100 + measurement_time=10 + warm_up_time=3 +else + sample_size=20 + measurement_time=2 + warm_up_time=1 +fi + +repo_root="$(git rev-parse --show-toplevel)" +current_branch="$(git rev-parse --abbrev-ref HEAD)" +head_sha="$(git rev-parse HEAD)" +timestamp="$(date -u +%Y%m%dT%H%M%SZ)" + +worktree_root="$repo_root/target/bench-worktrees" +master_worktree="$worktree_root/tracing-perf-master" +head_worktree="$repo_root" + +artifact_dir="$repo_root/target/bench-compare/$timestamp" +raw_dir="$artifact_dir/raw" +mkdir -p "$raw_dir/master" "$raw_dir/head" + +mkdir -p "$worktree_root" + +git config --global --add safe.directory "$repo_root" >/dev/null 2>&1 || true +git config --global --add safe.directory "$master_worktree" >/dev/null 2>&1 || true + +git fetch origin master >/dev/null + +if [[ ! -e "$master_worktree/.git" ]]; then + git worktree add --detach "$master_worktree" origin/master >/dev/null +else + git -C "$master_worktree" fetch origin master >/dev/null + git -C "$master_worktree" checkout --detach -f origin/master >/dev/null +fi + +# Keep benchmark harness identical between baseline and candidate. +mkdir -p "$master_worktree/sentry-tracing/benches" +cp "$repo_root/sentry-tracing/Cargo.toml" "$master_worktree/sentry-tracing/Cargo.toml" +cp "$repo_root/sentry-tracing/benches/tracing_layer_perf.rs" "$master_worktree/sentry-tracing/benches/tracing_layer_perf.rs" +cp "$repo_root/Cargo.lock" "$master_worktree/Cargo.lock" + +scenarios=( + enter_exit_existing_span + create_enter_exit_close_span + reenter_same_span_depth2 + cross_thread_shared_span +) + +modes=( + sentry_active + tracing_only_control +) + +commands_file="$artifact_dir/commands.txt" +{ + echo "# profile=$profile" + echo "# branch=$current_branch" + echo "# head_sha=$head_sha" + echo "cargo bench -p sentry-tracing --bench tracing_layer_perf --no-run" + for scenario in "${scenarios[@]}"; do + echo "cargo bench -p sentry-tracing --bench tracing_layer_perf $scenario -- --sample-size $sample_size --measurement-time $measurement_time --warm-up-time $warm_up_time --noplot" + done +} >"$commands_file" + +run_suite() { + local label="$1" + local worktree="$2" + + ( + cd "$worktree" + cargo bench -p sentry-tracing --bench tracing_layer_perf --no-run + ) >"$raw_dir/$label/build.log" 2>&1 + + for scenario in "${scenarios[@]}"; do + local log_file="$raw_dir/$label/$scenario.log" + ( + cd "$worktree" + cargo bench -p sentry-tracing --bench tracing_layer_perf "$scenario" -- \ + --sample-size "$sample_size" \ + --measurement-time "$measurement_time" \ + --warm-up-time "$warm_up_time" \ + --noplot + ) 2>&1 | tee "$log_file" + done +} + +parse_mean_ns() { + local log_file="$1" + local bench_name="$2" + + awk -v bench="$bench_name" ' + function to_ns(v, u) { + if (u == "ns") return v + if (u == "us" || u == "µs" || u == "μs") return v * 1000 + if (u == "ms") return v * 1000000 + if (u == "s") return v * 1000000000 + return -1 + } + /^Benchmarking / { + current = $0 + sub(/^Benchmarking /, "", current) + sub(/:.*/, "", current) + } + $1 == "time:" && current == bench { + gsub("\\[", "", $2) + middle_value = $4 + middle_unit = $5 + print to_ns(middle_value + 0, middle_unit) + exit + } + ' "$log_file" +} + +run_suite master "$master_worktree" +run_suite head "$head_worktree" + +summary_file="$artifact_dir/summary.md" +{ + echo "# tracing_layer_perf: origin/master vs $current_branch" + echo + printf -- "- profile: \`%s\`\n" "$profile" + printf -- "- baseline: \`%s\`\n" "origin/master" + printf -- "- candidate: \`%s (%s)\`\n" "$current_branch" "$head_sha" + echo + echo "| scenario | mode | master mean (ns) | head mean (ns) | delta |" + echo "|---|---|---:|---:|---:|" + + for scenario in "${scenarios[@]}"; do + for mode in "${modes[@]}"; do + bench_name="$scenario/$mode" + master_ns="$(parse_mean_ns "$raw_dir/master/$scenario.log" "$bench_name")" + head_ns="$(parse_mean_ns "$raw_dir/head/$scenario.log" "$bench_name")" + + if [[ -z "$master_ns" || -z "$head_ns" ]]; then + delta="n/a" + else + delta="$(awk -v a="$master_ns" -v b="$head_ns" 'BEGIN { printf "%.2f%%", ((b - a) / a) * 100 }')" + fi + + echo "| $scenario | $mode | $master_ns | $head_ns | $delta |" + done + done + echo + printf -- "Commands: \`%s\`\n" "$commands_file" + printf -- "Raw logs: \`%s\`\n" "$raw_dir" +} >"$summary_file" + +echo "Benchmark comparison complete." +echo "Artifacts: $artifact_dir" +echo "Summary: $summary_file" diff --git a/sentry-core/src/hub_impl.rs b/sentry-core/src/hub_impl.rs index 5786daa36..36994fa18 100644 --- a/sentry-core/src/hub_impl.rs +++ b/sentry-core/src/hub_impl.rs @@ -1,5 +1,6 @@ use std::cell::{Cell, UnsafeCell}; -use std::sync::{Arc, LazyLock, PoisonError, RwLock}; +use std::marker::PhantomData; +use std::sync::{Arc, LazyLock, MutexGuard, PoisonError, RwLock}; use std::thread; use crate::Scope; @@ -19,10 +20,14 @@ thread_local! { ); } -/// A Hub switch guard used to temporarily swap -/// active hub in thread local storage. +/// A guard that temporarily swaps the active hub in thread-local storage. +/// +/// This type is `!Send` because it manages thread-local state and must be +/// dropped on the same thread where it was created. pub struct SwitchGuard { inner: Option<(Arc, bool)>, + /// Makes this type `!Send` while keeping it `Sync`. + _not_send: PhantomData>, } impl SwitchGuard { @@ -41,7 +46,10 @@ impl SwitchGuard { let was_process_hub = is_process_hub.replace(false); Some((hub, was_process_hub)) }); - SwitchGuard { inner } + SwitchGuard { + inner, + _not_send: PhantomData, + } } fn swap(&mut self) -> Option> { diff --git a/sentry-tracing/Cargo.toml b/sentry-tracing/Cargo.toml index f5ba80abf..6bbbb718a 100644 --- a/sentry-tracing/Cargo.toml +++ b/sentry-tracing/Cargo.toml @@ -38,3 +38,8 @@ serde_json = "1" tracing = "0.1" tracing-subscriber = { version = "0.3.20", features = ["fmt", "registry"] } tokio = { version = "1.44", features = ["rt-multi-thread", "macros", "time"] } +criterion = "0.8.2" + +[[bench]] +name = "tracing_layer_perf" +harness = false diff --git a/sentry-tracing/benches/tracing_layer_perf.rs b/sentry-tracing/benches/tracing_layer_perf.rs new file mode 100644 index 000000000..156125f2f --- /dev/null +++ b/sentry-tracing/benches/tracing_layer_perf.rs @@ -0,0 +1,169 @@ +use std::sync::Arc; + +use criterion::{criterion_group, criterion_main, Criterion}; +use std::hint::black_box; +use tracing_subscriber::prelude::*; + +struct NoopTransport; + +impl sentry::Transport for NoopTransport { + fn send_envelope(&self, envelope: sentry::Envelope) {} +} + +fn active_hub() -> Arc { + let client = Arc::new(sentry::Client::from(sentry::ClientOptions { + dsn: Some("https://public@sentry.invalid/1".parse().unwrap()), + transport: Some(Arc::new(Arc::new(NoopTransport))), + traces_sample_rate: 1.0, + ..Default::default() + })); + let scope = Arc::new(sentry::Scope::default()); + Arc::new(sentry::Hub::new(Some(client), scope)) +} + +fn bench_sentry_active(b: &mut criterion::Bencher<'_>, mut op: F) +where + F: FnMut(), +{ + let dispatch = + tracing::Dispatch::new(tracing_subscriber::registry().with(sentry_tracing::layer())); + let hub = active_hub(); + + sentry::Hub::run(hub, || { + tracing::dispatcher::with_default(&dispatch, || { + b.iter(|| op()); + }); + }); +} + +fn bench_tracing_only_control(b: &mut criterion::Bencher<'_>, mut op: F) +where + F: FnMut(), +{ + let dispatch = tracing::Dispatch::new(tracing_subscriber::registry()); + + tracing::dispatcher::with_default(&dispatch, || { + b.iter(|| op()); + }); +} + +fn tracing_layer_perf(c: &mut Criterion) { + { + let mut group = c.benchmark_group("enter_exit_existing_span"); + group.bench_function("sentry_active", |b| { + let dispatch = tracing::Dispatch::new( + tracing_subscriber::registry().with(sentry_tracing::layer()), + ); + let hub = active_hub(); + + sentry::Hub::run(hub, || { + tracing::dispatcher::with_default(&dispatch, || { + let span = tracing::info_span!("existing"); + b.iter(|| { + let _guard = span.enter(); + black_box(()); + }); + }); + }); + }); + group.bench_function("tracing_only_control", |b| { + let dispatch = tracing::Dispatch::new(tracing_subscriber::registry()); + tracing::dispatcher::with_default(&dispatch, || { + let span = tracing::info_span!("existing"); + b.iter(|| { + let _guard = span.enter(); + black_box(()); + }); + }); + }); + group.finish(); + } + + { + let mut group = c.benchmark_group("create_enter_exit_close_span"); + group.bench_function("sentry_active", |b| { + bench_sentry_active(b, || { + let span = tracing::info_span!("created"); + let _guard = span.enter(); + black_box(()); + }) + }); + group.bench_function("tracing_only_control", |b| { + bench_tracing_only_control(b, || { + let span = tracing::info_span!("created"); + let _guard = span.enter(); + black_box(()); + }) + }); + group.finish(); + } + + { + let mut group = c.benchmark_group("reenter_same_span_depth2"); + group.bench_function("sentry_active", |b| { + bench_sentry_active(b, || { + let span = tracing::info_span!("reenter"); + let _guard1 = span.enter(); + let _guard2 = span.enter(); + black_box(()); + }) + }); + group.bench_function("tracing_only_control", |b| { + bench_tracing_only_control(b, || { + let span = tracing::info_span!("reenter"); + let _guard1 = span.enter(); + let _guard2 = span.enter(); + black_box(()); + }) + }); + group.finish(); + } + + { + let mut group = c.benchmark_group("cross_thread_shared_span"); + group.bench_function("sentry_active", |b| { + bench_sentry_active(b, || { + let span = tracing::info_span!("shared"); + let span_a = span.clone(); + let span_b = span; + + std::thread::scope(|scope| { + scope.spawn(move || { + let _guard = span_a.enter(); + let _child = tracing::info_span!("child_a").entered(); + black_box(()); + }); + scope.spawn(move || { + let _guard = span_b.enter(); + let _child = tracing::info_span!("child_b").entered(); + black_box(()); + }); + }); + }) + }); + group.bench_function("tracing_only_control", |b| { + bench_tracing_only_control(b, || { + let span = tracing::info_span!("shared"); + let span_a = span.clone(); + let span_b = span; + + std::thread::scope(|scope| { + scope.spawn(move || { + let _guard = span_a.enter(); + let _child = tracing::info_span!("child_a").entered(); + black_box(()); + }); + scope.spawn(move || { + let _guard = span_b.enter(); + let _child = tracing::info_span!("child_b").entered(); + black_box(()); + }); + }); + }) + }); + group.finish(); + } +} + +criterion_group!(benches, tracing_layer_perf); +criterion_main!(benches); diff --git a/sentry-tracing/src/layer.rs b/sentry-tracing/src/layer/mod.rs similarity index 90% rename from sentry-tracing/src/layer.rs rename to sentry-tracing/src/layer/mod.rs index d02c0496d..63b5e7242 100644 --- a/sentry-tracing/src/layer.rs +++ b/sentry-tracing/src/layer/mod.rs @@ -5,7 +5,7 @@ use std::sync::Arc; use bitflags::bitflags; use sentry_core::protocol::Value; -use sentry_core::{Breadcrumb, TransactionOrSpan}; +use sentry_core::{Breadcrumb, Hub, HubSwitchGuard, TransactionOrSpan}; use tracing_core::field::Visit; use tracing_core::{span, Event, Field, Level, Metadata, Subscriber}; use tracing_subscriber::layer::{Context, Layer}; @@ -16,6 +16,9 @@ use crate::SENTRY_NAME_FIELD; use crate::SENTRY_OP_FIELD; use crate::SENTRY_TRACE_FIELD; use crate::TAGS_PREFIX; +use span_guard_stack::SpanGuardStack; + +mod span_guard_stack; bitflags! { /// The action that Sentry should perform for a given [`Event`] @@ -236,7 +239,6 @@ pub(super) struct SentrySpanData { pub(super) sentry_span: TransactionOrSpan, parent_sentry_span: Option, hub: Arc, - hub_switch_guard: Option, } impl Layer for SentryLayer @@ -338,7 +340,6 @@ where sentry_span, parent_sentry_span, hub, - hub_switch_guard: None, }); } @@ -350,12 +351,27 @@ where None => return, }; - let mut extensions = span.extensions_mut(); - if let Some(data) = extensions.get_mut::() { - data.hub_switch_guard = Some(sentry_core::HubSwitchGuard::new(data.hub.clone())); - data.hub.configure_scope(|scope| { + let extensions = span.extensions(); + if let Some(data) = extensions.get::() { + // We fork the hub (based on the hub associated with the span) + // upon entering the span. This prevents data leakage if the span + // is entered and exited multiple times. + // + // Further, Hubs are meant to manage thread-local state, even + // though they can be shared across threads. As the span may being + // entered on a different thread than where it was created, we need + // to use a new hub to avoid altering state on the original thread. + let hub = Arc::new(Hub::new_from_top(&data.hub)); + + hub.configure_scope(|scope| { scope.set_span(Some(data.sentry_span.clone())); - }) + }); + + let guard = HubSwitchGuard::new(hub); + + SPAN_GUARDS.with(|guards| { + guards.borrow_mut().push(id.clone(), guard); + }); } } @@ -366,18 +382,29 @@ where None => return, }; - let mut extensions = span.extensions_mut(); - if let Some(data) = extensions.get_mut::() { + let extensions = span.extensions(); + if let Some(data) = extensions.get::() { data.hub.configure_scope(|scope| { scope.set_span(data.parent_sentry_span.clone()); }); - data.hub_switch_guard.take(); } + + // Drop the guard to switch back to previous hub + SPAN_GUARDS.with(|guards| guards.borrow_mut().pop(id.clone())); } /// When a span gets closed, finish the underlying sentry span, and set back /// its parent as the *current* sentry span. fn on_close(&self, id: span::Id, ctx: Context<'_, S>) { + // Ensure all remaining Hub guards are dropped, to restore the original + // Hub. + // + // By this point, the span probably should be fully executed, but we should + // still ensure the guard is dropped in case this expectation is violated. + SPAN_GUARDS.with(|guards| { + guards.borrow_mut().remove(&id); + }); + let span = match ctx.span(&id) { Some(span) => span, None => return, @@ -503,6 +530,9 @@ fn extract_span_data( thread_local! { static VISITOR_BUFFER: RefCell = const { RefCell::new(String::new()) }; + /// Hub switch guards keyed by span ID. Stored in thread-local so guards are + /// always dropped on the same thread where they were created. + static SPAN_GUARDS: RefCell = RefCell::new(SpanGuardStack::new()); } /// Records all span fields into a `BTreeMap`, reusing a mutable `String` as buffer. diff --git a/sentry-tracing/src/layer/span_guard_stack.rs b/sentry-tracing/src/layer/span_guard_stack.rs new file mode 100644 index 000000000..e18435290 --- /dev/null +++ b/sentry-tracing/src/layer/span_guard_stack.rs @@ -0,0 +1,118 @@ +//! This module contains code for stack-like storage for `HubSwitchGuard`s keyed +//! by tracing span ID. + +use std::collections::hash_map::Entry; +use std::collections::HashMap; + +use sentry_core::HubSwitchGuard; +use tracing_core::span::Id as SpanId; + +/// Holds per-span stacks of `HubSwitchGuard`s to handle span re-entrancy. +/// +/// Each time a span is entered, we should push a new guard onto the stack. +/// When the span exits, we should pop the guard from the stack. +pub(super) struct SpanGuardStack { + /// The map of span IDs to their respective guard stacks. + guards: HashMap>, +} + +impl SpanGuardStack { + /// Creates an empty guard stack map. + pub(super) fn new() -> Self { + Self { + guards: HashMap::new(), + } + } + + /// Pushes a guard for the given span ID, creating the stack if needed. + pub(super) fn push(&mut self, id: SpanId, guard: HubSwitchGuard) { + self.guards.entry(id).or_default().push(guard); + } + + /// Pops the most recent guard for the span ID, removing the stack when empty. + pub(super) fn pop(&mut self, id: SpanId) -> Option { + match self.guards.entry(id) { + Entry::Occupied(mut entry) => { + let stack = entry.get_mut(); + let guard = stack.pop(); + if stack.is_empty() { + entry.remove(); + } + guard + } + Entry::Vacant(_) => None, + } + } + + /// Removes all guards for the span ID without returning them. + /// + /// This function guarantees that the guards are dropped in LIFO order. + /// That way, the hub which was active when the span was first entered + /// will be the one active after this function returns. + /// + /// Typically, remove should only get called once the span is fully + /// exited, so this removal order guarantee is mostly just defensive. + pub(super) fn remove(&mut self, id: &SpanId) { + self.guards + .remove(id) + .into_iter() + .flatten() + .rev() // <- we drop in reverse order + .for_each(drop); + } +} + +#[cfg(test)] +mod tests { + use super::SpanGuardStack; + use sentry_core::{Hub, HubSwitchGuard}; + use std::sync::Arc; + use tracing_core::span::Id as SpanId; + + #[test] + fn pop_is_lifo() { + let initial = Hub::current(); + let hub_a = Arc::new(Hub::new_from_top(initial.clone())); + let hub_b = Arc::new(Hub::new_from_top(hub_a.clone())); + + let mut stack = SpanGuardStack::new(); + let id = SpanId::from_u64(1); + + stack.push(id.clone(), HubSwitchGuard::new(hub_a.clone())); + assert!(Arc::ptr_eq(&Hub::current(), &hub_a)); + + stack.push(id.clone(), HubSwitchGuard::new(hub_b.clone())); + assert!(Arc::ptr_eq(&Hub::current(), &hub_b)); + + drop(stack.pop(id.clone()).expect("guard for hub_b")); + assert!(Arc::ptr_eq(&Hub::current(), &hub_a)); + + drop(stack.pop(id.clone()).expect("guard for hub_a")); + assert!(Arc::ptr_eq(&Hub::current(), &initial)); + + assert!(stack.pop(id).is_none()); + } + + #[test] + fn remove_drops_all_guards_in_lifo_order() { + let initial = Hub::current(); + let hub_a = Arc::new(Hub::new_from_top(initial.clone())); + let hub_b = Arc::new(Hub::new_from_top(hub_a.clone())); + + assert!(!Arc::ptr_eq(&hub_b, &initial)); + assert!(!Arc::ptr_eq(&hub_a, &initial)); + assert!(!Arc::ptr_eq(&hub_a, &hub_b)); + + let mut stack = SpanGuardStack::new(); + let id = SpanId::from_u64(2); + + stack.push(id.clone(), HubSwitchGuard::new(hub_a.clone())); + assert!(Arc::ptr_eq(&Hub::current(), &hub_a)); + + stack.push(id.clone(), HubSwitchGuard::new(hub_b.clone())); + assert!(Arc::ptr_eq(&Hub::current(), &hub_b)); + + stack.remove(&id); + assert!(Arc::ptr_eq(&Hub::current(), &initial)); + } +} diff --git a/sentry-tracing/tests/span_cross_thread.rs b/sentry-tracing/tests/span_cross_thread.rs new file mode 100644 index 000000000..5eaa2cdd3 --- /dev/null +++ b/sentry-tracing/tests/span_cross_thread.rs @@ -0,0 +1,77 @@ +mod shared; + +use sentry::protocol::Context; +use std::thread; +use std::time::Duration; + +#[test] +fn cross_thread_span_entries_share_transaction() { + let transport = shared::init_sentry(1.0); + + let span = tracing::info_span!("foo"); + let span2 = span.clone(); + + let handle1 = thread::spawn(move || { + let _guard = span.enter(); + let _bar_span = tracing::info_span!("bar").entered(); + thread::sleep(Duration::from_millis(100)); + }); + + let handle2 = thread::spawn(move || { + thread::sleep(Duration::from_millis(10)); + let _guard = span2.enter(); + let _baz_span = tracing::info_span!("baz").entered(); + thread::sleep(Duration::from_millis(50)); + }); + + handle1.join().unwrap(); + handle2.join().unwrap(); + + let data = transport.fetch_and_clear_envelopes(); + let transactions: Vec<_> = data + .into_iter() + .flat_map(|envelope| { + envelope + .items() + .filter_map(|item| match item { + sentry::protocol::EnvelopeItem::Transaction(transaction) => { + Some(transaction.clone()) + } + _ => None, + }) + .collect::>() + }) + .collect(); + + assert_eq!( + transactions.len(), + 1, + "expected a single transaction for cross-thread span entries" + ); + + let transaction = &transactions[0]; + assert_eq!(transaction.name.as_deref(), Some("foo")); + + let trace = match transaction + .contexts + .get("trace") + .expect("transaction should include trace context") + { + Context::Trace(trace) => trace, + unexpected => panic!("expected trace context but got {unexpected:?}"), + }; + + let bar_span = transaction + .spans + .iter() + .find(|span| span.description.as_deref() == Some("bar")) + .expect("expected span \"bar\" to be recorded in the transaction"); + let baz_span = transaction + .spans + .iter() + .find(|span| span.description.as_deref() == Some("baz")) + .expect("expected span \"baz\" to be recorded in the transaction"); + + assert_eq!(bar_span.parent_span_id, Some(trace.span_id)); + assert_eq!(baz_span.parent_span_id, Some(trace.span_id)); +} diff --git a/sentry-tracing/tests/span_reentrancy.rs b/sentry-tracing/tests/span_reentrancy.rs new file mode 100644 index 000000000..8fc55aad4 --- /dev/null +++ b/sentry-tracing/tests/span_reentrancy.rs @@ -0,0 +1,70 @@ +use sentry::protocol::EnvelopeItem; + +mod shared; + +/// Ensures re-entering the same span does not corrupt the current tracing state, +/// so subsequent spans are still recorded under a single transaction. +#[test] +fn reentering_span_preserves_parent() { + let transport = shared::init_sentry(1.0); + + { + // Create a span and enter it, then re-enter the same span to simulate + // common async polling behavior where a span can be entered multiple times. + let span_a = tracing::info_span!("a"); + let _enter_a = span_a.enter(); + { + let _reenter_a = span_a.enter(); + } + + // Create another span while the original span is still entered to ensure + // it is recorded on the same transaction rather than starting a new one. + let span_b = tracing::info_span!("b"); + { + let _enter_b = span_b.enter(); + } + } + + let transactions: Vec<_> = transport + .fetch_and_clear_envelopes() + .into_iter() + .flat_map(|envelope| envelope.into_items()) + .filter_map(|item| match item { + EnvelopeItem::Transaction(transaction) => Some(transaction), + _ => None, + }) + .collect(); + + assert_eq!( + transactions.len(), + 1, + "expected a single transaction when reentering a span" + ); + + let transaction = &transactions[0]; + assert_eq!(transaction.name.as_deref(), Some("a")); + + let trace = match transaction + .contexts + .get("trace") + .expect("transaction should include trace context") + { + sentry::protocol::Context::Trace(trace) => trace, + unexpected => panic!("expected trace context but got {unexpected:?}"), + }; + + let b_span = transaction + .spans + .iter() + .find(|span| span.description.as_deref() == Some("b")) + .expect("expected span \"b\" to be recorded in the transaction"); + + assert_eq!(b_span.parent_span_id, Some(trace.span_id)); + assert!( + !transaction + .spans + .iter() + .any(|span| span.description.as_deref() == Some("a")), + "expected the transaction root span not to be duplicated in span list" + ); +}