bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

[Ian Kelling]

In GNU Emacs 25.0.50.63 (x86_64-unknown-linux-gnu, GTK+ Version 3.10.8)
 of 2015-07-04
Repository revision: 5c36788e76b22587e554960ed837f724473597a9
Windowing system distributor `The X.Org Foundation', version 11.0.11501000
System Description:	Ubuntu 14.04.2 LTS

Configured using:
 `configure 'CFLAGS=-O0 -g3''

Configured features:
XPM JPEG TIFF GIF PNG RSVG IMAGEMAGICK SOUND GPM DBUS GCONF GSETTINGS
NOTIFY ACL LIBSELINUX GNUTLS LIBXML2 FREETYPE M17N_FLT LIBOTF XFT ZLIB
TOOLKIT_SCROLL_BARS GTK3 X11


Overview:

The patch for debbugs:17647 causes emacs to return too fast sometimes
when reading from any processes. It made adaptive read buffering be
mostly dead code and caused readline-complete package to break. Instead,
limit timeout less aggressively.

Reproducing the problem:

emacs -Q -l repro.el

;; repro.el
(progn
  (setq explicit-bash-args '("--norc"))
  (setenv "EMACS" "")
  (setq comint-process-echoes t)
  (shell)
  (let* ((proc (get-buffer-process (current-buffer)))
         (filter-orig (process-filter proc))
         accumulated-output)
    (process-send-string proc "stty echo\n")
    (set-process-query-on-exit-flag proc nil)
    (dotimes (unused 10)
      (sleep-for .05))
    (set-process-filter proc (lambda (proc string) (push (list string) accumulated-output)))
    (process-send-string proc "echo a bit of text for testing\n")
    (dotimes (unused 100)
      (sleep-for .03))
    (message "waiting for any process: %s" (reverse accumulated-output))
    (switch-to-buffer "*Messages*")
    nil))


Output without my patches:

waiting for any process:
((ech) (o a ) (bi) (t ) (o) (f ) (t) (e) (x) (t) ( ) (f) (o) (r) ( ) (t) (e) (s) (t) (i) (n) (g) (
) (a bit of text for testing
) (bash-4.3$ ))

Output with my patches (also the same same output as before the
debbugs:17647 patch, aka git 05d2821):

waiting for any process:
((ec) (ho a bit of text for testing
a bit of text for testing
bash-4.3$ ))


Background:

The 17647 patch had a few things bundled in and the root problem and fix
was not documented. The problem was that we got output, and we
subsequently got a pselect of 0, but we have set
timeout_reduced_for_timers, so we don't break when we should. This is
the relevant condition:

if ((time_limit || nsecs) && nfds == 0 && ! timeout_reduced_for_timers)
  break;

This was fixed by setting the timeout to 0 if we've attempted to read
process output. However, that was too big a hammer.

What we actually want is what the original code tried to do, but had
some logic problems: read data, and stop if there is no more to read in
a reasonable amount of time or we've reached the requested timeout.

There is a reference to someone else having this issue as well, without
figuring out anything about it
http://lists.gnu.org/archive/html/bug-gnu-emacs/2014-06/msg00958.html
And there is a resulting workaround in flymake-tests.el.


About the patches:

The first 4 are refactoring and not necessarily dependent on any others,
but independent patches would conflict and they make the code clearer so
I included them. I can separate any of them if needed.

Patch 3 depends on the patch for debbugs:20976, which is a simple fix
and I expect no problem for it be applied first.

I was careful to not squash unrelated changes as the function is rather
complicated and I could have saved a fair amount of time if there
weren't unrelated changes in the patch that introduced this bug.

The last 2 patches are probably easier to understand squashed together,
but the last one one fixes a different avenue for the same bug to
manifest (SIGIO), which I haven't tried to reproduce, and includes more
circumstances (reading from a specific process and before we've gotten
any output), and I'm not sure if some code might depend on it's behavior
so I broke it out.

Make check succeeds on all the patches.

Ian Kelling (7):
  ; Minor cleanup of wait_reading_process_output
  ; Remove ADAPTIVE_READ_BUFFERING ifdef
  ; Rename local var to match function name
  ; Rename local var nsecs to adaptive_nsecs
  : Refactor timeouts in wait_reading_process_output
  Don't return as fast reading any process output
  Avoid returning early reading process output due to SIGIO

 src/process.c | 211 +++++++++++++++++++++++++++-------------------------------
 1 file changed, 98 insertions(+), 113 deletions(-)

--
2.4.5

bug#20978: [PATCH 1/7] ; Minor cleanup of wait_reading_process_output

[Ian Kelling]

* src/process.c (wait_reading_process_output): simplify logic, fix dos
version comments

diff --git a/src/process.c b/src/process.c
index 5272792..191f617 100644
--- a/src/process.c
+++ b/src/process.c
@@ -4873,8 +4873,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
          no_avail = 1;
          FD_ZERO (&Available);
        }
-
-      if (!no_avail)
+      else
        {

 #ifdef ADAPTIVE_READ_BUFFERING
@@ -6965,9 +6964,7 @@ extern int sys_select (int, fd_set *, fd_set *, fd_set *,
    DO_DISPLAY means redisplay should be done to show subprocess
    output that arrives.

-   Return positive if we received input from WAIT_PROC (or from any
-   process if WAIT_PROC is null), zero if we attempted to receive
-   input but got none, and negative if we didn't even try.  */
+   Returns -1 signifying we got no output and did not try.  */

 int
 wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
--
2.4.5

bug#20978: [PATCH 2/7] ; Remove ADAPTIVE_READ_BUFFERING ifdef

[Ian Kelling]

* src/process.c (make-process, make-pipe-process, deactivate_process)
(wait_reading_process_output, read_process_output, send_process)
(init_process_emacs): ifdef ADAPTIVE_READ_BUFFERING was originally
added in case there was an operating system in which it was not
useful. That was 11 years ago and it hasn't happened. Make development
easier by not considering the effect of changes on a theoretical OS
where this is disabled.

diff --git a/src/process.c b/src/process.c
index 191f617..1541de2 100644
--- a/src/process.c
+++ b/src/process.c
@@ -224,11 +224,6 @@ static EMACS_INT update_tick;
 # define HAVE_SEQPACKET
 #endif

-#if !defined (ADAPTIVE_READ_BUFFERING) && !defined (NO_ADAPTIVE_READ_BUFFERING)
-#define ADAPTIVE_READ_BUFFERING
-#endif
-
-#ifdef ADAPTIVE_READ_BUFFERING
 #define READ_OUTPUT_DELAY_INCREMENT (TIMESPEC_RESOLUTION / 100)
 #define READ_OUTPUT_DELAY_MAX       (READ_OUTPUT_DELAY_INCREMENT * 5)
 #define READ_OUTPUT_DELAY_MAX_MAX   (READ_OUTPUT_DELAY_INCREMENT * 7)
@@ -242,10 +237,6 @@ static int process_output_delay_count;

 static bool process_output_skip;

-#else
-#define process_output_delay_count 0
-#endif
-
 static void create_process (Lisp_Object, char **, Lisp_Object);
 #ifdef USABLE_SIGIO
 static bool keyboard_bit_set (fd_set *);
@@ -1517,11 +1508,9 @@ usage: (make-process &rest ARGS)  */)
   pset_gnutls_cred_type (XPROCESS (proc), Qnil);
 #endif

-#ifdef ADAPTIVE_READ_BUFFERING
   XPROCESS (proc)->adaptive_read_buffering
     = (NILP (Vprocess_adaptive_read_buffering) ? 0
        : EQ (Vprocess_adaptive_read_buffering, Qt) ? 1 : 2);
-#endif

   /* Make the process marker point into the process buffer (if any).  */
   if (BUFFERP (buffer))
@@ -2184,11 +2173,9 @@ usage:  (make-pipe-process &rest ARGS)  */)
       FD_SET (inchannel, &input_wait_mask);
       FD_SET (inchannel, &non_keyboard_wait_mask);
     }
-#ifdef ADAPTIVE_READ_BUFFERING
   p->adaptive_read_buffering
     = (NILP (Vprocess_adaptive_read_buffering) ? 0
        : EQ (Vprocess_adaptive_read_buffering, Qt) ? 1 : 2);
-#endif

   /* Make the process marker point into the process buffer (if any).  */
   if (BUFFERP (buffer))
@@ -4183,7 +4170,6 @@ deactivate_process (Lisp_Object proc)
   emacs_gnutls_deinit (proc);
 #endif /* HAVE_GNUTLS */

-#ifdef ADAPTIVE_READ_BUFFERING
   if (p->read_output_delay > 0)
     {
       if (--process_output_delay_count < 0)
@@ -4191,7 +4177,6 @@ deactivate_process (Lisp_Object proc)
       p->read_output_delay = 0;
       p->read_output_skip = 0;
     }
-#endif

   /* Beware SIGCHLD hereabouts.  */

@@ -4876,7 +4861,6 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
       else
        {

-#ifdef ADAPTIVE_READ_BUFFERING
          /* Set the timeout for adaptive read buffering if any
             process has non-zero read_output_skip and non-zero
             read_output_delay, and we are not reading output for a
@@ -4908,7 +4892,6 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
              timeout = make_timespec (0, nsecs);
              process_output_skip = 0;
            }
-#endif

 #if defined (HAVE_NS)
           nfds = ns_select
@@ -5345,7 +5328,6 @@ read_process_output (Lisp_Object proc, int channel)
 #endif
        nbytes = emacs_read (channel, chars + carryover + buffered,
                             readmax - buffered);
-#ifdef ADAPTIVE_READ_BUFFERING
       if (nbytes > 0 && p->adaptive_read_buffering)
        {
          int delay = p->read_output_delay;
@@ -5371,7 +5353,6 @@ read_process_output (Lisp_Object proc, int channel)
              process_output_skip = 1;
            }
        }
-#endif
       nbytes += buffered;
       nbytes += buffered && nbytes <= 0;
     }
@@ -5840,7 +5821,6 @@ send_process (Lisp_Object proc, const char *buf, ptrdiff_t len,
 #endif
                written = emacs_write_sig (outfd, cur_buf, cur_len);
              rv = (written ? 0 : -1);
-#ifdef ADAPTIVE_READ_BUFFERING
              if (p->read_output_delay > 0
                  && p->adaptive_read_buffering == 1)
                {
@@ -5848,7 +5828,6 @@ send_process (Lisp_Object proc, const char *buf, ptrdiff_t len,
                  process_output_delay_count--;
                  p->read_output_skip = 0;
                }
-#endif
            }

          if (rv < 0)
@@ -7470,10 +7449,8 @@ init_process_emacs (void)
   num_pending_connects = 0;
 #endif

-#ifdef ADAPTIVE_READ_BUFFERING
   process_output_delay_count = 0;
   process_output_skip = 0;
-#endif

   /* Don't do this, it caused infinite select loops.  The display
      method should call add_keyboard_wait_descriptor on stdin if it
@@ -7638,7 +7615,6 @@ then a pipe is used in any case.
 The value takes effect when `start-process' is called.  */);
   Vprocess_connection_type = Qt;

-#ifdef ADAPTIVE_READ_BUFFERING
   DEFVAR_LISP ("process-adaptive-read-buffering", Vprocess_adaptive_read_buffering,
               doc: /* If non-nil, improve receive buffering by delaying after short reads.
 On some systems, when Emacs reads the output from a subprocess, the output data
@@ -7650,7 +7626,6 @@ If the value is t, the delay is reset after each write to the process; any other
 non-nil value means that the delay is not reset on write.
 The variable takes effect when `start-process' is called.  */);
   Vprocess_adaptive_read_buffering = Qt;
-#endif

   defsubr (&Sprocessp);
   defsubr (&Sget_process);
--
2.4.5

bug#20978: [PATCH 3/7] ; Rename local var to match function name

[Ian Kelling]

* src/process.c (wait_reading_process_output, status_notify):
Previously the function wait_reading_process_input was renamed to the
more logical wait_reading_process_output. Make it's local variables
consistent with that change.

diff --git a/src/process.c b/src/process.c
index 1541de2..d5569d4 100644
--- a/src/process.c
+++ b/src/process.c
@@ -4586,7 +4586,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
   int xerrno;
   Lisp_Object proc;
   struct timespec timeout, end_time;
-  int got_some_input = -1;
+  int got_some_output = -1;
   ptrdiff_t count = SPECPDL_INDEX ();

   FD_ZERO (&Available);
@@ -4634,7 +4634,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
        break;

       /* After reading input, vacuum up any leftovers without waiting.  */
-      if (0 <= got_some_input)
+      if (0 <= got_some_output)
        nsecs = -1;

       /* Compute time from now till when time limit is up.  */
@@ -4755,7 +4755,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
              /* It's okay for us to do this and then continue with
                 the loop, since timeout has already been zeroed out.  */
              clear_waiting_for_input ();
-	      got_some_input = status_notify (NULL, wait_proc);
+	      got_some_output = status_notify (NULL, wait_proc);
              if (do_display) redisplay_preserve_echo_area (13);
            }
        }
@@ -4791,8 +4791,8 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
                    }
                  else
                    {
-		      if (got_some_input < nread)
-			got_some_input = nread;
+		      if (got_some_output < nread)
+			got_some_output = nread;
                      if (nread == 0)
                        break;
                      read_some_bytes = true;
@@ -5089,8 +5089,8 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
                 buffered-ahead character if we have one.  */

              nread = read_process_output (proc, channel);
-	      if ((!wait_proc || wait_proc == XPROCESS (proc)) && got_some_input < nread)
-		got_some_input = nread;
+	      if ((!wait_proc || wait_proc == XPROCESS (proc)) && got_some_output < nread)
+		got_some_output = nread;
              if (nread > 0)
                {
                  /* Since read_process_output can run a filter,
@@ -5250,7 +5250,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
       QUIT;
     }

-  return got_some_input;
+  return got_some_output;
 }
 \f
 /* Given a list (FUNCTION ARGS...), apply FUNCTION to the ARGS.  */
@@ -6659,7 +6659,7 @@ status_notify (struct Lisp_Process *deleting_process,
   Lisp_Object proc;
   Lisp_Object tail, msg;
   struct gcpro gcpro1, gcpro2;
-  int got_some_input = -1;
+  int got_some_output = -1;

   tail = Qnil;
   msg = Qnil;
@@ -6693,8 +6693,8 @@ status_notify (struct Lisp_Process *deleting_process,
            {
              int nread = read_process_output (proc, p->infd);
              if ((!wait_proc || wait_proc == XPROCESS (proc))
-                  && got_some_input < nread)
-		got_some_input = nread;
+                  && got_some_output < nread)
+               got_some_output = nread;
              if (nread <= 0)
                break;
            }
@@ -6729,7 +6729,7 @@ status_notify (struct Lisp_Process *deleting_process,

   update_mode_lines = 24;  /* In case buffers use %s in mode-line-format.  */
   UNGCPRO;
-  return got_some_input;
+  return got_some_output;
 }

 DEFUN ("internal-default-process-sentinel", Finternal_default_process_sentinel,
--
2.4.5

bug#20978: [PATCH 4/7] ; Rename local var nsecs to adaptive_nsecs

[Ian Kelling]

* src/process.c (wait_reading_process_output): Rename inner nsecs to
adaptive_nsecs. There is already an nsecs, and this function is
confusing enough.

diff --git a/src/process.c b/src/process.c
index d5569d4..68a815f 100644
--- a/src/process.c
+++ b/src/process.c
@@ -4868,9 +4868,9 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
             Vprocess_adaptive_read_buffering is nil.  */
          if (process_output_skip && check_delay > 0)
            {
-	      int nsecs = timeout.tv_nsec;
-	      if (timeout.tv_sec > 0 || nsecs > READ_OUTPUT_DELAY_MAX)
-		nsecs = READ_OUTPUT_DELAY_MAX;
+	      int adaptive_nsecs = timeout.tv_nsec;
+              if (timeout.tv_sec > 0 || adaptive_nsecs > READ_OUTPUT_DELAY_MAX)
+		adaptive_nsecs = READ_OUTPUT_DELAY_MAX;
              for (channel = 0; check_delay > 0 && channel <= max_process_desc; channel++)
                {
                  proc = chan_process[channel];
@@ -4885,11 +4885,11 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
                        continue;
                      FD_CLR (channel, &Available);
                      XPROCESS (proc)->read_output_skip = 0;
-		      if (XPROCESS (proc)->read_output_delay < nsecs)
-			nsecs = XPROCESS (proc)->read_output_delay;
+		      if (XPROCESS (proc)->read_output_delay < adaptive_nsecs)
+			adaptive_nsecs = XPROCESS (proc)->read_output_delay;
                    }
                }
-	      timeout = make_timespec (0, nsecs);
+	      timeout = make_timespec (0, adaptive_nsecs);
              process_output_skip = 0;
            }

--
2.4.5

bug#20978: [PATCH 5/7] : Refactor timeouts in wait_reading_process_output

[Ian Kelling]

* src/process.c (wait_reading_process_output): Simplify timeouts with
an enum. Remove a redundant condition.

diff --git a/src/process.c b/src/process.c
index 68a815f..538455c 100644
--- a/src/process.c
+++ b/src/process.c
@@ -4586,6 +4586,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
   int xerrno;
   Lisp_Object proc;
   struct timespec timeout, end_time;
+  enum { MINIMUM, TIMEOUT, INFINITY } wait;
   int got_some_output = -1;
   ptrdiff_t count = SPECPDL_INDEX ();

@@ -4601,21 +4602,19 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
                             waiting_for_user_input_p);
   waiting_for_user_input_p = read_kbd;

-  if (time_limit < 0)
-    {
-      time_limit = 0;
-      nsecs = -1;
-    }
-  else if (TYPE_MAXIMUM (time_t) < time_limit)
+  if (TYPE_MAXIMUM (time_t) < time_limit)
     time_limit = TYPE_MAXIMUM (time_t);

-  /* Since we may need to wait several times,
-     compute the absolute time to return at.  */
-  if (time_limit || nsecs > 0)
+  if (time_limit < 0 || nsecs < 0)
+    wait = MINIMUM;
+  else if (time_limit > 0 || nsecs > 0)
     {
-      timeout = make_timespec (time_limit, nsecs);
-      end_time = timespec_add (current_timespec (), timeout);
+      wait = TIMEOUT;
+      end_time = timespec_add (current_timespec (),
+                               make_timespec (time_limit, nsecs));
     }
+  else
+    wait = INFINITY;

   while (1)
     {
@@ -4635,19 +4634,15 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,

       /* After reading input, vacuum up any leftovers without waiting.  */
       if (0 <= got_some_output)
-	nsecs = -1;
+        wait = MINIMUM;

       /* Compute time from now till when time limit is up.  */
       /* Exit if already run out.  */
-      if (nsecs < 0)
+      if (wait == MINIMUM)
        {
-	  /* A negative timeout means
-	     gobble output available now
-	     but don't wait at all.  */
-
-	  timeout = make_timespec (0, 0);
+          timeout = make_timespec (0, 0);
        }
-      else if (time_limit || nsecs > 0)
+      else if (wait == TIMEOUT)
        {
          struct timespec now = current_timespec ();
          if (timespec_cmp (end_time, now) <= 0)
@@ -4698,24 +4693,20 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
              && requeued_events_pending_p ())
            break;

-	  /* A negative timeout means do not wait at all.  */
-	  if (nsecs >= 0)
-	    {
-	      if (timespec_valid_p (timer_delay))
-		{
-		  if (timespec_cmp (timer_delay, timeout) < 0)
-		    {
-		      timeout = timer_delay;
-		      timeout_reduced_for_timers = true;
-		    }
-		}
-	      else
-		{
-		  /* This is so a breakpoint can be put here.  */
-		  wait_reading_process_output_1 ();
-		}
-	    }
-	}
+          if (timespec_valid_p (timer_delay))
+            {
+              if (timespec_cmp (timer_delay, timeout) < 0)
+                {
+                  timeout = timer_delay;
+                  timeout_reduced_for_timers = true;
+                }
+            }
+          else
+            {
+              /* This is so a breakpoint can be put here.  */
+              wait_reading_process_output_1 ();
+            }
+        }

       /* Cause C-g and alarm signals to take immediate action,
         and cause input available signals to zero out timeout.
@@ -4964,7 +4955,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
       /*  If we woke up due to SIGWINCH, actually change size now.  */
       do_pending_window_change (0);

-      if ((time_limit || nsecs) && nfds == 0 && ! timeout_reduced_for_timers)
+      if (wait != INFINITY && nfds == 0 && ! timeout_reduced_for_timers)
        /* We waited the full specified time, so return now.  */
        break;
       if (nfds < 0)
@@ -6953,21 +6944,21 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
 {
   register int nfds;
   struct timespec end_time, timeout;
+  enum { MINIMUM, TIMEOUT, INFINITY } wait;

-  if (time_limit < 0)
-    {
-      time_limit = 0;
-      nsecs = -1;
-    }
-  else if (TYPE_MAXIMUM (time_t) < time_limit)
+  if (TYPE_MAXIMUM (time_t) < time_limit)
     time_limit = TYPE_MAXIMUM (time_t);

-  /* What does time_limit really mean?  */
-  if (time_limit || nsecs > 0)
+  if (time_limit < 0 || nsecs < 0)
+    wait = MINIMUM;
+  else if (time_limit > 0 || nsecs > 0)
     {
-      timeout = make_timespec (time_limit, nsecs);
-      end_time = timespec_add (current_timespec (), timeout);
+      wait = TIMEOUT;
+      end_time = timespec_add (current_timespec (),
+                               make_timespec (time_limit, nsecs));
     }
+  else
+    wait = INFINITY;

   /* Turn off periodic alarms (in case they are in use)
      and then turn off any other atimers,
@@ -6993,15 +6984,11 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,

       /* Compute time from now till when time limit is up.  */
       /* Exit if already run out.  */
-      if (nsecs < 0)
+      if (wait == MINIMUM)
        {
-	  /* A negative timeout means
-	     gobble output available now
-	     but don't wait at all.  */
-
-	  timeout = make_timespec (0, 0);
+          timeout = make_timespec (0, 0);
        }
-      else if (time_limit || nsecs > 0)
+      else if (wait == TIMEOUT)
        {
          struct timespec now = current_timespec ();
          if (timespec_cmp (end_time, now) <= 0)
@@ -7039,7 +7026,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
              && requeued_events_pending_p ())
            break;

-	  if (timespec_valid_p (timer_delay) && nsecs >= 0)
+	  if (timespec_valid_p (timer_delay))
            {
              if (timespec_cmp (timer_delay, timeout) < 0)
                {
@@ -7083,7 +7070,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
       /*  If we woke up due to SIGWINCH, actually change size now.  */
       do_pending_window_change (0);

-      if ((time_limit || nsecs) && nfds == 0 && ! timeout_reduced_for_timers)
+      if (wait != INFINITY && nfds == 0 && ! timeout_reduced_for_timers)
        /* We waited the full specified time, so return now.  */
        break;

--
2.4.5

bug#20978: [PATCH 6/7] Don't return as fast reading any process output

[Ian Kelling]

* src/process.c (wait_reading_process_output): The patch for
debbugs:17647 returns too fast sometimes when reading from any
processes. Revert part of it, and limit the timeout more
sensibly.

diff --git a/src/process.c b/src/process.c
index 538455c..cb48e5f 100644
--- a/src/process.c
+++ b/src/process.c
@@ -4585,7 +4585,8 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
   bool no_avail;
   int xerrno;
   Lisp_Object proc;
-  struct timespec timeout, end_time;
+  struct timespec timeout, end_time, timer_delay;
+  struct timespec got_output_end_time = invalid_timespec ();
   enum { MINIMUM, TIMEOUT, INFINITY } wait;
   int got_some_output = -1;
   ptrdiff_t count = SPECPDL_INDEX ();
@@ -4618,7 +4619,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,

   while (1)
     {
-      bool timeout_reduced_for_timers = false;
+      bool process_skipped = false;

       /* If calling from keyboard input, do not quit
         since we want to return C-g as an input character.
@@ -4632,10 +4633,6 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
       if (! NILP (wait_for_cell) && ! NILP (XCAR (wait_for_cell)))
        break;

-      /* After reading input, vacuum up any leftovers without waiting.  */
-      if (0 <= got_some_output)
-        wait = MINIMUM;
-
       /* Compute time from now till when time limit is up.  */
       /* Exit if already run out.  */
       if (wait == MINIMUM)
@@ -4661,8 +4658,6 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
       if (NILP (wait_for_cell)
          && just_wait_proc >= 0)
        {
-	  struct timespec timer_delay;
-
          do
            {
              unsigned old_timers_run = timers_run;
@@ -4693,19 +4688,9 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
              && requeued_events_pending_p ())
            break;

-          if (timespec_valid_p (timer_delay))
-            {
-              if (timespec_cmp (timer_delay, timeout) < 0)
-                {
-                  timeout = timer_delay;
-                  timeout_reduced_for_timers = true;
-                }
-            }
-          else
-            {
-              /* This is so a breakpoint can be put here.  */
+          /* This is so a breakpoint can be put here.  */
+          if (!timespec_valid_p (timer_delay))
               wait_reading_process_output_1 ();
-            }
         }

       /* Cause C-g and alarm signals to take immediate action,
@@ -4875,6 +4860,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
                      if (!XPROCESS (proc)->read_output_skip)
                        continue;
                      FD_CLR (channel, &Available);
+                      process_skipped = true;
                      XPROCESS (proc)->read_output_skip = 0;
                      if (XPROCESS (proc)->read_output_delay < adaptive_nsecs)
                        adaptive_nsecs = XPROCESS (proc)->read_output_delay;
@@ -4884,6 +4870,30 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
              process_output_skip = 0;
            }

+          /* If we've got some output and haven't limited our timeout
+           * with adaptive read buffering, limit it. */
+          if (got_some_output > 0 && !process_skipped
+              && (timeout.tv_sec
+                  || timeout.tv_nsec > READ_OUTPUT_DELAY_INCREMENT))
+            timeout = make_timespec (0, READ_OUTPUT_DELAY_INCREMENT);
+
+
+          if (NILP (wait_for_cell) && just_wait_proc >= 0
+              && timespec_valid_p (timer_delay)
+              && timespec_cmp (timer_delay, timeout) < 0)
+            {
+              struct timespec timeout_abs = timespec_add (current_timespec (),
+                                                          timeout);
+              if (!timespec_valid_p (got_output_end_time)
+                  || timespec_cmp (timeout_abs,
+                                   got_output_end_time) < 0)
+                got_output_end_time = timeout_abs;
+              timeout = timer_delay;
+            }
+          else
+            got_output_end_time = invalid_timespec ();
+
+
 #if defined (HAVE_NS)
           nfds = ns_select
 #elif defined (HAVE_GLIB)
@@ -4955,9 +4965,17 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
       /*  If we woke up due to SIGWINCH, actually change size now.  */
       do_pending_window_change (0);

-      if (wait != INFINITY && nfds == 0 && ! timeout_reduced_for_timers)
-	/* We waited the full specified time, so return now.  */
-	break;
+      if (nfds == 0)
+        {
+          struct timespec now = current_timespec ();
+          if ((timeout.tv_sec == 0 && timeout.tv_nsec == 0)
+              || (wait == TIMEOUT && timespec_cmp (end_time, now) <= 0)
+              || (!process_skipped && got_some_output > 0
+                  && (!timespec_valid_p (got_output_end_time)
+                      || timespec_cmp (got_output_end_time, now) <= 0)))
+            break;
+        }
+
       if (nfds < 0)
        {
          if (xerrno == EINTR)
@@ -5084,6 +5102,9 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
                got_some_output = nread;
              if (nread > 0)
                {
+                  /* vacuum up any leftovers without waiting.  */
+                  if (wait_proc == XPROCESS (proc))
+                    wait = MINIMUM;
                  /* Since read_process_output can run a filter,
                     which can call accept-process-output,
                     don't try to read from any other processes
--
2.4.5

bug#20978: [PATCH 7/7] Avoid returning early reading process output due to SIGIO

[Ian Kelling]

* src/process.c (wait_reading_process_output): Extend the behavior of
not breaking due to not finding output when a timer has lowered the
timeout to include when SIGIO lowers the timeout.

diff --git a/src/process.c b/src/process.c
index 052f94e..f64a064 100644
--- a/src/process.c
+++ b/src/process.c
@@ -4967,12 +4967,17 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,

       if (nfds == 0)
         {
+          /* If we've past the requested timeout, or got some output
+             and aren't skipping processes, and haven't lowered our
+             timeout due to timers or SIGIO, or have waited a long
+             amount of time due to repeated timers */
           struct timespec now = current_timespec ();
-          if ((timeout.tv_sec == 0 && timeout.tv_nsec == 0)
+          if (wait == MINIMUM
               || (wait == TIMEOUT && timespec_cmp (end_time, now) <= 0)
               || (!process_skipped && got_some_output > 0
                   && (!timespec_valid_p (got_output_end_time)
-                      || timespec_cmp (got_output_end_time, now) <= 0)))
+                      || timespec_cmp (got_output_end_time, now) <= 0)
+                  && (timeout.tv_sec > 0 || timeout.tv_nsec > 0)))
             break;
         }

--
2.4.5

bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

[Eli Zaretskii]

> From: Ian Kelling <ian@iankelling.org>
> Date: Sat, 04 Jul 2015 05:34:33 -0700
> 
> About the patches:
> 
> The first 4 are refactoring and not necessarily dependent on any others,
> but independent patches would conflict and they make the code clearer so
> I included them. I can separate any of them if needed.
> 
> Patch 3 depends on the patch for debbugs:20976, which is a simple fix
> and I expect no problem for it be applied first.

Thanks.

I don't know how others feel, but I personally would prefer that
patches not be split between different messages, as that makes it
harder to grasp and apply.  Especially since some (most) of them
belong to the same changeset.  And refactoring should IMO be together
with the actual changes.

> I was careful to not squash unrelated changes as the function is rather
> complicated and I could have saved a fair amount of time if there
> weren't unrelated changes in the patch that introduced this bug.

Unrelated is in the eyes of the beholder.  We all have our different
views on that.

Thanks again for working on this.  I will defer to Paul to provide the
_real_ feedback ;-)

bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

[Ian Kelling]

Eli Zaretskii <eliz@gnu.org> writes:
>
> I don't know how others feel, but I personally would prefer that
> patches not be split between different messages, as that makes it
> harder to grasp and apply.  Especially since some (most) of them
> belong to the same changeset.

That was my first intuition too. I hadn't submitted a set of patches
before to emacs and I couldn't find any documentation on it, except git
format-patch docs seems to assume you would always use separate
messages. Say the word and I will send one more message which is all of
them together.

> And refactoring should IMO be together
> with the actual changes.
>

Imo, it depends.

>> I was careful to not squash unrelated changes as the function is rather
>> complicated and I could have saved a fair amount of time if there
>> weren't unrelated changes in the patch that introduced this bug.
>
> Unrelated is in the eyes of the beholder.  We all have our different
> views on that.

Agreed.

bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

[Ian Kelling]

Eli Zaretskii <eliz@gnu.org> writes:

> Thanks again for working on this.  I will defer to Paul to provide the
> _real_ feedback ;-)

Yw. Thanks for the encouragement.

bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

[Eli Zaretskii]

> From: Ian Kelling <ian@iankelling.org>
> Cc: 20978@debbugs.gnu.org
> Date: Sat, 04 Jul 2015 06:13:37 -0700
> 
> Say the word and I will send one more message which is all of them
> together.

Please wait for others to chime in, I'd hate to have you do
unnecessary work, especially as I'm not the one to review your
patches.

Thanks.

bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

[Stefan Monnier]

>> Say the word and I will send one more message which is all of them
>> together.

I don't think it's worth resending, no.

> Please wait for others to chime in, I'd hate to have you do
> unnecessary work, especially as I'm not the one to review
> your patches.

It's a "standard" work flow in the Git world.  Presumably we should have
a Gnus command which (after marking the 7 messages) checks out a fresh
branch, and applies those 7 patches, after which you can look at the
separately or together at your leisure with Git/VC/Magit/...


        Stefan

bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

[Eli Zaretskii]

> From: Stefan Monnier <monnier@IRO.UMontreal.CA>
> Cc: Ian Kelling <ian@iankelling.org>, 20978@debbugs.gnu.org
> Date: Sat, 04 Jul 2015 14:56:00 -0400
> 
> It's a "standard" work flow in the Git world.

I know.  But it doesn't mean I must like it, nor that we must adopt
it.

bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

[Stefan Monnier]

>> It's a "standard" work flow in the Git world.
> I know.  But it doesn't mean I must like it, nor that we must
> adopt it.

No, indeed, but it's worth taking a good look at it, since the Linux
guys have spent a fair bit of effort to streamline their process, to
deal with the large number of patches they handle.


        Stefan

bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

[Paul Eggert]

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

Thanks for the patches; they were very clear and organized, in a difficult code 
area.  I installed them into the Emacs master with minor changes, along with the 
attached further patch, and am marking this bug as done.

As far as patch format goes, I mildly prefer attachments but the form you used 
was fine.  My preference is because I am not on the bug-gnu-emacs mailing list, 
and don't know how to retrieve your email from debbugs.gnu.org or from 
lists.gnu.org -- the best I could come up with was the mbox format of 
lists.gnu.org but that did not apply cleanly.

[-- Attachment #2: 0008-Avoid-duplicate-calls-to-current_timespec.patch --]
[-- Type: text/x-diff, Size: 4064 bytes --]

From fea99d2d8563334a8c88ec4207064ce49d77dd1f Mon Sep 17 00:00:00 2001
From: Paul Eggert <eggert@cs.ucla.edu>
Date: Sun, 5 Jul 2015 19:19:13 -0700
Subject: [PATCH 8/8] Avoid duplicate calls to current_timespec

* src/process.c (wait_reading_process_output):
Cache current_timespec results as long as we're not waiting.
---
 src/process.c | 44 +++++++++++++++++++++++++++++---------------
 1 file changed, 29 insertions(+), 15 deletions(-)

diff --git a/src/process.c b/src/process.c
index 8a8dad7..9d8fa22 100644
--- a/src/process.c
+++ b/src/process.c
@@ -4591,6 +4591,9 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
   int got_some_output = -1;
   ptrdiff_t count = SPECPDL_INDEX ();
 
+  /* Close to the current time if known, an invalid timespec otherwise.  */
+  struct timespec now = invalid_timespec ();
+
   FD_ZERO (&Available);
   FD_ZERO (&Writeok);
 
@@ -4611,8 +4614,8 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
   else if (time_limit > 0 || nsecs > 0)
     {
       wait = TIMEOUT;
-      end_time = timespec_add (current_timespec (),
-                               make_timespec (time_limit, nsecs));
+      now = current_timespec ();
+      end_time = timespec_add (now, make_timespec (time_limit, nsecs));
     }
   else
     wait = INFINITY;
@@ -4637,7 +4640,8 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
       /* Exit if already run out.  */
       if (wait == TIMEOUT)
 	{
-	  struct timespec now = current_timespec ();
+	  if (!timespec_valid_p (now))
+	    now = current_timespec ();
 	  if (timespec_cmp (end_time, now) <= 0)
 	    break;
 	  timeout = timespec_sub (end_time, now);
@@ -4830,7 +4834,6 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
 	}
       else
 	{
-
 	  /* Set the timeout for adaptive read buffering if any
 	     process has non-zero read_output_skip and non-zero
 	     read_output_delay, and we are not reading output for a
@@ -4876,17 +4879,21 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
 	      && timespec_valid_p (timer_delay)
 	      && timespec_cmp (timer_delay, timeout) < 0)
 	    {
-	      struct timespec timeout_abs = timespec_add (current_timespec (),
-							  timeout);
+	      if (!timespec_valid_p (now))
+		now = current_timespec ();
+	      struct timespec timeout_abs = timespec_add (now, timeout);
 	      if (!timespec_valid_p (got_output_end_time)
-		  || timespec_cmp (timeout_abs,
-				   got_output_end_time) < 0)
+		  || timespec_cmp (timeout_abs, got_output_end_time) < 0)
 		got_output_end_time = timeout_abs;
 	      timeout = timer_delay;
 	    }
 	  else
 	    got_output_end_time = invalid_timespec ();
 
+	  /* NOW can become inaccurate if time can pass during pselect.  */
+	  if (timeout.tv_sec > 0 || timeout.tv_nsec > 0)
+	    now = invalid_timespec ();
+
 #if defined (HAVE_NS)
           nfds = ns_select
 #elif defined (HAVE_GLIB)
@@ -4965,14 +4972,21 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
              haven't lowered our timeout due to timers or SIGIO and
              have waited a long amount of time due to repeated
              timers.  */
-	  struct timespec now = current_timespec ();
-          if (wait < TIMEOUT
-	      || (wait == TIMEOUT && timespec_cmp (end_time, now) <= 0)
-	      || (!process_skipped && got_some_output > 0
-		  && (!timespec_valid_p (got_output_end_time)
-		      || timespec_cmp (got_output_end_time, now) <= 0)
-		  && (timeout.tv_sec > 0 || timeout.tv_nsec > 0)))
+	  if (wait < TIMEOUT)
 	    break;
+	  struct timespec cmp_time
+	    = (wait == TIMEOUT
+	       ? end_time
+	       : (!process_skipped && got_some_output > 0
+		  && (timeout.tv_sec > 0 || timeout.tv_nsec > 0))
+	       ? got_output_end_time
+	       : invalid_timespec ());
+	  if (timespec_valid_p (cmp_time))
+	    {
+	      now = current_timespec ();
+	      if (timespec_cmp (cmp_time, now) <= 0)
+		break;
+	    }
 	}
 
       if (nfds < 0)
-- 
2.1.0

bug#20978: 25.0.50; [PATCH 0/7] Emacs can return too fast when reading from any processes

[Glenn Morris]

Paul Eggert wrote:

> As far as patch format goes, I mildly prefer attachments but the form
> you used was fine.  My preference is because I am not on the
> bug-gnu-emacs mailing list, and don't know how to retrieve your email
> from debbugs.gnu.org or from lists.gnu.org -- the best I could come up
> with was the mbox format of lists.gnu.org but that did not apply
> cleanly.

There's M-x gnus-read-ephemeral-emacs-bug-group, if that helps.
Or wget 'http://debbugs.gnu.org/cgi/bugreport.cgi?mbox=yes;bug=20978'.
(But I don't really get what the problem is.)