Logger improvements

src/libstore/build-result.cc

@@ -1,8 +1,49 @@
 #include "build-result.hh"
 
+#include <nlohmann/json.hpp>
+
 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);
+}
+
 }

src/libstore/build-result.hh

@@ -8,6 +8,8 @@
 #include <chrono>
 #include <optional>
 
+#include <nlohmann/json_fwd.hpp>
+
 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);
+
 }

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));
 }
 

src/libstore/build/substitution-goal.cc

@@ -3,8 +3,11 @@
 #include "nar-info.hh"
 #include "finally.hh"
 #include "signals.hh"
+
 #include <coroutine>
 
+#include <nlohmann/json.hpp>
+
 namespace nix {
 
 PathSubstitutionGoal::PathSubstitutionGoal(const StorePath & storePath, Worker & worker, RepairFlag repair, std::optional<ContentAddress> 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);
 }
 

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;

src/libstore/uds-remote-store.cc

@@ -84,9 +84,7 @@ ref<RemoteStore::Connection> UDSRemoteStore::openConnection()
     auto conn = make_ref<Connection>();
 
     /* 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();

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();

src/libutil/hash.cc

@@ -16,6 +16,8 @@
 #include <sys/stat.h>
 #include <fcntl.h>
 
+#include <nlohmann/json.hpp>
+
 #include <sodium.h>
 
 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)},
+        });
+}
+
 }

src/libutil/hash.hh

@@ -6,6 +6,8 @@
 #include "serialise.hh"
 #include "file-system.hh"
 
+#include <nlohmann/json_fwd.hpp>
+
 namespace nix {
 
 
@@ -210,6 +212,10 @@ std::optional<HashAlgorithm> parseHashAlgoOpt(std::string_view s);
  */
 std::string_view printHashAlgo(HashAlgorithm ha);
 
+/**
+ * Write a JSON serialisation of the format `{"algo":"<sha1|...>","base16":"<hex>"}`.
+ */
+void to_json(nlohmann::json & json, const Hash & hash);
 
 union Ctx;
 

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 <atomic>
 #include <sstream>
@@ -181,8 +183,12 @@ void to_json(nlohmann::json & json, std::shared_ptr<Pos> 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> _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,57 @@ 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<Logger> makeJSONLogger(Descriptor fd)
+std::unique_ptr<Logger> makeJSONLogger(Descriptor fd, bool includeNixPrefix)
+{
+    return std::make_unique<JSONLogger>(fd, includeNixPrefix);
+}
+
+std::unique_ptr<Logger> makeJSONLogger(const std::filesystem::path & path, bool includeNixPrefix)
 {
-    return std::make_unique<JSONLogger>(fd);
+    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<JSONFileLogger>(std::move(fd), includeNixPrefix);
+}
+
+void applyJSONLogger()
+{
+    if (!loggerSettings.jsonLogPath.get().empty()) {
+        std::vector<std::unique_ptr<Logger>> loggers;
+        try {
+            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();
+        }
+    }
 }
 
 static Logger::Fields getFields(nlohmann::json & json)