From dff12b38f9d836fd0a58abc41286a9ad6b602aa5 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Tue, 15 Aug 2017 15:31:59 +0200 Subject: Progress indicator: More improvements --- src/libstore/build.cc | 56 +++++++++++++++++++++---- src/libutil/logging.hh | 5 +-- src/nix/progress-bar.cc | 109 ++++++++++++++++++++++-------------------------- 3 files changed, 100 insertions(+), 70 deletions(-) (limited to 'src') diff --git a/src/libstore/build.cc b/src/libstore/build.cc index a45ca8923016..257f02a49196 100644 --- a/src/libstore/build.cc +++ b/src/libstore/build.cc @@ -122,8 +122,6 @@ protected: /* Whether the goal is finished. */ ExitCode exitCode; - Activity act; - Goal(Worker & worker) : worker(worker) { nrFailed = nrNoSubstituters = nrIncompleteClosure = 0; @@ -246,6 +244,7 @@ private: public: const Activity act; + const Activity actDerivations; const Activity actSubstitutions; /* Set if at least one derivation had a BuildError (i.e. permanent @@ -259,8 +258,14 @@ public: std::unique_ptr hook; + uint64_t expectedBuilds = 0; + uint64_t doneBuilds = 0; + uint64_t failedBuilds = 0; + uint64_t runningBuilds = 0; + uint64_t expectedSubstitutions = 0; uint64_t doneSubstitutions = 0; + uint64_t failedSubstitutions = 0; uint64_t runningSubstitutions = 0; uint64_t expectedDownloadSize = 0; uint64_t doneDownloadSize = 0; @@ -328,7 +333,8 @@ public: void updateProgress() { - actSubstitutions.progress(doneSubstitutions, expectedSubstitutions + doneSubstitutions, runningSubstitutions); + actDerivations.progress(doneBuilds, expectedBuilds + doneBuilds, runningBuilds, failedBuilds); + actSubstitutions.progress(doneSubstitutions, expectedSubstitutions + doneSubstitutions, runningSubstitutions, failedSubstitutions); logger->event(evSetExpected, act, actDownload, expectedDownloadSize + doneDownloadSize); logger->event(evSetExpected, act, actCopyPath, expectedNarSize + doneNarSize); } @@ -829,6 +835,10 @@ private: const static Path homeDir; + std::unique_ptr> mcExpectedBuilds, mcRunningBuilds; + + std::unique_ptr act; + public: DerivationGoal(const Path & drvPath, const StringSet & wantedOutputs, Worker & worker, BuildMode buildMode = bmNormal); @@ -926,7 +936,6 @@ private: void amDone(ExitCode result) override { - logger->event(evBuildFinished, act, result == ecSuccess); Goal::amDone(result); } @@ -949,7 +958,8 @@ DerivationGoal::DerivationGoal(const Path & drvPath, const StringSet & wantedOut name = (format("building of '%1%'") % drvPath).str(); trace("created"); - logger->event(evBuildCreated, act, drvPath); + mcExpectedBuilds = std::make_unique>(worker.expectedBuilds); + worker.updateProgress(); } @@ -965,7 +975,8 @@ DerivationGoal::DerivationGoal(const Path & drvPath, const BasicDerivation & drv name = (format("building of %1%") % showPaths(drv.outputPaths())).str(); trace("created"); - logger->event(evBuildCreated, act, drvPath); + mcExpectedBuilds = std::make_unique>(worker.expectedBuilds); + worker.updateProgress(); /* Prevent the .chroot directory from being garbage-collected. (See isActiveTempFile() in gc.cc.) */ @@ -1374,6 +1385,12 @@ void DerivationGoal::tryToBuild() supported for local builds. */ bool buildLocally = buildMode != bmNormal || drv->willBuildLocally(); + auto started = [&]() { + act = std::make_unique(actBuild, fmt("building '%s'", drvPath)); + mcRunningBuilds = std::make_unique>(worker.runningBuilds); + worker.updateProgress(); + }; + /* Is the build hook willing to accept this job? */ if (!buildLocally) { switch (tryBuildHook()) { @@ -1382,6 +1399,7 @@ void DerivationGoal::tryToBuild() EOF from the hook. */ result.startTime = time(0); // inexact state = &DerivationGoal::buildDone; + started(); return; case rpPostpone: /* Not now; wait until at least one child finishes or @@ -1422,6 +1440,8 @@ void DerivationGoal::tryToBuild() /* This state will be reached when we get EOF on the child's log pipe. */ state = &DerivationGoal::buildDone; + + started(); } @@ -2147,8 +2167,6 @@ void DerivationGoal::startBuilder() } debug(msg); } - - logger->event(evBuildStarted, act); } @@ -3239,7 +3257,7 @@ void DerivationGoal::flushLine() logTail.push_back(currentLogLine); if (logTail.size() > settings.logLines) logTail.pop_front(); } - logger->event(evBuildOutput, act, currentLogLine); + logger->event(evBuildOutput, *act, currentLogLine); currentLogLine = ""; currentLogLinePos = 0; } @@ -3282,6 +3300,19 @@ void DerivationGoal::done(BuildResult::Status status, const string & msg) worker.timedOut = true; if (result.status == BuildResult::PermanentFailure) worker.permanentFailure = true; + + mcExpectedBuilds.reset(); + mcRunningBuilds.reset(); + + if (result.success()) { + if (status == BuildResult::Built) + worker.doneBuilds++; + } else { + if (status != BuildResult::DependencyFailed) + worker.failedBuilds++; + } + + worker.updateProgress(); } @@ -3432,6 +3463,12 @@ void SubstitutionGoal::tryNext() In that case the calling derivation should just do a build. */ amDone(hasSubstitute ? ecFailed : ecNoSubstituters); + + if (hasSubstitute) { + worker.failedSubstitutions++; + worker.updateProgress(); + } + return; } @@ -3611,6 +3648,7 @@ static bool working = false; Worker::Worker(LocalStore & store) : act(actRealise) + , actDerivations(actBuilds) , actSubstitutions(actCopyPaths) , store(store) { diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index b6ab3d7d3b8f..097d486eff9c 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -19,6 +19,8 @@ typedef enum { actDownload = 101, actRealise = 102, actCopyPaths = 103, + actBuilds = 104, + actBuild = 105, } ActivityType; class Activity @@ -36,10 +38,7 @@ public: }; typedef enum { - evBuildCreated = 0, - evBuildStarted = 1, evBuildOutput = 2, - evBuildFinished = 3, evStartActivity = 1000, evStopActivity = 1001, diff --git a/src/nix/progress-bar.cc b/src/nix/progress-bar.cc index f4fc79fca160..c79a0d6d1db9 100644 --- a/src/nix/progress-bar.cc +++ b/src/nix/progress-bar.cc @@ -23,6 +23,7 @@ private: uint64_t done = 0; uint64_t expected = 0; uint64_t running = 0; + uint64_t failed = 0; std::map expectedByType; }; @@ -31,15 +32,11 @@ private: std::map::iterator> its; uint64_t done = 0; uint64_t expected = 0; + uint64_t failed = 0; }; struct State { - std::map builds; - std::set runningBuilds; - uint64_t succeededBuilds = 0; - uint64_t failedBuilds = 0; - std::list activities; std::map::iterator> its; @@ -62,7 +59,10 @@ public: ~ProgressBar() { auto state(state_.lock()); + std::string status = getStatus(*state); writeToStderr("\r\e[K"); + if (status != "") + writeToStderr("[" + status + "]\n"); } void log(Verbosity lvl, const FormatOrString & fs) override @@ -91,6 +91,7 @@ public: if (i != state.its.end()) { auto & act = state.activitiesByType[i->second->type]; act.done += i->second->done; + act.failed += i->second->failed; for (auto & j : i->second->expectedByType) state.activitiesByType[j.first].expected -= j.second; @@ -139,7 +140,7 @@ public: if (i != state.activities.rend()) { line += i->s; if (!i->s2.empty()) { - line += ": "; + if (!i->s.empty()) line += ": "; line += i->s2; } } @@ -155,42 +156,57 @@ public: std::string res; - auto add = [&](const std::string & s) { - if (!res.empty()) res += ", "; - res += s; - }; - - if (state.failedBuilds) { - add(fmt(ANSI_RED "%d failed" ANSI_NORMAL, state.failedBuilds)); - } - - if (!state.builds.empty() || state.succeededBuilds) - { - if (!res.empty()) res += ", "; - if (!state.runningBuilds.empty()) - res += fmt(ANSI_BLUE "%d" "/" ANSI_NORMAL, state.runningBuilds.size()); - res += fmt(ANSI_GREEN "%d/%d built" ANSI_NORMAL, - state.succeededBuilds, state.succeededBuilds + state.builds.size()); - } - - auto showActivity = [&](ActivityType type, const std::string & f, double unit) { + auto renderActivity = [&](ActivityType type, const std::string & itemFmt, const std::string & numberFmt, double unit) { auto & act = state.activitiesByType[type]; - uint64_t done = act.done, expected = act.done, running = 0; + uint64_t done = act.done, expected = act.done, running = 0, failed = act.failed; for (auto & j : act.its) { done += j.second->done; expected += j.second->expected; running += j.second->running; + failed += j.second->failed; } expected = std::max(expected, act.expected); - if (done || expected) - add(fmt(f, done / unit, expected / unit, running)); + std::string s; + + if (running || done || expected || failed) { + if (running) + s = fmt(ANSI_BLUE + numberFmt + ANSI_NORMAL "/" ANSI_GREEN + numberFmt + ANSI_NORMAL "/" + numberFmt, + running / unit, done / unit, expected / unit); + else if (expected != done) + s = fmt(ANSI_GREEN + numberFmt + ANSI_NORMAL "/" + numberFmt, + done / unit, expected / unit); + else + s = fmt(done ? ANSI_GREEN + numberFmt + ANSI_NORMAL : numberFmt, done / unit); + s = fmt(itemFmt, s); + + if (failed) + s += fmt(" (" ANSI_RED "%d failed" ANSI_NORMAL ")", failed / unit); + } + + return s; + }; + + auto showActivity = [&](ActivityType type, const std::string & itemFmt, const std::string & numberFmt, double unit) { + auto s = renderActivity(type, itemFmt, numberFmt, unit); + if (s.empty()) return; + if (!res.empty()) res += ", "; + res += s; }; - showActivity(actCopyPaths, ANSI_BLUE "%3$d" ANSI_NORMAL "/" ANSI_GREEN "%1$d" ANSI_NORMAL "/%2$d copied", 1); - showActivity(actDownload, "%1$.1f/%2$.1f MiB DL", MiB); - showActivity(actCopyPath, "%1$.1f/%2$.1f MiB copied", MiB); + showActivity(actBuilds, "%s built", "%d", 1); + + auto s1 = renderActivity(actCopyPaths, "%s copied", "%d", 1); + auto s2 = renderActivity(actCopyPath, "%s MiB", "%.1f", MiB); + + if (!s1.empty() || !s2.empty()) { + if (!res.empty()) res += ", "; + if (s1.empty()) res += "0 copied"; else res += s1; + if (!s2.empty()) { res += " ("; res += s2; res += ')'; } + } + + showActivity(actDownload, "%s MiB DL", "%.1f", MiB); return res; } @@ -216,6 +232,7 @@ public: actInfo.done = ev.getI(1); actInfo.expected = ev.getI(2); actInfo.running = ev.getI(3); + actInfo.failed = ev.getI(4); } if (ev.type == evSetExpected) { @@ -229,35 +246,11 @@ public: state->activitiesByType[type].expected += j; } - if (ev.type == evBuildCreated) { - state->builds[ev.getI(0)] = ev.getS(1); - } - - if (ev.type == evBuildStarted) { - Activity::t act = ev.getI(0); - state->runningBuilds.insert(act); - auto name = storePathToName(state->builds[act]); - if (hasSuffix(name, ".drv")) - name.resize(name.size() - 4); - createActivity(*state, act, fmt("building " ANSI_BOLD "%s" ANSI_NORMAL, name)); - } - - if (ev.type == evBuildFinished) { - Activity::t act = ev.getI(0); - if (ev.getI(1)) { - if (state->runningBuilds.count(act)) - state->succeededBuilds++; - } else - state->failedBuilds++; - state->runningBuilds.erase(act); - state->builds.erase(act); - deleteActivity(*state, act); - } - if (ev.type == evBuildOutput) { Activity::t act = ev.getI(0); - assert(state->runningBuilds.count(act)); - updateActivity(*state, act, ev.getS(1)); + auto s = trim(ev.getS(1)); + if (!s.empty()) + updateActivity(*state, act, s); } update(*state); -- cgit 1.4.1