Activated two-part nntp async fetch again

Activated two-part nntp async fetch again

[Lars Ingebrigtsen]

I've now activated the two-part NNTP async fetch again, so your Gnus
will hang again, if you were affected by the hangs earlier.

However, I think I may have made some headway in trying to figure out
why it hangs, although I've been unable to reproduce the problem myself.

I think the issues is that `nntp-retrieve-group-data-early' is called
twice on the same server, for some reason.  And that makes all the
output go into the same buffer, and things get really messed up.

If you are affected by this problem, could you `M-x debug-on-entry RET
nntp-retrieve-group-data-early RET' and then note what the value of the
`server' variable is in each instance?  If you get the same value twice
in the same `g' session, then we've found the culprit, and I'd like to
have the backtraces from two of those calls so that I can see what's
screwing things up.

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

Re: Activated two-part nntp async fetch again

[Eric Abrahamsen]

On Tue, Feb 15 2011, Lars Ingebrigtsen wrote:

> I've now activated the two-part NNTP async fetch again, so your Gnus
> will hang again, if you were affected by the hangs earlier.
>
> However, I think I may have made some headway in trying to figure out
> why it hangs, although I've been unable to reproduce the problem myself.
>
> I think the issues is that `nntp-retrieve-group-data-early' is called
> twice on the same server, for some reason.  And that makes all the
> output go into the same buffer, and things get really messed up.
>
> If you are affected by this problem, could you `M-x debug-on-entry RET
> nntp-retrieve-group-data-early RET' and then note what the value of the
> `server' variable is in each instance?  If you get the same value twice
> in the same `g' session, then we've found the culprit, and I'd like to
> have the backtraces from two of those calls so that I can see what's
> screwing things up.

Mine's hanging again and I'd love to contribute to the debugging
process, but I'm not quite sure what you mean by "each instance". Here's
what I get from one 'g' session, and it appeared to be the same when I
did it again:

Debugger entered--entering a function:
* nntp-retrieve-group-data-early("news.gmane.org" (("gmane.emacs.auctex.general" 3 (...) (...)) ("gmane.emacs.gnus.general" 3 (...) (... ... ... ... ...)) ("gmane.emacs.help" 3 (...) (... ... ...)) ("gmane.lisp.lib.tbnl.general" 3 (...) (...)) ("gmane.emacs.orgmode" 3 (...) (... ... ...)) ("gmane.comp.finance.ledger.general" 3 (...) (... ...)) ("gmane.mail.mairix.user" 3 (...) (... ...)) ("gmane.comp.lang.haskell.xmonad" 3 (...) (... ...)) ("gmane.emacs.gnus.user" 3 (...) (... ... ...))))
  gnus-retrieve-group-data-early((nntp "news.gmane.org") (("gmane.emacs.auctex.general" 3 (...) (...)) ("gmane.emacs.gnus.general" 3 (...) (... ... ... ... ...)) ("gmane.emacs.help" 3 (...) (... ... ...)) ("gmane.lisp.lib.tbnl.general" 3 (...) (...)) ("gmane.emacs.orgmode" 3 (...) (... ... ...)) ("gmane.comp.finance.ledger.general" 3 (...) (... ...)) ("gmane.mail.mairix.user" 3 (...) (... ...)) ("gmane.comp.lang.haskell.xmonad" 3 (...) (... ...)) ("gmane.emacs.gnus.user" 3 (...) (... ... ...))))
  gnus-get-unread-articles(nil)
  gnus-group-get-new-news(nil)
  call-interactively(gnus-group-get-new-news nil nil)

Re: Activated two-part nntp async fetch again

[Manoj Srivastava]

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

Hi,

        So, I checked out emacs24 from git today, and the expected hang
 happened.  `M-x debug-on-entry RET nntp-retrieve-group-data-early RET'
 dutifuly led to a backtrace. I hit c, and it returned me to another
 backtrace. This happened two more times, for a total of 4 visits to a
 backtrace buffer, which I am now attaching.

        manoj




[-- Attachment #2: backtrace 1 --]
[-- Type: application/octet-stream, Size: 32986 bytes --]

[-- Attachment #3: Backtrace 2 --]
[-- Type: application/octet-stream, Size: 32985 bytes --]

[-- Attachment #4: Backtrace 3 --]
[-- Type: application/octet-stream, Size: 32985 bytes --]

[-- Attachment #5: Backtrace 4 --]
[-- Type: application/octet-stream, Size: 34114 bytes --]

[-- Attachment #6: Type: text/plain, Size: 228 bytes --]


-- 
"So why don't you make like a tree, and get outta here." Biff in "Back
to the Future"
Manoj Srivastava <srivasta@acm.org> <http://www.golden-gryphon.com/>  
4096R/C5779A1C E37E 5EC5 2A01 DA25 AD20  05B6 CF48 9438 C577 9A1C

Re: Activated two-part nntp async fetch again

[Lars Ingebrigtsen]

Eric Abrahamsen <eric@ericabrahamsen.net> writes:

> Mine's hanging again and I'd love to contribute to the debugging
> process, but I'm not quite sure what you mean by "each instance". Here's
> what I get from one 'g' session, and it appeared to be the same when I
> did it again:
>
> Debugger entered--entering a function:
> * nntp-retrieve-group-data-early("news.gmane.org"

Is this function called only once when you do `g'?  That is, if you
continue with `c', is it called again later?  If my suspicions are
correct, it will be called several times with the same server parameter.

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

Re: Activated two-part nntp async fetch again

[Lars Ingebrigtsen]

I've now managed to reproduce the bug, and I think I've probably fixed
it, but this is deep into obscure method uniquilisation (that should be
a word) territory, so this may break other stuff.  Or lead to having a
lot of NNTP connections open.

Let me know what happens...

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

Re: Activated two-part nntp async fetch again

[Vincent Bernat]

OoO En cette  fin de nuit blanche du lundi 21  février 2011, vers 06:04,
Lars Ingebrigtsen <larsi@gnus.org> disait :

> I've now managed to reproduce the bug, and I think I've probably fixed
> it, but this is deep into obscure method uniquilisation (that should be
> a word) territory, so this may break other stuff.  Or lead to having a
> lot of NNTP connections open.

Hi!

I am using b5fa82f9d758d5e39bf7c8908189c44759cb90b4  but I still get the
problem. Here is a backtrace:

  nntp-with-open-group-function(nil "news.crans.org" nil #[nil "\306\b!\307	@@	@\"\310\311.^[.\211.\205\317.\x0e.\205\317.r.q\210\312.!\203L.\nb\210\313.\x19\2030.\314\2021.\315\316\317#\203=.\vT.\202&.`.\v.\x18W\203L.\320 \210\202.\0\321 \210.\x19\204}.ed{.\x1ar\bq\210\322 \210.^[\203l.\323.\x1a!\202n.\x0e.c\210eb\210*\324\f.\x1c\317#\202\316.eb\210\313\325\316\317#\203\223.\310\224\311y\210`|\210\202\200.ed{.\x1ar\bq\210\322 \210.^[\203\253.\323.\x1a!\202\255.\x0e.c\210eb\210*r\bq\210\326\327	@8:\203\307.\327	@8\202\310.\f.\x1c\316\317$)),\207" [nntp-server-buffer infos last-point received method buf nntp-find-connection-buffer gnus-find-method-for-group 0 1 gnus-buffer-live-p re-search-forward "^[.]" "^[0-9]" nil t nntp-accept-response nnheader-strip-cr erase-buffer mm-string-to-multibyte gnus-groups-to-gnus-format "^[.2-5]" gnus-active-to-gnus-format 4 count nntp-server-list-active-group string enable-multibyte-characters gnus-active-hashtb] 6])
  nntp-finish-retrieve-group-infos("news.crans.org" (("nntp+news.crans.org:crans.crans" 3 (...) (... ... ... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.crans.annonces" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.general" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.informatique" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.dino" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.culture" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.informatique.linux" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.test" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.web-sympas" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:tac.bde" 3 (...) (...) "nntp:news.crans.org" (...))) 10)
  gnus-finish-retrieve-group-infos((nntp "news.crans.org") (("nntp+news.crans.org:crans.crans" 3 (...) (... ... ... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.crans.annonces" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.general" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.informatique" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.dino" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.culture" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.informatique.linux" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.test" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.web-sympas" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:tac.bde" 3 (...) (...) "nntp:news.crans.org" (...))) 10)
  gnus-read-active-for-groups((nntp "news.crans.org") (("nntp+news.crans.org:crans.crans" 3 (...) (... ... ... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.crans.annonces" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.general" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.informatique" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.dino" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.culture" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.informatique.linux" 3 (...) (... ...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.test" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:crans.web-sympas" 3 (...) (...) "nntp:news.crans.org" (...)) ("nntp+news.crans.org:tac.bde" 3 (...) (...) "nntp:news.crans.org" (...))) 10)
-- 
Make input easy to proofread.
            - The Elements of Programming Style (Kernighan & Plauger)

Re: Activated two-part nntp async fetch again

[Lars Magne Ingebrigtsen]

Vincent Bernat <bernat@luffy.cx> writes:

>   gnus-finish-retrieve-group-infos((nntp "news.crans.org")

Darn.

If there's nothing too secret in your .newsrc.eld, could you email me
the entire file?  Alternatively, just pick out the group infos belonging
to news.crans.org and mail me those, and I can try to reproduce this.

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

Re: Activated two-part nntp async fetch again

[Eric Abrahamsen]

Lars Ingebrigtsen <larsi@gnus.org> writes:

> Eric Abrahamsen <eric@ericabrahamsen.net> writes:
>
>> Mine's hanging again and I'd love to contribute to the debugging
>> process, but I'm not quite sure what you mean by "each instance". Here's
>> what I get from one 'g' session, and it appeared to be the same when I
>> did it again:
>>
>> Debugger entered--entering a function:
>> * nntp-retrieve-group-data-early("news.gmane.org"
>
> Is this function called only once when you do `g'?  That is, if you
> continue with `c', is it called again later?  If my suspicions are
> correct, it will be called several times with the same server parameter.

Damn, for some reason I missed your response here. I'm still getting
this problem. I just debugged it, and I need to hit 'c' twice to get out
of the hang and past the nntp retrieval, into the rest of my mail
sources. Here's the *backtrace* buffer after one 'c', so I guess
nntp_retrieve-group-data-early is getting called twice…?

Debugger entered--returning value: 12
  nntp-retrieve-group-data-early("news.gmane.org" (("gmane.emacs.auctex.general" 3 (...) (...)) ("gmane.emacs.gnus.general" 3 (...) (... ... ... ...)) ("gmane.emacs.help" 3 (...) (... ... ...)) ("gmane.lisp.lib.tbnl.general" 3 (...) (...)) ("gmane.emacs.orgmode" 3 (...) (... ... ...)) ("gmane.comp.finance.ledger.general" 3 (...) (... ...)) ("gmane.mail.mairix.user" 3 (...) (...)) ("gmane.comp.lang.haskell.xmonad" 3 (...) (... ... ...)) ("gmane.mail.msmtp.user" 3 (...) (...)) ("gmane.emacs.gnus.user" 3 (...) (... ... ...)) ("gmane.emacs.bbdb.user" 3 (...) (... ...)) ("gmane.comp.python.django.user" 3 (...) (... ... ...))))
  gnus-retrieve-group-data-early((nntp "news.gmane.org") (("gmane.emacs.auctex.general" 3 (...) (...)) ("gmane.emacs.gnus.general" 3 (...) (... ... ... ...)) ("gmane.emacs.help" 3 (...) (... ... ...)) ("gmane.lisp.lib.tbnl.general" 3 (...) (...)) ("gmane.emacs.orgmode" 3 (...) (... ... ...)) ("gmane.comp.finance.ledger.general" 3 (...) (... ...)) ("gmane.mail.mairix.user" 3 (...) (...)) ("gmane.comp.lang.haskell.xmonad" 3 (...) (... ... ...)) ("gmane.mail.msmtp.user" 3 (...) (...)) ("gmane.emacs.gnus.user" 3 (...) (... ... ...)) ("gmane.emacs.bbdb.user" 3 (...) (... ...)) ("gmane.comp.python.django.user" 3 (...) (... ... ...))))
  gnus-get-unread-articles(nil)
  gnus-group-get-new-news(nil)
  call-interactively(gnus-group-get-new-news nil nil)

Re: Activated two-part nntp async fetch again

[Lars Magne Ingebrigtsen]

Eric Abrahamsen <eric@ericabrahamsen.net> writes:

> Damn, for some reason I missed your response here. I'm still getting
> this problem. I just debugged it, and I need to hit 'c' twice to get out
> of the hang and past the nntp retrieval, into the rest of my mail
> sources. Here's the *backtrace* buffer after one 'c', so I guess
> nntp_retrieve-group-data-early is getting called twice…?
>
> Debugger entered--returning value: 12
>   nntp-retrieve-group-data-early("news.gmane.org"

Could you repeat again with

(setq eval-expression-print-level 20)
(setq eval-expression-print-length 80)

and then post both backtraces?

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

Re: Activated two-part nntp async fetch again

[Eric Abrahamsen]

On Wed, Mar 30 2011, Lars Magne Ingebrigtsen wrote:

> Eric Abrahamsen <eric@ericabrahamsen.net> writes:
>
>> Damn, for some reason I missed your response here. I'm still getting
>> this problem. I just debugged it, and I need to hit 'c' twice to get out
>> of the hang and past the nntp retrieval, into the rest of my mail
>> sources. Here's the *backtrace* buffer after one 'c', so I guess
>> nntp_retrieve-group-data-early is getting called twice…?
>>
>> Debugger entered--returning value: 12
>>   nntp-retrieve-group-data-early("news.gmane.org"
>
> Could you repeat again with
>
> (setq eval-expression-print-level 20)
> (setq eval-expression-print-length 80)
>
> and then post both backtraces?

Thanks for sticking with this! If anything, it's happening more now
than before.

These are the backtraces from a fresh gnus startup. The byte-code("\204
lines are actually very long, I seem unable to copy and paste them.

http://pastebin.com/WPX5gGTu

Thanks again,
Eric

Re: Activated two-part nntp async fetch again

[Lars Magne Ingebrigtsen]

Eric Abrahamsen <eric@ericabrahamsen.net> writes:

> Thanks for sticking with this! If anything, it's happening more now
> than before.

Sorry for taking so long to respond.

> These are the backtraces from a fresh gnus startup. The byte-code("\204
> lines are actually very long, I seem unable to copy and paste them.
>
> http://pastebin.com/WPX5gGTu

And, sorry, my instructions may have been wrong.  The two backtraces
you've posted seem to have been from the same call?  After getting the
first backtrace, did you type `c' (to continue) and then get another
backtrace?  

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