From b01d62285cdcd376a8db1863049c68d8c7238837 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Tue, 16 May 2017 16:09:57 +0200 Subject: [PATCH] Improve progress indicator --- src/libexpr/eval.cc | 2 +- src/libexpr/get-drvs.cc | 3 +- src/libexpr/primops.cc | 8 +- src/libexpr/primops/fetchgit.cc | 2 +- src/libstore/build.cc | 31 ++- src/libstore/builtins.cc | 3 - src/libstore/download.cc | 38 +--- src/libstore/download.hh | 1 - src/libstore/export-import.cc | 8 +- src/libstore/gc.cc | 2 +- src/libstore/http-binary-cache-store.cc | 2 - src/libstore/optimise-store.cc | 2 +- src/libstore/store-api.cc | 9 +- src/libutil/logging.cc | 13 +- src/libutil/logging.hh | 91 ++++++--- src/libutil/util.cc | 2 +- src/libutil/util.hh | 2 + src/nix-channel/nix-channel.cc | 1 - src/nix-daemon/nix-daemon.cc | 7 +- src/nix-env/nix-env.cc | 2 +- src/nix-instantiate/nix-instantiate.cc | 2 +- src/nix/installables.cc | 6 +- src/nix/main.cc | 1 + src/nix/progress-bar.cc | 251 +++++++++++++++++++----- src/nix/sigs.cc | 6 +- src/nix/verify.cc | 12 +- 26 files changed, 339 insertions(+), 168 deletions(-) diff --git a/src/libexpr/eval.cc b/src/libexpr/eval.cc index 5e1ae63c4..0cdce602d 100644 --- a/src/libexpr/eval.cc +++ b/src/libexpr/eval.cc @@ -642,7 +642,7 @@ void EvalState::evalFile(const Path & path, Value & v) return; } - Activity act(*logger, lvlTalkative, format("evaluating file ‘%1%’") % path2); + printTalkative("evaluating file ‘%1%’", path2); Expr * e = parseExprFromFile(checkSourcePath(path2)); try { eval(e, v); diff --git a/src/libexpr/get-drvs.cc b/src/libexpr/get-drvs.cc index ae9fb0e5e..4200e8fd6 100644 --- a/src/libexpr/get-drvs.cc +++ b/src/libexpr/get-drvs.cc @@ -289,7 +289,7 @@ static void getDerivations(EvalState & state, Value & vIn, bound to the attribute with the "lower" name should take precedence). */ for (auto & i : v.attrs->lexicographicOrder()) { - Activity act(*logger, lvlDebug, format("evaluating attribute ‘%1%’") % i->name); + debug("evaluating attribute ‘%1%’", i->name); if (!std::regex_match(std::string(i->name), attrRegex)) continue; string pathPrefix2 = addToPath(pathPrefix, i->name); @@ -310,7 +310,6 @@ static void getDerivations(EvalState & state, Value & vIn, else if (v.isList()) { for (unsigned int n = 0; n < v.listSize(); ++n) { - Activity act(*logger, lvlDebug, "evaluating list element"); string pathPrefix2 = addToPath(pathPrefix, (format("%1%") % n).str()); if (getDerivation(state, *v.listElems()[n], pathPrefix2, drvs, done, ignoreAssertionFailures)) getDerivations(state, *v.listElems()[n], pathPrefix2, autoArgs, drvs, done, ignoreAssertionFailures); diff --git a/src/libexpr/primops.cc b/src/libexpr/primops.cc index cc23827a1..93b66269d 100644 --- a/src/libexpr/primops.cc +++ b/src/libexpr/primops.cc @@ -127,7 +127,7 @@ static void prim_scopedImport(EvalState & state, const Pos & pos, Value * * args env->values[displ++] = attr.value; } - Activity act(*logger, lvlTalkative, format("evaluating file ‘%1%’") % path); + printTalkative("evaluating file ‘%1%’", path); Expr * e = state.parseExprFromFile(resolveExprPath(path), staticEnv); e->eval(state, *env, v); @@ -326,8 +326,6 @@ typedef list ValueList; static void prim_genericClosure(EvalState & state, const Pos & pos, Value * * args, Value & v) { - Activity act(*logger, lvlDebug, "finding dependencies"); - state.forceAttrs(*args[0], pos); /* Get the start set. */ @@ -499,8 +497,6 @@ void prim_valueSize(EvalState & state, const Pos & pos, Value * * args, Value & derivation. */ static void prim_derivationStrict(EvalState & state, const Pos & pos, Value * * args, Value & v) { - Activity act(*logger, lvlVomit, "evaluating derivation"); - state.forceAttrs(*args[0], pos); /* Figure out the name first (for stack backtraces). */ @@ -544,7 +540,7 @@ static void prim_derivationStrict(EvalState & state, const Pos & pos, Value * * for (auto & i : args[0]->attrs->lexicographicOrder()) { if (i->name == state.sIgnoreNulls) continue; string key = i->name; - Activity act(*logger, lvlVomit, format("processing attribute ‘%1%’") % key); + vomit("processing attribute ‘%1%’", key); auto handleHashMode = [&](const std::string & s) { if (s == "recursive") outputHashRecursive = true; diff --git a/src/libexpr/primops/fetchgit.cc b/src/libexpr/primops/fetchgit.cc index 09e2c077b..3e4ece2cf 100644 --- a/src/libexpr/primops/fetchgit.cc +++ b/src/libexpr/primops/fetchgit.cc @@ -17,7 +17,7 @@ Path exportGit(ref store, const std::string & uri, const std::string & re runProgram("git", true, { "init", "--bare", cacheDir }); } - Activity act(*logger, lvlInfo, format("fetching Git repository ‘%s’") % uri); + //Activity act(*logger, lvlInfo, format("fetching Git repository ‘%s’") % uri); std::string localRef = "pid-" + std::to_string(getpid()); Path localRefFile = cacheDir + "/refs/heads/" + localRef; diff --git a/src/libstore/build.cc b/src/libstore/build.cc index 91156d313..44cae3431 100644 --- a/src/libstore/build.cc +++ b/src/libstore/build.cc @@ -120,6 +120,8 @@ protected: /* Whether the goal is finished. */ ExitCode exitCode; + Activity act; + Goal(Worker & worker) : worker(worker) { nrFailed = nrNoSubstituters = nrIncompleteClosure = 0; @@ -168,7 +170,8 @@ public: virtual string key() = 0; protected: - void amDone(ExitCode result); + + virtual void amDone(ExitCode result); }; @@ -902,6 +905,12 @@ private: void repairClosure(); + void amDone(ExitCode result) + { + logger->event(evBuildFinished, act, result == ecSuccess); + Goal::amDone(result); + } + void done(BuildResult::Status status, const string & msg = ""); }; @@ -920,6 +929,8 @@ DerivationGoal::DerivationGoal(const Path & drvPath, const StringSet & wantedOut state = &DerivationGoal::getDerivation; name = (format("building of ‘%1%’") % drvPath).str(); trace("created"); + + logger->event(evBuildCreated, act, drvPath); } @@ -935,6 +946,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); + /* Prevent the .chroot directory from being garbage-collected. (See isActiveTempFile() in gc.cc.) */ worker.store.addTempRoot(drvPath); @@ -2112,6 +2125,8 @@ void DerivationGoal::startBuilder() } debug(msg); } + + logger->event(evBuildStarted, act); } @@ -2857,7 +2872,7 @@ void DerivationGoal::registerOutputs() contained in it. Compute the SHA-256 NAR hash at the same time. The hash is stored in the database so that we can verify later on whether nobody has messed with the store. */ - Activity act(*logger, lvlTalkative, format("scanning for references inside ‘%1%’") % path); + debug("scanning for references inside ‘%1%’", path); HashResult hash; PathSet references = scanForReferences(actualPath, allPaths, hash); @@ -3130,6 +3145,7 @@ void DerivationGoal::flushLine() logTail.push_back(currentLogLine); if (logTail.size() > settings.logLines) logTail.pop_front(); } + logger->event(evBuildOutput, act, currentLogLine); currentLogLine = ""; currentLogLinePos = 0; } @@ -3244,6 +3260,12 @@ public: void handleEOF(int fd); Path getStorePath() { return storePath; } + + void amDone(ExitCode result) + { + logger->event(evSubstitutionFinished, act, result == ecSuccess); + Goal::amDone(result); + } }; @@ -3256,6 +3278,7 @@ SubstitutionGoal::SubstitutionGoal(const Path & storePath, Worker & worker, bool state = &SubstitutionGoal::init; name = (format("substitution of ‘%1%’") % storePath).str(); trace("created"); + logger->event(evSubstitutionCreated, act, storePath); } @@ -3391,6 +3414,8 @@ void SubstitutionGoal::tryToRun() printInfo(format("fetching path ‘%1%’...") % storePath); + logger->event(evSubstitutionStarted, act); + outPipe.create(); promise = std::promise(); @@ -3637,7 +3662,7 @@ void Worker::run(const Goals & _topGoals) { for (auto & i : _topGoals) topGoals.insert(i); - Activity act(*logger, lvlDebug, "entered goal loop"); + debug("entered goal loop"); while (1) { diff --git a/src/libstore/builtins.cc b/src/libstore/builtins.cc index c5dbd57f8..8a5cf3327 100644 --- a/src/libstore/builtins.cc +++ b/src/libstore/builtins.cc @@ -28,9 +28,6 @@ void builtinFetchurl(const BasicDerivation & drv, const std::string & netrcData) DownloadRequest request(url); request.verifyTLS = false; - /* Show a progress indicator, even though stderr is not a tty. */ - request.showProgress = DownloadRequest::yes; - /* Note: have to use a fresh downloader here because we're in a forked process. */ auto data = makeDownloader()->download(request); diff --git a/src/libstore/download.cc b/src/libstore/download.cc index dc1a3d94f..63e498f06 100644 --- a/src/libstore/download.cc +++ b/src/libstore/download.cc @@ -63,6 +63,7 @@ struct CurlDownloader : public Downloader CurlDownloader & downloader; DownloadRequest request; DownloadResult result; + Activity act; bool done = false; // whether either the success or failure function has been called std::function success; std::function failure; @@ -70,10 +71,6 @@ struct CurlDownloader : public Downloader bool active = false; // whether the handle has been added to the multi object std::string status; - bool showProgress = false; - double prevProgressTime{0}, startTime{0}; - unsigned int moveBack{1}; - unsigned int attempt = 0; /* Don't start this download until the specified time point @@ -87,12 +84,10 @@ struct CurlDownloader : public Downloader DownloadItem(CurlDownloader & downloader, const DownloadRequest & request) : downloader(downloader), request(request) { - showProgress = - request.showProgress == DownloadRequest::yes || - (request.showProgress == DownloadRequest::automatic && isatty(STDERR_FILENO)); - if (!request.expectedETag.empty()) requestHeaders = curl_slist_append(requestHeaders, ("If-None-Match: " + request.expectedETag).c_str()); + + logger->event(evDownloadCreated, act, request.uri); } ~DownloadItem() @@ -109,6 +104,7 @@ struct CurlDownloader : public Downloader } catch (...) { ignoreException(); } + logger->event(evDownloadDestroyed, act); } template @@ -171,19 +167,7 @@ struct CurlDownloader : public Downloader int progressCallback(double dltotal, double dlnow) { - if (showProgress) { - double now = getTime(); - if (prevProgressTime <= now - 1) { - string s = (format(" [%1$.0f/%2$.0f KiB, %3$.1f KiB/s]") - % (dlnow / 1024.0) - % (dltotal / 1024.0) - % (now == startTime ? 0 : dlnow / 1024.0 / (now - startTime))).str(); - std::cerr << "\e[" << moveBack << "D" << s; - moveBack = s.size(); - std::cerr.flush(); - prevProgressTime = now; - } - } + logger->event(evDownloadProgress, act, dltotal, dlnow); return _isInterrupted; } @@ -201,13 +185,6 @@ struct CurlDownloader : public Downloader void init() { - // FIXME: handle parallel downloads. - if (showProgress) { - std::cerr << (format("downloading ‘%1%’... ") % request.uri); - std::cerr.flush(); - startTime = getTime(); - } - if (!req) req = curl_easy_init(); curl_easy_reset(req); @@ -263,10 +240,6 @@ struct CurlDownloader : public Downloader void finish(CURLcode code) { - if (showProgress) - //std::cerr << "\e[" << moveBack << "D\e[K\n"; - std::cerr << "\n"; - long httpStatus = 0; curl_easy_getinfo(req, CURLINFO_RESPONSE_CODE, &httpStatus); @@ -292,6 +265,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()); } catch (...) { done = true; callFailure(failure, std::current_exception()); diff --git a/src/libstore/download.hh b/src/libstore/download.hh index 62f3860b9..7d8982d64 100644 --- a/src/libstore/download.hh +++ b/src/libstore/download.hh @@ -13,7 +13,6 @@ struct DownloadRequest std::string uri; std::string expectedETag; bool verifyTLS = true; - enum { yes, no, automatic } showProgress = yes; bool head = false; size_t tries = 5; unsigned int baseRetryTimeMs = 250; diff --git a/src/libstore/export-import.cc b/src/libstore/export-import.cc index 2b8ab063e..6e8bc692c 100644 --- a/src/libstore/export-import.cc +++ b/src/libstore/export-import.cc @@ -30,13 +30,13 @@ void Store::exportPaths(const Paths & paths, Sink & sink) std::reverse(sorted.begin(), sorted.end()); std::string doneLabel("paths exported"); - logger->incExpected(doneLabel, sorted.size()); + //logger->incExpected(doneLabel, sorted.size()); for (auto & path : sorted) { - Activity act(*logger, lvlInfo, format("exporting path ‘%s’") % path); + //Activity act(*logger, lvlInfo, format("exporting path ‘%s’") % path); sink << 1; exportPath(path, sink); - logger->incProgress(doneLabel); + //logger->incProgress(doneLabel); } sink << 0; @@ -81,7 +81,7 @@ Paths Store::importPaths(Source & source, std::shared_ptr accessor, info.path = readStorePath(*this, source); - Activity act(*logger, lvlInfo, format("importing path ‘%s’") % info.path); + //Activity act(*logger, lvlInfo, format("importing path ‘%s’") % info.path); info.references = readStorePaths(*this, source); diff --git a/src/libstore/gc.cc b/src/libstore/gc.cc index 3e7e42cbc..3cdbb114a 100644 --- a/src/libstore/gc.cc +++ b/src/libstore/gc.cc @@ -615,7 +615,7 @@ void LocalStore::tryToDelete(GCState & state, const Path & path) auto realPath = realStoreDir + "/" + baseNameOf(path); if (realPath == linksDir || realPath == trashDir) return; - Activity act(*logger, lvlDebug, format("considering whether to delete ‘%1%’") % path); + //Activity act(*logger, lvlDebug, format("considering whether to delete ‘%1%’") % path); if (!isStorePath(path) || !isValidPath(path)) { /* A lock file belonging to a path that we're building right diff --git a/src/libstore/http-binary-cache-store.cc b/src/libstore/http-binary-cache-store.cc index 37a7d6ace..cead81514 100644 --- a/src/libstore/http-binary-cache-store.cc +++ b/src/libstore/http-binary-cache-store.cc @@ -50,7 +50,6 @@ protected: { try { DownloadRequest request(cacheUri + "/" + path); - request.showProgress = DownloadRequest::no; request.head = true; request.tries = 5; getDownloader()->download(request); @@ -76,7 +75,6 @@ protected: std::function failure) override { DownloadRequest request(cacheUri + "/" + path); - request.showProgress = DownloadRequest::no; request.tries = 8; getDownloader()->enqueueDownload(request, diff --git a/src/libstore/optimise-store.cc b/src/libstore/optimise-store.cc index d354812e3..56167c4df 100644 --- a/src/libstore/optimise-store.cc +++ b/src/libstore/optimise-store.cc @@ -240,7 +240,7 @@ void LocalStore::optimiseStore(OptimiseStats & stats) for (auto & i : paths) { addTempRoot(i); if (!isValidPath(i)) continue; /* path was GC'ed, probably */ - Activity act(*logger, lvlChatty, format("hashing files in ‘%1%’") % i); + //Activity act(*logger, lvlChatty, format("hashing files in ‘%1%’") % i); optimisePath_(stats, realStoreDir + "/" + baseNameOf(i), inodeHash); } } diff --git a/src/libstore/store-api.cc b/src/libstore/store-api.cc index 96799adb1..e6cbd53dc 100644 --- a/src/libstore/store-api.cc +++ b/src/libstore/store-api.cc @@ -822,7 +822,7 @@ void copyPaths(ref from, ref to, const PathSet & storePaths, std::string copiedLabel = "copied"; - logger->setExpected(copiedLabel, missing.size()); + //logger->setExpected(copiedLabel, missing.size()); ThreadPool pool; @@ -838,13 +838,14 @@ void copyPaths(ref from, ref to, const PathSet & storePaths, checkInterrupt(); if (!to->isValidPath(storePath)) { - Activity act(*logger, lvlInfo, format("copying ‘%s’...") % storePath); + //Activity act(*logger, lvlInfo, format("copying ‘%s’...") % storePath); copyStorePath(from, to, storePath, false, dontCheckSigs); - logger->incProgress(copiedLabel); + //logger->incProgress(copiedLabel); } else - logger->incExpected(copiedLabel, -1); + ; + //logger->incExpected(copiedLabel, -1); }); pool.process(); diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index afcc2ec58..2d0acca24 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -1,6 +1,8 @@ #include "logging.hh" #include "util.hh" +#include + namespace nix { Logger * logger = makeDefaultLogger(); @@ -42,12 +44,7 @@ public: writeToStderr(prefix + (tty ? fs.s : filterANSIEscapes(fs.s)) + "\n"); } - void startActivity(Activity & activity, Verbosity lvl, const FormatOrString & fs) override - { - log(lvl, fs); - } - - void stopActivity(Activity & activity) override + void event(const Event & ev) override { } }; @@ -79,4 +76,8 @@ Logger * makeDefaultLogger() return new SimpleLogger(); } +std::atomic Activity::nextId{(uint64_t) getpid() << 32}; + +Activity::Activity() : id(nextId++) { }; + } diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index a8c69dbd9..ddfc336fe 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -13,7 +13,64 @@ typedef enum { lvlVomit } Verbosity; -class Activity; +class Activity +{ + static std::atomic nextId; +public: + typedef uint64_t t; + const t id; + Activity(); + Activity(const Activity & act) : id(act.id) { }; + Activity(uint64_t id) : id(id) { }; +}; + +typedef enum { + evBuildCreated = 0, + evBuildStarted = 1, + evBuildOutput = 2, + evBuildFinished = 3, + evDownloadCreated = 4, + evDownloadDestroyed = 5, + evDownloadProgress = 6, + evDownloadSucceeded = 7, + evSubstitutionCreated = 8, + evSubstitutionStarted = 9, + evSubstitutionFinished = 10, +} EventType; + +struct Event +{ + struct Field + { + // FIXME: use std::variant. + enum { tInt, tString } type; + uint64_t i = 0; + std::string s; + Field(const std::string & s) : type(tString), s(s) { } + Field(const char * s) : type(tString), s(s) { } + Field(const uint64_t & i) : type(tInt), i(i) { } + Field(const Activity & act) : type(tInt), i(act.id) { } + }; + + typedef std::vector Fields; + + EventType type; + Fields fields; + + std::string getS(size_t n) const + { + assert(n < fields.size()); + assert(fields[n].type == Field::tString); + return fields[n].s; + } + + uint64_t getI(size_t n) const + { + assert(n < fields.size()); + assert(fields[n].type == Field::tInt); + return fields[n].i; + } +}; class Logger { @@ -32,34 +89,16 @@ public: virtual void warn(const std::string & msg); - virtual void setExpected(const std::string & label, uint64_t value = 1) { } - virtual void setProgress(const std::string & label, uint64_t value = 1) { } - virtual void incExpected(const std::string & label, uint64_t value = 1) { } - virtual void incProgress(const std::string & label, uint64_t value = 1) { } - -private: - - virtual void startActivity(Activity & activity, Verbosity lvl, const FormatOrString & fs) = 0; - - virtual void stopActivity(Activity & activity) = 0; - -}; - -class Activity -{ -public: - Logger & logger; - - Activity(Logger & logger, Verbosity lvl, const FormatOrString & fs) - : logger(logger) + template + void event(EventType type, const Args & ... args) { - logger.startActivity(*this, lvl, fs); + Event ev; + ev.type = type; + nop{(ev.fields.emplace_back(Event::Field(args)), 1)...}; + event(ev); } - ~Activity() - { - logger.stopActivity(*this); - } + virtual void event(const Event & ev) = 0; }; extern Logger * logger; diff --git a/src/libutil/util.cc b/src/libutil/util.cc index 1d1f68fc8..16f4b232e 100644 --- a/src/libutil/util.cc +++ b/src/libutil/util.cc @@ -372,7 +372,7 @@ void deletePath(const Path & path) void deletePath(const Path & path, unsigned long long & bytesFreed) { - Activity act(*logger, lvlDebug, format("recursively deleting path ‘%1%’") % path); + //Activity act(*logger, lvlDebug, format("recursively deleting path ‘%1%’") % path); bytesFreed = 0; _deletePath(path, bytesFreed); } diff --git a/src/libutil/util.hh b/src/libutil/util.hh index 5a9c9513f..7ea32e8d9 100644 --- a/src/libutil/util.hh +++ b/src/libutil/util.hh @@ -364,6 +364,8 @@ void ignoreException(); #define ANSI_NORMAL "\e[0m" #define ANSI_BOLD "\e[1m" #define ANSI_RED "\e[31;1m" +#define ANSI_GREEN "\e[32;1m" +#define ANSI_BLUE "\e[34;1m" /* Filter out ANSI escape codes from the given string. If ‘nixOnly’ is diff --git a/src/nix-channel/nix-channel.cc b/src/nix-channel/nix-channel.cc index 2aaae2f47..f2742bc3b 100755 --- a/src/nix-channel/nix-channel.cc +++ b/src/nix-channel/nix-channel.cc @@ -112,7 +112,6 @@ static void update(const StringSet & channelNames) // The URL doesn't unpack directly, so let's try treating it like a full channel folder with files in it // Check if the channel advertises a binary cache. DownloadRequest request(url + "/binary-cache-url"); - request.showProgress = DownloadRequest::no; try { auto dlRes = dl->download(request); extraAttrs = "binaryCacheURL = \"" + *dlRes.data + "\";"; diff --git a/src/nix-daemon/nix-daemon.cc b/src/nix-daemon/nix-daemon.cc index d2bb7b8c8..44127635d 100644 --- a/src/nix-daemon/nix-daemon.cc +++ b/src/nix-daemon/nix-daemon.cc @@ -82,12 +82,7 @@ class TunnelLogger : public Logger defaultLogger->log(lvl, fs); } - void startActivity(Activity & activity, Verbosity lvl, const FormatOrString & fs) override - { - log(lvl, fs); - } - - void stopActivity(Activity & activity) override + void event(const Event & ev) override { } }; diff --git a/src/nix-env/nix-env.cc b/src/nix-env/nix-env.cc index da39bf36a..464bcee4a 100644 --- a/src/nix-env/nix-env.cc +++ b/src/nix-env/nix-env.cc @@ -989,7 +989,7 @@ static void opQuery(Globals & globals, Strings opFlags, Strings opArgs) try { if (i.hasFailed()) continue; - Activity act(*logger, lvlDebug, format("outputting query result ‘%1%’") % i.attrPath); + //Activity act(*logger, lvlDebug, format("outputting query result ‘%1%’") % i.attrPath); if (globals.prebuiltOnly && validPaths.find(i.queryOutPath()) == validPaths.end() && diff --git a/src/nix-instantiate/nix-instantiate.cc b/src/nix-instantiate/nix-instantiate.cc index c1b0b0ea0..25f0b1bd6 100644 --- a/src/nix-instantiate/nix-instantiate.cc +++ b/src/nix-instantiate/nix-instantiate.cc @@ -19,7 +19,7 @@ using namespace nix; static Expr * parseStdin(EvalState & state) { - Activity act(*logger, lvlTalkative, format("parsing standard input")); + //Activity act(*logger, lvlTalkative, format("parsing standard input")); return state.parseExprFromString(drainFD(0), absPath(".")); } diff --git a/src/nix/installables.cc b/src/nix/installables.cc index 4756fc44b..f23308b9b 100644 --- a/src/nix/installables.cc +++ b/src/nix/installables.cc @@ -223,9 +223,9 @@ PathSet InstallablesCommand::buildInstallables(ref store, bool dryRun) buildables.insert(b.begin(), b.end()); } - printMissing(store, buildables); - - if (!dryRun) + if (dryRun) + printMissing(store, buildables); + else store->buildPaths(buildables); PathSet outPaths; diff --git a/src/nix/main.cc b/src/nix/main.cc index 440ced97d..216f0bcce 100644 --- a/src/nix/main.cc +++ b/src/nix/main.cc @@ -27,6 +27,7 @@ struct NixArgs : virtual MultiCommand, virtual MixCommonArgs void mainWrapped(int argc, char * * argv) { + verbosity = lvlError; settings.verboseBuild = false; initNix(); diff --git a/src/nix/progress-bar.cc b/src/nix/progress-bar.cc index 69811b282..24e435f81 100644 --- a/src/nix/progress-bar.cc +++ b/src/nix/progress-bar.cc @@ -1,8 +1,12 @@ #include "progress-bar.hh" #include "util.hh" #include "sync.hh" +#include "store-api.hh" #include +#include + +#include namespace nix { @@ -12,31 +16,47 @@ private: struct ActInfo { - Activity * activity; - Verbosity lvl; - std::string s; + std::string s, s2; }; - struct Progress + struct DownloadInfo { - uint64_t expected = 0, progress = 0; + std::string uri; + uint64_t current = 0; + uint64_t expected = 0; }; struct State { + std::map builds; + std::set runningBuilds; + uint64_t succeededBuilds = 0; + uint64_t failedBuilds = 0; + std::map substitutions; + std::set runningSubstitutions; + uint64_t succeededSubstitutions = 0; + uint64_t downloadedBytes = 0; // finished downloads + std::map downloads; std::list activities; - std::map::iterator> its; - std::map progress; + std::map::iterator> its; }; Sync state_; + int width = 0; + public: + ProgressBar() + { + struct winsize ws; + if (ioctl(1, TIOCGWINSZ, &ws) == 0) + width = ws.ws_col; + } + ~ProgressBar() { auto state(state_.lock()); - assert(state->activities.empty()); writeToStderr("\r\e[K"); } @@ -52,52 +72,36 @@ public: update(state); } - void startActivity(Activity & activity, Verbosity lvl, const FormatOrString & fs) override + void createActivity(State & state, Activity::t activity, const std::string & s) { - if (lvl > verbosity) return; - auto state(state_.lock()); - state->activities.emplace_back(ActInfo{&activity, lvl, fs.s}); - state->its.emplace(&activity, std::prev(state->activities.end())); - update(*state); + state.activities.emplace_back(ActInfo{s}); + state.its.emplace(activity, std::prev(state.activities.end())); } - void stopActivity(Activity & activity) override + void deleteActivity(State & state, Activity::t activity) { - auto state(state_.lock()); - auto i = state->its.find(&activity); - if (i == state->its.end()) return; - state->activities.erase(i->second); - state->its.erase(i); - update(*state); + auto i = state.its.find(activity); + if (i != state.its.end()) { + state.activities.erase(i->second); + state.its.erase(i); + } } - void setExpected(const std::string & label, uint64_t value) override + void updateActivity(State & state, Activity::t activity, const std::string & s2) { - auto state(state_.lock()); - state->progress[label].expected = value; - } - - void setProgress(const std::string & label, uint64_t value) override - { - auto state(state_.lock()); - state->progress[label].progress = value; - } - - void incExpected(const std::string & label, uint64_t value) override - { - auto state(state_.lock()); - state->progress[label].expected += value; - } - - void incProgress(const std::string & label, uint64_t value) override - { - auto state(state_.lock()); - state->progress[label].progress += value; + auto i = state.its.find(activity); + assert(i != state.its.end()); + ActInfo info = *i->second; + state.activities.erase(i->second); + info.s2 = s2; + state.activities.emplace_back(info); + i->second = std::prev(state.activities.end()); } void update() { auto state(state_.lock()); + update(*state); } void update(State & state) @@ -113,28 +117,169 @@ public: if (!state.activities.empty()) { if (!status.empty()) line += " "; - line += state.activities.rbegin()->s; + auto i = state.activities.rbegin(); + line += i->s; + if (!i->s2.empty()) { + line += ": "; + line += i->s2; + } } line += "\e[K"; - writeToStderr(line); + writeToStderr(std::string(line, 0, width - 1)); } std::string getStatus(State & state) { std::string res; - for (auto & p : state.progress) - if (p.second.expected || p.second.progress) { - if (!res.empty()) res += ", "; - res += std::to_string(p.second.progress); - if (p.second.expected) { - res += "/"; - res += std::to_string(p.second.expected); - } - res += " "; res += p.first; + + if (state.failedBuilds) { + if (!res.empty()) res += ", "; + res += 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()); + } + + if (!state.substitutions.empty() || state.succeededSubstitutions) { + if (!res.empty()) res += ", "; + if (!state.runningSubstitutions.empty()) + res += fmt(ANSI_BLUE "%d" "/" ANSI_NORMAL, state.runningSubstitutions.size()); + res += fmt(ANSI_GREEN "%d/%d fetched" ANSI_NORMAL, + state.succeededSubstitutions, + 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); + } + return res; } + + void event(const Event & ev) override + { + if (ev.type == evBuildCreated) { + auto state(state_.lock()); + state->builds[ev.getI(0)] = ev.getS(1); + update(*state); + } + + if (ev.type == evBuildStarted) { + auto state(state_.lock()); + 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)); + update(*state); + } + + if (ev.type == evBuildFinished) { + auto state(state_.lock()); + 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); + update(*state); + } + + if (ev.type == evBuildOutput) { + auto state(state_.lock()); + Activity::t act = ev.getI(0); + assert(state->runningBuilds.count(act)); + updateActivity(*state, act, ev.getS(1)); + update(*state); + } + + if (ev.type == evSubstitutionCreated) { + auto state(state_.lock()); + state->substitutions[ev.getI(0)] = ev.getS(1); + update(*state); + } + + if (ev.type == evSubstitutionStarted) { + auto state(state_.lock()); + Activity::t act = ev.getI(0); + state->runningSubstitutions.insert(act); + auto name = storePathToName(state->substitutions[act]); + createActivity(*state, act, fmt("fetching " ANSI_BOLD "%s" ANSI_NORMAL, name)); + update(*state); + } + + if (ev.type == evSubstitutionFinished) { + auto state(state_.lock()); + Activity::t act = ev.getI(0); + if (ev.getI(1)) { + if (state->runningSubstitutions.count(act)) + state->succeededSubstitutions++; + } + state->runningSubstitutions.erase(act); + state->substitutions.erase(act); + deleteActivity(*state, act); + update(*state); + } + + if (ev.type == evDownloadCreated) { + auto state(state_.lock()); + 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)); + update(*state); + } + + if (ev.type == evDownloadProgress) { + auto state(state_.lock()); + 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); + update(*state); + } + + if (ev.type == evDownloadSucceeded) { + auto state(state_.lock()); + 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); + update(*state); + } + + if (ev.type == evDownloadDestroyed) { + auto state(state_.lock()); + Activity::t act = ev.getI(0); + auto i = state->downloads.find(act); + if (i != state->downloads.end()) { + state->downloads.erase(i); + deleteActivity(*state, act); + update(*state); + } + } + } }; StartProgressBar::StartProgressBar() diff --git a/src/nix/sigs.cc b/src/nix/sigs.cc index d8d8c0f53..3dd037716 100644 --- a/src/nix/sigs.cc +++ b/src/nix/sigs.cc @@ -42,10 +42,10 @@ struct CmdCopySigs : StorePathsCommand std::string doneLabel = "done"; std::atomic added{0}; - logger->setExpected(doneLabel, storePaths.size()); + //logger->setExpected(doneLabel, storePaths.size()); auto doPath = [&](const Path & storePath) { - Activity act(*logger, lvlInfo, format("getting signatures for ‘%s’") % storePath); + //Activity act(*logger, lvlInfo, format("getting signatures for ‘%s’") % storePath); checkInterrupt(); @@ -76,7 +76,7 @@ struct CmdCopySigs : StorePathsCommand added += newSigs.size(); } - logger->incProgress(doneLabel); + //logger->incProgress(doneLabel); }; for (auto & storePath : storePaths) diff --git a/src/nix/verify.cc b/src/nix/verify.cc index 2f8d02fa0..8facb4bef 100644 --- a/src/nix/verify.cc +++ b/src/nix/verify.cc @@ -65,7 +65,7 @@ struct CmdVerify : StorePathsCommand std::string untrustedLabel("untrusted"); std::string corruptedLabel("corrupted"); std::string failedLabel("failed"); - logger->setExpected(doneLabel, storePaths.size()); + //logger->setExpected(doneLabel, storePaths.size()); ThreadPool pool; @@ -73,7 +73,7 @@ struct CmdVerify : StorePathsCommand try { checkInterrupt(); - Activity act(*logger, lvlInfo, format("checking ‘%s’") % storePath); + //Activity act(*logger, lvlInfo, format("checking ‘%s’") % storePath); auto info = store->queryPathInfo(storePath); @@ -85,7 +85,7 @@ struct CmdVerify : StorePathsCommand auto hash = sink.finish(); if (hash.first != info->narHash) { - logger->incProgress(corruptedLabel); + //logger->incProgress(corruptedLabel); corrupted = 1; printError( format("path ‘%s’ was modified! expected hash ‘%s’, got ‘%s’") @@ -137,19 +137,19 @@ struct CmdVerify : StorePathsCommand } if (!good) { - logger->incProgress(untrustedLabel); + //logger->incProgress(untrustedLabel); untrusted++; printError(format("path ‘%s’ is untrusted") % info->path); } } - logger->incProgress(doneLabel); + //logger->incProgress(doneLabel); done++; } catch (Error & e) { printError(format(ANSI_RED "error:" ANSI_NORMAL " %s") % e.what()); - logger->incProgress(failedLabel); + //logger->incProgress(failedLabel); failed++; } };