Skip to content

Commit

Permalink
Improve substitution progress indicator
Browse files Browse the repository at this point in the history
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'
  • Loading branch information
edolstra committed Aug 16, 2017
1 parent b29b6fe commit c36467a
Show file tree
Hide file tree
Showing 5 changed files with 93 additions and 86 deletions.
55 changes: 54 additions & 1 deletion src/libstore/build.cc
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
#include "finally.hh"
#include "compression.hh"
#include "json.hh"
#include "nar-info.hh"

#include <algorithm>
#include <iostream>
Expand Down Expand Up @@ -201,6 +202,16 @@ struct Child
};


template<typename T>
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
{
Expand Down Expand Up @@ -244,6 +255,8 @@ class Worker

public:

const Activity act;

/* Set if at least one derivation had a BuildError (i.e. permanent
failure). */
bool permanentFailure;
Expand All @@ -255,6 +268,11 @@ class Worker

std::unique_ptr<HookInstance> hook;

uint64_t expectedDownloadSize = 0;
uint64_t doneDownloadSize = 0;
uint64_t expectedNarSize = 0;
uint64_t doneNarSize = 0;

Worker(LocalStore & store);
~Worker();

Expand Down Expand Up @@ -313,6 +331,12 @@ class Worker
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);
}
};


Expand Down Expand Up @@ -3304,6 +3328,8 @@ class SubstitutionGoal : public Goal
storePath when doing a repair. */
Path destPath;

std::unique_ptr<MaintainCount<uint64_t>> maintainExpectedNar, maintainExpectedDownload;

typedef void (SubstitutionGoal::*GoalState)();
GoalState state;

Expand Down Expand Up @@ -3430,6 +3456,18 @@ void SubstitutionGoal::tryNext()
return;
}

/* Update the total expected download size. */
auto narInfo = std::dynamic_pointer_cast<const NarInfo>(info);

maintainExpectedNar = std::make_unique<MaintainCount<uint64_t>>(worker.expectedNarSize, narInfo->narSize);

maintainExpectedDownload =
narInfo && narInfo->fileSize
? std::make_unique<MaintainCount<uint64_t>>(worker.expectedDownloadSize, narInfo->fileSize)
: nullptr;

worker.updateProgress();

hasSubstitute = true;

/* Bail out early if this substituter lacks a valid
Expand Down Expand Up @@ -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);
}

Expand All @@ -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();
Expand All @@ -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);
}


Expand Down
11 changes: 5 additions & 6 deletions src/libstore/download.cc
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand All @@ -105,7 +105,6 @@ struct CurlDownloader : public Downloader
} catch (...) {
ignoreException();
}
logger->event(evDownloadDestroyed, act);
}

template<class T>
Expand Down Expand Up @@ -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;
}

Expand Down Expand Up @@ -267,7 +266,7 @@ struct CurlDownloader : public Downloader
try {
result.data = decodeContent(encoding, ref<std::string>(result.data));
callSuccess(success, failure, const_cast<const DownloadResult &>(result));
logger->event(evDownloadSucceeded, act, result.data->size());
act.progress(result.data->size(), result.data->size());
} catch (...) {
done = true;
callFailure(failure, std::current_exception());
Expand Down
6 changes: 2 additions & 4 deletions src/libutil/logging.hh
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,8 @@ typedef enum {
typedef enum {
actUnknown = 0,
actCopyPath = 100,
actDownload = 101,
actRealise = 102,
} ActivityType;

class Activity
Expand All @@ -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,
Expand Down
2 changes: 1 addition & 1 deletion src/nix/installables.cc
Original file line number Diff line number Diff line change
Expand Up @@ -229,7 +229,7 @@ std::vector<std::shared_ptr<Installable>> InstallablesCommand::parseInstallables

PathSet InstallablesCommand::toStorePaths(ref<Store> store, ToStorePathsMode mode)
{
if (mode != DryRun)
if (mode != Build)
settings.readOnlyMode = true;

PathSet outPaths, buildables;
Expand Down
105 changes: 31 additions & 74 deletions src/nix/progress-bar.cc
Original file line number Diff line number Diff line change
Expand Up @@ -25,14 +25,6 @@ class ProgressBar : public Logger
std::map<ActivityType, uint64_t> 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;
Expand All @@ -58,9 +50,6 @@ class ProgressBar : public Logger
std::set<Activity::t> runningSubstitutions;
uint64_t succeededSubstitutions = 0;

uint64_t downloadedBytes = 0; // finished downloads
std::map<Activity::t, DownloadInfo> downloads;

std::map<Activity::t, CopyInfo> runningCopies;

std::list<ActInfo> activities;
Expand Down Expand Up @@ -155,10 +144,16 @@ class ProgressBar : public Logger
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;
}
}
}

Expand All @@ -172,9 +167,13 @@ class ProgressBar : public Logger

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)
Expand All @@ -195,39 +194,31 @@ class ProgressBar : public Logger
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;
}
Expand Down Expand Up @@ -318,40 +309,6 @@ class ProgressBar : public Logger
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];
Expand Down

0 comments on commit c36467a

Please sign in to comment.