Merge pull request #14788 from NixOS/coroutine-child-output
Way more RAII for `DerivationBuildingGoal`
This commit is contained in:
48
src/libstore/build/build-log.cc
Normal file
48
src/libstore/build/build-log.cc
Normal file
@@ -0,0 +1,48 @@
|
||||
#include "nix/store/build/build-log.hh"
|
||||
|
||||
namespace nix {
|
||||
|
||||
BuildLog::BuildLog(size_t maxTailLines, std::unique_ptr<Activity> act)
|
||||
: maxTailLines(maxTailLines)
|
||||
, act(std::move(act))
|
||||
{
|
||||
}
|
||||
|
||||
void BuildLog::operator()(std::string_view data)
|
||||
{
|
||||
for (auto c : data)
|
||||
if (c == '\r')
|
||||
currentLogLinePos = 0;
|
||||
else if (c == '\n')
|
||||
flushLine();
|
||||
else {
|
||||
if (currentLogLinePos >= currentLogLine.size())
|
||||
currentLogLine.resize(currentLogLinePos + 1);
|
||||
currentLogLine[currentLogLinePos++] = c;
|
||||
}
|
||||
}
|
||||
|
||||
void BuildLog::flush()
|
||||
{
|
||||
if (!currentLogLine.empty())
|
||||
flushLine();
|
||||
}
|
||||
|
||||
void BuildLog::flushLine()
|
||||
{
|
||||
// Truncate to actual content (currentLogLinePos may be less than size due to \r)
|
||||
currentLogLine.resize(currentLogLinePos);
|
||||
|
||||
if (!handleJSONLogMessage(currentLogLine, *act, builderActivities, "the derivation builder", false)) {
|
||||
// Line was not handled as JSON, emit and add to tail
|
||||
act->result(resBuildLogLine, currentLogLine);
|
||||
logTail.push_back(currentLogLine);
|
||||
if (logTail.size() > maxTailLines)
|
||||
logTail.pop_front();
|
||||
}
|
||||
|
||||
currentLogLine.clear();
|
||||
currentLogLinePos = 0;
|
||||
}
|
||||
|
||||
} // namespace nix
|
||||
@@ -40,37 +40,13 @@ DerivationBuildingGoal::DerivationBuildingGoal(
|
||||
worker.store.addTempRoot(this->drvPath);
|
||||
}
|
||||
|
||||
DerivationBuildingGoal::~DerivationBuildingGoal()
|
||||
{
|
||||
/* Careful: we should never ever throw an exception from a
|
||||
destructor. */
|
||||
#ifndef _WIN32 // TODO enable `DerivationBuilder` on Windows
|
||||
if (builder)
|
||||
builder.reset();
|
||||
#endif
|
||||
try {
|
||||
closeLogFile();
|
||||
} catch (...) {
|
||||
ignoreExceptionInDestructor();
|
||||
}
|
||||
}
|
||||
DerivationBuildingGoal::~DerivationBuildingGoal() = default;
|
||||
|
||||
std::string DerivationBuildingGoal::key()
|
||||
{
|
||||
return "dd$" + std::string(drvPath.name()) + "$" + worker.store.printStorePath(drvPath);
|
||||
}
|
||||
|
||||
void DerivationBuildingGoal::killChild()
|
||||
{
|
||||
#ifndef _WIN32 // TODO enable build hook on Windows
|
||||
hook.reset();
|
||||
#endif
|
||||
#ifndef _WIN32 // TODO enable `DerivationBuilder` on Windows
|
||||
if (builder && builder->killChild())
|
||||
worker.childTerminated(this);
|
||||
#endif
|
||||
}
|
||||
|
||||
std::string showKnownOutputs(const StoreDirConfig & store, const Derivation & drv)
|
||||
{
|
||||
std::string msg;
|
||||
@@ -146,6 +122,8 @@ Goal::Co DerivationBuildingGoal::gaveUpOnSubstitution(bool storeDerivation)
|
||||
writeDerivation(worker.store, *drv);
|
||||
}
|
||||
|
||||
StorePathSet inputPaths;
|
||||
|
||||
{
|
||||
/* If we get this far, we know no dynamic drvs inputs */
|
||||
|
||||
@@ -185,10 +163,23 @@ Goal::Co DerivationBuildingGoal::gaveUpOnSubstitution(bool storeDerivation)
|
||||
slot to become available, since we don't need one if there is a
|
||||
build hook. */
|
||||
co_await yield();
|
||||
co_return tryToBuild();
|
||||
co_return tryToBuild(std::move(inputPaths));
|
||||
}
|
||||
|
||||
Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
/**
|
||||
* RAII wrapper for build log file.
|
||||
* Constructor opens the log file, destructor closes it.
|
||||
*/
|
||||
struct LogFile
|
||||
{
|
||||
AutoCloseFD fd;
|
||||
std::shared_ptr<BufferedSink> fileSink, sink;
|
||||
|
||||
LogFile(Store & store, const StorePath & drvPath);
|
||||
~LogFile();
|
||||
};
|
||||
|
||||
Goal::Co DerivationBuildingGoal::tryToBuild(StorePathSet inputPaths)
|
||||
{
|
||||
auto drvOptions = [&] {
|
||||
DerivationOptions<SingleDerivedPath> temp;
|
||||
@@ -249,33 +240,6 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
}
|
||||
checkPathValidity(initialOutputs);
|
||||
|
||||
auto started = [&]() {
|
||||
auto msg =
|
||||
fmt(buildMode == bmRepair ? "repairing outputs of '%s'"
|
||||
: buildMode == bmCheck ? "checking outputs of '%s'"
|
||||
: "building '%s'",
|
||||
worker.store.printStorePath(drvPath));
|
||||
#ifndef _WIN32 // TODO enable build hook on Windows
|
||||
if (hook)
|
||||
msg += fmt(" on '%s'", hook->machineName);
|
||||
#endif
|
||||
act = std::make_unique<Activity>(
|
||||
*logger,
|
||||
lvlInfo,
|
||||
actBuild,
|
||||
msg,
|
||||
Logger::Fields{
|
||||
worker.store.printStorePath(drvPath),
|
||||
#ifndef _WIN32 // TODO enable build hook on Windows
|
||||
hook ? hook->machineName :
|
||||
#endif
|
||||
"",
|
||||
1,
|
||||
1});
|
||||
mcRunningBuilds = std::make_unique<MaintainCount<uint64_t>>(worker.runningBuilds);
|
||||
worker.updateProgress();
|
||||
};
|
||||
|
||||
/**
|
||||
* Activity that denotes waiting for a lock.
|
||||
*/
|
||||
@@ -366,7 +330,7 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
if (buildLocally) {
|
||||
useHook = false;
|
||||
} else {
|
||||
switch (tryBuildHook(initialOutputs, drvOptions)) {
|
||||
switch (tryBuildHook(drvOptions)) {
|
||||
case rpAccept:
|
||||
/* Yes, it has started doing so. Wait until we get
|
||||
EOF from the hook. */
|
||||
@@ -416,9 +380,6 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
Magenta(
|
||||
"/usr/sbin/softwareupdate --install-rosetta && launchctl stop org.nixos.nix-daemon"));
|
||||
|
||||
#ifndef _WIN32 // TODO enable `DerivationBuilder` on Windows
|
||||
builder.reset();
|
||||
#endif
|
||||
outputLocks.unlock();
|
||||
worker.permanentFailure = true;
|
||||
co_return doneFailure({BuildResult::Failure::InputRejected, std::move(msg)});
|
||||
@@ -433,103 +394,225 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
actLock.reset();
|
||||
|
||||
if (useHook) {
|
||||
buildResult.startTime = time(0); // inexact
|
||||
started();
|
||||
co_return buildWithHook(
|
||||
std::move(inputPaths), std::move(initialOutputs), std::move(drvOptions), std::move(outputLocks));
|
||||
} else {
|
||||
co_return buildLocally(
|
||||
std::move(inputPaths),
|
||||
std::move(initialOutputs),
|
||||
std::move(drvOptions),
|
||||
std::move(outputLocks),
|
||||
externalBuilder);
|
||||
}
|
||||
}
|
||||
|
||||
while (true) {
|
||||
auto event = co_await WaitForChildEvent{};
|
||||
if (auto * output = std::get_if<ChildOutput>(&event)) {
|
||||
co_await processChildOutput(output->fd, output->data);
|
||||
} else if (std::get_if<ChildEOF>(&event)) {
|
||||
if (!currentLogLine.empty())
|
||||
flushLine();
|
||||
break;
|
||||
} else if (auto * timeout = std::get_if<TimedOut>(&event)) {
|
||||
killChild();
|
||||
co_return doneFailure(std::move(*timeout));
|
||||
}
|
||||
}
|
||||
|
||||
#ifndef _WIN32
|
||||
assert(hook);
|
||||
#endif
|
||||
|
||||
trace("hook build done");
|
||||
|
||||
/* Since we got an EOF on the logger pipe, the builder is presumed
|
||||
to have terminated. In fact, the builder could also have
|
||||
simply have closed its end of the pipe, so just to be sure,
|
||||
kill it. */
|
||||
int status =
|
||||
#ifndef _WIN32 // TODO enable build hook on Windows
|
||||
hook->pid.kill();
|
||||
Goal::Co DerivationBuildingGoal::buildWithHook(
|
||||
StorePathSet inputPaths,
|
||||
std::map<std::string, InitialOutput> initialOutputs,
|
||||
DerivationOptions<StorePath> drvOptions,
|
||||
PathLocks outputLocks)
|
||||
{
|
||||
#ifdef _WIN32 // TODO enable build hook on Windows
|
||||
unreachable();
|
||||
#else
|
||||
0;
|
||||
#endif
|
||||
std::unique_ptr<HookInstance> hook = std::move(worker.hook);
|
||||
|
||||
debug("build hook for '%s' finished", worker.store.printStorePath(drvPath));
|
||||
|
||||
buildResult.timesBuilt++;
|
||||
buildResult.stopTime = time(0);
|
||||
|
||||
/* So the child is gone now. */
|
||||
worker.childTerminated(this);
|
||||
|
||||
/* Close the read side of the logger pipe. */
|
||||
#ifndef _WIN32 // TODO enable build hook on Windows
|
||||
hook->builderOut.readSide.close();
|
||||
hook->fromHook.readSide.close();
|
||||
#endif
|
||||
|
||||
/* Close the log file. */
|
||||
closeLogFile();
|
||||
|
||||
/* Check the exit status. */
|
||||
if (!statusOk(status)) {
|
||||
auto e = fixupBuilderFailureErrorMessage({BuildResult::Failure::MiscFailure, status, ""});
|
||||
|
||||
outputLocks.unlock();
|
||||
|
||||
/* TODO (once again) support fine-grained error codes, see issue #12641. */
|
||||
|
||||
co_return doneFailure(std::move(e));
|
||||
}
|
||||
|
||||
/* Compute the FS closure of the outputs and register them as
|
||||
being valid. */
|
||||
auto builtOutputs =
|
||||
/* When using a build hook, the build hook can register the output
|
||||
as valid (by doing `nix-store --import'). If so we don't have
|
||||
to do anything here.
|
||||
|
||||
We can only early return when the outputs are known a priori. For
|
||||
floating content-addressing derivations this isn't the case.
|
||||
|
||||
Aborts if any output is not valid or corrupt, and otherwise
|
||||
returns a 'SingleDrvOutputs' structure containing all outputs.
|
||||
*/
|
||||
[&] {
|
||||
auto [allValid, validOutputs] = checkPathValidity(initialOutputs);
|
||||
if (!allValid)
|
||||
throw Error("some outputs are unexpectedly invalid");
|
||||
return validOutputs;
|
||||
}();
|
||||
|
||||
StorePathSet outputPaths;
|
||||
for (auto & [_, output] : builtOutputs)
|
||||
outputPaths.insert(output.outPath);
|
||||
runPostBuildHook(worker.store, *logger, drvPath, outputPaths);
|
||||
|
||||
/* It is now safe to delete the lock files, since all future
|
||||
lockers will see that the output paths are valid; they will
|
||||
not create new lock files with the same names as the old
|
||||
(unlinked) lock files. */
|
||||
outputLocks.setDeletion(true);
|
||||
outputLocks.unlock();
|
||||
|
||||
co_return doneSuccess(BuildResult::Success::Built, std::move(builtOutputs));
|
||||
try {
|
||||
hook->machineName = readLine(hook->fromHook.readSide.get());
|
||||
} catch (Error & e) {
|
||||
e.addTrace({}, "while reading the machine name from the build hook");
|
||||
throw;
|
||||
}
|
||||
|
||||
CommonProto::WriteConn conn{hook->sink};
|
||||
|
||||
/* Tell the hook all the inputs that have to be copied to the
|
||||
remote system. */
|
||||
CommonProto::write(worker.store, conn, inputPaths);
|
||||
|
||||
/* Tell the hooks the missing outputs that have to be copied back
|
||||
from the remote system. */
|
||||
{
|
||||
StringSet missingOutputs;
|
||||
for (auto & [outputName, status] : initialOutputs) {
|
||||
// XXX: Does this include known CA outputs?
|
||||
if (buildMode != bmCheck && status.known && status.known->isValid())
|
||||
continue;
|
||||
missingOutputs.insert(outputName);
|
||||
}
|
||||
CommonProto::write(worker.store, conn, missingOutputs);
|
||||
}
|
||||
|
||||
hook->sink = FdSink();
|
||||
hook->toHook.writeSide.close();
|
||||
|
||||
/* Create the log file and pipe. */
|
||||
std::unique_ptr<LogFile> logFile = std::make_unique<LogFile>(worker.store, drvPath);
|
||||
|
||||
std::set<MuxablePipePollState::CommChannel> fds;
|
||||
fds.insert(hook->fromHook.readSide.get());
|
||||
fds.insert(hook->builderOut.readSide.get());
|
||||
worker.childStarted(shared_from_this(), fds, false, false);
|
||||
|
||||
buildResult.startTime = time(0); // inexact
|
||||
|
||||
auto msg =
|
||||
fmt(buildMode == bmRepair ? "repairing outputs of '%s'"
|
||||
: buildMode == bmCheck ? "checking outputs of '%s'"
|
||||
: "building '%s'",
|
||||
worker.store.printStorePath(drvPath));
|
||||
msg += fmt(" on '%s'", hook->machineName);
|
||||
|
||||
std::unique_ptr<BuildLog> buildLog = std::make_unique<BuildLog>(
|
||||
settings.logLines,
|
||||
std::make_unique<Activity>(
|
||||
*logger,
|
||||
lvlInfo,
|
||||
actBuild,
|
||||
msg,
|
||||
Logger::Fields{worker.store.printStorePath(drvPath), hook->machineName, 1, 1}));
|
||||
mcRunningBuilds = std::make_unique<MaintainCount<uint64_t>>(worker.runningBuilds);
|
||||
worker.updateProgress();
|
||||
|
||||
std::string currentHookLine;
|
||||
uint64_t logSize = 0;
|
||||
|
||||
while (true) {
|
||||
auto event = co_await WaitForChildEvent{};
|
||||
if (auto * output = std::get_if<ChildOutput>(&event)) {
|
||||
auto & fd = output->fd;
|
||||
auto & data = output->data;
|
||||
if (fd == hook->builderOut.readSide.get()) {
|
||||
logSize += data.size();
|
||||
if (settings.maxLogSize && logSize > settings.maxLogSize) {
|
||||
hook.reset();
|
||||
co_return doneFailureLogTooLong(*buildLog);
|
||||
}
|
||||
(*buildLog)(data);
|
||||
if (logFile->sink)
|
||||
(*logFile->sink)(data);
|
||||
} else if (fd == hook->fromHook.readSide.get()) {
|
||||
for (auto c : data)
|
||||
if (c == '\n') {
|
||||
auto json = parseJSONMessage(currentHookLine, "the derivation builder");
|
||||
if (json) {
|
||||
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 && logFile->sink) {
|
||||
const auto type = (*json)["type"];
|
||||
const auto fields = (*json)["fields"];
|
||||
if (type == resBuildLogLine) {
|
||||
(*logFile->sink)((fields.size() > 0 ? fields[0].get<std::string>() : "") + "\n");
|
||||
} else if (type == resSetPhase && !fields.is_null()) {
|
||||
const auto phase = fields[0];
|
||||
if (!phase.is_null()) {
|
||||
// nixpkgs' stdenv produces lines in the log to signal
|
||||
// phase changes.
|
||||
// We want to get the same lines in case of remote builds.
|
||||
// The format is:
|
||||
// @nix { "action": "setPhase", "phase": "$curPhase" }
|
||||
const auto logLine =
|
||||
nlohmann::json::object({{"action", "setPhase"}, {"phase", phase}});
|
||||
(*logFile->sink)(
|
||||
"@nix "
|
||||
+ logLine.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace)
|
||||
+ "\n");
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
currentHookLine.clear();
|
||||
} else
|
||||
currentHookLine += c;
|
||||
}
|
||||
} else if (std::get_if<ChildEOF>(&event)) {
|
||||
buildLog->flush();
|
||||
break;
|
||||
} else if (auto * timeout = std::get_if<TimedOut>(&event)) {
|
||||
hook.reset();
|
||||
co_return doneFailure(std::move(*timeout));
|
||||
}
|
||||
}
|
||||
|
||||
trace("hook build done");
|
||||
|
||||
/* Since we got an EOF on the logger pipe, the builder is presumed
|
||||
to have terminated. In fact, the builder could also have
|
||||
simply have closed its end of the pipe, so just to be sure,
|
||||
kill it. */
|
||||
int status = hook->pid.kill();
|
||||
|
||||
debug("build hook for '%s' finished", worker.store.printStorePath(drvPath));
|
||||
|
||||
buildResult.timesBuilt++;
|
||||
buildResult.stopTime = time(0);
|
||||
|
||||
/* So the child is gone now. */
|
||||
worker.childTerminated(this);
|
||||
|
||||
/* Close the read side of the logger pipe. */
|
||||
hook->builderOut.readSide.close();
|
||||
hook->fromHook.readSide.close();
|
||||
|
||||
/* Close the log file. */
|
||||
logFile.reset();
|
||||
|
||||
/* Check the exit status. */
|
||||
if (!statusOk(status)) {
|
||||
auto e = fixupBuilderFailureErrorMessage({BuildResult::Failure::MiscFailure, status, ""}, *buildLog);
|
||||
|
||||
outputLocks.unlock();
|
||||
|
||||
/* TODO (once again) support fine-grained error codes, see issue #12641. */
|
||||
|
||||
co_return doneFailure(std::move(e));
|
||||
}
|
||||
|
||||
/* Compute the FS closure of the outputs and register them as
|
||||
being valid. */
|
||||
auto builtOutputs =
|
||||
/* When using a build hook, the build hook can register the output
|
||||
as valid (by doing `nix-store --import'). If so we don't have
|
||||
to do anything here.
|
||||
|
||||
We can only early return when the outputs are known a priori. For
|
||||
floating content-addressing derivations this isn't the case.
|
||||
|
||||
Aborts if any output is not valid or corrupt, and otherwise
|
||||
returns a 'SingleDrvOutputs' structure containing all outputs.
|
||||
*/
|
||||
[&] {
|
||||
auto [allValid, validOutputs] = checkPathValidity(initialOutputs);
|
||||
if (!allValid)
|
||||
throw Error("some outputs are unexpectedly invalid");
|
||||
return validOutputs;
|
||||
}();
|
||||
|
||||
StorePathSet outputPaths;
|
||||
for (auto & [_, output] : builtOutputs)
|
||||
outputPaths.insert(output.outPath);
|
||||
runPostBuildHook(worker.store, *logger, drvPath, outputPaths);
|
||||
|
||||
/* It is now safe to delete the lock files, since all future
|
||||
lockers will see that the output paths are valid; they will
|
||||
not create new lock files with the same names as the old
|
||||
(unlinked) lock files. */
|
||||
outputLocks.setDeletion(true);
|
||||
outputLocks.unlock();
|
||||
|
||||
co_return doneSuccess(BuildResult::Success::Built, std::move(builtOutputs));
|
||||
#endif
|
||||
}
|
||||
|
||||
Goal::Co DerivationBuildingGoal::buildLocally(
|
||||
StorePathSet inputPaths,
|
||||
std::map<std::string, InitialOutput> initialOutputs,
|
||||
DerivationOptions<StorePath> drvOptions,
|
||||
PathLocks outputLocks,
|
||||
const ExternalBuilder * externalBuilder)
|
||||
{
|
||||
co_await yield();
|
||||
|
||||
if (!dynamic_cast<LocalStore *>(&worker.store)) {
|
||||
@@ -545,8 +628,29 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
#ifdef _WIN32 // TODO enable `DerivationBuilder` on Windows
|
||||
throw UnimplementedError("building derivations is not yet implemented on Windows");
|
||||
#else
|
||||
assert(!hook);
|
||||
std::unique_ptr<BuildLog> buildLog;
|
||||
std::unique_ptr<LogFile> logFile;
|
||||
|
||||
auto openLogFile = [&]() { logFile = std::make_unique<LogFile>(worker.store, drvPath); };
|
||||
|
||||
auto closeLogFile = [&]() { logFile.reset(); };
|
||||
|
||||
auto started = [&]() {
|
||||
auto msg =
|
||||
fmt(buildMode == bmRepair ? "repairing outputs of '%s'"
|
||||
: buildMode == bmCheck ? "checking outputs of '%s'"
|
||||
: "building '%s'",
|
||||
worker.store.printStorePath(drvPath));
|
||||
buildLog = std::make_unique<BuildLog>(
|
||||
settings.logLines,
|
||||
std::make_unique<Activity>(
|
||||
*logger, lvlInfo, actBuild, msg, Logger::Fields{worker.store.printStorePath(drvPath), "", 1, 1}));
|
||||
mcRunningBuilds = std::make_unique<MaintainCount<uint64_t>>(worker.runningBuilds);
|
||||
worker.updateProgress();
|
||||
};
|
||||
|
||||
std::unique_ptr<Activity> actLock;
|
||||
std::unique_ptr<DerivationBuilder> builder;
|
||||
Descriptor builderOut;
|
||||
|
||||
// Will continue here while waiting for a build user below
|
||||
@@ -556,7 +660,7 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
if (curBuilds >= settings.maxBuildJobs) {
|
||||
outputLocks.unlock();
|
||||
co_await waitForBuildSlot();
|
||||
co_return tryToBuild();
|
||||
co_return tryToBuild(std::move(inputPaths));
|
||||
}
|
||||
|
||||
if (!builder) {
|
||||
@@ -567,10 +671,16 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
struct DerivationBuildingGoalCallbacks : DerivationBuilderCallbacks
|
||||
{
|
||||
DerivationBuildingGoal & goal;
|
||||
std::function<void()> openLogFileFn;
|
||||
std::function<void()> closeLogFileFn;
|
||||
|
||||
DerivationBuildingGoalCallbacks(
|
||||
DerivationBuildingGoal & goal, std::unique_ptr<DerivationBuilder> & builder)
|
||||
DerivationBuildingGoal & goal,
|
||||
std::function<void()> openLogFileFn,
|
||||
std::function<void()> closeLogFileFn)
|
||||
: goal{goal}
|
||||
, openLogFileFn{std::move(openLogFileFn)}
|
||||
, closeLogFileFn{std::move(closeLogFileFn)}
|
||||
{
|
||||
}
|
||||
|
||||
@@ -581,14 +691,14 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
goal.worker.childTerminated(&goal);
|
||||
}
|
||||
|
||||
std::filesystem::path openLogFile() override
|
||||
void openLogFile() override
|
||||
{
|
||||
return goal.openLogFile();
|
||||
openLogFileFn();
|
||||
}
|
||||
|
||||
void closeLogFile() override
|
||||
{
|
||||
goal.closeLogFile();
|
||||
closeLogFileFn();
|
||||
}
|
||||
};
|
||||
|
||||
@@ -638,15 +748,16 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
|
||||
/* If we have to wait and retry (see below), then `builder` will
|
||||
already be created, so we don't need to create it again. */
|
||||
builder = externalBuilder ? makeExternalDerivationBuilder(
|
||||
*localStoreP,
|
||||
std::make_unique<DerivationBuildingGoalCallbacks>(*this, builder),
|
||||
std::move(params),
|
||||
*externalBuilder)
|
||||
: makeDerivationBuilder(
|
||||
*localStoreP,
|
||||
std::make_unique<DerivationBuildingGoalCallbacks>(*this, builder),
|
||||
std::move(params));
|
||||
builder = externalBuilder
|
||||
? makeExternalDerivationBuilder(
|
||||
*localStoreP,
|
||||
std::make_unique<DerivationBuildingGoalCallbacks>(*this, openLogFile, closeLogFile),
|
||||
std::move(params),
|
||||
*externalBuilder)
|
||||
: makeDerivationBuilder(
|
||||
*localStoreP,
|
||||
std::make_unique<DerivationBuildingGoalCallbacks>(*this, openLogFile, closeLogFile),
|
||||
std::move(params));
|
||||
}
|
||||
|
||||
if (auto builderOutOpt = builder->startBuild()) {
|
||||
@@ -671,16 +782,28 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
|
||||
started();
|
||||
|
||||
uint64_t logSize = 0;
|
||||
|
||||
while (true) {
|
||||
auto event = co_await WaitForChildEvent{};
|
||||
if (auto * output = std::get_if<ChildOutput>(&event)) {
|
||||
co_await processChildOutput(output->fd, output->data);
|
||||
if (output->fd == builder->builderOut.get()) {
|
||||
logSize += output->data.size();
|
||||
if (settings.maxLogSize && logSize > settings.maxLogSize) {
|
||||
if (builder->killChild())
|
||||
worker.childTerminated(this);
|
||||
co_return doneFailureLogTooLong(*buildLog);
|
||||
}
|
||||
(*buildLog)(output->data);
|
||||
if (logFile->sink)
|
||||
(*logFile->sink)(output->data);
|
||||
}
|
||||
} else if (std::get_if<ChildEOF>(&event)) {
|
||||
if (!currentLogLine.empty())
|
||||
flushLine();
|
||||
buildLog->flush();
|
||||
break;
|
||||
} else if (auto * timeout = std::get_if<TimedOut>(&event)) {
|
||||
killChild();
|
||||
if (builder->killChild())
|
||||
worker.childTerminated(this);
|
||||
co_return doneFailure(std::move(*timeout));
|
||||
}
|
||||
}
|
||||
@@ -693,7 +816,7 @@ Goal::Co DerivationBuildingGoal::tryToBuild()
|
||||
} catch (BuilderFailureError & e) {
|
||||
builder.reset();
|
||||
outputLocks.unlock();
|
||||
co_return doneFailure(fixupBuilderFailureErrorMessage(std::move(e)));
|
||||
co_return doneFailure(fixupBuilderFailureErrorMessage(std::move(e), *buildLog));
|
||||
} catch (BuildError & e) {
|
||||
builder.reset();
|
||||
outputLocks.unlock();
|
||||
@@ -814,7 +937,7 @@ static void runPostBuildHook(
|
||||
});
|
||||
}
|
||||
|
||||
BuildError DerivationBuildingGoal::fixupBuilderFailureErrorMessage(BuilderFailureError e)
|
||||
BuildError DerivationBuildingGoal::fixupBuilderFailureErrorMessage(BuilderFailureError e, BuildLog & buildLog)
|
||||
{
|
||||
auto msg =
|
||||
fmt("Cannot build '%s'.\n"
|
||||
@@ -824,6 +947,7 @@ BuildError DerivationBuildingGoal::fixupBuilderFailureErrorMessage(BuilderFailur
|
||||
|
||||
msg += showKnownOutputs(worker.store, *drv);
|
||||
|
||||
auto & logTail = buildLog.getTail();
|
||||
if (!logger->isVerbose() && !logTail.empty()) {
|
||||
msg += fmt("\nLast %d log lines:\n", logTail.size());
|
||||
for (auto & line : logTail) {
|
||||
@@ -846,8 +970,7 @@ BuildError DerivationBuildingGoal::fixupBuilderFailureErrorMessage(BuilderFailur
|
||||
return BuildError{e.status, msg};
|
||||
}
|
||||
|
||||
HookReply DerivationBuildingGoal::tryBuildHook(
|
||||
const std::map<std::string, InitialOutput> & initialOutputs, const DerivationOptions<StorePath> & drvOptions)
|
||||
HookReply DerivationBuildingGoal::tryBuildHook(const DerivationOptions<StorePath> & drvOptions)
|
||||
{
|
||||
#ifdef _WIN32 // TODO enable build hook on Windows
|
||||
return rpDecline;
|
||||
@@ -912,61 +1035,19 @@ HookReply DerivationBuildingGoal::tryBuildHook(
|
||||
throw;
|
||||
}
|
||||
|
||||
hook = std::move(worker.hook);
|
||||
|
||||
try {
|
||||
hook->machineName = readLine(hook->fromHook.readSide.get());
|
||||
} catch (Error & e) {
|
||||
e.addTrace({}, "while reading the machine name from the build hook");
|
||||
throw;
|
||||
}
|
||||
|
||||
CommonProto::WriteConn conn{hook->sink};
|
||||
|
||||
/* Tell the hook all the inputs that have to be copied to the
|
||||
remote system. */
|
||||
CommonProto::write(worker.store, conn, inputPaths);
|
||||
|
||||
/* Tell the hooks the missing outputs that have to be copied back
|
||||
from the remote system. */
|
||||
{
|
||||
StringSet missingOutputs;
|
||||
for (auto & [outputName, status] : initialOutputs) {
|
||||
// XXX: Does this include known CA outputs?
|
||||
if (buildMode != bmCheck && status.known && status.known->isValid())
|
||||
continue;
|
||||
missingOutputs.insert(outputName);
|
||||
}
|
||||
CommonProto::write(worker.store, conn, missingOutputs);
|
||||
}
|
||||
|
||||
hook->sink = FdSink();
|
||||
hook->toHook.writeSide.close();
|
||||
|
||||
/* Create the log file and pipe. */
|
||||
[[maybe_unused]] Path logFile = openLogFile();
|
||||
|
||||
std::set<MuxablePipePollState::CommChannel> fds;
|
||||
fds.insert(hook->fromHook.readSide.get());
|
||||
fds.insert(hook->builderOut.readSide.get());
|
||||
worker.childStarted(shared_from_this(), fds, false, false);
|
||||
|
||||
return rpAccept;
|
||||
#endif
|
||||
}
|
||||
|
||||
Path DerivationBuildingGoal::openLogFile()
|
||||
LogFile::LogFile(Store & store, const StorePath & drvPath)
|
||||
{
|
||||
logSize = 0;
|
||||
|
||||
if (!settings.keepLog)
|
||||
return "";
|
||||
return;
|
||||
|
||||
auto baseName = std::string(baseNameOf(worker.store.printStorePath(drvPath)));
|
||||
auto baseName = std::string(baseNameOf(store.printStorePath(drvPath)));
|
||||
|
||||
/* Create a log file. */
|
||||
Path logDir;
|
||||
if (auto localStore = dynamic_cast<LocalStore *>(&worker.store))
|
||||
if (auto localStore = dynamic_cast<LocalStore *>(&store))
|
||||
logDir = localStore->config->logDir;
|
||||
else
|
||||
logDir = settings.nixLogDir;
|
||||
@@ -975,7 +1056,7 @@ Path DerivationBuildingGoal::openLogFile()
|
||||
|
||||
Path logFileName = fmt("%s/%s%s", dir, baseName.substr(2), settings.compressLog ? ".bz2" : "");
|
||||
|
||||
fdLogFile = toDescriptor(open(
|
||||
fd = toDescriptor(open(
|
||||
logFileName.c_str(),
|
||||
O_CREAT | O_WRONLY | O_TRUNC
|
||||
#ifndef _WIN32
|
||||
@@ -983,122 +1064,37 @@ Path DerivationBuildingGoal::openLogFile()
|
||||
#endif
|
||||
,
|
||||
0666));
|
||||
if (!fdLogFile)
|
||||
if (!fd)
|
||||
throw SysError("creating log file '%1%'", logFileName);
|
||||
|
||||
logFileSink = std::make_shared<FdSink>(fdLogFile.get());
|
||||
fileSink = std::make_shared<FdSink>(fd.get());
|
||||
|
||||
if (settings.compressLog)
|
||||
logSink = std::shared_ptr<CompressionSink>(makeCompressionSink(CompressionAlgo::bzip2, *logFileSink));
|
||||
sink = std::shared_ptr<CompressionSink>(makeCompressionSink(CompressionAlgo::bzip2, *fileSink));
|
||||
else
|
||||
logSink = logFileSink;
|
||||
|
||||
return logFileName;
|
||||
sink = fileSink;
|
||||
}
|
||||
|
||||
void DerivationBuildingGoal::closeLogFile()
|
||||
LogFile::~LogFile()
|
||||
{
|
||||
auto logSink2 = std::dynamic_pointer_cast<CompressionSink>(logSink);
|
||||
if (logSink2)
|
||||
logSink2->finish();
|
||||
if (logFileSink)
|
||||
logFileSink->flush();
|
||||
logSink = logFileSink = 0;
|
||||
fdLogFile.close();
|
||||
}
|
||||
|
||||
bool DerivationBuildingGoal::isReadDesc(Descriptor fd)
|
||||
{
|
||||
#ifdef _WIN32 // TODO enable build hook on Windows
|
||||
return false;
|
||||
#else
|
||||
return (hook && fd == hook->builderOut.readSide.get()) || (builder && fd == builder->builderOut.get());
|
||||
#endif
|
||||
}
|
||||
|
||||
Goal::Co DerivationBuildingGoal::processChildOutput(Descriptor fd, std::string_view data)
|
||||
{
|
||||
// local & `ssh://`-builds are dealt with here.
|
||||
auto isWrittenToLog = isReadDesc(fd);
|
||||
if (isWrittenToLog) {
|
||||
logSize += data.size();
|
||||
if (settings.maxLogSize && logSize > settings.maxLogSize) {
|
||||
killChild();
|
||||
co_return doneFailure(BuildError(
|
||||
BuildResult::Failure::LogLimitExceeded,
|
||||
"%s killed after writing more than %d bytes of log output",
|
||||
getName(),
|
||||
settings.maxLogSize));
|
||||
}
|
||||
|
||||
for (auto c : data)
|
||||
if (c == '\r')
|
||||
currentLogLinePos = 0;
|
||||
else if (c == '\n')
|
||||
flushLine();
|
||||
else {
|
||||
if (currentLogLinePos >= currentLogLine.size())
|
||||
currentLogLine.resize(currentLogLinePos + 1);
|
||||
currentLogLine[currentLogLinePos++] = c;
|
||||
}
|
||||
|
||||
if (logSink)
|
||||
(*logSink)(data);
|
||||
try {
|
||||
auto sink2 = std::dynamic_pointer_cast<CompressionSink>(sink);
|
||||
if (sink2)
|
||||
sink2->finish();
|
||||
if (fileSink)
|
||||
fileSink->flush();
|
||||
} catch (...) {
|
||||
ignoreExceptionInDestructor();
|
||||
}
|
||||
|
||||
#ifndef _WIN32 // TODO enable build hook on Windows
|
||||
if (hook && fd == hook->fromHook.readSide.get()) {
|
||||
for (auto c : data)
|
||||
if (c == '\n') {
|
||||
auto json = parseJSONMessage(currentHookLine, "the derivation builder");
|
||||
if (json) {
|
||||
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 && !isWrittenToLog && logSink) {
|
||||
const auto type = (*json)["type"];
|
||||
const auto fields = (*json)["fields"];
|
||||
if (type == resBuildLogLine) {
|
||||
(*logSink)((fields.size() > 0 ? fields[0].get<std::string>() : "") + "\n");
|
||||
} else if (type == resSetPhase && !fields.is_null()) {
|
||||
const auto phase = fields[0];
|
||||
if (!phase.is_null()) {
|
||||
// nixpkgs' stdenv produces lines in the log to signal
|
||||
// phase changes.
|
||||
// We want to get the same lines in case of remote builds.
|
||||
// The format is:
|
||||
// @nix { "action": "setPhase", "phase": "$curPhase" }
|
||||
const auto logLine = nlohmann::json::object({{"action", "setPhase"}, {"phase", phase}});
|
||||
(*logSink)(
|
||||
"@nix " + logLine.dump(-1, ' ', false, nlohmann::json::error_handler_t::replace)
|
||||
+ "\n");
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
currentHookLine.clear();
|
||||
} else
|
||||
currentHookLine += c;
|
||||
}
|
||||
#endif
|
||||
co_return Return{};
|
||||
}
|
||||
|
||||
void DerivationBuildingGoal::flushLine()
|
||||
Goal::Done DerivationBuildingGoal::doneFailureLogTooLong(BuildLog & buildLog)
|
||||
{
|
||||
if (handleJSONLogMessage(currentLogLine, *act, builderActivities, "the derivation builder", false))
|
||||
;
|
||||
|
||||
else {
|
||||
logTail.push_back(currentLogLine);
|
||||
if (logTail.size() > settings.logLines)
|
||||
logTail.pop_front();
|
||||
|
||||
act->result(resBuildLogLine, currentLogLine);
|
||||
}
|
||||
|
||||
currentLogLine = "";
|
||||
currentLogLinePos = 0;
|
||||
return doneFailure(BuildError(
|
||||
BuildResult::Failure::LogLimitExceeded,
|
||||
"%s killed after writing more than %d bytes of log output",
|
||||
getName(),
|
||||
settings.maxLogSize));
|
||||
}
|
||||
|
||||
std::map<std::string, std::optional<StorePath>> DerivationBuildingGoal::queryPartialDerivationOutputMap()
|
||||
|
||||
84
src/libstore/include/nix/store/build/build-log.hh
Normal file
84
src/libstore/include/nix/store/build/build-log.hh
Normal file
@@ -0,0 +1,84 @@
|
||||
#pragma once
|
||||
///@file
|
||||
|
||||
#include "nix/util/logging.hh"
|
||||
#include "nix/util/serialise.hh"
|
||||
|
||||
#include <list>
|
||||
#include <map>
|
||||
#include <string>
|
||||
|
||||
namespace nix {
|
||||
|
||||
/**
|
||||
* Line buffering and log tracking for build output.
|
||||
*
|
||||
* This class handles:
|
||||
* - Owning the build Activity for logging
|
||||
* - Buffering partial lines (handling \r and \n)
|
||||
* - Maintaining a tail of recent log lines (for error messages)
|
||||
* - Processing JSON log messages via handleJSONLogMessage
|
||||
*
|
||||
* Implements Sink so it can be used as a data destination.
|
||||
* I/O is handled separately by the caller.
|
||||
*/
|
||||
struct BuildLog : Sink
|
||||
{
|
||||
private:
|
||||
size_t maxTailLines;
|
||||
|
||||
std::list<std::string> logTail;
|
||||
std::string currentLogLine;
|
||||
size_t currentLogLinePos = 0; // to handle carriage return
|
||||
|
||||
void flushLine();
|
||||
|
||||
public:
|
||||
/**
|
||||
* The build activity. Owned by BuildLog.
|
||||
*/
|
||||
std::unique_ptr<Activity> act;
|
||||
|
||||
/**
|
||||
* Map for tracking nested activities from JSON messages.
|
||||
*/
|
||||
std::map<ActivityId, Activity> builderActivities;
|
||||
|
||||
/**
|
||||
* @param maxTailLines Maximum number of tail lines to keep
|
||||
* @param act Activity for this build
|
||||
*/
|
||||
BuildLog(size_t maxTailLines, std::unique_ptr<Activity> act);
|
||||
|
||||
/**
|
||||
* Process output data from child process.
|
||||
* Handles JSON log messages and emits regular lines to activity.
|
||||
* @param data Raw output data from child
|
||||
*/
|
||||
void operator()(std::string_view data) override;
|
||||
|
||||
/**
|
||||
* Flush any remaining partial line.
|
||||
* Call this when the child process exits.
|
||||
*/
|
||||
void flush();
|
||||
|
||||
/**
|
||||
* Get the most recent log lines.
|
||||
* Used for including in error messages.
|
||||
*/
|
||||
const std::list<std::string> & getTail() const
|
||||
{
|
||||
return logTail;
|
||||
}
|
||||
|
||||
/**
|
||||
* Check if there's an incomplete line buffered.
|
||||
*/
|
||||
bool hasPartialLine() const
|
||||
{
|
||||
return !currentLogLine.empty();
|
||||
}
|
||||
};
|
||||
|
||||
} // namespace nix
|
||||
@@ -111,7 +111,7 @@ struct DerivationBuilderCallbacks
|
||||
/**
|
||||
* Open a log file and a pipe to it.
|
||||
*/
|
||||
virtual std::filesystem::path openLogFile() = 0;
|
||||
virtual void openLogFile() = 0;
|
||||
|
||||
/**
|
||||
* Close the log file.
|
||||
|
||||
@@ -9,12 +9,14 @@
|
||||
#include "nix/store/store-api.hh"
|
||||
#include "nix/store/pathlocks.hh"
|
||||
#include "nix/store/build/goal.hh"
|
||||
#include "nix/store/build/build-log.hh"
|
||||
|
||||
namespace nix {
|
||||
|
||||
using std::map;
|
||||
|
||||
struct BuilderFailureError;
|
||||
struct ExternalBuilder;
|
||||
#ifndef _WIN32 // TODO enable build hook on Windows
|
||||
struct HookInstance;
|
||||
struct DerivationBuilder;
|
||||
@@ -45,93 +47,46 @@ struct DerivationBuildingGoal : public Goal
|
||||
private:
|
||||
|
||||
/** The path of the derivation. */
|
||||
StorePath drvPath;
|
||||
const StorePath drvPath;
|
||||
|
||||
/**
|
||||
* The derivation stored at drvPath.
|
||||
*/
|
||||
std::unique_ptr<Derivation> drv;
|
||||
const std::unique_ptr<Derivation> drv;
|
||||
|
||||
/**
|
||||
* The remainder is state held during the build.
|
||||
*/
|
||||
|
||||
/**
|
||||
* All input paths (that is, the union of FS closures of the
|
||||
* immediate input paths).
|
||||
*/
|
||||
StorePathSet inputPaths;
|
||||
|
||||
/**
|
||||
* File descriptor for the log file.
|
||||
*/
|
||||
AutoCloseFD fdLogFile;
|
||||
std::shared_ptr<BufferedSink> logFileSink, logSink;
|
||||
|
||||
/**
|
||||
* Number of bytes received from the builder's stdout/stderr.
|
||||
*/
|
||||
unsigned long logSize;
|
||||
|
||||
/**
|
||||
* The most recent log lines.
|
||||
*/
|
||||
std::list<std::string> logTail;
|
||||
|
||||
std::string currentLogLine;
|
||||
size_t currentLogLinePos = 0; // to handle carriage return
|
||||
|
||||
std::string currentHookLine;
|
||||
|
||||
#ifndef _WIN32 // TODO enable build hook on Windows
|
||||
/**
|
||||
* The build hook.
|
||||
*/
|
||||
std::unique_ptr<HookInstance> hook;
|
||||
|
||||
std::unique_ptr<DerivationBuilder> builder;
|
||||
#endif
|
||||
|
||||
BuildMode buildMode;
|
||||
const BuildMode buildMode;
|
||||
|
||||
std::unique_ptr<MaintainCount<uint64_t>> mcRunningBuilds;
|
||||
|
||||
std::unique_ptr<Activity> act;
|
||||
|
||||
std::map<ActivityId, Activity> builderActivities;
|
||||
|
||||
std::string key() override;
|
||||
|
||||
/**
|
||||
* The states.
|
||||
*/
|
||||
Co gaveUpOnSubstitution(bool storeDerivation);
|
||||
Co tryToBuild();
|
||||
Co tryToBuild(StorePathSet inputPaths);
|
||||
Co buildWithHook(
|
||||
StorePathSet inputPaths,
|
||||
std::map<std::string, InitialOutput> initialOutputs,
|
||||
DerivationOptions<StorePath> drvOptions,
|
||||
PathLocks outputLocks);
|
||||
Co buildLocally(
|
||||
StorePathSet inputPaths,
|
||||
std::map<std::string, InitialOutput> initialOutputs,
|
||||
DerivationOptions<StorePath> drvOptions,
|
||||
PathLocks outputLocks,
|
||||
const ExternalBuilder * externalBuilder);
|
||||
|
||||
/**
|
||||
* Is the build hook willing to perform the build?
|
||||
*/
|
||||
HookReply tryBuildHook(
|
||||
const std::map<std::string, InitialOutput> & initialOutputs, const DerivationOptions<StorePath> & drvOptions);
|
||||
HookReply tryBuildHook(const DerivationOptions<StorePath> & drvOptions);
|
||||
|
||||
/**
|
||||
* Open a log file and a pipe to it.
|
||||
*/
|
||||
Path openLogFile();
|
||||
|
||||
/**
|
||||
* Close the log file.
|
||||
*/
|
||||
void closeLogFile();
|
||||
|
||||
bool isReadDesc(Descriptor fd);
|
||||
|
||||
/**
|
||||
* Process output from a child process.
|
||||
*/
|
||||
Co processChildOutput(Descriptor fd, std::string_view data);
|
||||
|
||||
void flushLine();
|
||||
Done doneFailureLogTooLong(BuildLog & buildLog);
|
||||
|
||||
/**
|
||||
* Wrappers around the corresponding Store methods that first consult the
|
||||
@@ -148,16 +103,11 @@ private:
|
||||
*/
|
||||
std::pair<bool, SingleDrvOutputs> checkPathValidity(std::map<std::string, InitialOutput> & initialOutputs);
|
||||
|
||||
/**
|
||||
* Forcibly kill the child process, if any.
|
||||
*/
|
||||
void killChild();
|
||||
|
||||
Done doneSuccess(BuildResult::Success::Status status, SingleDrvOutputs builtOutputs);
|
||||
|
||||
Done doneFailure(BuildError ex);
|
||||
|
||||
BuildError fixupBuilderFailureErrorMessage(BuilderFailureError msg);
|
||||
BuildError fixupBuilderFailureErrorMessage(BuilderFailureError msg, BuildLog & buildLog);
|
||||
|
||||
JobCategory jobCategory() const override
|
||||
{
|
||||
|
||||
@@ -13,6 +13,7 @@ headers = [ config_pub_h ] + files(
|
||||
'aws-creds.hh',
|
||||
'binary-cache-store.hh',
|
||||
'build-result.hh',
|
||||
'build/build-log.hh',
|
||||
'build/derivation-builder.hh',
|
||||
'build/derivation-building-goal.hh',
|
||||
'build/derivation-building-misc.hh',
|
||||
|
||||
@@ -275,6 +275,7 @@ subdir('nix-meson-build-support/common')
|
||||
sources = files(
|
||||
'binary-cache-store.cc',
|
||||
'build-result.cc',
|
||||
'build/build-log.cc',
|
||||
'build/derivation-builder.cc',
|
||||
'build/derivation-building-goal.cc',
|
||||
'build/derivation-check.cc',
|
||||
|
||||
Reference in New Issue
Block a user