From c36467ad2e2e27d04e681144e0e10417c53c10c1 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Mon, 14 Aug 2017 20:14:55 +0200 Subject: [PATCH] Improve substitution progress indicator E.g. $ nix build --store local?root=/tmp/nix nixpkgs.firefox-unwrapped [0/1 built, 1/97/98 fetched, 65.8/92.8 MiB DL, 203.2/309.2 MiB copied] downloading 'https://cache.nixos.org/nar/1czm9fk0svacy4h6a3fzkpafi4f7a9gml36kk8cq1igaghbspg3k.nar.xz' --- src/libstore/build.cc | 55 +++++++++++++++++++- src/libstore/download.cc | 11 ++-- src/libutil/logging.hh | 6 +-- src/nix/installables.cc | 2 +- src/nix/progress-bar.cc | 105 ++++++++++++--------------------------- 5 files changed, 93 insertions(+), 86 deletions(-) diff --git a/src/libstore/build.cc b/src/libstore/build.cc index 9250a9b17..d5f48237b 100644 --- a/src/libstore/build.cc +++ b/src/libstore/build.cc @@ -9,6 +9,7 @@ #include "finally.hh" #include "compression.hh" #include "json.hh" +#include "nar-info.hh" #include #include @@ -201,6 +202,16 @@ struct Child }; +template +struct MaintainCount +{ + T & counter; + T delta; + MaintainCount(T & counter, T delta) : counter(counter), delta(delta) { counter += delta; } + ~MaintainCount() { counter -= delta; } +}; + + /* The worker class. */ class Worker { @@ -244,6 +255,8 @@ private: public: + const Activity act; + /* Set if at least one derivation had a BuildError (i.e. permanent failure). */ bool permanentFailure; @@ -255,6 +268,11 @@ public: std::unique_ptr hook; + uint64_t expectedDownloadSize = 0; + uint64_t doneDownloadSize = 0; + uint64_t expectedNarSize = 0; + uint64_t doneNarSize = 0; + Worker(LocalStore & store); ~Worker(); @@ -313,6 +331,12 @@ public: bool pathContentsGood(const Path & path); void markContentsGood(const Path & path); + + void updateProgress() + { + logger->event(evSetExpected, act, actDownload, expectedDownloadSize + doneDownloadSize); + logger->event(evSetExpected, act, actCopyPath, expectedNarSize + doneNarSize); + } }; @@ -3304,6 +3328,8 @@ private: storePath when doing a repair. */ Path destPath; + std::unique_ptr> maintainExpectedNar, maintainExpectedDownload; + typedef void (SubstitutionGoal::*GoalState)(); GoalState state; @@ -3430,6 +3456,18 @@ void SubstitutionGoal::tryNext() return; } + /* Update the total expected download size. */ + auto narInfo = std::dynamic_pointer_cast(info); + + maintainExpectedNar = std::make_unique>(worker.expectedNarSize, narInfo->narSize); + + maintainExpectedDownload = + narInfo && narInfo->fileSize + ? std::make_unique>(worker.expectedDownloadSize, narInfo->fileSize) + : nullptr; + + worker.updateProgress(); + hasSubstitute = true; /* Bail out early if this substituter lacks a valid @@ -3538,6 +3576,17 @@ void SubstitutionGoal::finished() printMsg(lvlChatty, format("substitution of path '%1%' succeeded") % storePath); + if (maintainExpectedDownload) { + auto fileSize = maintainExpectedDownload->delta; + maintainExpectedDownload.reset(); + worker.doneDownloadSize += fileSize; + } + + worker.doneNarSize += maintainExpectedNar->delta; + maintainExpectedNar.reset(); + + worker.updateProgress(); + amDone(ecSuccess); } @@ -3560,7 +3609,8 @@ static bool working = false; Worker::Worker(LocalStore & store) - : store(store) + : act(actRealise) + , store(store) { /* Debugging: prevent recursive workers. */ if (working) abort(); @@ -3581,6 +3631,9 @@ Worker::~Worker() are in trouble, since goals may call childTerminated() etc. in their destructors). */ topGoals.clear(); + + assert(expectedDownloadSize == 0); + assert(expectedNarSize == 0); } diff --git a/src/libstore/download.cc b/src/libstore/download.cc index b731297a2..9ac4a65d5 100644 --- a/src/libstore/download.cc +++ b/src/libstore/download.cc @@ -83,12 +83,12 @@ struct CurlDownloader : public Downloader std::string encoding; DownloadItem(CurlDownloader & downloader, const DownloadRequest & request) - : downloader(downloader), request(request) + : downloader(downloader) + , request(request) + , act(actDownload, fmt("downloading '%s'", request.uri)) { if (!request.expectedETag.empty()) requestHeaders = curl_slist_append(requestHeaders, ("If-None-Match: " + request.expectedETag).c_str()); - - logger->event(evDownloadCreated, act, request.uri); } ~DownloadItem() @@ -105,7 +105,6 @@ struct CurlDownloader : public Downloader } catch (...) { ignoreException(); } - logger->event(evDownloadDestroyed, act); } template @@ -168,7 +167,7 @@ struct CurlDownloader : public Downloader int progressCallback(double dltotal, double dlnow) { - logger->event(evDownloadProgress, act, dltotal, dlnow); + act.progress(dlnow, dltotal); return _isInterrupted; } @@ -267,7 +266,7 @@ struct CurlDownloader : public Downloader try { result.data = decodeContent(encoding, ref(result.data)); callSuccess(success, failure, const_cast(result)); - logger->event(evDownloadSucceeded, act, result.data->size()); + act.progress(result.data->size(), result.data->size()); } catch (...) { done = true; callFailure(failure, std::current_exception()); diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index 6a4a36171..7633408ea 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -16,6 +16,8 @@ typedef enum { typedef enum { actUnknown = 0, actCopyPath = 100, + actDownload = 101, + actRealise = 102, } ActivityType; class Activity @@ -38,10 +40,6 @@ typedef enum { evBuildStarted = 1, evBuildOutput = 2, evBuildFinished = 3, - evDownloadCreated = 4, - evDownloadDestroyed = 5, - evDownloadProgress = 6, - evDownloadSucceeded = 7, evSubstitutionCreated = 8, evSubstitutionStarted = 9, evSubstitutionFinished = 10, diff --git a/src/nix/installables.cc b/src/nix/installables.cc index 54c9f7841..9d812fee4 100644 --- a/src/nix/installables.cc +++ b/src/nix/installables.cc @@ -229,7 +229,7 @@ std::vector> InstallablesCommand::parseInstallables PathSet InstallablesCommand::toStorePaths(ref store, ToStorePathsMode mode) { - if (mode != DryRun) + if (mode != Build) settings.readOnlyMode = true; PathSet outPaths, buildables; diff --git a/src/nix/progress-bar.cc b/src/nix/progress-bar.cc index b15f4488d..736eb5ede 100644 --- a/src/nix/progress-bar.cc +++ b/src/nix/progress-bar.cc @@ -25,14 +25,6 @@ private: std::map expectedByType; }; - struct DownloadInfo - { - std::string uri; - uint64_t current = 0; - uint64_t expected = 0; - DownloadInfo(const std::string & uri) : uri(uri) { } - }; - struct CopyInfo { uint64_t expected = 0; @@ -58,9 +50,6 @@ private: std::set runningSubstitutions; uint64_t succeededSubstitutions = 0; - uint64_t downloadedBytes = 0; // finished downloads - std::map downloads; - std::map runningCopies; std::list activities; @@ -155,10 +144,16 @@ public: if (!state.activities.empty()) { if (!status.empty()) line += " "; auto i = state.activities.rbegin(); - line += i->s; - if (!i->s2.empty()) { - line += ": "; - line += i->s2; + + while (i != state.activities.rend() && i->s.empty() && i->s2.empty()) + ++i; + + if (i != state.activities.rend()) { + line += i->s; + if (!i->s2.empty()) { + line += ": "; + line += i->s2; + } } } @@ -172,9 +167,13 @@ public: std::string res; - if (state.failedBuilds) { + auto add = [&](const std::string & s) { if (!res.empty()) res += ", "; - res += fmt(ANSI_RED "%d failed" ANSI_NORMAL, state.failedBuilds); + res += s; + }; + + if (state.failedBuilds) { + add(fmt(ANSI_RED "%d failed" ANSI_NORMAL, state.failedBuilds)); } if (!state.builds.empty() || state.succeededBuilds) @@ -195,39 +194,31 @@ public: state.succeededSubstitutions + state.substitutions.size()); } - if (!state.downloads.empty() || state.downloadedBytes) { - if (!res.empty()) res += ", "; - uint64_t expected = state.downloadedBytes, current = state.downloadedBytes; - for (auto & i : state.downloads) { - expected += i.second.expected; - current += i.second.current; - } - res += fmt("%1$.0f/%2$.0f KiB", current / 1024.0, expected / 1024.0); - } - if (!state.runningCopies.empty()) { - if (!res.empty()) res += ", "; uint64_t copied = 0, expected = 0; for (auto & i : state.runningCopies) { copied += i.second.copied; expected += i.second.expected - (i.second.done - i.second.copied); } - res += fmt("%d/%d copied", copied, expected); + add(fmt("%d/%d copied", copied, expected)); } - auto & act = state.activitiesByType[actCopyPath]; - uint64_t done = act.done, expected = act.done; - for (auto & j : act.its) { - done += j.second->done; - expected += j.second->expected; - } + auto showActivity = [&](ActivityType type, const std::string & f) { + auto & act = state.activitiesByType[type]; + uint64_t done = act.done, expected = act.done; + for (auto & j : act.its) { + done += j.second->done; + expected += j.second->expected; + } - expected = std::max(expected, act.expected); + expected = std::max(expected, act.expected); - if (done || expected) { - if (!res.empty()) res += ", "; - res += fmt("%1$.1f/%2$.1f MiB copied", done / MiB, expected / MiB); - } + if (done || expected) + add(fmt(f, done / MiB, expected / MiB)); + }; + + showActivity(actDownload, "%1$.1f/%2$.1f MiB DL"); + showActivity(actCopyPath, "%1$.1f/%2$.1f MiB copied"); return res; } @@ -318,40 +309,6 @@ public: deleteActivity(*state, act); } - if (ev.type == evDownloadCreated) { - Activity::t act = ev.getI(0); - std::string uri = ev.getS(1); - state->downloads.emplace(act, DownloadInfo{uri}); - if (state->runningSubstitutions.empty()) // FIXME: hack - createActivity(*state, act, fmt("downloading " ANSI_BOLD "%s" ANSI_NORMAL "", uri)); - } - - if (ev.type == evDownloadProgress) { - Activity::t act = ev.getI(0); - auto i = state->downloads.find(act); - assert(i != state->downloads.end()); - i->second.expected = ev.getI(1); - i->second.current = ev.getI(2); - } - - if (ev.type == evDownloadSucceeded) { - Activity::t act = ev.getI(0); - auto i = state->downloads.find(act); - assert(i != state->downloads.end()); - state->downloadedBytes += ev.getI(1); - state->downloads.erase(i); - deleteActivity(*state, act); - } - - if (ev.type == evDownloadDestroyed) { - Activity::t act = ev.getI(0); - auto i = state->downloads.find(act); - if (i != state->downloads.end()) { - state->downloads.erase(i); - deleteActivity(*state, act); - } - } - if (ev.type == evCopyProgress) { Activity::t act = ev.getI(0); auto & i = state->runningCopies[act];