bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Christer Ekholm]

[-- Attachment #1: message body text --]
[-- Type: text/plain, Size: 242 bytes --]

Hi,

I decided to test the next release, and observed that a elisp package
i'm using got very poor networ responsivenes.

I have bisected to commit
 ad236260 Avoid duplicate calls to current_timespec

And, The attached patch fixes it for me


[-- Attachment #2: [PATCH] Fix condition for return from waiting for process output. --]
[-- Type: text/plain, Size: 1244 bytes --]

From ce0d739141770f885527a9f1a2db8ff79599ae11 Mon Sep 17 00:00:00 2001
From: Christer Ekholm <che@chrekh.se>
Date: Sun, 26 Jun 2016 01:53:42 +0200
Subject: [PATCH] Fix condition for return from waiting for process output.

* src/process.c (wait_reading_process_output): Move the test for
process output to outside setting of cmp_time, so that we don't miss
to exit if we have output, but got_output_end_time is not valid.
---
 src/process.c | 7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/src/process.c b/src/process.c
index ed0c529..23e2c52 100644
--- a/src/process.c
+++ b/src/process.c
@@ -5271,12 +5271,13 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
              timers.  */
 	  if (wait < TIMEOUT)
 	    break;
+	  if (!process_skipped && got_some_output > 0
+	      && (!timespec_valid_p (got_output_end_time)
+		  || (timeout.tv_sec > 0 || timeout.tv_nsec > 0)))
+	    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))
 	    {
-- 
2.9.0


[-- Attachment #3: message body and .signature --]
[-- Type: text/plain, Size: 3838 bytes --]



In GNU Emacs 25.1.50.1 (x86_64-pc-linux-gnu, GTK+ Version 3.20.6)
 of 2016-06-28 built on jane
Repository revision: 2adc4ccd03d24660bcf7f8ff056c7f32b92b584d
Windowing system distributor 'The X.Org Foundation', version 11.0.11803000
System Description:	Gentoo Base System release 2.2

Configured using:
 'configure --prefix=/usr --build=x86_64-pc-linux-gnu
 --host=x86_64-pc-linux-gnu --mandir=/usr/share/man
 --infodir=/usr/share/info --datadir=/usr/share --sysconfdir=/etc
 --localstatedir=/var/lib --disable-dependency-tracking
 --disable-silent-rules --docdir=/usr/share/doc/emacs-vcs-25.1.9999-r1
 --htmldir=/usr/share/doc/emacs-vcs-25.1.9999-r1/html
 --libdir=/usr/lib64 --program-suffix=-emacs-25-vcs
 --infodir=/usr/share/info/emacs-25-vcs --localstatedir=/var
 --enable-locallisppath=/etc/emacs:/usr/share/emacs/site-lisp
 --with-gameuser=:gamestat --without-compress-install
 --with-file-notification=inotify --disable-acl --with-dbus
 --without-gpm --without-hesiod --without-kerberos --without-kerberos5
 --with-xml2 --without-selinux --with-gnutls --without-wide-int
 --with-zlib --with-sound=alsa --with-x --without-ns --without-gconf
 --without-gsettings --with-toolkit-scroll-bars --with-gif --with-jpeg
 --with-png --with-rsvg --without-tiff --with-xpm --with-imagemagick
 --without-xft --without-cairo --without-libotf --without-m17n-flt
 --with-x-toolkit=gtk3 --without-xwidgets
 GENTOO_PACKAGE=app-editors/emacs-vcs-25.1.9999-r1'

Configured features:
XPM JPEG GIF PNG RSVG IMAGEMAGICK SOUND DBUS NOTIFY GNUTLS LIBXML2 ZLIB
TOOLKIT_SCROLL_BARS GTK3 X11

Important settings:
  value of $LC_MESSAGES: C
  value of $LANG: sv_SE.utf8
  locale-coding-system: utf-8-unix

Major mode: Info

Minor modes in effect:
  tooltip-mode: t
  global-eldoc-mode: t
  electric-indent-mode: t
  mouse-wheel-mode: t
  tool-bar-mode: t
  menu-bar-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  font-lock-mode: t
  blink-cursor-mode: t
  auto-composition-mode: t
  auto-encryption-mode: t
  auto-compression-mode: t
  buffer-read-only: t
  line-number-mode: t
  transient-mark-mode: t

Load-path shadows:
None found.

Features:
(misearch multi-isearch jka-compr info pp shadow sort mail-extr emacsbug
message puny seq byte-opt gv bytecomp byte-compile cl-extra help-mode
cconv cl-loaddefs pcase cl-lib dired dired-loaddefs format-spec rfc822
mml easymenu mml-sec password-cache epa derived epg epg-config gnus-util
rmail rmail-loaddefs mm-decode mm-bodies mm-encode mail-parse rfc2231
mailabbrev gmm-utils mailheader sendmail rfc2047 rfc2045 ietf-drums
mm-util mail-prsvr mail-utils site-gentoo w3m-load time-date mule-util
tooltip eldoc electric uniquify ediff-hook vc-hooks lisp-float-type
mwheel term/x-win x-win term/common-win x-dnd tool-bar dnd fontset image
regexp-opt fringe tabulated-list newcomment elisp-mode lisp-mode
prog-mode register page menu-bar rfn-eshadow timer select scroll-bar
mouse jit-lock font-lock syntax facemenu font-core term/tty-colors frame
cl-generic cham georgian utf-8-lang misc-lang vietnamese tibetan thai
tai-viet lao korean japanese eucjp-ms cp51932 hebrew greek romanian
slovak czech european ethiopic indian cyrillic chinese charscript
case-table epa-hook jka-cmpr-hook help simple abbrev obarray minibuffer
cl-preloaded nadvice loaddefs button faces cus-face macroexp files
text-properties overlay sha1 md5 base64 format env code-pages mule
custom widget hashtable-print-readable backquote dbusbind inotify
dynamic-setting move-toolbar gtk x-toolkit x multi-tty
make-network-process emacs)

Memory information:
((conses 16 132582 36234)
 (symbols 48 21171 6)
 (miscs 40 121 488)
 (strings 32 24668 10672)
 (string-bytes 1 782873)
 (vectors 16 14829)
 (vector-slots 8 461770 9460)
 (floats 8 188 429)
 (intervals 56 5222 1)
 (buffers 976 15)
 (heap 1024 46495 2574))

-- 
 Christer

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Glenn Morris]

Christer Ekholm wrote:

> I decided to test the next release, and observed that a elisp package
> i'm using got very poor networ responsivenes.
>
> I have bisected to commit
>  ad236260 Avoid duplicate calls to current_timespec


I see this is in emacs-25, so perhaps should be fixed there.


> And, The attached patch fixes it for me
>
>>From ce0d739141770f885527a9f1a2db8ff79599ae11 Mon Sep 17 00:00:00 2001
> From: Christer Ekholm <che@chrekh.se>
> Date: Sun, 26 Jun 2016 01:53:42 +0200
> Subject: [PATCH] Fix condition for return from waiting for process output.
>
> * src/process.c (wait_reading_process_output): Move the test for
> process output to outside setting of cmp_time, so that we don't miss
> to exit if we have output, but got_output_end_time is not valid.
> ---
>  src/process.c | 7 ++++---
>  1 file changed, 4 insertions(+), 3 deletions(-)
>
> diff --git a/src/process.c b/src/process.c
> index ed0c529..23e2c52 100644
> --- a/src/process.c
> +++ b/src/process.c
> @@ -5271,12 +5271,13 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
>               timers.  */
>  	  if (wait < TIMEOUT)
>  	    break;
> +	  if (!process_skipped && got_some_output > 0
> +	      && (!timespec_valid_p (got_output_end_time)
> +		  || (timeout.tv_sec > 0 || timeout.tv_nsec > 0)))
> +	    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))
>  	    {
> -- 
> 2.9.0
>
> In GNU Emacs 25.1.50.1 (x86_64-pc-linux-gnu, GTK+ Version 3.20.6)
>  of 2016-06-28 built on jane
> Repository revision: 2adc4ccd03d24660bcf7f8ff056c7f32b92b584d
> Windowing system distributor 'The X.Org Foundation', version 11.0.11803000
> System Description:	Gentoo Base System release 2.2

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Paul Eggert]

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

On 06/30/2016 03:50 AM, Glenn Morris wrote:
> I see this is in emacs-25, so perhaps should be fixed there. 

I agree; it's a regression and the fix is small and localized. Thanks, 
Christer, for debugging and reporting this.

I installed the attached patch into master; it should have the same 
effect as Christer's patch but avoids some code duplication. I can 
backport it into the emacs-25 branch if there is no objection.

Ouch. Now I see that this patch has the wrong bug number (transposed 
digits) and attribution. Sorry about that. I will fix that for the 
backport, if we decide to install it into emacs-25.

[-- Attachment #2: 0001-Fix-open-network-stream-responsiveness.patch --]
[-- Type: text/x-patch, Size: 1771 bytes --]

From 115b407d0816737357cf1923087a2651fcb99867 Mon Sep 17 00:00:00 2001
From: Paul Eggert <eggert@cs.ucla.edu>
Date: Sun, 3 Jul 2016 10:49:21 +0200
Subject: [PATCH] Fix open-network-stream responsiveness

Problem reported by Constantin Kulikov (Bug#23684).
* src/process.c (wait_reading_process_output):
Fix typo introduced in 2015-07-06T02:19:13Z!eggert@cs.ucla.edu
when wait == INFINITY and got_output_end_time is invalid.
In this case the code should break, not continue.
---
 src/process.c | 20 ++++++++++++--------
 1 file changed, 12 insertions(+), 8 deletions(-)

diff --git a/src/process.c b/src/process.c
index ed0c529..376e872 100644
--- a/src/process.c
+++ b/src/process.c
@@ -5269,16 +5269,20 @@ 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 cmp_time;
+	  bool have_cmp_time = false;
 	  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))
+	  else if (wait == TIMEOUT)
+	    cmp_time = end_time, have_cmp_time = true;
+	  else if (!process_skipped && got_some_output > 0
+		   && (timeout.tv_sec > 0 || timeout.tv_nsec > 0))
+	    {
+	      if (!timespec_valid_p (got_output_end_time))
+		break;
+	      cmp_time = got_output_end_time, have_cmp_time = true;
+	    }
+	  if (have_cmp_time)
 	    {
 	      now = current_timespec ();
 	      if (timespec_cmp (cmp_time, now) <= 0)
-- 
2.5.5

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Christer Ekholm]

Paul Eggert writes:
 > On 06/30/2016 03:50 AM, Glenn Morris wrote:
 > > I see this is in emacs-25, so perhaps should be fixed there. 
 > 
 > I agree; it's a regression and the fix is small and localized. Thanks, 
 > Christer, for debugging and reporting this.
 > 
 > I installed the attached patch into master; it should have the same 
 > effect as Christer's patch but avoids some code duplication. I can 
 > backport it into the emacs-25 branch if there is no objection.

I have now tried 1e97ecb, but it didn't help. I observe the same
slowness as without it.

I'll examine further and report back here if I figure something out.

-- 
 Christer

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Eli Zaretskii]

> From: Christer Ekholm <che@chrekh.se>
> Date: Sun, 3 Jul 2016 13:21:09 +0200
> Cc: 23864@debbugs.gnu.org
> 
> Paul Eggert writes:
>  > On 06/30/2016 03:50 AM, Glenn Morris wrote:
>  > > I see this is in emacs-25, so perhaps should be fixed there. 
>  > 
>  > I agree; it's a regression and the fix is small and localized. Thanks, 
>  > Christer, for debugging and reporting this.
>  > 
>  > I installed the attached patch into master; it should have the same 
>  > effect as Christer's patch but avoids some code duplication. I can 
>  > backport it into the emacs-25 branch if there is no objection.
> 
> I have now tried 1e97ecb, but it didn't help. I observe the same
> slowness as without it.

Isn't that strange?  The commit made exactly the change you proposed,
didn't it?

> I'll examine further and report back here if I figure something out.

Thanks.  When we understand what needs to be changed, we will be able
to decide whether it's safe for the release branch.

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Christer Ekholm]

Eli Zaretskii writes:
 > 
 > Isn't that strange?  The commit made exactly the change you proposed,
 > didn't it?

Apparently not. But it was not easy to spot the difference. In my
try the test was added before the "if (WAIT == timeout)".

 > 
 > > I'll examine further and report back here if I figure something out.

I have tested some more now, and a simple change from "else if" to
just "if" does help.

diff --git a/src/process.c b/src/process.c
index 376e872..031967e 100644
--- a/src/process.c
+++ b/src/process.c
@@ -5275,7 +5275,7 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
            break;
          else if (wait == TIMEOUT)
            cmp_time = end_time, have_cmp_time = true;
-         else if (!process_skipped && got_some_output > 0
+         if (!process_skipped && got_some_output > 0
                   && (timeout.tv_sec > 0 || timeout.tv_nsec > 0))
            {
              if (!timespec_valid_p (got_output_end_time))

-- 
 Christer

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Paul Eggert]

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

On 07/03/2016 08:54 PM, Christer Ekholm wrote:
> I have tested some more now, and a simple change from "else if" to
> just "if" does help.
>

Thanks, that fixes part of the remaining bug, but I see another case 
where there's a problem: we need to test the minimum of the two end 
times against "now". I installed the attached further patch into 
'master', which I hope puts this all to rest on 'master'. It is indeed a 
tricky area.

[-- Attachment #2: 0001-Re-fix-open-network-stream-responsiveness.patch --]
[-- Type: text/x-patch, Size: 1943 bytes --]

From 1c046c2158762d01d512957f1fcb4ec4d45028a8 Mon Sep 17 00:00:00 2001
From: Paul Eggert <eggert@cs.ucla.edu>
Date: Mon, 4 Jul 2016 00:46:57 +0200
Subject: [PATCH] Re-fix open-network-stream responsiveness

Problem reported by Christer Ekholm (Bug#23864).
* src/process.c (wait_reading_process_output): Further fix for
typo introduced in 2015-07-06T02:19:13Z!eggert@cs.ucla.edu when
wait == INFINITY and got_output_end_time is invalid.  See:
http://bugs.gnu.org/23864#20
---
 src/process.c | 18 ++++++++++--------
 1 file changed, 10 insertions(+), 8 deletions(-)

diff --git a/src/process.c b/src/process.c
index 376e872..bdbdefa 100644
--- a/src/process.c
+++ b/src/process.c
@@ -5269,20 +5269,22 @@ 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 cmp_time;
-	  bool have_cmp_time = false;
+	  struct timespec huge_timespec
+	    = make_timespec (TYPE_MAXIMUM (time_t), 2 * TIMESPEC_RESOLUTION);
+	  struct timespec cmp_time = huge_timespec;
 	  if (wait < TIMEOUT)
 	    break;
-	  else if (wait == TIMEOUT)
-	    cmp_time = end_time, have_cmp_time = true;
-	  else if (!process_skipped && got_some_output > 0
-		   && (timeout.tv_sec > 0 || timeout.tv_nsec > 0))
+	  if (wait == TIMEOUT)
+	    cmp_time = end_time;
+	  if (!process_skipped && got_some_output > 0
+	      && (timeout.tv_sec > 0 || timeout.tv_nsec > 0))
 	    {
 	      if (!timespec_valid_p (got_output_end_time))
 		break;
-	      cmp_time = got_output_end_time, have_cmp_time = true;
+	      if (timespec_cmp (got_output_end_time, cmp_time) < 0)
+		cmp_time = got_output_end_time;
 	    }
-	  if (have_cmp_time)
+	  if (timespec_cmp (cmp_time, huge_timespec) < 0)
 	    {
 	      now = current_timespec ();
 	      if (timespec_cmp (cmp_time, now) <= 0)
-- 
2.5.5

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Christer Ekholm]

Paul Eggert writes:
 > On 07/03/2016 08:54 PM, Christer Ekholm wrote:
 > > I have tested some more now, and a simple change from "else if" to
 > > just "if" does help.
 > >
 > 
 > Thanks, that fixes part of the remaining bug, but I see another case 
 > where there's a problem: we need to test the minimum of the two end 
 > times against "now". I installed the attached further patch into 
 > 'master', which I hope puts this all to rest on 'master'. It is indeed a 
 > tricky area.

I have tested commit 838f122, and it works for me. Thanks.


-- 
 Christer

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Eli Zaretskii]

> Cc: 23864@debbugs.gnu.org
> From: Paul Eggert <eggert@cs.ucla.edu>
> Date: Mon, 4 Jul 2016 00:51:10 +0200
> 
> Thanks, that fixes part of the remaining bug, but I see another case 
> where there's a problem: we need to test the minimum of the two end 
> times against "now". I installed the attached further patch into 
> 'master', which I hope puts this all to rest on 'master'. It is indeed a 
> tricky area.

Thanks.

Do you consider these changes safe for back-porting to emacs-25?

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Paul Eggert]

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

On 07/04/2016 04:35 PM, Eli Zaretskii wrote:
> Do you consider these changes safe for back-porting to emacs-25?

Yes. Propose patch to emacs-25 attached.

[-- Attachment #2: 0001-Fix-open-network-stream-responsiveness.patch --]
[-- Type: text/x-patch, Size: 1916 bytes --]

From ea23b4519698c9695a851508c3455f36ff94115b Mon Sep 17 00:00:00 2001
From: Paul Eggert <eggert@cs.ucla.edu>
Date: Tue, 5 Jul 2016 20:40:40 +0200
Subject: [PATCH] Fix open-network-stream responsiveness

Problem reported by Christer Ekholm (Bug#23864).
Backport from master.
* src/process.c (wait_reading_process_output):
Fix typo introduced in 2015-07-06T02:19:13Z!eggert@cs.ucla.edu
when wait == INFINITY and got_output_end_time is invalid.
In this case the code should break, not continue.
---
 src/process.c | 22 ++++++++++++++--------
 1 file changed, 14 insertions(+), 8 deletions(-)

diff --git a/src/process.c b/src/process.c
index 14d7b6d..0593429 100644
--- a/src/process.c
+++ b/src/process.c
@@ -4911,16 +4911,22 @@ 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 huge_timespec
+	    = make_timespec (TYPE_MAXIMUM (time_t), 2 * TIMESPEC_RESOLUTION);
+	  struct timespec cmp_time = huge_timespec;
 	  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))
+	  if (wait == TIMEOUT)
+	    cmp_time = end_time;
+	  if (!process_skipped && got_some_output > 0
+	      && (timeout.tv_sec > 0 || timeout.tv_nsec > 0))
+	    {
+	      if (!timespec_valid_p (got_output_end_time))
+		break;
+	      if (timespec_cmp (got_output_end_time, cmp_time) < 0)
+		cmp_time = got_output_end_time;
+	    }
+	  if (timespec_cmp (cmp_time, huge_timespec) < 0)
 	    {
 	      now = current_timespec ();
 	      if (timespec_cmp (cmp_time, now) <= 0)
-- 
2.5.5

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Eli Zaretskii]

> Cc: che@chrekh.se, 23864@debbugs.gnu.org
> From: Paul Eggert <eggert@cs.ucla.edu>
> Date: Tue, 5 Jul 2016 20:43:48 +0200
> 
> On 07/04/2016 04:35 PM, Eli Zaretskii wrote:
> > Do you consider these changes safe for back-porting to emacs-25?
> 
> Yes. Propose patch to emacs-25 attached.

Thanks, please push there.

bug#23864: 25.1.50; Poor network responsivenes using open-network-stream

[Paul Eggert]

On 07/05/2016 09:46 PM, Eli Zaretskii wrote:
> please push there.

Done, and closing the bug report.