bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Christopher Wellons]

Emacs 24.4.1 on x86_64 Linux, the callback passed to `url-retrieve' is
invoked twice if `kill-buffer' is called within the callback when the
status reports a connection failure. In the example below, it's assumed
this URL will reject the connection, which will cause `url-retrieve' to
asynchronously invoke the callback with an error status ("failed with
code 111\n"). The second invocation of the callback is synchronous with
the first invocation, because it's called recursively from within the
`kill-buffer' call. The error message the second time is "deleted\n".

    ;;; -*- lexical-binding: t; -*-
    (let ((calls 0))
      (url-retrieve "http://localhost:1/"
                    (lambda (_)
                      (assert (= 1 (cl-incf calls)))
                      (kill-buffer))))

When I eval the above expression, the assertion fails asynchronously.

    error in process sentinel: Assertion failed: (= 1 (cl-incf calls))

I expect the callback given to `url-retrieve' to never be invoked more
than once each time it's passed to `url-retrieve'. Ideally I expect it
to be called exactly once for each call to `url-retrieve', always
delivering errors asynchronously.

I also tested this on a Windows build of Emacs. The callback is invoked
zero times because the connection error is delivered synchronously at
the call to `url-retrieve' (which I now realize explains why connection
queuing doesn't work right on Windows). So even if the double-invoke
problem is fixed for Linux, the behavior still differs across platforms.

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Eli Zaretskii]

> From: Christopher Wellons <wellons@nullprogram.com>
> Date: Sat, 21 Mar 2015 16:46:16 -0400
> 
> 
>     ;;; -*- lexical-binding: t; -*-
>     (let ((calls 0))
>       (url-retrieve "http://localhost:1/"
>                     (lambda (_)
>                       (assert (= 1 (cl-incf calls)))
>                       (kill-buffer))))
> 
> When I eval the above expression, the assertion fails asynchronously.
> 
>     error in process sentinel: Assertion failed: (= 1 (cl-incf calls))
> 
> I expect the callback given to `url-retrieve' to never be invoked more
> than once each time it's passed to `url-retrieve'. Ideally I expect it
> to be called exactly once for each call to `url-retrieve', always
> delivering errors asynchronously.
> 
> I also tested this on a Windows build of Emacs. The callback is invoked
> zero times because the connection error is delivered synchronously at
> the call to `url-retrieve' (which I now realize explains why connection
> queuing doesn't work right on Windows). So even if the double-invoke
> problem is fixed for Linux, the behavior still differs across platforms.

I don't understand what you mean by "error is delivered synchronously
at the call", and by "connection queuing doesn't work right".  Please
consider elaborating on those 2 points.

Thanks.

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Christopher Wellons]

>> I also tested this on a Windows build of Emacs. The callback is invoked
>> zero times because the connection error is delivered synchronously at
>> the call to `url-retrieve' (which I now realize explains why connection
>> queuing doesn't work right on Windows). So even if the double-invoke
>> problem is fixed for Linux, the behavior still differs across platforms.
>
> I don't understand what you mean by "error is delivered synchronously
> at the call", and by "connection queuing doesn't work right".  Please
> consider elaborating on those 2 points.

On Windows, url-retrieve doesn't return until the connection is either
established or fails, making the call mostly synchronous. If the remote
server takes 20 seconds to SYNACK, Emacs will lock up for 20 seconds
(and C-g doesn't work either!). For example, currently the server at
example.com doesn't seem to respond to anything, so try evaluating the
following on Windows. For me, Emacs freezes for 21 seconds, until timing
out, and the callback is never invoked.

    (url-retrieve "http://example.com:1/" (lambda (_)))

On Linux it returns immediately and about a minute later the callback is
invoked with an error status, timing out. I could call this 100 times in
a loop without locking up Emacs. On Windows 7 on my computer, this locks
up Emacs for half an hour, though hitting C-g will stop it within 21
seconds (between loop iterations):

    ;; Try it if you dare!
    (dotimes (_ 100)
      (ignore-errors
        (url-retrieve "http://example.com:1/" (lambda (_)))))

Since it's synchronous on Windows, the error can be reported directly to
the caller, which is what it does. The downside is awful performance and
inconsistent error reporting (sometimes synchronously to the caller,
sometimes asynchronously using the callback).

I maintain the Elfeed RSS/Atom reader. I've noticed over the past 1.5
years that its performance on Windows is very poor compared to Linux.
It's bad enough that I've disabled parallel fetching of feeds on
Windows. I see now that it's probably because url-retrieve isn't fully
synchronous there. If I call url-retrieve four times in a row to fire
off four connections, the TCP connections themselves will be performed
serially between calls and not in parallel, as it is on Linux, so
there's no point to doing so. They don't queue properly.

I hope that explains it well enough!

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Eli Zaretskii]

> From: Christopher Wellons <wellons@nullprogram.com>
> Cc: 20159@debbugs.gnu.org
> Date: Sat, 21 Mar 2015 17:48:05 -0400
> 
> On Windows, url-retrieve doesn't return until the connection is either
> established or fails, making the call mostly synchronous. If the remote
> server takes 20 seconds to SYNACK, Emacs will lock up for 20 seconds
> (and C-g doesn't work either!). For example, currently the server at
> example.com doesn't seem to respond to anything, so try evaluating the
> following on Windows. For me, Emacs freezes for 21 seconds, until timing
> out, and the callback is never invoked.
> 
>     (url-retrieve "http://example.com:1/"; (lambda (_)))
> 
> On Linux it returns immediately and about a minute later the callback is
> invoked with an error status, timing out. I could call this 100 times in
> a loop without locking up Emacs. On Windows 7 on my computer, this locks
> up Emacs for half an hour, though hitting C-g will stop it within 21
> seconds (between loop iterations):
> 
>     ;; Try it if you dare!
>     (dotimes (_ 100)
>       (ignore-errors
>         (url-retrieve "http://example.com:1/"; (lambda (_)))))

Thanks for the example.

Due to some subtle technical issues with the 'select' emulation, the
':nowait' subfeature is turned off on Windows since more than 8 years
ago.  The result is that the 'connect' call is blocking, and I believe
this is what you see.

Volunteers are welcome to add support for non-blocking connections;
see these messages for the starting point:

  http://lists.gnu.org/archive/html/emacs-devel/2005-11/msg01586.html
  http://lists.gnu.org/archive/html/emacs-devel/2006-12/msg00873.html

However, the URL retrieval once the connection is established
generally works the same as on GNU/Linux: 'select' notifies the main
loop when some stuff is available for reading, and Emacs then reads
from every connection that has stuff ready.  The 'select' emulation
uses separate threads for each connection, so there's no serialization
there.  Therefore, if you see performance issues after the connection
is established, they are most probably due to other factor(s).

> Since it's synchronous on Windows, the error can be reported directly to
> the caller, which is what it does. The downside is awful performance and
> inconsistent error reporting (sometimes synchronously to the caller,
> sometimes asynchronously using the callback).

Errors for connection part are indeed reported directly.  As for
performance issues, see above: I see no direct relation between these
two, but maybe I'm missing something.

> I maintain the Elfeed RSS/Atom reader. I've noticed over the past 1.5
> years that its performance on Windows is very poor compared to Linux.
> It's bad enough that I've disabled parallel fetching of feeds on
> Windows. I see now that it's probably because url-retrieve isn't fully
> synchronous there. If I call url-retrieve four times in a row to fire
> off four connections, the TCP connections themselves will be performed
> serially between calls and not in parallel, as it is on Linux, so
> there's no point to doing so. They don't queue properly.

Again, this is true for the connection establishing part, but
shouldn't be so for the subsequent retrieval.

Thanks.

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Eli Zaretskii]

> Date: Sun, 22 Mar 2015 19:31:48 +0200
> From: Eli Zaretskii <eliz@gnu.org>
> Cc: 20159@debbugs.gnu.org
> 
> Due to some subtle technical issues with the 'select' emulation, the
> ':nowait' subfeature is turned off on Windows since more than 8 years
> ago.  The result is that the 'connect' call is blocking, and I believe
> this is what you see.
> 
> Volunteers are welcome to add support for non-blocking connections;
> see these messages for the starting point:
> 
>   http://lists.gnu.org/archive/html/emacs-devel/2005-11/msg01586.html
>   http://lists.gnu.org/archive/html/emacs-devel/2006-12/msg00873.html

No one volunteered, so I did it myself, see commit d133cf8 on master.

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Andy Moreton]

On Fri 27 Mar 2015, Eli Zaretskii wrote:

>> Date: Sun, 22 Mar 2015 19:31:48 +0200
>> From: Eli Zaretskii <eliz@gnu.org>
>> Cc: 20159@debbugs.gnu.org
>> 
>> Due to some subtle technical issues with the 'select' emulation, the
>> ':nowait' subfeature is turned off on Windows since more than 8 years
>> ago.  The result is that the 'connect' call is blocking, and I believe
>> this is what you see.
>> 
>> Volunteers are welcome to add support for non-blocking connections;
>> see these messages for the starting point:
>> 
>>   http://lists.gnu.org/archive/html/emacs-devel/2005-11/msg01586.html
>>   http://lists.gnu.org/archive/html/emacs-devel/2006-12/msg00873.html
>
> No one volunteered, so I did it myself, see commit d133cf8 on master.

This change broke gnus for me on a mingw64 x64 build of emacs, as gnutls
seems unable to connect to the NNTP server at gmane.org.

I will report more details when I have time to investigate this further
with gdb.

    AndyM

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Eli Zaretskii]

> From: Andy Moreton <andrewjmoreton@gmail.com>
> Date: Fri, 27 Mar 2015 16:59:39 +0000
> 
> > No one volunteered, so I did it myself, see commit d133cf8 on master.
> 
> This change broke gnus for me on a mingw64 x64 build of emacs, as gnutls
> seems unable to connect to the NNTP server at gmane.org.

Sorry about that.  Does Gnus do something windows-specific for
connecting?  Perhaps that specific treatment relied on something that
is no longer true on Windows.

> I will report more details when I have time to investigate this further
> with gdb.

Thanks.  If you cannot figure it out, a recipe from "emacs -Q" will
help.  Bonus points if you can reproduce the problem with just a TLS
connection that doesn't need Gnus.

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Eli Zaretskii]

> Date: Fri, 27 Mar 2015 22:22:31 +0300
> From: Eli Zaretskii <eliz@gnu.org>
> Cc: 20159@debbugs.gnu.org
> 
> > From: Andy Moreton <andrewjmoreton@gmail.com>
> > Date: Fri, 27 Mar 2015 16:59:39 +0000
> > 
> > > No one volunteered, so I did it myself, see commit d133cf8 on master.
> > 
> > This change broke gnus for me on a mingw64 x64 build of emacs, as gnutls
> > seems unable to connect to the NNTP server at gmane.org.
> 
> Sorry about that.  Does Gnus do something windows-specific for
> connecting?  Perhaps that specific treatment relied on something that
> is no longer true on Windows.

Another, perhaps more probable culprit is the emacs_gnutls_pull
function.  It calls sys_read, where I made some changes to support the
non-blocking connect.  Perhaps emacs_gnutls_pull cannot cope with some
results of those changes, and itself needs to be amended.

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Eli Zaretskii]

> Date: Fri, 27 Mar 2015 22:40:19 +0300
> From: Eli Zaretskii <eliz@gnu.org>
> Cc: 20159@debbugs.gnu.org
> 
> > > This change broke gnus for me on a mingw64 x64 build of emacs, as gnutls
> > > seems unable to connect to the NNTP server at gmane.org.
> > 
> > Sorry about that.  Does Gnus do something windows-specific for
> > connecting?  Perhaps that specific treatment relied on something that
> > is no longer true on Windows.
> 
> Another, perhaps more probable culprit is the emacs_gnutls_pull
> function.  It calls sys_read, where I made some changes to support the
> non-blocking connect.  Perhaps emacs_gnutls_pull cannot cope with some
> results of those changes, and itself needs to be amended.

I found and fixed a stupid mistake in sys_connect that broke blocking
connects.  Before I fixed it, "M-x eww" wouldn't work; now it does,
including with HTTPS URLs that require GnuTLS.  Please see if this
also fixes your problem with Gnus and GnuTLS connections to NNTP
servers.

Sorry.

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Andy Moreton]

On Sat 28 Mar 2015, Eli Zaretskii wrote:

>> Date: Fri, 27 Mar 2015 22:40:19 +0300
>> From: Eli Zaretskii <eliz@gnu.org>
>> Cc: 20159@debbugs.gnu.org
>> 
>> > > This change broke gnus for me on a mingw64 x64 build of emacs, as gnutls
>> > > seems unable to connect to the NNTP server at gmane.org.
>> > 
>> > Sorry about that.  Does Gnus do something windows-specific for
>> > connecting?  Perhaps that specific treatment relied on something that
>> > is no longer true on Windows.
>> 
>> Another, perhaps more probable culprit is the emacs_gnutls_pull
>> function.  It calls sys_read, where I made some changes to support the
>> non-blocking connect.  Perhaps emacs_gnutls_pull cannot cope with some
>> results of those changes, and itself needs to be amended.
>
> I found and fixed a stupid mistake in sys_connect that broke blocking
> connects.  Before I fixed it, "M-x eww" wouldn't work; now it does,
> including with HTTPS URLs that require GnuTLS.  Please see if this
> also fixes your problem with Gnus and GnuTLS connections to NNTP
> servers.

Thanks Eli, gnus is working again for me.

    AndyM

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Eli Zaretskii]

> From: Andy Moreton <andrewjmoreton@gmail.com>
> Date: Sat, 28 Mar 2015 10:56:10 +0000
> 
> > I found and fixed a stupid mistake in sys_connect that broke blocking
> > connects.  Before I fixed it, "M-x eww" wouldn't work; now it does,
> > including with HTTPS URLs that require GnuTLS.  Please see if this
> > also fixes your problem with Gnus and GnuTLS connections to NNTP
> > servers.
> 
> Thanks Eli, gnus is working again for me.

Great, thanks for testing.

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Lars Ingebrigtsen]

Christopher Wellons <wellons@nullprogram.com> writes:

>     ;;; -*- lexical-binding: t; -*-
>     (let ((calls 0))
>       (url-retrieve "http://localhost:1/"
>                     (lambda (_)
>                       (assert (= 1 (cl-incf calls)))
>                       (kill-buffer))))
>
> When I eval the above expression, the assertion fails asynchronously.
>
>     error in process sentinel: Assertion failed: (= 1 (cl-incf calls))

Eli fixed something related to this, but the bug still remains.  I used
this version:

;;; -*- lexical-binding: t; -*-
(let ((calls 0))
  (url-retrieve "http://localhost:1/"
                (lambda (status)
		  (message "%s '%s'" calls status)
                  (assert (= 1 (cl-incf calls)))
		  (kill-buffer))))

These are the messages:

Contacting host: localhost:1
#<buffer  *http localhost:1*-537967>
0 ’(:error (error connection-failed failed with code 111
 :host localhost :service 1))’
1 ’(:error (error connection-failed deleted
 :host localhost :service 1) :error (error connection-failed failed with code 111
 :host localhost :service 1))’

The second message is...  pretty weird...

Anybody have a guess why this happens?

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

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Lars Ingebrigtsen]

Lars Ingebrigtsen <larsi@gnus.org> writes:

> Eli fixed something related to this, but the bug still remains.  I used
> this version:
>
> ;;; -*- lexical-binding: t; -*-
> (let ((calls 0))
>   (url-retrieve "http://localhost:1/"
>                 (lambda (status)
> 		  (message "%s '%s'" calls status)
>                   (assert (= 1 (cl-incf calls)))
> 		  (kill-buffer))))
>
> These are the messages:
>
> Contacting host: localhost:1
> #<buffer  *http localhost:1*-537967>
> 0 ’(:error (error connection-failed failed with code 111
>  :host localhost :service 1))’
> 1 ’(:error (error connection-failed deleted
>  :host localhost :service 1) :error (error connection-failed failed with code 111
>  :host localhost :service 1))’
>
> The second message is...  pretty weird...
>
> Anybody have a guess why this happens?

I've done some further debugging, and what's happening is (simply, ahem)
that when we get a "connection failed" message from the sentinel, and
then kill the buffer, we also kill the process, and then the sentinel is
called again, and then it calls our callback again.

So the weird thing is that the process isn't already dead, kinda...  Or
something...

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

bug#20159: 24.4; url-retrieve invokes same callback twice with kill-buffer

[Lars Ingebrigtsen]

The two statuses are these:

Process status failed
Process status closed

But I kinda think that url.el is behaving as specified.  The callbacks
may be called many times, and you're supposed to check the status.  And
if you're killing the same buffer twice, this is pilot error.

So I don't think there's really a bug here.

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