diff --git a/lix/libstore/build/derivation-goal.cc b/lix/libstore/build/derivation-goal.cc index bd5bd9461..54fbd08de 100644 --- a/lix/libstore/build/derivation-goal.cc +++ b/lix/libstore/build/derivation-goal.cc @@ -1215,7 +1215,7 @@ HookReply DerivationGoal::tryBuildHook() throw; } }(); - if (handleJSONLogMessage(s, worker.act, worker.hook.instance->activities, true)) + if (handleJSONLogMessage(s, worker.act, worker.hook.instance->activities, "the build hook", true)) ; else if (s.substr(0, 2) == "# ") { reply = s.substr(2); @@ -1440,9 +1440,9 @@ try { for (auto c : data) if (c == '\n') { - auto json = parseJSONMessage(currentHookLine); + auto json = parseJSONMessage(currentHookLine, "the derivation builder"); if (json) { - auto s = handleJSONLogMessage(*json, worker.act, hook->activities, true); + auto s = handleJSONLogMessage(*json, worker.act, hook->activities, "the derivation builder", true); // ensure that logs from a builder using `ssh-ng://` as protocol // are also available to `nix log`. if (s && logSink) { @@ -1557,7 +1557,7 @@ DerivationGoal::handleChildStreams(InputStream & builderIn, InputStream * hookIn void DerivationGoal::flushLine() { - if (handleJSONLogMessage(currentLogLine, *act, builderActivities, false)) + if (handleJSONLogMessage(currentLogLine, *act, builderActivities, "the derivation builder", false)) ; else { diff --git a/lix/libutil/logging-json.hh b/lix/libutil/logging-json.hh index a76904a3e..e679721de 100644 --- a/lix/libutil/logging-json.hh +++ b/lix/libutil/logging-json.hh @@ -10,14 +10,25 @@ namespace nix { -std::optional parseJSONMessage(const std::string & msg); +/** + * @param source A noun phrase describing the source of the message, e.g. "the builder". + */ +std::optional parseJSONMessage(const std::string & msg, std::string_view source); +/** + * @param source A noun phrase describing the source of the message, e.g. "the builder". + */ bool handleJSONLogMessage(nlohmann::json & json, const Activity & act, std::map & activities, + std::string_view source, bool trusted); +/** + * @param source A noun phrase describing the source of the message, e.g. "the builder". + */ bool handleJSONLogMessage(const std::string & msg, const Activity & act, std::map & activities, + std::string_view source, bool trusted); }; diff --git a/lix/libutil/logging.cc b/lix/libutil/logging.cc index 5adbf078d..50ed4b83c 100644 --- a/lix/libutil/logging.cc +++ b/lix/libutil/logging.cc @@ -290,20 +290,22 @@ static Logger::Fields getFields(nlohmann::json & json) return fields; } -std::optional parseJSONMessage(const std::string & msg) +std::optional parseJSONMessage(const std::string & msg, std::string_view source) { if (!msg.starts_with("@nix ")) return std::nullopt; try { return nlohmann::json::parse(std::string(msg, 5)); } catch (std::exception & e) { - printError("bad JSON log message from builder: %s", e.what()); + printError("bad JSON log message from %s: %s", + Uncolored(source), + e.what()); } return std::nullopt; } bool handleJSONLogMessage(nlohmann::json & json, const Activity & act, std::map & activities, - bool trusted) + std::string_view source, bool trusted) { try { std::string action = json["action"]; @@ -339,7 +341,8 @@ bool handleJSONLogMessage(nlohmann::json & json, return true; } catch (nlohmann::json::exception &e) { warn( - "warning: Unable to handle a JSON message from the builder: %s", + "Unable to handle a JSON message from %s: %s", + Uncolored(source), e.what() ); return false; @@ -347,12 +350,12 @@ bool handleJSONLogMessage(nlohmann::json & json, } bool handleJSONLogMessage(const std::string & msg, - const Activity & act, std::map & activities, bool trusted) + const Activity & act, std::map & activities, std::string_view source, bool trusted) { - auto json = parseJSONMessage(msg); + auto json = parseJSONMessage(msg, source); if (!json) return false; - return handleJSONLogMessage(*json, act, activities, trusted); + return handleJSONLogMessage(*json, act, activities, source, trusted); } Activity::~Activity() diff --git a/tests/functional/dependencies.nix b/tests/functional/dependencies.nix index 7c39321ee..944371053 100644 --- a/tests/functional/dependencies.nix +++ b/tests/functional/dependencies.nix @@ -32,17 +32,6 @@ let outputHash = "1dq9p0hnm1y75q2x40fws5887bq1r840hzdxak0a9djbwvx0b16d"; }; - unusual-logging = mkDerivation { - name = "unusual-logging"; - buildCommand = '' - { - echo "@nix 1" - echo "@nix {}" - echo '@nix {"action": null}' - } >&$NIX_LOG_FD - touch $out - ''; - }; in mkDerivation { name = "dependencies-top"; @@ -52,7 +41,6 @@ mkDerivation { input1_drv = input1; input2_drv = input2; input0_drv = input0; - unusual_logging_drv = unusual-logging; fod_input_drv = fod_input; meta.description = "Random test package"; } diff --git a/tests/functional/logging.sh b/tests/functional/logging.sh index 1ccc21d0b..7dcfa0b57 100644 --- a/tests/functional/logging.sh +++ b/tests/functional/logging.sh @@ -24,3 +24,6 @@ outp="$(nix-build -E \ test -d "$outp" nix log "$outp" + +# 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:' diff --git a/tests/functional/logging/unusual-logging.nix b/tests/functional/logging/unusual-logging.nix new file mode 100644 index 000000000..ddb8aa530 --- /dev/null +++ b/tests/functional/logging/unusual-logging.nix @@ -0,0 +1,16 @@ +let + inherit (import ../config.nix) mkDerivation; +in +mkDerivation { + name = "unusual-logging"; + buildCommand = '' + { + echo "@nix 1" + echo "@nix {}" + echo '@nix {"action": null}' + echo '@nix {"action": 123}' + echo '@nix ][' + } >&$NIX_LOG_FD + touch $out + ''; +}