From 0087188d47f35778e1c347a2f853b9d2b1df39d0 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Fri, 11 Apr 2025 16:11:57 +0200 Subject: [PATCH 1/3] Add convenience function for connecting to a Unix domain socket --- src/libstore/uds-remote-store.cc | 4 +--- src/libutil/include/nix/util/unix-domain-socket.hh | 7 +++++++ src/libutil/unix-domain-socket.cc | 7 +++++++ 3 files changed, 15 insertions(+), 3 deletions(-) diff --git a/src/libstore/uds-remote-store.cc b/src/libstore/uds-remote-store.cc index 9950e38b3..c979b5e47 100644 --- a/src/libstore/uds-remote-store.cc +++ b/src/libstore/uds-remote-store.cc @@ -83,9 +83,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()), config->path); + conn->fd = nix::connect(config->path); conn->from.fd = conn->fd.get(); conn->to.fd = conn->fd.get(); diff --git a/src/libutil/include/nix/util/unix-domain-socket.hh b/src/libutil/include/nix/util/unix-domain-socket.hh index 704999ec1..6885d740b 100644 --- a/src/libutil/include/nix/util/unix-domain-socket.hh +++ b/src/libutil/include/nix/util/unix-domain-socket.hh @@ -9,6 +9,8 @@ #endif #include +#include + namespace nix { /** @@ -80,4 +82,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/libutil/unix-domain-socket.cc b/src/libutil/unix-domain-socket.cc index 8722c8f05..0e8c21d66 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; +} + } From 7240fb198f2ebc0e222969ba389979a45da2dc89 Mon Sep 17 00:00:00 2001 From: Eelco Dolstra Date: Fri, 11 Apr 2025 16:45:59 +0200 Subject: [PATCH 2/3] Add `json-log-path` setting This setting specifies a path (which can be a regular file or Unix domain socket) that receives a copy of all Nix log messages (in JSON format). --- doc/manual/rl-next/json-logger.md | 6 ++ src/libstore/daemon.cc | 2 + src/libutil/include/nix/util/logging.hh | 25 +++++- src/libutil/logging.cc | 53 +++++++++++- src/libutil/meson.build | 1 + src/libutil/tee-logger.cc | 107 ++++++++++++++++++++++++ src/nix/main.cc | 2 + tests/functional/logging.sh | 9 ++ 8 files changed, 200 insertions(+), 5 deletions(-) create mode 100644 doc/manual/rl-next/json-logger.md create mode 100644 src/libutil/tee-logger.cc diff --git a/doc/manual/rl-next/json-logger.md b/doc/manual/rl-next/json-logger.md new file mode 100644 index 000000000..867b5d8b3 --- /dev/null +++ b/doc/manual/rl-next/json-logger.md @@ -0,0 +1,6 @@ +--- +synopsis: "`json-log-path` setting" +prs: [13003] +--- + +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/src/libstore/daemon.cc b/src/libstore/daemon.cc index 8f7514273..dfc068bc7 100644 --- a/src/libstore/daemon.cc +++ b/src/libstore/daemon.cc @@ -15,6 +15,7 @@ #include "nix/store/derivations.hh" #include "nix/util/args.hh" #include "nix/util/git.hh" +#include "nix/util/logging.hh" #ifndef _WIN32 // TODO need graceful async exit support on Windows? # include "nix/util/monitor-fd.hh" @@ -1050,6 +1051,7 @@ void processConnection( if (!recursive) { prevLogger_ = std::move(logger); logger = std::move(tunnelLogger_); + applyJSONLogger(); } unsigned int opCount = 0; diff --git a/src/libutil/include/nix/util/logging.hh b/src/libutil/include/nix/util/logging.hh index 9210229bf..f2064b74d 100644 --- a/src/libutil/include/nix/util/logging.hh +++ b/src/libutil/include/nix/util/logging.hh @@ -6,6 +6,8 @@ #include "nix/util/file-descriptor.hh" #include "nix/util/finally.hh" +#include + #include namespace nix { @@ -49,6 +51,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; @@ -196,7 +206,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/logging.cc b/src/libutil/logging.cc index 21f13d3c0..a328a5c73 100644 --- a/src/libutil/logging.cc +++ b/src/libutil/logging.cc @@ -7,6 +7,7 @@ #include "nix/util/source-path.hh" #include "nix/util/position.hh" #include "nix/util/sync.hh" +#include "nix/util/unix-domain-socket.hh" #include #include @@ -182,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; @@ -212,7 +217,7 @@ struct JSONLogger : Logger { void write(const nlohmann::json & json) { auto line = - "@nix " + + (includeNixPrefix ? "@nix " : "") + json.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace); /* Acquire a lock to prevent log messages from clobbering each @@ -300,9 +305,49 @@ struct JSONLogger : Logger { } }; -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/meson.build b/src/libutil/meson.build index b0e82e46a..04ca06eee 100644 --- a/src/libutil/meson.build +++ b/src/libutil/meson.build @@ -147,6 +147,7 @@ sources = [config_priv_h] + 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..55334a821 --- /dev/null +++ b/src/libutil/tee-logger.cc @@ -0,0 +1,107 @@ +#include "nix/util/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); + } +}; + +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/nix/main.cc b/src/nix/main.cc index 05c5da27d..0e5ccf34b 100644 --- a/src/nix/main.cc +++ b/src/nix/main.cc @@ -460,6 +460,8 @@ void mainWrapped(int argc, char * * argv) if (!args.helpRequested && !args.completions) throw; } + applyJSONLogger(); + if (args.helpRequested) { std::vector subcommand; MultiCommand * command = &args; diff --git a/tests/functional/logging.sh b/tests/functional/logging.sh index ddb1913ad..83df9a45d 100755 --- a/tests/functional/logging.sh +++ b/tests/functional/logging.sh @@ -33,3 +33,12 @@ if isDaemonNewer "2.26"; then # Build works despite ill-formed structured build log entries. expectStderr 0 nix build -f ./logging/unusual-logging.nix --no-link | grepQuiet 'warning: Unable to handle a JSON message from the derivation builder:' fi + +# Test json-log-path. +if [[ "$NIX_REMOTE" != "daemon" ]]; then + clearStore + nix build -vv --file dependencies.nix --no-link --json-log-path "$TEST_ROOT/log.json" 2>&1 | grepQuiet 'building.*dependencies-top.drv' + jq < "$TEST_ROOT/log.json" + grep '{"action":"start","fields":\[".*-dependencies-top.drv","",1,1\],"id":.*,"level":3,"parent":0' "$TEST_ROOT/log.json" >&2 + (( $(grep '{"action":"msg","level":5,"msg":"executing builder .*"}' "$TEST_ROOT/log.json" | wc -l) == 5 )) +fi From 7cef4559fecc1b0ed1ebd0420773ac714b62bf64 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?J=C3=B6rg=20Thalheim?= Date: Fri, 23 May 2025 10:34:49 +0200 Subject: [PATCH 3/3] util/json-log-path: document unix sockets and concurrency issues --- src/libutil/include/nix/util/logging.hh | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/libutil/include/nix/util/logging.hh b/src/libutil/include/nix/util/logging.hh index f2064b74d..765975faa 100644 --- a/src/libutil/include/nix/util/logging.hh +++ b/src/libutil/include/nix/util/logging.hh @@ -55,9 +55,11 @@ struct LoggerSettings : Config Setting jsonLogPath{ this, "", "json-log-path", R"( - A path to which JSON records of Nix's log output will be + A file or unix socket 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). + Concurrent writes to the same file by multiple Nix processes are not supported and + may result in interleaved or corrupted log records. )"}; };