feat: introduce warnings/traces fields and optional stderr prefix of attribute path

src/eval-args.cc

@@ -203,6 +203,19 @@ MyArgs::MyArgs() : MixCommonArgs("nix-eval-jobs") {
         .experimentalFeature = std::nullopt,
     });
 
+    addFlag({
+        .longName = "log-attr-prefix",
+        .aliases = {},
+        .shortName = 0,
+        .description = "prefix stderr log lines with the attribute path that "
+                       "produced them",
+        .category = "",
+        .labels = {},
+        .handler = {&logAttrPrefix, true},
+        .completer = nullptr,
+        .experimentalFeature = std::nullopt,
+    });
+
     addFlag({
         .longName = "expr",
         .aliases = {},

src/eval-args.hh

@@ -32,6 +32,7 @@ class MyArgs : virtual public nix::MixEvalArgs,
     bool showInputDrvs = false;
     bool constituents = false;
     bool noInstantiate = false;
+    bool logAttrPrefix = false;
     size_t nrWorkers = 1;
     size_t maxMemorySize = DEFAULT_MAX_MEMORY_SIZE;
 

src/meson.build

@@ -7,7 +7,8 @@ common_src = [
   'worker.cc',
   'strings-portable.cc',
   'output-stream-lock.cc',
-  'daemon-settings.cc'
+  'daemon-settings.cc',
+  'prefix-logger.cc',
 ]
 
 common_deps = [

src/prefix-logger.cc

@@ -0,0 +1,108 @@
+#include "prefix-logger.hh"
+
+#include <format>
+#include <memory>
+#include <nix/util/error.hh>
+#include <nix/util/logging.hh>
+#include <nix/util/terminal.hh>
+#include <optional>
+#include <sstream>
+#include <string>
+#include <string_view>
+#include <utility>
+#include <vector>
+
+PrefixLogger::PrefixLogger(std::unique_ptr<nix::Logger> wrapped,
+                           bool prefixStderr)
+    : wrapped(std::move(wrapped)), prefixStderr(prefixStderr) {}
+
+void PrefixLogger::setAttrPath(std::string path) { attrPath = std::move(path); }
+
+auto PrefixLogger::drainLogs() -> Logs {
+    Logs logs{
+        .traces = std::move(traceBuffer),
+        .warnings = std::move(warningBuffer),
+    };
+    traceBuffer.clear();
+    warningBuffer.clear();
+    return logs;
+}
+
+void PrefixLogger::stop() { wrapped->stop(); }
+void PrefixLogger::pause() { wrapped->pause(); }
+void PrefixLogger::resume() { wrapped->resume(); }
+auto PrefixLogger::isVerbose() -> bool { return wrapped->isVerbose(); }
+
+void PrefixLogger::log(nix::Verbosity lvl, std::string_view msg) {
+    if (!attrPath.empty()) {
+        auto filtered = nix::filterANSIEscapes(msg, true);
+        if (filtered.starts_with("trace:")) {
+            traceBuffer.emplace_back(std::move(filtered));
+        } else {
+            warningBuffer.emplace_back(std::move(filtered));
+        }
+        if (prefixStderr) {
+            wrapped->log(lvl, std::format("{}: {}", attrPath, msg));
+        } else {
+            wrapped->log(lvl, msg);
+        }
+    } else {
+        wrapped->log(lvl, msg);
+    }
+}
+
+void PrefixLogger::logEI(const nix::ErrorInfo &info) {
+    if (!attrPath.empty()) {
+        std::ostringstream oss;
+        nix::showErrorInfo(oss, info, nix::loggerSettings.showTrace.get());
+        warningBuffer.emplace_back(nix::filterANSIEscapes(oss.str(), true));
+        if (prefixStderr) {
+            auto modified = info;
+            modified.traces.push_front(nix::Trace{
+                .pos = {},
+                .hint =
+                    nix::HintFmt("while evaluating attribute '%s'", attrPath),
+                .print = nix::TracePrint::Always,
+            });
+            wrapped->logEI(modified);
+        } else {
+            wrapped->logEI(info);
+        }
+    } else {
+        wrapped->logEI(info);
+    }
+}
+
+void PrefixLogger::startActivity(nix::ActivityId act, nix::Verbosity lvl,
+                                 nix::ActivityType type,
+                                 const std::string &text, const Fields &fields,
+                                 nix::ActivityId parent) {
+    if (!attrPath.empty() && prefixStderr) {
+        wrapped->startActivity(act, lvl, type,
+                               std::format("{}: {}", attrPath, text), fields,
+                               parent);
+    } else {
+        wrapped->startActivity(act, lvl, type, text, fields, parent);
+    }
+}
+
+void PrefixLogger::stopActivity(nix::ActivityId act) {
+    wrapped->stopActivity(act);
+}
+
+void PrefixLogger::result(nix::ActivityId act, nix::ResultType type,
+                          const Fields &fields) {
+    wrapped->result(act, type, fields);
+}
+
+void PrefixLogger::writeToStdout(std::string_view data) {
+    wrapped->writeToStdout(data);
+}
+
+auto PrefixLogger::ask(std::string_view msg) -> std::optional<char> {
+    return wrapped->ask(msg);
+}
+
+void PrefixLogger::setPrintBuildLogs(bool printBuildLogs) {
+    wrapped->setPrintBuildLogs(printBuildLogs);
+}

src/prefix-logger.hh

@@ -0,0 +1,47 @@
+#pragma once
+///@file
+
+#include <nix/util/logging.hh>
+
+#include <memory>
+#include <string>
+#include <vector>
+
+class PrefixLogger : public nix::Logger {
+    std::unique_ptr<nix::Logger> wrapped;
+    std::string attrPath;
+    bool prefixStderr;
+    std::vector<std::string> traceBuffer;
+    std::vector<std::string> warningBuffer;
+
+  public:
+    struct Logs {
+        std::vector<std::string> traces;
+        std::vector<std::string> warnings;
+    };
+
+    explicit PrefixLogger(std::unique_ptr<nix::Logger> wrapped,
+                          bool prefixStderr);
+
+    void setAttrPath(std::string path);
+    auto drainLogs() -> Logs;
+
+    void stop() override;
+    void pause() override;
+    void resume() override;
+    bool isVerbose() override;
+
+    void log(nix::Verbosity lvl, std::string_view msg) override;
+    void logEI(const nix::ErrorInfo &info) override;
+
+    void startActivity(nix::ActivityId act, nix::Verbosity lvl,
+                       nix::ActivityType type, const std::string &text,
+                       const Fields &fields, nix::ActivityId parent) override;
+    void stopActivity(nix::ActivityId act) override;
+    void result(nix::ActivityId act, nix::ResultType type,
+                const Fields &fields) override;
+
+    void writeToStdout(std::string_view data) override;
+    std::optional<char> ask(std::string_view msg) override;
+    void setPrintBuildLogs(bool printBuildLogs) override;
+};

src/response.cc

@@ -26,6 +26,12 @@ void adl_serializer<Response>::to_json(json &res, const Response &response) {
         {"attr", response.attr},
         {"attrPath", response.attrPath},
     };
+    if (!response.traces.empty()) {
+        res["traces"] = response.traces;
+    }
+    if (!response.warnings.empty()) {
+        res["warnings"] = response.warnings;
+    }
 
     std::visit(overloaded{
                    [&](const Response::Job &job) -> void {
@@ -51,11 +57,21 @@ auto adl_serializer<Response>::from_json(const json &_json) -> Response {
 
     auto attr = getString(valueAt(json, "attr"));
     std::vector<std::string> attrPath = valueAt(json, "attrPath");
+    std::vector<std::string> traces;
+    if (const auto *tracesJson = get(json, "traces")) {
+        traces = tracesJson->get<std::vector<std::string>>();
+    }
+    std::vector<std::string> warnings;
+    if (const auto *warningsJson = get(json, "warnings")) {
+        warnings = warningsJson->get<std::vector<std::string>>();
+    }
 
     auto makeResponse = [&](Response::Payload payload) -> Response {
         return Response{
             .attr = std::move(attr),
             .attrPath = std::move(attrPath),
+            .traces = std::move(traces),
+            .warnings = std::move(warnings),
             .payload = std::move(payload),
         };
     };

src/response.hh

@@ -24,6 +24,8 @@
 struct Response {
     std::string attr;                  // dot-joined attribute path
     std::vector<std::string> attrPath; // attribute path components
+    std::vector<std::string> traces;   // builtins.trace output during eval
+    std::vector<std::string> warnings; // warnings emitted during eval
 
     struct Job {
         Drv drv;

src/worker.cc

@@ -1,18 +1,20 @@
 // doesn't exist on macOS
 // IWYU pragma: no_include <bits/types/struct_rusage.h>
 
+#include <cstdio>
+#include <iostream>
+#include <memory>
+#include <nix/cmd/installable-flake.hh>
+#include <nix/expr/attr-path.hh>
 #include <nix/expr/eval-error.hh>
+#include <nix/expr/value-to-json.hh>
+#include <nix/store/globals.hh>
+#include <nix/store/local-fs-store.hh>
+#include <nix/util/finally.hh>
 #include <nix/util/pos-idx.hh>
 #include <nix/util/terminal.hh>
-#include <nix/expr/attr-path.hh>
-#include <nix/store/local-fs-store.hh>
-#include <nix/store/globals.hh>
-#include <nix/cmd/installable-flake.hh>
-#include <nix/expr/value-to-json.hh>
-#include <sys/resource.h>
 #include <nlohmann/json.hpp>
-#include <cstdio>
-#include <iostream>
+#include <sys/resource.h>
 // NOLINTBEGIN(modernize-deprecated-headers)
 // misc-include-cleaner wants this header rather than the C++ version
 #include <stdlib.h>
@@ -47,6 +49,7 @@
 
 #include "worker.hh"
 #include "drv.hh"
+#include "prefix-logger.hh"
 #include "response.hh"
 #include "buffered-io.hh"
 #include "eval-args.hh"
@@ -318,7 +321,8 @@ auto shouldRestart(const MyArgs &args) -> bool {
 
 auto processJobRequest(nix::EvalState &state, LineReader &fromReader,
                        nix::AutoCloseFD &toParent, nix::Bindings &autoArgs,
-                       nix::Value *vRoot, MyArgs &args) -> bool {
+                       nix::Value *vRoot, MyArgs &args,
+                       PrefixLogger *prefixLogger) -> bool {
     /* Wait for the collector to send us a job name. */
     if (tryWriteLine(toParent.get(), "next") < 0) {
         return false; // main process died
@@ -337,6 +341,8 @@ auto processJobRequest(nix::EvalState &state, LineReader &fromReader,
 
     auto path = nlohmann::json::parse(line.substr(3));
     auto attrPathS = attrPathJoin(path);
+    prefixLogger->setAttrPath(attrPathS);
+    Finally const clearPrefix([&] -> void { prefixLogger->setAttrPath(""); });
 
     /* Evaluate it and send info back to the collector. */
     Response::Payload payload = [&]() -> Response::Payload {
@@ -360,13 +366,21 @@ auto processJobRequest(nix::EvalState &state, LineReader &fromReader,
             auto msg = oss.str();
 
             // Print to STDERR for Hydra UI
-            std::cerr << msg << "\n";
+            if (args.logAttrPrefix) {
+                std::cerr << attrPathS << ": " << msg << "\n";
+            } else {
+                std::cerr << msg << "\n";
+            }
             return Response::Error{nix::filterANSIEscapes(msg, true)};
         } catch (const std::exception &e) {
             // FIXME: for some reason the catch block above doesn't trigger on
             // macOS (?)
             const auto *msg = e.what();
-            std::cerr << msg << '\n';
+            if (args.logAttrPrefix) {
+                std::cerr << attrPathS << ": " << msg << '\n';
+            } else {
+                std::cerr << msg << '\n';
+            }
             return Response::Error{
                 .error = nix::filterANSIEscapes(msg, true),
                 // Nix 2.34 throws `StackOverflowError` whreas before, Nix
@@ -380,9 +394,13 @@ auto processJobRequest(nix::EvalState &state, LineReader &fromReader,
         }
     }();
 
+    auto logs = prefixLogger->drainLogs();
+
     Response const response{
         .attr = attrPathS,
         .attrPath = path.get<std::vector<std::string>>(),
+        .traces = std::move(logs.traces),
+        .warnings = std::move(logs.warnings),
         .payload = std::move(payload),
     };
     nlohmann::json const reply = response;
@@ -406,12 +424,17 @@ void worker(
         args.lookupPath, evalStore, nix::fetchSettings, nix::evalSettings);
     nix::Bindings &autoArgs = *args.getAutoArgs(*state);
 
+    auto prefixLogger = std::make_unique<PrefixLogger>(std::move(nix::logger),
+                                                       args.logAttrPrefix);
+    auto *prefixLoggerPtr = prefixLogger.get();
+    nix::logger = std::move(prefixLogger);
+
     nix::Value *vRoot = initializeRootValue(state, autoArgs, args);
 
     LineReader fromReader(fromParent.release());
 
     while (processJobRequest(*state, fromReader, toParent, autoArgs, vRoot,
-                             args)) {
+                             args, prefixLoggerPtr)) {
         // Continue processing jobs until we need to exit
     }