Clean up depth handling in debug output

The indentation shown in debug output was misleading.  Increment the
depth when we are working on a prerequisite, not for the current
target.

* src/remake.c (check_dep): Increment depth only on recursion.
(update_file_1): Ditto.  Don't show "Finished..." if prereqs are
still running.
* src/implicit.c (pattern_search): Increment depth for the entire
search.
* tests/scripts/features/output-sync: Support debug output when run
by hand.

src/implicit.c

@@ -272,6 +272,8 @@ pattern_search (struct file *file, int archive,
 
   PATH_VAR (stem_str); /* @@ Need to get rid of stem, stemlen, etc. */
 
+  ++depth;
+
 #ifndef NO_ARCHIVES
   if (archive || ar_name (filename))
     lastslash = 0;
@@ -893,7 +895,7 @@ pattern_search (struct file *file, int archive,
 
                       if (pattern_search (int_file,
                                           0,
-                                          depth + 1,
+                                          depth,
                                           recursions + 1,
                                           allow_compat_rules))
                         {
@@ -1139,6 +1141,8 @@ pattern_search (struct file *file, int archive,
   free (tryrules);
   free (deplist);
 
+  --depth;
+
   if (rule)
     {
       DBS (DB_IMPLICIT, (_("Found implicit rule '%s' for '%s'.\n"),

src/remake.c

@@ -491,8 +491,6 @@ update_file_1 (struct file *file, unsigned int depth)
      fail. */
   file->no_diag = file->dontcare;
 
-  ++depth;
-
   /* Notice recursive update of the same file.  */
   start_updating (file);
 
@@ -500,6 +498,9 @@ update_file_1 (struct file *file, unsigned int depth)
      remember this one to turn off updating.  */
   ofile = file;
 
+  /* Increase the depth for reporting how we build the file.  */
+  ++depth;
+
   /* Looking at the file's modtime beforehand allows the possibility
      that its name may be changed by a VPATH search, and thus it may
      not need an implicit rule.  If this were not done, the file
@@ -734,16 +735,18 @@ update_file_1 (struct file *file, unsigned int depth)
   finish_updating (file);
   finish_updating (ofile);
 
-  DBF (DB_VERBOSE, _("Finished prerequisites of target file '%s'.\n"));
+  /* We've decided what we need to do to build the file.  */
+  --depth;
 
   if (running)
     {
       set_command_state (file, cs_deps_running);
-      --depth;
       DBF (DB_VERBOSE, _("The prerequisites of '%s' are being made.\n"));
       return us_success;
     }
 
+  DBF (DB_VERBOSE, _("Finished prerequisites of target file '%s'.\n"));
+
   /* If any dependency failed, give up now.  */
 
   if (dep_status)
@@ -752,8 +755,6 @@ update_file_1 (struct file *file, unsigned int depth)
       file->update_status = dep_status == us_none ? us_failed : dep_status;
       notice_finished_file (file);
 
-      --depth;
-
       DBF (DB_VERBOSE, _("Giving up on target file '%s'.\n"));
 
       if (depth == 0 && keep_going_flag
@@ -828,16 +829,13 @@ update_file_1 (struct file *file, unsigned int depth)
 
           if (fmt)
             {
-              print_spaces (depth);
+              print_spaces (depth+1);
               printf (fmt, dep_name (d), file->name);
               fflush (stdout);
             }
         }
     }
 
-  /* Here depth returns to the value it had when we were called.  */
-  depth--;
-
   if (file->double_colon && file->deps == 0)
     {
       must_make = 1;
@@ -1084,7 +1082,6 @@ check_dep (struct file *file, unsigned int depth,
   struct dep *d;
   enum update_status dep_status = us_success;
 
-  ++depth;
   start_updating (file);
 
   /* We might change file if we find a different one via vpath;
@@ -1182,7 +1179,7 @@ check_dep (struct file *file, unsigned int depth,
 
               d->file->parent = file;
               maybe_make = *must_make_ptr;
-              new = check_dep (d->file, depth, this_mtime, &maybe_make);
+              new = check_dep (d->file, depth+1, this_mtime, &maybe_make);
               if (new > dep_status)
                 dep_status = new;
 

tests/scripts/features/output-sync

@@ -38,10 +38,10 @@ sub output_sync_clean {
 # reliable.  If things are too fast, then sometimes a different job will steal
 # the output sync lock and the output is mis-ordered from what we expect.
 sub output_sync_wait {
-    return subst_make_string("#HELPER# -q wait ../mksync.$_[0] sleep 1");
+    return subst_make_string("#HELPER# \$Q wait ../mksync.$_[0] sleep 1");
 }
 sub output_sync_set {
-    return subst_make_string("#HELPER# -q file ../mksync.$_[0]");
+    return subst_make_string("#HELPER# \$Q file ../mksync.$_[0]");
 }
 
 @syncfiles = qw(mksync.foo mksync.foo_start mksync.bar mksync.bar_start);
@@ -66,27 +66,32 @@ open(MAKEFILE,"> foo/Makefile");
 print MAKEFILE <<EOF;
 all: foo
 
-foo: foo-base ; \@$set_foo
+foo: foo-base ; $set_foo
 
 foo-base:
 \t\@echo foo: start
-\t\@$wait_bar
+\t$wait_bar
 \t\@echo foo: end
 
-foo-job: foo-job-base ; \@$set_foo
+foo-job: foo-job-base ; $set_foo
 
 foo-job-base:
-\t\@$wait_bar_start
+\t$wait_bar_start
 \t\@echo foo: start
-\t\@$set_foo_start
-\t\@$wait_bar
+\t$set_foo_start
+\t$wait_bar
 \t\@echo foo: end
 
 foo-fail:
 \t\@echo foo-fail: start
-\t\@$wait_bar
+\t$wait_bar
 \t\@echo foo-fail: end
-\t\@exit 1
+\texit 1
+
+V :=
+\$V.SILENT:
+Q :=
+\$VQ := -q
 EOF
 close(MAKEFILE);
 
@@ -94,24 +99,29 @@ open(MAKEFILE,"> bar/Makefile");
 print MAKEFILE <<EOF;
 all: bar baz
 
-bar: bar-base ; \@$set_bar
+bar: bar-base ; $set_bar
 bar-base:
 \t\@echo bar: start
 \t\@echo bar: end
 
-bar-job: bar-job-base ; \@$set_bar
+bar-job: bar-job-base ; $set_bar
 
 bar-job-base:
 \t\@echo bar: start
-\t\@$set_bar_start
-\t\@$wait_foo_start
+\t$set_bar_start
+\t$wait_foo_start
 \t\@echo bar: end
 
 baz: baz-base
 baz-base:
 \t\@echo baz: start
-\t\@$wait_foo
+\t$wait_foo
 \t\@echo baz: end
+
+V :=
+\$V.SILENT:
+Q :=
+\$VQ := -q
 EOF
 close(MAKEFILE);