daemon: Support multiplexed build output.

This allows clients to tell whether output comes from the daemon or, if
it comes from a builder, from which builder it comes.  The latter is
particularly useful when MAX-BUILD-JOBS > 1.

* nix/libstore/build.cc (DerivationGoal::tryBuildHook)
(DerivationGoal::startBuilder): Print the child's PID in "@ build-started"
traces.
(DerivationGoal::handleChildOutput): Define 'prefix', pass it to
'writeToStderr'.
* nix/libstore/globals.cc (Settings:Settings): Initialize
'multiplexedBuildOutput'.
(Settings::update): Likewise.
* nix/libstore/globals.hh (Settings)[multiplexedBuildOutput]: New field.
Update 'printBuildTrace' documentation.
* nix/libstore/worker-protocol.hh (PROTOCOL_VERSION): Bump to 0.163.
* nix/nix-daemon/nix-daemon.cc (performOp) <wopSetOptions>: Special-case
"multiplexed-build-output" and remove "use-ssh-substituter".
* guix/store.scm (set-build-options): Add #:multiplexed-build-output?
and honor it.
(%protocol-version): Bump to #x163.
* tests/store.scm ("multiplexed-build-output"): New test.

fixlet
This commit is contained in:
Ludovic Courtès 2018-10-15 22:40:35 +02:00
parent 2ab321ca37
commit 6ef61cc4c3
No known key found for this signature in database
GPG key ID: 090B11993D9AEBB5
7 changed files with 108 additions and 10 deletions

View file

@ -155,7 +155,7 @@ (define-module (guix store)
derivation-log-file
log-file))
(define %protocol-version #x162)
(define %protocol-version #x163)
(define %worker-magic-1 #x6e697863) ; "nixc"
(define %worker-magic-2 #x6478696f) ; "dxio"
@ -709,6 +709,15 @@ (define* (set-build-options server
;; disabled by default.
print-extended-build-trace?
;; When true, the daemon prefixes builder output
;; with "@ build-log" traces so we can
;; distinguish it from daemon output, and we can
;; distinguish each builder's output
;; (PRINT-BUILD-TRACE must be true as well.) The
;; latter is particularly useful when
;; MAX-BUILD-JOBS > 1.
multiplexed-build-output?
build-cores
(use-substitutes? #t)
@ -757,6 +766,10 @@ (define socket
`(("print-extended-build-trace"
. ,(if print-extended-build-trace? "1" "0")))
'())
,@(if multiplexed-build-output?
`(("multiplexed-build-output"
. ,(if multiplexed-build-output? "true" "false")))
'())
,@(if timeout
`(("build-timeout" . ,(number->string timeout)))
'())

View file

@ -1652,8 +1652,8 @@ HookReply DerivationGoal::tryBuildHook()
worker.childStarted(shared_from_this(), hook->pid, fds, false, false);
if (settings.printBuildTrace)
printMsg(lvlError, format("@ build-started %1% - %2% %3%")
% drvPath % drv.platform % logFile);
printMsg(lvlError, format("@ build-started %1% - %2% %3% %4%")
% drvPath % drv.platform % logFile % hook->pid);
return rpAccept;
}
@ -2038,8 +2038,8 @@ void DerivationGoal::startBuilder()
if (!msg.empty()) throw Error(msg);
if (settings.printBuildTrace) {
printMsg(lvlError, format("@ build-started %1% - %2% %3%")
% drvPath % drv.platform % logFile);
printMsg(lvlError, format("@ build-started %1% - %2% %3% %4%")
% drvPath % drv.platform % logFile % pid);
}
}
@ -2736,6 +2736,19 @@ void DerivationGoal::deleteTmpDir(bool force)
void DerivationGoal::handleChildOutput(int fd, const string & data)
{
string prefix;
if (settings.multiplexedBuildOutput) {
/* Print a prefix that allows clients to determine whether a message
comes from the daemon or from a build process, and in the latter
case, which build process it comes from. The PID here matches the
one given in "@ build-started" traces; it's shorter that the
derivation file name, hence this choice. */
prefix = "@ build-log "
+ std::to_string(pid < 0 ? hook->pid : pid)
+ " " + std::to_string(data.size()) + "\n";
}
if ((hook && fd == hook->builderOut.readSide) ||
(!hook && fd == builderOut.readSide))
{
@ -2748,7 +2761,7 @@ void DerivationGoal::handleChildOutput(int fd, const string & data)
return;
}
if (verbosity >= settings.buildVerbosity)
writeToStderr(data);
writeToStderr(prefix + data);
if (gzLogFile) {
if (data.size() > 0) {
@ -2767,7 +2780,7 @@ void DerivationGoal::handleChildOutput(int fd, const string & data)
}
if (hook && fd == hook->fromHook.readSide)
writeToStderr(data);
writeToStderr(prefix + data);
}

View file

@ -36,6 +36,7 @@ Settings::Settings()
buildTimeout = 0;
useBuildHook = true;
printBuildTrace = false;
multiplexedBuildOutput = false;
reservedSize = 8 * 1024 * 1024;
fsyncMetadata = true;
useSQLiteWAL = true;
@ -120,6 +121,7 @@ void Settings::update()
_get(maxBuildJobs, "build-max-jobs");
_get(buildCores, "build-cores");
_get(thisSystem, "system");
_get(multiplexedBuildOutput, "multiplexed-build-output");
_get(maxSilentTime, "build-max-silent-time");
_get(buildTimeout, "build-timeout");
_get(reservedSize, "gc-reserved-space");

View file

@ -127,7 +127,7 @@ struct Settings {
a fixed format to allow its progress to be monitored. Each
line starts with a "@". The following are defined:
@ build-started <drvpath> <outpath> <system> <logfile>
@ build-started <drvpath> <outpath> <system> <logfile> <pid>
@ build-failed <drvpath> <outpath> <exitcode> <error text>
@ build-succeeded <drvpath> <outpath>
@ substituter-started <outpath> <substituter>
@ -139,6 +139,13 @@ struct Settings {
builders. */
bool printBuildTrace;
/* When true, 'buildDerivations' prefixes lines coming from builders so
that clients know exactly which line comes from which builder, and
which line comes from the daemon itself. The prefix for data coming
from builders is "log:PID:LEN:DATA" where PID uniquely identifies the
builder (PID is given in "build-started" traces.) */
bool multiplexedBuildOutput;
/* Amount of reserved space for the garbage collector
(/nix/var/nix/db/reserved). */
off_t reservedSize;

View file

@ -6,7 +6,7 @@ namespace nix {
#define WORKER_MAGIC_1 0x6e697863
#define WORKER_MAGIC_2 0x6478696f
#define PROTOCOL_VERSION 0x162
#define PROTOCOL_VERSION 0x163
#define GET_PROTOCOL_MAJOR(x) ((x) & 0xff00)
#define GET_PROTOCOL_MINOR(x) ((x) & 0x00ff)

View file

@ -594,7 +594,7 @@ static void performOp(bool trusted, unsigned int clientVersion,
if (name == "build-timeout" || name == "build-max-silent-time"
|| name == "build-max-jobs" || name == "build-cores"
|| name == "build-repeat"
|| name == "use-ssh-substituter")
|| name == "multiplexed-build-output")
settings.set(name, value);
else
settings.set(trusted ? name : "untrusted-" + name, value);

View file

@ -31,6 +31,7 @@ (define-module (test-store)
#:use-module (gnu packages)
#:use-module (gnu packages bootstrap)
#:use-module (ice-9 match)
#:use-module (ice-9 regex)
#:use-module (rnrs bytevectors)
#:use-module (rnrs io ports)
#:use-module (web uri)
@ -1021,4 +1022,66 @@ (define ref-hash
(call-with-input-file (derivation->output-path drv2)
read))))))
(test-equal "multiplexed-build-output"
'("Hello from first." "Hello from second.")
(with-store store
(let* ((build (add-text-to-store store "build.sh"
"echo Hello from $NAME.; echo > $out"))
(bash (add-to-store store "bash" #t "sha256"
(search-bootstrap-binary "bash"
(%current-system))))
(drv1 (derivation store "one" bash
`("-e" ,build)
#:inputs `((,bash) (,build))
#:env-vars `(("NAME" . "first")
("x" . ,(random-text)))))
(drv2 (derivation store "two" bash
`("-e" ,build)
#:inputs `((,bash) (,build))
#:env-vars `(("NAME" . "second")
("x" . ,(random-text))))))
(set-build-options store
#:print-build-trace #t
#:multiplexed-build-output? #t
#:max-build-jobs 10)
(let ((port (open-output-string)))
;; Send the build log to PORT.
(parameterize ((current-build-output-port port))
(build-derivations store (list drv1 drv2)))
;; Retrieve the build log; make sure it contains valid "@ build-log"
;; traces that allow us to retrieve each builder's output (we assume
;; there's exactly one "build-output" trace for each builder, which is
;; reasonable.)
(let* ((log (get-output-string port))
(started (fold-matches
(make-regexp "@ build-started ([^ ]+) - ([^ ]+) ([^ ]+) ([0-9]+)")
log '() cons))
(done (fold-matches
(make-regexp "@ build-succeeded (.*) - (.*) (.*) (.*)")
log '() cons))
(output (fold-matches
(make-regexp "@ build-log ([[:digit:]]+) ([[:digit:]]+)\n([A-Za-z .*]+)\n")
log '() cons))
(drv-pid (lambda (name)
(lambda (m)
(let ((drv (match:substring m 1))
(pid (string->number
(match:substring m 4))))
(and (string-suffix? name drv) pid)))))
(pid-log (lambda (pid)
(lambda (m)
(let ((n (string->number
(match:substring m 1)))
(len (string->number
(match:substring m 2)))
(str (match:substring m 3)))
(and (= pid n)
(= (string-length str) (- len 1))
str)))))
(pid1 (any (drv-pid "one.drv") started))
(pid2 (any (drv-pid "two.drv") started)))
(list (any (pid-log pid1) output)
(any (pid-log pid2) output)))))))
(test-end "store")