diff --git a/lix/libmain/progress-bar.cc b/lix/libmain/progress-bar.cc index 841b8b24b..378ffacd3 100644 --- a/lix/libmain/progress-bar.cc +++ b/lix/libmain/progress-bar.cc @@ -104,31 +104,34 @@ bool ProgressBar::isVerbose() return printBuildLogs; } -void ProgressBar::log(Verbosity lvl, std::string_view s) +Logger::BufferState ProgressBar::log(Verbosity lvl, std::string_view s) { - if (lvl > verbosity) return; + if (lvl > verbosity) { + return BufferState::HasSpace; + } auto state(state_.lock()); - log(*state, lvl, s); + return log(*state, lvl, s); } -void ProgressBar::logEI(const ErrorInfo & ei) +Logger::BufferState ProgressBar::logEI(const ErrorInfo & ei) { auto state(state_.lock()); std::stringstream oss; showErrorInfo(oss, ei, loggerSettings.showTrace.get()); - log(*state, ei.level, oss.str()); + return log(*state, ei.level, oss.str()); } -void ProgressBar::log(State & state, Verbosity lvl, std::string_view s) +Logger::BufferState ProgressBar::log(State & state, Verbosity lvl, std::string_view s) { if (state.paused == 0) eraseProgressDisplay(state); writeLogsToStderr(filterANSIEscapes(s + ANSI_NORMAL "\n", !isTTY)); restoreProgressDisplay(state); + return BufferState::HasSpace; } -void ProgressBar::startActivityImpl( +Logger::BufferState ProgressBar::startActivityImpl( ActivityId act, Verbosity lvl, ActivityType type, @@ -140,7 +143,7 @@ void ProgressBar::startActivityImpl( auto state(state_.lock()); if (lvl <= verbosity && !s.empty() && type != actBuildWaiting) - log(*state, lvl, s + "..."); + (void) log(*state, lvl, s + "..."); state->activities.emplace_back(ActInfo { .s = s, @@ -198,6 +201,7 @@ void ProgressBar::startActivityImpl( i->visible = false; update(*state); + return BufferState::HasSpace; } /* Check whether an activity has an ancestore with the specified @@ -213,7 +217,7 @@ bool ProgressBar::hasAncestor(State & state, ActivityType type, ActivityId act) return false; } -void ProgressBar::stopActivityImpl(ActivityId act) +Logger::BufferState ProgressBar::stopActivityImpl(ActivityId act) { auto state(state_.lock()); @@ -233,9 +237,11 @@ void ProgressBar::stopActivityImpl(ActivityId act) } update(*state); + return BufferState::HasSpace; } -void ProgressBar::resultImpl(ActivityId act, ResultType type, const std::vector & fields) +Logger::BufferState +ProgressBar::resultImpl(ActivityId act, ResultType type, const std::vector & fields) { auto state(state_.lock()); @@ -256,7 +262,11 @@ void ProgressBar::resultImpl(ActivityId act, ResultType type, const std::vector< if (type == resPostBuildLogLine) { suffix = " (post)> "; } - log(*state, lvlInfo, ANSI_FAINT + info.name.value_or("unnamed") + suffix + ANSI_NORMAL + lastLine); + (void) log( + *state, + lvlInfo, + ANSI_FAINT + info.name.value_or("unnamed") + suffix + ANSI_NORMAL + lastLine + ); } else { if (!printMultiline) { state->activities.erase(i->second); @@ -310,6 +320,8 @@ void ProgressBar::resultImpl(ActivityId act, ResultType type, const std::vector< state->activitiesByType[type].expected += j; update(*state); } + + return BufferState::HasSpace; } void ProgressBar::update(State & state) diff --git a/lix/libmain/progress-bar.hh b/lix/libmain/progress-bar.hh index 0fc6f005e..a3f2b580d 100644 --- a/lix/libmain/progress-bar.hh +++ b/lix/libmain/progress-bar.hh @@ -75,13 +75,13 @@ struct ProgressBar : public Logger bool isVerbose() override; - void log(Verbosity lvl, std::string_view s) override; + BufferState log(Verbosity lvl, std::string_view s) override; - void logEI(const ErrorInfo & ei) override; + BufferState logEI(const ErrorInfo & ei) override; - void log(State & state, Verbosity lvl, std::string_view s); + BufferState log(State & state, Verbosity lvl, std::string_view s); - void startActivityImpl( + BufferState startActivityImpl( ActivityId act, Verbosity lvl, ActivityType type, @@ -92,9 +92,10 @@ struct ProgressBar : public Logger bool hasAncestor(State & state, ActivityType type, ActivityId act); - void stopActivityImpl(ActivityId act) override; + BufferState stopActivityImpl(ActivityId act) override; - void resultImpl(ActivityId act, ResultType type, const std::vector & fields) override; + BufferState + resultImpl(ActivityId act, ResultType type, const std::vector & fields) override; void update(State & state); diff --git a/lix/libstore/build/derivation-goal.cc b/lix/libstore/build/derivation-goal.cc index e043c6525..0c7cf27b0 100644 --- a/lix/libstore/build/derivation-goal.cc +++ b/lix/libstore/build/derivation-goal.cc @@ -1261,9 +1261,11 @@ try { for (auto c : data) if (c == '\r') currentLogLinePos = 0; - else if (c == '\n') - flushLine(); - else { + else if (c == '\n') { + if (flushLine() == Logger::BufferState::NeedsFlush) { + TRY_AWAIT(act->getLogger().flush()); + } + } else { if (currentLogLinePos >= currentLogLine.size()) currentLogLine.resize(currentLogLinePos + 1); currentLogLine[currentLogLinePos++] = c; @@ -1357,12 +1359,13 @@ try { ); } - return handlers.then([this](auto r) { - if (!currentLogLine.empty()) flushLine(); - return r; - }); + const auto r = TRY_AWAIT(handlers); + if (!currentLogLine.empty() && flushLine() == Logger::BufferState::NeedsFlush) { + TRY_AWAIT(act->getLogger().flush()); + } + co_return r; } catch (...) { - return {result::current_exception()}; + co_return result::current_exception(); } kj::Promise>> DerivationGoal::monitorForSilence() noexcept @@ -1413,20 +1416,24 @@ DerivationGoal::handleChildStreams(AsyncInputStream * builderIn, AsyncInputStrea co_return std::nullopt; } -void DerivationGoal::flushLine() +Logger::BufferState DerivationGoal::flushLine() { - if (handleJSONLogMessage(currentLogLine, *act, builderActivities, "the derivation builder", false)) - ; + KJ_DEFER({ + currentLogLine = ""; + currentLogLinePos = 0; + }); - else { + if (const auto state = handleJSONLogMessage( + currentLogLine, *act, builderActivities, "the derivation builder", false + )) + { + return *state; + } else { logTail.push_back(currentLogLine); if (logTail.size() > settings.logLines) logTail.pop_front(); - act->result(resBuildLogLine, currentLogLine); + return act->result(resBuildLogLine, currentLogLine); } - - currentLogLine = ""; - currentLogLinePos = 0; } diff --git a/lix/libstore/build/derivation-goal.hh b/lix/libstore/build/derivation-goal.hh index 3389a0f1a..2df3adf42 100644 --- a/lix/libstore/build/derivation-goal.hh +++ b/lix/libstore/build/derivation-goal.hh @@ -325,7 +325,7 @@ protected: kj::Promise>> handleHookOutput(AsyncInputStream & in) noexcept; kj::Promise>> monitorForSilence() noexcept; WorkResult tooMuchLogs(); - void flushLine(); + Logger::BufferState flushLine(); virtual std::string buildErrorContents(const std::string & exitMsg, bool diskFull); diff --git a/lix/libstore/daemon.cc b/lix/libstore/daemon.cc index 75e156a77..e129f552e 100644 --- a/lix/libstore/daemon.cc +++ b/lix/libstore/daemon.cc @@ -64,7 +64,7 @@ struct TunnelLogger : public Logger assert(clientVersion >= MIN_SUPPORTED_WORKER_PROTO_VERSION); } - void enqueueMsg(const std::string & s) + BufferState enqueueMsg(const std::string & s) { auto state(state_.lock()); @@ -81,27 +81,32 @@ struct TunnelLogger : public Logger } } else state->pendingMsgs.push_back(s); + return BufferState::HasSpace; } - void log(Verbosity lvl, std::string_view s) override + BufferState log(Verbosity lvl, std::string_view s) override { - if (lvl > verbosity) return; + if (lvl > verbosity) { + return BufferState::HasSpace; + } StringSink buf; buf << STDERR_NEXT << (s + "\n"); - enqueueMsg(buf.s); + return enqueueMsg(buf.s); } - void logEI(const ErrorInfo & ei) override + BufferState logEI(const ErrorInfo & ei) override { - if (ei.level > verbosity) return; + if (ei.level > verbosity) { + return BufferState::HasSpace; + } std::stringstream oss; showErrorInfo(oss, ei, false); StringSink buf; buf << STDERR_NEXT << oss.str(); - enqueueMsg(buf.s); + return enqueueMsg(buf.s); } /* startWork() means that we're starting an operation for which we @@ -134,7 +139,7 @@ struct TunnelLogger : public Logger } } - void startActivityImpl( + BufferState startActivityImpl( ActivityId act, Verbosity lvl, ActivityType type, @@ -145,21 +150,21 @@ struct TunnelLogger : public Logger { StringSink buf; buf << STDERR_START_ACTIVITY << act << lvl << type << s << fields << parent; - enqueueMsg(buf.s); + return enqueueMsg(buf.s); } - void stopActivityImpl(ActivityId act) override + BufferState stopActivityImpl(ActivityId act) override { StringSink buf; buf << STDERR_STOP_ACTIVITY << act; - enqueueMsg(buf.s); + return enqueueMsg(buf.s); } - void resultImpl(ActivityId act, ResultType type, const Fields & fields) override + BufferState resultImpl(ActivityId act, ResultType type, const Fields & fields) override { StringSink buf; buf << STDERR_RESULT << act << type << fields; - enqueueMsg(buf.s); + return enqueueMsg(buf.s); } }; diff --git a/lix/libstore/filetransfer.cc b/lix/libstore/filetransfer.cc index a8087b1da..37b2f48cb 100644 --- a/lix/libstore/filetransfer.cc +++ b/lix/libstore/filetransfer.cc @@ -3,6 +3,7 @@ #include "lix/libutil/async.hh" #include "lix/libutil/c-calls.hh" #include "lix/libutil/error.hh" +#include "lix/libutil/logging.hh" #include "lix/libutil/namespaces.hh" #include "lix/libstore/globals.hh" #include "lix/libstore/store-api.hh" @@ -373,7 +374,9 @@ struct curlFileTransfer : public FileTransfer int progressCallback(curl_off_t dltotal, curl_off_t dlnow) { try { - act.progress(dlnow, dltotal); + if (act.progress(dlnow, dltotal) == Logger::BufferState::NeedsFlush) { + act.getLogger().waitForSpace(); + } } catch (nix::Interrupted &) { } return isInterrupted(); @@ -405,7 +408,9 @@ struct curlFileTransfer : public FileTransfer else if (code == CURLE_OK && successfulStatuses.count(httpStatus)) { - act.progress(bodySize, bodySize); + if (act.progress(bodySize, bodySize) == Logger::BufferState::NeedsFlush) { + act.getLogger().waitForSpace(); + } auto state = downloadState.lock(); state->done = true; state->signal(); diff --git a/lix/libstore/store-api.cc b/lix/libstore/store-api.cc index 3472dc66f..328de248c 100644 --- a/lix/libstore/store-api.cc +++ b/lix/libstore/store-api.cc @@ -383,6 +383,12 @@ try { if (!settings.keepGoing) throw e; printMsg(lvlError, "could not copy %s: %s", printStorePath(path), e.what()); + goto failed; + } + + // can't co_await in catch, so we need this monstrosity + if (false) { + failed: SHOW_PROGRESS(); co_return result::success(); } diff --git a/lix/libutil/logging.cc b/lix/libutil/logging.cc index c451b52b1..d189f4119 100644 --- a/lix/libutil/logging.cc +++ b/lix/libutil/logging.cc @@ -11,6 +11,7 @@ #include #include #include +#include #include #include @@ -31,7 +32,9 @@ Activity Logger::startActivity( ) { Activity result{*this}; - startActivityImpl(result.id, lvl, type, s, fields, parent ? parent->id : 0); + // NOTE we assume that activities aren't started in monstrous numbers, so the inevitable + // state updates (via progress, result, or setExpected) should be enough to flush stuff. + (void) startActivityImpl(result.id, lvl, type, s, fields, parent ? parent->id : 0); return result; } @@ -72,9 +75,11 @@ public: return printBuildLogs; } - void log(Verbosity lvl, std::string_view s) override + BufferState log(Verbosity lvl, std::string_view s) override { - if (lvl > verbosity) return; + if (lvl > verbosity) { + return BufferState::HasSpace; + } std::string prefix; @@ -92,17 +97,18 @@ public: } writeLogsToStderr(prefix + filterANSIEscapes(s, !tty) + "\n"); + return BufferState::HasSpace; } - void logEI(const ErrorInfo & ei) override + BufferState logEI(const ErrorInfo & ei) override { std::stringstream oss; showErrorInfo(oss, ei, loggerSettings.showTrace.get()); - log(ei.level, oss.str()); + return log(ei.level, oss.str()); } - void startActivityImpl( + BufferState startActivityImpl( ActivityId act, Verbosity lvl, ActivityType type, @@ -111,11 +117,13 @@ public: ActivityId parent ) override { - if (lvl <= verbosity && !s.empty()) - log(lvl, s + "..."); + if (lvl <= verbosity && !s.empty()) { + return log(lvl, s + "..."); + } + return BufferState::HasSpace; } - void resultImpl(ActivityId act, ResultType type, const Fields & fields) override + BufferState resultImpl(ActivityId act, ResultType type, const Fields & fields) override { if (type == resBuildLogLine && printBuildLogs) { auto lastLine = fields[0].s; @@ -125,6 +133,7 @@ public: auto lastLine = fields[0].s; printError("post-build-hook: %1%", Uncolored(lastLine)); } + return BufferState::HasSpace; } }; @@ -184,21 +193,23 @@ struct JSONLogger : Logger { abort(); } - void write(const JSON & json) + BufferState write(const JSON & json) { - prevLogger.log(lvlError, "@nix " + json.dump(-1, ' ', false, JSON::error_handler_t::replace)); + return prevLogger.log( + lvlError, "@nix " + json.dump(-1, ' ', false, JSON::error_handler_t::replace) + ); } - void log(Verbosity lvl, std::string_view s) override + BufferState log(Verbosity lvl, std::string_view s) override { JSON json; json["action"] = "msg"; json["level"] = lvl; json["msg"] = s; - write(json); + return write(json); } - void logEI(const ErrorInfo & ei) override + BufferState logEI(const ErrorInfo & ei) override { std::ostringstream oss; showErrorInfo(oss, ei, loggerSettings.showTrace.get()); @@ -222,10 +233,10 @@ struct JSONLogger : Logger { json["trace"] = traces; } - write(json); + return write(json); } - void startActivityImpl( + BufferState startActivityImpl( ActivityId act, Verbosity lvl, ActivityType type, @@ -242,25 +253,25 @@ struct JSONLogger : Logger { json["text"] = s; json["parent"] = parent; addFields(json, fields); - write(json); + return write(json); } - void stopActivityImpl(ActivityId act) override + BufferState stopActivityImpl(ActivityId act) override { JSON json; json["action"] = "stop"; json["id"] = act; - write(json); + return write(json); } - void resultImpl(ActivityId act, ResultType type, const Fields & fields) override + BufferState resultImpl(ActivityId act, ResultType type, const Fields & fields) override { JSON json; json["action"] = "result"; json["id"] = act; json["type"] = type; addFields(json, fields); - write(json); + return write(json); } }; @@ -295,9 +306,13 @@ std::optional parseJSONMessage(const std::string & msg, std::string_view s return std::nullopt; } -bool handleJSONLogMessage(JSON & json, - const Activity & act, std::map & activities, - std::string_view source, bool trusted) +std::optional handleJSONLogMessage( + JSON & json, + const Activity & act, + std::map & activities, + std::string_view source, + bool trusted +) { try { std::string action = json["action"]; @@ -319,33 +334,40 @@ bool handleJSONLogMessage(JSON & json, else if (action == "result") { auto i = activities.find((ActivityId) json["id"]); if (i != activities.end()) - i->second.result((ResultType) json["type"], getFields(json["fields"])); + return i->second.result((ResultType) json["type"], getFields(json["fields"])); } else if (action == "setPhase") { std::string phase = json["phase"]; - act.result(resSetPhase, phase); + return act.result(resSetPhase, phase); } else if (action == "msg") { std::string msg = json["msg"]; - logger->log((Verbosity) json["level"], msg); + return logger->log((Verbosity) json["level"], msg); } - return true; + return Logger::BufferState::HasSpace; } catch (JSON::exception &e) { // NOLINT(lix-foreign-exceptions) printTaggedWarning( "Unable to handle a JSON message from %s: %s", Uncolored(source), e.what() ); - return false; + return std::nullopt; } } -bool handleJSONLogMessage(const std::string & msg, - const Activity & act, std::map & activities, std::string_view source, bool trusted) +std::optional handleJSONLogMessage( + const std::string & msg, + const Activity & act, + std::map & activities, + std::string_view source, + bool trusted +) { auto json = parseJSONMessage(msg, source); - if (!json) return false; + if (!json) { + return std::nullopt; + } return handleJSONLogMessage(*json, act, activities, source, trusted); } @@ -356,7 +378,10 @@ Activity::~Activity() return; } try { - logger->stopActivityImpl(id); + // NOTE we can't flush here, and async destruction of activities is bound to fail + // at some point. eventually something will flush the buffer for us (see also the + // startActivity comment, we also don't flush buffers there even when they fill.) + (void) logger->stopActivityImpl(id); } catch (...) { ignoreExceptionInDestructor(); } diff --git a/lix/libutil/logging.hh b/lix/libutil/logging.hh index 9aab120b6..e95d315b2 100644 --- a/lix/libutil/logging.hh +++ b/lix/libutil/logging.hh @@ -4,6 +4,10 @@ #include "lix/libutil/types.hh" #include "lix/libutil/error.hh" #include "lix/libutil/config.hh" +#include "result.hh" +#include "serialise.hh" +#include +#include namespace nix { @@ -105,6 +109,11 @@ class Logger public: + enum class [[nodiscard]] BufferState { + HasSpace, + NeedsFlush, + }; + struct Field { // FIXME: use std::variant. @@ -127,14 +136,19 @@ public: // Whether the logger prints the whole build log virtual bool isVerbose() { return false; } - virtual void log(Verbosity lvl, std::string_view s) = 0; + virtual BufferState bufferState() const + { + return BufferState::HasSpace; + } - virtual void logEI(const ErrorInfo & ei) = 0; + virtual BufferState log(Verbosity lvl, std::string_view s) = 0; - void logEI(Verbosity lvl, ErrorInfo ei) + virtual BufferState logEI(const ErrorInfo & ei) = 0; + + BufferState logEI(Verbosity lvl, ErrorInfo ei) { ei.level = lvl; - logEI(ei); + return logEI(ei); } Activity startActivity( @@ -148,19 +162,35 @@ public: Activity startActivity(ActivityType type, const Fields & fields = {}, const Activity * parent = nullptr); + virtual kj::Promise> flush() + { + return {result::success()}; + } + + virtual void waitForSpace() {} + protected: - virtual void startActivityImpl( + virtual BufferState startActivityImpl( ActivityId act, Verbosity lvl, ActivityType type, const std::string & s, const Fields & fields, ActivityId parent - ) {}; + ) + { + return BufferState::HasSpace; + } - virtual void stopActivityImpl(ActivityId act) {}; + virtual BufferState stopActivityImpl(ActivityId act) + { + return BufferState::HasSpace; + } - virtual void resultImpl(ActivityId act, ResultType type, const Fields & fields) {}; + virtual BufferState resultImpl(ActivityId act, ResultType type, const Fields & fields) + { + return BufferState::HasSpace; + } public: virtual void writeToStdout(std::string_view s); @@ -216,6 +246,11 @@ public: ~Activity(); + Logger & getLogger() const + { + return *logger; + } + void swap(Activity & other) { std::swap(logger, other.logger); @@ -232,23 +267,29 @@ public: return logger->startActivity(level, type, s, fields, this); } - void progress(uint64_t done = 0, uint64_t expected = 0, uint64_t running = 0, uint64_t failed = 0) const - { result(resProgress, done, expected, running, failed); } + Logger::BufferState progress( + uint64_t done = 0, uint64_t expected = 0, uint64_t running = 0, uint64_t failed = 0 + ) const + { + return result(resProgress, done, expected, running, failed); + } - void setExpected(ActivityType type2, uint64_t expected) const - { result(resSetExpected, type2, expected); } + Logger::BufferState setExpected(ActivityType type2, uint64_t expected) const + { + return result(resSetExpected, type2, expected); + } template - void result(ResultType type, const Args & ... args) const + Logger::BufferState result(ResultType type, const Args &... args) const { Logger::Fields fields; nop{(fields.emplace_back(Logger::Field(args)), 1)...}; - result(type, fields); + return result(type, fields); } - void result(ResultType type, const Logger::Fields & fields) const + Logger::BufferState result(ResultType type, const Logger::Fields & fields) const { - logger->resultImpl(id, type, fields); + return logger->resultImpl(id, type, fields); } friend class Logger; @@ -265,49 +306,71 @@ Logger * makeJSONLogger(Logger & prevLogger); */ extern Verbosity verbosity; -#define ACTIVITY_PROGRESS(act, ...) \ - do { \ - auto && _lix_act = (act); \ - _lix_act.progress(__VA_ARGS__); \ +#define ACTIVITY_PROGRESS(act, ...) \ + do { \ + auto && _lix_act = (act); \ + if (_lix_act.progress(__VA_ARGS__) == ::nix::Logger::BufferState::NeedsFlush) { \ + LIX_TRY_AWAIT(_lix_act.getLogger().flush()); \ + } \ } while (0) -#define ACTIVITY_RESULT(act, ...) \ - do { \ - auto && _lix_act = (act); \ - _lix_act.result(__VA_ARGS__); \ +#define ACTIVITY_RESULT(act, ...) \ + do { \ + auto && _lix_act = (act); \ + if (_lix_act.result(__VA_ARGS__) == ::nix::Logger::BufferState::NeedsFlush) { \ + LIX_TRY_AWAIT(_lix_act.getLogger().flush()); \ + } \ } while (0) -#define ACTIVITY_SET_EXPECTED(act, ...) \ - do { \ - auto && _lix_act = (act); \ - _lix_act.setExpected(__VA_ARGS__); \ +#define ACTIVITY_SET_EXPECTED(act, ...) \ + do { \ + auto && _lix_act = (act); \ + if (_lix_act.setExpected(__VA_ARGS__) == ::nix::Logger::BufferState::NeedsFlush) { \ + LIX_TRY_AWAIT(_lix_act.getLogger().flush()); \ + } \ } while (0) -#define ACTIVITY_PROGRESS_SYNC(aio, act, ...) \ - do { \ - auto && _lix_act = (act); \ - _lix_act.progress(__VA_ARGS__); \ +#define ACTIVITY_PROGRESS_SYNC(aio, act, ...) \ + do { \ + auto && _lix_act = (act); \ + if (_lix_act.progress(__VA_ARGS__) == ::nix::Logger::BufferState::NeedsFlush) { \ + (aio).blockOn(_lix_act.getLogger().flush()); \ + } \ } while (0) -#define ACTIVITY_RESULT_SYNC(aio, act, ...) \ - do { \ - auto && _lix_act = (act); \ - _lix_act.result(__VA_ARGS__); \ +#define ACTIVITY_RESULT_SYNC(aio, act, ...) \ + do { \ + auto && _lix_act = (act); \ + if (_lix_act.result(__VA_ARGS__) == ::nix::Logger::BufferState::NeedsFlush) { \ + (aio).blockOn(_lix_act.getLogger().flush()); \ + } \ } while (0) -#define ACTIVITY_SET_EXPECTED_SYNC(aio, act, ...) \ - do { \ - auto && _lix_act = (act); \ - _lix_act.setExpected(__VA_ARGS__); \ +#define ACTIVITY_SET_EXPECTED_SYNC(aio, act, ...) \ + do { \ + auto && _lix_act = (act); \ + if (_lix_act.setExpected(__VA_ARGS__) == ::nix::Logger::BufferState::NeedsFlush) { \ + (aio).blockOn(_lix_act.getLogger().flush()); \ + } \ } while (0) +// NOTE: unlike activity progress updates we *do not* flush buffers for "normal" +// messages. the largest producers or log items are builds (which report logs as +// activity results), the curl thread (which can only wait after we have reached +// a buffer watermark, not actually flush it due to kj limitations), debug level +// log messages (which are not latency-sensitive), and interactive use (which we +// only ever run with a logger that writes directly to stderr). we have tried to +// add buffer flushing to these log macros, but it turned out to be *incredibly* +// invasive in many places to outright impossible in some, such as logError in a +// catch block (because c++ doesn't allow awaits in catch blocks). fucking mess. + /** * Print a message with the standard ErrorInfo format. * In general, use these 'log' macros for reporting problems that may require user * intervention or that need more explanation. Use the 'print' macros for more * lightweight status messages. */ -#define logErrorInfo(level, errorInfo...) \ - do { \ - if ((level) <= ::nix::verbosity) { \ - ::nix::logger->logEI((level), errorInfo); \ - } \ +#define logErrorInfo(level, errorInfo...) \ + do { \ + if ((level) <= ::nix::verbosity) { \ + (void) ::nix::logger->logEI((level), errorInfo); \ + } \ } while (0) #define logError(errorInfo...) logErrorInfo(::nix::lvlError, errorInfo) @@ -323,7 +386,8 @@ extern Verbosity verbosity; auto _lix_logger_print_lvl = level; \ const char * _lix_format = [](const char(&_lix_fs)[N]) { return _lix_fs; }(fs); \ if (_lix_logger_print_lvl <= ::nix::verbosity) { \ - loggerParam->log(_lix_logger_print_lvl, ::nix::HintFmt(_lix_format, ##args).str()); \ + (void \ + ) loggerParam->log(_lix_logger_print_lvl, ::nix::HintFmt(_lix_format, ##args).str()); \ } \ } while (0) #define printMsg(level, fs, args...) printMsgUsing(::nix::logger, level, fs, ##args) @@ -353,17 +417,24 @@ std::optional parseJSONMessage(const std::string & msg, std::string_view s /** * @param source A noun phrase describing the source of the message, e.g. "the builder". */ -bool handleJSONLogMessage(JSON & json, - const Activity & act, std::map & activities, +[[nodiscard]] +std::optional handleJSONLogMessage( + JSON & json, + const Activity & act, + std::map & activities, std::string_view source, - bool trusted); + bool trusted +); /** * @param source A noun phrase describing the source of the message, e.g. "the builder". */ -bool handleJSONLogMessage(const std::string & msg, - const Activity & act, std::map & activities, +[[nodiscard]] +std::optional handleJSONLogMessage( + const std::string & msg, + const Activity & act, + std::map & activities, std::string_view source, - bool trusted); - + bool trusted +); } diff --git a/tests/unit/libexpr/primops.cc b/tests/unit/libexpr/primops.cc index 6669d1cf1..4e3c4072a 100644 --- a/tests/unit/libexpr/primops.cc +++ b/tests/unit/libexpr/primops.cc @@ -3,6 +3,7 @@ #include "lix/libexpr/eval-settings.hh" +#include "lix/libutil/logging.hh" #include "tests/libexpr.hh" namespace nix { @@ -17,12 +18,16 @@ namespace nix { return oss.str(); } - void log(Verbosity lvl, std::string_view s) override { + BufferState log(Verbosity lvl, std::string_view s) override + { oss << s << std::endl; + return BufferState::HasSpace; } - void logEI(const ErrorInfo & ei) override { + BufferState logEI(const ErrorInfo & ei) override + { showErrorInfo(oss, ei, loggerSettings.showTrace.get()); + return BufferState::HasSpace; } }; diff --git a/tests/unit/libmain/progress-bar.cc b/tests/unit/libmain/progress-bar.cc index eb4a2acbb..1187bee28 100644 --- a/tests/unit/libmain/progress-bar.cc +++ b/tests/unit/libmain/progress-bar.cc @@ -34,7 +34,7 @@ namespace nix fmt("downloading '%s'", TEST_URL), {"https://github.com/NixOS/nixpkgs/archive/master.tar.gz"} ); - act.progress(TEST_DONE, TEST_EXPECTED); + (void) act.progress(TEST_DONE, TEST_EXPECTED); auto state = progressBar.state_.lock(); std::string const renderedStatus = progressBar.getStatus(*state); diff --git a/tests/unit/libstore/filetransfer.cc b/tests/unit/libstore/filetransfer.cc index a1d584cd3..7d4f227a8 100644 --- a/tests/unit/libstore/filetransfer.cc +++ b/tests/unit/libstore/filetransfer.cc @@ -431,15 +431,17 @@ TEST(FileTransfer, DISABLED_interrupt) { struct InterruptingLogger : Logger { - void log(Verbosity lvl, std::string_view s) override + BufferState log(Verbosity lvl, std::string_view s) override { if (s.starts_with("finished") && s.ends_with("body = 10 bytes")) { triggerInterrupt(); checkInterrupt(); } + return BufferState::HasSpace; } - void logEI(const ErrorInfo & ei) override + BufferState logEI(const ErrorInfo & ei) override { + return BufferState::HasSpace; } };