Merge 0981c51045 into f9afc1e68c

src/libmain/include/nix/main/loggers.hh

@@ -9,6 +9,7 @@ enum class LogFormat {
   raw,
   rawWithLogs,
   internalJSON,
+  diffs,
   bar,
   barWithLogs,
 };

src/libmain/loggers.cc

@@ -1,4 +1,5 @@
 #include "nix/main/loggers.hh"
+#include "nix/util/logging-diffs.hh"
 #include "nix/util/environment-variables.hh"
 #include "nix/main/progress-bar.hh"
 
@@ -14,6 +15,8 @@ LogFormat parseLogFormat(const std::string & logFormatStr)
         return LogFormat::rawWithLogs;
     else if (logFormatStr == "internal-json")
         return LogFormat::internalJSON;
+    else if (logFormatStr == "diffs")
+        return LogFormat::diffs;
     else if (logFormatStr == "bar")
         return LogFormat::bar;
     else if (logFormatStr == "bar-with-logs")
@@ -30,6 +33,8 @@ std::unique_ptr<Logger> makeDefaultLogger()
         return makeSimpleLogger(true);
     case LogFormat::internalJSON:
         return makeJSONLogger(getStandardError());
+    case LogFormat::diffs:
+        return makeDiffLogger(getStandardError());
     case LogFormat::bar:
         return makeProgressBar();
     case LogFormat::barWithLogs: {

src/libutil/include/nix/util/logging-diffs.hh

@@ -0,0 +1,51 @@
+#pragma once
+
+#include "nix/util/types.hh"
+#include "nix/util/error.hh"
+#include "nix/util/configuration.hh"
+#include "nix/util/logging.hh"
+
+#include <nlohmann/json.hpp>
+
+#include <list>
+#include <map>
+#include <optional>
+
+namespace nix {
+
+std::unique_ptr<Logger> makeDiffLogger(Descriptor fd);
+
+struct ActivityState {
+    bool isComplete;
+    ActivityType type;
+    std::string text;
+    Logger::Fields fields;
+    ActivityId parent;
+
+    ActivityState(ActivityType _type, const std::string _text, const Logger::Fields &_fields, ActivityId _parent):
+        isComplete(false),
+        type(_type),
+        text(_text),
+        fields(_fields),
+        parent(_parent) { }
+};
+
+struct NixMessage {
+    int level;
+
+    std::optional<int> line;
+    std::optional<int> column;
+    std::optional<std::string> file;
+
+    std::optional<nlohmann::json> trace;
+
+    std::string msg;
+    std::string raw_msg;
+};
+
+struct NixBuildState {
+    std::map<ActivityId, ActivityState> activities;
+    std::list<NixMessage> messages;
+};
+
+}

src/libutil/include/nix/util/meson.build

@@ -41,6 +41,7 @@ headers = files(
   'json-impls.hh',
   'json-utils.hh',
   'logging.hh',
+  'logging-diffs.hh',
   'lru-cache.hh',
   'memory-source-accessor.hh',
   'muxable-pipe.hh',

src/libutil/logging-diffs.cc

@@ -0,0 +1,238 @@
+
+#include "nix/util/configuration.hh"
+#include "nix/util/logging.hh"
+#include "nix/util/logging-diffs.hh"
+#include "nix/util/position.hh"
+#include "nix/util/sync.hh"
+#include "nix/util/util.hh"
+
+#include <atomic>
+#include <chrono>
+#include <iostream>
+#include <nlohmann/json.hpp>
+#include <thread>
+
+using json = nlohmann::json;
+
+namespace nix {
+
+void addFields(json & json, const Logger::Fields & fields)
+{
+    if (fields.empty()) return;
+    auto & arr = json["fields"] = json::array();
+    for (auto & f : fields)
+        if (f.type == Logger::Field::tInt)
+            arr.push_back(f.i);
+        else if (f.type == Logger::Field::tString)
+            arr.push_back(f.s);
+        else
+            abort();
+}
+
+void to_json(json & j, const NixMessage & m)
+{
+    j = json{ {"level", m.level} };
+
+    if (m.line.has_value()) j["line"] = m.line.value();
+    if (m.column.has_value()) j["column"] = m.column.value();
+    if (m.file.has_value()) j["file"] = m.file.value();
+
+    if (m.trace.has_value()) j["trace"] = m.trace.value();
+
+    if (!m.msg.empty()) j["msg"] = m.msg;
+    if (!m.raw_msg.empty()) j["raw_msg"] = m.raw_msg;
+}
+
+void to_json(json & j, const ActivityState & as)
+{
+    j = json{ {"is_complete", as.isComplete}, {"type", as.type}, {"text", as.text} };
+    addFields(j, as.fields);
+}
+
+void to_json(json & j, const NixBuildState & s)
+{
+    j = json{ {"messages", s.messages} };
+
+    j["activities"] = json(json::value_t::object);
+    for (const auto& [key, value] : s.activities) {
+        j["activities"][std::to_string(key)] = value;
+    }
+}
+
+static void addPosToMessage(NixMessage & msg, std::shared_ptr<Pos> pos)
+{
+    if (pos) {
+        msg.line = pos->line;
+        msg.column = pos->column;
+        std::ostringstream str;
+        pos->print(str, true);
+        msg.file = str.str();
+    } else {
+        msg.line = std::nullopt;
+        msg.column = std::nullopt;
+        msg.file = std::nullopt;
+    }
+}
+
+static void posToJson(json & json, std::shared_ptr<Pos> pos)
+{
+    if (pos) {
+        json["line"] = pos->line;
+        json["column"] = pos->column;
+        std::ostringstream str;
+        pos->print(str, true);
+        json["file"] = str.str();
+    } else {
+        json["line"] = nullptr;
+        json["column"] = nullptr;
+        json["file"] = nullptr;
+    }
+}
+
+struct DiffLogger : Logger {
+    Descriptor fd;
+
+    Sync<NixBuildState> state;
+    json last_sent;
+    std::mutex lock;
+    std::atomic_bool exitPeriodicAction;
+    std::atomic_bool exited;
+    std::thread printerThread;
+
+    DiffLogger(Descriptor fd)
+        : fd(fd)
+        , last_sent(nullptr)
+        , exitPeriodicAction(false)
+        , exited(false)
+        , printerThread(std::thread(&DiffLogger::periodicAction, this))
+        { }
+
+    // Note: tried to move the contents of the stop() fn to ~DiffLogger, but couldn't get
+    // it to run.
+
+    ~DiffLogger() {
+        this->stop();
+    }
+
+    void stop() override {
+        // Make stop() idempotent
+        if (this->exitPeriodicAction) return;
+
+        this->exitPeriodicAction = true;
+        this->printerThread.join();
+        sendLatestIfNecessary();
+        this->exited = true;
+    }
+
+    void periodicAction() {
+        // Send initial value as a normal value
+        {
+            auto state_(state.lock());
+            write(*state_);
+            this->last_sent = *state_;
+        }
+
+        while (true) {
+            if (this->exitPeriodicAction) break;
+
+            sendLatestIfNecessary();
+
+            std::this_thread::sleep_for(std::chrono::milliseconds(300));
+        }
+    }
+
+    void sendLatestIfNecessary() {
+        auto state_(state.lock());
+        this->sendLatestIfNecessaryUnlocked(state_);
+    }
+
+    void sendLatestIfNecessaryUnlocked(Sync<NixBuildState>::WriteLock & _state) {
+        if (this->last_sent == *_state) return;
+
+        write(json::diff(this->last_sent, *_state));
+        this->last_sent = *_state;
+    }
+
+    bool isVerbose() override {
+        return true;
+    }
+
+    void write(const json & json)
+    {
+        writeLine(fd, json.dump(-1, ' ', false, json::error_handler_t::replace));
+    }
+
+    void log(Verbosity lvl, std::string_view s) override
+    {
+        auto state_(state.lock());
+        NixMessage msg;
+        msg.msg = s;
+        state_->messages.push_back(msg);
+
+        // Not sure why, but sometimes log messages happen after stop() is called
+        if (this->exited) sendLatestIfNecessaryUnlocked(state_);
+    }
+
+    void logEI(const ErrorInfo & ei) override
+    {
+        NixMessage msg;
+
+        std::ostringstream oss;
+        showErrorInfo(oss, ei, loggerSettings.showTrace.get());
+
+        msg.level = ei.level;
+        msg.msg = oss.str();
+        msg.raw_msg = ei.msg.str();
+
+        addPosToMessage(msg, ei.pos);
+
+        if (loggerSettings.showTrace.get() && !ei.traces.empty()) {
+            json traces = json::array();
+            for (auto iter = ei.traces.rbegin(); iter != ei.traces.rend(); ++iter) {
+                json stackFrame;
+                stackFrame["raw_msg"] = iter->hint.str();
+                posToJson(stackFrame, iter->pos);
+                traces.push_back(stackFrame);
+            }
+
+            msg.trace = traces;
+        }
+
+        auto state_(state.lock());
+        state_->messages.push_back(msg);
+
+        // Not sure why, but sometimes log messages happen after stop() is called
+        if (this->exited) sendLatestIfNecessaryUnlocked(state_);
+    }
+
+    void startActivity(ActivityId act, Verbosity lvl, ActivityType type,
+        const std::string & s, const Fields & fields, ActivityId parent) override
+    {
+        ActivityState as(type, s, fields, parent);
+        auto state_(state.lock());
+        state_->activities.insert(std::pair<ActivityId, ActivityState>(act, as));
+    }
+
+    void stopActivity(ActivityId act) override
+    {
+        auto state_(state.lock());
+        try { state_->activities.at(act).isComplete = true; }
+        catch (const std::out_of_range& oor) { }
+    }
+
+    void result(ActivityId act, ResultType type, const Fields & fields) override
+    {
+        auto state_(state.lock());
+        try { state_->activities.at(act).fields = fields; }
+        catch (const std::out_of_range& oor) {
+            Logger::writeToStdout("Failed to look up result of type " + std::to_string(static_cast<int>(type)));
+        }
+    }
+};
+
+std::unique_ptr<Logger> makeDiffLogger(Descriptor fd)
+{
+    return std::make_unique<DiffLogger>(fd);
+}
+
+}

src/libutil/meson.build

@@ -132,6 +132,7 @@ sources = [config_priv_h] + files(
   'hilite.cc',
   'json-utils.cc',
   'logging.cc',
+  'logging-diffs.cc',
   'memory-source-accessor.cc',
   'mounted-source-accessor.cc',
   'position.cc',