From b4c6bfd72a8652031c166ac4c71f2c1f1a7bc3c7 Mon Sep 17 00:00:00 2001 From: eldritch horrors Date: Sat, 5 Apr 2025 21:57:20 +0200 Subject: [PATCH] libutil: trace unwinding through async tasks this gives us a semblance of a stack trace if async tasks fail, like: Async task trace (probably incomplete): #0: virtual kj::Promise> nix::LocalDerivationGoal::tryLocalBuild() (lix/libstore/build/local-derivation-goal.cc:257:33) building of '//0ppb5aj4p3vp0icnkq4yibajw1czvdja-bash52-009.drv^out' from .drv file #1: kj::Promise> nix::DerivationGoal::outputsSubstitutionTried() (lix/libstore/build/derivation-goal.cc:381:47) building of '//0ppb5aj4p3vp0icnkq4yibajw1czvdja-bash52-009.drv^out' from .drv file #2: kj::Promise> nix::DerivationGoal::loadDerivation() (lix/libstore/build/derivation-goal.cc:213:41) building of '//0ppb5aj4p3vp0icnkq4yibajw1czvdja-bash52-009.drv^out' from .drv file #3: kj::Promise> nix::DerivationGoal::gaveUpOnSubstitution() (lix/libstore/build/derivation-goal.cc:453:62) building of '//f8rkb1vam9y9vi9scsm1v213b01rm72h-bash-5.2p37.drv^out' from .drv file #4: kj::Promise> nix::DerivationGoal::outputsSubstitutionTried() (lix/libstore/build/derivation-goal.cc:381:47) building of '//f8rkb1vam9y9vi9scsm1v213b01rm72h-bash-5.2p37.drv^out' from .drv file #5: kj::Promise> nix::DerivationGoal::loadDerivation() (lix/libstore/build/derivation-goal.cc:213:41) building of '//f8rkb1vam9y9vi9scsm1v213b01rm72h-bash-5.2p37.drv^out' from .drv file #6: kj::Promise> nix::DerivationGoal::gaveUpOnSubstitution() (lix/libstore/build/derivation-goal.cc:453:62) building of '//qa9jvc4j6fphzwr63k5c829b2hr04q6z-foo.drv^*' from .drv file #7: kj::Promise> nix::DerivationGoal::outputsSubstitutionTried() (lix/libstore/build/derivation-goal.cc:381:47) building of '//qa9jvc4j6fphzwr63k5c829b2hr04q6z-foo.drv^*' from .drv file #8: kj::Promise> nix::DerivationGoal::loadDerivation() (lix/libstore/build/derivation-goal.cc:213:41) building of '//qa9jvc4j6fphzwr63k5c829b2hr04q6z-foo.drv^*' from .drv file #9: virtual kj::Promise> nix::Store::buildPaths(const std::vector &, BuildMode, std::shared_ptr) (lix/libstore/build/entry-points.cc:20:11) it's not much, but it's a lot better than nothing. sadly we're forced to disable another clang-tidy warning now, but since that one's about assert side effects being compiled out in release mode and we've long since decided to just not do that we are not affected by this at all. also see #724 for a related but different approach to origin tracing. Change-Id: I8161f82ca39d0b271316ea4df80513acc1b06a03 --- .clang-tidy | 2 ++ lix/libmain/crash-handler.cc | 27 +++++++++++++++ lix/libstore/build/goal.hh | 5 +++ lix/libstore/build/local-derivation-goal.cc | 2 ++ lix/libutil/async.hh | 38 +++++++++++++++++++-- lix/libutil/error.hh | 32 ++++++++++++++++- 6 files changed, 102 insertions(+), 4 deletions(-) diff --git a/.clang-tidy b/.clang-tidy index 77ee39cb8..9a34d8fc1 100644 --- a/.clang-tidy +++ b/.clang-tidy @@ -18,6 +18,8 @@ Checks: - -bugprone-branch-clone # extremely noisy before clang 19: https://github.com/llvm/llvm-project/issues/93959 - -bugprone-multi-level-implicit-pointer-conversion + # we don't compile out our asserts + - -bugprone-assert-side-effect # all thrown exceptions must derive from std::exception - hicpp-exception-baseclass # capturing async lambdas are dangerous diff --git a/lix/libmain/crash-handler.cc b/lix/libmain/crash-handler.cc index 8c3b7c233..419eb0f26 100644 --- a/lix/libmain/crash-handler.cc +++ b/lix/libmain/crash-handler.cc @@ -1,9 +1,11 @@ #include "lix/libmain/crash-handler.hh" +#include "lix/libutil/error.hh" #include "lix/libutil/fmt.hh" #include "lix/libutil/logging.hh" #include #include +#include namespace nix { @@ -11,6 +13,8 @@ namespace { void onTerminate() { + std::shared_ptr> asyncTrace; + logFatal("Lix crashed. This is a bug. We would appreciate if you report it along with what caused it at https://git.lix.systems/lix-project/lix/issues with the following information included:\n"); try { std::exception_ptr eptr = std::current_exception(); @@ -19,6 +23,12 @@ void onTerminate() } else { logFatal("std::terminate() called without exception"); } + } catch (const ForeignException & ex) { + asyncTrace = ex.asyncTrace(); + logFatal(fmt("Exception: %s: %s", boost::core::demangle(ex.innerType.name()), ex.what())); + } catch (const BaseException & ex) { + asyncTrace = ex.asyncTrace(); + logFatal(fmt("Exception: %s: %s", boost::core::demangle(typeid(ex).name()), ex.what())); } catch (const std::exception & ex) { // NOLINT(lix-foreign-exceptions) logFatal(fmt("Exception: %s: %s", boost::core::demangle(typeid(ex).name()), ex.what())); } catch (...) { @@ -28,6 +38,23 @@ void onTerminate() logFatal("Stack trace:"); logFatal(getStackTrace()); + if (asyncTrace && !asyncTrace->empty()) { + logFatal("Async task trace (probably incomplete):"); + for (auto [i, frame] : enumerate(*asyncTrace)) { + logFatal( + fmt("#%i: %s (%s:%i:%i)", + i, + frame.location.function_name(), + frame.location.file_name(), + frame.location.line(), + frame.location.column()) + ); + if (frame.description) { + logFatal(fmt("\t%s", *frame.description)); + } + } + } + std::abort(); } } diff --git a/lix/libstore/build/goal.hh b/lix/libstore/build/goal.hh index 8b4043d10..c4ed70603 100644 --- a/lix/libstore/build/goal.hh +++ b/lix/libstore/build/goal.hh @@ -115,6 +115,11 @@ protected: virtual kj::Promise> workImpl() noexcept = 0; + std::string lixAsyncTaskContext() const + { + return name; + } + public: explicit Goal(Worker & worker, bool isDependency) : worker(worker) diff --git a/lix/libstore/build/local-derivation-goal.cc b/lix/libstore/build/local-derivation-goal.cc index 4ce79d42f..4239be3ab 100644 --- a/lix/libstore/build/local-derivation-goal.cc +++ b/lix/libstore/build/local-derivation-goal.cc @@ -26,9 +26,11 @@ #include "lix/libutil/thread-name.hh" #include +#include #include #include +#include #include #include #include diff --git a/lix/libutil/async.hh b/lix/libutil/async.hh index 513c56cac..288dfaeee 100644 --- a/lix/libutil/async.hh +++ b/lix/libutil/async.hh @@ -1,11 +1,14 @@ #pragma once ///@file +#include "lix/libutil/error.hh" #include "lix/libutil/result.hh" #include "lix/libutil/signals.hh" #include #include #include +#include +#include namespace nix { @@ -94,14 +97,43 @@ auto runAsyncInNewThread(std::invocable auto fn) return AIOROOT.blockOn(__VA_ARGS__); \ }) +#define LIX_TRY_AWAIT_CONTEXT(ctx, ...) \ + ({ \ + auto _lix_awaited = co_await (__VA_ARGS__); \ + if (_lix_awaited.has_error()) { \ + try { \ + _lix_awaited.value(); \ + } catch (::nix::BaseException & e) { \ + e.addAsyncTrace(::std::source_location::current(), ctx()); \ + throw; \ + } catch (::std::exception & e) { /* NOLINT(lix-foreign-exceptions) */ \ + ::nix::ForeignException fe(e); \ + fe.addAsyncTrace(::std::source_location::current(), ctx()); \ + throw fe; \ + } \ + } \ + ::nix::detail::materializeResult(std::move(_lix_awaited)); \ + }) + +/** + * Magic name used by `LIX_TRY_AWAIT` to insert additional context into an + * async trace frame. This name will be looked up in the local scope every + * time a try-await expression encounters an exception and then called. As + * such it can be a function, a member function name, or even a type name. + */ +static constexpr std::optional lixAsyncTaskContext() +{ + return std::nullopt; +} + // force materialization of the value. result::value() returns only an rvalue reference // and is thus unsuitable for use in e.g. range for without materialization. ideally we // would wrap the expression in `auto()`, but apple clang fails when given `auto(void)` -#define LIX_TRY_AWAIT(...) (::nix::detail::materializeResult(co_await (__VA_ARGS__))) +#define LIX_TRY_AWAIT(...) LIX_TRY_AWAIT_CONTEXT(lixAsyncTaskContext, __VA_ARGS__) #if LIX_UR_COMPILER_UWU -# define RUN_ASYNC_IN_NEW_THREAD LIX_RUN_ASYNC_IN_NEW_THREAD -# define TRY_AWAIT LIX_TRY_AWAIT +#define RUN_ASYNC_IN_NEW_THREAD LIX_RUN_ASYNC_IN_NEW_THREAD +#define TRY_AWAIT LIX_TRY_AWAIT #endif template diff --git a/lix/libutil/error.hh b/lix/libutil/error.hh index 34c5fb189..2530b0a82 100644 --- a/lix/libutil/error.hh +++ b/lix/libutil/error.hh @@ -25,6 +25,7 @@ #include #include +#include #include #include #include @@ -98,8 +99,37 @@ std::ostream & showErrorInfo(std::ostream & out, const ErrorInfo & einfo, bool s * Base class for both errors we can handle (c.f. `BaseError`) and anything * we want to log and terminate when encountered (c.f. `ForeignException`). */ -struct BaseException : public std::exception +class BaseException : public std::exception { +public: + struct AsyncTraceFrame + { + std::source_location location; + std::optional description; + }; + +private: + /** + * Approximate list of async tasks this exception propagated through. + * It is the responsibility of each task to add itself to the back of + * this list during stack unwinding. `TRY_AWAIT` does this when used. + */ + std::shared_ptr> _asyncTrace; + +public: + std::shared_ptr> asyncTrace() const + { + return _asyncTrace; + } + + void + addAsyncTrace(std::source_location loc, std::optional description = std::nullopt) + { + if (!_asyncTrace) { + _asyncTrace = std::make_shared>(); + } + _asyncTrace->push_back(AsyncTraceFrame{loc, std::move(description)}); + } }; /**