bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Dmitry Gutov]

This applies both to master and emacs-24 (with a caveat).

With sufficiently suitable server, calling long-ops-now or long-ops-idle
can lead to the "outer" request never returning:

--8<---------------cut here---------------start------------->8---
(defun long-ops-idle ()
  (interactive)
  (run-with-idle-timer 0.2 nil #'long-outer-op)
  (run-with-idle-timer 0.5 nil #'long-inner-op))

(defun long-ops-now ()
  (interactive)
  (run-with-timer 0.2 nil #'long-inner-op)
  (long-outer-op))

(defun long-outer-op ()
  (message "retrieving outer")
  (url-retrieve-synchronously "http://localhost:9292")
  (message "outer retrieved"))

(defun long-inner-op ()
  (message "retrieving inner")
  (url-retrieve-synchronously "http://localhost:9292")
  (message "inner retrieved"))
--8<---------------cut here---------------end--------------->8---

The window freezes, the last message in the echo area being "inner
retrieved" (but C-g breaks out of it, and if we're calling
`long-ops-idle', the "outer" request succeeds, too).

It doesn't happen with just any web server, though. I can reproduce it
using both master and emacs-24 using this Ruby server:

--8<---------------cut here---------------start------------->8---
run proc { |env|
  sleep 1
  [200, {'Content-Type' => 'text/plain'}, [""]]
}
--8<---------------cut here---------------end--------------->8---

Save it as test.ru and launch with 'rackup test.ru'.

But only with master using this Python server (an example for those who
don't have Ruby installed):

--8<---------------cut here---------------start------------->8---
from wsgiref.util import setup_testing_defaults
from wsgiref.simple_server import make_server
import time

def simple_app(environ, start_response):
    setup_testing_defaults(environ)

    status = '200 OK'
    headers = [('Content-type', 'text/plain')]

    time.sleep(1)

    start_response(status, headers)

    return ""

httpd = make_server('', 9292, simple_app)
print "Serving on port 9292..."
httpd.serve_forever()
--8<---------------cut here---------------end--------------->8---

Save it as server.py, and launch with 'python server.py'.

The key difference seems to be Keep-Alive (enabled by default by WEBrick
(Ruby); wsgiref doesn't support it at all). Adding "Connection: close"
to the Ruby example server makes emacs-24 behave as expected with it.

And someone who doesn't want to run the server can also try the
following URLs with master: http://xip.io/ and http://ya.ru/. When
calling xip.io, the outer request eventually returns, but much later
than expected; when calling ya.ru, it doesn't.

The present bug report is based on this long-standing issue, which I
haven't been able to reliably reproduce until now:
https://github.com/dgutov/robe/issues/36

In GNU Emacs 25.0.50.5 (x86_64-unknown-linux-gnu, GTK+ Version 3.12.2)
 of 2015-02-13 on axl
Repository revision: 69e38a5b1fdb5ac20440b6ce7ba1fc2cd575f4e6
Windowing system distributor `The X.Org Foundation', version 11.0.11601901
System Description:	Ubuntu 14.10

bug#19860: Acknowledgement (25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it)

[Dmitry Gutov]

With debug-on-quit, pressing C-g during the wait yields:

Debugger entered--Lisp error: (quit)
   (condition-case nil (let ((inhibit-quit nil)) (accept-process-output 
proc)) (quit (setq quit-flag t) (eval (quote (ignore nil)))))
   (or (condition-case nil (let ((inhibit-quit nil)) 
(accept-process-output proc)) (quit (setq quit-flag t) (eval (quote 
(ignore nil))))) (null proc))
   (if (or (condition-case nil (let ((inhibit-quit nil)) 
(accept-process-output proc)) (quit (setq quit-flag t) (eval (quote 
(ignore nil))))) (null proc)) nil (if quit-flag (progn (delete-process 
proc))) (setq proc (and (not quit-flag) (get-buffer-process 
asynch-buffer))))
   (if (buffer-local-value (quote url-redirect-buffer) asynch-buffer) 
(setq proc (get-buffer-process (setq asynch-buffer (buffer-local-value 
(quote url-redirect-buffer) asynch-buffer)))) (if (and proc (memq 
(process-status proc) (quote (closed exit signal failed))) (eq proc (or 
(get-buffer-process asynch-buffer) proc))) (progn (delete-process proc) 
(setq retrieval-done t))) (if (or (condition-case nil (let 
((inhibit-quit nil)) (accept-process-output proc)) (quit (setq quit-flag 
t) (eval (quote (ignore nil))))) (null proc)) nil (if quit-flag (progn 
(delete-process proc))) (setq proc (and (not quit-flag) 
(get-buffer-process asynch-buffer)))))
   (while (not retrieval-done) (url-debug (quote retrieval) "Spinning in 
url-retrieve-synchronously: %S (%S)" retrieval-done asynch-buffer) (if 
(buffer-local-value (quote url-redirect-buffer) asynch-buffer) (setq 
proc (get-buffer-process (setq asynch-buffer (buffer-local-value (quote 
url-redirect-buffer) asynch-buffer)))) (if (and proc (memq 
(process-status proc) (quote (closed exit signal failed))) (eq proc (or 
(get-buffer-process asynch-buffer) proc))) (progn (delete-process proc) 
(setq retrieval-done t))) (if (or (condition-case nil (let 
((inhibit-quit nil)) (accept-process-output proc)) (quit (setq quit-flag 
t) (eval (quote ...)))) (null proc)) nil (if quit-flag (progn 
(delete-process proc))) (setq proc (and (not quit-flag) 
(get-buffer-process asynch-buffer))))))
   (let ((proc (get-buffer-process asynch-buffer))) (while (not 
retrieval-done) (url-debug (quote retrieval) "Spinning in 
url-retrieve-synchronously: %S (%S)" retrieval-done asynch-buffer) (if 
(buffer-local-value (quote url-redirect-buffer) asynch-buffer) (setq 
proc (get-buffer-process (setq asynch-buffer (buffer-local-value (quote 
url-redirect-buffer) asynch-buffer)))) (if (and proc (memq 
(process-status proc) (quote (closed exit signal failed))) (eq proc (or 
(get-buffer-process asynch-buffer) proc))) (progn (delete-process proc) 
(setq retrieval-done t))) (if (or (condition-case nil (let (...) 
(accept-process-output proc)) (quit (setq quit-flag t) (eval ...))) 
(null proc)) nil (if quit-flag (progn (delete-process proc))) (setq proc 
(and (not quit-flag) (get-buffer-process asynch-buffer)))))))
   (if (null asynch-buffer) nil (let ((proc (get-buffer-process 
asynch-buffer))) (while (not retrieval-done) (url-debug (quote 
retrieval) "Spinning in url-retrieve-synchronously: %S (%S)" 
retrieval-done asynch-buffer) (if (buffer-local-value (quote 
url-redirect-buffer) asynch-buffer) (setq proc (get-buffer-process (setq 
asynch-buffer (buffer-local-value ... asynch-buffer)))) (if (and proc 
(memq (process-status proc) (quote ...)) (eq proc (or ... proc))) (progn 
(delete-process proc) (setq retrieval-done t))) (if (or (condition-case 
nil (let ... ...) (quit ... ...)) (null proc)) nil (if quit-flag (progn 
(delete-process proc))) (setq proc (and (not quit-flag) 
(get-buffer-process asynch-buffer))))))) asynch-buffer)
   (let ((retrieval-done nil) (asynch-buffer nil)) (setq asynch-buffer 
(url-retrieve url (function (lambda (&rest ignored) (url-debug (quote 
retrieval) "Synchronous fetching done (%S)" (current-buffer)) (setq 
retrieval-done t asynch-buffer (current-buffer)))) nil silent 
inhibit-cookies)) (if (null asynch-buffer) nil (let ((proc 
(get-buffer-process asynch-buffer))) (while (not retrieval-done) 
(url-debug (quote retrieval) "Spinning in url-retrieve-synchronously: %S 
(%S)" retrieval-done asynch-buffer) (if (buffer-local-value (quote 
url-redirect-buffer) asynch-buffer) (setq proc (get-buffer-process (setq 
asynch-buffer ...))) (if (and proc (memq ... ...) (eq proc ...)) (progn 
(delete-process proc) (setq retrieval-done t))) (if (or (condition-case 
nil ... ...) (null proc)) nil (if quit-flag (progn ...)) (setq proc (and 
... ...)))))) asynch-buffer))
   url-retrieve-synchronously("http://xip.io")
   long-outer-op()
   long-ops-now()

bug#19860: Acknowledgement (25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it)

[Dmitry Gutov]

And here's me attaching to that process:

0x00007fae43df32d9 in __pselect (nfds=nfds@entry=14, 
readfds=readfds@entry=0x7fffa07d4370, writefds=0x7fffa07d43f0, 
exceptfds=exceptfds@entry=0x0, timeout=<optimized out>, 
timeout@entry=0x7fffa07d4920,
     sigmask=sigmask@entry=0x0) at ../sysdeps/unix/sysv/linux/pselect.c:77
77	../sysdeps/unix/sysv/linux/pselect.c: No such file or directory.
(gdb) finish
Run till exit from #0  0x00007fae43df32d9 in __pselect 
(nfds=nfds@entry=14, readfds=readfds@entry=0x7fffa07d4370, 
writefds=0x7fffa07d43f0, exceptfds=exceptfds@entry=0x0, 
timeout=<optimized out>,
     timeout@entry=0x7fffa07d4920, sigmask=sigmask@entry=0x0) at 
../sysdeps/unix/sysv/linux/pselect.c:77
0x00000000005b464a in xg_select (fds_lim=14, 
rfds=rfds@entry=0x7fffa07d4940, wfds=0x7fffa07d49c0, 
efds=efds@entry=0x0, timeout=timeout@entry=0x7fffa07d4920, 
sigmask=sigmask@entry=0x0) at xgselect.c:114
114	  nfds = pselect (fds_lim, &all_rfds, have_wfds ? &all_wfds : NULL,
Value returned is $1 = 1
(gdb) finish
Run till exit from #0  0x00000000005b464a in xg_select (fds_lim=14, 
rfds=rfds@entry=0x7fffa07d4940, wfds=0x7fffa07d49c0, 
efds=efds@entry=0x0, timeout=timeout@entry=0x7fffa07d4920,
     sigmask=sigmask@entry=0x0) at xgselect.c:114
0x00000000005836e1 in wait_reading_process_output (time_limit=<optimized 
out>, nsecs=0, read_kbd=read_kbd@entry=0, 
do_display=do_display@entry=false, wait_for_cell=wait_for_cell@entry=0,
     wait_proc=0x351a938, just_wait_proc=0) at process.c:4597
4597		  nfds = xg_select
Value returned is $2 = -1
(gdb) finish
Run till exit from #0  0x00000000005836e1 in wait_reading_process_output 
(time_limit=<optimized out>, nsecs=0, read_kbd=read_kbd@entry=0, 
do_display=do_display@entry=false,
     wait_for_cell=wait_for_cell@entry=0, wait_proc=0x351a938, 
just_wait_proc=0) at process.c:4597

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Glenn Morris]

You've marked this as blocking the 24.5 release.
Could you say why? Is it a new issue in 24.4?

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Dmitry Gutov]

On 02/17/2015 09:20 PM, Glenn Morris wrote:
>
> You've marked this as blocking the 24.5 release.
> Could you say why? Is it a new issue in 24.4?

No, sorry, it's not. Unblocking. I didn't know, at the time, that 24.5 
will be so soon.

This bug is quite annoying, though, especially on master, where it 
manifests in real-life usage.

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Dmitry Gutov]

On 02/14/2015 02:09 AM, Dmitry Gutov wrote:

> The key difference seems to be Keep-Alive (enabled by default by WEBrick
> (Ruby); wsgiref doesn't support it at all). Adding "Connection: close"
> to the Ruby example server makes emacs-24 behave as expected with it.

Like mentioned, when using http://ya.ru/ as the request URL, emacs-24 
doesn't freeze. Fixing that case in master should be a step forward.

'git bisect' points to 12dc5429352223f7ba8314d2e16177036a762733.

Paul, could you look into this?

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Paul Eggert]

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

Dmitry Gutov wrote:

> 'git bisect' points to 12dc5429352223f7ba8314d2e16177036a762733.
>
> Paul, could you look into this?

Thanks for doing all that legwork.  It let me reproduce the problem and come up 
with a simple fix that works for me.  I installed the attached patch.


[-- Attachment #2: 0001-Don-t-freeze-with-unreadable-processes.patch --]
[-- Type: text/x-patch, Size: 2351 bytes --]

From 9ca712e2689f1875d7facd229f2cb1916719cf49 Mon Sep 17 00:00:00 2001
From: Paul Eggert <eggert@cs.ucla.edu>
Date: Sat, 25 Apr 2015 16:16:58 -0700
Subject: [PATCH] Don't freeze with unreadable processes

Don't freeze if an exiting process can't be read from. (Bug#19860).
This fixes a bug I introduced in
2014-07-08T07:24:07Z@eggert@cs.ucla.edu
"* process.c: Add sanity checks for file descriptors."
Dmitry Gutov did most of the legwork in finding the problem.
* src/process.c (wait_reading_process_output):
Treat non-running processes that can't be read from
the same as other non-running processes.
---
 src/process.c | 40 ++++++++++++++++++++++------------------
 1 file changed, 22 insertions(+), 18 deletions(-)

diff --git a/src/process.c b/src/process.c
index c745507..3e04cb7 100644
--- a/src/process.c
+++ b/src/process.c
@@ -4785,37 +4785,41 @@ wait_reading_process_output (intmax_t time_limit, int nsecs, int read_kbd,
       if (wait_proc && wait_proc->raw_status_new)
 	update_status (wait_proc);
       if (wait_proc
-	  && wait_proc->infd >= 0
 	  && ! EQ (wait_proc->status, Qrun)
 	  && ! EQ (wait_proc->status, Qconnect))
 	{
 	  bool read_some_bytes = false;
 
 	  clear_waiting_for_input ();
-	  XSETPROCESS (proc, wait_proc);
 
-	  /* Read data from the process, until we exhaust it.  */
-	  while (true)
+	  /* If data can be read from the process, do so until exhausted.  */
+	  if (wait_proc->infd >= 0)
 	    {
-	      int nread = read_process_output (proc, wait_proc->infd);
-	      if (nread < 0)
+	      XSETPROCESS (proc, wait_proc);
+
+	      while (true)
 		{
-		  if (errno == EIO || errno == EAGAIN)
-		    break;
+		  int nread = read_process_output (proc, wait_proc->infd);
+		  if (nread < 0)
+		    {
+		    if (errno == EIO || errno == EAGAIN)
+		      break;
 #ifdef EWOULDBLOCK
-		  if (errno == EWOULDBLOCK)
-		    break;
+		    if (errno == EWOULDBLOCK)
+		      break;
 #endif
-		}
-	      else
-		{
-		  if (got_some_input < nread)
-		    got_some_input = nread;
-		  if (nread == 0)
-		    break;
-		  read_some_bytes = true;
+		    }
+		  else
+		    {
+		      if (got_some_input < nread)
+			got_some_input = nread;
+		      if (nread == 0)
+			break;
+		      read_some_bytes = true;
+		    }
 		}
 	    }
+
 	  if (read_some_bytes && do_display)
 	    redisplay_preserve_echo_area (10);
 
-- 
2.1.4

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Dmitry Gutov]

On 04/26/2015 02:19 AM, Paul Eggert wrote:

> Thanks for doing all that legwork.  It let me reproduce the problem and
> come up with a simple fix that works for me.  I installed the attached
> patch.

Thank you for fixing the regression, that should help with the project 
it manifested in.

However, in certain conditions the bug still reproduces, both in 
emacs-24 and master, as described in the original report (basically, 
using the 4-line server written in Ruby, which sends "Connection: 
Keep-Alive" at the end).

Please let me know if you're having problems reproducing it locally.

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Dmitry Gutov]

On 04/26/2015 07:24 AM, Dmitry Gutov wrote:

> (basically,
> using the 4-line server written in Ruby, which sends "Connection:
> Keep-Alive" at the end).

And inded, (setq url-http-attempt-keepalives nil) makes the problem go away.

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Paul Eggert]

Dmitry Gutov wrote:
> However, in certain conditions the bug still reproduces

OK, but in that case I don't see the relevance of commit 
12dc5429352223f7ba8314d2e16177036a762733.  I get similar symptoms when I run 
Emacs 24.3, which predates that commit.

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Eli Zaretskii]

> Date: Sun, 26 Apr 2015 07:24:50 +0300
> From: Dmitry Gutov <dgutov@yandex.ru>
> 
> On 04/26/2015 02:19 AM, Paul Eggert wrote:
> 
> > Thanks for doing all that legwork.  It let me reproduce the problem and
> > come up with a simple fix that works for me.  I installed the attached
> > patch.
> 
> Thank you for fixing the regression, that should help with the project 
> it manifested in.

It looks like this also fixed bug#20207 and #19729, so I think we can
close them.  Dmitry, can you verify that they are solved for you as
well?

Thanks, Paul.

bug#19729: bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Dmitry Gutov]

On 04/26/2015 06:01 PM, Eli Zaretskii wrote:

> It looks like this also fixed bug#20207 and #19729, so I think we can
> close them.  Dmitry, can you verify that they are solved for you as
> well?

Indeed, they are. Thanks for the reminder.

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Dmitry Gutov]

On 04/26/2015 08:11 AM, Paul Eggert wrote:

> OK, but in that case I don't see the relevance of commit
> 12dc5429352223f7ba8314d2e16177036a762733.  I get similar symptoms when I
> run Emacs 24.3, which predates that commit.

Fixing the regression was useful by itself, but whether the nearby code 
is relevant for the remaining problem, I'm indeed not sure.

Do you think the Lisp code is at fault there?

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Paul Eggert]

Dmitry Gutov wrote:
> Do you think the Lisp code is at fault there?

Sorry, I don't know.  I did not look at the Lisp code.

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Lars Ingebrigtsen]

Dmitry Gutov <dgutov@yandex.ru> writes:

> This applies both to master and emacs-24 (with a caveat).
>
> With sufficiently suitable server, calling long-ops-now or long-ops-idle
> can lead to the "outer" request never returning:
>
> (defun long-ops-idle ()
>   (interactive)
>   (run-with-idle-timer 0.2 nil #'long-outer-op)
>   (run-with-idle-timer 0.5 nil #'long-inner-op))
>
> (defun long-ops-now ()
>   (interactive)
>   (run-with-timer 0.2 nil #'long-inner-op)
>   (long-outer-op))
>
> (defun long-outer-op ()
>   (message "retrieving outer")
>   (url-retrieve-synchronously "http://localhost:9292")
>   (message "outer retrieved"))
>
> (defun long-inner-op ()
>   (message "retrieving inner")
>   (url-retrieve-synchronously "http://localhost:9292")
>   (message "inner retrieved"))
>
> The window freezes, the last message in the echo area being "inner
> retrieved" (but C-g breaks out of it, and if we're calling
> `long-ops-idle', the "outer" request succeeds, too).

It's unclear from the bug thread whether this is still a problem or
not...  Are you still seeing this?

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

bug#19860: 25.0.50; One url-retrieve-synchronously call running concurrently with another can freeze it

[Dmitry Gutov]

On 12/25/2015 08:34 PM, Lars Ingebrigtsen wrote:
> Are you still seeing this?

I still do, pretty much like the original report describes.

I haven't tried the Python-based server just now, but nothing seems to 
have changed with the Ruby one (as implemented in the first comment), 
and if I change the URL to point to ya.ru or xip.io, the call eventually 
returns, but much later than one would expect.