bug#46388: 27.1; emacs -batch does not output messages immediately when invoked outside of the command prompt

[Ioannis Kappas]

Hi Eli,

(apologies for the long email)

On Fri, Feb 12, 2021 at 8:03 PM Eli Zaretskii <eliz@gnu.org> wrote:
>
> > From: Ioannis Kappas <ioannis.kappas@gmail.com>
> > Date: Fri, 12 Feb 2021 19:59:02 +0000
> > Cc: Paul Eggert <eggert@cs.ucla.edu>, 46388@debbugs.gnu.org
> >
> > How do you suggest we flush the message out so that it is always
> > displayed to the user irrespective of the architecture/prompt it is
> > ran on? Is there perhaps an elisp function to flush messages out (e.g.
> > (progn (message "...") (message-flush!) (sit-for ...))) ?
> >
>
> As I said, this cannot be helped, not until we teach Emacs on Windows
> to use the pseudo-console.  This is how the platform behaves when we
> use pipes.
>
> Sorry, there's no way around this.

although ConPTY support will hopefully solve all issues with regards
to an Emacs parent process interacting with its children, it wont
solve this particular issue when the parent process is different than
Emacs or Emacs is running on a Windows version less than 10 (ConPTY as
I understand is only available on Windows 10).

A have created a little C program and written an analysis on the
buffering behavior of stderr when redirected to a pipe at
https://github.com/ikappaki/standard-streams-test#readme, with the aim
to understanding the technology involved, reach your level of
understanding and hopefully strengthen my argument for a fix.

Just to summarize the results:

1. stderr is unbuffered when attached to the console.
2. A child's stderr stream is fully buffered when redirected to a
   pipe, with a default buffer size of 4096 bytes long. This buffer is
   complementary to the pipe's buffer.
3. The pipe's buffer size, configured by the parent process, defaults
   to a size of 4096 bytes long (the size is controlled by
   `w32-pipe-buffer-size' in Emacs, of which see).
4. The stderr stream mode can be reset to unbuffered or fully buffered
   at process start up when no characters are yet written to it.

(PARENT PROCESS) READER <= [PIPE BUFFER] <= [STDERR STREAM BUFFER] <=
WRITER (CHILD PROCESS)

Given the above results, it seems to me like a proper fix to reset the
stream to unbuffered when Emacs --batch stderr stream has been
redirected to a pipe it, ensuring first of course that we distinguish
between pipe, file and socket redirections. I believe one of the
arguments against the original patch is that it will affect
redirections to files, which we do need to be buffered at the stream
level.

Please note, that resetting the stream's buffer mode does not reset
the pipe's buffer which is still in effect. The child writer (in our
case Emacs --batch) will not block on a write, unless of course the
write is more than 4096 bytes long and the parent process is
unavailable to consume data.

Here is the updated patch:

@@ -10266,6 +10266,37 @@ init_ntproc (int dumping)
     else
       _open ("nul", O_TEXT | O_NOINHERIT | O_WRONLY);
     _fdopen (2, "w");
+
+    /* stderr is unbuffered when attached to the console but fully
+       buffered (4096 bytes) when redirected to a pipe (this buffer is
+       complementary to the pipe buffer).
+
+       Since Emacs --batch does not, at least on Windows, flush stderr
+       it means output (such as that generated with `message') will
+       not reach the parent process, not until at least this process
+       exits or the stream buffer is full, resulting to a very poor
+       interaction with the parent process.
+
+       We thus switch to unbuffered mode and rely only on the pipe's
+       buffer for ensuring this process is not blocked writing data
+       chunks to stderr (the default pipe's buffer size is 4096 bytes,
+       but this is only configurable by the parent process). Setting
+       the stream up to line buffer mode unfortunately does not work
+       because it is the same as fully buffered on win32.
+
+       Note that the below does not affect stderr redirection to a
+       file, since this will come back as `FILE_TYPE_DISK'.
+    */
+    HANDLE seh = (HANDLE)_get_osfhandle(_fileno(stderr));
+    if (noninteractive
+ /* is pipe (anonymous, named or socket)*/
+ && GetFileType(seh) == FILE_TYPE_PIPE
+ /* and is definitely not a socket */
+ && GetNamedPipeInfo(seh, NULL, NULL, NULL, NULL))
+      {
+ setvbuf(stderr, NULL, _IONBF, 0);
+ DebPrint((":stderr-mode-set-to-unbuf\n"));
+      }

Please let me know of any cases you might think removing stderr buffer
might prove problematic and is not covered by the presence of the
pipe's buffer presence alone.

An alternative to the above, and perhaps a little more involved, is to
provide an interface to `message' to be able to flush a
pipe-redirected stderr stream after outputting a message with a
newline. This will make it behave as if the `message's output was line
buffered, which I believe would have been the ideal outcome for stderr
to begin with.

Please also note that as mentioned earlier in this thread, there is a
precedence of flushing stderr "on platforms defining _PC_PIPE_BUF"
(see /sysdep.c:init_standard_fds()/), strengthening the argument of the
eligibility of the following fix.

In the patch below, I tried to maintain what I thought was the
existing writing style and also make it obvious that the decision to
flush the buffer was explicitly taken by /xdisp.c:message_to_stderr()/
rather than perhaps hiding it in /sysdep.c:errputc()/, although I am
not so sure about scattering such a simple login in three different
files:

@@ -2789,6 +2789,30 @@ safe_strsignal (int code)
/* Output to stderr.  */

+/* On windows, stderr is unbuffered when attached to the console but
+   fully buffered (4096 bytes) when redirected to a pipe (this buffer
+   is complementary to the pipe buffer).
+
+   Since Emacs --batch, at least on Windows, does not flush stderr it
+   means output (such as that created with `message') will not reach
+   the parent process, not until at least this process exits or the
+   stream buffer is full, resulting to a very poor interaction with
+   the parent process.
+
+   We thus provide an interface to functions such as `message' to
+   flush stderr after they output a newline, make them in effect
+   behave as if stderr was line buffered (unfortunately resetting the
+   stream to line buffer mode is the same as resetting it to full
+   buffer mode, so this can't be enforced at the stream level).
+*/
+void maybe_flush_stderr_after_newline (void)
+{
+#ifdef WINDOWSNT
+  if (is_stderr_pipe())
+    fflush_unlocked(stderr);
+#endif /* WINDOWSNT */
+}
+
 /* Return the error output stream.  */
 static FILE *
 errstream (void)
modified   src/sysstdio.h
@@ -27,6 +27,7 @@ #define EMACS_SYSSTDIO_H
 #include "unlocked-io.h"

 extern FILE *emacs_fopen (char const *, char const *);
+extern void maybe_flush_stderr_after_newline (void);
 extern void errputc (int);
 extern void errwrite (void const *, ptrdiff_t);
 extern void close_output_streams (void);
modified   src/w32.c
@@ -10190,6 +10190,12 @@ term_ntproc (int ignored)
   term_w32select ();
 }

+static bool _is_stderr_pipe = false;
+bool is_stderr_pipe (void)
+{
+  return _is_stderr_pipe;
+}
+
 void
 init_ntproc (int dumping)
 {
@@ -10268,6 +10274,13 @@ init_ntproc (int dumping)
     _fdopen (2, "w");
   }

+  HANDLE seh = (HANDLE)_get_osfhandle(_fileno(stderr));
+  _is_stderr_pipe =
+    /* is pipe (anonymous, named or socket)*/
+    GetFileType(seh) == FILE_TYPE_PIPE
+    /* and is definitely not a socket */
+    && GetNamedPipeInfo(seh, NULL, NULL, NULL, NULL);
+
   /* unfortunately, atexit depends on implementation of malloc */
   /* atexit (term_ntproc); */
   if (!dumping)
modified   src/w32.h
@@ -170,6 +170,9 @@ #define FILE_SERIAL             0x0800
 extern HANDLE maybe_load_unicows_dll (void);
 extern void globals_of_w32 (void);

+/* return whether standard error is redirected to a pipe. */
+extern bool is_stderr_pipe (void);
+
 extern void term_timers (void);
 extern void init_timers (void);

modified   src/xdisp.c
@@ -10968,6 +10968,7 @@ message_to_stderr (Lisp_Object m)
     {
       noninteractive_need_newline = false;
       errputc ('\n');
+      maybe_flush_stderr_after_newline();
     }
   if (STRINGP (m))
     {
@@ -10984,7 +10985,11 @@ message_to_stderr (Lisp_Object m)
       errwrite (SDATA (s), SBYTES (s));
     }
   if (STRINGP (m) || !cursor_in_echo_area)
-    errputc ('\n');
+    {
+      errputc ('\n');
+      maybe_flush_stderr_after_newline();
+    }
+
 }

 /* The non-logging version of message3.

Thank you!