bug#47299: 27.1; emacs --batch on MS-Windows does not immediately display `print'ed lines when invoked outside of the Command Prompt

bug#47299: 27.1; emacs --batch on MS-Windows does not immediately display `print'ed lines when invoked outside of the Command Prompt

[Ioannis Kappas]

[-- Attachment #1.1: Type: text/plain, Size: 2661 bytes --]

emacs --batch behaves differently on MS-Windows vs. GNU/Linux (at
least) while `print'ing values out, leading to poor user experience
and unexpected behavior.

`print' and its variants (e.g. `prin1' and `princ'), output the printed
representation of an OBJECT passed in as an argument.

A user expects to see `print'ed output from a --batch program as it is
printed out, but output on 'windows-nt when Emacs --batch program is
invoked outside of Command Prompt is only displayed after the
accumulated `print'ed output reaches a certain threshold (4096 bytes)
or the program exits, leading to a poor user experience.

This is unlike the behavior when the program is invoked from the
Command Prompt (output is displayed immediately) or when the program
is invoked from a terminal on 'gnu/linux (output is displayed after a
newline is encountered).

For example, the following is expected to print out immediately a
newline followed by 1 followed by a newline (i.e. "\n1\n"):

: emacs -Q --batch --eval "(progn (princ 1) (sleep-for 5))"

but when invoked from outside the Command Prompt (e.g. M-x shell), the
output is only displayed after 5 seconds (i.e. while the program is
about to exit).

| `system-type' | invoked-from   | result          |
|---------------+----------------+-----------------|
| 'windows-nt   | Command Prompt | immediately     |
| 'windows-nt   | M-x shell      | after 5 seconds |
| 'gnu/linux    | terminal       | immediately     |
| 'gnu/linux    | M-x shell      | immediately     |

Further more, the behavior is even worse when emacs --batch is invoked
programmatically by Emacs itself. If the accumulated `print'ed output
length is relatively small (less than 4096 bytes), no output is
received by the parent Emacs process, unlikely that on 'gnu/linux
where output is received while lines are `print'ed out.

The attached `ert' test demonstrates the above point using `princ',
whereby the parent Emacs process receives the "hi\n" output from the
emacs --batch child process on 'gnu/linux as expected, but it receives
nothing on 'windows-nt.

: emacs -Q --batch -l ert -l batch-print-test.el -f ert-run-tests-batch

| `system-type' | result      |
|---------------+-------------|
| 'windows-nt   | fail        |
| 'gnu/linux    | pass        |

Analysis with likely fixes to follow.

(This report is similar to bug#46388)

Configured using:
 'configure --prefix=/mingw64 --build=x86_64-w64-mingw32 --with-modules
 --without-dbus --without-compress-install 'CFLAGS=-march=x86-64
 -mtune=generic -O2 -pipe' CPPFLAGS=-D__USE_MINGW_ANSI_STDIO=1
 'LDFLAGS=-pipe
 -Wl,--dynamicbase,--high-entropy-va,--nxcompat,--default-image-base-high''

[-- Attachment #1.2: Type: text/html, Size: 3210 bytes --]

[-- Attachment #2: batch-print-test.el --]
[-- Type: application/octet-stream, Size: 1208 bytes --]

;;; -*- lexical-binding: t; -*-
(require 'ert)

(ert-deftest batch-print ()
  "Test that when invoking emacs in batch mode as a
subprocess (i.e. not directly from a terminal), lines printed
with `princ' are flushed to output immediately (i.e. not
buffered)."
  (message ":system %s :version %s" system-configuration emacs-version)

  (let* ((proc-buf (get-buffer-create "issue/batch-print"))

	 ;; start a new emacs process that will print a line to stdout,
	 ;; wait for five second and then exit.
	 (cmd (format "%s -Q --batch --eval=\"%s\""
		      (substring-no-properties (car command-line-args))
		      '(progn (princ \\\"hi\\n\\\")
			 (sit-for 5))))
	 (proc (start-file-process-shell-command
                "test/batch-print" proc-buf cmd))

	 (outputs '()))
    
    ;; capture emacs output
    (set-process-filter proc (lambda (proc output)
			       (push output outputs)))
    
    ;; wait for the process to start
    (sleep-for 2)
    (should (equal 'run (process-status proc)))
    ;; program should have printed out "hi\n"
    (should (equal '("hi\n") outputs))

    ;; kill process and wait for it to die
    (delete-process proc)
    (sleep-for 1)))

bug#47299: 27.1; emacs --batch on MS-Windows does not immediately display `print'ed lines when invoked outside of the Command Prompt

[Ioannis Kappas]

[-- Attachment #1: Type: text/plain, Size: 6641 bytes --]

Analysis follows.

The `print' family of functions send their output to stdout by default
when ran in emacs --batch mode.

Similar to bug#46388 (27.1; emacs -batch does not output messages
immediately when invoked outside of the command prompt) the issue
stems from the expectation that stdout buffering should behave like in
POSIX systems, which is not necessarily the case on 'windows-nt.

The POSIX standard reads
(https://pubs.opengroup.org/onlinepubs/9699919799/functions/stdin.html)
under "stderr, stdin, stdout - standard I/O streams":

"""
...
At program start-up, three streams shall be predefined and need not be
opened explicitly: standard input (for reading conventional input),
standard output (for writing conventional output), and standard error
(for writing diagnostic output). When opened, the standard error
stream is not fully buffered; the standard input and standard output
streams are fully buffered if and only if the stream can be determined
not to refer to an interactive device.
...
"""

stdout on windows-nt is either always unbuffered (when attached to the
console) or fully-buffered (otherwise), while on 'gnu/linux I have
experimentally found it to be line-buffered when invoked from the
terminal or from another program such as Emacs M-x shell. I consider
this line-buffered behavior of 'gnu/linux to fall under the "interactive
device" of the standard mentioned above.

(When stdout is redirected to a file on 'gnu/linux, I found stdout to
be fully-buffered having a 4096 buffer size).

(See standard-streams-test report @
https://github.com/ikappaki/standard-streams-test for a tool that was
written to investigate the buffering behavior of stderr on MS-Windows,
i.e. unbuffered when attached to console, fully buffered
otherwise. The same tool was modified to test stdout on a similar
manner, which yielded exactly the same result).

Thus the difference in behavior as described in the bug report is due
to stdout on 'windows-nt being fully buffered, rather than being line
buffered as in 'gnu/linux.

As such, two likely fixes are presented below, one that flushes stdout
on a newline only iff stdout is attached to a pipe (as if it is the
"interactive device" of the POSIX standard) but staying fully buffered
otherwise (e.g. when output was redirected to a pipe or a socket), while
the other fix always flushing stdout on a newline (a much simpler and less
involved solution -- similar to the one in bug#46388 suggested by Mr. Eggert
-- though not optimized for redirections to files).

(Please note that the intention below is to change
src/print.c:printchar_to_stream(), which unless I missed something, is
only called from the `print' family of functions when Emacs is in
non-interactive mode).

_flush on newline when pipe_:
#+begin_src diff
5 files changed, 40 insertions(+)
src/print.c    |  2 ++
src/sysdep.c   | 21 +++++++++++++++++++++
src/sysstdio.h |  1 +
src/w32.c      | 13 +++++++++++++
src/w32.h      |  3 +++

modified   src/print.c
@@ -234,6 +234,8 @@ printchar_to_stream (unsigned int ch, FILE *stream)
       if (ASCII_CHAR_P (ch))
  {
    putc (ch, stream);

+          if (ch == '\n')
+            maybe_flush_stdout();
 #ifdef WINDOWSNT
    /* Send the output to a debugger (nothing happens if there
       isn't one).  */
modified   src/sysdep.c
@@ -2821,6 +2821,27 @@ errwrite (void const *buf, ptrdiff_t nbuf)
   fwrite_unlocked (buf, 1, nbuf, errstream ());
 }

+/* On windows, stdout 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 stdout it
+   means printing to standard output (for example with `princ' and its
+   variants) will not reach the parent process until at least this
+   process exits or the stream buffer is full, resulting to a very
+   poor interaction with the parent, contrary to how 'gnu/linux stdout
works.
+
+   We thus provide an interface to these functions to flush stdout
+   when has been redirected to a pipe.
+*/
+void maybe_flush_stdout (void)
+{
+#ifdef WINDOWSNT
+  if (is_stdout_pipe())
+    fflush_unlocked(stdout);
+#endif /* WINDOWSNT */
+}
+
 /* Close standard output and standard error, reporting any write
    errors as best we can.  This is intended for use with atexit.  */
 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_stdout (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_stdout_pipe = false;
+bool is_stdout_pipe (void)
+{
+  return _is_stdout_pipe;
+}
+
 void
 init_ntproc (int dumping)
 {
@@ -10268,6 +10274,13 @@ init_ntproc (int dumping)
     _fdopen (2, "w");
   }

+  HANDLE soh = (HANDLE)_get_osfhandle(_fileno(stdout));
+  _is_stdout_pipe =
+    /* is pipe (anonymous, named or socket)*/
+    GetFileType(soh) == FILE_TYPE_PIPE
+    /* and is definitely not a socket */
+    && GetNamedPipeInfo(soh, 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 output is redirected to a pipe. */
+extern bool is_stdout_pipe (void);
+
 extern void term_timers (void);
 extern void init_timers (void);
#+end_src

#+begin_src diff
  1 file changed, 8 insertions(+)
  src/print.c | 8 ++++++++

  modified   src/print.c
  @@ -235,6 +235,14 @@ printchar_to_stream (unsigned int ch, FILE *stream)
          {
            putc (ch, stream);
   #ifdef WINDOWSNT
  +          /* Flush stdout after outputting a newline since stdout is
  +             fully buffered when redirected to a pipe, contrary to
  +             POSIX when attached to an "interactive device" (see
  +             "stderr, stdin, stdout - standard I/O streams" in IEEE
  +             1003.1-2017) */
  +          if (ch == '\n' && stream == stdout)
  +            fflush_unlocked(stdout);
  +
            /* Send the output to a debugger (nothing happens if there
               isn't one).  */
            if (print_output_debug_flag && stream == stderr)

#+end_src

Feel free to modify/replace the above two as you find appropriate
(especially the excessive comments).

Thanks

[-- Attachment #2: Type: text/html, Size: 15043 bytes --]

bug#47299: 27.1; emacs --batch on MS-Windows does not immediately display `print'ed lines when invoked outside of the Command Prompt

[Eli Zaretskii]

> From: Ioannis Kappas <ioannis.kappas@gmail.com>
> Date: Sun, 21 Mar 2021 21:06:28 +0000
> 
> Similar to bug#46388 (27.1; emacs -batch does not output messages
> immediately when invoked outside of the command prompt) the issue
> stems from the expectation that stdout buffering should behave like in
> POSIX systems, which is not necessarily the case on 'windows-nt.

How stdout is buffered when it is not connected to a console device is
system-dependent, and any program that relies on a specific buffering
has a bug.

> stdout on windows-nt is either always unbuffered (when attached to the
> console) or fully-buffered (otherwise), while on 'gnu/linux I have
> experimentally found it to be line-buffered when invoked from the
> terminal or from another program such as Emacs M-x shell. I consider 
> this line-buffered behavior of 'gnu/linux to fall under the "interactive 
> device" of the standard mentioned above.
> 
> (When stdout is redirected to a file on 'gnu/linux, I found stdout to
> be fully-buffered having a 4096 buffer size).
> 
> (See standard-streams-test report @
> https://github.com/ikappaki/standard-streams-test for a tool that was
> written to investigate the buffering behavior of stderr on MS-Windows,
> i.e. unbuffered when attached to console, fully buffered
> otherwise. The same tool was modified to test stdout on a similar
> manner, which yielded exactly the same result).
> 
> Thus the difference in behavior as described in the bug report is due
> to stdout on 'windows-nt being fully buffered, rather than being line
> buffered as in 'gnu/linux.

The difference you observe is because on Windows we use pipes to
communicate with subprocesses, while on Posix platforms we by default
use PTYs, which are a kind of console device.  You can try using pipes
on GNU/Linux (by setting the process-connection-type variable), and
you will then see that the behavior on these two systems is similar,
not different.

> As such, two likely fixes are presented below, one that flushes stdout
> on a newline only iff stdout is attached to a pipe (as if it is the
> "interactive device" of the POSIX standard) but staying fully buffered
> otherwise (e.g. when output was redirected to a pipe or a socket), while
> the other fix always flushing stdout on a newline (a much simpler and less
> involved solution -- similar to the one in bug#46388 suggested by Mr. Eggert
> -- though not optimized for redirections to files).

I'm against both these changes.  Unconditionally flushing stdout each
newline is a non-starter, because it will slow down Lisp programs that
aren't interactive and need to send large buffers both ways.  At this
low level it cannot be known whether "the other end" of the pipe
expects interactivity or not.

What I can offer is to add a Lisp function to flush the stdout stream.
Lisp programs that need to provide interactive experience could call
that function where appropriate.

I don't see any other solution; doing what we do with stderr is
certainly inappropriate.

Thanks.

bug#47299: 27.1; emacs --batch on MS-Windows does not immediately display `print'ed lines when invoked outside of the Command Prompt

[Ioannis Kappas]

Hi Eli,

On Tue, Mar 23, 2021 at 11:33 AM Eli Zaretskii <eliz@gnu.org> wrote:

> What I can offer is to add a Lisp function to flush the stdout stream.
> Lisp programs that need to provide interactive experience could call
> that function where appropriate.
>

yes please, if you could do this at least we have a way to flush
important messages out to stdout. I can review/test the patch once
available.

Thanks

bug#47299: 27.1; emacs --batch on MS-Windows does not immediately display `print'ed lines when invoked outside of the Command Prompt

[Lars Ingebrigtsen]

Ioannis Kappas <ioannis.kappas@gmail.com> writes:

>> What I can offer is to add a Lisp function to flush the stdout stream.
>> Lisp programs that need to provide interactive experience could call
>> that function where appropriate.
>>
>
> yes please, if you could do this at least we have a way to flush
> important messages out to stdout. I can review/test the patch once
> available.

(I'm going through old bug reports that unfortunately weren't resolved
at the time.)

This was added as `flush-standard-output' in Emacs 29.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no