* Checking new mail very slow with current CVS
@ 2001-12-25 6:49 Russ Allbery
2001-12-25 13:36 ` Simon Josefsson
0 siblings, 1 reply; 19+ messages in thread
From: Russ Allbery @ 2001-12-25 6:49 UTC (permalink / raw)
I just upgraded to the current CVS version of Gnus so that I could start
playing with nndiary, and I immediately noticed that checking new mail
with "g" is *much* slower than it was under 5.8.7. Does anyone have any
idea what's changed and if there's anything I can do about it? It's slow
enough to be fairly frustrating.
Here's the tail end of the message log; I've marked the two places where
there's a noticeable pause:
nntp read: 22k
nntp read: 22k
nntp read: 22k
nntp read: 22k
nntp read: 22k
nntp read: 22k
nntp read: 22k
nntp read: 22k
nntp read: 23k
===>
Reading active file via nnml...
Opening nnml server...
Opening nnml server...done
nnml: Reading incoming mail from maildir...
nnml: Reading incoming mail (no new mail)...done
Reading active file via nnml...
Reading active file via nnml...done
Reading active file via nndiary...
Reading active file via nndiary...
Reading active file via nndiary...done
Reading active file from sent via nnml...
Opening nnml server on sent...
Opening nnml server on sent...done
Reading active file from sent via nnml...
Reading active file from sent via nnml...done
Checking new news...
===>
Checking new news...done
The first pause isn't too bad, but the second pause is really noticeable,
and XEmacs does four or six garbage collection passes in the middle of
it. Setting gnus-verbose-backends to 10 doesn't produce any additional
messages, and setting nnml-marks-is-evil to t makes no difference at all.
Setting gnus-debug-on-quit and pressing C-g in the middle of the long
pause gave the following backtrace:
Signaling: (quit)
nnmail-group-pathname("work.watch.registry" "~/Mail/")
nnml-possibly-change-directory("work.watch.registry" "")
nnml-request-group("work.watch.registry" "" t)
gnus-activate-group("nnml:work.watch.registry" nil t)
gnus-get-unread-articles(nil)
gnus-group-get-new-news(nil)
call-interactively(gnus-group-get-new-news)
My *guess* from that is that for some reason activating every nnml group
is taking quite a long time and that 5.8.7 either didn't do that or did it
much more quickly. I have several hundred nnml groups.
A search of the mailing list traffic reveals nothing except a few messages
about marks, which seems unrelated given that I see the same behavior
regardless of whether marks are enabled.
Does anyone have any ideas?
--
Russ Allbery (rra@stanford.edu) <http://www.eyrie.org/~eagle/>
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-25 6:49 Checking new mail very slow with current CVS Russ Allbery
@ 2001-12-25 13:36 ` Simon Josefsson
2001-12-25 22:07 ` Russ Allbery
0 siblings, 1 reply; 19+ messages in thread
From: Simon Josefsson @ 2001-12-25 13:36 UTC (permalink / raw)
Cc: ding
Russ Allbery <rra@stanford.edu> writes:
> Does anyone have any ideas?
M-x elp-instrument-package RET gnus RET (try `mail' and `nn' as well)
and post the M-x elp-results RET.
`c' the C-g'ed backtrace and C-g it a few more times could be useful
as well, to make sure the backtrace reflects what is really spending
all the time.
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-25 13:36 ` Simon Josefsson
@ 2001-12-25 22:07 ` Russ Allbery
2001-12-25 22:15 ` Russ Allbery
2001-12-25 23:11 ` Simon Josefsson
0 siblings, 2 replies; 19+ messages in thread
From: Russ Allbery @ 2001-12-25 22:07 UTC (permalink / raw)
Simon Josefsson <jas@extundo.com> writes:
> Russ Allbery <rra@stanford.edu> writes:
>> Does anyone have any ideas?
> M-x elp-instrument-package RET gnus RET (try `mail' and `nn' as well)
> and post the M-x elp-results RET.
You make this sound so easy. :)
After fighting with this for about twenty minutes, I finally managed to
load all of the portions of Gnus it wanted loaded and then kept doing
elp-instrument-package over and over until it stopped complaining about
invalid arguments. It then broke most of Gnus's keymaps as near as I
could tell, but I still managed to check new mail and save the results.
If elp-instrument-package is supposed to actually work more smoothly than
that, one of the Gnus developers may want to try it and make whatever
changes to Gnus are necessary to make it work better, because right now
it's a complete mess.
Anyway, here are the results. I'll try to get this working with nnml as
well, but no guarantees given all the trouble I had getting this.
Function Name Call Count Elapsed Time Average Time
====================================== ========== ============ ============
gnus-group-get-new-news 1 5.8076979999 5.8076979999
gnus-get-unread-articles 1 3.6845229999 3.6845229999
gnus-read-active-file 1 1.7725740000 1.7725740000
gnus-read-active-file-1 4 1.7713559999 0.4428389999
gnus-read-active-file-2 1 1.3952470000 1.3952470000
gnus-activate-group 231 1.3869699999 0.0060041991
gnus-retrieve-groups 1 1.3493820000 1.3493820000
gnus-group-list-groups 1 0.3495850000 0.3495850000
gnus-group-prepare-flat 1 0.3431689999 0.3431689999
gnus-group-insert-group-line 32 0.3019759999 0.0094367499
gnus-server-opened 237 0.2143719999 0.0009045232
gnus-server-extend-method 458 0.1936130000 0.0004227358
gnus-range-length 224 0.1873809999 0.0008365223
gnus-uncompress-range 224 0.1754580000 0.0007832946
gnus-active-to-gnus-format 4 0.1065650000 0.0266412500
gnuserv-kill-buffer-query-function 686 0.0789320000 0.0001150612
gnuserv-kill-buffer-function 686 0.0602279999 8.779...e-05
gnus-run-hooks 37 0.0520300000 0.0014062162
gnus-group-highlight-line 32 0.0495860000 0.0015495625
gnus-request-scan 3 0.0464609999 0.0154869999
gnus-request-list 3 0.0454999999 0.0151666666
gnus-check-backend-function 480 0.0414509999 8.635...e-05
gnuserv-buffer-p 686 0.0397180000 5.789...e-05
gnus-server-to-method 332 0.0292130000 8.799...e-05
gnus-point-at-eol 1199 0.0199929999 1.667...e-05
gnus-get-function 472 0.0186919999 3.960...e-05
gnus-add-text-properties 32 0.0186399999 0.0005824999
gnus-xmas-add-text-properties 32 0.0169740000 0.0005304375
gnus-put-text-property-excluding-characters-with-faces 32 0.0166280000 0.0005196250
gnuserv-buffer-clients 686 0.0165809999 2.417...e-05
gnus-put-text-property 64 0.0165439999 0.0002584999
gnus-server-get-method 477 0.0135709999 2.845...e-05
gnus-xmas-put-text-property 64 0.0129499999 0.0002023437
gnus-group-prepare-logic 480 0.0099389999 2.070...e-05
gnus-message 16 0.0084930000 0.0005308125
gnus-group-timestamp-delta 32 0.0065569999 0.0002049062
gnus-correct-length 64 0.0061730000 9.645...e-05
gnus-check-server 6 0.0050119999 0.0008353333
gnus-server-status 237 0.0048550000 2.048...e-05
gnus-update-format-specifications 1 0.0044170000 0.0044170000
gnus-group-group-name 33 0.0042439999 0.0001286060
gnus-group-get-parameter 32 0.0041570000 0.0001299062
gnus-byte-compile 1 0.0039120000 0.0039120000
gnus-parse-format 2 0.0036509999 0.0018254999
gnus-server-add-address 102 0.0036179999 3.547...e-05
gnus-extent-start-open 32 0.0033649999 0.0001051562
gnus-parse-complex-format 1 0.0026950000 0.0026950000
gnus-complex-form-to-spec 2 0.0025489999 0.0012744999
gnus-parse-simple-format 4 0.0024790000 0.0006197500
gnus-group-parameter-value 33 0.0020860000 6.321...e-05
gnus-xmas-extent-start-open 32 0.0018090000 5.653...e-05
gnus-char-width 74 0.0017540000 2.370...e-05
gnus-group-name-charset 32 0.0017379999 5.431...e-05
gnus-group-prefixed-name 5 0.0016019999 0.0003203999
gnus-group-name-decode 64 0.0013710000 2.142...e-05
gnus-open-server 2 0.0010649999 0.0005324999
gnus-server-equal 11 0.0006599999 5.999...e-05
gnus-group-set-mode-line 2 0.0006039999 0.0003019999
gnus-find-method-for-group 10 0.0005909999 5.909...e-05
gnus-group-remove-excess-properties 32 0.0005199999 1.624...e-05
gnus-point-at-bol 34 0.0005029999 1.479...e-05
gnus-master-read-slave-newsrc 1 0.0003789999 0.0003789999
gnus-continuum-version 1 0.0003570000 0.0003570000
gnus-group-position-point 1 0.0002900000 0.0002900000
gnus-methods-using 5 0.0002560000 5.120...e-05
gnus-mode-line-buffer-identification 2 0.0002450000 0.0001225000
gnus-goto-colon 1 0.0002369999 0.0002369999
gnus-buffer-live-p 11 0.0002359999 2.145...e-05
gnus-set-work-buffer 5 0.0002290000 4.580...e-05
gnus-make-directory 2 0.0001980000 9.900...e-05
gnus-update-read-articles 2 0.0001589999 7.949...e-05
gnus-xmas-mode-line-buffer-identification 2 0.0001370000 6.850...e-05
gnus-parse-active 1 0.0001080000 0.0001080000
gnus-group-setup-buffer 1 7.800...e-05 7.800...e-05
gnus-display-time-event-handler 1 7.600...e-05 7.600...e-05
gnus-correct-pad-form 2 6.599...e-05 3.299...e-05
gnus-group-default-level 2 4.500...e-05 2.250...e-05
gnus-undo-boundary 2 3.699...e-05 1.849...e-05
gnus-mouse-face-function 1 2.599...e-05 2.599...e-05
gnus-get-buffer-create 1 2.300...e-05 2.300...e-05
gnus-boundp 1 2.200...e-05 2.200...e-05
gnus-archive-server-wanted-p 1 1.799...e-05 1.799...e-05
gnus-add-buffer 1 1.699...e-05 1.699...e-05
--
Russ Allbery (rra@stanford.edu) <http://www.eyrie.org/~eagle/>
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-25 22:07 ` Russ Allbery
@ 2001-12-25 22:15 ` Russ Allbery
2001-12-25 23:11 ` Simon Josefsson
1 sibling, 0 replies; 19+ messages in thread
From: Russ Allbery @ 2001-12-25 22:15 UTC (permalink / raw)
Russ Allbery <rra@Stanford.EDU> writes:
> Anyway, here are the results. I'll try to get this working with nnml as
> well, but no guarantees given all the trouble I had getting this.
Here are the nnml results; those were much easier to get.
Function Name Call Count Elapsed Time Average Time
====================================== ========== ============ ============
nnml-request-update-info 228 0.9812729999 0.0043038289
nnml-possibly-change-directory 458 0.7332279998 0.0016009344
nnml-marks-changed-p 228 0.4948360000 0.0021703333
nnml-request-group 228 0.4659119999 0.0020434736
nnml-request-scan 2 0.2299389999 0.1149694999
nnml-request-list 3 0.0397420000 0.0132473333
nnml-open-marks 15 0.0346749999 0.0023116666
nnml-save-mail 1 0.0268789999 0.0268789999
nnml-server-opened 688 0.0228669999 3.323...e-05
nnml-save-nov 1 0.0155460000 0.0155460000
nnml-add-nov 1 0.0072329999 0.0072329999
nnml-open-nov 1 0.0069779999 0.0069779999
nnml-get-nov-buffer 1 0.0069159999 0.0069159999
nnml-open-server 12 0.0048450000 0.0004037500
nnml-parse-head 1 0.0018419999 0.0018419999
nnml-active-number 1 0.0014040000 0.0014040000
nnml-possibly-create-directory 1 0.0011759999 0.0011759999
--
Russ Allbery (rra@stanford.edu) <http://www.eyrie.org/~eagle/>
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-25 22:07 ` Russ Allbery
2001-12-25 22:15 ` Russ Allbery
@ 2001-12-25 23:11 ` Simon Josefsson
2001-12-26 0:41 ` Russ Allbery
1 sibling, 1 reply; 19+ messages in thread
From: Simon Josefsson @ 2001-12-25 23:11 UTC (permalink / raw)
Cc: ding
Russ Allbery <rra@stanford.edu> writes:
>> M-x elp-instrument-package RET gnus RET (try `mail' and `nn' as well)
>> and post the M-x elp-results RET.
>
> You make this sound so easy. :)
It is easy. elp.el under XEmacs was broken. I've sent a patch.
> Function Name Call Count Elapsed Time Average Time
> ====================================== ========== ============ ============
> gnus-group-get-new-news 1 5.8076979999 5.8076979999
> gnus-get-unread-articles 1 3.6845229999 3.6845229999
> gnus-read-active-file 1 1.7725740000 1.7725740000
> Function Name Call Count Elapsed Time Average Time
> ====================================== ========== ============ ============
> nnml-request-update-info 228 0.9812729999 0.0043038289
> nnml-possibly-change-directory 458 0.7332279998 0.0016009344
> nnml-marks-changed-p 228 0.4948360000 0.0021703333
Is 5.8 seconds slow? I guess the new marks stuff makes up for 1
second of that time. Hm. But `nnml-request-update-info' takes 0.5
seconds longer than `nnml-marks-changed-p' which should only happen
when Gnus starts the first time (or if some other Gnus changed the
files). Then the marks stuff should only be bound by the extra time
spent in `nnml-marks-changed-p'. You could try adding a
'nnml-marks-is-evil' server parameter.
But maybe something else has changed as well that makes things slow.
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-25 23:11 ` Simon Josefsson
@ 2001-12-26 0:41 ` Russ Allbery
2001-12-26 13:56 ` Simon Josefsson
0 siblings, 1 reply; 19+ messages in thread
From: Russ Allbery @ 2001-12-26 0:41 UTC (permalink / raw)
Simon Josefsson <jas@extundo.com> writes:
> It is easy. elp.el under XEmacs was broken. I've sent a patch.
Cool, thanks.
> Is 5.8 seconds slow?
Yes, it's roughly five times longer than it took under 5.8.7 as an
unmeasured estimate. The slowdown was really dramatic; it's not just a
matter of a half-second here and there.
> I guess the new marks stuff makes up for 1 second of that time. Hm.
> But `nnml-request-update-info' takes 0.5 seconds longer than
> `nnml-marks-changed-p' which should only happen when Gnus starts the
> first time (or if some other Gnus changed the files). Then the marks
> stuff should only be bound by the extra time spent in
> `nnml-marks-changed-p'. You could try adding a 'nnml-marks-is-evil'
> server parameter.
I'm not quite following what you're saying here; do you think this is due
to marks? Setting nnml-marks-is-evil and then pressing "g" again resulted
in no noticeable time difference, but is that too late to change the
setting?
--
Russ Allbery (rra@stanford.edu) <http://www.eyrie.org/~eagle/>
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-26 0:41 ` Russ Allbery
@ 2001-12-26 13:56 ` Simon Josefsson
2001-12-26 21:32 ` Russ Allbery
2001-12-27 10:04 ` Russ Allbery
0 siblings, 2 replies; 19+ messages in thread
From: Simon Josefsson @ 2001-12-26 13:56 UTC (permalink / raw)
Cc: ding
Russ Allbery <rra@stanford.edu> writes:
>> Is 5.8 seconds slow?
>
> Yes, it's roughly five times longer than it took under 5.8.7 as an
> unmeasured estimate. The slowdown was really dramatic; it's not just a
> matter of a half-second here and there.
Then probably the marks stuff isn't to blame. Hm. For comparison,
could you get the similar elp results from Gnus 5.8.7? (Be sure to
not read lots of mail using it, those marks will be lost when you
revert to Oort Gnus. Maybe I should fix this.)
>> I guess the new marks stuff makes up for 1 second of that time. Hm.
>> But `nnml-request-update-info' takes 0.5 seconds longer than
>> `nnml-marks-changed-p' which should only happen when Gnus starts the
>> first time (or if some other Gnus changed the files). Then the marks
>> stuff should only be bound by the extra time spent in
>> `nnml-marks-changed-p'. You could try adding a 'nnml-marks-is-evil'
>> server parameter.
>
> I'm not quite following what you're saying here; do you think this is due
> to marks? Setting nnml-marks-is-evil and then pressing "g" again resulted
> in no noticeable time difference, but is that too late to change the
> setting?
It should make it 1s (or .5s) faster judging from your elp results. If
you instrument it, you should see that `nnml-request-update-info' and
`nnml-marks-changed-p' doesn't take any measurable time, if
`nnml-marks-is-evil' is non-nil.
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-26 13:56 ` Simon Josefsson
@ 2001-12-26 21:32 ` Russ Allbery
2001-12-26 21:55 ` Simon Josefsson
` (2 more replies)
2001-12-27 10:04 ` Russ Allbery
1 sibling, 3 replies; 19+ messages in thread
From: Russ Allbery @ 2001-12-26 21:32 UTC (permalink / raw)
Simon Josefsson <jas@extundo.com> writes:
> Then probably the marks stuff isn't to blame. Hm. For comparison,
> could you get the similar elp results from Gnus 5.8.7? (Be sure to not
> read lots of mail using it, those marks will be lost when you revert to
> Oort Gnus. Maybe I should fix this.)
Can I get a copy of that patch to elp.el? It will make that process a lot
less painful.
--
Russ Allbery (rra@stanford.edu) <http://www.eyrie.org/~eagle/>
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-26 21:32 ` Russ Allbery
@ 2001-12-26 21:55 ` Simon Josefsson
2001-12-26 23:26 ` Steve Youngs
2002-01-03 18:59 ` Jan Vroonhof
2 siblings, 0 replies; 19+ messages in thread
From: Simon Josefsson @ 2001-12-26 21:55 UTC (permalink / raw)
Cc: ding
Russ Allbery <rra@stanford.edu> writes:
> Can I get a copy of that patch to elp.el? It will make that process a lot
> less painful.
If you have Emacs installed, you can probably use that version,
otherwise:
http://list-archive.xemacs.org/xemacs-patches/200112/msg00199.html
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-26 21:32 ` Russ Allbery
2001-12-26 21:55 ` Simon Josefsson
@ 2001-12-26 23:26 ` Steve Youngs
2002-01-03 18:59 ` Jan Vroonhof
2 siblings, 0 replies; 19+ messages in thread
From: Steve Youngs @ 2001-12-26 23:26 UTC (permalink / raw)
|--==> "RA" == Russ Allbery <rra@stanford.edu> writes:
RA> Can I get a copy of that patch to elp.el? It will make that process a lot
RA> less painful.
I've just uploaded a new 'xemacs-devel' package that has this patch
applied to elp.el.
/ftp.xemacs.org:/pub/xemacs/beta/experimental/packages/
--
|---<Steve Youngs>---------------<GnuPG KeyID: 10D5C9C5>---|
| XEmacs - It's not just an editor. |
| It's a way of life. |
|------------------------------------<youngs@xemacs.org>---|
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-26 13:56 ` Simon Josefsson
2001-12-26 21:32 ` Russ Allbery
@ 2001-12-27 10:04 ` Russ Allbery
2001-12-27 15:33 ` Simon Josefsson
1 sibling, 1 reply; 19+ messages in thread
From: Russ Allbery @ 2001-12-27 10:04 UTC (permalink / raw)
Simon Josefsson <jas@extundo.com> writes:
> Then probably the marks stuff isn't to blame. Hm. For comparison,
> could you get the similar elp results from Gnus 5.8.7? (Be sure to not
> read lots of mail using it, those marks will be lost when you revert to
> Oort Gnus. Maybe I should fix this.)
Okay, the new elp helped me track down part of the problem; 1 second of
the time was nndiary. I only had one article in it, so that seems a bit
excessive. I've stopped using that for the time being, since the delay is
more annoying to me than the new features it offers.
However, the speed difference is still very noticeable. What follows is
two elp-results from instrumenting both "gnus" and "nn"; the first is from
Oort (CVS pull as of a few days ago) and the second is from 5.8.7.
Note that checking new mail takes 3.9 seconds for Oort and 0.9 seconds for
Gnus 5.8.7, so it's about 4.7 times slower; my estimate was just about
right on. Note also that 5.8.7 never runs a whole bunch of functions that
Oort runs several hundred times, apparently once for every group that I
have in my newsrc.eld.
Function Name Call Count Elapsed Time Average Time
====================================== ========== ============ ============
gnus-group-get-new-news 1 3.883442 3.883442
gnus-get-unread-articles 1 1.965818 1.965818
gnus-read-active-file 1 1.656048 1.656048
gnus-read-active-file-1 3 1.654937 0.5516456666
gnus-read-active-file-2 1 1.434889 1.434889
gnus-retrieve-groups 1 1.388825 1.388825
nntp-retrieve-groups 1 1.388692 1.388692
nntp-accept-response 251 1.277373 0.0050891354
nntp-accept-process-output 251 1.259354 0.0050173466
nnmail-group-pathname 644 1.2270809999 0.0019054052
nnml-possibly-change-directory 427 0.9667099999 0.0022639578
nnml-request-update-info 213 0.9637049999 0.0045244366
gnus-activate-group 215 0.8194799999 0.0038115348
nnml-request-group 213 0.5900420000 0.0027701502
nnml-marks-changed-p 213 0.5039689999 0.0023660516
gnus-group-list-groups 1 0.260599 0.260599
gnus-group-prepare-flat 1 0.254833 0.254833
nnml-server-opened 641 0.1659939999 0.0002589609
gnus-server-opened 220 0.1468420000 0.0006674636
nnoo-server-opened 647 0.1366290000 0.0002111731
gnus-request-list 2 0.133441 0.0667205
nnml-request-list 1 0.13243 0.13243
nnmail-get-active 2 0.130874 0.065437
nnmail-parse-active 2 0.130755 0.0653775000
gnus-group-insert-group-line 30 0.11916 0.0039720000
gnus-group-prepare-logic 479 0.1026369999 0.0002142734
gnus-active-to-gnus-format 3 0.0843640000 0.0281213333
nnheader-message 144 0.0661179999 0.0004591527
gnus-run-hooks 33 0.0455109999 0.0013791212
gnus-group-highlight-line 30 0.0435869999 0.0014529
nnheader-replace-duplicate-chars-in-st 644 0.0382320000 5.936...e-05
gnus-check-backend-function 464 0.0295479999 6.368...e-05
gnus-server-to-method 316 0.0217809999 6.892...e-05
gnus-range-length 210 0.0177750000 8.464...e-05
gnus-add-text-properties 30 0.015636 0.0005212
gnus-put-text-property-excluding-chara 30 0.015017 0.0005005666
gnus-put-text-property 60 0.014384 0.0002397333
gnus-xmas-add-text-properties 30 0.014309 0.0004769666
nnheader-translate-file-chars 644 0.0133309999 2.070...e-05
gnus-get-function 436 0.0126889999 2.910...e-05
gnus-server-extend-method 443 0.0119769999 2.703...e-05
nnheader-report 217 0.011825 5.449...e-05
gnus-xmas-put-text-property 60 0.0117139999 0.0001952333
gnus-request-scan 2 0.0089 0.00445
gnus-server-get-method 474 0.0087679999 1.849...e-05
nnml-request-scan 1 0.0081600000 0.0081600000
nnmail-get-new-mail 2 0.008041 0.0040205
gnus-uncompress-range 210 0.0078769999 3.750...e-05
nndraft-request-group 2 0.006551 0.0032755
nntp-find-connection-buffer 254 0.0064679999 2.546...e-05
nnoo-parent-function 3 0.005563 0.0018543333
gnus-group-timestamp-delta 30 0.005466 0.0001822
gnus-correct-length 60 0.0052110000 8.685...e-05
gnus-message 9 0.004787 0.0005318888
nnoo-current-server 654 0.0047260000 7.226...e-06
gnus-point-at-eol 715 0.0044679999 6.248...e-06
gnus-update-format-specifications 1 0.004287 0.004287
nnmh-request-group 2 0.004005 0.0020025
gnus-byte-compile 1 0.003837 0.003837
gnus-group-group-name 31 0.0035369999 0.0001140967
gnus-parse-format 2 0.00351 0.001755
gnus-group-get-parameter 30 0.0034529999 0.0001151
gnus-extent-start-open 30 0.002645 8.816...e-05
gnus-parse-complex-format 1 0.002509 0.002509
gnus-complex-form-to-spec 2 0.002336 0.001168
gnus-parse-simple-format 4 0.00229 0.0005725
nndraft-request-update-info 2 0.002257 0.0011285
gnus-server-status 220 0.0022020000 1.000...e-05
nnmail-find-file 2 0.002086 0.001043
gnus-server-add-address 63 0.001772 2.812...e-05
gnus-group-parameter-value 30 0.001677 5.590...e-05
gnus-check-server 5 0.001611 0.0003222
gnus-xmas-extent-start-open 30 0.0014 4.666...e-05
nnmh-possibly-change-directory 2 0.001399 0.0006995
nnheader-init-server-buffer 3 0.001346 0.0004486666
gnus-char-width 71 0.001244 1.752...e-05
gnus-group-name-charset 30 0.001194 3.98e-05
gnus-group-prefixed-name 4 0.001186 0.0002965
nndraft-possibly-change-group 4 0.001181 0.0002952499
nndraft-open-server 2 0.000924 0.000462
nnmail-activate 1 0.000853 0.000853
nnoo-change-server 5 0.0008430000 0.0001686
nndiary-request-list 1 0.00076 0.00076
gnus-group-name-decode 60 0.0007439999 1.239...e-05
nndraft-close-group 1 0.000614 0.000614
nntp-server-opened 4 0.000578 0.0001445
nndraft-articles 2 0.000553 0.0002765
gnus-group-set-mode-line 2 0.000547 0.0002735
nndiary-request-scan 1 0.000476 0.000476
gnus-server-equal 9 0.000433 4.811...e-05
gnus-find-method-for-group 7 0.000432 6.171...e-05
gnus-continuum-version 1 0.000357 0.000357
gnus-master-read-slave-newsrc 1 0.000332 0.000332
nntp-possibly-change-group 1 0.000299 0.000299
nnmh-server-opened 2 0.000287 0.0001435
gnus-group-position-point 1 0.000263 0.000263
nndiary-server-opened 2 0.000223 0.0001115
gnus-group-remove-excess-properties 30 0.0002210000 7.366...e-06
gnus-goto-colon 1 0.00022 0.00022
nndraft-server-opened 2 0.000217 0.0001085
gnus-mode-line-buffer-identification 2 0.000209 0.0001045
gnus-point-at-bol 32 0.0001860000 5.812...e-06
gnus-set-work-buffer 5 0.00018 3.599...e-05
gnus-methods-using 4 0.000162 4.05e-05
nndiary-possibly-change-directory 1 0.000161 0.000161
gnus-make-directory 2 0.000149 7.449...e-05
gnus-buffer-live-p 11 0.000139 1.263...e-05
nnheader-insert 1 0.000133 0.000133
gnus-update-read-articles 2 0.000132 6.600...e-05
gnus-xmas-mode-line-buffer-identificat 2 0.000114 5.7e-05
gnus-parse-active 1 0.000109 0.000109
nnoo-backend 3 0.000103 3.433...e-05
nnoo-parents 11 9.500...e-05 8.636...e-06
nnmail-get-value 2 7.500...e-05 3.75e-05
gnus-group-setup-buffer 1 6.1e-05 6.1e-05
gnus-display-time-event-handler 1 6e-05 6e-05
nnheader-concat 2 5.6e-05 2.8e-05
gnus-correct-pad-form 2 4.7e-05 2.35e-05
nnoo-variables 5 4.4e-05 8.8e-06
gnus-group-default-level 2 3e-05 1.5e-05
nnheader-re-read-dir 2 2.8e-05 1.4e-05
gnus-undo-boundary 2 2.7e-05 1.35e-05
nntp-find-connection 1 2.3e-05 2.3e-05
gnus-mouse-face-function 1 1.6e-05 1.6e-05
nnmail-cache-close 1 1.6e-05 1.6e-05
gnus-boundp 1 1.3e-05 1.3e-05
gnus-get-buffer-create 1 1.3e-05 1.3e-05
nnmail-cache-open 1 1.3e-05 1.3e-05
nnmh-close-group 1 9e-06 9e-06
gnus-archive-server-wanted-p 1 8e-06 8e-06
Function Name Call Count Elapsed Time Average Time
====================================== ========== ============ ============
gnus-group-get-new-news 1 0.832394 0.832394
gnus-read-active-file 1 0.486088 0.486088
gnus-read-active-file-1 2 0.485121 0.2425605
gnus-read-active-file-2 1 0.334234 0.334234
gnus-group-list-groups 1 0.217655 0.217655
gnus-group-prepare-flat 1 0.210033 0.210033
gnus-retrieve-groups 1 0.2022969999 0.2022969999
nntp-retrieve-groups 1 0.202164 0.202164
gnus-group-insert-group-line 31 0.20207 0.0065183870
gnus-active-to-gnus-format 2 0.170295 0.0851475
gnus-get-unread-articles 1 0.127812 0.127812
nntp-accept-response 3 0.102748 0.0342493333
nntp-accept-process-output 3 0.102511 0.0341703333
gnus-point-at-eol 947 0.0928039999 9.799...e-05
nnml-request-list 2 0.060771 0.0303855
nnmail-get-active 2 0.057748 0.028874
nnmail-parse-active 2 0.057629 0.0288145
gnus-run-hooks 34 0.0513209999 0.0015094411
gnus-group-highlight-line 31 0.0492290000 0.0015880322
gnus-request-scan 1 0.043761 0.043761
nnml-request-scan 1 0.043624 0.043624
nnmail-get-new-mail 1 0.043335 0.043335
nnmail-activate 1 0.031564 0.031564
gnus-request-list 1 0.030109 0.030109
gnus-range-length 217 0.0204670000 9.431...e-05
gnus-put-text-property-excluding-chara 31 0.017611 0.0005680967
gnus-put-text-property 62 0.0173499999 0.0002798387
gnus-add-text-properties 31 0.016529 0.0005331935
gnus-server-to-method 248 0.015055 6.070...e-05
gnus-xmas-add-text-properties 31 0.015027 0.0004847419
gnus-xmas-put-text-property 62 0.013915 0.0002244354
gnus-server-get-method 458 0.0098189999 2.143...e-05
gnus-uncompress-range 217 0.0087940000 4.052...e-05
nnmail-cache-open 1 0.008541 0.008541
gnus-server-extend-method 299 0.0084680000 2.832...e-05
nnheader-insert-file-contents 1 0.0081880000 0.0081880000
gnus-activate-group 2 0.006648 0.003324
gnus-group-timestamp-delta 31 0.0063489999 0.0002048064
nnoo-parent-function 3 0.005591 0.0018636666
nndraft-request-group 2 0.005158 0.002579
gnus-group-get-parameter 31 0.0040149999 0.0001295161
gnus-group-group-name 32 0.003924 0.000122625
nnmh-request-group 2 0.003831 0.0019155
gnus-message 6 0.00321 0.000535
gnus-extent-start-open 31 0.0030330000 9.783...e-05
nnmail-find-file 2 0.002793 0.0013965
nnheader-message 4 0.002443 0.0006107500
nndraft-request-update-info 2 0.00235 0.001175
gnus-server-add-address 63 0.0019380000 3.076...e-05
gnus-group-parameter-value 31 0.0018500000 5.967...e-05
gnus-xmas-extent-start-open 31 0.001615 5.209...e-05
gnus-server-opened 6 0.001509 0.0002515
nnmail-group-pathname 4 0.001491 0.00037275
nnmh-possibly-change-directory 2 0.001384 0.0006919999
gnus-check-server 4 0.001242 0.0003105
nnheader-init-server-buffer 3 0.000967 0.0003223333
gnus-group-prefixed-name 3 0.000934 0.0003113333
nnoo-change-server 4 0.000685 0.00017125
gnus-correct-length 62 0.0006330000 1.020...e-05
nndraft-possibly-change-group 2 0.00062 0.00031
nndraft-close-group 1 0.000588 0.000588
gnus-group-set-mode-line 2 0.000553 0.0002765
nndraft-articles 2 0.000536 0.000268
nndraft-open-server 1 0.000479 0.000479
nnoo-server-opened 6 0.000468 7.8e-05
nntp-server-opened 4 0.000421 0.00010525
gnus-master-read-slave-newsrc 1 0.000396 0.000396
gnus-find-method-for-group 7 0.000376 5.371...e-05
gnus-server-equal 7 0.000359 5.128...e-05
gnus-group-remove-excess-properties 31 0.0003020000 9.741...e-06
nnmh-server-opened 2 0.000281 0.0001405
gnus-point-at-bol 33 0.0002630000 7.969...e-06
nntp-possibly-change-group 1 0.000262 0.000262
nnml-server-opened 2 0.000255 0.0001275
nndraft-server-opened 2 0.00024 0.00012
gnus-mode-line-buffer-identification 2 0.000222 0.000111
gnus-update-format-specifications 1 0.00021 0.00021
gnus-get-function 6 0.000194 3.233...e-05
nnml-possibly-change-directory 1 0.000188 0.000188
nntp-find-connection-buffer 6 0.000186 3.1e-05
nnheader-replace-duplicate-chars-in-st 4 0.000172 4.3e-05
nnheader-report 3 0.000166 5.533...e-05
gnus-update-read-articles 2 0.000146 7.3e-05
gnus-make-directory 2 0.000142 7.1e-05
gnus-parse-active 2 0.000133 6.649...e-05
nnoo-current-server 13 0.000132 1.015...e-05
nnheader-replace-chars-in-string 4 0.000131 3.275e-05
nnoo-backend 3 0.000131 4.366...e-05
gnus-group-position-point 1 0.000125 0.000125
gnus-xmas-mode-line-buffer-identificat 2 0.000124 6.199...e-05
gnus-methods-using 3 0.000123 4.1e-05
nnoo-parents 10 0.000118 1.18e-05
nnheader-insert 1 0.000114 0.000114
nnheader-translate-file-chars 4 8.3e-05 2.075e-05
gnus-server-status 6 8.2e-05 1.366...e-05
gnus-goto-colon 1 8.000...e-05 8.000...e-05
gnus-check-backend-function 1 6.999...e-05 6.999...e-05
gnus-group-setup-buffer 1 6.999...e-05 6.999...e-05
gnus-buffer-live-p 3 5.099...e-05 1.7e-05
nnoo-variables 4 4.8e-05 1.2e-05
nnmail-get-value 1 4.1e-05 4.1e-05
nnheader-concat 1 3.3e-05 3.3e-05
gnus-group-default-level 2 3.1e-05 1.55e-05
nntp-find-connection 1 2.6e-05 2.6e-05
nnmail-cache-close 1 2e-05 2e-05
nnheader-re-read-dir 1 1.8e-05 1.8e-05
gnus-get-buffer-create 1 1.5e-05 1.5e-05
gnus-archive-server-wanted-p 1 1e-05 1e-05
nnmh-close-group 1 1e-05 1e-05
--
Russ Allbery (rra@stanford.edu) <http://www.eyrie.org/~eagle/>
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-27 10:04 ` Russ Allbery
@ 2001-12-27 15:33 ` Simon Josefsson
2002-01-09 17:08 ` Sebastian Krause
0 siblings, 1 reply; 19+ messages in thread
From: Simon Josefsson @ 2001-12-27 15:33 UTC (permalink / raw)
Cc: ding
Russ Allbery <rra@stanford.edu> writes:
> However, the speed difference is still very noticeable. What follows is
> two elp-results from instrumenting both "gnus" and "nn"; the first is from
> Oort (CVS pull as of a few days ago) and the second is from 5.8.7.
Thank you. FWIW, I can reproduce this. Gnus 5.9.0 from Emacs 21 is
faster than Oort Gnus 0.0.4 (8 seconds vs 12 seconds for me). The
following speed things up, but I don't think everything can be blamed
on this. Does it have any effect for you?
--- nntp.el.~6.15.~ Tue Oct 30 18:47:08 2001
+++ nntp.el Thu Dec 27 16:31:50 2001
@@ -396,15 +396,15 @@
nntp-address nntp-port-number nntp-server-buffer
wait-for nnheader-callback-function)
;; If nothing to wait for, still remove possibly echo'ed commands
- (unless wait-for
- (nntp-accept-response)
- (save-excursion
- (set-buffer buffer)
- (goto-char pos)
- (if (looking-at (regexp-quote command))
- (delete-region pos (progn (forward-line 1) (gnus-point-at-bol))))
+; (unless wait-for
+; (nntp-accept-response)
+; (save-excursion
+; (set-buffer buffer)
+; (goto-char pos)
+; (if (looking-at (regexp-quote command))
+; (delete-region pos (progn (forward-line 1) (gnus-point-at-bol))))
+; )))
)))
- ))
(defun nntp-send-command-nodelete (wait-for &rest strings)
"Send STRINGS to server and wait until WAIT-FOR returns."
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-26 21:32 ` Russ Allbery
2001-12-26 21:55 ` Simon Josefsson
2001-12-26 23:26 ` Steve Youngs
@ 2002-01-03 18:59 ` Jan Vroonhof
2002-01-03 19:22 ` Simon Josefsson
2 siblings, 1 reply; 19+ messages in thread
From: Jan Vroonhof @ 2002-01-03 18:59 UTC (permalink / raw)
Russ Allbery <rra@stanford.edu> writes:
> Can I get a copy of that patch to elp.el? It will make that process a lot
> less painful.
You guys are aware that XEmacs has native profiling support (see 'start-profiling')? Although that does not do tree based profiling.
Jan
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2002-01-03 18:59 ` Jan Vroonhof
@ 2002-01-03 19:22 ` Simon Josefsson
2002-01-04 13:00 ` Jan Vroonhof
0 siblings, 1 reply; 19+ messages in thread
From: Simon Josefsson @ 2002-01-03 19:22 UTC (permalink / raw)
Cc: ding
Jan Vroonhof <jvlists@ntlworld.com> writes:
> Russ Allbery <rra@stanford.edu> writes:
>
>> Can I get a copy of that patch to elp.el? It will make that process a lot
>> less painful.
>
> You guys are aware that XEmacs has native profiling support (see
> 'start-profiling')?
Cool! I wasn't aware of it, it seems to give more reliable results.
(Shouldn't `start-profiling' be a interactive function?)
> Although that does not do tree based profiling.
What is that? Does elp do it?
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2002-01-03 19:22 ` Simon Josefsson
@ 2002-01-04 13:00 ` Jan Vroonhof
2002-01-04 15:19 ` Jan Vroonhof
2002-01-05 6:02 ` Russ Allbery
0 siblings, 2 replies; 19+ messages in thread
From: Jan Vroonhof @ 2002-01-04 13:00 UTC (permalink / raw)
Simon Josefsson <jas@extundo.com> writes:
>> You guys are aware that XEmacs has native profiling support (see
>> 'start-profiling')?
>
> Cool! I wasn't aware of it, it seems to give more reliable results.
> (Shouldn't `start-profiling' be a interactive function?)
Possibly... The main interactive use is supposed to be M-x
profile-key-sequence or lisp-eval calls..
>> Although that does not do tree based profiling.
>
> What is that? Does elp do it?
I meant that the fact the current XEmacs profiling only counts time to
the function we are actually in. i.e. in
(def foo ()
bar())
If bar takes 3 seconds that time isn't counted to foo. XEmacs does
this because it is most easy to implement if you do sample based
profiling.
Elp on the other hand attributes the time to both foo and bar. That is
more easy to do if you do wrapping. It would be possible to add this
to XEmacs as well (for instance by walking the stack on each profiling
tick).
True tree based profiling will give you times for each path from the
root in the call tree, i.e. with tell you we spend 3 seconds in bar
when called from foo and 0.5 seconds when called from xyz.
All three are useful. The current XEmacs way is better at spotting
lowlevel hotspots, for instance so we know which C functions to
optimize to make that app go futher. The elp way is better at spotting
higher-level problem (and luckily the loss of accuracy isn't as
important there).
Jan
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2002-01-04 13:00 ` Jan Vroonhof
@ 2002-01-04 15:19 ` Jan Vroonhof
2002-01-05 6:02 ` Russ Allbery
1 sibling, 0 replies; 19+ messages in thread
From: Jan Vroonhof @ 2002-01-04 15:19 UTC (permalink / raw)
Jan Vroonhof <jvlists@ntlworld.com> writes:
> (def foo ()
> bar())
I didn't write this really... Must have been the other me...
Jan
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2002-01-04 13:00 ` Jan Vroonhof
2002-01-04 15:19 ` Jan Vroonhof
@ 2002-01-05 6:02 ` Russ Allbery
1 sibling, 0 replies; 19+ messages in thread
From: Russ Allbery @ 2002-01-05 6:02 UTC (permalink / raw)
Jan Vroonhof <jvlists@ntlworld.com> writes:
> Possibly... The main interactive use is supposed to be M-x
> profile-key-sequence or lisp-eval calls..
I tried to use that and was unable to get any results in a situation where
I was able to get elp to work, and I can't find good documentation on it.
Could you give me a pointer?
--
Russ Allbery (rra@stanford.edu) <http://www.eyrie.org/~eagle/>
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2001-12-27 15:33 ` Simon Josefsson
@ 2002-01-09 17:08 ` Sebastian Krause
2002-01-09 17:42 ` Simon Josefsson
0 siblings, 1 reply; 19+ messages in thread
From: Sebastian Krause @ 2002-01-09 17:08 UTC (permalink / raw)
Cc: Simon Josefsson
Simon Josefsson <jas@extundo.com> writes:
> Russ Allbery <rra@stanford.edu> writes:
>> However, the speed difference is still very noticeable. What follows is
>> two elp-results from instrumenting both "gnus" and "nn"; the first is from
>> Oort (CVS pull as of a few days ago) and the second is from 5.8.7.
>
> Thank you. FWIW, I can reproduce this. Gnus 5.9.0 from Emacs 21 is
> faster than Oort Gnus 0.0.4 (8 seconds vs 12 seconds for me). The
> following speed things up, but I don't think everything can be blamed
> on this. Does it have any effect for you?
I had the same problem with the current CVS and your patch solved my
problem that Gnus takes a long time when I hit 'g' in the Group
buffer. Could anyone please patch the current CVS with Simon's
following patch, it seems to me that this solution isn't in the CVS
yet, because i still had the problem with the current Oort Gnus from
a few hours ago.
> --- nntp.el.~6.15.~ Tue Oct 30 18:47:08 2001
> +++ nntp.el Thu Dec 27 16:31:50 2001
> @@ -396,15 +396,15 @@
> nntp-address nntp-port-number nntp-server-buffer
> wait-for nnheader-callback-function)
> ;; If nothing to wait for, still remove possibly echo'ed commands
> - (unless wait-for
> - (nntp-accept-response)
> - (save-excursion
> - (set-buffer buffer)
> - (goto-char pos)
> - (if (looking-at (regexp-quote command))
> - (delete-region pos (progn (forward-line 1) (gnus-point-at-bol))))
> +; (unless wait-for
> +; (nntp-accept-response)
> +; (save-excursion
> +; (set-buffer buffer)
> +; (goto-char pos)
> +; (if (looking-at (regexp-quote command))
> +; (delete-region pos (progn (forward-line 1) (gnus-point-at-bol))))
> +; )))
> )))
> - ))
>
> (defun nntp-send-command-nodelete (wait-for &rest strings)
> "Send STRINGS to server and wait until WAIT-FOR returns."
Sebastian
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Checking new mail very slow with current CVS
2002-01-09 17:08 ` Sebastian Krause
@ 2002-01-09 17:42 ` Simon Josefsson
0 siblings, 0 replies; 19+ messages in thread
From: Simon Josefsson @ 2002-01-09 17:42 UTC (permalink / raw)
Cc: ding
Sebastian Krause <krause@sdbk.de> writes:
>> Thank you. FWIW, I can reproduce this. Gnus 5.9.0 from Emacs 21 is
>> faster than Oort Gnus 0.0.4 (8 seconds vs 12 seconds for me). The
>> following speed things up, but I don't think everything can be blamed
>> on this. Does it have any effect for you?
>
> I had the same problem with the current CVS and your patch solved my
> problem that Gnus takes a long time when I hit 'g' in the Group
> buffer. Could anyone please patch the current CVS with Simon's
> following patch, it seems to me that this solution isn't in the CVS
> yet, because i still had the problem with the current Oort Gnus from
> a few hours ago.
I'm not sure the change is The Right Thing. It seems as if it is
related to the nntp.el overhaul -- Didier?
^ permalink raw reply [flat|nested] 19+ messages in thread
end of thread, other threads:[~2002-01-09 17:42 UTC | newest]
Thread overview: 19+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2001-12-25 6:49 Checking new mail very slow with current CVS Russ Allbery
2001-12-25 13:36 ` Simon Josefsson
2001-12-25 22:07 ` Russ Allbery
2001-12-25 22:15 ` Russ Allbery
2001-12-25 23:11 ` Simon Josefsson
2001-12-26 0:41 ` Russ Allbery
2001-12-26 13:56 ` Simon Josefsson
2001-12-26 21:32 ` Russ Allbery
2001-12-26 21:55 ` Simon Josefsson
2001-12-26 23:26 ` Steve Youngs
2002-01-03 18:59 ` Jan Vroonhof
2002-01-03 19:22 ` Simon Josefsson
2002-01-04 13:00 ` Jan Vroonhof
2002-01-04 15:19 ` Jan Vroonhof
2002-01-05 6:02 ` Russ Allbery
2001-12-27 10:04 ` Russ Allbery
2001-12-27 15:33 ` Simon Josefsson
2002-01-09 17:08 ` Sebastian Krause
2002-01-09 17:42 ` Simon Josefsson
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).