1501654 - Cranelift logger's memory is leaked on shutdown

Status: RESOLVED WONTFIX

(Core :: JavaScript: WebAssembly, defect, P5)

Description

[Benjamin Bouvier [:bbouvier] (inactive)]

This looks plausible: the logger is stored into a global static variable (in the `log` crate), and :acrichton told me that Rust global memory storage is just leaked when exiting the program.

Gecko is doing something different here, by providing its own logger impl, but it should also leak memory:
https://searchfox.org/mozilla-central/source/toolkit/library/rust/shared/lib.rs#75-80

I've done a quick search in the Valgrind suppression files, but couldn't find any reference to the gkrust init function in there.

==19253== HEAP SUMMARY:
==19253==     in use at exit: 392 bytes in 10 blocks
==19253==   total heap usage: 8,151 allocs, 8,141 frees, 7,386,959
bytes allocated
==19253==
==19253== 8 bytes in 1 blocks are still reachable in loss record 1 of 10
==19253==    at 0x4C2DE4D: malloc (vg_replace_malloc.c:299)
==19253==    by 0x2197CF2: alloc (alloc.rs:62)
==19253==    by 0x2197CF2: exchange_malloc (alloc.rs:157)
==19253==    by 0x2197CF2: new<closure> (boxed.rs:96)
==19253==    by 0x2197CF2: at_exit<closure> (mod.rs:111)
==19253==    by 0x2197CF2:
init<std::sys_common::remutex::ReentrantMutex<core::cell::RefCell<std::io::stdio::Maybe<std::io::stdio::StderrRaw>>>>
(lazy.rs:56)
==19253==    by 0x2197CF2: <std::io::lazy::Lazy<T>>::get (lazy.rs:42)
==19253==    by 0x21C0500: std::io::stdio::stderr (stdio.rs:536)
==19253==    by 0x206278E: termcolor::IoStandardStream::new (lib.rs:209)
==19253==    by 0x2062C4E: termcolor::BufferWriter::create (lib.rs:601)
==19253==    by 0x2062CB1: termcolor::BufferWriter::stderr (lib.rs:662)
==19253==    by 0x1FB0DA6: env_logger::fmt::Builder::build (fmt.rs:251)
==19253==    by 0x1FAFC0C: env_logger::Builder::build (lib.rs:632)
==19253==    by 0x1FAFB6C: env_logger::Builder::try_init (lib.rs:606)
==19253==    by 0x1FAFF53: env_logger::try_init_from_env (lib.rs:846)
==19253==    by 0x1FAFEE7: env_logger::try_init (lib.rs:795)
==19253==    by 0x1D0DFB9: js::wasm::Init() (WasmProcess.cpp:286)
==19253==
==19253== 8 bytes in 1 blocks are still reachable in loss record 2 of 10
==19253==    at 0x4C2DE4D: malloc (vg_replace_malloc.c:299)
==19253==    by 0x2197D2F: alloc (alloc.rs:62)
==19253==    by 0x2197D2F: exchange_malloc (alloc.rs:157)
==19253==    by 0x2197D2F:
new<alloc::sync::Arc<std::sys_common::remutex::ReentrantMutex<core::cell::RefCell<std::io::stdio::Maybe<std::io::stdio::StderrRaw>>>>>
(boxed.rs:96)
==19253==    by 0x2197D2F:
init<std::sys_common::remutex::ReentrantMutex<core::cell::RefCell<std::io::stdio::Maybe<std::io::stdio::StderrRaw>>>>
(lazy.rs:65)
==19253==    by 0x2197D2F: <std::io::lazy::Lazy<T>>::get (lazy.rs:42)
==19253==    by 0x21C0500: std::io::stdio::stderr (stdio.rs:536)
==19253==    by 0x206278E: termcolor::IoStandardStream::new (lib.rs:209)
==19253==    by 0x2062C4E: termcolor::BufferWriter::create (lib.rs:601)
==19253==    by 0x2062CB1: termcolor::BufferWriter::stderr (lib.rs:662)
==19253==    by 0x1FB0DA6: env_logger::fmt::Builder::build (fmt.rs:251)
==19253==    by 0x1FAFC0C: env_logger::Builder::build (lib.rs:632)
==19253==    by 0x1FAFB6C: env_logger::Builder::try_init (lib.rs:606)
==19253==    by 0x1FAFF53: env_logger::try_init_from_env (lib.rs:846)
==19253==    by 0x1FAFEE7: env_logger::try_init (lib.rs:795)
==19253==    by 0x1D0DFB9: js::wasm::Init() (WasmProcess.cpp:286)
==19253==
==19253== 16 bytes in 1 blocks are still reachable in loss record 3 of 10
==19253==    at 0x4C2DE4D: malloc (vg_replace_malloc.c:299)
==19253==    by 0x21CFB41: alloc (alloc.rs:62)
==19253==    by 0x21CFB41: alloc (alloc.rs:123)
==19253==    by 0x21CFB41:
reserve_internal<alloc::boxed::Box<FnMut<()>>,alloc::alloc::Global>
(raw_vec.rs:679)
==19253==    by 0x21CFB41: <alloc::raw_vec::RawVec<T, A>>::reserve
(raw_vec.rs:502)
==19253==    by 0x21B9CFC: reserve<alloc::boxed::Box<FnBox<()>>> (vec.rs:464)
==19253==    by 0x21B9CFC: push<alloc::boxed::Box<FnBox<()>>> (vec.rs:1066)
==19253==    by 0x21B9CFC: std::sys_common::at_exit_imp::push
(at_exit_imp.rs:75)
==19253==    by 0x2197D09: at_exit<closure> (mod.rs:111)
==19253==    by 0x2197D09:
init<std::sys_common::remutex::ReentrantMutex<core::cell::RefCell<std::io::stdio::Maybe<std::io::stdio::StderrRaw>>>>
(lazy.rs:56)
==19253==    by 0x2197D09: <std::io::lazy::Lazy<T>>::get (lazy.rs:42)
==19253==    by 0x21C0500: std::io::stdio::stderr (stdio.rs:536)
==19253==    by 0x206278E: termcolor::IoStandardStream::new (lib.rs:209)
==19253==    by 0x2062C4E: termcolor::BufferWriter::create (lib.rs:601)
==19253==    by 0x2062CB1: termcolor::BufferWriter::stderr (lib.rs:662)
==19253==    by 0x1FB0DA6: env_logger::fmt::Builder::build (fmt.rs:251)
==19253==    by 0x1FAFC0C: env_logger::Builder::build (lib.rs:632)
==19253==    by 0x1FAFB6C: env_logger::Builder::try_init (lib.rs:606)
==19253==    by 0x1FAFF53: env_logger::try_init_from_env (lib.rs:846)
==19253==
==19253== 24 bytes in 1 blocks are still reachable in loss record 4 of 10
==19253==    at 0x4C2DE4D: malloc (vg_replace_malloc.c:299)
==19253==    by 0x21B9CBE: alloc (alloc.rs:62)
==19253==    by 0x21B9CBE: exchange_malloc (alloc.rs:157)
==19253==    by 0x21B9CBE: init (at_exit_imp.rs:39)
==19253==    by 0x21B9CBE: std::sys_common::at_exit_imp::push
(at_exit_imp.rs:74)
==19253==    by 0x2197D09: at_exit<closure> (mod.rs:111)
==19253==    by 0x2197D09:
init<std::sys_common::remutex::ReentrantMutex<core::cell::RefCell<std::io::stdio::Maybe<std::io::stdio::StderrRaw>>>>
(lazy.rs:56)
==19253==    by 0x2197D09: <std::io::lazy::Lazy<T>>::get (lazy.rs:42)
==19253==    by 0x21C0500: std::io::stdio::stderr (stdio.rs:536)
==19253==    by 0x206278E: termcolor::IoStandardStream::new (lib.rs:209)
==19253==    by 0x2062C4E: termcolor::BufferWriter::create (lib.rs:601)
==19253==    by 0x2062CB1: termcolor::BufferWriter::stderr (lib.rs:662)
==19253==    by 0x1FB0DA6: env_logger::fmt::Builder::build (fmt.rs:251)
==19253==    by 0x1FAFC0C: env_logger::Builder::build (lib.rs:632)
==19253==    by 0x1FAFB6C: env_logger::Builder::try_init (lib.rs:606)
==19253==    by 0x1FAFF53: env_logger::try_init_from_env (lib.rs:846)
==19253==    by 0x1FAFEE7: env_logger::try_init (lib.rs:795)
==19253==
==19253== 24 bytes in 1 blocks are still reachable in loss record 5 of 10
==19253==    at 0x4C2DE4D: malloc (vg_replace_malloc.c:299)
==19253==    by 0x1FAF30F: alloc::alloc::exchange_malloc (alloc.rs:157)
==19253==    by 0x1FAF5AB: new<closure> (boxed.rs:96)
==19253==    by 0x1FAF5AB: env_logger::Format::into_boxed_fn (lib.rs:272)
==19253==    by 0x1FAFC43: env_logger::Builder::build (lib.rs:634)
==19253==    by 0x1FAFB6C: env_logger::Builder::try_init (lib.rs:606)
==19253==    by 0x1FAFF53: env_logger::try_init_from_env (lib.rs:846)
==19253==    by 0x1FAFEE7: env_logger::try_init (lib.rs:795)
==19253==    by 0x1D0DFB9: js::wasm::Init() (WasmProcess.cpp:286)
==19253==    by 0x1A9654C: JS::detail::InitWithFailureDiagnostic(bool)
(Initialization.cpp:116)
==19253==    by 0x13742BD: JS_Init() (Initialization.h:93)
==19253==    by 0x1354B8F: main (js.cpp:10620)
==19253==
==19253== 32 bytes in 1 blocks are still reachable in loss record 6 of 10
==19253==    at 0x4C2DE4D: malloc (vg_replace_malloc.c:299)
==19253==    by 0x1FB7015:
_ZN59_$LT$alloc..alloc..Global$u20$as$u20$core..alloc..Alloc$GT$5alloc17h53384f8fe813facdE.llvm.6879053585081954382
(alloc.rs:123)
==19253==    by 0x1FB6C23: <alloc::raw_vec::RawVec<T,
A>>::reserve_internal (raw_vec.rs:679)
==19253==    by 0x1FB6D10: <alloc::raw_vec::RawVec<T, A>>::reserve
(raw_vec.rs:502)
==19253==    by 0x1FB2673:
_ZN33_$LT$alloc..vec..Vec$LT$T$GT$$GT$4push17h49082ebedec53874E.llvm.2903068862048922144
(vec.rs:1066)
==19253==    by 0x1FB3FA9: env_logger::filter::Builder::build (mod.rs:234)
==19253==    by 0x1FAFC17: env_logger::Builder::build (lib.rs:633)
==19253==    by 0x1FAFB6C: env_logger::Builder::try_init (lib.rs:606)
==19253==    by 0x1FAFF53: env_logger::try_init_from_env (lib.rs:846)
==19253==    by 0x1FAFEE7: env_logger::try_init (lib.rs:795)
==19253==    by 0x1D0DFB9: js::wasm::Init() (WasmProcess.cpp:286)
==19253==    by 0x1A9654C: JS::detail::InitWithFailureDiagnostic(bool)
(Initialization.cpp:116)
==19253==
==19253== 32 bytes in 1 blocks are still reachable in loss record 7 of 10
==19253==    at 0x4C3009C: calloc (vg_replace_malloc.c:752)
==19253==    by 0x536367E: _dlerror_run (in /usr/lib64/libdl-2.24.so)
==19253==    by 0x5362FA1: dlopen@@GLIBC_2.2.5 (in /usr/lib64/libdl-2.24.so)
==19253==    by 0x15C6B6F: loadiJIT_Funcs (jitprofiling.c:263)
==19253==    by 0x15C6379: js::vtune::Initialize() (VTuneWrapper.cpp:39)
==19253==    by 0x1A9657E: JS::detail::InitWithFailureDiagnostic(bool)
(Initialization.cpp:129)
==19253==    by 0x13742BD: JS_Init() (Initialization.h:93)
==19253==    by 0x1354B8F: main (js.cpp:10620)
==19253==
==19253== 40 bytes in 1 blocks are still reachable in loss record 8 of 10
==19253==    at 0x4C2DE4D: malloc (vg_replace_malloc.c:299)
==19253==    by 0x2198B23: alloc (alloc.rs:62)
==19253==    by 0x2198B23: exchange_malloc (alloc.rs:157)
==19253==    by 0x2198B23:
<std::sys_common::remutex::ReentrantMutex<T>>::new (remutex.rs:64)
==19253==    by 0x21C0551: std::io::stdio::stderr::stderr_init (stdio.rs:544)
==19253==    by 0x2197D0E:
init<std::sys_common::remutex::ReentrantMutex<core::cell::RefCell<std::io::stdio::Maybe<std::io::stdio::StderrRaw>>>>
(lazy.rs:63)
==19253==    by 0x2197D0E: <std::io::lazy::Lazy<T>>::get (lazy.rs:42)
==19253==    by 0x21C0500: std::io::stdio::stderr (stdio.rs:536)
==19253==    by 0x206278E: termcolor::IoStandardStream::new (lib.rs:209)
==19253==    by 0x2062C4E: termcolor::BufferWriter::create (lib.rs:601)
==19253==    by 0x2062CB1: termcolor::BufferWriter::stderr (lib.rs:662)
==19253==    by 0x1FB0DA6: env_logger::fmt::Builder::build (fmt.rs:251)
==19253==    by 0x1FAFC0C: env_logger::Builder::build (lib.rs:632)
==19253==    by 0x1FAFB6C: env_logger::Builder::try_init (lib.rs:606)
==19253==    by 0x1FAFF53: env_logger::try_init_from_env (lib.rs:846)
==19253==
==19253== 48 bytes in 1 blocks are still reachable in loss record 9 of 10
==19253==    at 0x4C2DE4D: malloc (vg_replace_malloc.c:299)
==19253==    by 0x21C0560: alloc (alloc.rs:62)
==19253==    by 0x21C0560: exchange_malloc (alloc.rs:157)
==19253==    by 0x21C0560:
new<std::sys_common::remutex::ReentrantMutex<core::cell::RefCell<std::io::stdio::Maybe<std::io::stdio::StderrRaw>>>>
(sync.rs:291)
==19253==    by 0x21C0560: std::io::stdio::stderr::stderr_init (stdio.rs:544)
==19253==    by 0x2197D0E:
init<std::sys_common::remutex::ReentrantMutex<core::cell::RefCell<std::io::stdio::Maybe<std::io::stdio::StderrRaw>>>>
(lazy.rs:63)
==19253==    by 0x2197D0E: <std::io::lazy::Lazy<T>>::get (lazy.rs:42)
==19253==    by 0x21C0500: std::io::stdio::stderr (stdio.rs:536)
==19253==    by 0x206278E: termcolor::IoStandardStream::new (lib.rs:209)
==19253==    by 0x2062C4E: termcolor::BufferWriter::create (lib.rs:601)
==19253==    by 0x2062CB1: termcolor::BufferWriter::stderr (lib.rs:662)
==19253==    by 0x1FB0DA6: env_logger::fmt::Builder::build (fmt.rs:251)
==19253==    by 0x1FAFC0C: env_logger::Builder::build (lib.rs:632)
==19253==    by 0x1FAFB6C: env_logger::Builder::try_init (lib.rs:606)
==19253==    by 0x1FAFF53: env_logger::try_init_from_env (lib.rs:846)
==19253==    by 0x1FAFEE7: env_logger::try_init (lib.rs:795)
==19253==
==19253== 160 bytes in 1 blocks are still reachable in loss record 10 of 10
==19253==    at 0x4C2DE4D: malloc (vg_replace_malloc.c:299)
==19253==    by 0x1FAF30F: alloc::alloc::exchange_malloc (alloc.rs:157)
==19253==    by 0x1FAFB9E: new<env_logger::Logger> (boxed.rs:96)
==19253==    by 0x1FAFB9E: env_logger::Builder::try_init (lib.rs:609)
==19253==    by 0x1FAFF53: env_logger::try_init_from_env (lib.rs:846)
==19253==    by 0x1FAFEE7: env_logger::try_init (lib.rs:795)
==19253==    by 0x1D0DFB9: js::wasm::Init() (WasmProcess.cpp:286)
==19253==    by 0x1A9654C: JS::detail::InitWithFailureDiagnostic(bool)
(Initialization.cpp:116)
==19253==    by 0x13742BD: JS_Init() (Initialization.h:93)
==19253==    by 0x1354B8F: main (js.cpp:10620)
==19253==
==19253== LEAK SUMMARY:
==19253==    definitely lost: 0 bytes in 0 blocks
==19253==    indirectly lost: 0 bytes in 0 blocks
==19253==      possibly lost: 0 bytes in 0 blocks
==19253==    still reachable: 392 bytes in 10 blocks
==19253==         suppressed: 0 bytes in 0 blocks
==19253==
==19253== For counts of detected and suppressed errors, rerun with: -v
==19253== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

Comment 1

[Benjamin Bouvier [:bbouvier] (inactive)]

Configure parameters needed for this:

(cd ../src && autoconf-2.13) && \
CC="ccache clang" CXX="ccache clang++" ../src/configure \
  --enable-debug --enable-optimize="-g -Og" \
  --enable-valgrind --disable-jemalloc

Runtime parameters for valgrind: valgrind --leak-check=full --show-reachable=yes $jsshell
Since the indications were sent by Julian, this might need quite a recent version of Valgrind. I, for one, couldn't get precise names in the stack frames.