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.
This commit is contained in:
Avery Pennarun 2018-11-19 16:27:41 -05:00
commit 7165b342f5
2 changed files with 23 additions and 4 deletions

View file

@ -56,6 +56,12 @@ def start_stdin_log_reader(status, details, pretty, color,
os.close(w) os.close(w)
os.dup2(r, 0) os.dup2(r, 0)
os.close(r) 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 = [ argv = [
'redo-log', 'redo-log',
'--recursive', '--follow', '--recursive', '--follow',
@ -251,10 +257,22 @@ class BuildJob:
os.close(self.f.fileno()) os.close(self.f.fileno())
close_on_exec(1, False) close_on_exec(1, False)
if vars.LOG: if vars.LOG:
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') 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) os.dup2(logf.fileno(), 2)
close_on_exec(2, False) close_on_exec(2, False)
logf.close() 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 signal.signal(signal.SIGPIPE, signal.SIG_DFL) # python ignores SIGPIPE
if vars.VERBOSE or vars.XTRACE: if vars.VERBOSE or vars.XTRACE:
logs.write('* %s' % ' '.join(self.argv).replace('\n', ' ')) logs.write('* %s' % ' '.join(self.argv).replace('\n', ' '))

View file

@ -17,6 +17,7 @@ VERBOSE = os.environ.get('REDO_VERBOSE', '') and 1 or 0
XTRACE = os.environ.get('REDO_XTRACE', '') 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 KEEP_GOING = os.environ.get('REDO_KEEP_GOING', '') and 1 or 0
LOG = atoi(os.environ.get('REDO_LOG', '1')) # defaults on 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 COLOR = atoi(os.environ.get('REDO_COLOR', '1')) # defaults on
# subprocesses mustn't pretty-print if a parent is running redo-log # subprocesses mustn't pretty-print if a parent is running redo-log
PRETTY = (not LOG) and atoi(os.environ.get('REDO_PRETTY', '1')) PRETTY = (not LOG) and atoi(os.environ.get('REDO_PRETTY', '1'))