From 1212b1fbfeee93ce7a04911a4085d796d6d9c72a Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Mon, 17 Feb 2025 14:59:07 +0100 Subject: [PATCH 01/22] JSONLogger: Log to a file descriptor instead of another Logger Logging to another Logger was kind of nonsensical - it was really just an easy way to get it to write its output to stderr, but that only works if the underlying logger writes to stderr. This change is needed to make it easy to log JSON output somewhere else (like a file or socket). --- src/build-remote/build-remote.cc | 2 +- src/libmain/loggers.cc | 2 +- src/libstore/unix/build/local-derivation-goal.cc | 2 +- src/libutil/logging.cc | 10 +++++----- src/libutil/logging.hh | 3 ++- 5 files changed, 10 insertions(+), 9 deletions(-) diff --git a/src/build-remote/build-remote.cc b/src/build-remote/build-remote.cc index 82ad7d862..2c3176724 100644 --- a/src/build-remote/build-remote.cc +++ b/src/build-remote/build-remote.cc @@ -51,7 +51,7 @@ static bool allSupportedLocally(Store & store, const std::set& requ static int main_build_remote(int argc, char * * argv) { { - logger = makeJSONLogger(*logger); + logger = makeJSONLogger(STDERR_FILENO); /* Ensure we don't get any SSH passphrase or host key popups. */ unsetenv("DISPLAY"); diff --git a/src/libmain/loggers.cc b/src/libmain/loggers.cc index a4e0530c8..ede5ddae3 100644 --- a/src/libmain/loggers.cc +++ b/src/libmain/loggers.cc @@ -27,7 +27,7 @@ Logger * makeDefaultLogger() { case LogFormat::rawWithLogs: return makeSimpleLogger(true); case LogFormat::internalJSON: - return makeJSONLogger(*makeSimpleLogger(true)); + return makeJSONLogger(STDERR_FILENO); case LogFormat::bar: return makeProgressBar(); case LogFormat::barWithLogs: { diff --git a/src/libstore/unix/build/local-derivation-goal.cc b/src/libstore/unix/build/local-derivation-goal.cc index 5b9bc0bb0..805c3bbca 100644 --- a/src/libstore/unix/build/local-derivation-goal.cc +++ b/src/libstore/unix/build/local-derivation-goal.cc @@ -2219,7 +2219,7 @@ void LocalDerivationGoal::runChild() /* Execute the program. This should not return. */ if (drv->isBuiltin()) { try { - logger = makeJSONLogger(*logger); + logger = makeJSONLogger(STDERR_FILENO); std::map outputs; for (auto & e : drv->outputs) diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index a5add5565..9caa83efe 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -167,9 +167,9 @@ void to_json(nlohmann::json & json, std::shared_ptr pos) } struct JSONLogger : Logger { - Logger & prevLogger; + Descriptor fd; - JSONLogger(Logger & prevLogger) : prevLogger(prevLogger) { } + JSONLogger(Descriptor fd) : fd(fd) { } bool isVerbose() override { return true; @@ -190,7 +190,7 @@ struct JSONLogger : Logger { void write(const nlohmann::json & json) { - prevLogger.log(lvlError, "@nix " + json.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace)); + writeLine(fd, "@nix " + json.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace)); } void log(Verbosity lvl, std::string_view s) override @@ -262,9 +262,9 @@ struct JSONLogger : Logger { } }; -Logger * makeJSONLogger(Logger & prevLogger) +Logger * makeJSONLogger(Descriptor fd) { - return new JSONLogger(prevLogger); + return new JSONLogger(fd); } static Logger::Fields getFields(nlohmann::json & json) diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index 11e4033a5..e8112c6b0 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -3,6 +3,7 @@ #include "error.hh" #include "config.hh" +#include "file-descriptor.hh" #include @@ -183,7 +184,7 @@ extern Logger * logger; Logger * makeSimpleLogger(bool printBuildLogs = true); -Logger * makeJSONLogger(Logger & prevLogger); +Logger * makeJSONLogger(Descriptor fd); /** * @param source A noun phrase describing the source of the message, e.g. "the builder". From 8ef94c111413ce14a7f69dfe643e69dde2e724e3 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Mon, 17 Feb 2025 14:40:50 +0100 Subject: [PATCH 02/22] Add a structured log message for FOD hash mismatches --- src/libstore/unix/build/local-derivation-goal.cc | 6 ++++++ src/libutil/logging.hh | 1 + 2 files changed, 7 insertions(+) diff --git a/src/libstore/unix/build/local-derivation-goal.cc b/src/libstore/unix/build/local-derivation-goal.cc index 805c3bbca..9ab0da32b 100644 --- a/src/libstore/unix/build/local-derivation-goal.cc +++ b/src/libstore/unix/build/local-derivation-goal.cc @@ -2656,6 +2656,12 @@ SingleDrvOutputs LocalDerivationGoal::registerOutputs() worker.store.printStorePath(drvPath), wanted.to_string(HashFormat::SRI, true), got.to_string(HashFormat::SRI, true))); + // FIXME: put this in BuildResult and log that as JSON. + act->result(resHashMismatch, + {worker.store.printStorePath(drvPath), + wanted.to_string(HashFormat::SRI, true), + got.to_string(HashFormat::SRI, true) + }); } if (!newInfo0.references.empty()) { auto numViolations = newInfo.references.size(); diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index e8112c6b0..21493b969 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -36,6 +36,7 @@ typedef enum { resSetExpected = 106, resPostBuildLogLine = 107, resFetchStatus = 108, + resHashMismatch = 109, } ResultType; typedef uint64_t ActivityId; From 1f702cdb0166a9f3b03f931b27c6bd000c223eb3 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Mon, 17 Feb 2025 16:36:02 +0100 Subject: [PATCH 03/22] Allow separate JSON logging If the NIX_LOG_FILE environment variable is set, Nix will write JSON log messages to that file in addition to the regular logger (e.g. the progress bar). --- src/libutil/logging.cc | 18 +++++++ src/libutil/logging.hh | 6 +++ src/libutil/meson.build | 1 + src/libutil/tee-logger.cc | 102 ++++++++++++++++++++++++++++++++++++++ src/nix/main.cc | 4 ++ 5 files changed, 131 insertions(+) create mode 100644 src/libutil/tee-logger.cc diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index 9caa83efe..0bffe40e3 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -267,6 +267,24 @@ Logger * makeJSONLogger(Descriptor fd) return new JSONLogger(fd); } +Logger * makeJSONLogger(const std::filesystem::path & path) +{ + struct JSONFileLogger : JSONLogger { + AutoCloseFD fd; + + JSONFileLogger(AutoCloseFD && fd) + : JSONLogger(fd.get()) + , fd(std::move(fd)) + { } + }; + + auto fd{toDescriptor(open(path.c_str(), O_CREAT | O_APPEND | O_WRONLY, 0644))}; + if (!fd) + throw SysError("opening log file '%1%'", path); + + return new JSONFileLogger(std::move(fd)); +} + static Logger::Fields getFields(nlohmann::json & json) { Logger::Fields fields; diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index 21493b969..cadeafea4 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -5,6 +5,8 @@ #include "config.hh" #include "file-descriptor.hh" +#include + #include namespace nix { @@ -185,8 +187,12 @@ extern Logger * logger; Logger * makeSimpleLogger(bool printBuildLogs = true); +Logger * makeTeeLogger(std::vector loggers); + Logger * makeJSONLogger(Descriptor fd); +Logger * makeJSONLogger(const std::filesystem::path & path); + /** * @param source A noun phrase describing the source of the message, e.g. "the builder". */ diff --git a/src/libutil/meson.build b/src/libutil/meson.build index ac701d8fd..d5855442d 100644 --- a/src/libutil/meson.build +++ b/src/libutil/meson.build @@ -158,6 +158,7 @@ sources = files( 'strings.cc', 'suggestions.cc', 'tarfile.cc', + 'tee-logger.cc', 'terminal.cc', 'thread-pool.cc', 'unix-domain-socket.cc', diff --git a/src/libutil/tee-logger.cc b/src/libutil/tee-logger.cc new file mode 100644 index 000000000..7a5115ea7 --- /dev/null +++ b/src/libutil/tee-logger.cc @@ -0,0 +1,102 @@ +#include "logging.hh" + +namespace nix { + +struct TeeLogger : Logger +{ + std::vector loggers; + + TeeLogger(std::vector loggers) + : loggers(std::move(loggers)) + { + } + + void stop() override + { + for (auto & logger : loggers) + logger->stop(); + }; + + void pause() override + { + for (auto & logger : loggers) + logger->pause(); + }; + + void resume() override + { + for (auto & logger : loggers) + logger->resume(); + }; + + void log(Verbosity lvl, std::string_view s) override + { + for (auto & logger : loggers) + logger->log(lvl, s); + } + + void logEI(const ErrorInfo & ei) override + { + for (auto & logger : loggers) + logger->logEI(ei); + } + + void startActivity( + ActivityId act, + Verbosity lvl, + ActivityType type, + const std::string & s, + const Fields & fields, + ActivityId parent) override + { + for (auto & logger : loggers) + logger->startActivity(act, lvl, type, s, fields, parent); + } + + void stopActivity(ActivityId act) override + { + for (auto & logger : loggers) + logger->stopActivity(act); + } + + void result(ActivityId act, ResultType type, const Fields & fields) override + { + for (auto & logger : loggers) + logger->result(act, type, fields); + } + + void writeToStdout(std::string_view s) override + { + for (auto & logger : loggers) { + /* Let only the first logger write to stdout to avoid + duplication. This means that the first logger needs to + be the one managing stdout/stderr + (e.g. `ProgressBar`). */ + logger->writeToStdout(s); + break; + } + } + + std::optional ask(std::string_view s) override + { + for (auto & logger : loggers) { + auto c = logger->ask(s); + if (c) + return c; + } + return std::nullopt; + } + + void setPrintBuildLogs(bool printBuildLogs) override + { + for (auto & logger : loggers) + logger->setPrintBuildLogs(printBuildLogs); + } +}; + +Logger * makeTeeLogger(std::vector loggers) +{ + return new TeeLogger(std::move(loggers)); +} + +} diff --git a/src/nix/main.cc b/src/nix/main.cc index f8f9d03a4..5f83e997c 100644 --- a/src/nix/main.cc +++ b/src/nix/main.cc @@ -485,6 +485,10 @@ void mainWrapped(int argc, char * * argv) if (!args.helpRequested && !args.completions) throw; } + if (auto logFile = getEnv("NIX_LOG_FILE")) { + logger = makeTeeLogger({logger, makeJSONLogger(*logFile)}); + } + if (args.helpRequested) { std::vector subcommand; MultiCommand * command = &args; From 2972e7394606650ed2ed4669ea79581817294a72 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 13 Mar 2025 13:15:14 +0100 Subject: [PATCH 04/22] Turn NIX_LOG_FILE into a setting --- src/nix/main.cc | 19 +++++++++++++++++-- 1 file changed, 17 insertions(+), 2 deletions(-) diff --git a/src/nix/main.cc b/src/nix/main.cc index 5f83e997c..10a02fe3f 100644 --- a/src/nix/main.cc +++ b/src/nix/main.cc @@ -5,6 +5,7 @@ #include "eval.hh" #include "eval-settings.hh" #include "globals.hh" +#include "config-global.hh" #include "legacy.hh" #include "shared.hh" #include "store-api.hh" @@ -347,6 +348,20 @@ struct CmdHelpStores : Command static auto rCmdHelpStores = registerCommand("help-stores"); +struct ExtLoggerSettings : Config +{ + Setting jsonLogPath{ + this, "", "json-log-path", + R"( + A path to which JSON records of Nix's log output will be + written, in the same format as `--log-format internal-json`. + )"}; +}; + +static ExtLoggerSettings extLoggerSettings; + +static GlobalConfig::Register rExtLoggerSettings(&extLoggerSettings); + void mainWrapped(int argc, char * * argv) { savedArgv = argv; @@ -485,8 +500,8 @@ void mainWrapped(int argc, char * * argv) if (!args.helpRequested && !args.completions) throw; } - if (auto logFile = getEnv("NIX_LOG_FILE")) { - logger = makeTeeLogger({logger, makeJSONLogger(*logFile)}); + if (!extLoggerSettings.jsonLogPath.get().empty()) { + logger = makeTeeLogger({logger, makeJSONLogger(std::filesystem::path(extLoggerSettings.jsonLogPath.get()))}); } if (args.helpRequested) { From 29a9e638c1bf70eb5f57bf8c6b78de71293cdedf Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 13 Mar 2025 13:37:38 +0100 Subject: [PATCH 05/22] Remove "@nix" prefix from json-log-path output --- src/libutil/logging.cc | 22 ++++++++++++++-------- src/libutil/logging.hh | 4 ++-- src/nix/main.cc | 5 +++-- 3 files changed, 19 insertions(+), 12 deletions(-) diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index 0bffe40e3..fcbc61d5e 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -168,8 +168,12 @@ void to_json(nlohmann::json & json, std::shared_ptr pos) struct JSONLogger : Logger { Descriptor fd; + bool includeNixPrefix; - JSONLogger(Descriptor fd) : fd(fd) { } + JSONLogger(Descriptor fd, bool includeNixPrefix) + : fd(fd) + , includeNixPrefix(includeNixPrefix) + { } bool isVerbose() override { return true; @@ -190,7 +194,9 @@ struct JSONLogger : Logger { void write(const nlohmann::json & json) { - writeLine(fd, "@nix " + json.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace)); + writeLine(fd, + (includeNixPrefix ? "@nix " : "") + + json.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace)); } void log(Verbosity lvl, std::string_view s) override @@ -262,18 +268,18 @@ struct JSONLogger : Logger { } }; -Logger * makeJSONLogger(Descriptor fd) +Logger * makeJSONLogger(Descriptor fd, bool includeNixPrefix) { - return new JSONLogger(fd); + return new JSONLogger(fd, includeNixPrefix); } -Logger * makeJSONLogger(const std::filesystem::path & path) +Logger * makeJSONLogger(const std::filesystem::path & path, bool includeNixPrefix) { struct JSONFileLogger : JSONLogger { AutoCloseFD fd; - JSONFileLogger(AutoCloseFD && fd) - : JSONLogger(fd.get()) + JSONFileLogger(AutoCloseFD && fd, bool includeNixPrefix) + : JSONLogger(fd.get(), includeNixPrefix) , fd(std::move(fd)) { } }; @@ -282,7 +288,7 @@ Logger * makeJSONLogger(const std::filesystem::path & path) if (!fd) throw SysError("opening log file '%1%'", path); - return new JSONFileLogger(std::move(fd)); + return new JSONFileLogger(std::move(fd), includeNixPrefix); } static Logger::Fields getFields(nlohmann::json & json) diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index cadeafea4..ef449d03e 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -189,9 +189,9 @@ Logger * makeSimpleLogger(bool printBuildLogs = true); Logger * makeTeeLogger(std::vector loggers); -Logger * makeJSONLogger(Descriptor fd); +Logger * makeJSONLogger(Descriptor fd, bool includeNixPrefix = true); -Logger * makeJSONLogger(const std::filesystem::path & path); +Logger * makeJSONLogger(const std::filesystem::path & path, bool includeNixPrefix = true); /** * @param source A noun phrase describing the source of the message, e.g. "the builder". diff --git a/src/nix/main.cc b/src/nix/main.cc index 10a02fe3f..68137a216 100644 --- a/src/nix/main.cc +++ b/src/nix/main.cc @@ -354,7 +354,8 @@ struct ExtLoggerSettings : Config this, "", "json-log-path", R"( A path to which JSON records of Nix's log output will be - written, in the same format as `--log-format internal-json`. + written, in the same format as `--log-format internal-json` + (without the `@nix ` prefixes on each line). )"}; }; @@ -501,7 +502,7 @@ void mainWrapped(int argc, char * * argv) } if (!extLoggerSettings.jsonLogPath.get().empty()) { - logger = makeTeeLogger({logger, makeJSONLogger(std::filesystem::path(extLoggerSettings.jsonLogPath.get()))}); + logger = makeTeeLogger({logger, makeJSONLogger(std::filesystem::path(extLoggerSettings.jsonLogPath.get()), false)}); } if (args.helpRequested) { From 1efccf34b12ceaf3565bd70b8c3b3465e65d4a18 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 13 Mar 2025 13:58:35 +0100 Subject: [PATCH 06/22] JSONLogger: Acquire a lock to prevent log messages from clobbering each other --- src/libutil/logging.cc | 16 ++++++++++++++-- 1 file changed, 14 insertions(+), 2 deletions(-) diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index fcbc61d5e..c3ccfba42 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -6,6 +6,7 @@ #include "config-global.hh" #include "source-path.hh" #include "position.hh" +#include "sync.hh" #include #include @@ -192,11 +193,22 @@ struct JSONLogger : Logger { unreachable(); } + struct State + { + }; + + Sync _state; + void write(const nlohmann::json & json) { - writeLine(fd, + auto line = (includeNixPrefix ? "@nix " : "") + - json.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace)); + json.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace); + + /* Acquire a lock to prevent log messages from clobbering each + other. */ + auto state(_state.lock()); + writeLine(fd, line); } void log(Verbosity lvl, std::string_view s) override From d9730fc93b61c864fb73fae887a2d9bd102f0221 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 13 Mar 2025 15:42:17 +0100 Subject: [PATCH 07/22] Fix fd check --- src/libutil/logging.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index c3ccfba42..8ef7a3612 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -296,7 +296,7 @@ Logger * makeJSONLogger(const std::filesystem::path & path, bool includeNixPrefi { } }; - auto fd{toDescriptor(open(path.c_str(), O_CREAT | O_APPEND | O_WRONLY, 0644))}; + AutoCloseFD fd{toDescriptor(open(path.c_str(), O_CREAT | O_APPEND | O_WRONLY, 0644))}; if (!fd) throw SysError("opening log file '%1%'", path); From 220000dc1aaa1157862ea287542092eeab14111a Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 13 Mar 2025 15:48:52 +0100 Subject: [PATCH 08/22] makeJSONLogger(): Support logging to a Unix domain socket --- src/libstore/uds-remote-store.cc | 4 +--- src/libutil/logging.cc | 6 +++++- src/libutil/unix-domain-socket.cc | 7 +++++++ src/libutil/unix-domain-socket.hh | 5 +++++ 4 files changed, 18 insertions(+), 4 deletions(-) diff --git a/src/libstore/uds-remote-store.cc b/src/libstore/uds-remote-store.cc index 3c445eb13..93c48c0e6 100644 --- a/src/libstore/uds-remote-store.cc +++ b/src/libstore/uds-remote-store.cc @@ -84,9 +84,7 @@ ref UDSRemoteStore::openConnection() auto conn = make_ref(); /* Connect to a daemon that does the privileged work for us. */ - conn->fd = createUnixDomainSocket(); - - nix::connect(toSocket(conn->fd.get()), path); + conn->fd = nix::connect(path); conn->from.fd = conn->fd.get(); conn->to.fd = conn->fd.get(); diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index 8ef7a3612..94683cca5 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -7,6 +7,7 @@ #include "source-path.hh" #include "position.hh" #include "sync.hh" +#include "unix-domain-socket.hh" #include #include @@ -296,7 +297,10 @@ Logger * makeJSONLogger(const std::filesystem::path & path, bool includeNixPrefi { } }; - AutoCloseFD fd{toDescriptor(open(path.c_str(), O_CREAT | O_APPEND | O_WRONLY, 0644))}; + AutoCloseFD fd = + std::filesystem::is_socket(path) + ? connect(path) + : toDescriptor(open(path.c_str(), O_CREAT | O_APPEND | O_WRONLY, 0644)); if (!fd) throw SysError("opening log file '%1%'", path); diff --git a/src/libutil/unix-domain-socket.cc b/src/libutil/unix-domain-socket.cc index 1707fdb75..0a7af1308 100644 --- a/src/libutil/unix-domain-socket.cc +++ b/src/libutil/unix-domain-socket.cc @@ -114,4 +114,11 @@ void connect(Socket fd, const std::string & path) bindConnectProcHelper("connect", ::connect, fd, path); } +AutoCloseFD connect(const std::filesystem::path & path) +{ + auto fd = createUnixDomainSocket(); + nix::connect(toSocket(fd.get()), path); + return fd; +} + } diff --git a/src/libutil/unix-domain-socket.hh b/src/libutil/unix-domain-socket.hh index ba2baeb13..e0d934011 100644 --- a/src/libutil/unix-domain-socket.hh +++ b/src/libutil/unix-domain-socket.hh @@ -80,4 +80,9 @@ void bind(Socket fd, const std::string & path); */ void connect(Socket fd, const std::string & path); +/** + * Connect to a Unix domain socket. + */ +AutoCloseFD connect(const std::filesystem::path & path); + } From 2a2af3f72f1841a67d06120d0be5553fddda71d7 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 13 Mar 2025 18:23:00 +0100 Subject: [PATCH 09/22] Logger::result(): Support logging arbitrary JSON objects --- src/libstore/unix/build/local-derivation-goal.cc | 8 ++++---- src/libutil/logging.cc | 10 ++++++++++ src/libutil/logging.hh | 7 +++++++ src/libutil/tee-logger.cc | 6 ++++++ 4 files changed, 27 insertions(+), 4 deletions(-) diff --git a/src/libstore/unix/build/local-derivation-goal.cc b/src/libstore/unix/build/local-derivation-goal.cc index 9ab0da32b..ec06c2044 100644 --- a/src/libstore/unix/build/local-derivation-goal.cc +++ b/src/libstore/unix/build/local-derivation-goal.cc @@ -2656,11 +2656,11 @@ SingleDrvOutputs LocalDerivationGoal::registerOutputs() worker.store.printStorePath(drvPath), wanted.to_string(HashFormat::SRI, true), got.to_string(HashFormat::SRI, true))); - // FIXME: put this in BuildResult and log that as JSON. act->result(resHashMismatch, - {worker.store.printStorePath(drvPath), - wanted.to_string(HashFormat::SRI, true), - got.to_string(HashFormat::SRI, true) + { + {"storePath", worker.store.printStorePath(drvPath)}, + {"wanted", wanted.to_string(HashFormat::SRI, true)}, + {"got", got.to_string(HashFormat::SRI, true)}, }); } if (!newInfo0.references.empty()) { diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index 94683cca5..c7b859bd5 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -279,6 +279,16 @@ struct JSONLogger : Logger { addFields(json, fields); write(json); } + + void result(ActivityId act, ResultType type, const nlohmann::json & j) override + { + nlohmann::json json; + json["action"] = "result"; + json["id"] = act; + json["type"] = type; + json["payload"] = j; + write(json); + } }; Logger * makeJSONLogger(Descriptor fd, bool includeNixPrefix) diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index ef449d03e..9d655f735 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -108,6 +108,8 @@ public: virtual void result(ActivityId act, ResultType type, const Fields & fields) { }; + virtual void result(ActivityId act, ResultType type, const nlohmann::json & json) { }; + virtual void writeToStdout(std::string_view s); template @@ -160,6 +162,11 @@ struct Activity void setExpected(ActivityType type2, uint64_t expected) const { result(resSetExpected, type2, expected); } + void result(ResultType type, const nlohmann::json & json) const + { + logger.result(id, type, json); + } + template void result(ResultType type, const Args & ... args) const { diff --git a/src/libutil/tee-logger.cc b/src/libutil/tee-logger.cc index 7a5115ea7..c9873a53a 100644 --- a/src/libutil/tee-logger.cc +++ b/src/libutil/tee-logger.cc @@ -65,6 +65,12 @@ struct TeeLogger : Logger logger->result(act, type, fields); } + void result(ActivityId act, ResultType type, const nlohmann::json & json) override + { + for (auto & logger : loggers) + logger->result(act, type, json); + } + void writeToStdout(std::string_view s) override { for (auto & logger : loggers) { From c515bc66f1d8941290ef448eea4661b741a8fcc7 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 13 Mar 2025 18:52:29 +0100 Subject: [PATCH 10/22] Provide a structured JSON serialisation of hashes --- src/libstore/unix/build/local-derivation-goal.cc | 4 ++-- src/libutil/hash.cc | 11 +++++++++++ src/libutil/hash.hh | 6 ++++++ 3 files changed, 19 insertions(+), 2 deletions(-) diff --git a/src/libstore/unix/build/local-derivation-goal.cc b/src/libstore/unix/build/local-derivation-goal.cc index ec06c2044..cb3d4a04f 100644 --- a/src/libstore/unix/build/local-derivation-goal.cc +++ b/src/libstore/unix/build/local-derivation-goal.cc @@ -2659,8 +2659,8 @@ SingleDrvOutputs LocalDerivationGoal::registerOutputs() act->result(resHashMismatch, { {"storePath", worker.store.printStorePath(drvPath)}, - {"wanted", wanted.to_string(HashFormat::SRI, true)}, - {"got", got.to_string(HashFormat::SRI, true)}, + {"wanted", wanted}, + {"got", got}, }); } if (!newInfo0.references.empty()) { diff --git a/src/libutil/hash.cc b/src/libutil/hash.cc index b69dec685..9668800af 100644 --- a/src/libutil/hash.cc +++ b/src/libutil/hash.cc @@ -14,6 +14,8 @@ #include #include +#include + #include namespace nix { @@ -456,4 +458,13 @@ std::string_view printHashAlgo(HashAlgorithm ha) } } +void to_json(nlohmann::json & json, const Hash & hash) +{ + json = nlohmann::json::object( + { + {"algo", printHashAlgo(hash.algo)}, + {"base16", hash.to_string(HashFormat::Base16, false)}, + }); +} + } diff --git a/src/libutil/hash.hh b/src/libutil/hash.hh index dc95b9f2f..3ef7e8b14 100644 --- a/src/libutil/hash.hh +++ b/src/libutil/hash.hh @@ -5,6 +5,8 @@ #include "serialise.hh" #include "file-system.hh" +#include + namespace nix { @@ -209,6 +211,10 @@ std::optional parseHashAlgoOpt(std::string_view s); */ std::string_view printHashAlgo(HashAlgorithm ha); +/** + * Write a JSON serialisation of the format `{"algo":"","base16":""}`. + */ +void to_json(nlohmann::json & json, const Hash & hash); union Ctx; From 762114b7c4d28027cdc7a673035f87664cc0fe68 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 13 Mar 2025 19:42:52 +0100 Subject: [PATCH 11/22] Log BuildResult --- src/libstore/build-result.cc | 25 ++++++++++++ src/libstore/build-result.hh | 52 +++++++++++++++---------- src/libstore/build/derivation-goal.cc | 7 ++++ src/libstore/build/substitution-goal.cc | 11 ++++++ src/libutil/logging.hh | 1 + 5 files changed, 75 insertions(+), 21 deletions(-) diff --git a/src/libstore/build-result.cc b/src/libstore/build-result.cc index 96cbfd62f..3e316f679 100644 --- a/src/libstore/build-result.cc +++ b/src/libstore/build-result.cc @@ -1,8 +1,33 @@ #include "build-result.hh" +#include + namespace nix { bool BuildResult::operator==(const BuildResult &) const noexcept = default; std::strong_ordering BuildResult::operator<=>(const BuildResult &) const noexcept = default; +void to_json(nlohmann::json & json, const BuildResult & buildResult) +{ + json = nlohmann::json::object(); + json["status"] = BuildResult::statusToString(buildResult.status); + if (buildResult.errorMsg != "") + json["errorMsg"] = buildResult.errorMsg; + if (buildResult.timesBuilt) + json["timesBuilt"] = buildResult.timesBuilt; + if (buildResult.isNonDeterministic) + json["isNonDeterministic"] = buildResult.isNonDeterministic; + if (buildResult.startTime) + json["startTime"] = buildResult.startTime; + if (buildResult.stopTime) + json["stopTime"] = buildResult.stopTime; +} + +nlohmann::json KeyedBuildResult::toJSON(Store & store) const +{ + auto json = nlohmann::json((const BuildResult &) *this); + json["path"] = path.toJSON(store); + return json; +} + } diff --git a/src/libstore/build-result.hh b/src/libstore/build-result.hh index 8c66cfeb3..f56817f19 100644 --- a/src/libstore/build-result.hh +++ b/src/libstore/build-result.hh @@ -8,6 +8,8 @@ #include #include +#include + namespace nix { struct BuildResult @@ -46,28 +48,32 @@ struct BuildResult */ std::string errorMsg; + static std::string_view statusToString(Status status) + { + switch (status) { + case Built: return "Built"; + case Substituted: return "Substituted"; + case AlreadyValid: return "AlreadyValid"; + case PermanentFailure: return "PermanentFailure"; + case InputRejected: return "InputRejected"; + case OutputRejected: return "OutputRejected"; + case TransientFailure: return "TransientFailure"; + case CachedFailure: return "CachedFailure"; + case TimedOut: return "TimedOut"; + case MiscFailure: return "MiscFailure"; + case DependencyFailed: return "DependencyFailed"; + case LogLimitExceeded: return "LogLimitExceeded"; + case NotDeterministic: return "NotDeterministic"; + case ResolvesToAlreadyValid: return "ResolvesToAlreadyValid"; + case NoSubstituters: return "NoSubstituters"; + default: return "Unknown"; + }; + } + std::string toString() const { - auto strStatus = [&]() { - switch (status) { - case Built: return "Built"; - case Substituted: return "Substituted"; - case AlreadyValid: return "AlreadyValid"; - case PermanentFailure: return "PermanentFailure"; - case InputRejected: return "InputRejected"; - case OutputRejected: return "OutputRejected"; - case TransientFailure: return "TransientFailure"; - case CachedFailure: return "CachedFailure"; - case TimedOut: return "TimedOut"; - case MiscFailure: return "MiscFailure"; - case DependencyFailed: return "DependencyFailed"; - case LogLimitExceeded: return "LogLimitExceeded"; - case NotDeterministic: return "NotDeterministic"; - case ResolvesToAlreadyValid: return "ResolvesToAlreadyValid"; - case NoSubstituters: return "NoSubstituters"; - default: return "Unknown"; - }; - }(); - return strStatus + ((errorMsg == "") ? "" : " : " + errorMsg); + return + std::string(statusToString(status)) + + ((errorMsg == "") ? "" : " : " + errorMsg); } /** @@ -128,6 +134,10 @@ struct KeyedBuildResult : BuildResult KeyedBuildResult(BuildResult res, DerivedPath path) : BuildResult(std::move(res)), path(std::move(path)) { } + + nlohmann::json toJSON(Store & store) const; }; +void to_json(nlohmann::json & json, const BuildResult & buildResult); + } diff --git a/src/libstore/build/derivation-goal.cc b/src/libstore/build/derivation-goal.cc index 714dc87c8..6c335e17c 100644 --- a/src/libstore/build/derivation-goal.cc +++ b/src/libstore/build/derivation-goal.cc @@ -1563,6 +1563,13 @@ Goal::Done DerivationGoal::done( fs << worker.store.printStorePath(drvPath) << "\t" << buildResult.toString() << std::endl; } + logger->result( + act ? act->id : getCurActivity(), + resBuildResult, + KeyedBuildResult( + buildResult, + DerivedPath::Built{.drvPath = makeConstantStorePathRef(drvPath), .outputs = wantedOutputs}).toJSON(worker.store)); + return amDone(buildResult.success() ? ecSuccess : ecFailed, std::move(ex)); } diff --git a/src/libstore/build/substitution-goal.cc b/src/libstore/build/substitution-goal.cc index 983c86601..625e64781 100644 --- a/src/libstore/build/substitution-goal.cc +++ b/src/libstore/build/substitution-goal.cc @@ -3,8 +3,11 @@ #include "nar-info.hh" #include "finally.hh" #include "signals.hh" + #include +#include + namespace nix { PathSubstitutionGoal::PathSubstitutionGoal(const StorePath & storePath, Worker & worker, RepairFlag repair, std::optional ca) @@ -35,6 +38,14 @@ Goal::Done PathSubstitutionGoal::done( debug(*errorMsg); buildResult.errorMsg = *errorMsg; } + + logger->result( + getCurActivity(), + resBuildResult, + KeyedBuildResult( + buildResult, + DerivedPath::Opaque{storePath}).toJSON(worker.store)); + return amDone(result); } diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index 9d655f735..aeb058526 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -39,6 +39,7 @@ typedef enum { resPostBuildLogLine = 107, resFetchStatus = 108, resHashMismatch = 109, + resBuildResult = 110, } ResultType; typedef uint64_t ActivityId; From fd0d824fa5b3ed367903d49efd75c30d886de6a5 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Fri, 14 Mar 2025 17:05:38 +0100 Subject: [PATCH 12/22] Don't use DerivedPath::toJSON() It doesn't work on unrealized paths. --- src/libstore/build-result.cc | 17 +++++++++++++---- src/libstore/build-result.hh | 3 +-- src/libstore/build/derivation-goal.cc | 7 ++++--- src/libstore/build/substitution-goal.cc | 7 ++++--- 4 files changed, 22 insertions(+), 12 deletions(-) diff --git a/src/libstore/build-result.cc b/src/libstore/build-result.cc index 3e316f679..e6469e38f 100644 --- a/src/libstore/build-result.cc +++ b/src/libstore/build-result.cc @@ -23,11 +23,20 @@ void to_json(nlohmann::json & json, const BuildResult & buildResult) json["stopTime"] = buildResult.stopTime; } -nlohmann::json KeyedBuildResult::toJSON(Store & store) const +void to_json(nlohmann::json & json, const KeyedBuildResult & buildResult) { - auto json = nlohmann::json((const BuildResult &) *this); - json["path"] = path.toJSON(store); - return json; + to_json(json, (const BuildResult &) buildResult); + auto path = nlohmann::json::object(); + std::visit( + overloaded{ + [&](const DerivedPathOpaque & opaque) { path["opaque"] = opaque.path.to_string(); }, + [&](const DerivedPathBuilt & drv) { + path["drvPath"] = drv.drvPath->getBaseStorePath().to_string(); + path["outputs"] = drv.outputs.to_string(); + }, + }, + buildResult.path.raw()); + json["path"] = std::move(path); } } diff --git a/src/libstore/build-result.hh b/src/libstore/build-result.hh index f56817f19..44862980d 100644 --- a/src/libstore/build-result.hh +++ b/src/libstore/build-result.hh @@ -134,10 +134,9 @@ struct KeyedBuildResult : BuildResult KeyedBuildResult(BuildResult res, DerivedPath path) : BuildResult(std::move(res)), path(std::move(path)) { } - - nlohmann::json toJSON(Store & store) const; }; void to_json(nlohmann::json & json, const BuildResult & buildResult); +void to_json(nlohmann::json & json, const KeyedBuildResult & buildResult); } diff --git a/src/libstore/build/derivation-goal.cc b/src/libstore/build/derivation-goal.cc index 6c335e17c..a32dc5e53 100644 --- a/src/libstore/build/derivation-goal.cc +++ b/src/libstore/build/derivation-goal.cc @@ -1566,9 +1566,10 @@ Goal::Done DerivationGoal::done( logger->result( act ? act->id : getCurActivity(), resBuildResult, - KeyedBuildResult( - buildResult, - DerivedPath::Built{.drvPath = makeConstantStorePathRef(drvPath), .outputs = wantedOutputs}).toJSON(worker.store)); + nlohmann::json( + KeyedBuildResult( + buildResult, + DerivedPath::Built{.drvPath = makeConstantStorePathRef(drvPath), .outputs = wantedOutputs}))); return amDone(buildResult.success() ? ecSuccess : ecFailed, std::move(ex)); } diff --git a/src/libstore/build/substitution-goal.cc b/src/libstore/build/substitution-goal.cc index 625e64781..41d8a0c30 100644 --- a/src/libstore/build/substitution-goal.cc +++ b/src/libstore/build/substitution-goal.cc @@ -42,9 +42,10 @@ Goal::Done PathSubstitutionGoal::done( logger->result( getCurActivity(), resBuildResult, - KeyedBuildResult( - buildResult, - DerivedPath::Opaque{storePath}).toJSON(worker.store)); + nlohmann::json( + KeyedBuildResult( + buildResult, + DerivedPath::Opaque{storePath}))); return amDone(result); } From 8674792eba1ba41dc3d048ab8d88f3cdf2bb2aa2 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Fri, 14 Mar 2025 17:33:48 +0100 Subject: [PATCH 13/22] Make the JSON logger more robust We now ignore connection / write errors. --- src/libutil/logging.cc | 15 +++++++++++++-- src/nix/main.cc | 6 +++++- 2 files changed, 18 insertions(+), 3 deletions(-) diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index c7b859bd5..de8df24b0 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -196,6 +196,7 @@ struct JSONLogger : Logger { struct State { + bool enabled = true; }; Sync _state; @@ -208,8 +209,18 @@ struct JSONLogger : Logger { /* Acquire a lock to prevent log messages from clobbering each other. */ - auto state(_state.lock()); - writeLine(fd, line); + try { + auto state(_state.lock()); + if (state->enabled) + writeLine(fd, line); + } catch (...) { + bool enabled = false; + std::swap(_state.lock()->enabled, enabled); + if (enabled) { + ignoreExceptionExceptInterrupt(); + logger->warn("disabling JSON logger due to write errors"); + } + } } void log(Verbosity lvl, std::string_view s) override diff --git a/src/nix/main.cc b/src/nix/main.cc index 68137a216..644c65cf0 100644 --- a/src/nix/main.cc +++ b/src/nix/main.cc @@ -502,7 +502,11 @@ void mainWrapped(int argc, char * * argv) } if (!extLoggerSettings.jsonLogPath.get().empty()) { - logger = makeTeeLogger({logger, makeJSONLogger(std::filesystem::path(extLoggerSettings.jsonLogPath.get()), false)}); + try { + logger = makeTeeLogger({logger, makeJSONLogger(std::filesystem::path(extLoggerSettings.jsonLogPath.get()), false)}); + } catch (...) { + ignoreExceptionExceptInterrupt(); + } } if (args.helpRequested) { From c32441f207194e480f4570df5560a9ffc2d207da Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 20 Mar 2025 20:20:02 +0100 Subject: [PATCH 14/22] Remove redundant quotes --- src/libutil/logging.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index de8df24b0..ddf90d7c5 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -323,7 +323,7 @@ Logger * makeJSONLogger(const std::filesystem::path & path, bool includeNixPrefi ? connect(path) : toDescriptor(open(path.c_str(), O_CREAT | O_APPEND | O_WRONLY, 0644)); if (!fd) - throw SysError("opening log file '%1%'", path); + throw SysError("opening log file %1%", path); return new JSONFileLogger(std::move(fd), includeNixPrefix); } From bc3a847784223978580878fdb8dce141c37d9cbf Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Fri, 21 Mar 2025 15:59:05 +0100 Subject: [PATCH 15/22] BuildResult: Serialize builtOutputs --- src/libstore/build-result.cc | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/src/libstore/build-result.cc b/src/libstore/build-result.cc index e6469e38f..1f27f68f4 100644 --- a/src/libstore/build-result.cc +++ b/src/libstore/build-result.cc @@ -32,7 +32,14 @@ void to_json(nlohmann::json & json, const KeyedBuildResult & buildResult) [&](const DerivedPathOpaque & opaque) { path["opaque"] = opaque.path.to_string(); }, [&](const DerivedPathBuilt & drv) { path["drvPath"] = drv.drvPath->getBaseStorePath().to_string(); - path["outputs"] = drv.outputs.to_string(); + path["outputs"] = drv.outputs; + auto outputs = nlohmann::json::object(); + for (auto & [name, output] : buildResult.builtOutputs) + outputs[name] = { + {"path", output.outPath.to_string()}, + {"signatures", output.signatures}, + }; + json["builtOutputs"] = std::move(outputs); }, }, buildResult.path.raw()); From 502f0273904536d7c162767f33d0dfe3d6612e10 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Wed, 26 Mar 2025 22:15:39 +0100 Subject: [PATCH 16/22] nix daemon: Respect json-log-path and re-open for every connection We don't want to inherit the parent's JSON logger since then messages from different daemon processes may clobber each other. --- src/libstore/daemon.cc | 12 +++++++++++- src/libutil/logging.hh | 8 ++++++++ src/nix/main.cc | 19 ++----------------- 3 files changed, 21 insertions(+), 18 deletions(-) diff --git a/src/libstore/daemon.cc b/src/libstore/daemon.cc index b921dbe2d..13655f6a8 100644 --- a/src/libstore/daemon.cc +++ b/src/libstore/daemon.cc @@ -15,6 +15,7 @@ #include "derivations.hh" #include "args.hh" #include "git.hh" +#include "logging.hh" #ifndef _WIN32 // TODO need graceful async exit support on Windows? # include "monitor-fd.hh" @@ -1044,9 +1045,18 @@ void processConnection( auto tunnelLogger = new TunnelLogger(conn.to, protoVersion); auto prevLogger = nix::logger; // FIXME - if (!recursive) + if (!recursive) { logger = tunnelLogger; + if (!loggerSettings.jsonLogPath.get().empty()) { + try { + logger = makeTeeLogger({logger, makeJSONLogger(std::filesystem::path(loggerSettings.jsonLogPath.get()), false)}); + } catch (...) { + ignoreExceptionExceptInterrupt(); + } + } + } + unsigned int opCount = 0; Finally finally([&]() { diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index aeb058526..479459e9f 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -52,6 +52,14 @@ struct LoggerSettings : Config Whether Nix should print out a stack trace in case of Nix expression evaluation errors. )"}; + + Setting jsonLogPath{ + this, "", "json-log-path", + R"( + A path to which JSON records of Nix's log output will be + written, in the same format as `--log-format internal-json` + (without the `@nix ` prefixes on each line). + )"}; }; extern LoggerSettings loggerSettings; diff --git a/src/nix/main.cc b/src/nix/main.cc index 644c65cf0..cad561c66 100644 --- a/src/nix/main.cc +++ b/src/nix/main.cc @@ -348,21 +348,6 @@ struct CmdHelpStores : Command static auto rCmdHelpStores = registerCommand("help-stores"); -struct ExtLoggerSettings : Config -{ - Setting jsonLogPath{ - this, "", "json-log-path", - R"( - A path to which JSON records of Nix's log output will be - written, in the same format as `--log-format internal-json` - (without the `@nix ` prefixes on each line). - )"}; -}; - -static ExtLoggerSettings extLoggerSettings; - -static GlobalConfig::Register rExtLoggerSettings(&extLoggerSettings); - void mainWrapped(int argc, char * * argv) { savedArgv = argv; @@ -501,9 +486,9 @@ void mainWrapped(int argc, char * * argv) if (!args.helpRequested && !args.completions) throw; } - if (!extLoggerSettings.jsonLogPath.get().empty()) { + if (!loggerSettings.jsonLogPath.get().empty()) { try { - logger = makeTeeLogger({logger, makeJSONLogger(std::filesystem::path(extLoggerSettings.jsonLogPath.get()), false)}); + logger = makeTeeLogger({logger, makeJSONLogger(std::filesystem::path(loggerSettings.jsonLogPath.get()), false)}); } catch (...) { ignoreExceptionExceptInterrupt(); } From 17d0810a7c4d5cd8ae6deff7d15fce6ea100a35b Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Wed, 26 Mar 2025 23:49:35 +0100 Subject: [PATCH 17/22] Cleanup --- src/libstore/daemon.cc | 12 +----------- src/libutil/logging.cc | 14 ++++++++++++++ src/libutil/logging.hh | 2 ++ src/nix/main.cc | 11 +---------- 4 files changed, 18 insertions(+), 21 deletions(-) diff --git a/src/libstore/daemon.cc b/src/libstore/daemon.cc index 1013b23a3..32c8f4d2d 100644 --- a/src/libstore/daemon.cc +++ b/src/libstore/daemon.cc @@ -1050,17 +1050,7 @@ void processConnection( if (!recursive) { prevLogger_ = std::move(logger); logger = std::move(tunnelLogger_); - - if (!loggerSettings.jsonLogPath.get().empty()) { - try { - std::vector> loggers; - loggers.push_back(std::move(logger)); - loggers.push_back(makeJSONLogger(std::filesystem::path(loggerSettings.jsonLogPath.get()), false)); - logger = makeTeeLogger(std::move(loggers)); - } catch (...) { - ignoreExceptionExceptInterrupt(); - } - } + applyJSONLogger(); } unsigned int opCount = 0; diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index b4bca0b36..fd54cc580 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -341,6 +341,20 @@ std::unique_ptr makeJSONLogger(const std::filesystem::path & path, bool return std::make_unique(std::move(fd), includeNixPrefix); } +void applyJSONLogger() +{ + if (!loggerSettings.jsonLogPath.get().empty()) { + try { + std::vector> loggers; + loggers.push_back(std::move(logger)); + loggers.push_back(makeJSONLogger(std::filesystem::path(loggerSettings.jsonLogPath.get()), false)); + logger = makeTeeLogger(std::move(loggers)); + } catch (...) { + ignoreExceptionExceptInterrupt(); + } + } +} + static Logger::Fields getFields(nlohmann::json & json) { Logger::Fields fields; diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index 5b69f501c..290a49bb8 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -221,6 +221,8 @@ std::unique_ptr makeJSONLogger(Descriptor fd, bool includeNixPrefix = tr std::unique_ptr makeJSONLogger(const std::filesystem::path & path, bool includeNixPrefix = true); +void applyJSONLogger(); + /** * @param source A noun phrase describing the source of the message, e.g. "the builder". */ diff --git a/src/nix/main.cc b/src/nix/main.cc index f81a02ce6..a2dc371d4 100644 --- a/src/nix/main.cc +++ b/src/nix/main.cc @@ -487,16 +487,7 @@ void mainWrapped(int argc, char * * argv) if (!args.helpRequested && !args.completions) throw; } - if (!loggerSettings.jsonLogPath.get().empty()) { - try { - std::vector> loggers; - loggers.push_back(std::move(logger)); - loggers.push_back(makeJSONLogger(std::filesystem::path(loggerSettings.jsonLogPath.get()), false)); - logger = makeTeeLogger(std::move(loggers)); - } catch (...) { - ignoreExceptionExceptInterrupt(); - } - } + applyJSONLogger(); if (args.helpRequested) { std::vector subcommand; From eca002ddc40c92ee714445a28e6155b9c235a801 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 27 Mar 2025 13:54:07 +0100 Subject: [PATCH 18/22] Don't segfault if we can't create the JSON logger --- src/libutil/logging.cc | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index fd54cc580..16ff1c5f4 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -344,12 +344,13 @@ std::unique_ptr makeJSONLogger(const std::filesystem::path & path, bool void applyJSONLogger() { if (!loggerSettings.jsonLogPath.get().empty()) { + std::vector> loggers; try { - std::vector> loggers; loggers.push_back(std::move(logger)); loggers.push_back(makeJSONLogger(std::filesystem::path(loggerSettings.jsonLogPath.get()), false)); logger = makeTeeLogger(std::move(loggers)); } catch (...) { + logger = std::move(loggers[0]); ignoreExceptionExceptInterrupt(); } } From 37f3b255b285e87f353bc9451be5f322c7696e1b Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 27 Mar 2025 17:17:01 +0100 Subject: [PATCH 19/22] makeTeeLogger(): Distinguish between main and extra loggers --- src/libutil/logging.cc | 9 +++++---- src/libutil/logging.hh | 9 ++++++++- src/libutil/tee-logger.cc | 9 +++++++-- 3 files changed, 20 insertions(+), 7 deletions(-) diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index 16ff1c5f4..7884b6f29 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -344,15 +344,16 @@ std::unique_ptr makeJSONLogger(const std::filesystem::path & path, bool void applyJSONLogger() { if (!loggerSettings.jsonLogPath.get().empty()) { - std::vector> loggers; try { - loggers.push_back(std::move(logger)); + std::vector> loggers; loggers.push_back(makeJSONLogger(std::filesystem::path(loggerSettings.jsonLogPath.get()), false)); - logger = makeTeeLogger(std::move(loggers)); + // Note: this had better not throw, otherwise `logger` is + // left unset. + logger = makeTeeLogger(std::move(logger), std::move(loggers)); } catch (...) { - logger = std::move(loggers[0]); ignoreExceptionExceptInterrupt(); } + } } diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index 290a49bb8..07f49be19 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -215,7 +215,14 @@ extern std::unique_ptr logger; std::unique_ptr makeSimpleLogger(bool printBuildLogs = true); -std::unique_ptr makeTeeLogger(std::vector> && loggers); +/** + * Create a logger that sends log messages to `mainLogger` and the + * list of loggers in `extraLoggers`. Only `mainLogger` is used for + * writing to stdout and getting user input. + */ +std::unique_ptr makeTeeLogger( + std::unique_ptr mainLogger, + std::vector> && extraLoggers); std::unique_ptr makeJSONLogger(Descriptor fd, bool includeNixPrefix = true); diff --git a/src/libutil/tee-logger.cc b/src/libutil/tee-logger.cc index 84527ffde..cb2548264 100644 --- a/src/libutil/tee-logger.cc +++ b/src/libutil/tee-logger.cc @@ -100,9 +100,14 @@ struct TeeLogger : Logger } }; -std::unique_ptr makeTeeLogger(std::vector> && loggers) +std::unique_ptr +makeTeeLogger(std::unique_ptr mainLogger, std::vector> && extraLoggers) { - return std::make_unique(std::move(loggers)); + std::vector> allLoggers; + allLoggers.push_back(std::move(mainLogger)); + for (auto & l : extraLoggers) + allLoggers.push_back(std::move(l)); + return std::make_unique(std::move(allLoggers)); } } From f80f7e001b4638667d59551f89b641f0e3fcbfa6 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 27 Mar 2025 19:07:00 +0100 Subject: [PATCH 20/22] Abort if we cannot create TeeLogger --- src/libutil/logging.cc | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index 7884b6f29..617ebeb16 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -347,9 +347,12 @@ void applyJSONLogger() try { std::vector> loggers; loggers.push_back(makeJSONLogger(std::filesystem::path(loggerSettings.jsonLogPath.get()), false)); - // Note: this had better not throw, otherwise `logger` is - // left unset. - logger = makeTeeLogger(std::move(logger), std::move(loggers)); + try { + logger = makeTeeLogger(std::move(logger), std::move(loggers)); + } catch (...) { + // `logger` is now gone so give up. + abort(); + } } catch (...) { ignoreExceptionExceptInterrupt(); } From 9e6c999bdfdf54dbf02c28e5cddab0ba670c14be Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 27 Mar 2025 19:07:06 +0100 Subject: [PATCH 21/22] Add release note --- doc/manual/source/release-notes-determinate/changes.md | 2 ++ doc/manual/source/release-notes-determinate/rl-3.0.0.md | 2 ++ 2 files changed, 4 insertions(+) diff --git a/doc/manual/source/release-notes-determinate/changes.md b/doc/manual/source/release-notes-determinate/changes.md index fa468dee9..8e6d053d0 100644 --- a/doc/manual/source/release-notes-determinate/changes.md +++ b/doc/manual/source/release-notes-determinate/changes.md @@ -5,3 +5,5 @@ This section lists the differences between upstream Nix 2.24 and Determinate Nix * In Determinate Nix, flakes are stable. You no longer need to enable the `flakes` experimental feature. * In Determinate Nix, the new Nix CLI (i.e. the `nix` command) is stable. You no longer need to enable the `nix-command` experimental feature. + +* Determinate Nix has a setting [`json-log-path`](@docroot@/command-ref/conf-file.md#conf-json-log-path) to send a copy of all Nix log messages (in JSON format) to a file or Unix domain socket. diff --git a/doc/manual/source/release-notes-determinate/rl-3.0.0.md b/doc/manual/source/release-notes-determinate/rl-3.0.0.md index d60786e9a..ba9c0479b 100644 --- a/doc/manual/source/release-notes-determinate/rl-3.0.0.md +++ b/doc/manual/source/release-notes-determinate/rl-3.0.0.md @@ -3,3 +3,5 @@ * Initial release of Determinate Nix. * Based on [upstream Nix 2.26.2](../release-notes/rl-2.26.md). + +* New setting `json-log-path` that sends a copy of all Nix log messages (in JSON format) to a file or Unix domain socket. From 10f9b2f1fc7edab32d7729ed1643d474caaec114 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Thu, 27 Mar 2025 19:08:09 +0100 Subject: [PATCH 22/22] Set release date --- doc/manual/source/SUMMARY.md.in | 2 +- doc/manual/source/release-notes-determinate/rl-3.1.0.md | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/doc/manual/source/SUMMARY.md.in b/doc/manual/source/SUMMARY.md.in index 57edad199..69babe05b 100644 --- a/doc/manual/source/SUMMARY.md.in +++ b/doc/manual/source/SUMMARY.md.in @@ -129,7 +129,7 @@ - [Determinate Nix Release Notes](release-notes-determinate/index.md) - [Changes between Nix and Determinate Nix](release-notes-determinate/changes.md) - [Release 3.0.0 (2025-03-04)](release-notes-determinate/rl-3.0.0.md) - - [Release 3.1.0 (2025-??-??)](release-notes-determinate/rl-3.1.0.md) + - [Release 3.1.0 (2025-03-27)](release-notes-determinate/rl-3.1.0.md) - [Nix Release Notes](release-notes/index.md) {{#include ./SUMMARY-rl-next.md}} - [Release 2.27 (2025-03-03)](release-notes/rl-2.27.md) diff --git a/doc/manual/source/release-notes-determinate/rl-3.1.0.md b/doc/manual/source/release-notes-determinate/rl-3.1.0.md index 8d55939da..02b22ba9f 100644 --- a/doc/manual/source/release-notes-determinate/rl-3.1.0.md +++ b/doc/manual/source/release-notes-determinate/rl-3.1.0.md @@ -1,3 +1,3 @@ -# Release 3.1.0 (2025-??-??) +# Release 3.1.0 (2025-03-27) * Based on [upstream Nix 2.27.1](../release-notes/rl-2.27.md).