From mboxrd@z Thu Jan 1 00:00:00 1970 X-Msuck: nntp://news.gmane.io/gmane.emacs.gnus.general/14999 Path: main.gmane.org!not-for-mail From: Eze Ogwuma Newsgroups: gmane.emacs.gnus.general Subject: Re: Gnus as slow as molasses Date: 17 Apr 1998 17:20:01 +0100 Sender: owner-ding@hpc.uh.edu Message-ID: References: NNTP-Posting-Host: coloc-standby.netfonds.no X-Trace: main.gmane.org 1035154103 19488 80.91.224.250 (20 Oct 2002 22:48:23 GMT) X-Complaints-To: usenet@main.gmane.org NNTP-Posting-Date: Sun, 20 Oct 2002 22:48:23 +0000 (UTC) Cc: ding@gnus.org Return-Path: Original-Received: from xemacs.org (xemacs.cs.uiuc.edu [128.174.252.16]) by altair.xemacs.org (8.8.8/8.8.8) with ESMTP id JAA27603 for ; Fri, 17 Apr 1998 09:20:17 -0700 Original-Received: from gizmo.hpc.uh.edu (gizmo.hpc.uh.edu [129.7.102.31]) by xemacs.org (8.8.5/8.8.5) with ESMTP id LAA03972 for ; Fri, 17 Apr 1998 11:26:20 -0500 (CDT) Original-Received: from sina.hpc.uh.edu (sina.hpc.uh.edu [129.7.3.5]) by gizmo.hpc.uh.edu (8.7.6/8.7.3) with ESMTP id LAN21369; Fri, 17 Apr 1998 11:58:22 -0500 Original-Received: by sina.hpc.uh.edu (TLB v0.09a (1.20 tibbs 1996/10/09 22:03:07)); Fri, 17 Apr 1998 11:22:08 -0500 (CDT) Original-Received: from claymore.vcinet.com (claymore.vcinet.com [208.205.12.23]) by sina.hpc.uh.edu (8.7.3/8.7.3) with SMTP id LAA17148 for ; Fri, 17 Apr 1998 11:21:58 -0500 (CDT) Original-Received: (qmail 7924 invoked by uid 504); 17 Apr 1998 16:21:29 -0000 Original-Received: (qmail 7921 invoked from network); 17 Apr 1998 16:21:28 -0000 Original-Received: from mailhost.dircon.co.uk (194.112.32.10) by claymore.vcinet.com with SMTP; 17 Apr 1998 16:21:27 -0000 Original-Received: from typhoon.ncc.co.uk (zcaceog@bh-cw04-013.pool.dircon.co.uk [194.112.52.13]) by mailhost.dircon.co.uk (8.8.5/8.8.7) with ESMTP id RAA14694; Fri, 17 Apr 1998 17:21:24 +0100 (BST) Original-Received: (from zcaceog@localhost) by typhoon.ncc.co.uk (8.8.7/8.8.7) id RAA11221; Fri, 17 Apr 1998 17:20:24 +0100 Original-To: Hrvoje Niksic In-Reply-To: Hrvoje Niksic's message of "17 Apr 1998 13:12:14 +0200" X-Mailer: Gnus v5.6.4/XEmacs 20.4 - "Emerald" Original-Lines: 282 Precedence: list X-Majordomo: 1.94.jlt7 Xref: main.gmane.org gmane.emacs.gnus.general:14999 X-Report-Spam: http://spam.gmane.org/gmane.emacs.gnus.general:14999 Hrvoje Niksic writes: > Eze Ogwuma writes: > > > This additional information was sent to someone as a reply. > > > > The problem isn't opening the group as I rarely select more that 100 > > articles. It's selecting the first article once I'm in the group. > > > > I have this in my .gnus file so I get to choose which article to > > select: > > ;; Don't select the first article automatically > > (setq gnus-auto-select-first nil) > > > > Whichever article I select then takes about 10-15 seconds to > > display. All articles selected after that are almost instantaneous > > whether they are above or below the first article. > > Under XEmacs 20.4 you can use `M-x profile-key-sequence', press a key > (say RET in the Group buffer), and get the results using > `M-x profile-results'. It should give you an idea of where the time > is being spent. Thanks, I was hoping for something like this. The results are below. I think this has something to do with the number of read/unread articles in a group. For some reason, before showing the first article, Gnus parses the article directory twice. There is an strace of some "open" calls at the very end of this message. 1) Gnus thinks one group has ~17600 articles in it with ~7800 unread. It takes around 15-18 seconds to open the first article even when the Summary buffer only has 100 articles in it. 2) A buffer with ~9000 articles of which ~500 are unread takes about 8-11 seconds to select the first article. 3) A buffer with ~3000 articles of which ~2300 are unread takes about 3 seconds to select the first article. 4) A buffer with ~1800 articles of which 16 are unread takes less than 1 second to select the first article. The profiles are for cases 1 and 4. I use the article backlog and this works in all buffers. I've found that exiting a buffer then re-entering and selecting a previously seen article (already in the backlog) is instantaneous. While exiting a buffer then re-entering and selecting a previously unseen article takes the same time as normal. These problems all occur with no .gnus file and only a pointer to my Gnus lisp directories in my .emacs file. ********* Profiles ********* SLOW Function Name Ticks %/Total ======================================= ===== ======= (in garbage collection) 303 20.254 string-match 264 17.647 directory-files 261 17.447 match-string 168 11.230 # 162 10.829 string-to-int 50 3.342 put-char-table 46 3.075 syntax-string-to-code 25 1.671 load-internal 16 1.070 put-text-property 14 0.936 re-search-forward 14 0.936 modify-syntax-entry 13 0.869 insert-buffer-substring 12 0.802 next-single-property-change 11 0.735 mapcar 11 0.735 x-get-resource 11 0.735 check-menu-syntax 9 0.602 text-prop-extent-paste-function 6 0.401 simple-set-syntax-entry 6 0.401 # 5 0.334 x-init-face-from-resources 5 0.334 add-text-properties 4 0.267 init-face-from-resources 4 0.267 logior 4 0.267 char-to-string 4 0.267 # 3 0.201 x-get-resource-and-maybe-bogosity-check 3 0.201 x-bogosity-check-resource 3 0.201 make-extent 2 0.134 looking-at 2 0.134 file-exists-p 2 0.134 syntax-table-p 2 0.134 kill-all-local-variables 2 0.134 custom-initialize-reset 2 0.134 custom-add-to-group 2 0.134 lsh 2 0.134 format 2 0.134 copy-keymap 1 0.067 nnheader-directory-files-safe 1 0.067 nnheader-replace-chars-in-string 1 0.067 gnus-add-text-properties 1 0.067 gnus-put-text-property 1 0.067 eval 1 0.067 run-hook-with-args 1 0.067 buffer-substring-no-properties 1 0.067 gnus-xmas-redefine 1 0.067 gnus-cite-add-face 1 0.067 gnus-article-hide-headers-if-wanted 1 0.067 gnus-article-add-buttons-to-head 1 0.067 gnus-article-highlight-headers 1 0.067 set-extent-face 1 0.067 redisplay-echo-area 1 0.067 get-text-property 1 0.067 store-match-data 1 0.067 get-face 1 0.067 face-name 1 0.067 valid-instantiator-p 1 0.067 try-font-name 1 0.067 syntax-designator-chars 1 0.067 get-buffer-create 1 0.067 mime::content-info/rcnum 1 0.067 erase-buffer 1 0.067 canonicalize-inst-list 1 0.067 window-displayed-height 1 0.067 mail-extract-address-components 1 0.067 remove-message 1 0.067 raw-append-message 1 0.067 make-char-table 1 0.067 frob-face-property-1 1 0.067 frob-face-font-2 1 0.067 gnus-mode-string-quote 1 0.067 nnmail-find-file 1 0.067 gnus-point-at-eol 1 0.067 sort-reorder-buffer 1 0.067 get-custom-frame-properties 1 0.067 gnus-configure-frame 1 0.067 frame-type 1 0.067 # 1 0.067 ----------------------------------------------------------- Total 1496 100.00 One tick = 1 ms FAST Function Name Ticks %/Total ======================================= ===== ======= (in garbage collection) 70 22.436 string-match 25 8.013 directory-files 23 7.372 match-string 18 5.769 # 16 5.128 put-text-property 11 3.526 load-internal 10 3.205 re-search-forward 10 3.205 x-get-resource 10 3.205 next-single-property-change 8 2.564 check-menu-syntax 8 2.564 insert-buffer-substring 7 2.244 x-get-resource-and-maybe-bogosity-check 7 2.244 text-prop-extent-paste-function 6 1.923 string-to-int 5 1.603 looking-at 5 1.603 syntax-string-to-code 5 1.603 put-char-table 5 1.603 x-init-face-from-resources 5 1.603 add-text-properties 4 1.282 redisplay-echo-area 3 0.962 x-bogosity-check-resource 3 0.962 map-extents 2 0.641 get-text-property 2 0.641 mapcar 2 0.641 highlight-headers 2 0.641 custom-declare-variable 2 0.641 custom-add-to-group 2 0.641 raw-append-message 2 0.641 std11-field-end 2 0.641 gnus-article-highlight-headers 2 0.641 format 2 0.641 subst-char-in-region 1 0.321 copy-keymap 1 0.321 append-message 1 0.321 gnus-cite-add-face 1 0.321 make-extent 1 0.321 regexp-quote 1 0.321 make-face 1 0.321 init-face-from-resources 1 0.321 valid-instantiator-p 1 0.321 file-exists-p 1 0.321 x-frob-font-slant 1 0.321 modify-syntax-entry 1 0.321 syntax-table-p 1 0.321 gnus-cite-parse 1 0.321 message-next-header 1 0.321 featurep 1 0.321 window-displayed-height 1 0.321 custom-initialize-reset 1 0.321 mime-preview/display-content 1 0.321 custom-declare-face 1 0.321 set-face-underline-p 1 0.321 set-face-property 1 0.321 vectorp 1 0.321 gnus-configure-frame 1 0.321 gnus-all-windows-visible-p 1 0.321 frame-type 1 0.321 lsh 1 0.321 nnml-server-opened 1 0.321 ----------------------------------------------------------- Total 312 100.00 One tick = 1 ms ********* Strace ********* Below is an excerpt from an Strace. I used "script" to record all output and then I typed "strace xemacs" then iconified the window. In another window I used "tail -f typescript |grep open" so that I could see the corresponding open calls as I used Gnus. At this point I enter the redhat.list group: open("/home/zcaceog/News/cache/nnml:redhat.list", O_RDONLY|O_NONBLOCK) = 8 open("/home/zcaceog/Mail/redhat/list/.overview", O_RDONLY) = 8 open("/home/zcaceog/News/cache/nnml:redhat.list/.overview", O_RDONLY) = 8 open("/usr/local/share/xemacs/site-lisp/gnus-score.elc", O_RDONLY) = 8 open("/home/zcaceog/News", O_RDONLY|O_NONBLOCK) = 8 open("/home/zcaceog/News/nnml:redhat.list.SCORE", O_RDONLY) = 8 open("/home/zcaceog/News/nnml:redhat.list.SCORE", O_RDONLY) = 8 open("/etc/localtime", O_RDONLY) = 8 Here I select the first article: open("/usr/local/share/xemacs/site-lisp/gnus-bcklg.elc", O_RDONLY) = 8 open("/usr/local/share/xemacs/site-lisp/gnus-async.elc", O_RDONLY) = 8 open("/home/zcaceog/Mail/redhat/list", O_RDONLY|O_NONBLOCK) = 8 open("/home/zcaceog/Mail/redhat/list", O_RDONLY|O_NONBLOCK) = 8 open("/home/zcaceog/Mail/redhat/list/17542", O_RDONLY) = 8 open("/usr/lib/xemacs-20.4/lisp/utils/highlight-headers.elc", O_RDONLY) = 8 open("/usr/local/share/xemacs/site-lisp/gnus-cite.elc", O_RDONLY) = 8 open("/usr/lib/xemacs-20.4/lisp/prim/sort.elc", O_RDONLY) = 8 open("/usr/lib/xemacs-20.4/lisp/utils/mail-extr.elc", O_RDONLY) = 8 The second, third, fourth ... open("/home/zcaceog/Mail/redhat/list/17557", O_RDONLY) = 8 open("/home/zcaceog/Mail/redhat/list/17565", O_RDONLY) = 8 open("/home/zcaceog/Mail/redhat/list/17568", O_RDONLY) = 8 open("/home/zcaceog/Mail/redhat/list/17581", O_RDONLY) = 8 open("/home/zcaceog/Mail/redhat/list/17567", O_RDONLY) = 8 open("/home/zcaceog/Mail/redhat/list/17566", O_RDONLY) = 8 Here I enter the hurricane group: open("/home/zcaceog/News/cache/nnml:hurricane", O_RDONLY|O_NONBLOCK) = 8 open("/home/zcaceog/Mail/hurricane/.overview", O_RDONLY) = 8 open("/home/zcaceog/News/cache/nnml:hurricane/.overview", O_RDONLY) = 8 open("/home/zcaceog/News/nnml:hurricane.SCORE", O_RDONLY) = 8 open("/home/zcaceog/News/nnml:hurricane.SCORE", O_RDONLY) = 8 Here I select the first article: open("/home/zcaceog/Mail/hurricane", O_RDONLY|O_NONBLOCK) = 8 open("/home/zcaceog/Mail/hurricane", O_RDONLY|O_NONBLOCK) = 8 open("/home/zcaceog/Mail/hurricane/8865", O_RDONLY) = 8 open("/home/zcaceog/News/cache/nnml:hurricane/.overview", O_RDONLY) = 8 open("/usr/lib/xemacs-20.4/lisp/utils/pp.elc", O_RDONLY) = 8 open("/home/zcaceog/News/nnml:hurricane.SCORE", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 8 -- Eze Ogwuma