Merge pull request #6029 from Ma27/nix-log-ssh-ng

ssh-ng: also store build logs to make them accessible by `nix log`
This commit is contained in:
Théophane Hufschmitt 2022-03-07 09:51:40 +01:00 committed by GitHub
commit a2ace54fe4
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
6 changed files with 89 additions and 47 deletions

View file

@ -1175,10 +1175,11 @@ bool DerivationGoal::isReadDesc(int fd)
return fd == hook->builderOut.readSide.get(); return fd == hook->builderOut.readSide.get();
} }
void DerivationGoal::handleChildOutput(int fd, std::string_view data) void DerivationGoal::handleChildOutput(int fd, std::string_view data)
{ {
if (isReadDesc(fd)) // local & `ssh://`-builds are dealt with here.
auto isWrittenToLog = isReadDesc(fd);
if (isWrittenToLog)
{ {
logSize += data.size(); logSize += data.size();
if (settings.maxLogSize && logSize > settings.maxLogSize) { if (settings.maxLogSize && logSize > settings.maxLogSize) {
@ -1207,7 +1208,16 @@ void DerivationGoal::handleChildOutput(int fd, std::string_view data)
if (hook && fd == hook->fromHook.readSide.get()) { if (hook && fd == hook->fromHook.readSide.get()) {
for (auto c : data) for (auto c : data)
if (c == '\n') { if (c == '\n') {
handleJSONLogMessage(currentHookLine, worker.act, hook->activities, true); auto json = parseJSONMessage(currentHookLine);
if (json) {
auto s = handleJSONLogMessage(*json, worker.act, hook->activities, true);
// ensure that logs from a builder using `ssh-ng://` as protocol
// are also available to `nix log`.
if (s && !isWrittenToLog && logSink && (*json)["type"] == resBuildLogLine) {
auto f = (*json)["fields"];
(*logSink)((f.size() > 0 ? f.at(0).get<std::string>() : "") + "\n");
}
}
currentHookLine.clear(); currentHookLine.clear();
} else } else
currentHookLine += c; currentHookLine += c;

View file

@ -266,51 +266,63 @@ static Logger::Fields getFields(nlohmann::json & json)
return fields; return fields;
} }
bool handleJSONLogMessage(const std::string & msg, std::optional<nlohmann::json> parseJSONMessage(const std::string & msg)
const Activity & act, std::map<ActivityId, Activity> & activities, bool trusted)
{ {
if (!hasPrefix(msg, "@nix ")) return false; if (!hasPrefix(msg, "@nix ")) return std::nullopt;
try { try {
auto json = nlohmann::json::parse(std::string(msg, 5)); return nlohmann::json::parse(std::string(msg, 5));
std::string action = json["action"];
if (action == "start") {
auto type = (ActivityType) json["type"];
if (trusted || type == actFileTransfer)
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) { } catch (std::exception & e) {
printError("bad JSON log message from builder: %s", e.what()); printError("bad JSON log message from builder: %s", e.what());
} }
return std::nullopt;
}
bool handleJSONLogMessage(nlohmann::json & json,
const Activity & act, std::map<ActivityId, Activity> & activities,
bool trusted)
{
std::string action = json["action"];
if (action == "start") {
auto type = (ActivityType) json["type"];
if (trusted || type == actFileTransfer)
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);
}
return true; return true;
} }
bool handleJSONLogMessage(const std::string & msg,
const Activity & act, std::map<ActivityId, Activity> & activities, bool trusted)
{
auto json = parseJSONMessage(msg);
if (!json) return false;
return handleJSONLogMessage(*json, act, activities, trusted);
}
Activity::~Activity() Activity::~Activity()
{ {
try { try {

View file

@ -4,6 +4,8 @@
#include "error.hh" #include "error.hh"
#include "config.hh" #include "config.hh"
#include <nlohmann/json_fwd.hpp>
namespace nix { namespace nix {
typedef enum { typedef enum {
@ -166,6 +168,12 @@ Logger * makeSimpleLogger(bool printBuildLogs = true);
Logger * makeJSONLogger(Logger & prevLogger); Logger * makeJSONLogger(Logger & prevLogger);
std::optional<nlohmann::json> parseJSONMessage(const std::string & msg);
bool handleJSONLogMessage(nlohmann::json & json,
const Activity & act, std::map<ActivityId, Activity> & activities,
bool trusted);
bool handleJSONLogMessage(const std::string & msg, bool handleJSONLogMessage(const std::string & msg,
const Activity & act, std::map<ActivityId, Activity> & activities, const Activity & act, std::map<ActivityId, Activity> & activities,
bool trusted); bool trusted);

View file

@ -11,13 +11,13 @@ let
args = ["sh" "-e" args.builder or (builtins.toFile "builder-${args.name}.sh" "if [ -e .attrs.sh ]; then source .attrs.sh; fi; eval \"$buildCommand\"")]; args = ["sh" "-e" args.builder or (builtins.toFile "builder-${args.name}.sh" "if [ -e .attrs.sh ]; then source .attrs.sh; fi; eval \"$buildCommand\"")];
outputHashMode = "recursive"; outputHashMode = "recursive";
outputHashAlgo = "sha256"; outputHashAlgo = "sha256";
} // removeAttrs args ["builder" "meta"]) } // removeAttrs args ["builder" "meta" "passthru"])
// { meta = args.meta or {}; }; // { meta = args.meta or {}; passthru = args.passthru or {}; };
input1 = mkDerivation { input1 = mkDerivation {
shell = busybox; shell = busybox;
name = "build-remote-input-1"; name = "build-remote-input-1";
buildCommand = "echo FOO > $out"; buildCommand = "echo hi-input1; echo FOO > $out";
requiredSystemFeatures = ["foo"]; requiredSystemFeatures = ["foo"];
outputHash = "sha256-FePFYIlMuycIXPZbWi7LGEiMmZSX9FMbaQenWBzm1Sc="; outputHash = "sha256-FePFYIlMuycIXPZbWi7LGEiMmZSX9FMbaQenWBzm1Sc=";
}; };
@ -25,7 +25,7 @@ let
input2 = mkDerivation { input2 = mkDerivation {
shell = busybox; shell = busybox;
name = "build-remote-input-2"; name = "build-remote-input-2";
buildCommand = "echo BAR > $out"; buildCommand = "echo hi; echo BAR > $out";
requiredSystemFeatures = ["bar"]; requiredSystemFeatures = ["bar"];
outputHash = "sha256-XArauVH91AVwP9hBBQNlkX9ccuPpSYx9o0zeIHb6e+Q="; outputHash = "sha256-XArauVH91AVwP9hBBQNlkX9ccuPpSYx9o0zeIHb6e+Q=";
}; };
@ -34,6 +34,7 @@ let
shell = busybox; shell = busybox;
name = "build-remote-input-3"; name = "build-remote-input-3";
buildCommand = '' buildCommand = ''
echo hi-input3
read x < ${input2} read x < ${input2}
echo $x BAZ > $out echo $x BAZ > $out
''; '';
@ -46,6 +47,7 @@ in
mkDerivation { mkDerivation {
shell = busybox; shell = busybox;
name = "build-remote"; name = "build-remote";
passthru = { inherit input1 input2 input3; };
buildCommand = buildCommand =
'' ''
read x < ${input1} read x < ${input1}

View file

@ -9,20 +9,20 @@ let
inherit system; inherit system;
builder = busybox; builder = busybox;
args = ["sh" "-e" args.builder or (builtins.toFile "builder-${args.name}.sh" "if [ -e .attrs.sh ]; then source .attrs.sh; fi; eval \"$buildCommand\"")]; args = ["sh" "-e" args.builder or (builtins.toFile "builder-${args.name}.sh" "if [ -e .attrs.sh ]; then source .attrs.sh; fi; eval \"$buildCommand\"")];
} // removeAttrs args ["builder" "meta"]) } // removeAttrs args ["builder" "meta" "passthru"])
// { meta = args.meta or {}; }; // { meta = args.meta or {}; passthru = args.passthru or {}; };
input1 = mkDerivation { input1 = mkDerivation {
shell = busybox; shell = busybox;
name = "build-remote-input-1"; name = "build-remote-input-1";
buildCommand = "echo FOO > $out"; buildCommand = "echo hi-input1; echo FOO > $out";
requiredSystemFeatures = ["foo"]; requiredSystemFeatures = ["foo"];
}; };
input2 = mkDerivation { input2 = mkDerivation {
shell = busybox; shell = busybox;
name = "build-remote-input-2"; name = "build-remote-input-2";
buildCommand = "echo BAR > $out"; buildCommand = "echo hi; echo BAR > $out";
requiredSystemFeatures = ["bar"]; requiredSystemFeatures = ["bar"];
}; };
@ -30,6 +30,7 @@ let
shell = busybox; shell = busybox;
name = "build-remote-input-3"; name = "build-remote-input-3";
buildCommand = '' buildCommand = ''
echo hi-input3
read x < ${input2} read x < ${input2}
echo $x BAZ > $out echo $x BAZ > $out
''; '';
@ -41,6 +42,7 @@ in
mkDerivation { mkDerivation {
shell = busybox; shell = busybox;
name = "build-remote"; name = "build-remote";
passthru = { inherit input1 input2 input3; };
buildCommand = buildCommand =
'' ''
read x < ${input1} read x < ${input1}

View file

@ -54,6 +54,14 @@ nix path-info --store $TEST_ROOT/machine3 --all \
| grep -v builder-build-remote-input-2.sh \ | grep -v builder-build-remote-input-2.sh \
| grep builder-build-remote-input-3.sh | grep builder-build-remote-input-3.sh
# Temporarily disabled because of https://github.com/NixOS/nix/issues/6209
if [[ -z "$CONTENT_ADDRESSED" ]]; then
for i in input1 input3; do
nix log --store $TEST_ROOT/machine0 --file "$file" --arg busybox $busybox passthru."$i" | grep hi-$i
done
fi
# Behavior of keep-failed # Behavior of keep-failed
out="$(nix-build 2>&1 failing.nix \ out="$(nix-build 2>&1 failing.nix \
--builders "$(join_by '; ' "${builders[@]}")" \ --builders "$(join_by '; ' "${builders[@]}")" \