Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Attempt to remove *very small* leak for Logger #5579

Draft
wants to merge 1 commit into
base: master
Choose a base branch
from

Conversation

fzakaria
Copy link
Contributor

@fzakaria fzakaria commented Nov 17, 2021

I'm running through running various sanitizers on the Nix project.
This was one leak that looked like it could be fixed intentionally using unique_ptr; granted the amount of memory here is pretty small.

Here is the leak that is fixed:

Direct leak of 16 byte(s) in 1 object(s) allocated from:
    #0 0x5876ef in operator new(unsigned long) (/home/fmzakari/code/github.com/NixOS/nix/src/nix/nix+0x5876ef)
    #1 0x7fa222e0b5d5 in nix::makeSimpleLogger(bool) /home/fmzakari/code/github.com/NixOS/nix/src/libutil/logging.cc:130:12
    #2 0x7fa222e0b5d5 in __cxx_global_var_init.6 /home/fmzakari/code/github.com/NixOS/nix/src/libutil/logging.cc:26
    #3 0x7fa222e0b5d5 in _GLOBAL__sub_I_logging.cc /home/fmzakari/code/github.com/NixOS/nix/src/libutil/logging.cc

Looks like there are in fact a few more given how that the loggers are just re-assigned over each other.

According to some discussion on Matrix, the Nix tool intentionally leaks memory through the AST/parser.

Perhaps it's worth investigating somehow disabling these leaks from the sanitizer so that at least they can be excluded from the result since they are quite noisy.

./src/nix/nix search jdk
==1526543==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 5432 byte(s) in 97 object(s) allocated from:
    #0 0x7139cf in operator new(unsigned long) (/home/fmzakari/code/github.com/NixOS/nix/src/nix/nix+0x7139cf)
    #1 0x7f644b4f1e13 in nix::EvalState::addPrimOp(nix::PrimOp&&) /home/fmzakari/code/github.com/NixOS/nix/src/libexpr/eval.cc:637:17
    #2 0x7f644b6ad46b in nix::EvalState::createBaseEnv() /home/fmzakari/code/github.com/NixOS/nix/src/libexpr/primops.cc:3719:13
    #3 0x7f644b4ef0f0 in nix::EvalState::EvalState(std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > const&, nix::ref<nix::Store>, std::shared_ptr<nix::Store>) /home/fmzakari/code/github.com/NixOS/nix/src/libexpr/eval.cc:459:5
    #4 0x7f644946c07e in void __gnu_cxx::new_allocator<nix::EvalState>::construct<nix::EvalState, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>, nix::ref<nix::Store> >(nix::EvalState*, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>&&, nix::ref<nix::Store>&&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/ext/new_allocator.h:150:23
    #5 0x7f644946bc9b in void std::allocator_traits<std::allocator<nix::EvalState> >::construct<nix::EvalState, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>, nix::ref<nix::Store> >(std::allocator<nix::EvalState>&, nix::EvalState*, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>&&, nix::ref<nix::Store>&&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/alloc_traits.h:512:8
    #6 0x7f644946b92d in std::_Sp_counted_ptr_inplace<nix::EvalState, std::allocator<nix::EvalState>, (__gnu_cxx::_Lock_policy)2>::_Sp_counted_ptr_inplace<std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>, nix::ref<nix::Store> >(std::allocator<nix::EvalState>, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>&&, nix::ref<nix::Store>&&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/shared_ptr_base.h:551:4
    #7 0x7f644946b5cf in std::__shared_count<(__gnu_cxx::_Lock_policy)2>::__shared_count<nix::EvalState, std::allocator<nix::EvalState>, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>, nix::ref<nix::Store> >(nix::EvalState*&, std::_Sp_alloc_shared_tag<std::allocator<nix::EvalState> >, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>&&, nix::ref<nix::Store>&&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/shared_ptr_base.h:683:6
    #8 0x7f644946b441 in std::__shared_ptr<nix::EvalState, (__gnu_cxx::_Lock_policy)2>::__shared_ptr<std::allocator<nix::EvalState>, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>, nix::ref<nix::Store> >(std::_Sp_alloc_shared_tag<std::allocator<nix::EvalState> >, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>&&, nix::ref<nix::Store>&&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/shared_ptr_base.h:1371:14
    #9 0x7f644946b3bb in std::shared_ptr<nix::EvalState>::shared_ptr<std::allocator<nix::EvalState>, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>, nix::ref<nix::Store> >(std::_Sp_alloc_shared_tag<std::allocator<nix::EvalState> >, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>&&, nix::ref<nix::Store>&&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/shared_ptr.h:408:4
    #10 0x7f644946b32b in std::shared_ptr<nix::EvalState> std::allocate_shared<nix::EvalState, std::allocator<nix::EvalState>, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>, nix::ref<nix::Store> >(std::allocator<nix::EvalState> const&, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>&&, nix::ref<nix::Store>&&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/shared_ptr.h:859:14
    #11 0x7f644944a0bd in std::shared_ptr<nix::EvalState> std::make_shared<nix::EvalState, std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>, nix::ref<nix::Store> >(std::__cxx11::list<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >&, nix::ref<nix::Store>&&, nix::ref<nix::Store>&&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/shared_ptr.h:875:14
    #12 0x7f644944235a in nix::EvalCommand::getEvalState() /home/fmzakari/code/github.com/NixOS/nix/src/libcmd/command.cc:77:21
    #13 0x7f64494830a3 in nix::SourceExprCommand::parseInstallables(nix::ref<nix::Store>, std::vector<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > >) /home/fmzakari/code/github.com/NixOS/nix/src/libcmd/installables.cc:672:25
    #14 0x7f6449483abe in nix::SourceExprCommand::parseInstallable(nix::ref<nix::Store>, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) /home/fmzakari/code/github.com/NixOS/nix/src/libcmd/installables.cc:692:25
    #15 0x7f64494873df in nix::InstallableCommand::prepare() /home/fmzakari/code/github.com/NixOS/nix/src/libcmd/installables.cc:890:19
    #16 0x7f6449487532 in virtual thunk to nix::InstallableCommand::prepare() /home/fmzakari/code/github.com/NixOS/nix/src/libcmd/installables.cc
    #17 0x97981d in nix::mainWrapped(int, char**) /home/fmzakari/code/github.com/NixOS/nix/src/nix/main.cc:365:27
    #18 0x97d47a in main::$_2::operator()() const /home/fmzakari/code/github.com/NixOS/nix/src/nix/main.cc:378:9
    #19 0x97d400 in void std::__invoke_impl<void, main::$_2&>(std::__invoke_other, main::$_2&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/invoke.h:60:14
    #20 0x97d3c0 in std::enable_if<is_invocable_r_v<void, main::$_2&>, void>::type std::__invoke_r<void, main::$_2&>(main::$_2&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/invoke.h:110:2
    #21 0x97d2f0 in std::_Function_handler<void (), main::$_2>::_M_invoke(std::_Any_data const&) /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/std_function.h:291:9
    #22 0x98a24b in std::function<void ()>::operator()() const /nix/store/sjhz1j2d1ssn59f66kqp92xj9mpsww2d-gcc-10.3.0/include/c++/10.3.0/bits/std_function.h:622:14
    #23 0x7f644adbcdca in nix::handleExceptions(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::function<void ()>) /home/fmzakari/code/github.com/NixOS/nix/src/libmain/shared.cc:359:13
    #24 0x97bf95 in main /home/fmzakari/code/github.com/NixOS/nix/src/nix/main.cc:377:24
    #25 0x7f6448ff3dec in __libc_start_main (/nix/store/jsp3h3wpzc842j0rz61m5ly71ak6qgdn-glibc-2.32-54/lib/libc.so.6+0x27dec)
...
......
............
SUMMARY: AddressSanitizer: 14982 byte(s) leaked in 331 allocation(s).

@fzakaria fzakaria changed the base branch from master to 2.4-maintenance November 17, 2021 03:58
@fzakaria fzakaria changed the title Faridzakaria/remove logging leak Attempt to remove *very small* leak Nov 17, 2021
@fzakaria fzakaria changed the title Attempt to remove *very small* leak Attempt to remove *very small* leak for Logger Nov 17, 2021
@thufschmitt
Copy link
Member

I have a vague recollection of trying that first when I wrote this, and then encountering some weird segfaults so falling back to the leaky-but-working plain pointers. But I’d be very interested if you can find the reason for the failures :)

{
return new ProgressBar(
return std::unique_ptr<Logger>(new ProgressBar(
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

std::make_unique please. The current proposal has a race condition where throwing as part of the ProgressBar constructor would still leak memory.

@@ -944,16 +944,21 @@ void processConnection(
throw Error("the Nix client version is too old");

auto tunnelLogger = new TunnelLogger(to, clientVersion);
auto prevLogger = nix::logger;
auto prevLogger = nix::logger.get();
Copy link
Member

@andir andir Nov 17, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You could std::move it and construct the TunnelLogger with std::make_unique instead.

This wouldn't require dealing with any raw pointers at all. Also we don't have to recreate a new smart pointer for the tunneLogger further down. Right now this is using a dangling pointer (as the unique_ptr was overriden which frees the previous memory it pointed at).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Here was the problem with this code:
If I std::move it to prevLogger, then nix::logger is invalid. It is only set to the tunnelLogger if its !recursive; so it has to remain correct otherwise.

I also can't simply assign nix::logger to the tunnelLogger as that will destroy the previousLogger which is called in the Finally block later.

It's a very tricky piece of code to get right with unique_ptr -- perhaps nix::logger should be shared_ptr instead or I can get make the prevLogger a const


unsigned int opCount = 0;

Finally finally([&]() {
_isInterrupted = false;
prevLogger->log(lvlDebug, fmt("%d operations", opCount));
delete(prevLogger);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just don't start doing that. Use smart pointers all the way if we do it. Keep them "smart" that way it'll cleanup for us.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please see the comment above -- happy to keep discussing it. I couldn't make it work easily.

@fzakaria
Copy link
Contributor Author

@regnat I think I got some of the segmentation fault fixed -- unfortunately one remains in the recursive nix test....
I have very little context on how that works

@fzakaria
Copy link
Contributor Author

@regnat GDB was helpful in finding at least some of the segfaults

[New Thread 0x7fffd5b4f640 (LWP 254377)]
--Type <RET> for more, q to quit, c to continue without paging--

Thread 3.1 "nix-build" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffff5d23a80 (LWP 254376)]
0x00007ffff755a66c in nix::JSONLogger::write (this=this@entry=0x7f9c00, json=...) at src/libutil/logging.cc:166
166	        prevLogger.log(lvlError, "@nix " + json.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace));

In this case it was that JSONLogger needs to take ownership of the loggers being passed in.
I've updated the code to reflect this.

@fzakaria fzakaria force-pushed the faridzakaria/remove-logging-leak branch 2 times, most recently from baef428 to d506b9d Compare November 18, 2021 00:26
@fzakaria fzakaria changed the base branch from 2.4-maintenance to master November 18, 2021 00:27
Comment on lines +112 to +117
if (!state->active) {
// wait for the thread to complete to avoid
// 'terminate called without an active exception'
if (updateThread.joinable()) updateThread.join();
return;
}
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would love feedback here.
This was kind of tricky because it looked like in some cases the ProgressBar class was destroyed while the thread was still active which raised an error.

I then tried to add join but I believe that there is a timing issue here that the thread was not even started.
Still feels like a data race.

@fzakaria fzakaria force-pushed the faridzakaria/remove-logging-leak branch from b9fc301 to b8256b2 Compare November 18, 2021 02:51
@fzakaria
Copy link
Contributor Author

Tests are timing out at 60m for some reason but they look healthy.

@fzakaria
Copy link
Contributor Author

fzakaria commented Dec 1, 2021

@regnat looks like it's timing out after 60m, which is surprising.

The logs show it's still trying to build. Not sure why this PR takes so long to build.

  LD     /nix/store/4szm9vi07k6vy043k2q25va0l0hf3g44-nix-2.5pre19700101_dirty/bin/nix
  GEN    doc/manual/nix.json
  GEN    doc/manual/conf-file.json
warning: you don't have Internet access; disabling some network-dependent features
  GEN    doc/manual/src/command-ref/new-cli
warning: you don't have Internet access; disabling some network-dependent features
  GEN    doc/manual/generated/man1/nix3-manpages

@thufschmitt
Copy link
Member

The logs show it's still trying to build. Not sure why this PR takes so long to build.

The last steps of the build are actually using the freshly built Nix. So maybe there’s something in the changes that causes Nix to hang (I guess that would be https://github.com/NixOS/nix/pull/5579/files#diff-3dbafb27c00d5891f1be772269e9979627f31e3ec1545660f7278523dda23606R112-R117 , but I’m not sure why it would hang )

@Ericson2314
Copy link
Member

TBH, if we are stuck on weird bugs, I would just use shared_ptr everywhere. Fixing leaks for long-lived daemons is much more important than squeezing out every last bit of performance.

@thufschmitt
Copy link
Member

@Ericson2314 has a point indeed :) Esp. in this case where using a shared_pointer won’t have even a remotely measurable impact

@stale
Copy link

stale bot commented Jun 12, 2022

I marked this as stale due to inactivity. → More info

@stale stale bot added the stale label Jun 12, 2022
@Ericson2314
Copy link
Member

On a separate note, it would be good to get whatever static analyses you were running in CI!

@stale stale bot removed the stale label Jun 14, 2023
@Ericson2314 Ericson2314 marked this pull request as draft June 22, 2023 23:33
@Ericson2314
Copy link
Member

Making as draft because IIRC this doesn't quite work.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants