Handle log messages from build-remote

This makes the progress indicator show statuses like "connecting to
'root@machine'".

2 files changed, 135 insertions, 0 deletions

diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc
index e38a460537ea..1a2684a43a5e 100644
--- a/src/libutil/logging.cc
+++ b/src/libutil/logging.cc
@@ -2,6 +2,7 @@
 #include "util.hh"
 
 #include <atomic>
+#include <nlohmann/json.hpp>
 
 namespace nix {
 
@@ -90,4 +91,133 @@ Activity::Activity(Logger & logger, Verbosity lvl, ActivityType type,
     logger.startActivity(id, lvl, type, s, fields, parent);
 }
 
+struct JSONLogger : Logger
+{
+    Logger & prevLogger;
+
+    JSONLogger(Logger & prevLogger) : prevLogger(prevLogger) { }
+
+    void addFields(nlohmann::json & json, const Fields & fields)
+    {
+        if (fields.empty()) return;
+        auto & arr = json["fields"] = nlohmann::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 write(const nlohmann::json & json)
+    {
+        prevLogger.log(lvlError, "@nix " + json.dump());
+    }
+
+    void log(Verbosity lvl, const FormatOrString & fs) override
+    {
+        nlohmann::json json;
+        json["action"] = "msg";
+        json["level"] = lvl;
+        json["msg"] = fs.s;
+        write(json);
+    }
+
+    void startActivity(ActivityId act, Verbosity lvl, ActivityType type,
+        const std::string & s, const Fields & fields, ActivityId parent) override
+    {
+        nlohmann::json json;
+        json["action"] = "start";
+        json["id"] = act;
+        json["level"] = lvl;
+        json["type"] = type;
+        json["text"] = s;
+        addFields(json, fields);
+        // FIXME: handle parent
+        write(json);
+    }
+
+    void stopActivity(ActivityId act) override
+    {
+        nlohmann::json json;
+        json["action"] = "stop";
+        json["id"] = act;
+        write(json);
+    }
+
+    void result(ActivityId act, ResultType type, const Fields & fields) override
+    {
+        nlohmann::json json;
+        json["action"] = "result";
+        json["id"] = act;
+        json["type"] = type;
+        addFields(json, fields);
+        write(json);
+    }
+};
+
+Logger * makeJSONLogger(Logger & prevLogger)
+{
+    return new JSONLogger(prevLogger);
+}
+
+static Logger::Fields getFields(nlohmann::json & json)
+{
+    Logger::Fields fields;
+    for (auto & f : json) {
+        if (f.type() == nlohmann::json::value_t::number_unsigned)
+            fields.emplace_back(Logger::Field(f.get<uint64_t>()));
+        else if (f.type() == nlohmann::json::value_t::string)
+            fields.emplace_back(Logger::Field(f.get<std::string>()));
+        else throw Error("unsupported JSON type %d", (int) f.type());
+    }
+    return fields;
+}
+
+bool handleJSONLogMessage(const std::string & msg,
+    const Activity & act, std::map<ActivityId, Activity> & activities)
+{
+    if (!hasPrefix(msg, "@nix ")) return false;
+
+    try {
+        auto json = nlohmann::json::parse(std::string(msg, 5));
+
+        std::string action = json["action"];
+
+        if (action == "start") {
+            auto type = (ActivityType) json["type"];
+            if (type == actDownload || type == actUnknown)
+                activities.emplace(std::piecewise_construct,
+                    std::forward_as_tuple(json["id"]),
+                    std::forward_as_tuple(*logger, (Verbosity) json["level"], type,
+                        json["text"], getFields(json["fields"]), act.id));
+        }
+
+        else if (action == "stop")
+            activities.erase((ActivityId) json["id"]);
+
+        else if (action == "result") {
+            auto i = activities.find((ActivityId) json["id"]);
+            if (i != activities.end())
+                i->second.result((ResultType) json["type"], getFields(json["fields"]));
+        }
+
+        else if (action == "setPhase") {
+            std::string phase = json["phase"];
+            act.result(resSetPhase, phase);
+        }
+
+        else if (action == "msg") {
+            std::string msg = json["msg"];
+            logger->log((Verbosity) json["level"], msg);
+        }
+
+    } catch (std::exception & e) {
+        printError("bad log message from builder: %s", e.what());
+    }
+
+    return true;
+}
+
 }
diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh
index 21898c03a276..70a9f5d86249 100644
--- a/src/libutil/logging.hh
+++ b/src/libutil/logging.hh
@@ -130,6 +130,11 @@ extern Logger * logger;
 
 Logger * makeDefaultLogger();
 
+Logger * makeJSONLogger(Logger & prevLogger);
+
+bool handleJSONLogMessage(const std::string & msg,
+    const Activity & act, std::map<ActivityId, Activity> & activities);
+
 extern Verbosity verbosity; /* suppress msgs > this */
 
 /* Print a message if the current log level is at least the specified