Nebulous streaming/point bug

Nebulous streaming/point bug

[Lars Magne Ingebrigtsen]

I'm not able to create an "emacs -Q" recipe for this bug, but it started
happening today, so something must have changed somewhere during the
last few days in process/point handling somewhere, I think.

The symptoms are as follows:

1) I go to an nntp connection buffer, which is totally empty.

2) I say (process-send-string (get-buffer-process (current-buffer)) "ARTICLE 1202464\r\n")

3) I get the thing included below.

The salient thing here is that the end of the article ends up at the
beginning of the buffer.  That is, the last three lines in the buffer
should be the "end pgp signature" stuff.  There are no process sentinels
here, and nntp.el hasn't changed since August.

Does anybody know what this could possibly mean?  Did somebody work on
point movement/process output functionality the last few days?

>>> snip <<<
D PGP SIGNATURE-----

--Signature=_Thu__13_Oct_2011_09_26_29_+1100_I=tEzV/xEmi3FQAY--
.
220 1202464 <20111013092629.429358e7c3117ce18d12fd24@canb.auug.org.au> article
Path: news.gmane.org!not-for-mail
From: Stephen Rothwell <sfr@canb.auug.org.au>
Newsgroups: gmane.linux.kernel.next,gmane.linux.kernel
Subject: Re: linux-next: Tree for Oct 12
Date: Thu, 13 Oct 2011 09:26:29 +1100
Lines: 43
Approved: news@gmane.org
Message-ID: <20111013092629.429358e7c3117ce18d12fd24@canb.auug.org.au>
References: <20111012175425.a2e3e6e6a92265e433aeca25@canb.auug.org.au>
	<4E95B18D.9070806@xenotime.net>
NNTP-Posting-Host: lo.gmane.org
Mime-Version: 1.0
Content-Type: multipart/signed; protocol="application/pgp-signature";
 micalg="PGP-SHA256";
 boundary="Signature=_Thu__13_Oct_2011_09_26_29_+1100_I=tEzV/xEmi3FQAY"
X-Trace: dough.gmane.org 1318458405 9171 80.91.229.12 (12 Oct 2011 22:26:45 GMT)
X-Complaints-To: usenet@dough.gmane.org
NNTP-Posting-Date: Wed, 12 Oct 2011 22:26:45 +0000 (UTC)
Cc: linux-next@vger.kernel.org, LKML <linux-kernel@vger.kernel.org>
To: Randy Dunlap <rdunlap@xenotime.net>
Original-X-From: linux-next-owner@vger.kernel.org Thu Oct 13 00:26:40 2011
Return-path: <linux-next-owner@vger.kernel.org>
Envelope-to: glkn-linux-next@lo.gmane.org
Original-Received: from vger.kernel.org ([209.132.180.67])
	by lo.gmane.org with esmtp (Exim 4.69)
	(envelope-from <linux-next-owner@vger.kernel.org>)
	id 1RE7G3-0004hg-UO
	for glkn-linux-next@lo.gmane.org; Thu, 13 Oct 2011 00:26:40 +0200
Original-Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
	id S1752731Ab1JLW0i (ORCPT <rfc822;glkn-linux-next@m.gmane.org>);
	Wed, 12 Oct 2011 18:26:38 -0400
Original-Received: from calzone.tip.net.au ([203.10.76.15]:58153 "EHLO
	calzone.tip.net.au" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
	with ESMTP id S1751844Ab1JLW0i (ORCPT
	<rfc822;linux-next@vger.kernel.org>); Wed, 12 Oct 2011 18:26:38 -0400
Original-Received: from canb.auug.org.au (ash.rothwell.emu.id.au [IPv6:2402:b800:7003:7010:223:14ff:fe30:c8e4])
	(using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits))
	(No client certificate requested)
	by calzone.tip.net.au (Postfix) with ESMTPSA id 3114712843E;
	Thu, 13 Oct 2011 09:26:35 +1100 (EST)
In-Reply-To: <4E95B18D.9070806@xenotime.net>
X-Mailer: Sylpheed 3.2.0beta3 (GTK+ 2.24.6; i486-pc-linux-gnu)
Original-Sender: linux-next-owner@vger.kernel.org
Precedence: bulk
List-ID: <linux-next.vger.kernel.org>
X-Mailing-List: linux-next@vger.kernel.org
Xref: news.gmane.org gmane.linux.kernel.next:19039 gmane.linux.kernel:1202464
Archived-At: <http://permalink.gmane.org/gmane.linux.kernel.next/19039>

--Signature=_Thu__13_Oct_2011_09_26_29_+1100_I=tEzV/xEmi3FQAY
Content-Type: text/plain; charset=US-ASCII
Content-Disposition: inline
Content-Transfer-Encoding: quoted-printable

Hi all,

On Wed, 12 Oct 2011 08:26:05 -0700 Randy Dunlap <rdunlap@xenotime.net> wrot=
e:
>
> eh?  I can't find it on github or kernel.org.  what gives?

I was in a bit of a rush and forgot to push it to github, sorry about
that.  On the other hand, it has finally appeared on git.kernel.org.  I
have pushed it to github now as well.

--=20
Cheers,
Stephen Rothwell                    sfr@canb.auug.org.au
http://www.canb.auug.org.au/~sfr/

--Signature=_Thu__13_Oct_2011_09_26_29_+1100_I=tEzV/xEmi3FQAY
Content-Type: application/pgp-signature

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)

iQIcBAEBCAAGBQJOlhQVAAoJEECxmPOUX5FE9TgP/0OpAyerACxJenT3yNla2GYB
hPQklUyqpQz3UI5FMfihmN6abZPMcdgNIf+eSMLtxWS/tbCemzCWEa6d5VJBnXrs
YatCMA2OceaZUmdKUC5VAjChayChhJmXGKBsn46t4CHz1Zc9J9J+dxRYhOn0eroN
UL00pUN9FyN8Uoq5Nh8/Ff3/hPV7s/5gDr322ZDH+c8/zm0x3DpJpu30qHTgst3T
tlg6Gx+NucfeW/7rljCVtwIAkMrtNsvSYRKsbRNUfYvXUp8s1Ug5wySrF5sjQGGK
p5A1I9KsCcyfRz/q/f/bpKZ1RTx4/fXlz1kkQqpnMQlMsSOn3vWM5BPGibu01RI3
zB96M9i2+DGA7ws6mKY1uYFs/17P3BJg+d0a3hWDk21QOwuQbZtyWDbgBYDDbah7
S7U6YbMN612IBvJYhbn5BPnH+4bwEdfkZGW8+toBzmVa1glHshN2K2VVavTnivyq
oEtRH7V6rpi6sXsvT3ZY79NKxR/iB8UlnYCxTmDU0fCLD5Y5QN6RKVcd8BZZzFQZ
TyS/xNiUkeTiGng3pOFKroZe5lMJWVftV8LY2An0fZAqUeSj3PgWx7EHHyYRpC0N
QKbSQ8QSG/JBGygWMtVettJVepr/2RSLZ3/94+0oqHUGJakhdHUkVbncxY/TYYpm
HEUpSVoxwF7h6HzaT4T8
=xmpv
-----EN
>>> snip <<<



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

Re: Nebulous streaming/point bug

[Lars Magne Ingebrigtsen]

Lars Magne Ingebrigtsen <larsi@gnus.org> writes:

> Does anybody know what this could possibly mean?  Did somebody work on
> point movement/process output functionality the last few days?

Data point: The wrapover happens after 4096 characters have been
received in a single package, apparently.  All these look like:

220 1202430 <65795E11DBF1E645A09CEC7EAEE94B9CB516D055@USINDEVS02.corp.hds.com> article
Path: news.gmane.org!not-for-mail
From: Satoru Moriya <satoru.moriya@hds.com>
Newsgroups: gmane.linux.kernel.mm,gmane.linux.kernel
...
Original-Received: from USINDEVS02.corp.hds.com ([10.74.24.1

The length from the first character of the article itself (the bit
starting with "Path:" to the end of the buffer is always 4096 characters
long.

And then the rest of the article appears at the beginning of the
buffer...

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

Re: Nebulous streaming/point bug

[Lars Magne Ingebrigtsen]

This "emacs -Q" reproduces the problem somewhat for me.

The "lala" buffer will end with "-----EN" instead of the getting the
entire message.  It won't "wrap" point, though...

(progn
  (setq proc
	(open-protocol-stream
		     "nntpd" (get-buffer-create "lala")
		     "news.gmane.org" "nntp"
		     :end-of-command "^\\([2345]\\|[.]\\).*\n"
		     :capability-command "CAPABILITIES\r\n"
		     :success "^3"
		     :starttls-function
		     (lambda (capabilities)
		       (if (not (string-match "STARTTLS" capabilities))
			   nil
			 "STARTTLS\r\n"))))
  (process-send-string proc "MODE READER\r\n")
  (process-send-string proc "GROUP gmane.linux.kernel\r\n")
  (process-send-string proc "ARTICLE 1202464\r\n"))

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

Re: Nebulous streaming/point bug

[Lars Magne Ingebrigtsen]

Lars Magne Ingebrigtsen <larsi@gnus.org> writes:

> This "emacs -Q" reproduces the problem somewhat for me.
>
> The "lala" buffer will end with "-----EN" instead of the getting the
> entire message.  It won't "wrap" point, though...

So it seems like the problem is with the GnuTLS support?  Because it
won't fail like this on non-GnuTLS builds.

And I upgraded my machine to a newer Debian version with gnutls
2.12.11-1, which is probably the reason for this problem popping up
now. 

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

Re: Nebulous streaming/point bug

[Lars Magne Ingebrigtsen]

Lars Magne Ingebrigtsen <larsi@gnus.org> writes:

> And I upgraded my machine to a newer Debian version with gnutls
> 2.12.11-1, which is probably the reason for this problem popping up
> now. 

After pumping up the log level, I get the following when I request a
single article.  The numbers in the trace are suggestive, but I'm not
quite sure what they mean.  :-) The real length of the article is 4188,
as reported by "BUF[REC]: Inserted 4188 bytes of Data".  The number of
characters inserted into the buffer is 4096, as reported by
"BUFFER[REC][AD]: Read 4096 bytes of Data".

So something is wonky here.  Ted?  :-)

This is with Debian Testing.

gnutls.c: [4] REC[0x33a61a0]: Sending Packet[6] Application Data(23) with length: 17
gnutls.c: [7] WRITE: enqueued 69 bytes for 0x8. Total 69 bytes.
gnutls.c: [7] WRITE FLUSH: 69 bytes in buffer.
gnutls.c: [7] WRITE: wrote 69 bytes, 0 bytes left.
gnutls.c: [4] REC[0x33a61a0]: Sent Packet[7] Application Data(23) with length: 69
gnutls.c: [6] BUFFER[REC][AD]: Read 92 bytes of Data(23)
gnutls.c: [7] READ: Got 5 bytes from 0x8
gnutls.c: [7] READ: read 5 bytes from 0x8
gnutls.c: [7] RB: Have 0 bytes into buffer. Adding 5 bytes.
gnutls.c: [7] RB: Requested 5 bytes
gnutls.c: [4] REC[0x33a61a0]: Expected Packet[19] Application Data(23) with length: 4096
gnutls.c: [4] REC[0x33a61a0]: Received Packet[19] Application Data(23) with length: 112
gnutls.c: [7] READ: Got 112 bytes from 0x8
gnutls.c: [7] READ: read 112 bytes from 0x8
gnutls.c: [7] RB: Have 5 bytes into buffer. Adding 112 bytes.
gnutls.c: [7] RB: Requested 117 bytes
gnutls.c: [4] REC[0x33a61a0]: Decrypted Packet[19] Application Data(23) with length: 80
gnutls.c: [6] BUF[REC]: Inserted 80 bytes of Data(23)
gnutls.c: [6] BUFFER[REC][AD]: Read 80 bytes of Data(23)
gnutls.c: [7] READ: Got 5 bytes from 0x8
gnutls.c: [7] READ: read 5 bytes from 0x8
gnutls.c: [7] RB: Have 0 bytes into buffer. Adding 5 bytes.
gnutls.c: [7] RB: Requested 5 bytes
gnutls.c: [4] REC[0x33a61a0]: Expected Packet[20] Application Data(23) with length: 4096
gnutls.c: [4] REC[0x33a61a0]: Received Packet[20] Application Data(23) with length: 4224
gnutls.c: [7] READ: Got 4224 bytes from 0x8
gnutls.c: [7] READ: read 4224 bytes from 0x8
gnutls.c: [7] RB: Have 5 bytes into buffer. Adding 4224 bytes.
gnutls.c: [7] RB: Requested 4229 bytes
gnutls.c: [4] REC[0x33a61a0]: Decrypted Packet[20] Application Data(23) with length: 4188
gnutls.c: [6] BUF[REC]: Inserted 4188 bytes of Data(23)
gnutls.c: [6] BUFFER[REC][AD]: Read 4096 bytes of Data(23)

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

Re: Nebulous streaming/point bug

[Lars Magne Ingebrigtsen]

Lars Magne Ingebrigtsen <larsi@gnus.org> writes:

> So something is wonky here.  Ted?  :-)

I've added a lot of printf, and I think I now can see what's going on.
Sort of.

If I call `accept-process-output' explicitly on the GnuTLS process, then
I get all the data.  If I'm waiting for the idle loop to fetch the data
(i.e., wait_reading_process_output being called with no explicit
process), then that never happens.

I'm guessing this doesn't happen because select somehow doesn't work the
same on the GnuTLS sockets as they used to in older versions of the
library, even though the manual page says that it probably should...

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

Re: Nebulous streaming/point bug

[Lars Magne Ingebrigtsen]

Yup.  Looks like the problem was where I thought it would be.

Now, I obviously don't recommend the horror included below as a patch,
but it seems to make it possible to read news with Gnus again under
Emacs 24.  But it should be fixed in a different way.  :-)

I'm not familiar enough with GnuTLS internals to say what the fix really
should be, but I can test patches.

=== modified file 'src/process.c'
--- src/process.c	2011-09-09 01:06:52 +0000
+++ src/process.c	2011-10-13 01:01:35 +0000
@@ -4612,6 +4612,23 @@
              some data in the TCP buffers so that select works, but
              with custom pull/push functions we need to check if some
              data is available in the buffers manually.  */
+          if (nfds == 0)
+	    {
+	      for (channel = 0; channel < MAXDESC; ++channel)
+		{
+		  if (! NILP (chan_process[channel]))
+		    {
+		      struct Lisp_Process *proc = XPROCESS (chan_process[channel]);
+		      if (proc && proc->gnutls_p &&
+			  proc->infd &&
+			  emacs_gnutls_record_check_pending (proc->gnutls_state) > 0)
+			{
+			  nfds++;
+			  FD_SET (proc->infd, &Available);
+			}
+		    }
+		}
+	    }
           if (nfds == 0 &&
               wait_proc && wait_proc->gnutls_p /* Check for valid process.  */
               /* Do we have pending data?  */


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

Re: Nebulous streaming/point bug

[Ted Zlatanov]

On Thu, 13 Oct 2011 03:04:53 +0200 Lars Magne Ingebrigtsen <larsi@gnus.org> wrote: 

LMI> Yup.  Looks like the problem was where I thought it would be.
LMI> Now, I obviously don't recommend the horror included below as a patch,
LMI> but it seems to make it possible to read news with Gnus again under
LMI> Emacs 24.  But it should be fixed in a different way.  :-)

LMI> I'm not familiar enough with GnuTLS internals to say what the fix really
LMI> should be, but I can test patches.

Based on your patch I think it's a GnuTLS bug.  They are up to 3.x now,
which makes it harder: do we keep supporting the 2.x series or do we
start using 3.x, which will be harder to obtain because it's new,
especially for the W32 build?  I'd rather not support both and just move
to 3.x, which has a fairly compatible API, and see if the bug is still
there.  What do you think?

Obviously all this would happen after the release; for now I think it's
best to use your patch and note it's temporary.

Ted

Re: Nebulous streaming/point bug

[Ted Zlatanov]

On Thu, 13 Oct 2011 07:56:19 -0500 Ted Zlatanov <tzz@lifelogs.com> wrote: 

TZ> On Thu, 13 Oct 2011 03:04:53 +0200 Lars Magne Ingebrigtsen <larsi@gnus.org> wrote: 
LMI> Yup.  Looks like the problem was where I thought it would be.
LMI> Now, I obviously don't recommend the horror included below as a patch,
LMI> but it seems to make it possible to read news with Gnus again under
LMI> Emacs 24.  But it should be fixed in a different way.  :-)

LMI> I'm not familiar enough with GnuTLS internals to say what the fix really
LMI> should be, but I can test patches.

TZ> Based on your patch I think it's a GnuTLS bug.  They are up to 3.x now,
TZ> which makes it harder: do we keep supporting the 2.x series or do we
TZ> start using 3.x, which will be harder to obtain because it's new,
TZ> especially for the W32 build?  I'd rather not support both and just move
TZ> to 3.x, which has a fairly compatible API, and see if the bug is still
TZ> there.  What do you think?

TZ> Obviously all this would happen after the release; for now I think it's
TZ> best to use your patch and note it's temporary.

Ping?  I plan to dive into gnutls.{c,el} and need some feedback on 2.x
vs. 3.x.  Can we get 3.x built for W32 like 2.x?

Thanks
Ted

Re: Nebulous streaming/point bug

[Lars Magne Ingebrigtsen]

Ted Zlatanov <tzz@lifelogs.com> writes:

> Based on your patch I think it's a GnuTLS bug.  They are up to 3.x now,
> which makes it harder: do we keep supporting the 2.x series or do we
> start using 3.x, which will be harder to obtain because it's new,
> especially for the W32 build?  I'd rather not support both and just move
> to 3.x, which has a fairly compatible API, and see if the bug is still
> there.  What do you think?

I think we should support both.  I really want normal Emacs 24.1 users
to have encrypted network connections by default.

> Obviously all this would happen after the release; for now I think it's
> best to use your patch and note it's temporary.

If people think the approach is halfway sane, I can clean up the patch
and apply, but I'd love to have some feedback first.

To recap:

Some versions of libgnutls do not seem to work well with select.  That
is, they don't say that there's anything there even though there is.

So the idle loop, which does a select on all the file descriptors don't
get (all) the data from gnutls sockets.  My "fix" is to loop through all
the channels, see whether they are gnutls sockets, and then calling
emacs_gnutls_record_check_pending on each one.

Since this is done in the idle loop, it's typically done once every
second or so, apparently.  So the performance hit should be negligible.

The loop looks like this:

for (channel = 0; channel < MAXDESC; ++channel)
  if (! NILP (chan_process[channel]))
     ... do stuff

But it's an ugly hack.

So: Add the hack or not?

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

Re: Nebulous streaming/point bug

[Ted Zlatanov]

On Thu, 03 Nov 2011 21:20:32 +0100 Lars Magne Ingebrigtsen <larsi@gnus.org> wrote: 

LMI> Ted Zlatanov <tzz@lifelogs.com> writes:
>> Based on your patch I think it's a GnuTLS bug.  They are up to 3.x now,
>> which makes it harder: do we keep supporting the 2.x series or do we
>> start using 3.x, which will be harder to obtain because it's new,
>> especially for the W32 build?  I'd rather not support both and just move
>> to 3.x, which has a fairly compatible API, and see if the bug is still
>> there.  What do you think?

LMI> I think we should support both.  I really want normal Emacs 24.1 users
LMI> to have encrypted network connections by default.

Hrm.  OK, I'll do what I can, but I don't think I'll have the time to do
this work in the next few months.

>> Obviously all this would happen after the release; for now I think it's
>> best to use your patch and note it's temporary.

LMI> If people think the approach is halfway sane, I can clean up the patch
LMI> and apply, but I'd love to have some feedback first.

LMI> To recap:

LMI> Some versions of libgnutls do not seem to work well with select.  That
LMI> is, they don't say that there's anything there even though there is.

LMI> So the idle loop, which does a select on all the file descriptors don't
LMI> get (all) the data from gnutls sockets.  My "fix" is to loop through all
LMI> the channels, see whether they are gnutls sockets, and then calling
LMI> emacs_gnutls_record_check_pending on each one.

LMI> Since this is done in the idle loop, it's typically done once every
LMI> second or so, apparently.  So the performance hit should be negligible.

LMI> The loop looks like this:

LMI> for (channel = 0; channel < MAXDESC; ++channel)
LMI>   if (! NILP (chan_process[channel]))
LMI>      ... do stuff

LMI> But it's an ugly hack.

LMI> So: Add the hack or not?

I'm in favor, if the GnuTLS devs agree.  They should know best if this
is a bug or we're using it badly.

Ted