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

4 files changed, 30 insertions, 8 deletions

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)