tracing icon indicating copy to clipboard operation
tracing copied to clipboard

add a test to reproduce #1147

Open matklad opened this issue 3 years ago • 2 comments

Run

$ cargo test --package tracing-subscriber --lib -- over_the_stack --exact --nocapture

The cyclic fragment of backtrace:

7693: core::ptr::drop_in_place<tracing_subscriber::registry::sharded::CloseGuard>
             at /rustc/1bc802e990a3393731b19b30f7fad1794b478df0/library/core/src/ptr/mod.rs:486:1
7694: core::ptr::drop_in_place<core::option::Option<tracing_subscriber::registry::sharded::CloseGuard>>
             at /rustc/1bc802e990a3393731b19b30f7fad1794b478df0/library/core/src/ptr/mod.rs:486:1
7695: <tracing_subscriber::subscribe::layered::Layered<S,C> as tracing_core::collect::Collect>::try_close
             at src/subscribe/layered.rs:201:5
7696: <tracing_subscriber::fmt::Collector<N,E,F,W> as tracing_core::collect::Collect>::try_close
             at src/fmt/mod.rs:429:9
7697: tracing_core::dispatch::Dispatch::try_close
             at /home/matklad/p/tracing/tracing-core/src/dispatch.rs:777:9
7698: <tracing_subscriber::registry::sharded::DataInner as sharded_slab::clear::Clear>::clear
             at src/registry/sharded.rs:504:25
7699: sharded_slab::page::slot::Slot<T,C>::clear_storage::{{closure}}::{{closure}}
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/page/slot.rs:484:44
7700: core::option::Option<T>::map
             at /rustc/1bc802e990a3393731b19b30f7fad1794b478df0/library/core/src/option.rs:909:29
7701: sharded_slab::page::slot::Slot<T,C>::clear_storage::{{closure}}
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/page/slot.rs:484:27
7702: sharded_slab::page::slot::Slot<T,C>::release_with::{{closure}}
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/page/slot.rs:283:46
7703: sharded_slab::sync::inner::UnsafeCell<T>::with_mut
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/sync.rs:103:13
      sharded_slab::page::slot::Slot<T,C>::release_with
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/page/slot.rs:281:37
7704: sharded_slab::page::slot::Slot<T,C>::clear_storage
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/page/slot.rs:483:9
7705: sharded_slab::page::slot::Slot<T,C>::try_clear_storage
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/page/slot.rs:466:20
7706: sharded_slab::page::Shared<T,C>::mark_clear::{{closure}}
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/page/mod.rs:323:17
7707: sharded_slab::sync::inner::UnsafeCell<T>::with
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/sync.rs:95:13
      sharded_slab::page::Shared<T,C>::mark_clear
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/page/mod.rs:320:9
7708: sharded_slab::shard::Shard<T,C>::mark_clear_local
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/shard.rs:190:9
7709: sharded_slab::pool::Pool<T,C>::clear::{{closure}}
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/pool.rs:826:30
7710: core::option::Option<T>::map
             at /rustc/1bc802e990a3393731b19b30f7fad1794b478df0/library/core/src/option.rs:909:29
7711: sharded_slab::pool::Pool<T,C>::clear
             at /home/matklad/.cargo/registry/src/github.com-1ecc6299db9ec823/sharded-slab-0.1.4/src/pool.rs:825:13
7712: <tracing_subscriber::registry::sharded::CloseGuard as core::ops::drop::Drop>::drop::{{closure}}
             at src/registry/sharded.rs:400:17
7713: std::thread::local::LocalKey<T>::try_with
             at /rustc/1bc802e990a3393731b19b30f7fad1794b478df0/library/std/src/thread/local.rs:445:16
7714: <tracing_subscriber::registry::sharded::CloseGuard as core::ops::drop::Drop>::drop
             at src/registry/sharded.rs:386:17
7715: core::ptr::drop_in_place<tracing_subscriber::registry::sharded::CloseGuard>
             at /rustc/1bc802e990a3393731b19b30f7fad1794b478df0/library/core/src/ptr/mod.rs:486:1

It's the text-book example of linked-list based stack overflow: when we drop a span, this might recursively trigger dropping of the parent spans, which then overflows The textbook fix here would be to write a drop impl as a loop:

https://rust-unofficial.github.io/too-many-lists/first-drop.html

At this moment, I am not sure how exactly to do that though, as abstraction is layered pretty thick in this area :-)

Motivation

Solution

matklad avatar Jul 01 '22 16:07 matklad

Thanks for the repro. If memory serves from the last time I looked into this, I think the way this code is currently structured makes it quite difficult to rewrite it to drop spans in a loop rather than recursively. I think a larger structural change such as https://github.com/tokio-rs/tracing/pull/1505 will be necessary in order to make that possible.

hawkw avatar Jul 01 '22 16:07 hawkw

Aha, this matches my thoughts after poking at the code for 10 minutes!

#1505 looks really sweet for this and other reasons, huge fan of that direction!

I guess this means though that there isn't anything super actionable here, so feel free to close!

matklad avatar Jul 01 '22 16:07 matklad