gnutls error handling

gnutls error handling

[Lars Magne Ingebrigtsen]

I've been using the built-in gnutls stuff exclusively for all the tls
connections for a while now, and it seems to work fine, except for
certain situations that I'm not able to reproduce reliably.

Sometimes, Emacs starts using 100% CPU.  When I strace, I see that it's
in a poll loop, so the strace always looks like this:

poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
select(15, [3 4 8 10 13], [], NULL, {0, 15591}) = 2 (in [8 10], left {0, 15589})
read(3, 0xec9b94, 4096)                 = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
select(15, [3 4 8 10 13], [], NULL, {0, 15532}) = 2 (in [8 10], left {0, 15530})
read(3, 0xec9b94, 4096)                 = -1 EAGAIN (Resource temporarily unavailable)

There's always a gnutls socket involved in the select call -- in this
instance it was fd 10.  lsof showed the socket to be in the CLOSE_WAIT
state.  So my suspicion is that the we're somehow now communicating back
to Emacs that a gnutls socket has closed.

I'm not familiar enough with Emacs internals to know how that's supposed
to be done, and I'm not familiar enough with the gnutls library to know
how it reports this, so...  er...  help?

-- 
(domestic pets only, the antidote for overdose, milk.)
  larsi@gnus.org * Lars Magne Ingebrigtsen

Re: gnutls error handling

[Eli Zaretskii]

> From: Lars Magne Ingebrigtsen <larsi@gnus.org>
> Date: Sun, 17 Oct 2010 15:55:24 +0200
> Mail-Copies-To: never
> 
> poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
> select(15, [3 4 8 10 13], [], NULL, {0, 15591}) = 2 (in [8 10], left {0, 15589})
> read(3, 0xec9b94, 4096)                 = -1 EAGAIN (Resource temporarily unavailable)
> poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
> select(15, [3 4 8 10 13], [], NULL, {0, 15532}) = 2 (in [8 10], left {0, 15530})
> read(3, 0xec9b94, 4096)                 = -1 EAGAIN (Resource temporarily unavailable)
> 
> There's always a gnutls socket involved in the select call -- in this
> instance it was fd 10.  lsof showed the socket to be in the CLOSE_WAIT
> state.  So my suspicion is that the we're somehow now communicating back
> to Emacs that a gnutls socket has closed.

Not really a useful answer, but the `select' man page has this piece
of wisdom:

       Under Linux, select() may report a socket file descriptor as
       "ready for reading", while nevertheless a subsequent read
       blocks.  This could for example happen when data has arrived
       but upon examination has wrong checksum and is discarded.
       There may be other circumstances in which a file descriptor is
       spuriously reported as ready.  Thus it may be safer to use
       O_NONBLOCK on sockets that should not block.

Of course, we already use O_NONBLOCK (AFAIK).

Re: gnutls error handling

[Jan D.]

  Eli Zaretskii skrev 2010-10-17 17:22:
>> From: Lars Magne Ingebrigtsen<larsi@gnus.org>
>> Date: Sun, 17 Oct 2010 15:55:24 +0200
>> Mail-Copies-To: never
>>
>> poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
>> select(15, [3 4 8 10 13], [], NULL, {0, 15591}) = 2 (in [8 10], left {0, 15589})
>> read(3, 0xec9b94, 4096)                 = -1 EAGAIN (Resource temporarily unavailable)
>> poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
>> select(15, [3 4 8 10 13], [], NULL, {0, 15532}) = 2 (in [8 10], left {0, 15530})
>> read(3, 0xec9b94, 4096)                 = -1 EAGAIN (Resource temporarily unavailable)
>>
>> There's always a gnutls socket involved in the select call -- in this
>> instance it was fd 10.  lsof showed the socket to be in the CLOSE_WAIT
>> state.  So my suspicion is that the we're somehow now communicating back
>> to Emacs that a gnutls socket has closed.
> Not really a useful answer, but the `select' man page has this piece
> of wisdom:
>
>         Under Linux, select() may report a socket file descriptor as
>         "ready for reading", while nevertheless a subsequent read
>         blocks.  This could for example happen when data has arrived
>         but upon examination has wrong checksum and is discarded.
>         There may be other circumstances in which a file descriptor is
>         spuriously reported as ready.  Thus it may be safer to use
>         O_NONBLOCK on sockets that should not block.
>
> Of course, we already use O_NONBLOCK (AFAIK).

The question is why is Emacs reading fd 3?  It is not reported as ready 
by select, fd 8 and 10 are ready, but those aren't read.

     Jan D.

Re: gnutls error handling

[Lars Magne Ingebrigtsen]

"Jan D." <jan.h.d@swipnet.se> writes:

> The question is why is Emacs reading fd 3?  It is not reported as
> ready by select, fd 8 and 10 are ready, but those aren't read.

Yeah, I wondered that, too.  fd 3 is the connection to the X server, so
it may perhaps be a red herring?  The select says that fd 10 has stuff,
but then it turns out that fd 10 is closed (?), so it isn't read anyway,
so the loop thinks this is a good time to see whether there's any X work
to be done?  I'm just guessing wildly here...

-- 
(domestic pets only, the antidote for overdose, milk.)
  larsi@gnus.org * Lars Magne Ingebrigtsen

Re: gnutls error handling

[Lars Magne Ingebrigtsen]

It happened again just now:

poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
select(20, [3 4 6 7 8 10 11 12 13 14 18], [], NULL, {0, 232293}) = 1 (in [18], left {0, 232288})
read(3, 0xec9b94, 4096)                 = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
select(20, [3 4 6 7 8 10 11 12 13 14 18], [], NULL, {0, 232200}) = 1 (in [18], left {0, 232195})
read(3, 0xec9b94, 4096)                 = -1 EAGAIN (Resource temporarily unavailable)

And fd 18 is:

[larsi@quimbies ~/pgnus]$ lsof | grep 29932331
emacs      2687       larsi   18u     IPv4           29932331      0t0        TCP quimbies.gnus.org:35134->ew-in-f132.1e100.net:https (CLOSE_WAIT)

So that's again a gnutls connection in CLOSE_WAIT.

-- 
(domestic pets only, the antidote for overdose, milk.)
  larsi@gnus.org * Lars Magne Ingebrigtsen

Re: gnutls error handling

[Eli Zaretskii]

> From: Lars Magne Ingebrigtsen <larsi@gnus.org>
> Date: Sun, 17 Oct 2010 19:18:21 +0200
> 
> It happened again just now:
> 
> poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
> select(20, [3 4 6 7 8 10 11 12 13 14 18], [], NULL, {0, 232293}) = 1 (in [18], left {0, 232288})
> read(3, 0xec9b94, 4096)                 = -1 EAGAIN (Resource temporarily unavailable)
> poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
> select(20, [3 4 6 7 8 10 11 12 13 14 18], [], NULL, {0, 232200}) = 1 (in [18], left {0, 232195})
> read(3, 0xec9b94, 4096)                 = -1 EAGAIN (Resource temporarily unavailable)
> 
> And fd 18 is:
> 
> [larsi@quimbies ~/pgnus]$ lsof | grep 29932331
> emacs      2687       larsi   18u     IPv4           29932331      0t0        TCP quimbies.gnus.org:35134->ew-in-f132.1e100.net:https (CLOSE_WAIT)
> 
> So that's again a gnutls connection in CLOSE_WAIT.

Does Emacs try to read from this fd (18 in this case)?  Because AFAIU,
a read from such a socket should return zero bytes, which could be
used as a sign that we need to close the file descriptor.

Or maybe this logic should be (or is) in gnutls, and there's either a
bug there or maybe we use it incorrectly.

Re: gnutls error handling

[Lars Magne Ingebrigtsen]

Eli Zaretskii <eliz@gnu.org> writes:

> Does Emacs try to read from this fd (18 in this case)?  Because AFAIU,
> a read from such a socket should return zero bytes, which could be
> used as a sign that we need to close the file descriptor.

Ah, right.  I've now changed the code in emacs_gnutls_read to do that on
most errors from the library, and using that, and I'll see whether I can
repeat the bug or not.

-- 
(domestic pets only, the antidote for overdose, milk.)
  larsi@gnus.org * Lars Magne Ingebrigtsen