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/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. 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). diff --git a/src/libstore/build-result.cc b/src/libstore/build-result.cc index 96cbfd62f..1f27f68f4 100644 --- a/src/libstore/build-result.cc +++ b/src/libstore/build-result.cc @@ -1,8 +1,49 @@ #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; +} + +void to_json(nlohmann::json & json, const KeyedBuildResult & buildResult) +{ + 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; + 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()); + json["path"] = std::move(path); +} + } diff --git a/src/libstore/build-result.hh b/src/libstore/build-result.hh index 8c66cfeb3..44862980d 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); } /** @@ -130,4 +136,7 @@ struct KeyedBuildResult : BuildResult { } }; +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 f7d306bf7..b54176418 100644 --- a/src/libstore/build/derivation-goal.cc +++ b/src/libstore/build/derivation-goal.cc @@ -1540,6 +1540,14 @@ Goal::Done DerivationGoal::done( fs << worker.store.printStorePath(drvPath) << "\t" << buildResult.toString() << std::endl; } + logger->result( + act ? act->id : getCurActivity(), + resBuildResult, + 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 983c86601..41d8a0c30 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,15 @@ Goal::Done PathSubstitutionGoal::done( debug(*errorMsg); buildResult.errorMsg = *errorMsg; } + + logger->result( + getCurActivity(), + resBuildResult, + nlohmann::json( + KeyedBuildResult( + buildResult, + DerivedPath::Opaque{storePath}))); + return amDone(result); } diff --git a/src/libstore/daemon.cc b/src/libstore/daemon.cc index 60cb64b7b..32c8f4d2d 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" @@ -1049,6 +1050,7 @@ void processConnection( if (!recursive) { prevLogger_ = std::move(logger); logger = std::move(tunnelLogger_); + applyJSONLogger(); } unsigned int opCount = 0; 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/libstore/unix/build/local-derivation-goal.cc b/src/libstore/unix/build/local-derivation-goal.cc index b4f5c23a4..4cd79f897 100644 --- a/src/libstore/unix/build/local-derivation-goal.cc +++ b/src/libstore/unix/build/local-derivation-goal.cc @@ -2654,6 +2654,12 @@ SingleDrvOutputs LocalDerivationGoal::registerOutputs() worker.store.printStorePath(drvPath), wanted.to_string(HashFormat::SRI, true), got.to_string(HashFormat::SRI, true))); + act->result(resHashMismatch, + { + {"storePath", worker.store.printStorePath(drvPath)}, + {"wanted", wanted}, + {"got", got}, + }); } if (!newInfo0.references.empty()) { auto numViolations = newInfo.references.size(); diff --git a/src/libutil/hash.cc b/src/libutil/hash.cc index 6a7a8b092..a248ba14c 100644 --- a/src/libutil/hash.cc +++ b/src/libutil/hash.cc @@ -16,6 +16,8 @@ #include #include +#include + #include namespace nix { @@ -467,4 +469,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 13d526f42..c333bd424 100644 --- a/src/libutil/hash.hh +++ b/src/libutil/hash.hh @@ -6,6 +6,8 @@ #include "serialise.hh" #include "file-system.hh" +#include + namespace nix { @@ -210,6 +212,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; diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc index 406452738..617ebeb16 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -6,6 +6,8 @@ #include "config-global.hh" #include "source-path.hh" #include "position.hh" +#include "sync.hh" +#include "unix-domain-socket.hh" #include #include @@ -181,8 +183,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; @@ -201,9 +207,33 @@ struct JSONLogger : Logger { unreachable(); } + struct State + { + bool enabled = true; + }; + + Sync _state; + void write(const nlohmann::json & json) { - writeLine(fd, "@nix " + json.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace)); + auto line = + (includeNixPrefix ? "@nix " : "") + + json.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace); + + /* Acquire a lock to prevent log messages from clobbering each + other. */ + 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 @@ -273,11 +303,61 @@ 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); + } }; -std::unique_ptr makeJSONLogger(Descriptor fd) +std::unique_ptr makeJSONLogger(Descriptor fd, bool includeNixPrefix) { - return std::make_unique(fd); + return std::make_unique(fd, includeNixPrefix); +} + +std::unique_ptr makeJSONLogger(const std::filesystem::path & path, bool includeNixPrefix) +{ + struct JSONFileLogger : JSONLogger { + AutoCloseFD fd; + + JSONFileLogger(AutoCloseFD && fd, bool includeNixPrefix) + : JSONLogger(fd.get(), includeNixPrefix) + , fd(std::move(fd)) + { } + }; + + 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); + + return std::make_unique(std::move(fd), includeNixPrefix); +} + +void applyJSONLogger() +{ + if (!loggerSettings.jsonLogPath.get().empty()) { + try { + std::vector> loggers; + loggers.push_back(makeJSONLogger(std::filesystem::path(loggerSettings.jsonLogPath.get()), false)); + try { + logger = makeTeeLogger(std::move(logger), std::move(loggers)); + } catch (...) { + // `logger` is now gone so give up. + abort(); + } + } catch (...) { + ignoreExceptionExceptInterrupt(); + } + + } } static Logger::Fields getFields(nlohmann::json & json) diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh index e5a7a833f..07f49be19 100644 --- a/src/libutil/logging.hh +++ b/src/libutil/logging.hh @@ -6,6 +6,8 @@ #include "file-descriptor.hh" #include "finally.hh" +#include + #include namespace nix { @@ -37,6 +39,8 @@ typedef enum { resSetExpected = 106, resPostBuildLogLine = 107, resFetchStatus = 108, + resHashMismatch = 109, + resBuildResult = 110, } ResultType; typedef uint64_t ActivityId; @@ -49,6 +53,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; @@ -117,6 +129,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 @@ -169,6 +183,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 { @@ -196,7 +215,20 @@ extern std::unique_ptr logger; std::unique_ptr makeSimpleLogger(bool printBuildLogs = true); -std::unique_ptr makeJSONLogger(Descriptor fd); +/** + * 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); + +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/libutil/meson.build b/src/libutil/meson.build index 9e70d0549..ab8f8f4db 100644 --- a/src/libutil/meson.build +++ b/src/libutil/meson.build @@ -166,6 +166,7 @@ sources = files( 'strings.cc', 'suggestions.cc', 'tarfile.cc', + 'tee-logger.cc', 'terminal.cc', 'thread-pool.cc', 'union-source-accessor.cc', diff --git a/src/libutil/tee-logger.cc b/src/libutil/tee-logger.cc new file mode 100644 index 000000000..cb2548264 --- /dev/null +++ b/src/libutil/tee-logger.cc @@ -0,0 +1,113 @@ +#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 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) { + /* 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); + } +}; + +std::unique_ptr +makeTeeLogger(std::unique_ptr mainLogger, std::vector> && extraLoggers) +{ + 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)); +} + +} 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); + } diff --git a/src/nix/main.cc b/src/nix/main.cc index 13438b31a..a2dc371d4 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" @@ -486,6 +487,8 @@ void mainWrapped(int argc, char * * argv) if (!args.helpRequested && !args.completions) throw; } + applyJSONLogger(); + if (args.helpRequested) { std::vector subcommand; MultiCommand * command = &args;