diff options
| -rw-r--r-- | guix/store.scm | 15 | ||||
| -rw-r--r-- | nix/libstore/build.cc | 25 | ||||
| -rw-r--r-- | nix/libstore/globals.cc | 2 | ||||
| -rw-r--r-- | nix/libstore/globals.hh | 9 | ||||
| -rw-r--r-- | nix/libstore/worker-protocol.hh | 2 | ||||
| -rw-r--r-- | nix/nix-daemon/nix-daemon.cc | 2 | ||||
| -rw-r--r-- | tests/store.scm | 63 |
7 files changed, 108 insertions, 10 deletions
diff --git a/guix/store.scm b/guix/store.scm index 8b35fc8d7a..b1bdbf3813 100644 --- a/guix/store.scm +++ b/guix/store.scm @@ -155,7 +155,7 @@ 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 @@ encoding conversion errors." ;; 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 @@ encoding conversion errors." `(("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))) '()) diff --git a/nix/libstore/build.cc b/nix/libstore/build.cc index b2c319f00b..d7b8b0f0ca 100644 --- a/nix/libstore/build.cc +++ b/nix/libstore/build.cc @@ -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); } diff --git a/nix/libstore/globals.cc b/nix/libstore/globals.cc index 94c2e516f8..4b5b485e65 100644 --- a/nix/libstore/globals.cc +++ b/nix/libstore/globals.cc @@ -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"); diff --git a/nix/libstore/globals.hh b/nix/libstore/globals.hh index 4c142e6933..a6935c3337 100644 --- a/nix/libstore/globals.hh +++ b/nix/libstore/globals.hh @@ -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; diff --git a/nix/libstore/worker-protocol.hh b/nix/libstore/worker-protocol.hh index 103d60a8c2..ea67b10a5b 100644 --- a/nix/libstore/worker-protocol.hh +++ b/nix/libstore/worker-protocol.hh @@ -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) diff --git a/nix/nix-daemon/nix-daemon.cc b/nix/nix-daemon/nix-daemon.cc index 782e4acfc5..2939422172 100644 --- a/nix/nix-daemon/nix-daemon.cc +++ b/nix/nix-daemon/nix-daemon.cc @@ -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); diff --git a/tests/store.scm b/tests/store.scm index 2858369706..3ff526cdcf 100644 --- a/tests/store.scm +++ b/tests/store.scm @@ -31,6 +31,7 @@ #: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 @@ (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") |