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

Previous Next

To reply to this bug, email your comments to 19860 AT debbugs.gnu.org.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Dmitry Gutov <dgutov <at> yandex.ru>
To: bug-gnu-emacs <at> gnu.org
Subject: 25.0.50;
 One url-retrieve-synchronously call running concurrently with another
 can freeze it
Date: Sat, 14 Feb 2015 02:09:57 +0200

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

Message #10 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Dmitry Gutov <dgutov <at> yandex.ru>
To: 19860 <at> debbugs.gnu.org
Subject: Re: bug#19860: Acknowledgement (25.0.50; One
 url-retrieve-synchronously call running concurrently with another can
 freeze it)
Date: Mon, 16 Feb 2015 00:19:23 +0200

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()

Message #13 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Dmitry Gutov <dgutov <at> yandex.ru>
To: 19860 <at> debbugs.gnu.org
Subject: Re: bug#19860: Acknowledgement (25.0.50; One
 url-retrieve-synchronously call running concurrently with another can
 freeze it)
Date: Mon, 16 Feb 2015 03:00:24 +0200

And here's me attaching to that process:

0x00007fae43df32d9 in __pselect (nfds=nfds <at> entry=14, 
readfds=readfds <at> entry=0x7fffa07d4370, writefds=0x7fffa07d43f0, 
exceptfds=exceptfds <at> entry=0x0, timeout=<optimized out>, 
timeout <at> entry=0x7fffa07d4920,
    sigmask=sigmask <at> 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 <at> entry=14, readfds=readfds <at> entry=0x7fffa07d4370, 
writefds=0x7fffa07d43f0, exceptfds=exceptfds <at> entry=0x0, 
timeout=<optimized out>,
    timeout <at> entry=0x7fffa07d4920, sigmask=sigmask <at> entry=0x0) at 
../sysdeps/unix/sysv/linux/pselect.c:77
0x00000000005b464a in xg_select (fds_lim=14, 
rfds=rfds <at> entry=0x7fffa07d4940, wfds=0x7fffa07d49c0, 
efds=efds <at> entry=0x0, timeout=timeout <at> entry=0x7fffa07d4920, 
sigmask=sigmask <at> 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 <at> entry=0x7fffa07d4940, wfds=0x7fffa07d49c0, 
efds=efds <at> entry=0x0, timeout=timeout <at> entry=0x7fffa07d4920,
    sigmask=sigmask <at> entry=0x0) at xgselect.c:114
0x00000000005836e1 in wait_reading_process_output (time_limit=<optimized 
out>, nsecs=0, read_kbd=read_kbd <at> entry=0, 
do_display=do_display <at> entry=false, wait_for_cell=wait_for_cell <at> 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 <at> entry=0, 
do_display=do_display <at> entry=false,
    wait_for_cell=wait_for_cell <at> entry=0, wait_proc=0x351a938, 
just_wait_proc=0) at process.c:4597

Message #16 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Glenn Morris <rgm <at> gnu.org>
To: Dmitry Gutov <dgutov <at> yandex.ru>
Cc: 19860 <at> debbugs.gnu.org
Subject: Re: bug#19860: 25.0.50;
 One url-retrieve-synchronously call running concurrently with another
 can freeze it
Date: Tue, 17 Feb 2015 14:20:48 -0500

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

Message #19 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Dmitry Gutov <dgutov <at> yandex.ru>
To: Glenn Morris <rgm <at> gnu.org>
Cc: 19860 <at> debbugs.gnu.org
Subject: Re: bug#19860: 25.0.50; One url-retrieve-synchronously call
 running concurrently with another can freeze it
Date: Wed, 18 Feb 2015 01:24:54 +0200

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.

Message #24 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Dmitry Gutov <dgutov <at> yandex.ru>
To: 19860 <at> debbugs.gnu.org
Cc: Paul Eggert <eggert <at> cs.ucla.edu>
Subject: Re: bug#19860: 25.0.50; One url-retrieve-synchronously call
 running concurrently with another can freeze it
Date: Fri, 24 Apr 2015 15:18:17 +0300

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?

Message #29 received at 19860-done <at> debbugs.gnu.org (full text, mbox):

From: Paul Eggert <eggert <at> cs.ucla.edu>
To: Dmitry Gutov <dgutov <at> yandex.ru>, 19860-done <at> debbugs.gnu.org
Subject: Re: bug#19860: 25.0.50; One url-retrieve-synchronously call running
 concurrently with another can freeze it
Date: Sat, 25 Apr 2015 16:19:52 -0700

[Message part 1 (text/plain, inline)]

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.

[0001-Don-t-freeze-with-unreadable-processes.patch (text/x-patch, attachment)]

Message #34 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Dmitry Gutov <dgutov <at> yandex.ru>
To: 19860 <at> debbugs.gnu.org, eggert <at> cs.ucla.edu
Subject: Re: bug#19860: 25.0.50; One url-retrieve-synchronously call
 running concurrently with another can freeze it
Date: Sun, 26 Apr 2015 07:24:50 +0300

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.

Message #37 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Dmitry Gutov <dgutov <at> yandex.ru>
To: 19860 <at> debbugs.gnu.org, eggert <at> cs.ucla.edu
Subject: Re: bug#19860: 25.0.50; One url-retrieve-synchronously call
 running concurrently with another can freeze it
Date: Sun, 26 Apr 2015 07:30:01 +0300

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.

Message #40 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Paul Eggert <eggert <at> cs.ucla.edu>
To: Dmitry Gutov <dgutov <at> yandex.ru>, 19860 <at> debbugs.gnu.org
Subject: Re: bug#19860: 25.0.50; One url-retrieve-synchronously call running
 concurrently with another can freeze it
Date: Sat, 25 Apr 2015 22:11:05 -0700

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.

Message #43 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Dmitry Gutov <dgutov <at> yandex.ru>
Cc: 19860 <at> debbugs.gnu.org, eggert <at> cs.ucla.edu
Subject: Re: bug#19860: 25.0.50;
 One url-retrieve-synchronously call running concurrently with
 another	can freeze it
Date: Sun, 26 Apr 2015 18:01:49 +0300

> Date: Sun, 26 Apr 2015 07:24:50 +0300
> From: Dmitry Gutov <dgutov <at> 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.

Message #46 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Dmitry Gutov <dgutov <at> yandex.ru>
To: Paul Eggert <eggert <at> cs.ucla.edu>, 19860 <at> debbugs.gnu.org
Subject: Re: bug#19860: 25.0.50; One url-retrieve-synchronously call
 running concurrently with another can freeze it
Date: Sun, 26 Apr 2015 18:28:28 +0300

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?

Message #49 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Paul Eggert <eggert <at> cs.ucla.edu>
To: Dmitry Gutov <dgutov <at> yandex.ru>, 19860 <at> debbugs.gnu.org
Subject: Re: bug#19860: 25.0.50; One url-retrieve-synchronously call running
 concurrently with another can freeze it
Date: Sun, 26 Apr 2015 14:47:34 -0700

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.

Message #52 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: Dmitry Gutov <dgutov <at> yandex.ru>
Cc: 19860 <at> debbugs.gnu.org
Subject: Re: bug#19860: 25.0.50;
 One url-retrieve-synchronously call running concurrently with another
 can freeze it
Date: Fri, 25 Dec 2015 19:34:09 +0100

Dmitry Gutov <dgutov <at> 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

Message #55 received at 19860 <at> debbugs.gnu.org (full text, mbox):

From: Dmitry Gutov <dgutov <at> yandex.ru>
To: Lars Ingebrigtsen <larsi <at> gnus.org>
Cc: 19860 <at> debbugs.gnu.org
Subject: Re: bug#19860: 25.0.50; One url-retrieve-synchronously call running
 concurrently with another can freeze it
Date: Fri, 25 Dec 2015 22:08:14 +0200

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.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.