Gnus gets terribly slow when exiting high-traffic groups

[Jason L Tibbitts III]

I have a few some mail folders which have absurdly high traffic
(linux-kernel, a folder with logwatch output from every host I manage,
etc.). Exiting those groups has started to take so long that I don't
even bother trying to read mail there. We're talking over an hour on a
good CPU (i5-4690).

I had this problem a while back but it got better after I updated gnus.
Now I'm running the absolute latest version pulled from git a few
minutes ago. This happens even if I enter a group that has had loads of
traffic but currently has no articles in it. (It got big, I gave up and
unsubscribed, all of the articles ended up getting nuked by
total-expire, and so there's nothing in there now but the folder still
exists. Entering it immediately goes back to the summary buffer with
"Expiring articles...")

debug-on-quit tells me it's sitting around in
gnus-summary-expire-articles(). It's not doing anything with the IMAP
server and the CPU is pegged. Any idea how I can debug this, or get
things back to a usable state? (I guess I can always rename the
folder.) I once knew how to debug elisp but that's long been forgotten.

- J<

[Lars Ingebrigtsen]

Post by Jason L Tibbitts III
debug-on-quit tells me it's sitting around in
gnus-summary-expire-articles(). It's not doing anything with the IMAP
server and the CPU is pegged. Any idea how I can debug this, or get
things back to a usable state? (I guess I can always rename the
folder.) I once knew how to debug elisp but that's long been forgotten.

Hm... let's see... Is the nnimap group marked as a total-expirable
group? Because then that function will go through all read articles in
the group and see whether it's eligible for expiration.

[Jason L Tibbitts III]

LI> Hm... let's see... Is the nnimap group marked as a total-expirable
LI> group?

Yes, all of my groups are marked total-expire except for my inbox.

- J<

[Lars Ingebrigtsen]

Post by Jason L Tibbitts III
LI> Hm... let's see... Is the nnimap group marked as a total-expirable
LI> group?
Yes, all of my groups are marked total-expire except for my inbox.

Did the articles in that group really get expired? If so, the list of
articles it has to loop over shouldn't really be that big.

Gnus keeps track of messages that have been deleted in the `unexist'
list for the group. If you do a `M-g' on the group (after upgrading to
the latest git Gnus), and then `G E' to display the group data, does the
`unexist' list cover most of the group's messages?

[Jason L Tibbitts III]

LI> Did the articles in that group really get expired?

All of the ones that should have. I have a group I'm using for testing
that only takes 20 seconds or so to exit. I renamed it a bit under two
days ago and total-expire is set to 2. There are 39 articles in it.

LI> Gnus keeps track of messages that have been deleted in the `unexist'
LI> list for the group. If you do a `M-g' on the group (after upgrading
LI> to the latest git Gnus), and then `G E' to display the group data,
LI> does the `unexist' list cover most of the group's messages?

Just pulled the last three commits from git and rebuilt. Entered and
exited the group a couple of times to make sure that it hadn't magically
gotten faster. (It hadn't.) G E shows:

("system-updates-2" 3
((1 . 139843))
((unexist
(1 . 139804))
(seen
(136648 . 139843)))
nil
((modseq)
(uidvalidity . "1205769859")
(active 1 . 139843)
(permanent-flags %Answered %Flagged %Draft %Deleted %Seen %*)
total-expire
(expiry-wait . 2)))

Doesn't look particularly problematic to me.

- J<

[Lars Ingebrigtsen]

Post by Jason L Tibbitts III
Just pulled the last three commits from git and rebuilt. Entered and
exited the group a couple of times to make sure that it hadn't magically
("system-updates-2" 3
((1 . 139843))
((unexist
(1 . 139804))
(seen
(136648 . 139843)))
nil
((modseq)
(uidvalidity . "1205769859")
(active 1 . 139843)
(permanent-flags %Answered %Flagged %Draft %Deleted %Seen %*)
total-expire
(expiry-wait . 2)))
Doesn't look particularly problematic to me.

No, that looks the way it should.

I've tried reproducing this, but setting this up as a test case is quite
tricky.

Could you `M-x edebug-defun' though gnus-summary-expire-articles in
gnus-sum.el and see why it's looping there so much?

[Jason L Tibbitts III]

LI> Could you `M-x edebug-defun' though gnus-summary-expire-articles in
LI> gnus-sum.el and see why it's looping there so much?

Well, when I did this, nothing appeared to take very long. Holding down
'n' How very
odd. The only interesting thing was that
(gnus-list-of-read-articles gnus-newsgroup-name) generated a really long
list, but it only looped over the 39 articles and took less time holding
down space than it's ever taken before.

How can I be trebly sure I'm running the right version? I mean, G E
wouldn't have given me the info you needed if I wasn't running the
current code, right?

I have
(setq load-path (cons (expand-file-name "~/work/gnus/lisp" load-path))
in my .emacs (before (require 'gnus-load)) and that's where the current
stuff is. I'm feeling like I must have screwed something up somewhere.

- J<

[Jason L Tibbitts III]

That didn't entirely come out right, but basically I just held down
space and watched it iterate over the 39 unexpired articles in that
group. Took a few seconds. I'm at a loss. I'll make sure there's no
other gnus code on my system, just in case.

- J<

[Lars Ingebrigtsen]

Post by Jason L Tibbitts III
How can I be trebly sure I'm running the right version? I mean, G E
wouldn't have given me the info you needed if I wasn't running the
current code, right?

The output from `G E' looked like from a pretty recentish (i.e., within
a couple of years) Gnus.

Try `M-x list-load-path-shadows' to list shadowing, or `M-x find-library
RET gnus-sum RET' to see which version of gnus-sum you're loading.

[Jason L Tibbitts III]

LI> Try `M-x list-load-path-shadows' to list shadowing, or `M-x
LI> find-library RET gnus-sum RET' to see which version of gnus-sum
LI> you're loading.

Everything looks good there; my local copy of gnus seems to completely
shadow the system one (which is whatever comes with emacs 24.4.1). And
somehow, in the meantime, exiting that group has become instantaneous.
I don't get it. I still have another group that is slow, however:

("linux-wireless" 3
((1 . 118651))
((unexist)
(seen 86377
(111823 . 118651)))
nil
((modseq)
(uidvalidity . "1180109607")
(active 1 . 118651)
(permanent-flags %Answered %Flagged %Draft %Deleted %Seen NonJunk %*)
total-expire
(expiry-wait . 2)))

There are no unexpired articles at all in that group; entering it simply
exits back to the group buffer after a long pause at "Expiring
articles...". Stepping through gnus-summary-expire-articles shows it
iterating from 1 to, well, I assume 111822 but I didn't stick around to
find out.

- J<

[Lars Ingebrigtsen]

Post by Jason L Tibbitts III
("linux-wireless" 3
((1 . 118651))
((unexist)
(seen 86377
(111823 . 118651)))

[...]

Post by Jason L Tibbitts III
There are no unexpired articles at all in that group; entering it simply
exits back to the group buffer after a long pause at "Expiring
articles...". Stepping through gnus-summary-expire-articles shows it
iterating from 1 to, well, I assume 111822 but I didn't stick around to
find out.

That group info seems incomplete. The "unexist" list is empty, which
means that Gnus thinks that all those read articles exist on the server,
so it tries to expire them.

`M-g' on the group should fix this, however...

[Jason L Tibbitts III]

LI> That group info seems incomplete. The "unexist" list is empty,
LI> which means that Gnus thinks that all those read articles exist on
LI> the server, so it tries to expire them.

That's what I figured.

LI> `M-g' on the group should fix this, however...

And indeed it did. I expect that it fixed the last one, too. I'll just
do that over all of my groups and if I can find another one that's slow
even after that, I'll worry about it then.

- J<