From 7165b342f545bd4090db438ea3b76f41897f34b7 Mon Sep 17 00:00:00 2001
From: Avery Pennarun <apenwarr@gmail.com>
Date: Mon, 19 Nov 2018 16:27:41 -0500
Subject: [PATCH] redo-log: fix stdout vs stderr; don't recapture if .do script
 redirects stderr.

redo-log should log to stdout, because when you ask for the specific
logs from a run, the logs are the output you requested.  redo-log's
stderr should be about any errors retrieving that output.

On the other hand, when you run redo, the logs are literally the stderr
of the build steps, which are incidental to the main job (building
things).  So that should be send to stderr.  Previously, we were
sending to stderr when --no-log, but stdout when --log, which is
totally wrong.

Also, adding redo-log had the unexpected result that if a .do script
redirected the stderr of a sub-redo or redo-ifchange to a file or pipe,
the output would be eaten by redo-log instead of the intended output.
So a test runner like this:

	self.test:
		redo self.runtest 2>&1 | grep ERROR

would not work; the self.runtest output would be sent to redo's log
buffer (and from there, probably printed to the toplevel redo's stderr)
rather than passed along to grep.
---
 builder.py | 26 ++++++++++++++++++++++----
 vars.py    |  1 +
 2 files changed, 23 insertions(+), 4 deletions(-)

diff --git a/builder.py b/builder.py
index aff26c7..490f196 100644
--- a/builder.py
+++ b/builder.py
@@ -56,6 +56,12 @@ def start_stdin_log_reader(status, details, pretty, color,
             os.close(w)
             os.dup2(r, 0)
             os.close(r)
+            # redo-log sends to stdout (because if you ask for logs, that's
+            # the output you wanted!).  But redo itself sends logs to stderr
+            # (because they're incidental to the thing you asked for).
+            # To make these semantics work, we point redo-log's stdout at
+            # our stderr when we launch it.
+            os.dup2(2, 1)
             argv = [
                 'redo-log',
                 '--recursive', '--follow',
@@ -251,10 +257,22 @@ class BuildJob:
         os.close(self.f.fileno())
         close_on_exec(1, False)
         if vars.LOG:
-            logf = open(state.logname(self.sf.id), 'w')
-            os.dup2(logf.fileno(), 2)
-            close_on_exec(2, False)
-            logf.close()
+            cur_inode = str(os.fstat(2).st_ino)
+            if not vars.LOG_INODE or cur_inode == vars.LOG_INODE:
+                # .do script has *not* redirected stderr, which means we're
+                # using redo-log's log saving mode.  That means subprocs
+                # should be logged to their own file.  If the .do script
+                # *does* redirect stderr, that redirection should be inherited
+                # by subprocs, so we'd do nothing.
+                logf = open(state.logname(self.sf.id), 'w')
+                new_inode = str(os.fstat(logf.fileno()).st_ino)
+                os.environ['REDO_LOG_INODE'] = new_inode
+                os.dup2(logf.fileno(), 2)
+                close_on_exec(2, False)
+                logf.close()
+        else:
+            if 'REDO_LOG_INODE' in os.environ:
+                del os.environ['REDO_LOG_INODE']
         signal.signal(signal.SIGPIPE, signal.SIG_DFL)  # python ignores SIGPIPE
         if vars.VERBOSE or vars.XTRACE:
             logs.write('* %s' % ' '.join(self.argv).replace('\n', ' '))
diff --git a/vars.py b/vars.py
index 3b95915..e28235a 100644
--- a/vars.py
+++ b/vars.py
@@ -17,6 +17,7 @@ VERBOSE = os.environ.get('REDO_VERBOSE', '') and 1 or 0
 XTRACE = os.environ.get('REDO_XTRACE', '') and 1 or 0
 KEEP_GOING = os.environ.get('REDO_KEEP_GOING', '') and 1 or 0
 LOG = atoi(os.environ.get('REDO_LOG', '1'))  # defaults on
+LOG_INODE = os.environ.get('REDO_LOG_INODE', '')
 COLOR = atoi(os.environ.get('REDO_COLOR', '1'))  # defaults on
 # subprocesses mustn't pretty-print if a parent is running redo-log
 PRETTY = (not LOG) and atoi(os.environ.get('REDO_PRETTY', '1'))