Improve 'redo -v' output whitespace.

It was too hard to tell when an ifchange ended and the commands from the
prior level started running again.  Now it's a little better.

helpers.py

@@ -33,23 +33,21 @@ def mkdirp(d, mode=None):
             raise
 
 
-def _log(s):
+def log_(s):
     sys.stdout.flush()
     sys.stderr.write(s)
     sys.stderr.flush()
 
 
 def _clog(s):
-    if vars.VERBOSE: _log('\n')
-    _log('\x1b[32mredo  %s\x1b[1m%s\x1b[m' % (vars.DEPTH, s))
+    log_('\x1b[32mredo  %s\x1b[1m%s\x1b[m' % (vars.DEPTH, s))
 def _bwlog(s):
-    if vars.VERBOSE: _log('\n')
-    _log('redo  %s%s' % (vars.DEPTH, s))
+    log_('redo  %s%s' % (vars.DEPTH, s))
 
 def _cerr(s):
-    _log('\x1b[31mredo: %s\x1b[1m%s\x1b[m' % (vars.DEPTH, s))
+    log_('\x1b[31mredo: %s\x1b[1m%s\x1b[m' % (vars.DEPTH, s))
 def _bwerr(s):
-    _log('redo: %s%s' % (vars.DEPTH, s))
+    log_('redo: %s%s' % (vars.DEPTH, s))
 
 
 if os.isatty(2):
@@ -62,10 +60,10 @@ else:
 
 def debug(s):
     if vars.DEBUG >= 1:
-        _log('redo: %s%s' % (vars.DEPTH, s))
+        log_('redo: %s%s' % (vars.DEPTH, s))
 def debug2(s):
     if vars.DEBUG >= 2:
-        _log('redo: %s%s' % (vars.DEPTH, s))
+        log_('redo: %s%s' % (vars.DEPTH, s))
 
 
 def relpath(t, base):

redo.py

@@ -131,6 +131,7 @@ def _build(t):
             ]
     if vars.VERBOSE:
         argv[1] += 'v'
+        log_('\n')
     log('%s\n' % relpath(t, vars.STARTDIR))
     rv = subprocess.call(argv, preexec_fn=lambda: _preexec(t),
                          stdout=f.fileno())
@@ -150,6 +151,8 @@ def _build(t):
     f.close()
     if rv != 0:
         raise BuildError('%s: exit code %d' % (t,rv))
+    if vars.VERBOSE:
+        log('%s (done)\n\n' % relpath(t, vars.STARTDIR))
 
 
 def build(t):

test.do

@@ -1,2 +1,3 @@
 redo-ifchange t/c.c t/all
+echo >&2
 ./wvtestrun "$REDO" runtests >&2