GNU bug report logs - #14786
24.3.50; `field-end' is now very slow

Please note: This is a static page, with minimal formatting, updated once a day.
Click here to see this page with the latest information and nicer formatting.

Package: emacs; Reported by: Drew Adams <drew.adams@HIDDEN>; dated Thu, 4 Jul 2013 05:35:01 UTC; Maintainer for emacs is bug-gnu-emacs@HIDDEN.

Message received at 14786 <at> debbugs.gnu.org:


Received: (at 14786) by debbugs.gnu.org; 5 Jul 2013 18:34:24 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Fri Jul 05 14:34:24 2013
Received: from localhost ([127.0.0.1]:60808 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.80)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1UvApr-0001ss-Qm
	for submit <at> debbugs.gnu.org; Fri, 05 Jul 2013 14:34:24 -0400
Received: from mtaout20.012.net.il ([80.179.55.166]:60205)
 by debbugs.gnu.org with esmtp (Exim 4.80)
 (envelope-from <eliz@HIDDEN>) id 1UvApo-0001sM-2R
 for 14786 <at> debbugs.gnu.org; Fri, 05 Jul 2013 14:34:21 -0400
Received: from conversion-daemon.a-mtaout20.012.net.il by
 a-mtaout20.012.net.il (HyperSendmail v2007.08) id
 <0MPH00I007JMYR00@HIDDEN> for 14786 <at> debbugs.gnu.org;
 Fri, 05 Jul 2013 21:33:52 +0300 (IDT)
Received: from HOME-C4E4A596F7 ([87.69.4.28]) by a-mtaout20.012.net.il
 (HyperSendmail v2007.08) with ESMTPA id
 <0MPH00IQ57KGR180@HIDDEN>;
 Fri, 05 Jul 2013 21:33:52 +0300 (IDT)
Date: Fri, 05 Jul 2013 21:33:49 +0300
From: Eli Zaretskii <eliz@HIDDEN>
Subject: Re: bug#14786: 24.3.50; `field-end' is now very slow
In-reply-to: <e5457a6f-1e4f-4717-ac71-124a102c74db@default>
X-012-Sender: halo1@HIDDEN
To: Drew Adams <drew.adams@HIDDEN>
Message-id: <83zju0yhyq.fsf@HIDDEN>
References: <e5457a6f-1e4f-4717-ac71-124a102c74db@default>
X-Spam-Score: 1.0 (+)
X-Debbugs-Envelope-To: 14786
Cc: 14786 <at> debbugs.gnu.org
X-BeenThere: debbugs-submit <at> debbugs.gnu.org
X-Mailman-Version: 2.1.15
Precedence: list
Reply-To: Eli Zaretskii <eliz@HIDDEN>
List-Id: <debbugs-submit.debbugs.gnu.org>
List-Unsubscribe: <http://debbugs.gnu.org/cgi-bin/mailman/options/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=unsubscribe>
List-Archive: <http://debbugs.gnu.org/cgi-bin/mailman/private/debbugs-submit/>
List-Post: <mailto:debbugs-submit <at> debbugs.gnu.org>
List-Help: <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=help>
List-Subscribe: <http://debbugs.gnu.org/cgi-bin/mailman/listinfo/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=subscribe>
Errors-To: debbugs-submit-bounces <at> debbugs.gnu.org
Sender: "Debbugs-submit" <debbugs-submit-bounces <at> debbugs.gnu.org>
X-Spam-Score: 1.0 (+)

> Date: Fri, 5 Jul 2013 10:06:41 -0700 (PDT)
> From: Drew Adams <drew.adams@HIDDEN>
> Cc: 14786 <at> debbugs.gnu.org
> 
> For my info: When such a code change is made, is there no log of the
> reason behind the change?

Every change comes with a change log.  The reason is not always stated
in the change log, it can sometimes be in the comments to the changed
code or in some discussion that led to the change (preferably cited in
the change log).

> If it was to fix a bug, for instance, wouldn't that bug # be noted?

Yes, definitely.




Information forwarded to bug-gnu-emacs@HIDDEN:
bug#14786; Package emacs. Full text available.

Message received at 14786 <at> debbugs.gnu.org:


Received: (at 14786) by debbugs.gnu.org; 5 Jul 2013 17:06:55 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Fri Jul 05 13:06:55 2013
Received: from localhost ([127.0.0.1]:60648 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.80)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1Uv9TC-00077j-2l
	for submit <at> debbugs.gnu.org; Fri, 05 Jul 2013 13:06:54 -0400
Received: from userp1040.oracle.com ([156.151.31.81]:31412)
 by debbugs.gnu.org with esmtp (Exim 4.80)
 (envelope-from <drew.adams@HIDDEN>) id 1Uv9TA-00077R-2i
 for 14786 <at> debbugs.gnu.org; Fri, 05 Jul 2013 13:06:52 -0400
Received: from acsinet21.oracle.com (acsinet21.oracle.com [141.146.126.237])
 by userp1040.oracle.com (Sentrion-MTA-4.3.1/Sentrion-MTA-4.3.1) with ESMTP id
 r65H6jQr015986
 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=OK);
 Fri, 5 Jul 2013 17:06:46 GMT
Received: from userz7022.oracle.com (userz7022.oracle.com [156.151.31.86])
 by acsinet21.oracle.com (8.14.4+Sun/8.14.4) with ESMTP id r65H6iCM002952
 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO);
 Fri, 5 Jul 2013 17:06:44 GMT
Received: from abhmt106.oracle.com (abhmt106.oracle.com [141.146.116.58])
 by userz7022.oracle.com (8.14.4+Sun/8.14.4) with ESMTP id r65H6hKW005801;
 Fri, 5 Jul 2013 17:06:43 GMT
MIME-Version: 1.0
Message-ID: <e5457a6f-1e4f-4717-ac71-124a102c74db@default>
Date: Fri, 5 Jul 2013 10:06:41 -0700 (PDT)
From: Drew Adams <drew.adams@HIDDEN>
To: Eli Zaretskii <eliz@HIDDEN>
Subject: RE: bug#14786: 24.3.50; `field-end' is now very slow
References: <<029969a6-cd0e-45c9-b778-57b5daf98c2a@default>>
 <<8338rtyp0y.fsf@HIDDEN>>
In-Reply-To: <<8338rtyp0y.fsf@HIDDEN>>
X-Priority: 3
X-Mailer: Oracle Beehive Extensions for Outlook 2.0.1.7  (607090) [OL
 12.0.6668.5000 (x86)]
Content-Type: text/plain; charset=us-ascii
Content-Transfer-Encoding: quoted-printable
X-Source-IP: acsinet21.oracle.com [141.146.126.237]
X-Spam-Score: -2.5 (--)
X-Debbugs-Envelope-To: 14786
Cc: 14786 <at> debbugs.gnu.org
X-BeenThere: debbugs-submit <at> debbugs.gnu.org
X-Mailman-Version: 2.1.15
Precedence: list
List-Id: <debbugs-submit.debbugs.gnu.org>
List-Unsubscribe: <http://debbugs.gnu.org/cgi-bin/mailman/options/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=unsubscribe>
List-Archive: <http://debbugs.gnu.org/cgi-bin/mailman/private/debbugs-submit/>
List-Post: <mailto:debbugs-submit <at> debbugs.gnu.org>
List-Help: <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=help>
List-Subscribe: <http://debbugs.gnu.org/cgi-bin/mailman/listinfo/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=subscribe>
Errors-To: debbugs-submit-bounces <at> debbugs.gnu.org
Sender: "Debbugs-submit" <debbugs-submit-bounces <at> debbugs.gnu.org>
X-Spam-Score: -2.5 (--)

> > 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.
>=20
> Not exactly immediately, but approximately 4 to 5 times faster.

OK.  I was describing the user experience.  Less than a second is
quick enough for a large Dired buffer.  Four seconds it not.

> The problem is that dired-details floods the Dired buffer with
> overlays.  When there are so many overlays, searching for an end of
> a non-existent property takes a lot of time, because Emacs needs to
> examine every overlay in the buffer.

OK.

> What happened between Emacs 24.3 and the current trunk is that the
> call GET_OVERLAYS_AT (XINT (position), overlay_vec, noverlays, NULL, 0);
> in get_char_property_and_overlay got roughly 4 to 5 times slower.  I
> don't know why this slowdown happened, but it just moved the time
> needed by field-end from below the annoyance threshold to well above
> it.

I agree with your characterization in the last phrase.

> If someone can find out why GET_OVERLAYS_AT is now slower, we could
> see if that could be fixed.  But it's quite possible that the change
> which caused that fixed some bug that we don't want to re-introduce.
> In any case, I think having so many overlays in a buffer is asking for
> trouble.

Agreed, in general.  Emacs does make heavy use of overlays here and
there, and I don't see that possibility disappearing.  I hope this bug
(performance regression) can be fixed.  It is not particular to
dired-details.el, though that is one place that it can easily be
noticed.

For my info: When such a code change is made, is there no log of the
reason behind the change?  If it was to fix a bug, for instance,
wouldn't that bug # be noted?




Information forwarded to bug-gnu-emacs@HIDDEN:
bug#14786; Package emacs. Full text available.

Message received at 14786 <at> debbugs.gnu.org:


Received: (at 14786) by debbugs.gnu.org; 5 Jul 2013 16:02:08 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Fri Jul 05 12:02:08 2013
Received: from localhost ([127.0.0.1]:60488 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.80)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1Uv8ST-0003Yf-Up
	for submit <at> debbugs.gnu.org; Fri, 05 Jul 2013 12:02:07 -0400
Received: from mtaout21.012.net.il ([80.179.55.169]:47529)
 by debbugs.gnu.org with esmtp (Exim 4.80)
 (envelope-from <eliz@HIDDEN>) id 1Uv8SQ-0003XW-Bs
 for 14786 <at> debbugs.gnu.org; Fri, 05 Jul 2013 12:02:04 -0400
Received: from conversion-daemon.a-mtaout21.012.net.il by
 a-mtaout21.012.net.il (HyperSendmail v2007.08) id
 <0MPH00M000ERJO00@HIDDEN> for 14786 <at> debbugs.gnu.org;
 Fri, 05 Jul 2013 19:01:22 +0300 (IDT)
Received: from HOME-C4E4A596F7 ([87.69.4.28]) by a-mtaout21.012.net.il
 (HyperSendmail v2007.08) with ESMTPA id
 <0MPH00MIE0I9DJD0@HIDDEN>;
 Fri, 05 Jul 2013 19:01:21 +0300 (IDT)
Date: Fri, 05 Jul 2013 19:01:17 +0300
From: Eli Zaretskii <eliz@HIDDEN>
Subject: Re: bug#14786: 24.3.50; `field-end' is now very slow
In-reply-to: <029969a6-cd0e-45c9-b778-57b5daf98c2a@default>
X-012-Sender: halo1@HIDDEN
To: Drew Adams <drew.adams@HIDDEN>
Message-id: <8338rtyp0y.fsf@HIDDEN>
References: <029969a6-cd0e-45c9-b778-57b5daf98c2a@default>
X-Spam-Score: 1.0 (+)
X-Debbugs-Envelope-To: 14786
Cc: 14786 <at> debbugs.gnu.org
X-BeenThere: debbugs-submit <at> debbugs.gnu.org
X-Mailman-Version: 2.1.15
Precedence: list
Reply-To: Eli Zaretskii <eliz@HIDDEN>
List-Id: <debbugs-submit.debbugs.gnu.org>
List-Unsubscribe: <http://debbugs.gnu.org/cgi-bin/mailman/options/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=unsubscribe>
List-Archive: <http://debbugs.gnu.org/cgi-bin/mailman/private/debbugs-submit/>
List-Post: <mailto:debbugs-submit <at> debbugs.gnu.org>
List-Help: <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=help>
List-Subscribe: <http://debbugs.gnu.org/cgi-bin/mailman/listinfo/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=subscribe>
Errors-To: debbugs-submit-bounces <at> debbugs.gnu.org
Sender: "Debbugs-submit" <debbugs-submit-bounces <at> debbugs.gnu.org>
X-Spam-Score: 1.0 (+)

> Date: Thu, 4 Jul 2013 13:57:52 -0700 (PDT)
> From: Drew Adams <drew.adams@HIDDEN>
> Cc: 14786 <at> debbugs.gnu.org
> 
> 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.

Not exactly immediately, but approximately 4 to 5 times faster.

The problem is that dired-details floods the Dired buffer with
overlays.  When there are so many overlays, searching for an end of a
non-existent property takes a lot of time, because Emacs needs to
examine every overlay in the buffer.

What happened between Emacs 24.3 and the current trunk is that the
call

    GET_OVERLAYS_AT (XINT (position), overlay_vec, noverlays, NULL, 0);

in get_char_property_and_overlay got roughly 4 to 5 times slower.  I
don't know why this slowdown happened, but it just moved the time
needed by field-end from below the annoyance threshold to well above
it.

If someone can find out why GET_OVERLAYS_AT is now slower, we could
see if that could be fixed.  But it's quite possible that the change
which caused that fixed some bug that we don't want to re-introduce.
In any case, I think having so many overlays in a buffer is asking for
trouble.




Information forwarded to bug-gnu-emacs@HIDDEN:
bug#14786; Package emacs. Full text available.

Message received at 14786 <at> debbugs.gnu.org:


Received: (at 14786) by debbugs.gnu.org; 4 Jul 2013 20:58:09 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Thu Jul 04 16:58:09 2013
Received: from localhost ([127.0.0.1]:58050 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.80)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1UuqbQ-0007WL-Hp
	for submit <at> debbugs.gnu.org; Thu, 04 Jul 2013 16:58:09 -0400
Received: from userp1040.oracle.com ([156.151.31.81]:40664)
 by debbugs.gnu.org with esmtp (Exim 4.80)
 (envelope-from <drew.adams@HIDDEN>) id 1UuqbL-0007Vj-7k
 for 14786 <at> debbugs.gnu.org; Thu, 04 Jul 2013 16:58:05 -0400
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
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
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
MIME-Version: 1.0
Message-ID: <029969a6-cd0e-45c9-b778-57b5daf98c2a@default>
Date: Thu, 4 Jul 2013 13:57:52 -0700 (PDT)
From: Drew Adams <drew.adams@HIDDEN>
To: Eli Zaretskii <eliz@HIDDEN>
Subject: RE: bug#14786: 24.3.50; `field-end' is now very slow
References: <<82afc751-3de7-4315-833d-fa6c9ab9378a@default>>
 <<83sizuz791.fsf@HIDDEN>>
In-Reply-To: <<83sizuz791.fsf@HIDDEN>>
X-Priority: 3
X-Mailer: Oracle Beehive Extensions for Outlook 2.0.1.7  (607090) [OL
 12.0.6668.5000 (x86)]
Content-Type: multipart/mixed;
 boundary="__1372971474350144486abhmt104.oracle.com"
X-Source-IP: acsinet22.oracle.com [141.146.126.238]
X-Spam-Score: -2.5 (--)
X-Debbugs-Envelope-To: 14786
Cc: 14786 <at> debbugs.gnu.org
X-BeenThere: debbugs-submit <at> debbugs.gnu.org
X-Mailman-Version: 2.1.15
Precedence: list
List-Id: <debbugs-submit.debbugs.gnu.org>
List-Unsubscribe: <http://debbugs.gnu.org/cgi-bin/mailman/options/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=unsubscribe>
List-Archive: <http://debbugs.gnu.org/cgi-bin/mailman/private/debbugs-submit/>
List-Post: <mailto:debbugs-submit <at> debbugs.gnu.org>
List-Help: <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=help>
List-Subscribe: <http://debbugs.gnu.org/cgi-bin/mailman/listinfo/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=subscribe>
Errors-To: debbugs-submit-bounces <at> debbugs.gnu.org
Sender: "Debbugs-submit" <debbugs-submit-bounces <at> debbugs.gnu.org>
X-Spam-Score: -2.5 (--)

--__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%
                                #<compiled 0xd6dff9>            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%
        - #<compiled 0x4cb765>                              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 "#<compiled 0x4cb765>" 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 ["#<compiled 0xd6df=
f9>" 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--




Information forwarded to bug-gnu-emacs@HIDDEN:
bug#14786; Package emacs. Full text available.

Message received at 14786 <at> debbugs.gnu.org:


Received: (at 14786) by debbugs.gnu.org; 4 Jul 2013 15:15:44 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Thu Jul 04 11:15:44 2013
Received: from localhost ([127.0.0.1]:57482 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.80)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1UulG4-0005OB-4s
	for submit <at> debbugs.gnu.org; Thu, 04 Jul 2013 11:15:44 -0400
Received: from mtaout20.012.net.il ([80.179.55.166]:61005)
 by debbugs.gnu.org with esmtp (Exim 4.80)
 (envelope-from <eliz@HIDDEN>) id 1UulG1-0005Np-Rl
 for 14786 <at> debbugs.gnu.org; Thu, 04 Jul 2013 11:15:43 -0400
Received: from conversion-daemon.a-mtaout20.012.net.il by
 a-mtaout20.012.net.il (HyperSendmail v2007.08) id
 <0MPF003003P1NF00@HIDDEN> for 14786 <at> debbugs.gnu.org;
 Thu, 04 Jul 2013 18:15:30 +0300 (IDT)
Received: from HOME-C4E4A596F7 ([87.69.4.28]) by a-mtaout20.012.net.il
 (HyperSendmail v2007.08) with ESMTPA id
 <0MPF0032C3PT5LC0@HIDDEN>;
 Thu, 04 Jul 2013 18:15:30 +0300 (IDT)
Date: Thu, 04 Jul 2013 18:15:22 +0300
From: Eli Zaretskii <eliz@HIDDEN>
Subject: Re: bug#14786: 24.3.50; `field-end' is now very slow
In-reply-to: <82afc751-3de7-4315-833d-fa6c9ab9378a@default>
X-012-Sender: halo1@HIDDEN
To: Drew Adams <drew.adams@HIDDEN>
Message-id: <83sizuz791.fsf@HIDDEN>
References: <82afc751-3de7-4315-833d-fa6c9ab9378a@default>
X-Spam-Score: 1.0 (+)
X-Debbugs-Envelope-To: 14786
Cc: 14786 <at> debbugs.gnu.org
X-BeenThere: debbugs-submit <at> debbugs.gnu.org
X-Mailman-Version: 2.1.15
Precedence: list
Reply-To: Eli Zaretskii <eliz@HIDDEN>
List-Id: <debbugs-submit.debbugs.gnu.org>
List-Unsubscribe: <http://debbugs.gnu.org/cgi-bin/mailman/options/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=unsubscribe>
List-Archive: <http://debbugs.gnu.org/cgi-bin/mailman/private/debbugs-submit/>
List-Post: <mailto:debbugs-submit <at> debbugs.gnu.org>
List-Help: <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=help>
List-Subscribe: <http://debbugs.gnu.org/cgi-bin/mailman/listinfo/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=subscribe>
Errors-To: debbugs-submit-bounces <at> debbugs.gnu.org
Sender: "Debbugs-submit" <debbugs-submit-bounces <at> debbugs.gnu.org>
X-Spam-Score: 1.0 (+)

> Date: Wed, 3 Jul 2013 22:34:31 -0700 (PDT)
> From: Drew Adams <drew.adams@HIDDEN>
> 
> I'm not very good at measuring processing time.  If you need more info
> about that then someone will need to remind me what functions to use for
> measuring.

profiler-start and profiler-report.

> 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.

I cannot reproduce this with yesterday's trunk.  Does this happen for
you in "emacs -Q"?




Information forwarded to bug-gnu-emacs@HIDDEN:
bug#14786; Package emacs. Full text available.

Message received at submit <at> debbugs.gnu.org:


Received: (at submit) by debbugs.gnu.org; 4 Jul 2013 05:34:47 +0000
From debbugs-submit-bounces <at> debbugs.gnu.org Thu Jul 04 01:34:47 2013
Received: from localhost ([127.0.0.1]:56225 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.80)
	(envelope-from <debbugs-submit-bounces <at> debbugs.gnu.org>)
	id 1UucBq-0007IQ-L0
	for submit <at> debbugs.gnu.org; Thu, 04 Jul 2013 01:34:46 -0400
Received: from eggs.gnu.org ([208.118.235.92]:46469)
 by debbugs.gnu.org with esmtp (Exim 4.80)
 (envelope-from <drew.adams@HIDDEN>) id 1UucBo-0007I8-M2
 for submit <at> debbugs.gnu.org; Thu, 04 Jul 2013 01:34:45 -0400
Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71)
 (envelope-from <drew.adams@HIDDEN>) id 1UucBi-0007WY-Qy
 for submit <at> debbugs.gnu.org; Thu, 04 Jul 2013 01:34:39 -0400
X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on eggs.gnu.org
X-Spam-Level: 
X-Spam-Status: No, score=-100.5 required=5.0 tests=BAYES_05, USER_IN_WHITELIST
 autolearn=disabled version=3.3.2
Received: from lists.gnu.org ([2001:4830:134:3::11]:60398)
 by eggs.gnu.org with esmtp (Exim 4.71)
 (envelope-from <drew.adams@HIDDEN>) id 1UucBi-0007WL-Nf
 for submit <at> debbugs.gnu.org; Thu, 04 Jul 2013 01:34:38 -0400
Received: from eggs.gnu.org ([2001:4830:134:3::10]:48190)
 by lists.gnu.org with esmtp (Exim 4.71)
 (envelope-from <drew.adams@HIDDEN>) id 1UucBg-0002oT-IS
 for bug-gnu-emacs@HIDDEN; Thu, 04 Jul 2013 01:34:38 -0400
Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71)
 (envelope-from <drew.adams@HIDDEN>) id 1UucBf-0007P1-P4
 for bug-gnu-emacs@HIDDEN; Thu, 04 Jul 2013 01:34:36 -0400
Received: from userp1040.oracle.com ([156.151.31.81]:24315)
 by eggs.gnu.org with esmtp (Exim 4.71)
 (envelope-from <drew.adams@HIDDEN>) id 1UucBf-0007Np-GQ
 for bug-gnu-emacs@HIDDEN; Thu, 04 Jul 2013 01:34:35 -0400
Received: from ucsinet21.oracle.com (ucsinet21.oracle.com [156.151.31.93])
 by userp1040.oracle.com (Sentrion-MTA-4.3.1/Sentrion-MTA-4.3.1) with ESMTP id
 r645SDiT001849
 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=OK)
 for <bug-gnu-emacs@HIDDEN>; Thu, 4 Jul 2013 05:28:14 GMT
Received: from userz7022.oracle.com (userz7022.oracle.com [156.151.31.86])
 by ucsinet21.oracle.com (8.14.4+Sun/8.14.4) with ESMTP id r645YXGW026766
 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO)
 for <bug-gnu-emacs@HIDDEN>; Thu, 4 Jul 2013 05:34:33 GMT
Received: from abhmt104.oracle.com (abhmt104.oracle.com [141.146.116.56])
 by userz7022.oracle.com (8.14.4+Sun/8.14.4) with ESMTP id r645YXBh001580
 for <bug-gnu-emacs@HIDDEN>; Thu, 4 Jul 2013 05:34:33 GMT
MIME-Version: 1.0
Message-ID: <82afc751-3de7-4315-833d-fa6c9ab9378a@default>
Date: Wed, 3 Jul 2013 22:34:31 -0700 (PDT)
From: Drew Adams <drew.adams@HIDDEN>
To: bug-gnu-emacs@HIDDEN
Subject: 24.3.50; `field-end' is now very slow
X-Priority: 3
X-Mailer: Oracle Beehive Extensions for Outlook 2.0.1.7  (607090) [OL
 12.0.6668.5000 (x86)]
Content-Type: text/plain; charset=us-ascii
Content-Transfer-Encoding: quoted-printable
X-Source-IP: ucsinet21.oracle.com [156.151.31.93]
X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.4.x-2.6.x [generic]
X-detected-operating-system: by eggs.gnu.org: Error: Malformed IPv6 address
 (bad octet value).
X-Received-From: 2001:4830:134:3::11
X-Spam-Score: -4.0 (----)
X-Debbugs-Envelope-To: submit
X-BeenThere: debbugs-submit <at> debbugs.gnu.org
X-Mailman-Version: 2.1.15
Precedence: list
List-Id: <debbugs-submit.debbugs.gnu.org>
List-Unsubscribe: <http://debbugs.gnu.org/cgi-bin/mailman/options/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=unsubscribe>
List-Archive: <http://debbugs.gnu.org/cgi-bin/mailman/private/debbugs-submit/>
List-Post: <mailto:debbugs-submit <at> debbugs.gnu.org>
List-Help: <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=help>
List-Subscribe: <http://debbugs.gnu.org/cgi-bin/mailman/listinfo/debbugs-submit>, 
 <mailto:debbugs-submit-request <at> debbugs.gnu.org?subject=subscribe>
Errors-To: debbugs-submit-bounces <at> debbugs.gnu.org
Sender: "Debbugs-submit" <debbugs-submit-bounces <at> debbugs.gnu.org>
X-Spam-Score: -4.0 (----)

I'm not very good at measuring processing time.  If you need more info
about that then someone will need to remind me what functions to use for
measuring.

Here's what I see:

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.

This is a really noticeable difference.  It makes certain interactive
interactions nearly unusable.  Can something be done about this, or
is it perhaps an inevitable consequence of some feature that has been
added recently?

In GNU Emacs 24.3.50.1 (i686-pc-mingw32)
 of 2013-07-01 on LEG570
Bzr revision: 113246 lekktu@HIDDEN
Windowing system distributor `Microsoft Corp.', version 6.1.7601
Configured using:
 `configure --prefix=3D/c/usr --enable-checking CFLAGS=3D'-O0 -g3'
 CPPFLAGS=3D'-DGLYPH_DEBUG=3D1 -I/c/usr/include''




Acknowledgement sent to Drew Adams <drew.adams@HIDDEN>:
New bug report received and forwarded. Copy sent to bug-gnu-emacs@HIDDEN. Full text available.
Report forwarded to bug-gnu-emacs@HIDDEN:
bug#14786; Package emacs. Full text available.
Please note: This is a static page, with minimal formatting, updated once a day.
Click here to see this page with the latest information and nicer formatting.
Last modified: Fri, 31 Oct 2014 17:00:04 UTC

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997 nCipher Corporation Ltd, 1994-97 Ian Jackson.