Valgrind reports memory leak in `tracing_subscriber`
Closed this issue · 2 comments
clubby789 commented
Bug Report
Version
> cargo tree | grep tracing
├── tracing v0.1.33
│ ├── tracing-attributes v0.1.20 (proc-macro)
│ └── tracing-core v0.1.24
└── tracing-subscriber v0.3.11
├── tracing-core v0.1.24 (*)
└── tracing-log v0.1.2
└── tracing-core v0.1.24 (*)
Platform
Linux clubby789 5.16.18-1-MANJARO #1 SMP PREEMPT Mon Mar 28 09:13:53 UTC 2022 x86_64 GNU/Linux
Crates
tracing_subscriber
Description
Running this program:
use tracing::info;
use tracing_subscriber::fmt;
fn main() {
fmt::init();
info!("Hello, world!");
}under Valgrind (--leak-check=full --show-leak-kinds=all) reports
==28380==
==28380== LEAK SUMMARY:
==28380== definitely lost: 0 bytes in 0 blocks
==28380== indirectly lost: 0 bytes in 0 blocks
==28380== possibly lost: 0 bytes in 0 blocks
==28380== still reachable: 34,136 bytes in 8 blocks
==28380== suppressed: 0 bytes in 0 blocks
Removing the tracing_subscriber::fmt::init() call results in no leaks being reported
Full Valgrind output
==28380== Memcheck, a memory error detector
==28380== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==28380== Using Valgrind-3.18.1 and LibVEX; rerun with -h for copyright info
==28380== Command: ./target/debug/tracetest
==28380==
2022-04-12T11:55:31.413744Z INFO tracetest: Hello, world!
==28380==
==28380== HEAP SUMMARY:
==28380== in use at exit: 34,136 bytes in 8 blocks
==28380== total heap usage: 28 allocs, 20 frees, 37,670 bytes allocated
==28380==
==28380== 16 bytes in 1 blocks are still reachable in loss record 1 of 7
==28380== at 0x4845899: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==28380== by 0x1D5E3B: alloc::alloc::alloc (alloc.rs:89)
==28380== by 0x1D5EC6: alloc::alloc::Global::alloc_impl (alloc.rs:171)
==28380== by 0x1D6769: <alloc::alloc::Global as core::alloc::Allocator>::allocate (alloc.rs:231)
==28380== by 0x1D5D9C: alloc::alloc::exchange_malloc (alloc.rs:320)
==28380== by 0x1DDA77: tracing_log::log_tracer::Builder::init (boxed.rs:195)
==28380== by 0x198CCC: tracing_subscriber::util::SubscriberInitExt::try_init (util.rs:66)
==28380== by 0x1B038B: tracing_subscriber::fmt::try_init (mod.rs:1179)
==28380== by 0x1B0529: tracing_subscriber::fmt::init (mod.rs:1201)
==28380== by 0x16517C: tracetest::main (main.rs:5)
==28380== by 0x16589A: core::ops::function::FnOnce::call_once (function.rs:248)
==28380== by 0x1658DD: std::sys_common::backtrace::__rust_begin_short_backtrace (backtrace.rs:122)
==28380==
==28380== 32 bytes in 1 blocks are still reachable in loss record 2 of 7
==28380== at 0x4845899: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==28380== by 0x1C918B: alloc::alloc::alloc (alloc.rs:89)
==28380== by 0x1C9216: alloc::alloc::Global::alloc_impl (alloc.rs:171)
==28380== by 0x1C9A69: <alloc::alloc::Global as core::alloc::Allocator>::allocate (alloc.rs:231)
==28380== by 0x1CA5DD: alloc::raw_vec::finish_grow (raw_vec.rs:469)
==28380== by 0x1CAA75: alloc::raw_vec::RawVec<T,A>::grow_amortized (raw_vec.rs:401)
==28380== by 0x1CAC01: alloc::raw_vec::RawVec<T,A>::reserve_for_push (raw_vec.rs:299)
==28380== by 0x1C8C19: alloc::vec::Vec<T,A>::push (mod.rs:1731)
==28380== by 0x1CA14A: alloc::collections::binary_heap::BinaryHeap<T>::push (binary_heap.rs:493)
==28380== by 0x1C6DEF: thread_local::thread_id::ThreadIdManager::free (thread_id.rs:42)
==28380== by 0x1C7152: <thread_local::thread_id::ThreadHolder as core::ops::drop::Drop>::drop (thread_id.rs:85)
==28380== by 0x1CCD4A: core::ptr::drop_in_place<thread_local::thread_id::ThreadHolder> (mod.rs:486)
==28380==
==28380== 64 bytes in 1 blocks are still reachable in loss record 3 of 7
==28380== at 0x4845899: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==28380== by 0x1EA29B: alloc::alloc::alloc (alloc.rs:89)
==28380== by 0x1EA326: alloc::alloc::Global::alloc_impl (alloc.rs:171)
==28380== by 0x1EAB59: <alloc::alloc::Global as core::alloc::Allocator>::allocate (alloc.rs:231)
==28380== by 0x1E516D: alloc::raw_vec::finish_grow (raw_vec.rs:469)
==28380== by 0x1E5715: alloc::raw_vec::RawVec<T,A>::grow_amortized (raw_vec.rs:401)
==28380== by 0x1E5C01: alloc::raw_vec::RawVec<T,A>::reserve_for_push (raw_vec.rs:299)
==28380== by 0x1E7669: alloc::vec::Vec<T,A>::push (mod.rs:1731)
==28380== by 0x1EB1C1: tracing_core::callsite::register_dispatch (callsite.rs:144)
==28380== by 0x17F19C: tracing_core::dispatcher::Dispatch::new (dispatcher.rs:417)
==28380== by 0x182603: <tracing_core::dispatcher::Dispatch as core::convert::From<S>>::from (dispatcher.rs:656)
==28380== by 0x195103: <T as core::convert::Into<U>>::into (mod.rs:550)
==28380==
==28380== 64 bytes in 1 blocks are still reachable in loss record 4 of 7
==28380== at 0x4845899: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==28380== by 0x1EA29B: alloc::alloc::alloc (alloc.rs:89)
==28380== by 0x1EA326: alloc::alloc::Global::alloc_impl (alloc.rs:171)
==28380== by 0x1EAB59: <alloc::alloc::Global as core::alloc::Allocator>::allocate (alloc.rs:231)
==28380== by 0x1E516D: alloc::raw_vec::finish_grow (raw_vec.rs:469)
==28380== by 0x1E59C5: alloc::raw_vec::RawVec<T,A>::grow_amortized (raw_vec.rs:401)
==28380== by 0x1E5BD1: alloc::raw_vec::RawVec<T,A>::reserve_for_push (raw_vec.rs:299)
==28380== by 0x1E77C3: alloc::vec::Vec<T,A>::push (mod.rs:1731)
==28380== by 0x1EB0CF: tracing_core::callsite::register (callsite.rs:139)
==28380== by 0x1E1094: tracing::__macro_support::MacroCallsite::register::{{closure}} (lib.rs:1029)
==28380== by 0x1E133C: std::sync::once::Once::call_once::{{closure}} (once.rs:276)
==28380== by 0x206B69: std::sync::once::Once::call_inner (once.rs:434)
==28380==
==28380== 80 bytes in 2 blocks are still reachable in loss record 5 of 7
==28380== at 0x4845899: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==28380== by 0x1770AB: alloc::alloc::alloc (alloc.rs:89)
==28380== by 0x177136: alloc::alloc::Global::alloc_impl (alloc.rs:171)
==28380== by 0x178E99: <alloc::alloc::Global as core::alloc::Allocator>::allocate (alloc.rs:231)
==28380== by 0x1999AD: alloc::raw_vec::RawVec<T,A>::allocate_in (raw_vec.rs:186)
==28380== by 0x19C08C: alloc::raw_vec::RawVec<T,A>::with_capacity_in (raw_vec.rs:132)
==28380== by 0x16D953: alloc::vec::Vec<T,A>::with_capacity_in (mod.rs:613)
==28380== by 0x16C6E6: alloc::vec::Vec<T>::with_capacity (mod.rs:470)
==28380== by 0x165C7A: <alloc::vec::Vec<T> as alloc::vec::spec_from_iter_nested::SpecFromIterNested<T,I>>::from_iter (spec_from_iter_nested.rs:54)
==28380== by 0x16F64A: <alloc::vec::Vec<T> as alloc::vec::spec_from_iter::SpecFromIter<T,I>>::from_iter (spec_from_iter.rs:33)
==28380== by 0x16ED36: <alloc::vec::Vec<T> as core::iter::traits::collect::FromIterator<T>>::from_iter (mod.rs:2554)
==28380== by 0x173CAA: core::iter::traits::iterator::Iterator::collect (iterator.rs:1784)
==28380==
==28380== 1,112 bytes in 1 blocks are still reachable in loss record 6 of 7
==28380== at 0x4845899: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==28380== by 0x1770AB: alloc::alloc::alloc (alloc.rs:89)
==28380== by 0x177136: alloc::alloc::Global::alloc_impl (alloc.rs:171)
==28380== by 0x178E99: <alloc::alloc::Global as core::alloc::Allocator>::allocate (alloc.rs:231)
==28380== by 0x17700C: alloc::alloc::exchange_malloc (alloc.rs:320)
==28380== by 0x1B120A: alloc::sync::Arc<T>::new (sync.rs:346)
==28380== by 0x17F173: tracing_core::dispatcher::Dispatch::new (dispatcher.rs:415)
==28380== by 0x182603: <tracing_core::dispatcher::Dispatch as core::convert::From<S>>::from (dispatcher.rs:656)
==28380== by 0x195103: <T as core::convert::Into<U>>::into (mod.rs:550)
==28380== by 0x198A31: tracing_subscriber::util::SubscriberInitExt::try_init (util.rs:59)
==28380== by 0x1B038B: tracing_subscriber::fmt::try_init (mod.rs:1179)
==28380== by 0x1B0529: tracing_subscriber::fmt::init (mod.rs:1201)
==28380==
==28380== 32,768 bytes in 1 blocks are still reachable in loss record 7 of 7
==28380== at 0x4845899: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==28380== by 0x1770AB: alloc::alloc::alloc (alloc.rs:89)
==28380== by 0x177136: alloc::alloc::Global::alloc_impl (alloc.rs:171)
==28380== by 0x178E99: <alloc::alloc::Global as core::alloc::Allocator>::allocate (alloc.rs:231)
==28380== by 0x19938D: alloc::raw_vec::RawVec<T,A>::allocate_in (raw_vec.rs:186)
==28380== by 0x19C0CC: alloc::raw_vec::RawVec<T,A>::with_capacity_in (raw_vec.rs:132)
==28380== by 0x16D8F3: alloc::vec::Vec<T,A>::with_capacity_in (mod.rs:613)
==28380== by 0x16C6B6: alloc::vec::Vec<T>::with_capacity (mod.rs:470)
==28380== by 0x166060: sharded_slab::shard::Array<T,C>::new (shard.rs:273)
==28380== by 0x19E2ED: sharded_slab::pool::Pool<T>::new_with_config (pool.rs:394)
==28380== by 0x19E32D: sharded_slab::pool::Pool<T>::new (pool.rs:387)
==28380== by 0x17929B: <tracing_subscriber::registry::sharded::Registry as core::default::Default>::default (sharded.rs:138)
==28380==
==28380== LEAK SUMMARY:
==28380== definitely lost: 0 bytes in 0 blocks
==28380== indirectly lost: 0 bytes in 0 blocks
==28380== possibly lost: 0 bytes in 0 blocks
==28380== still reachable: 34,136 bytes in 8 blocks
==28380== suppressed: 0 bytes in 0 blocks
==28380==
==28380== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
hawkw commented
The default tracing subscriber is stored in a static. Creating a new fmt subscriber allocates some memory on the heap, and then stores the Subscriber in that static. In Rust, destructors are not run for static values, even when the program exits. Thus, Valgrind will report any held by a static as a "leak". However, the size of the heap allocation should be bounded rather than growing endlessly over the program's lifetime, so it shouldn't result in an issue in practice.
clubby789 commented
I see, thank you for explaining