From b73a7f18159059b7968fbc5665a7f74261860a7c Mon Sep 17 00:00:00 2001 From: eldritch horrors Date: Sat, 11 Oct 2025 21:59:56 +0200 Subject: [PATCH] libutil: clean up the Activity interface a bit create activities from loggers themselves instead of passing the logger as a constructor argument and allow direct construction of children, no direct logger access needed. most call sites are not changed because we still need to handle the "no parent" case, and the logger method can do that more cleanly than a ternary at each site that creates an activity. we may eventually want to create a root activity, which is cleaner too. Change-Id: I295e056228dabb08a1316eba7973874784baa113 --- lix/legacy/build-remote.cc | 16 +++-- lix/libcmd/installable-flake.cc | 3 +- lix/libfetchers/fetch-to-store.cc | 6 +- lix/libfetchers/git.cc | 16 +++-- lix/libfetchers/mercurial.cc | 4 +- lix/libfetchers/path.cc | 2 +- lix/libmain/progress-bar.cc | 6 +- lix/libmain/progress-bar.hh | 6 +- lix/libstore/binary-cache-store.cc | 5 +- lix/libstore/build/derivation-goal.cc | 26 +++++--- lix/libstore/build/derivation-goal.hh | 4 +- lix/libstore/build/local-derivation-goal.cc | 8 ++- lix/libstore/build/substitution-goal.cc | 6 +- lix/libstore/build/worker.cc | 10 +-- lix/libstore/daemon.cc | 14 ++-- lix/libstore/filetransfer.cc | 5 +- lix/libstore/misc.cc | 2 +- lix/libstore/optimise-store.cc | 6 +- lix/libstore/remote-store.cc | 2 +- lix/libstore/store-api.cc | 11 ++-- lix/libutil/logging.cc | 71 ++++++++++++--------- lix/libutil/logging.hh | 66 +++++++++++-------- lix/nix/flake.cc | 57 ++++++++++------- lix/nix/prefetch.cc | 7 +- lix/nix/profile.cc | 3 +- lix/nix/search.cc | 10 +-- lix/nix/upgrade-nix.cc | 12 +++- lix/nix/verify.cc | 6 +- tests/unit/libmain/progress-bar.cc | 5 +- 29 files changed, 238 insertions(+), 157 deletions(-) diff --git a/lix/legacy/build-remote.cc b/lix/legacy/build-remote.cc index 780e7c990..4b6b82132 100644 --- a/lix/legacy/build-remote.cc +++ b/lix/legacy/build-remote.cc @@ -295,8 +295,8 @@ try { Pipe logPipe; try { - Activity act( - *logger, lvlTalkative, actUnknown, fmt("connecting to '%s'", bestMachine->storeUri) + auto act = logger->startActivity( + lvlTalkative, actUnknown, fmt("connecting to '%s'", bestMachine->storeUri) ); std::tie(sshStore, logPipe) = TRY_AWAIT(bestMachine->openStore()); @@ -445,7 +445,9 @@ kj::Promise AcceptedBuild::run(RunContext context) AutoCloseFD uploadLock = openLockFile(lockFileName, true); { - Activity act(*logger, lvlTalkative, actUnknown, fmt("waiting for the upload lock to '%s'", storeUri)); + auto act = logger->startActivity( + lvlTalkative, actUnknown, fmt("waiting for the upload lock to '%s'", storeUri) + ); auto result = TRY_AWAIT( AIO().timeoutAfter(15 * kj::MINUTES, lockFileAsync(uploadLock.get(), ltWrite)) @@ -458,7 +460,9 @@ kj::Promise AcceptedBuild::run(RunContext context) auto substitute = settings.buildersUseSubstitutes ? Substitute : NoSubstitute; { - Activity act(*logger, lvlTalkative, actUnknown, fmt("copying dependencies to '%s'", storeUri)); + auto act = logger->startActivity( + lvlTalkative, actUnknown, fmt("copying dependencies to '%s'", storeUri) + ); TRY_AWAIT(copyPaths(*store, *sshStore, inputs, NoRepair, NoCheckSigs, substitute)); } @@ -528,7 +532,9 @@ kj::Promise AcceptedBuild::run(RunContext context) } if (!missingPaths.empty()) { - Activity act(*logger, lvlTalkative, actUnknown, fmt("copying outputs from '%s'", storeUri)); + auto act = logger->startActivity( + lvlTalkative, actUnknown, fmt("copying outputs from '%s'", storeUri) + ); if (auto localStore = store.try_cast_shared()) for (auto & path : missingPaths) localStore->locksHeld.insert(store->printStorePath(path)); /* FIXME: ugly */ diff --git a/lix/libcmd/installable-flake.cc b/lix/libcmd/installable-flake.cc index 700c43688..988248d93 100644 --- a/lix/libcmd/installable-flake.cc +++ b/lix/libcmd/installable-flake.cc @@ -60,7 +60,8 @@ InstallableFlake::InstallableFlake( DerivedPathsWithInfo InstallableFlake::toDerivedPaths(EvalState & state) { - Activity act(*logger, lvlTalkative, actUnknown, fmt("evaluating derivation '%s'", what())); + auto act = + logger->startActivity(lvlTalkative, actUnknown, fmt("evaluating derivation '%s'", what())); auto attr = getCursor(state); diff --git a/lix/libfetchers/fetch-to-store.cc b/lix/libfetchers/fetch-to-store.cc index b86effc8b..b8f4ec764 100644 --- a/lix/libfetchers/fetch-to-store.cc +++ b/lix/libfetchers/fetch-to-store.cc @@ -10,7 +10,7 @@ kj::Promise> fetchToStoreFlat( std::string_view name, RepairFlag repair) try { - Activity act(*logger, lvlChatty, actUnknown, fmt("copying '%s' to the store", path)); + auto act = logger->startActivity(lvlChatty, actUnknown, fmt("copying '%s' to the store", path)); auto physicalPath = path.canonical().abs(); co_return settings.readOnlyMode @@ -26,8 +26,8 @@ kj::Promise> fetchToStoreRecursive( std::string_view name, RepairFlag repair) try { - Activity act( - *logger, lvlChatty, actUnknown, fmt("copying '%s' to the store", contents.rootPath) + auto act = logger->startActivity( + lvlChatty, actUnknown, fmt("copying '%s' to the store", contents.rootPath) ); co_return settings.readOnlyMode diff --git a/lix/libfetchers/git.cc b/lix/libfetchers/git.cc index 0c694187b..f8de4c37a 100644 --- a/lix/libfetchers/git.cc +++ b/lix/libfetchers/git.cc @@ -758,7 +758,9 @@ struct GitInputScheme : InputScheme // Because git needs to figure out what we're fetching // (i.e. is it a rev? a branch? a tag?) if (doFetch) { - Activity act(*logger, lvlTalkative, actUnknown, fmt("fetching Git repository '%s'", actualUrl)); + auto act = logger->startActivity( + lvlTalkative, actUnknown, fmt("fetching Git repository '%s'", actualUrl) + ); auto ref = input.getRef(); std::string fetchRef; @@ -893,7 +895,9 @@ struct GitInputScheme : InputScheme // TODO: repoDir might lack the ref (it only checks if rev // exists, see FIXME above) so use a big hammer and fetch // everything to ensure we get the rev. - Activity act(*logger, lvlTalkative, actUnknown, fmt("making temporary clone of '%s'", repoDir)); + auto act = logger->startActivity( + lvlTalkative, actUnknown, fmt("making temporary clone of '%s'", repoDir) + ); TRY_AWAIT(runProgram( "git", true, @@ -932,13 +936,17 @@ struct GitInputScheme : InputScheme source repo if it exists. */ auto modulesPath = repoDir + "/" + gitDir + "/modules"; if (pathExists(modulesPath)) { - Activity act(*logger, lvlTalkative, actUnknown, fmt("copying submodules of '%s'", actualUrl)); + auto act = logger->startActivity( + lvlTalkative, actUnknown, fmt("copying submodules of '%s'", actualUrl) + ); TRY_AWAIT(runProgram("cp", true, {"-R", "--", modulesPath, tmpGitDir + "/modules"}) ); } { - Activity act(*logger, lvlTalkative, actUnknown, fmt("fetching submodules of '%s'", actualUrl)); + auto act = logger->startActivity( + lvlTalkative, actUnknown, fmt("fetching submodules of '%s'", actualUrl) + ); TRY_AWAIT(runProgram( "git", true, diff --git a/lix/libfetchers/mercurial.cc b/lix/libfetchers/mercurial.cc index 5472c1639..96d256145 100644 --- a/lix/libfetchers/mercurial.cc +++ b/lix/libfetchers/mercurial.cc @@ -307,7 +307,9 @@ struct MercurialInputScheme : InputScheme .second == "1")) { - Activity act(*logger, lvlTalkative, actUnknown, fmt("fetching Mercurial repository '%s'", actualUrl)); + auto act = logger->startActivity( + lvlTalkative, actUnknown, fmt("fetching Mercurial repository '%s'", actualUrl) + ); if (pathExists(cacheDir)) { try { diff --git a/lix/libfetchers/path.cc b/lix/libfetchers/path.cc index ce1b9f01f..ea07c76cf 100644 --- a/lix/libfetchers/path.cc +++ b/lix/libfetchers/path.cc @@ -131,7 +131,7 @@ struct PathInputScheme : InputScheme } else absPath = path; - Activity act(*logger, lvlTalkative, actUnknown, fmt("copying '%s'", absPath)); + auto act = logger->startActivity(lvlTalkative, actUnknown, fmt("copying '%s'", absPath)); // FIXME: check whether access to 'path' is allowed. auto storePath = store->maybeParseStorePath(absPath); diff --git a/lix/libmain/progress-bar.cc b/lix/libmain/progress-bar.cc index 4e68977fe..841b8b24b 100644 --- a/lix/libmain/progress-bar.cc +++ b/lix/libmain/progress-bar.cc @@ -128,7 +128,7 @@ void ProgressBar::log(State & state, Verbosity lvl, std::string_view s) restoreProgressDisplay(state); } -void ProgressBar::startActivity( +void ProgressBar::startActivityImpl( ActivityId act, Verbosity lvl, ActivityType type, @@ -213,7 +213,7 @@ bool ProgressBar::hasAncestor(State & state, ActivityType type, ActivityId act) return false; } -void ProgressBar::stopActivity(ActivityId act) +void ProgressBar::stopActivityImpl(ActivityId act) { auto state(state_.lock()); @@ -235,7 +235,7 @@ void ProgressBar::stopActivity(ActivityId act) update(*state); } -void ProgressBar::result(ActivityId act, ResultType type, const std::vector & fields) +void ProgressBar::resultImpl(ActivityId act, ResultType type, const std::vector & fields) { auto state(state_.lock()); diff --git a/lix/libmain/progress-bar.hh b/lix/libmain/progress-bar.hh index bbda5b741..0fc6f005e 100644 --- a/lix/libmain/progress-bar.hh +++ b/lix/libmain/progress-bar.hh @@ -81,7 +81,7 @@ struct ProgressBar : public Logger void log(State & state, Verbosity lvl, std::string_view s); - void startActivity( + void startActivityImpl( ActivityId act, Verbosity lvl, ActivityType type, @@ -92,9 +92,9 @@ struct ProgressBar : public Logger bool hasAncestor(State & state, ActivityType type, ActivityId act); - void stopActivity(ActivityId act) override; + void stopActivityImpl(ActivityId act) override; - void result(ActivityId act, ResultType type, const std::vector & fields) override; + void resultImpl(ActivityId act, ResultType type, const std::vector & fields) override; void update(State & state); diff --git a/lix/libstore/binary-cache-store.cc b/lix/libstore/binary-cache-store.cc index 11dcdf004..51c5a26b2 100644 --- a/lix/libstore/binary-cache-store.cc +++ b/lix/libstore/binary-cache-store.cc @@ -463,8 +463,7 @@ BinaryCacheStore::queryPathInfoUncached(const StorePath & storePath, const Activ try { auto uri = getUri(); auto storePathS = printStorePath(storePath); - auto act = std::make_shared( - *logger, + auto act = logger->startActivity( lvlTalkative, actQueryPathInfo, fmt("querying info about '%s' on '%s'", storePathS, uri), @@ -474,7 +473,7 @@ try { auto narInfoFile = narInfoFileFor(storePath); - auto data = TRY_AWAIT(getFileContents(narInfoFile, act.get())); + auto data = TRY_AWAIT(getFileContents(narInfoFile, &act)); if (!data) co_return result::success(nullptr); diff --git a/lix/libstore/build/derivation-goal.cc b/lix/libstore/build/derivation-goal.cc index 10f1d566e..41f068a24 100644 --- a/lix/libstore/build/derivation-goal.cc +++ b/lix/libstore/build/derivation-goal.cc @@ -616,8 +616,12 @@ void DerivationGoal::started() "building '%s'", worker.store.printStorePath(drvPath)); fmt("building '%s'", worker.store.printStorePath(drvPath)); if (hook) msg += fmt(" on '%s'", machineName); - act = std::make_unique(*logger, lvlInfo, actBuild, msg, - Logger::Fields{worker.store.printStorePath(drvPath), hook ? machineName : "", 1, 1}); + act = logger->startActivity( + lvlInfo, + actBuild, + msg, + Logger::Fields{worker.store.printStorePath(drvPath), hook ? machineName : "", 1, 1} + ); mcRunningBuilds = worker.runningBuilds.addTemporarily(1); } @@ -649,8 +653,11 @@ retry: outputLocks = tryLockPaths(lockFiles); if (!outputLocks) { if (!actLock) - actLock = std::make_unique(*logger, lvlWarn, actBuildWaiting, - fmt("waiting for lock on %s", Magenta(showPaths(lockFiles)))); + actLock = logger->startActivity( + lvlWarn, + actBuildWaiting, + fmt("waiting for lock on %s", Magenta(showPaths(lockFiles))) + ); co_await waitForAWhile(); // we can loop very often, and `co_return co_await` always allocates a new frame goto retry; @@ -706,8 +713,12 @@ retry: /* Not now; wait until at least one child finishes or the wake-up timeout expires. */ if (!actLock) - actLock = std::make_unique(*logger, lvlTalkative, actBuildWaiting, - fmt("waiting for a machine to build '%s'", Magenta(worker.store.printStorePath(drvPath)))); + actLock = logger->startActivity( + lvlTalkative, + actBuildWaiting, + fmt("waiting for a machine to build '%s'", + Magenta(worker.store.printStorePath(drvPath))) + ); outputLocks.reset(); co_await waitForAWhile(); goto retry; @@ -842,8 +853,7 @@ try { co_return result::success(); } - Activity act( - logger, + auto act = logger.startActivity( lvlTalkative, actPostBuildHook, fmt("running post-build-hook '%s'", settings.postBuildHook), diff --git a/lix/libstore/build/derivation-goal.hh b/lix/libstore/build/derivation-goal.hh index dba8c0ce7..3389a0f1a 100644 --- a/lix/libstore/build/derivation-goal.hh +++ b/lix/libstore/build/derivation-goal.hh @@ -227,12 +227,12 @@ struct DerivationGoal : public Goal NotifyingCounter::Bump mcExpectedBuilds, mcRunningBuilds; - std::unique_ptr act; + std::optional act; /** * Activity that denotes waiting for a lock. */ - std::unique_ptr actLock; + std::optional actLock; std::map builderActivities; diff --git a/lix/libstore/build/local-derivation-goal.cc b/lix/libstore/build/local-derivation-goal.cc index c330b12b1..6fa1c33d1 100644 --- a/lix/libstore/build/local-derivation-goal.cc +++ b/lix/libstore/build/local-derivation-goal.cc @@ -240,8 +240,12 @@ retry: if (!buildUser) { if (!actLock) - actLock = std::make_unique(*logger, lvlWarn, actBuildWaiting, - fmt("waiting for a free build user ID for '%s'", Magenta(worker.store.printStorePath(drvPath)))); + actLock = logger->startActivity( + lvlWarn, + actBuildWaiting, + fmt("waiting for a free build user ID for '%s'", + Magenta(worker.store.printStorePath(drvPath))) + ); co_await waitForAWhile(); // we can loop very often, and `co_return co_await` always allocates a new frame goto retry; diff --git a/lix/libstore/build/substitution-goal.cc b/lix/libstore/build/substitution-goal.cc index 8b177d795..c35c3712c 100644 --- a/lix/libstore/build/substitution-goal.cc +++ b/lix/libstore/build/substitution-goal.cc @@ -223,10 +223,8 @@ try { try { ReceiveInterrupts receiveInterrupts; - Activity act( - *logger, - actSubstitute, - Logger::Fields{worker.store.printStorePath(storePath), sub->getUri()} + auto act = logger->startActivity( + actSubstitute, Logger::Fields{worker.store.printStorePath(storePath), sub->getUri()} ); aio.blockOn(copyStorePath( diff --git a/lix/libstore/build/worker.cc b/lix/libstore/build/worker.cc index 9dc6650af..d7323ba02 100644 --- a/lix/libstore/build/worker.cc +++ b/lix/libstore/build/worker.cc @@ -25,13 +25,13 @@ struct ErrorHandler : kj::TaskSet::ErrorHandler } Worker::Worker(Store & store, Store & evalStore) - : act(*logger, actRealise) - , actDerivations(*logger, actBuilds) - , actSubstitutions(*logger, actCopyPaths) + : act(logger->startActivity(actRealise)) + , actDerivations(logger->startActivity(actBuilds)) + , actSubstitutions(logger->startActivity(actCopyPaths)) , store(store) , evalStore(evalStore) - /* Make sure that we are always allowed to run at least one substitution. - This prevents infinite waiting. */ + /* Make sure that we are always allowed to run at least one substitution. + This prevents infinite waiting. */ , substitutions(std::max(1, settings.maxSubstitutionJobs)) , localBuilds(settings.maxBuildJobs) , children(errorHandler) diff --git a/lix/libstore/daemon.cc b/lix/libstore/daemon.cc index f1a6eab97..75e156a77 100644 --- a/lix/libstore/daemon.cc +++ b/lix/libstore/daemon.cc @@ -134,22 +134,28 @@ struct TunnelLogger : public Logger } } - void startActivity(ActivityId act, Verbosity lvl, ActivityType type, - const std::string & s, const Fields & fields, ActivityId parent) override + void startActivityImpl( + ActivityId act, + Verbosity lvl, + ActivityType type, + const std::string & s, + const Fields & fields, + ActivityId parent + ) override { StringSink buf; buf << STDERR_START_ACTIVITY << act << lvl << type << s << fields << parent; enqueueMsg(buf.s); } - void stopActivity(ActivityId act) override + void stopActivityImpl(ActivityId act) override { StringSink buf; buf << STDERR_STOP_ACTIVITY << act; enqueueMsg(buf.s); } - void result(ActivityId act, ResultType type, const Fields & fields) override + void resultImpl(ActivityId act, ResultType type, const Fields & fields) override { StringSink buf; buf << STDERR_RESULT << act << type << fields; diff --git a/lix/libstore/filetransfer.cc b/lix/libstore/filetransfer.cc index 44edfd09a..a8087b1da 100644 --- a/lix/libstore/filetransfer.cc +++ b/lix/libstore/filetransfer.cc @@ -150,12 +150,13 @@ struct curlFileTransfer : public FileTransfer const std::chrono::milliseconds & connectTimeout ) : uri(uri) - , act(*logger, + , act(logger->startActivity( lvlTalkative, actFileTransfer, fmt(uploadData ? "uploading '%s'" : "downloading '%s'", uri), {uri}, - parentAct) + parentAct + )) , metadataPromise(std::move(metadataPromise)) , req(curl_easy_init()) { diff --git a/lix/libstore/misc.cc b/lix/libstore/misc.cc index 9e899a3af..5f52e56a6 100644 --- a/lix/libstore/misc.cc +++ b/lix/libstore/misc.cc @@ -313,7 +313,7 @@ kj::Promise> Store::queryMissing(const std::vector & t StorePathSet & willBuild_, StorePathSet & willSubstitute_, StorePathSet & unknown_, uint64_t & downloadSize_, uint64_t & narSize_) try { - Activity act(*logger, lvlDebug, actUnknown, "querying info about missing paths"); + auto act = logger->startActivity(lvlDebug, actUnknown, "querying info about missing paths"); downloadSize_ = narSize_ = 0; diff --git a/lix/libstore/optimise-store.cc b/lix/libstore/optimise-store.cc index ee3ee2819..49c34a1f7 100644 --- a/lix/libstore/optimise-store.cc +++ b/lix/libstore/optimise-store.cc @@ -267,7 +267,7 @@ void LocalStore::optimisePath_(Activity * act, OptimiseStats & stats, kj::Promise> LocalStore::optimiseStore(OptimiseStats & stats) try { - Activity act(*logger, actOptimiseStore); + auto act = logger->startActivity(actOptimiseStore); auto paths = TRY_AWAIT(queryAllValidPaths()); InodeHash inodeHash = loadInodeHash(); @@ -280,7 +280,9 @@ try { TRY_AWAIT(addTempRoot(i)); if (!TRY_AWAIT(isValidPath(i))) continue; /* path was GC'ed, probably */ { - Activity act(*logger, lvlTalkative, actUnknown, fmt("optimising path '%s'", printStorePath(i))); + auto act = logger->startActivity( + lvlTalkative, actUnknown, fmt("optimising path '%s'", printStorePath(i)) + ); optimisePath_( &act, stats, diff --git a/lix/libstore/remote-store.cc b/lix/libstore/remote-store.cc index d72c38b8a..e9aa951f7 100644 --- a/lix/libstore/remote-store.cc +++ b/lix/libstore/remote-store.cc @@ -809,7 +809,7 @@ try { } return parent; }(); - remoteActivities.emplace(act, Activity(*logger, lvl, type, s, fields, parent)); + remoteActivities.emplace(act, logger->startActivity(lvl, type, s, fields, parent)); } else if (msg == STDERR_STOP_ACTIVITY) { auto act = TRY_AWAIT(readNum(from)); if (remoteActivities.erase(act) == 0) { diff --git a/lix/libstore/store-api.cc b/lix/libstore/store-api.cc index 5dc515292..e776fc8d2 100644 --- a/lix/libstore/store-api.cc +++ b/lix/libstore/store-api.cc @@ -1034,8 +1034,7 @@ try { auto srcUri = srcStore.getUri(); auto dstUri = dstStore.getUri(); auto storePathS = srcStore.printStorePath(storePath); - Activity act( - *logger, + auto act = logger->startActivity( lvlInfo, actCopyPath, makeCopyPathMessage(srcUri, dstUri, storePathS), @@ -1104,7 +1103,8 @@ try { for (auto & path : storePaths) if (!valid.count(path)) missing.insert(path); - Activity act(*logger, lvlInfo, actCopyPaths, fmt("copying %d paths", missing.size())); + auto act = + logger->startActivity(lvlInfo, actCopyPaths, fmt("copying %d paths", missing.size())); // In the general case, `addMultipleToStore` requires a sorted list of // store paths to add, so sort them right now @@ -1167,13 +1167,12 @@ try { auto srcUri = srcStore.getUri(); auto dstUri = dstStore.getUri(); auto storePathS = srcStore.printStorePath(missingPath); - auto act = std::make_shared( - *logger, + auto act = std::make_shared(logger->startActivity( lvlInfo, actCopyPath, makeCopyPathMessage(srcUri, dstUri, storePathS), Logger::Fields{storePathS, srcUri, dstUri} - ); + )); co_return make_box_ptr( act, info->narSize, TRY_AWAIT(srcStore.narFromPath(missingPath, act.get())) diff --git a/lix/libutil/logging.cc b/lix/libutil/logging.cc index fab6fed69..c451b52b1 100644 --- a/lix/libutil/logging.cc +++ b/lix/libutil/logging.cc @@ -22,6 +22,24 @@ static GlobalConfig::Register rLoggerSettings(&loggerSettings); Logger * logger = makeSimpleLogger(true); +Activity Logger::startActivity( + Verbosity lvl, + ActivityType type, + const std::string & s, + const Fields & fields, + const Activity * parent +) +{ + Activity result{*this}; + startActivityImpl(result.id, lvl, type, s, fields, parent ? parent->id : 0); + return result; +} + +Activity Logger::startActivity(ActivityType type, const Fields & fields, const Activity * parent) +{ + return startActivity(lvlError, type, "", fields, parent); +} + void Logger::writeToStdout(std::string_view s) { writeFull( @@ -84,15 +102,20 @@ public: log(ei.level, oss.str()); } - void startActivity(ActivityId act, Verbosity lvl, ActivityType type, - const std::string & s, const Fields & fields, ActivityId parent) - override + void startActivityImpl( + ActivityId act, + Verbosity lvl, + ActivityType type, + const std::string & s, + const Fields & fields, + ActivityId parent + ) override { if (lvl <= verbosity && !s.empty()) log(lvl, s + "..."); } - void result(ActivityId act, ResultType type, const Fields & fields) override + void resultImpl(ActivityId act, ResultType type, const Fields & fields) override { if (type == resBuildLogLine && printBuildLogs) { auto lastLine = fields[0].s; @@ -120,18 +143,8 @@ Logger * makeSimpleLogger(bool printBuildLogs) std::atomic nextId{0}; -Activity::Activity( - Logger & logger, - Verbosity lvl, - ActivityType type, - const std::string & s, - const Logger::Fields & fields, - const Activity * parent -) - : logger(&logger) - , id(nextId++ + (((uint64_t) getpid()) << 32)) +Activity::Activity(Logger & logger) : logger(&logger), id(nextId++ + (((uint64_t) getpid()) << 32)) { - logger.startActivity(id, lvl, type, s, fields, parent ? parent->id : 0); } void to_json(JSON & json, std::shared_ptr pos) @@ -212,8 +225,14 @@ struct JSONLogger : Logger { write(json); } - void startActivity(ActivityId act, Verbosity lvl, ActivityType type, - const std::string & s, const Fields & fields, ActivityId parent) override + void startActivityImpl( + ActivityId act, + Verbosity lvl, + ActivityType type, + const std::string & s, + const Fields & fields, + ActivityId parent + ) override { JSON json; json["action"] = "start"; @@ -226,7 +245,7 @@ struct JSONLogger : Logger { write(json); } - void stopActivity(ActivityId act) override + void stopActivityImpl(ActivityId act) override { JSON json; json["action"] = "stop"; @@ -234,7 +253,7 @@ struct JSONLogger : Logger { write(json); } - void result(ActivityId act, ResultType type, const Fields & fields) override + void resultImpl(ActivityId act, ResultType type, const Fields & fields) override { JSON json; json["action"] = "result"; @@ -287,15 +306,9 @@ bool handleJSONLogMessage(JSON & json, auto type = (ActivityType) json["type"]; if (trusted || type == actFileTransfer) activities.emplace( - std::piecewise_construct, - std::forward_as_tuple(json["id"]), - std::forward_as_tuple( - *logger, - (Verbosity) json["level"], - type, - json["text"], - getFields(json["fields"]), - &act + json["id"], + act.addChild( + (Verbosity) json["level"], type, json["text"], getFields(json["fields"]) ) ); } @@ -343,7 +356,7 @@ Activity::~Activity() return; } try { - logger->stopActivity(id); + logger->stopActivityImpl(id); } catch (...) { ignoreExceptionInDestructor(); } diff --git a/lix/libutil/logging.hh b/lix/libutil/logging.hh index d8d347d2b..e2c2e496e 100644 --- a/lix/libutil/logging.hh +++ b/lix/libutil/logging.hh @@ -97,9 +97,11 @@ struct LoggerSettings : Config extern LoggerSettings loggerSettings; +class Activity; + class Logger { - friend struct Activity; + friend class Activity; public: @@ -135,13 +137,32 @@ public: logEI(ei); } - virtual void startActivity(ActivityId act, Verbosity lvl, ActivityType type, - const std::string & s, const Fields & fields, ActivityId parent) { }; + Activity startActivity( + Verbosity lvl, + ActivityType type, + const std::string & s, + const Fields & fields = {}, + const Activity * parent = nullptr + ); - virtual void stopActivity(ActivityId act) { }; + Activity + startActivity(ActivityType type, const Fields & fields = {}, const Activity * parent = nullptr); - virtual void result(ActivityId act, ResultType type, const Fields & fields) { }; +protected: + virtual void startActivityImpl( + ActivityId act, + Verbosity lvl, + ActivityType type, + const std::string & s, + const Fields & fields, + ActivityId parent + ) {}; + virtual void stopActivityImpl(ActivityId act) {}; + + virtual void resultImpl(ActivityId act, ResultType type, const Fields & fields) {}; + +public: virtual void writeToStdout(std::string_view s); template @@ -171,31 +192,14 @@ struct nop { } }; -struct Activity +class Activity { -private: Logger * logger; - ActivityId id; + explicit Activity(Logger & logger); + public: - Activity( - Logger & logger, - Verbosity lvl, - ActivityType type, - const std::string & s = "", - const Logger::Fields & fields = {}, - const Activity * parent = nullptr - ); - - Activity( - Logger & logger, - ActivityType type, - const Logger::Fields & fields = {}, - const Activity * parent = nullptr - ) - : Activity(logger, lvlError, type, "", fields, parent) {}; - Activity(Activity && other) : logger(nullptr), id(0) { swap(other); @@ -218,6 +222,16 @@ public: std::swap(id, other.id); } + Activity addChild( + Verbosity level, + ActivityType type, + const std::string & s = "", + const Logger::Fields & fields = {} + ) const + { + return logger->startActivity(level, type, s, fields, this); + } + void progress(uint64_t done = 0, uint64_t expected = 0, uint64_t running = 0, uint64_t failed = 0) const { result(resProgress, done, expected, running, failed); } @@ -234,7 +248,7 @@ public: void result(ResultType type, const Logger::Fields & fields) const { - logger->result(id, type, fields); + logger->resultImpl(id, type, fields); } friend class Logger; diff --git a/lix/nix/flake.cc b/lix/nix/flake.cc index 3e9a9c846..757d22258 100644 --- a/lix/nix/flake.cc +++ b/lix/nix/flake.cc @@ -417,8 +417,9 @@ struct CmdFlakeCheck : FlakeCommand auto checkDerivation = [&](const std::string & attrPath, Value & v, const PosIdx pos) -> std::optional { try { - Activity act(*logger, lvlInfo, actUnknown, - fmt("checking derivation %s", attrPath)); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("checking derivation %s", attrPath) + ); auto drvInfo = getDerivation(*state, v, false); if (!drvInfo) throw Error("flake attribute '%s' is not a derivation", attrPath); @@ -459,8 +460,9 @@ struct CmdFlakeCheck : FlakeCommand auto checkOverlay = [&](const std::string_view attrPath, Value & v, const PosIdx pos) { try { - Activity act(*logger, lvlInfo, actUnknown, - fmt("checking overlay '%s'", attrPath)); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("checking overlay '%s'", attrPath) + ); state->forceValue(v, pos); if (!v.isLambda()) { throw Error("overlay is not a function, but %s instead", showType(v)); @@ -480,8 +482,9 @@ struct CmdFlakeCheck : FlakeCommand auto checkModule = [&](const std::string_view attrPath, Value & v, const PosIdx pos) { try { - Activity act(*logger, lvlInfo, actUnknown, - fmt("checking NixOS module '%s'", attrPath)); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("checking NixOS module '%s'", attrPath) + ); state->forceValue(v, pos); } catch (Error & e) { e.addTrace(resolve(pos), HintFmt("while checking the NixOS module '%s'", attrPath)); @@ -494,8 +497,9 @@ struct CmdFlakeCheck : FlakeCommand checkHydraJobs = [&](const std::string_view attrPath, Value & v, const PosIdx pos) { try { - Activity act(*logger, lvlInfo, actUnknown, - fmt("checking Hydra job '%s'", attrPath)); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("checking Hydra job '%s'", attrPath) + ); state->forceAttrs(v, pos, ""); if (state->isDerivation(v)) @@ -505,8 +509,9 @@ struct CmdFlakeCheck : FlakeCommand state->forceAttrs(attr.value, attr.pos, ""); auto attrPath2 = concatStrings(attrPath, ".", evaluator->symbols[attr.name]); if (state->isDerivation(attr.value)) { - Activity act(*logger, lvlInfo, actUnknown, - fmt("checking Hydra job '%s'", attrPath2)); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("checking Hydra job '%s'", attrPath2) + ); checkDerivation(attrPath2, attr.value, attr.pos); } else { checkHydraJobs(attrPath2, attr.value, attr.pos); @@ -521,8 +526,9 @@ struct CmdFlakeCheck : FlakeCommand auto checkNixOSConfiguration = [&](const std::string & attrPath, Value & v, const PosIdx pos) { try { - Activity act(*logger, lvlInfo, actUnknown, - fmt("checking NixOS configuration '%s'", attrPath)); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("checking NixOS configuration '%s'", attrPath) + ); Bindings & bindings(*evaluator->mem.allocBindings(0)); auto vToplevel = findAlongAttrPath(*state, "config.system.build.toplevel", bindings, v).first; state->forceValue(vToplevel, pos); @@ -537,8 +543,9 @@ struct CmdFlakeCheck : FlakeCommand auto checkTemplate = [&](const std::string_view attrPath, Value & v, const PosIdx pos) { try { - Activity act(*logger, lvlInfo, actUnknown, - fmt("checking template '%s'", attrPath)); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("checking template '%s'", attrPath) + ); state->forceAttrs(v, pos, ""); @@ -573,8 +580,9 @@ struct CmdFlakeCheck : FlakeCommand auto checkBundler = [&](const std::string & attrPath, Value & v, const PosIdx pos) { try { - Activity act(*logger, lvlInfo, actUnknown, - fmt("checking bundler '%s'", attrPath)); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("checking bundler '%s'", attrPath) + ); state->forceValue(v, pos); if (!v.isLambda()) throw Error("bundler must be a function"); @@ -586,7 +594,7 @@ struct CmdFlakeCheck : FlakeCommand }; { - Activity act(*logger, lvlInfo, actUnknown, "evaluating flake"); + auto act = logger->startActivity(lvlInfo, actUnknown, "evaluating flake"); Value vFlake; flake::callFlake(*state, flake, vFlake); @@ -595,8 +603,9 @@ struct CmdFlakeCheck : FlakeCommand *state, vFlake, [&](const std::string_view name, Value & vOutput, const PosIdx pos) { - Activity act(*logger, lvlInfo, actUnknown, - fmt("checking flake output '%s'", name)); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("checking flake output '%s'", name) + ); try { evalSettings.enableImportFromDerivation.setDefault(name != "hydraJobs"); @@ -857,8 +866,9 @@ struct CmdFlakeCheck : FlakeCommand } if (build && !drvPaths.empty()) { - Activity act(*logger, lvlInfo, actUnknown, - fmt("running %d flake checks", drvPaths.size())); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("running %d flake checks", drvPaths.size()) + ); aio().blockOn(store->buildPaths(drvPaths)); } if (hasErrors) @@ -1273,8 +1283,9 @@ struct CmdFlakeShow : FlakeCommand, MixJSON { auto j = JSON::object(); - Activity act(*logger, lvlInfo, actUnknown, - fmt("evaluating '%s'", concatStringsSep(".", attrPath))); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("evaluating '%s'", concatStringsSep(".", attrPath)) + ); try { auto recurse = [&](NeverAsync = {}) diff --git a/lix/nix/prefetch.cc b/lix/nix/prefetch.cc index 40a37a40d..af8016fe5 100644 --- a/lix/nix/prefetch.cc +++ b/lix/nix/prefetch.cc @@ -110,8 +110,7 @@ std::tuple prefetchFile( /* Optionally unpack the file. */ if (unpack) { - Activity act(*logger, lvlChatty, actUnknown, - fmt("unpacking '%s'", url)); + auto act = logger->startActivity(lvlChatty, actUnknown, fmt("unpacking '%s'", url)); Path unpacked = (Path) tmpDir + "/unpacked"; createDirs(unpacked); unpackTarfile(tmpFile, unpacked); @@ -125,8 +124,8 @@ std::tuple prefetchFile( tmpFile = unpacked; } - Activity act(*logger, lvlChatty, actUnknown, - fmt("adding '%s' to the store", url)); + auto act = + logger->startActivity(lvlChatty, actUnknown, fmt("adding '%s' to the store", url)); auto info = aio.blockOn( store->addToStoreSlow(*name, tmpFile, ingestionMethod, hashType, expectedHash) diff --git a/lix/nix/profile.cc b/lix/nix/profile.cc index cb4798686..cbfdb5cb3 100644 --- a/lix/nix/profile.cc +++ b/lix/nix/profile.cc @@ -329,8 +329,7 @@ struct CmdProfileUpgrade : virtual SourceExprCommand, MixDefaultProfile, MixProf upgradedCount++; - Activity act( - *logger, + auto act = logger->startActivity( lvlChatty, actUnknown, fmt("checking '%s' for updates", element.source->attrPath), diff --git a/lix/nix/search.cc b/lix/nix/search.cc index f76ba2638..f872e043c 100644 --- a/lix/nix/search.cc +++ b/lix/nix/search.cc @@ -95,10 +95,12 @@ struct CmdSearch : InstallableCommand, MixJSON std::function & attrPath, bool initialRecurse)> visit; - visit = [&](eval_cache::AttrCursor & cursor, const std::vector & attrPath, bool initialRecurse) - { - Activity act(*logger, lvlInfo, actUnknown, - fmt("evaluating '%s'", concatStringsSep(".", attrPath))); + visit = [&](eval_cache::AttrCursor & cursor, + const std::vector & attrPath, + bool initialRecurse) { + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("evaluating '%s'", concatStringsSep(".", attrPath)) + ); try { auto recurse = [&]() { diff --git a/lix/nix/upgrade-nix.cc b/lix/nix/upgrade-nix.cc index 2e96efe26..5d2066b4c 100644 --- a/lix/nix/upgrade-nix.cc +++ b/lix/nix/upgrade-nix.cc @@ -94,7 +94,9 @@ struct CmdUpgradeNix : MixDryRun, EvalCommand } { - Activity act(*logger, lvlInfo, actUnknown, fmt("downloading '%s'...", store->printStorePath(storePath))); + auto act = logger->startActivity( + lvlInfo, actUnknown, fmt("downloading '%s'...", store->printStorePath(storePath)) + ); aio().blockOn(store->ensurePath(storePath)); } @@ -107,7 +109,11 @@ struct CmdUpgradeNix : MixDryRun, EvalCommand Path const newNixEnv = store->printStorePath(storePath) + "/bin/nix-env"; { - Activity act(*logger, lvlInfo, actUnknown, fmt("verifying that '%s' works...", store->printStorePath(storePath))); + auto act = logger->startActivity( + lvlInfo, + actUnknown, + fmt("verifying that '%s' works...", store->printStorePath(storePath)) + ); auto s = aio().blockOn(runProgram(newNixEnv, false, {"--version"})); if (s.find("Nix") == std::string::npos) throw Error("could not verify that '%s' works", newNixEnv); @@ -284,7 +290,7 @@ struct CmdUpgradeNix : MixDryRun, EvalCommand return store->parseStorePath(*this->overrideStorePath); } - Activity act(*logger, lvlInfo, actUnknown, "querying latest Nix version"); + auto act = logger->startActivity(lvlInfo, actUnknown, "querying latest Nix version"); // FIXME: use nixos.org? auto [res, content] = aio().blockOn(getFileTransfer()->download(storePathsUrl)); diff --git a/lix/nix/verify.cc b/lix/nix/verify.cc index 4e7c10e72..5334be7f8 100644 --- a/lix/nix/verify.cc +++ b/lix/nix/verify.cc @@ -70,7 +70,7 @@ struct CmdVerify : StorePathsCommand auto publicKeys = getDefaultPublicKeys(); - Activity act(*logger, actVerifyPaths); + auto act = logger->startActivity(actVerifyPaths); std::atomic done{0}; std::atomic untrusted{0}; @@ -96,7 +96,9 @@ struct CmdVerify : StorePathsCommand // Note: info->path can be different from storePath // for binary cache stores when using --all (since we // can't enumerate names efficiently). - Activity act2(*logger, lvlInfo, actUnknown, fmt("checking '%s'", store->printStorePath(info->path))); + auto act2 = logger->startActivity( + lvlInfo, actUnknown, fmt("checking '%s'", store->printStorePath(info->path)) + ); if (!noContents) { diff --git a/tests/unit/libmain/progress-bar.cc b/tests/unit/libmain/progress-bar.cc index ae5f912ec..eb4a2acbb 100644 --- a/tests/unit/libmain/progress-bar.cc +++ b/tests/unit/libmain/progress-bar.cc @@ -28,12 +28,11 @@ namespace nix ASSERT_NE(dynamic_cast(logger), nullptr); ProgressBar & progressBar = dynamic_cast(*logger); - Activity act( - progressBar, + auto act = progressBar.startActivity( lvlDebug, actFileTransfer, fmt("downloading '%s'", TEST_URL), - { "https://github.com/NixOS/nixpkgs/archive/master.tar.gz" } + {"https://github.com/NixOS/nixpkgs/archive/master.tar.gz"} ); act.progress(TEST_DONE, TEST_EXPECTED); auto state = progressBar.state_.lock();