Improve progress indicator

This commit is contained in:
Eelco Dolstra 2017-05-16 16:09:57 +02:00
parent e80257f122
commit b01d62285c
No known key found for this signature in database
GPG key ID: 8170B4726D7198DE
26 changed files with 339 additions and 168 deletions

View file

@ -642,7 +642,7 @@ void EvalState::evalFile(const Path & path, Value & v)
return; return;
} }
Activity act(*logger, lvlTalkative, format("evaluating file %1%") % path2); printTalkative("evaluating file %1%", path2);
Expr * e = parseExprFromFile(checkSourcePath(path2)); Expr * e = parseExprFromFile(checkSourcePath(path2));
try { try {
eval(e, v); eval(e, v);

View file

@ -289,7 +289,7 @@ static void getDerivations(EvalState & state, Value & vIn,
bound to the attribute with the "lower" name should take bound to the attribute with the "lower" name should take
precedence). */ precedence). */
for (auto & i : v.attrs->lexicographicOrder()) { 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)) if (!std::regex_match(std::string(i->name), attrRegex))
continue; continue;
string pathPrefix2 = addToPath(pathPrefix, i->name); string pathPrefix2 = addToPath(pathPrefix, i->name);
@ -310,7 +310,6 @@ static void getDerivations(EvalState & state, Value & vIn,
else if (v.isList()) { else if (v.isList()) {
for (unsigned int n = 0; n < v.listSize(); ++n) { for (unsigned int n = 0; n < v.listSize(); ++n) {
Activity act(*logger, lvlDebug, "evaluating list element");
string pathPrefix2 = addToPath(pathPrefix, (format("%1%") % n).str()); string pathPrefix2 = addToPath(pathPrefix, (format("%1%") % n).str());
if (getDerivation(state, *v.listElems()[n], pathPrefix2, drvs, done, ignoreAssertionFailures)) if (getDerivation(state, *v.listElems()[n], pathPrefix2, drvs, done, ignoreAssertionFailures))
getDerivations(state, *v.listElems()[n], pathPrefix2, autoArgs, drvs, done, ignoreAssertionFailures); getDerivations(state, *v.listElems()[n], pathPrefix2, autoArgs, drvs, done, ignoreAssertionFailures);

View file

@ -127,7 +127,7 @@ static void prim_scopedImport(EvalState & state, const Pos & pos, Value * * args
env->values[displ++] = attr.value; 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); Expr * e = state.parseExprFromFile(resolveExprPath(path), staticEnv);
e->eval(state, *env, v); e->eval(state, *env, v);
@ -326,8 +326,6 @@ typedef list<Value *> ValueList;
static void prim_genericClosure(EvalState & state, const Pos & pos, Value * * args, Value & v) static void prim_genericClosure(EvalState & state, const Pos & pos, Value * * args, Value & v)
{ {
Activity act(*logger, lvlDebug, "finding dependencies");
state.forceAttrs(*args[0], pos); state.forceAttrs(*args[0], pos);
/* Get the start set. */ /* Get the start set. */
@ -499,8 +497,6 @@ void prim_valueSize(EvalState & state, const Pos & pos, Value * * args, Value &
derivation. */ derivation. */
static void prim_derivationStrict(EvalState & state, const Pos & pos, Value * * args, Value & v) static void prim_derivationStrict(EvalState & state, const Pos & pos, Value * * args, Value & v)
{ {
Activity act(*logger, lvlVomit, "evaluating derivation");
state.forceAttrs(*args[0], pos); state.forceAttrs(*args[0], pos);
/* Figure out the name first (for stack backtraces). */ /* 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()) { for (auto & i : args[0]->attrs->lexicographicOrder()) {
if (i->name == state.sIgnoreNulls) continue; if (i->name == state.sIgnoreNulls) continue;
string key = i->name; string key = i->name;
Activity act(*logger, lvlVomit, format("processing attribute %1%") % key); vomit("processing attribute %1%", key);
auto handleHashMode = [&](const std::string & s) { auto handleHashMode = [&](const std::string & s) {
if (s == "recursive") outputHashRecursive = true; if (s == "recursive") outputHashRecursive = true;

View file

@ -17,7 +17,7 @@ Path exportGit(ref<Store> store, const std::string & uri, const std::string & re
runProgram("git", true, { "init", "--bare", cacheDir }); 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()); std::string localRef = "pid-" + std::to_string(getpid());
Path localRefFile = cacheDir + "/refs/heads/" + localRef; Path localRefFile = cacheDir + "/refs/heads/" + localRef;

View file

@ -120,6 +120,8 @@ protected:
/* Whether the goal is finished. */ /* Whether the goal is finished. */
ExitCode exitCode; ExitCode exitCode;
Activity act;
Goal(Worker & worker) : worker(worker) Goal(Worker & worker) : worker(worker)
{ {
nrFailed = nrNoSubstituters = nrIncompleteClosure = 0; nrFailed = nrNoSubstituters = nrIncompleteClosure = 0;
@ -168,7 +170,8 @@ public:
virtual string key() = 0; virtual string key() = 0;
protected: protected:
void amDone(ExitCode result);
virtual void amDone(ExitCode result);
}; };
@ -902,6 +905,12 @@ private:
void repairClosure(); void repairClosure();
void amDone(ExitCode result)
{
logger->event(evBuildFinished, act, result == ecSuccess);
Goal::amDone(result);
}
void done(BuildResult::Status status, const string & msg = ""); void done(BuildResult::Status status, const string & msg = "");
}; };
@ -920,6 +929,8 @@ DerivationGoal::DerivationGoal(const Path & drvPath, const StringSet & wantedOut
state = &DerivationGoal::getDerivation; state = &DerivationGoal::getDerivation;
name = (format("building of %1%") % drvPath).str(); name = (format("building of %1%") % drvPath).str();
trace("created"); 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(); name = (format("building of %1%") % showPaths(drv.outputPaths())).str();
trace("created"); trace("created");
logger->event(evBuildCreated, act, drvPath);
/* Prevent the .chroot directory from being /* Prevent the .chroot directory from being
garbage-collected. (See isActiveTempFile() in gc.cc.) */ garbage-collected. (See isActiveTempFile() in gc.cc.) */
worker.store.addTempRoot(drvPath); worker.store.addTempRoot(drvPath);
@ -2112,6 +2125,8 @@ void DerivationGoal::startBuilder()
} }
debug(msg); 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 contained in it. Compute the SHA-256 NAR hash at the same
time. The hash is stored in the database so that we can time. The hash is stored in the database so that we can
verify later on whether nobody has messed with the store. */ 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; HashResult hash;
PathSet references = scanForReferences(actualPath, allPaths, hash); PathSet references = scanForReferences(actualPath, allPaths, hash);
@ -3130,6 +3145,7 @@ void DerivationGoal::flushLine()
logTail.push_back(currentLogLine); logTail.push_back(currentLogLine);
if (logTail.size() > settings.logLines) logTail.pop_front(); if (logTail.size() > settings.logLines) logTail.pop_front();
} }
logger->event(evBuildOutput, act, currentLogLine);
currentLogLine = ""; currentLogLine = "";
currentLogLinePos = 0; currentLogLinePos = 0;
} }
@ -3244,6 +3260,12 @@ public:
void handleEOF(int fd); void handleEOF(int fd);
Path getStorePath() { return storePath; } 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; state = &SubstitutionGoal::init;
name = (format("substitution of %1%") % storePath).str(); name = (format("substitution of %1%") % storePath).str();
trace("created"); trace("created");
logger->event(evSubstitutionCreated, act, storePath);
} }
@ -3391,6 +3414,8 @@ void SubstitutionGoal::tryToRun()
printInfo(format("fetching path %1%...") % storePath); printInfo(format("fetching path %1%...") % storePath);
logger->event(evSubstitutionStarted, act);
outPipe.create(); outPipe.create();
promise = std::promise<void>(); promise = std::promise<void>();
@ -3637,7 +3662,7 @@ void Worker::run(const Goals & _topGoals)
{ {
for (auto & i : _topGoals) topGoals.insert(i); for (auto & i : _topGoals) topGoals.insert(i);
Activity act(*logger, lvlDebug, "entered goal loop"); debug("entered goal loop");
while (1) { while (1) {

View file

@ -28,9 +28,6 @@ void builtinFetchurl(const BasicDerivation & drv, const std::string & netrcData)
DownloadRequest request(url); DownloadRequest request(url);
request.verifyTLS = false; 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 /* Note: have to use a fresh downloader here because we're in
a forked process. */ a forked process. */
auto data = makeDownloader()->download(request); auto data = makeDownloader()->download(request);

View file

@ -63,6 +63,7 @@ struct CurlDownloader : public Downloader
CurlDownloader & downloader; CurlDownloader & downloader;
DownloadRequest request; DownloadRequest request;
DownloadResult result; DownloadResult result;
Activity act;
bool done = false; // whether either the success or failure function has been called bool done = false; // whether either the success or failure function has been called
std::function<void(const DownloadResult &)> success; std::function<void(const DownloadResult &)> success;
std::function<void(std::exception_ptr exc)> failure; std::function<void(std::exception_ptr exc)> failure;
@ -70,10 +71,6 @@ struct CurlDownloader : public Downloader
bool active = false; // whether the handle has been added to the multi object bool active = false; // whether the handle has been added to the multi object
std::string status; std::string status;
bool showProgress = false;
double prevProgressTime{0}, startTime{0};
unsigned int moveBack{1};
unsigned int attempt = 0; unsigned int attempt = 0;
/* Don't start this download until the specified time point /* Don't start this download until the specified time point
@ -87,12 +84,10 @@ struct CurlDownloader : public Downloader
DownloadItem(CurlDownloader & downloader, const DownloadRequest & request) DownloadItem(CurlDownloader & downloader, const DownloadRequest & request)
: downloader(downloader), request(request) : downloader(downloader), request(request)
{ {
showProgress =
request.showProgress == DownloadRequest::yes ||
(request.showProgress == DownloadRequest::automatic && isatty(STDERR_FILENO));
if (!request.expectedETag.empty()) if (!request.expectedETag.empty())
requestHeaders = curl_slist_append(requestHeaders, ("If-None-Match: " + request.expectedETag).c_str()); requestHeaders = curl_slist_append(requestHeaders, ("If-None-Match: " + request.expectedETag).c_str());
logger->event(evDownloadCreated, act, request.uri);
} }
~DownloadItem() ~DownloadItem()
@ -109,6 +104,7 @@ struct CurlDownloader : public Downloader
} catch (...) { } catch (...) {
ignoreException(); ignoreException();
} }
logger->event(evDownloadDestroyed, act);
} }
template<class T> template<class T>
@ -171,19 +167,7 @@ struct CurlDownloader : public Downloader
int progressCallback(double dltotal, double dlnow) int progressCallback(double dltotal, double dlnow)
{ {
if (showProgress) { logger->event(evDownloadProgress, act, dltotal, dlnow);
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;
}
}
return _isInterrupted; return _isInterrupted;
} }
@ -201,13 +185,6 @@ struct CurlDownloader : public Downloader
void init() 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(); if (!req) req = curl_easy_init();
curl_easy_reset(req); curl_easy_reset(req);
@ -263,10 +240,6 @@ struct CurlDownloader : public Downloader
void finish(CURLcode code) void finish(CURLcode code)
{ {
if (showProgress)
//std::cerr << "\e[" << moveBack << "D\e[K\n";
std::cerr << "\n";
long httpStatus = 0; long httpStatus = 0;
curl_easy_getinfo(req, CURLINFO_RESPONSE_CODE, &httpStatus); curl_easy_getinfo(req, CURLINFO_RESPONSE_CODE, &httpStatus);
@ -292,6 +265,7 @@ struct CurlDownloader : public Downloader
try { try {
result.data = decodeContent(encoding, ref<std::string>(result.data)); result.data = decodeContent(encoding, ref<std::string>(result.data));
callSuccess(success, failure, const_cast<const DownloadResult &>(result)); callSuccess(success, failure, const_cast<const DownloadResult &>(result));
logger->event(evDownloadSucceeded, act, result.data->size());
} catch (...) { } catch (...) {
done = true; done = true;
callFailure(failure, std::current_exception()); callFailure(failure, std::current_exception());

View file

@ -13,7 +13,6 @@ struct DownloadRequest
std::string uri; std::string uri;
std::string expectedETag; std::string expectedETag;
bool verifyTLS = true; bool verifyTLS = true;
enum { yes, no, automatic } showProgress = yes;
bool head = false; bool head = false;
size_t tries = 5; size_t tries = 5;
unsigned int baseRetryTimeMs = 250; unsigned int baseRetryTimeMs = 250;

View file

@ -30,13 +30,13 @@ void Store::exportPaths(const Paths & paths, Sink & sink)
std::reverse(sorted.begin(), sorted.end()); std::reverse(sorted.begin(), sorted.end());
std::string doneLabel("paths exported"); std::string doneLabel("paths exported");
logger->incExpected(doneLabel, sorted.size()); //logger->incExpected(doneLabel, sorted.size());
for (auto & path : sorted) { for (auto & path : sorted) {
Activity act(*logger, lvlInfo, format("exporting path %s") % path); //Activity act(*logger, lvlInfo, format("exporting path %s") % path);
sink << 1; sink << 1;
exportPath(path, sink); exportPath(path, sink);
logger->incProgress(doneLabel); //logger->incProgress(doneLabel);
} }
sink << 0; sink << 0;
@ -81,7 +81,7 @@ Paths Store::importPaths(Source & source, std::shared_ptr<FSAccessor> accessor,
info.path = readStorePath(*this, source); 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<PathSet>(*this, source); info.references = readStorePaths<PathSet>(*this, source);

View file

@ -615,7 +615,7 @@ void LocalStore::tryToDelete(GCState & state, const Path & path)
auto realPath = realStoreDir + "/" + baseNameOf(path); auto realPath = realStoreDir + "/" + baseNameOf(path);
if (realPath == linksDir || realPath == trashDir) return; 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)) { if (!isStorePath(path) || !isValidPath(path)) {
/* A lock file belonging to a path that we're building right /* A lock file belonging to a path that we're building right

View file

@ -50,7 +50,6 @@ protected:
{ {
try { try {
DownloadRequest request(cacheUri + "/" + path); DownloadRequest request(cacheUri + "/" + path);
request.showProgress = DownloadRequest::no;
request.head = true; request.head = true;
request.tries = 5; request.tries = 5;
getDownloader()->download(request); getDownloader()->download(request);
@ -76,7 +75,6 @@ protected:
std::function<void(std::exception_ptr exc)> failure) override std::function<void(std::exception_ptr exc)> failure) override
{ {
DownloadRequest request(cacheUri + "/" + path); DownloadRequest request(cacheUri + "/" + path);
request.showProgress = DownloadRequest::no;
request.tries = 8; request.tries = 8;
getDownloader()->enqueueDownload(request, getDownloader()->enqueueDownload(request,

View file

@ -240,7 +240,7 @@ void LocalStore::optimiseStore(OptimiseStats & stats)
for (auto & i : paths) { for (auto & i : paths) {
addTempRoot(i); addTempRoot(i);
if (!isValidPath(i)) continue; /* path was GC'ed, probably */ 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); optimisePath_(stats, realStoreDir + "/" + baseNameOf(i), inodeHash);
} }
} }

View file

@ -822,7 +822,7 @@ void copyPaths(ref<Store> from, ref<Store> to, const PathSet & storePaths,
std::string copiedLabel = "copied"; std::string copiedLabel = "copied";
logger->setExpected(copiedLabel, missing.size()); //logger->setExpected(copiedLabel, missing.size());
ThreadPool pool; ThreadPool pool;
@ -838,13 +838,14 @@ void copyPaths(ref<Store> from, ref<Store> to, const PathSet & storePaths,
checkInterrupt(); checkInterrupt();
if (!to->isValidPath(storePath)) { 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); copyStorePath(from, to, storePath, false, dontCheckSigs);
logger->incProgress(copiedLabel); //logger->incProgress(copiedLabel);
} else } else
logger->incExpected(copiedLabel, -1); ;
//logger->incExpected(copiedLabel, -1);
}); });
pool.process(); pool.process();

View file

@ -1,6 +1,8 @@
#include "logging.hh" #include "logging.hh"
#include "util.hh" #include "util.hh"
#include <atomic>
namespace nix { namespace nix {
Logger * logger = makeDefaultLogger(); Logger * logger = makeDefaultLogger();
@ -42,12 +44,7 @@ public:
writeToStderr(prefix + (tty ? fs.s : filterANSIEscapes(fs.s)) + "\n"); writeToStderr(prefix + (tty ? fs.s : filterANSIEscapes(fs.s)) + "\n");
} }
void startActivity(Activity & activity, Verbosity lvl, const FormatOrString & fs) override void event(const Event & ev) override
{
log(lvl, fs);
}
void stopActivity(Activity & activity) override
{ {
} }
}; };
@ -79,4 +76,8 @@ Logger * makeDefaultLogger()
return new SimpleLogger(); return new SimpleLogger();
} }
std::atomic<uint64_t> Activity::nextId{(uint64_t) getpid() << 32};
Activity::Activity() : id(nextId++) { };
} }

View file

@ -13,7 +13,64 @@ typedef enum {
lvlVomit lvlVomit
} Verbosity; } Verbosity;
class Activity; class Activity
{
static std::atomic<uint64_t> 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<Field> 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 class Logger
{ {
@ -32,34 +89,16 @@ public:
virtual void warn(const std::string & msg); virtual void warn(const std::string & msg);
virtual void setExpected(const std::string & label, uint64_t value = 1) { } template<typename... Args>
virtual void setProgress(const std::string & label, uint64_t value = 1) { } void event(EventType type, const Args & ... args)
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)
{ {
logger.startActivity(*this, lvl, fs); Event ev;
ev.type = type;
nop{(ev.fields.emplace_back(Event::Field(args)), 1)...};
event(ev);
} }
~Activity() virtual void event(const Event & ev) = 0;
{
logger.stopActivity(*this);
}
}; };
extern Logger * logger; extern Logger * logger;

View file

@ -372,7 +372,7 @@ void deletePath(const Path & path)
void deletePath(const Path & path, unsigned long long & bytesFreed) 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; bytesFreed = 0;
_deletePath(path, bytesFreed); _deletePath(path, bytesFreed);
} }

View file

@ -364,6 +364,8 @@ void ignoreException();
#define ANSI_NORMAL "\e[0m" #define ANSI_NORMAL "\e[0m"
#define ANSI_BOLD "\e[1m" #define ANSI_BOLD "\e[1m"
#define ANSI_RED "\e[31;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 /* Filter out ANSI escape codes from the given string. If nixOnly is

View file

@ -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 // 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. // Check if the channel advertises a binary cache.
DownloadRequest request(url + "/binary-cache-url"); DownloadRequest request(url + "/binary-cache-url");
request.showProgress = DownloadRequest::no;
try { try {
auto dlRes = dl->download(request); auto dlRes = dl->download(request);
extraAttrs = "binaryCacheURL = \"" + *dlRes.data + "\";"; extraAttrs = "binaryCacheURL = \"" + *dlRes.data + "\";";

View file

@ -82,12 +82,7 @@ class TunnelLogger : public Logger
defaultLogger->log(lvl, fs); defaultLogger->log(lvl, fs);
} }
void startActivity(Activity & activity, Verbosity lvl, const FormatOrString & fs) override void event(const Event & ev) override
{
log(lvl, fs);
}
void stopActivity(Activity & activity) override
{ {
} }
}; };

View file

@ -989,7 +989,7 @@ static void opQuery(Globals & globals, Strings opFlags, Strings opArgs)
try { try {
if (i.hasFailed()) continue; 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 && if (globals.prebuiltOnly &&
validPaths.find(i.queryOutPath()) == validPaths.end() && validPaths.find(i.queryOutPath()) == validPaths.end() &&

View file

@ -19,7 +19,7 @@ using namespace nix;
static Expr * parseStdin(EvalState & state) 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(".")); return state.parseExprFromString(drainFD(0), absPath("."));
} }

View file

@ -223,9 +223,9 @@ PathSet InstallablesCommand::buildInstallables(ref<Store> store, bool dryRun)
buildables.insert(b.begin(), b.end()); buildables.insert(b.begin(), b.end());
} }
printMissing(store, buildables); if (dryRun)
printMissing(store, buildables);
if (!dryRun) else
store->buildPaths(buildables); store->buildPaths(buildables);
PathSet outPaths; PathSet outPaths;

View file

@ -27,6 +27,7 @@ struct NixArgs : virtual MultiCommand, virtual MixCommonArgs
void mainWrapped(int argc, char * * argv) void mainWrapped(int argc, char * * argv)
{ {
verbosity = lvlError;
settings.verboseBuild = false; settings.verboseBuild = false;
initNix(); initNix();

View file

@ -1,8 +1,12 @@
#include "progress-bar.hh" #include "progress-bar.hh"
#include "util.hh" #include "util.hh"
#include "sync.hh" #include "sync.hh"
#include "store-api.hh"
#include <map> #include <map>
#include <atomic>
#include <sys/ioctl.h>
namespace nix { namespace nix {
@ -12,31 +16,47 @@ private:
struct ActInfo struct ActInfo
{ {
Activity * activity; std::string s, s2;
Verbosity lvl;
std::string s;
}; };
struct Progress struct DownloadInfo
{ {
uint64_t expected = 0, progress = 0; std::string uri;
uint64_t current = 0;
uint64_t expected = 0;
}; };
struct State struct State
{ {
std::map<Activity::t, Path> builds;
std::set<Activity::t> runningBuilds;
uint64_t succeededBuilds = 0;
uint64_t failedBuilds = 0;
std::map<Activity::t, Path> substitutions;
std::set<Activity::t> runningSubstitutions;
uint64_t succeededSubstitutions = 0;
uint64_t downloadedBytes = 0; // finished downloads
std::map<Activity::t, DownloadInfo> downloads;
std::list<ActInfo> activities; std::list<ActInfo> activities;
std::map<Activity *, std::list<ActInfo>::iterator> its; std::map<Activity::t, std::list<ActInfo>::iterator> its;
std::map<std::string, Progress> progress;
}; };
Sync<State> state_; Sync<State> state_;
int width = 0;
public: public:
ProgressBar()
{
struct winsize ws;
if (ioctl(1, TIOCGWINSZ, &ws) == 0)
width = ws.ws_col;
}
~ProgressBar() ~ProgressBar()
{ {
auto state(state_.lock()); auto state(state_.lock());
assert(state->activities.empty());
writeToStderr("\r\e[K"); writeToStderr("\r\e[K");
} }
@ -52,52 +72,36 @@ public:
update(state); 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; state.activities.emplace_back(ActInfo{s});
auto state(state_.lock()); state.its.emplace(activity, std::prev(state.activities.end()));
state->activities.emplace_back(ActInfo{&activity, lvl, fs.s});
state->its.emplace(&activity, std::prev(state->activities.end()));
update(*state);
} }
void stopActivity(Activity & activity) override void deleteActivity(State & state, Activity::t activity)
{ {
auto state(state_.lock()); auto i = state.its.find(activity);
auto i = state->its.find(&activity); if (i != state.its.end()) {
if (i == state->its.end()) return; state.activities.erase(i->second);
state->activities.erase(i->second); state.its.erase(i);
state->its.erase(i); }
update(*state);
} }
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()); auto i = state.its.find(activity);
state->progress[label].expected = value; assert(i != state.its.end());
} ActInfo info = *i->second;
state.activities.erase(i->second);
void setProgress(const std::string & label, uint64_t value) override info.s2 = s2;
{ state.activities.emplace_back(info);
auto state(state_.lock()); i->second = std::prev(state.activities.end());
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;
} }
void update() void update()
{ {
auto state(state_.lock()); auto state(state_.lock());
update(*state);
} }
void update(State & state) void update(State & state)
@ -113,28 +117,169 @@ public:
if (!state.activities.empty()) { if (!state.activities.empty()) {
if (!status.empty()) line += " "; 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"; line += "\e[K";
writeToStderr(line); writeToStderr(std::string(line, 0, width - 1));
} }
std::string getStatus(State & state) std::string getStatus(State & state)
{ {
std::string res; std::string res;
for (auto & p : state.progress)
if (p.second.expected || p.second.progress) { if (state.failedBuilds) {
if (!res.empty()) res += ", "; if (!res.empty()) res += ", ";
res += std::to_string(p.second.progress); res += fmt(ANSI_RED "%d failed" ANSI_NORMAL, state.failedBuilds);
if (p.second.expected) { }
res += "/";
res += std::to_string(p.second.expected); if (!state.builds.empty() || state.succeededBuilds)
} {
res += " "; res += p.first; 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; 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() StartProgressBar::StartProgressBar()

View file

@ -42,10 +42,10 @@ struct CmdCopySigs : StorePathsCommand
std::string doneLabel = "done"; std::string doneLabel = "done";
std::atomic<size_t> added{0}; std::atomic<size_t> added{0};
logger->setExpected(doneLabel, storePaths.size()); //logger->setExpected(doneLabel, storePaths.size());
auto doPath = [&](const Path & storePath) { 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(); checkInterrupt();
@ -76,7 +76,7 @@ struct CmdCopySigs : StorePathsCommand
added += newSigs.size(); added += newSigs.size();
} }
logger->incProgress(doneLabel); //logger->incProgress(doneLabel);
}; };
for (auto & storePath : storePaths) for (auto & storePath : storePaths)

View file

@ -65,7 +65,7 @@ struct CmdVerify : StorePathsCommand
std::string untrustedLabel("untrusted"); std::string untrustedLabel("untrusted");
std::string corruptedLabel("corrupted"); std::string corruptedLabel("corrupted");
std::string failedLabel("failed"); std::string failedLabel("failed");
logger->setExpected(doneLabel, storePaths.size()); //logger->setExpected(doneLabel, storePaths.size());
ThreadPool pool; ThreadPool pool;
@ -73,7 +73,7 @@ struct CmdVerify : StorePathsCommand
try { try {
checkInterrupt(); checkInterrupt();
Activity act(*logger, lvlInfo, format("checking %s") % storePath); //Activity act(*logger, lvlInfo, format("checking %s") % storePath);
auto info = store->queryPathInfo(storePath); auto info = store->queryPathInfo(storePath);
@ -85,7 +85,7 @@ struct CmdVerify : StorePathsCommand
auto hash = sink.finish(); auto hash = sink.finish();
if (hash.first != info->narHash) { if (hash.first != info->narHash) {
logger->incProgress(corruptedLabel); //logger->incProgress(corruptedLabel);
corrupted = 1; corrupted = 1;
printError( printError(
format("path %s was modified! expected hash %s, got %s") format("path %s was modified! expected hash %s, got %s")
@ -137,19 +137,19 @@ struct CmdVerify : StorePathsCommand
} }
if (!good) { if (!good) {
logger->incProgress(untrustedLabel); //logger->incProgress(untrustedLabel);
untrusted++; untrusted++;
printError(format("path %s is untrusted") % info->path); printError(format("path %s is untrusted") % info->path);
} }
} }
logger->incProgress(doneLabel); //logger->incProgress(doneLabel);
done++; done++;
} catch (Error & e) { } catch (Error & e) {
printError(format(ANSI_RED "error:" ANSI_NORMAL " %s") % e.what()); printError(format(ANSI_RED "error:" ANSI_NORMAL " %s") % e.what());
logger->incProgress(failedLabel); //logger->incProgress(failedLabel);
failed++; failed++;
} }
}; };