Ensure command lines are written synchronously with -O.
authorPaul Smith <psmith@gnu.org>
Sun, 5 May 2013 21:03:51 +0000 (17:03 -0400)
committerPaul Smith <psmith@gnu.org>
Sun, 5 May 2013 21:03:51 +0000 (17:03 -0400)
If output-sync is enabled, have make write the command line to the temp file
instead of printing it directly to the screen to ensure that the output is
ordered properly.  Also, remove extraneous enter/leave operations by having
them printed directly when dumping temp file output.

ChangeLog
job.c
misc.c
tests/ChangeLog
tests/scripts/features/output-sync

index 9f30bf78d6ba7811c3e38b164ba1446b7fc26ca0..8632e1af9c8d86960edec92109d1acf324fcb3bd 100644 (file)
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,15 @@
+2013-05-05  Paul Smith  <psmith@gnu.org>
+
+       * job.c (child_out): Write newlines explicitly, and don't do
+       anything if the message is empty.
+       (sync_output): Put working dir messages around stdout AND stderr.
+       (start_job_command): Move the tmp file assignment earlier.  After
+       we do it, write the command line to the temp file to get the order
+       correct.
+
+       * misc.c (message): Remove special handling for output_sync.
+       (error): Ditto.
+
 2013-05-04  Paul Smith  <psmith@gnu.org>
 
        * loadapi.c (gmk_alloc): New function.
diff --git a/job.c b/job.c
index 03898661873658f363830cc77cb2cefb06aacec3..726cca894631dfde1a55c6f721c13ee39ebee013 100644 (file)
--- a/job.c
+++ b/job.c
@@ -478,14 +478,17 @@ child_out (const struct child *child, const char *msg, int out)
 {
   int fd = out ? child->outfd : child->errfd;
 
+  if (!msg || msg[0] == '\0')
+    return;
+
   if (fd >= 0)
     {
       int len = strlen (msg);
+      int b;
 
       lseek (fd, 0, SEEK_END);
       while (1)
         {
-          int b;
           EINTRLOOP (b, write (fd, msg, len));
           if (b == len)
             break;
@@ -494,12 +497,14 @@ child_out (const struct child *child, const char *msg, int out)
           len -= b;
           msg += b;
         }
+      EINTRLOOP (b, write (fd, "\n", 1));
     }
   else
     {
       FILE *f = out ? stdout : stderr;
       fputs (msg, f);
       fflush (f);
+      putc ('\n', f);
     }
 }
 
@@ -548,7 +553,7 @@ child_error (const struct child *child,
   l = strlen (pre) + strlen (f->name) + strlen (post);
 
 #ifdef VMS
-  if (exit_code & 1 != 0)
+  if ((exit_code & 1) != 0)
     return;
 
   msg = error_s (l + INTEGER_LENGTH, NILF,
@@ -651,28 +656,28 @@ sync_init ()
 static void
 assign_child_tempfiles (struct child *c)
 {
-  /* If we have a temp file, we're done.  */
-  if (c->outfd >= 0 || c->errfd >= 0)
-    return;
-
-  if (STREAM_OK (stdout))
-    {
-      c->outfd = open_tmpfd ();
-      if (c->outfd < 0)
-        goto error;
-      CLOSE_ON_EXEC (c->outfd);
-    }
-
-  if (STREAM_OK (stderr))
+  /* If we don't have a temp file, get one.  */
+  if (c->outfd < 0 && c->errfd < 0)
     {
-      if (c->outfd >= 0 && combined_output)
-        c->errfd = c->outfd;
-      else
+      if (STREAM_OK (stdout))
         {
-          c->errfd = open_tmpfd ();
-          if (c->errfd < 0)
+          c->outfd = open_tmpfd ();
+          if (c->outfd < 0)
             goto error;
-          CLOSE_ON_EXEC (c->errfd);
+          CLOSE_ON_EXEC (c->outfd);
+        }
+
+      if (STREAM_OK (stderr))
+        {
+          if (c->outfd >= 0 && combined_output)
+            c->errfd = c->outfd;
+          else
+            {
+              c->errfd = open_tmpfd ();
+              if (c->errfd < 0)
+                goto error;
+              CLOSE_ON_EXEC (c->errfd);
+            }
         }
     }
 
@@ -765,14 +770,12 @@ sync_output (struct child *c)
 
       /* We've entered the "critical section" during which a lock is held.
          We want to keep it as short as possible.  */
+      log_working_directory (1, 1);
       if (outfd_not_empty)
-        {
-          log_working_directory (1, 1);
           pump_from_tmp (c->outfd, stdout);
-          log_working_directory (0, 1);
-        }
       if (errfd_not_empty && c->errfd != c->outfd)
         pump_from_tmp (c->errfd, stderr);
+      log_working_directory (0, 1);
 
       /* Exit the critical section.  */
       if (sem)
@@ -1375,7 +1378,8 @@ start_job_command (struct child *child)
 #if !defined(_AMIGA) && !defined(WINDOWS32)
   static int bad_stdin = -1;
 #endif
-  int sync_cmd = 0;
+  int print_cmd;
+  int sync_cmd;
   char *p;
   /* Must be volatile to silence bogus GCC warning about longjmp/vfork.  */
   volatile int flags;
@@ -1503,13 +1507,40 @@ start_job_command (struct child *child)
       return;
     }
 
-  /* Print out the command.  If silent, we call 'message' with null so it
-     can log the working directory before the command's own error messages
-     appear.  */
+  print_cmd = (just_print_flag || trace_flag
+               || (!(flags & COMMANDS_SILENT) && !silent_flag));
 
-  message (0, (just_print_flag || trace_flag
-               || (!(flags & COMMANDS_SILENT) && !silent_flag))
-          ? "%s" : (char *) 0, p);
+#ifdef OUTPUT_SYNC
+  if (output_sync && sync_handle == -1)
+    sync_init();
+#endif
+
+  /* Are we going to synchronize this command's output?  Do so if either we're
+     in SYNC_MAKE mode or this command is not recursive.  We'll also check
+     output_sync separately below in case it changes due to error.  */
+  sync_cmd = output_sync && (output_sync == OUTPUT_SYNC_MAKE
+                             || !(flags & COMMANDS_RECURSE));
+
+#ifdef OUTPUT_SYNC
+  if (sync_cmd)
+    {
+      /* If syncing, make sure we have temp files.
+         Write the command to the temp file so it's output in order.  */
+      assign_child_tempfiles (child);
+      if (print_cmd)
+        child_out (child, p, 1);
+    }
+  else
+    /* We don't want to sync this command: to avoid misordered
+       output ensure any already-synced content is written.  */
+    sync_output (child);
+#endif /* OUTPUT_SYNC */
+
+  /* If we're not syncing, print out the command.  If silent, we call
+     'message' with null so it can log the working directory before the
+     command's own error messages appear.  */
+  if (! sync_cmd)
+    message (0, print_cmd ? "%s" : NULL, p);
 
   /* Tell update_goal_chain that a command has been started on behalf of
      this target.  It is important that this happens here and not in
@@ -1563,11 +1594,6 @@ start_job_command (struct child *child)
   fflush (stdout);
   fflush (stderr);
 
-  /* Are we going to synchronize this command's output?  Do so if either we're
-     in SYNC_MAKE mode or this command is not recursive.  We'll also check
-     output_sync separately below in case it changes due to error.  */
-  sync_cmd = output_sync == OUTPUT_SYNC_MAKE || !(flags & COMMANDS_RECURSE);
-
 #ifndef VMS
 #if !defined(WINDOWS32) && !defined(_AMIGA) && !defined(__MSDOS__)
 
@@ -1692,19 +1718,6 @@ start_job_command (struct child *child)
 
 #else  /* !__EMX__ */
 
-#ifdef OUTPUT_SYNC
-      if (output_sync && sync_handle == -1)
-        sync_init();
-
-      if (output_sync && sync_cmd)
-        /* If we still want to sync, make sure we have temp files. */
-        assign_child_tempfiles (child);
-      else
-        /* We don't want to sync this command: to avoid misordered
-           output ensure any already-synched content is written.  */
-        sync_output (child);
-#endif /* OUTPUT_SYNC */
-
       child->pid = vfork ();
       environ = parent_environ;        /* Restore value child may have clobbered.  */
       if (child->pid == 0)
@@ -1831,19 +1844,6 @@ start_job_command (struct child *child)
       HANDLE hPID;
       char* arg0;
 
-#ifdef OUTPUT_SYNC
-      if (output_sync && sync_handle == -1)
-        sync_init();
-
-      if (output_sync && sync_cmd)
-        /* If we still want to sync, make sure we have temp files. */
-        assign_child_tempfiles (child);
-      else
-        /* We don't want to sync this command: to avoid misordered output
-           ensure any already-synched content is written.  */
-        sync_output (child);
-#endif /* OUTPUT_SYNC */
-
       /* make UNC paths safe for CreateProcess -- backslash format */
       arg0 = argv[0];
       if (arg0 && arg0[0] == '/' && arg0[1] == '/')
diff --git a/misc.c b/misc.c
index 766874fc416545ddb134706a01458d55555edd42..2a6c6ea3c95c0dd684a450d419e14c0d07a0469f 100644 (file)
--- a/misc.c
+++ b/misc.c
@@ -179,11 +179,11 @@ concat (unsigned int num, ...)
   return result;
 }
 \f
-/* If we had a standard-compliant vsnprintf() this would be a lot simpler.
-   Maybe in the future we'll include gnulib's version.  */
 
 /* Return a formatted string buffer.
-   LENGTH must be the maximum length of all format arguments, stringified.  */
+   LENGTH must be the maximum length of all format arguments, stringified.
+   If we had a standard-compliant vsnprintf() this would be a lot simpler.
+   Maybe in the future we'll include gnulib's version.  */
 
 const char *
 message_s (unsigned int length, int prefix, const char *fmt, ...)
@@ -215,8 +215,6 @@ message_s (unsigned int length, int prefix, const char *fmt, ...)
   vsprintf (bp, fmt, args);
   va_end (args);
 
-  strcat (bp, "\n");
-
   return buffer;
 }
 
@@ -253,8 +251,6 @@ error_s (unsigned int length, const gmk_floc *flocp, const char *fmt, ...)
   vsprintf (bp, fmt, args);
   va_end (args);
 
-  strcat (bp, "\n");
-
   return buffer;
 }
 \f
@@ -270,9 +266,6 @@ message (int prefix, const char *fmt, ...)
 
   if (fmt != 0)
     {
-      if (output_sync)
-        log_working_directory (1, 1);
-
       if (prefix)
        {
          if (makelevel == 0)
@@ -284,9 +277,6 @@ message (int prefix, const char *fmt, ...)
       vfprintf (stdout, fmt, args);
       va_end (args);
       putchar ('\n');
-
-      if (output_sync)
-        log_working_directory (0, 1);
     }
 
   fflush (stdout);
@@ -299,10 +289,7 @@ error (const gmk_floc *flocp, const char *fmt, ...)
 {
   va_list args;
 
-  if (output_sync)
-    log_working_directory (1, 1);
-  else
-    log_working_directory (1, 0);
+  log_working_directory (1, 0);
 
   if (flocp && flocp->filenm)
     fprintf (stderr, "%s:%lu: ", flocp->filenm, flocp->lineno);
@@ -317,9 +304,6 @@ error (const gmk_floc *flocp, const char *fmt, ...)
 
   putc ('\n', stderr);
   fflush (stderr);
-
-  if (output_sync)
-    log_working_directory (0, 1);
 }
 
 /* Print an error message and exit.  */
index ade64f0b67c323a0354fbb2c7ae2fe4585ac9610..4d11706b5e7a2ce93cdb9c534c2ed2398d688113 100644 (file)
@@ -1,3 +1,9 @@
+2013-05-05  Paul Smith  <psmith@gnu.org>
+
+       * scripts/features/output-sync (output_sync_set): Remove
+       extraneous enter/leave lines, which are no longer printed.
+       Add tests for syncing command line printing.
+
 2013-05-04  Paul Smith  <psmith@gnu.org>
 
        * scripts/features/loadapi: Use the new alloc functions.
index a1560adbd694b133cab005a30421d6de6b9ced07..e7edfce50477a55fc1f2e04b0c8765c559ff6880 100644 (file)
@@ -127,14 +127,11 @@ make-foo: ; \$(MAKE) -C foo
 make-bar: ; \$(MAKE) -C bar!,
               '-j -Omake',
 "#MAKEPATH# -C foo
-#MAKEPATH# -C bar
-#MAKE#[1]: Entering directory '#PWD#/foo'
 #MAKE#[1]: Entering directory '#PWD#/foo'
 foo: start
 foo: end
 #MAKE#[1]: Leaving directory '#PWD#/foo'
-#MAKE#[1]: Leaving directory '#PWD#/foo'
-#MAKE#[1]: Entering directory '#PWD#/bar'
+#MAKEPATH# -C bar
 #MAKE#[1]: Entering directory '#PWD#/bar'
 bar: start
 bar: end
@@ -142,7 +139,6 @@ bar: end
 #MAKE#[1]: Entering directory '#PWD#/bar'
 baz: start
 baz: end
-#MAKE#[1]: Leaving directory '#PWD#/bar'
 #MAKE#[1]: Leaving directory '#PWD#/bar'\n", 0, 6);
 
 # Test per-target synchronization.
@@ -160,8 +156,6 @@ make-bar: ; $sleep_command 1 ; \$(MAKE) -C bar!,
               '-j --output-sync=target',
 "#MAKEPATH# -C foo
 $sleep_command 1 ; #MAKEPATH# -C bar
-#MAKE#[1]: Entering directory '#PWD#/foo'
-#MAKE#[1]: Entering directory '#PWD#/bar'
 #MAKE#[1]: Entering directory '#PWD#/bar'
 bar: start
 bar: end
@@ -170,11 +164,9 @@ bar: end
 foo: start
 foo: end
 #MAKE#[1]: Leaving directory '#PWD#/foo'
-#MAKE#[1]: Leaving directory '#PWD#/foo'
 #MAKE#[1]: Entering directory '#PWD#/bar'
 baz: start
 baz: end
-#MAKE#[1]: Leaving directory '#PWD#/bar'
 #MAKE#[1]: Leaving directory '#PWD#/bar'\n", 0, 6);
 
 # Test that messages from make itself are enclosed with
@@ -189,20 +181,16 @@ make-bar-bar: ; $sleep_command 1 ; \$(MAKE) -C bar bar!,
               '-j -O',
 "#MAKEPATH# -C foo foo-fail
 $sleep_command 1 ; #MAKEPATH# -C bar bar
-#MAKE#[1]: Entering directory '#PWD#/foo'
-#MAKE#[1]: Entering directory '#PWD#/bar'
 #MAKE#[1]: Entering directory '#PWD#/bar'
 bar: start
 bar: end
 #MAKE#[1]: Leaving directory '#PWD#/bar'
-#MAKE#[1]: Leaving directory '#PWD#/bar'
 #MAKE#[1]: Entering directory '#PWD#/foo'
 foo-fail: start
 foo-fail: end
 Makefile:20: recipe for target 'foo-fail' failed
 #MAKE#[1]: *** [foo-fail] Error 1
 #MAKE#[1]: Leaving directory '#PWD#/foo'
-#MAKE#[1]: Leaving directory '#PWD#/foo'
 #MAKEFILE#:4: recipe for target 'make-foo-fail' failed
 #MAKE#: *** [make-foo-fail] Error 2\n",
 512);
@@ -224,20 +212,16 @@ make-bar: ; $sleep_command 1 ; \$(MAKE) -C bar bar-job!,
 "#MAKEPATH# -C foo foo-job
 $sleep_command 1 ; #MAKEPATH# -C bar bar-job
 #MAKE#[1]: Entering directory '#PWD#/foo'
-#MAKE#[1]: Entering directory '#PWD#/foo'
 foo: start
 #MAKE#[1]: Leaving directory '#PWD#/foo'
 #MAKE#[1]: Entering directory '#PWD#/bar'
-#MAKE#[1]: Entering directory '#PWD#/bar'
 bar: start
 #MAKE#[1]: Leaving directory '#PWD#/bar'
 #MAKE#[1]: Entering directory '#PWD#/bar'
 bar: end
 #MAKE#[1]: Leaving directory '#PWD#/bar'
-#MAKE#[1]: Leaving directory '#PWD#/bar'
 #MAKE#[1]: Entering directory '#PWD#/foo'
 foo: end
-#MAKE#[1]: Leaving directory '#PWD#/foo'
 #MAKE#[1]: Leaving directory '#PWD#/foo'\n", 0, 6);
 
 
@@ -254,5 +238,15 @@ all:
 
 run_make_test(undef, '-j -Otarget', "foo\nbar\n");
 
+# Ensure when make writes out command it's not misordered
+run_make_test(qq!
+all:
+\t\@echo foobar
+\ttrue
+!,
+              '-j -Ojob', "foobar\ntrue\n");
+
+run_make_test(undef, '-j -Otarget', "foobar\ntrue\n");
+
 # This tells the test driver that the perl test script executed properly.
 1;