From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.org!not-for-mail From: Drew Adams Newsgroups: gmane.emacs.bugs Subject: bug#14786: 24.3.50; `field-end' is now very slow Date: Thu, 4 Jul 2013 13:57:52 -0700 (PDT) Message-ID: <029969a6-cd0e-45c9-b778-57b5daf98c2a@default> References: <<82afc751-3de7-4315-833d-fa6c9ab9378a@default>> <<83sizuz791.fsf@gnu.org>> NNTP-Posting-Host: plane.gmane.org Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="__1372971474350144486abhmt104.oracle.com" X-Trace: ger.gmane.org 1372971556 15078 80.91.229.3 (4 Jul 2013 20:59:16 GMT) X-Complaints-To: usenet@ger.gmane.org NNTP-Posting-Date: Thu, 4 Jul 2013 20:59:16 +0000 (UTC) Cc: 14786@debbugs.gnu.org To: Eli Zaretskii Original-X-From: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Thu Jul 04 22:59:17 2013 Return-path: Envelope-to: geb-bug-gnu-emacs@m.gmane.org Original-Received: from lists.gnu.org ([208.118.235.17]) by plane.gmane.org with esmtp (Exim 4.69) (envelope-from ) id 1UuqcS-0005eR-IP for geb-bug-gnu-emacs@m.gmane.org; Thu, 04 Jul 2013 22:59:12 +0200 Original-Received: from localhost ([::1]:47401 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1UuqcS-0001rb-9p for geb-bug-gnu-emacs@m.gmane.org; Thu, 04 Jul 2013 16:59:12 -0400 Original-Received: from eggs.gnu.org ([2001:4830:134:3::10]:55144) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1UuqcL-0001qX-Ep for bug-gnu-emacs@gnu.org; Thu, 04 Jul 2013 16:59:08 -0400 Original-Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1UuqcJ-0007mg-HT for bug-gnu-emacs@gnu.org; Thu, 04 Jul 2013 16:59:05 -0400 Original-Received: from debbugs.gnu.org ([140.186.70.43]:35501) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1UuqcJ-0007mW-E2 for bug-gnu-emacs@gnu.org; Thu, 04 Jul 2013 16:59:03 -0400 Original-Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.80) (envelope-from ) id 1UuqcI-0007Xp-Nb for bug-gnu-emacs@gnu.org; Thu, 04 Jul 2013 16:59:02 -0400 X-Loop: help-debbugs@gnu.org Resent-From: Drew Adams Original-Sender: "Debbugs-submit" Resent-CC: bug-gnu-emacs@gnu.org Resent-Date: Thu, 04 Jul 2013 20:59:02 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 14786 X-GNU-PR-Package: emacs X-GNU-PR-Keywords: Original-Received: via spool by 14786-submit@debbugs.gnu.org id=B14786.137297148928919 (code B ref 14786); Thu, 04 Jul 2013 20:59:02 +0000 Original-Received: (at 14786) by debbugs.gnu.org; 4 Jul 2013 20:58:09 +0000 Original-Received: from localhost ([127.0.0.1]:58050 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.80) (envelope-from ) id 1UuqbQ-0007WL-Hp for submit@debbugs.gnu.org; Thu, 04 Jul 2013 16:58:09 -0400 Original-Received: from userp1040.oracle.com ([156.151.31.81]:40664) by debbugs.gnu.org with esmtp (Exim 4.80) (envelope-from ) id 1UuqbL-0007Vj-7k for 14786@debbugs.gnu.org; Thu, 04 Jul 2013 16:58:05 -0400 Original-Received: from acsinet22.oracle.com (acsinet22.oracle.com [141.146.126.238]) by userp1040.oracle.com (Sentrion-MTA-4.3.1/Sentrion-MTA-4.3.1) with ESMTP id r64KvugS015462 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=OK); Thu, 4 Jul 2013 20:57:57 GMT Original-Received: from userz7021.oracle.com (userz7021.oracle.com [156.151.31.85]) by acsinet22.oracle.com (8.14.4+Sun/8.14.4) with ESMTP id r64Kvt46016247 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Thu, 4 Jul 2013 20:57:55 GMT Original-Received: from abhmt104.oracle.com (abhmt104.oracle.com [141.146.116.56]) by userz7021.oracle.com (8.14.4+Sun/8.14.4) with ESMTP id r64KvsJj018130; Thu, 4 Jul 2013 20:57:54 GMT In-Reply-To: <<83sizuz791.fsf@gnu.org>> X-Priority: 3 X-Mailer: Oracle Beehive Extensions for Outlook 2.0.1.7 (607090) [OL 12.0.6668.5000 (x86)] X-Source-IP: acsinet22.oracle.com [141.146.126.238] X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.15 Precedence: list X-detected-operating-system: by eggs.gnu.org: GNU/Linux 3.x X-Received-From: 140.186.70.43 X-BeenThere: bug-gnu-emacs@gnu.org List-Id: "Bug reports for GNU Emacs, the Swiss army knife of text editors" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Original-Sender: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane.org@gnu.org Xref: news.gmane.org gmane.emacs.bugs:75916 Archived-At: --__1372971474350144486abhmt104.oracle.com Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: quoted-printable > > I put the cursor on, say, the first file or dir name in a large Dired > > buffer (1860 lines). I do `M-: (field-end nil)'. > > > > In Emacs 22, 23, and even 24.3, the result appears immediately - no > > perceptible delay. In recent Emacs 24 (e.g., this build), the result > > appears after several seconds - 3 to 4 sec. >=20 > I cannot reproduce this with yesterday's trunk. Does this happen for > you in "emacs -Q"? Sorry, the description was incomplete. 1. emacs -Q 2. Load library dired-details.el, from Emacs Wiki: http://www.emacswiki.org/emacs/download/dired-details.el 3. C-x d ; in some directory that has lots of files 4. M-x dired-details-toggle 5. M-x dired-details-toggle ; (optional, so you see all info) 6. Position the cursor on a file or dir name near the beginning of the list. 7. M-: (field-end nil) The result appears after a few seconds (I'm guessing about 4 sec in the directory I used). Do the same thing in previous Emacs versions (including as recent as 24.3, at least), and the result appears immediately. I tried `M-x profiler-start', then `M-: (field-end nil)', then `M-x profiler-report', then `M-x profiler-stop'. Then I wrote each buffer to a file using C-x C-w. The files are attached. This is what I saw in *Memory-Profiler-Report...*: - command-execute 42,437,777 0% - call-interactively 42,437,777 0% - byte-code 39,515,026 -4% - read-extended-command 19,764,987 -2% - completing-read 19,764,987 -2% - completing-read-default 19,764,987 -2% - read-from-minibuffer 19,764,586 -2% - redisplay_internal (C function) 19,740,876 -2% - find-image 19,740,876 -2% - image-search-load-path 19,740,876 -2% image-search-load-path 18,166,368 -3% - command-execute 1,208 0% - call-interactively 40 0% - minibuffer-complete-and-exit 40 0% minibuffer--complete-and-exit 40 0% - read--expression 19,750,039 -2% - read-from-minibuffer 19,749,638 -2% - redisplay_internal (C function) 19,723,328 -2% - find-image 19,723,328 -2% - image-search-load-path 19,723,328 -2% image-search-load-path 18,148,820 -3% - command-execute 808 0% - call-interactively 680 0% - self-insert-command 680 0% - blink-paren-post-self-insert-function 680 0% - blink-matching-open 680 0% - sit-for 480 0% redisplay 320 0% read-event 160 0% - execute-extended-command 2,025,794 2% - command-execute 1,980,502 2% - call-interactively 1,980,494 2% - profiler-report 1,979,210 2% - profiler-report-cpu 1,076,878 1% - profiler-cpu-profile 944,730 1% profiler-make-profile 1,198 0% - profiler-report-profile-other-window 132,148 0% - profiler-report-setup-buffer 132,148 0% - profiler-report-setup-buffer-1 131,636 0% profiler-report-make-buffer-name 131,104 0% - profiler-report-render-calltree 512 0% - profiler-report-rerender-calltree 512 0% - profiler-report-render-calltree 512 0% - profiler-report-header-line-f 512 0% replace-regexp-in-string 512 0% - profiler-report-memory 902,332 1% profiler-memory-profile 902,332 1% - profiler-start 1,284 0% message 1,284 0% - eval-expression 745,480 0% eval 745,480 0% - profiler-report 151,477 0% - profiler-report-cpu 151,477 0% - profiler-report-profile-other-window 151,477 0% - switch-to-buffer-other-window 143,289 0% - pop-to-buffer 143,289 0% - display-buffer 143,289 0% - display-buffer--maybe-pop-up-frame-or 143,289 0% - display-buffer-pop-up-window 143,289 0% - window--try-to-split-window 143,289 0% - funcall 143,289 0% - split-window-sensibly 143,289 0% - split-window-below 143,289 0% - split-window 143,289 0% byte-code 143,289 0% - profiler-report-setup-buffer 8,188 0% - profiler-report-render-calltree 8,188 0% - profiler-report-rerender-calltree 8,188 0% - profiler-report-render-calltree-1 8,188 0% - profiler-calltree-build 8,188 0% - profiler-calltree-compute-percent 8,188 0% - profiler-calltree-walk 8,188 0% - profiler-calltree-walk 8,188 0% - profiler-calltree-walk 8,188 0% - profiler-calltree-walk 8,188 0% # 8,188 0% - redisplay_internal (C function) 40,759,238 -2% - find-image 39,446,656 -4% - image-search-load-path 39,446,656 -4% image-search-load-path 36,297,640 4% - tool-bar-make-keymap 1,312,070 1% - tool-bar-make-keymap-1 1,312,070 1% - mapcar 1,312,070 1% - # 1,312,070 1% - eval 1,312,070 1% - find-image 1,312,070 1% image-search-load-path 1,312,070 1% - kill-this-buffer-enabled-p 512 0% byte-code 512 0% And this in *CPU-Profiler-Report..*: - command-execute 215 98% - call-interactively 215 98% - eval-expression 204 93% eval 204 93% - byte-code 10 4% - read--expression 5 2% - read-from-minibuffer 4 1% - redisplay_internal (C function) 2 0% - find-image 2 0% - image-search-load-path 2 0% image-search-load-path 2 0% - command-execute 1 0% - call-interactively 1 0% - self-insert-command 1 0% - blink-paren-post-self-insert-fun 1 0% - blink-matching-open 1 0% sit-for 1 0% - read-extended-command 5 2% - completing-read 5 2% - completing-read-default 5 2% - read-from-minibuffer 4 1% - redisplay_internal (C function) 2 0% - find-image 2 0% - image-search-load-path 2 0% image-search-load-path 2 0% - execute-extended-command 1 0% - command-execute 1 0% - call-interactively 1 0% - profiler-report 1 0% - profiler-report-cpu 1 0% profiler-cpu-profile 1 0% Automatic GC 2 0% - redisplay_internal (C function) 1 0% - find-image 1 0% - image-search-load-path 1 0% image-search-load-path 1 0% HTH. BTW - 1. Is there an easier way to open everything up like that? All I could find was to hit TAB or RET or i on each line. PITA. 2. Seems like the mode line info should also (or instead) appear in the buffer as a title, so it gets picked up by C-x h. 3. The numeric columns should have headers. No idea what the numbers mean - what units for the first column, percentage of what (what compared to what) for the second column. --__1372971474350144486abhmt104.oracle.com Content-Type: text/plain; charset=Windows-1252; name="throw-prof-cpu.txt" Content-Transfer-Encoding: quoted-printable Content-Disposition: attachment; filename="throw-prof-cpu.txt" [profiler-profile "24.3" cpu #s(hash-table size 65 test equal rehash-size 1= .5 rehash-threshold 0.8 data ([nil nil nil nil nil nil nil nil nil nil nil = nil nil nil nil nil] 5 [image-search-load-path image-search-load-path find-= image redisplay_internal\ \(C\ function\) read-from-minibuffer read--expres= sion byte-code call-interactively command-execute nil nil nil nil nil nil n= il] 2 [read-from-minibuffer read--expression byte-code call-interactively c= ommand-execute nil nil nil nil nil nil nil nil nil nil nil] 1 [read--expres= sion byte-code call-interactively command-execute nil nil nil nil nil nil n= il nil nil nil nil nil] 1 [sit-for blink-matching-open blink-paren-post-sel= f-insert-function self-insert-command call-interactively command-execute re= ad-from-minibuffer read--expression byte-code call-interactively command-ex= ecute nil nil nil nil nil] 1 [eval eval-expression call-interactively comma= nd-execute nil nil nil nil nil nil nil nil nil nil nil nil] 204 [image-sear= ch-load-path image-search-load-path find-image redisplay_internal\ \(C\ fun= ction\) nil nil nil nil nil nil nil nil nil nil nil nil] 1 [image-search-lo= ad-path image-search-load-path find-image redisplay_internal\ \(C\ function= \) read-from-minibuffer completing-read-default completing-read read-extend= ed-command byte-code call-interactively command-execute nil nil nil nil nil= ] 2 [read-from-minibuffer completing-read-default completing-read read-exte= nded-command byte-code call-interactively command-execute nil nil nil nil n= il nil nil nil nil] 2 [completing-read-default completing-read read-extende= d-command byte-code call-interactively command-execute nil nil nil nil nil = nil nil nil nil nil] 1 [profiler-cpu-profile profiler-report-cpu profiler-r= eport call-interactively command-execute execute-extended-command call-inte= ractively command-execute nil nil nil nil nil nil nil nil] 1 [Automatic\ GC= ] 2)) (20949 57121 639000 0) nil] --__1372971474350144486abhmt104.oracle.com Content-Type: text/plain; charset=Windows-1252; name="throw-prof-mem.txt" Content-Transfer-Encoding: quoted-printable Content-Disposition: attachment; filename="throw-prof-mem.txt" [profiler-profile "24.3" memory #s(hash-table size 65 test equal rehash-siz= e 1.5 rehash-threshold 0.8 data ([message profiler-start call-interactively= command-execute execute-extended-command call-interactively command-execut= e nil nil nil nil nil nil nil nil nil] 1284 [profiler-start call-interactiv= ely command-execute execute-extended-command call-interactively command-exe= cute nil nil nil nil nil nil nil nil nil nil] 0 [image-search-load-path fin= d-image eval "#" mapcar tool-bar-make-keymap-1 tool-bar-= make-keymap redisplay_internal\ \(C\ function\) nil nil nil nil nil nil nil= nil] 1312070 [nil nil nil nil nil nil nil nil nil nil nil nil nil nil nil = nil] 36564 [byte-code kill-this-buffer-enabled-p redisplay_internal\ \(C\ f= unction\) nil nil nil nil nil nil nil nil nil nil nil nil nil] 512 [image-s= earch-load-path find-image redisplay_internal\ \(C\ function\) nil nil nil = nil nil nil nil nil nil nil nil nil nil] 3149016 [image-search-load-path im= age-search-load-path find-image redisplay_internal\ \(C\ function\) nil nil= nil nil nil nil nil nil nil nil nil nil] 36297640 [read--expression byte-c= ode call-interactively command-execute nil nil nil nil nil nil nil nil nil = nil nil nil] 401 [read-from-minibuffer read--expression byte-code call-inte= ractively command-execute nil nil nil nil nil nil nil nil nil nil nil] 2550= 2 [image-search-load-path find-image redisplay_internal\ \(C\ function\) re= ad-from-minibuffer read--expression byte-code call-interactively command-ex= ecute nil nil nil nil nil nil nil nil] 1574508 [image-search-load-path imag= e-search-load-path find-image redisplay_internal\ \(C\ function\) read-from= -minibuffer read--expression byte-code call-interactively command-execute n= il nil nil nil nil nil nil] 18148820 [command-execute read-from-minibuffer = read--expression byte-code call-interactively command-execute nil nil nil n= il nil nil nil nil nil nil] 128 [blink-matching-open blink-paren-post-self-= insert-function self-insert-command call-interactively command-execute read= -from-minibuffer read--expression byte-code call-interactively command-exec= ute nil nil nil nil nil nil] 200 [redisplay sit-for blink-matching-open bli= nk-paren-post-self-insert-function self-insert-command call-interactively c= ommand-execute read-from-minibuffer read--expression byte-code call-interac= tively command-execute nil nil nil nil] 320 [read-event sit-for blink-match= ing-open blink-paren-post-self-insert-function self-insert-command call-int= eractively command-execute read-from-minibuffer read--expression byte-code = call-interactively command-execute nil nil nil nil] 160 [eval eval-expressi= on call-interactively command-execute nil nil nil nil nil nil nil nil nil n= il nil nil] 745480 [completing-read-default completing-read read-extended-c= ommand byte-code call-interactively command-execute nil nil nil nil nil nil= nil nil nil nil] 401 [read-from-minibuffer completing-read-default complet= ing-read read-extended-command byte-code call-interactively command-execute= nil nil nil nil nil nil nil nil nil] 22502 [image-search-load-path find-im= age redisplay_internal\ \(C\ function\) read-from-minibuffer completing-rea= d-default completing-read read-extended-command byte-code call-interactivel= y command-execute nil nil nil nil nil nil] 1574508 [image-search-load-path = image-search-load-path find-image redisplay_internal\ \(C\ function\) read-= from-minibuffer completing-read-default completing-read read-extended-comma= nd byte-code call-interactively command-execute nil nil nil nil nil] 181663= 68 [command-execute read-from-minibuffer completing-read-default completing= -read read-extended-command byte-code call-interactively command-execute ni= l nil nil nil nil nil nil nil] 1168 [minibuffer--complete-and-exit minibuff= er-complete-and-exit call-interactively command-execute read-from-minibuffe= r completing-read-default completing-read read-extended-command byte-code c= all-interactively command-execute nil nil nil nil nil] 40 [execute-extended= -command call-interactively command-execute nil nil nil nil nil nil nil nil= nil nil nil nil nil] 45292 [command-execute execute-extended-command call-= interactively command-execute nil nil nil nil nil nil nil nil nil nil nil n= il] 8 [profiler-cpu-profile profiler-report-cpu profiler-report call-intera= ctively command-execute execute-extended-command call-interactively command= -execute nil nil nil nil nil nil nil nil] 943532 [profiler-make-profile pro= filer-cpu-profile profiler-report-cpu profiler-report call-interactively co= mmand-execute execute-extended-command call-interactively command-execute n= il nil nil nil nil nil nil] 1198 [profiler-report-make-buffer-name profiler= -report-setup-buffer-1 profiler-report-setup-buffer profiler-report-profile= -other-window profiler-report-cpu profiler-report call-interactively comman= d-execute execute-extended-command call-interactively command-execute nil n= il nil nil nil] 131104 [profiler-report-setup-buffer-1 profiler-report-setu= p-buffer profiler-report-profile-other-window profiler-report-cpu profiler-= report call-interactively command-execute execute-extended-command call-int= eractively command-execute nil nil nil nil nil nil] 532 ["#" profiler-calltree-walk profiler-calltree-walk profiler-calltree-walk p= rofiler-calltree-walk profiler-calltree-compute-percentages profiler-calltr= ee-build profiler-report-render-calltree-1 profiler-report-rerender-calltre= e profiler-report-render-calltree profiler-report-setup-buffer profiler-rep= ort-profile-other-window profiler-report-cpu profiler-report call-interacti= vely command-execute] 8188 [replace-regexp-in-string profiler-report-header= -line-format profiler-report-render-calltree-1 profiler-report-rerender-cal= ltree profiler-report-render-calltree profiler-report-setup-buffer profiler= -report-profile-other-window profiler-report-cpu profiler-report call-inter= actively command-execute execute-extended-command call-interactively comman= d-execute nil nil] 512 [byte-code split-window split-window-below split-win= dow-sensibly funcall window--try-to-split-window display-buffer-pop-up-wind= ow display-buffer--maybe-pop-up-frame-or-window display-buffer pop-to-buffe= r switch-to-buffer-other-window profiler-report-profile-other-window profil= er-report-cpu profiler-report call-interactively command-execute] 143289 [p= rofiler-memory-profile profiler-report-memory profiler-report call-interact= ively command-execute execute-extended-command call-interactively command-e= xecute nil nil nil nil nil nil nil nil] 902332)) (20949 57121 697000 0) nil= ] --__1372971474350144486abhmt104.oracle.com--