GNU bug report logs - #53606
29.0.50; Very slow Customize buffer for bibtex-biblatex-entry-alist

Previous Next

Package: emacs;

Reported by: Lars Ingebrigtsen <larsi <at> gnus.org>

Date: Fri, 28 Jan 2022 15:04:02 UTC

Severity: normal

Tags: confirmed

Found in version 29.0.50

Done: Eli Zaretskii <eliz <at> gnu.org>

Bug is archived. No further changes may be made.

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 53606 in the body.
You can then email your comments to 53606 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

View this report as an mbox folder, status mbox, maintainer mbox


Report forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Fri, 28 Jan 2022 15:04:02 GMT) Full text and rfc822 format available.

Acknowledgement sent to Lars Ingebrigtsen <larsi <at> gnus.org>:
New bug report received and forwarded. Copy sent to bug-gnu-emacs <at> gnu.org. (Fri, 28 Jan 2022 15:04:02 GMT) Full text and rfc822 format available.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Lars Ingebrigtsen <larsi <at> gnus.org>
To: bug-gnu-emacs <at> gnu.org
Subject: 29.0.50; Very slow Customize buffer for bibtex-biblatex-entry-alist
Date: Fri, 28 Jan 2022 16:03:47 +0100
`M-x customize-option RET bibtex-biblatex-entry-alist RET'

takes a very long time -- more than 20 seconds on this laptop.  It's a
long alist, but it shouldn't take that long.


In GNU Emacs 29.0.50 (build 9, x86_64-pc-linux-gnu, GTK+ Version 3.24.31, cairo version 1.16.0)
 of 2022-01-24 built on giant
Repository revision: 77b72f77b3a5d13fc6e71746dee2cf68305057e2
Repository branch: master
Windowing system distributor 'The X.Org Foundation', version 11.0.12014000
System Description: Debian GNU/Linux bookworm/sid

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no





Added tag(s) confirmed. Request was from Stefan Kangas <stefan <at> marxist.se> to control <at> debbugs.gnu.org. (Sun, 19 Jun 2022 19:21:01 GMT) Full text and rfc822 format available.

Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Sat, 09 Sep 2023 22:24:02 GMT) Full text and rfc822 format available.

Message #10 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Mauro Aranda <maurooaranda <at> gmail.com>
To: 53606 <at> debbugs.gnu.org
Cc: Lars Ingebrigtsen <larsi <at> gnus.org>
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Sat, 9 Sep 2023 19:23:16 -0300
Lars Ingebrigtsen <larsi <at> gnus.org> writes:

> `M-x customize-option RET bibtex-biblatex-entry-alist RET'
>
> takes a very long time -- more than 20 seconds on this laptop.  It's a
> long alist, but it shouldn't take that long.

I don't have any concrete ideas on how to speed it up on the Widget
library side.  But looking at the defcustom for
bibtex-biblatex-entry-alist I noted two things that can help to create
the Customize buffer more quickly:

1) It uses a custom widget derived from the lazy widget, but doesn't
provide a :tag.  That makes it look awful and giving it a proper :tag 
reduced
the buffer creation time somewhat in my testings.

2) More importantly, the bibtex-entry-alist widget looks like this:
(define-widget 'bibtex-entry-alist 'lazy
  "Format of `bibtex-BibTeX-entry-alist' and friends."
  :type '(repeat (group (string :tag "Entry type")
                        (string :tag "Documentation")
                        (repeat :tag "Required fields"
                                (group (string :tag "Field")
                                       (option (choice :tag "Comment" 
:value nil
                                                       (const nil) string))
                                       (option (choice :tag "Init" 
:value nil
                                                       (const nil) 
string function))
                                       (option (choice :tag 
"Alternative" :value nil
                                                       (const nil) 
integer))))
                        (repeat :tag "Crossref fields"
                                (group (string :tag "Field")
                                       (option (choice :tag "Comment" 
:value nil
                                                       (const nil) string))
                                       (option (choice :tag "Init" 
:value nil
                                                       (const nil) 
string function))
                                       (option (choice :tag 
"Alternative" :value nil
                                                       (const nil) 
integer))))
                        (repeat :tag "Optional fields"
                                (group (string :tag "Field")
                                       (option (choice :tag "Comment" 
:value nil
                                                       (const nil) string))
                                       (option (choice :tag "Init" 
:value nil
                                                       (const nil) 
string function))
                                       (option (choice :tag 
"Alternative" :value nil
                                                       (const nil) 
integer)))))))

Why combine option and choice? That's redundant, specially since the
choice widget allows for the nil value.  Removing the `option's and just
leaving the `choice's should be equivalent in functionality, and in my
testings reduced the creation time to the half.

I ran customize-option 5 times and got:

With `option':
(172.526219636 69 6.120602505999997)

Without `option':
(86.260726994 42 3.5430049540000113)

This is without native compilation.

Based on the above results and since there's no lost in functionality, I
propose to make the changes to the bibtex-entry-alist widget. It is a
net gain in speed, and it might make the wait bearable.





Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Sat, 09 Sep 2023 22:52:02 GMT) Full text and rfc822 format available.

Message #13 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Mauro Aranda <maurooaranda <at> gmail.com>
To: 53606 <at> debbugs.gnu.org
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Sat, 9 Sep 2023 19:51:23 -0300
On 9/9/23 19:23, Mauro Aranda wrote:
> Based on the above results and since there's no lost in functionality, I
> propose to make the changes to the bibtex-entry-alist widget. It is a
> net gain in speed, and it might make the wait bearable.

Hmm, spoke too soon :-(.  Using option is not as redundant as I
thought it was.  Using `choice's alone would set all the values that
are nil in the group like so: ("author" nil nil nil), while using it
with `option' allows for setting it as: ("author")

So that's something to consider.





Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Sun, 10 Sep 2023 05:03:02 GMT) Full text and rfc822 format available.

Message #16 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Mauro Aranda <maurooaranda <at> gmail.com>
Cc: 53606 <at> debbugs.gnu.org
Subject: Re: bug#53606: 29.0.50;
 Very slow Customize buffer for bibtex-biblatex-entry-alist
Date: Sun, 10 Sep 2023 08:01:36 +0300
> Date: Sat, 9 Sep 2023 19:51:23 -0300
> From: Mauro Aranda <maurooaranda <at> gmail.com>
> 
> On 9/9/23 19:23, Mauro Aranda wrote:
>  > Based on the above results and since there's no lost in functionality, I
>  > propose to make the changes to the bibtex-entry-alist widget. It is a
>  > net gain in speed, and it might make the wait bearable.
> 
> Hmm, spoke too soon :-(.  Using option is not as redundant as I
> thought it was.  Using `choice's alone would set all the values that
> are nil in the group like so: ("author" nil nil nil), while using it
> with `option' allows for setting it as: ("author")
> 
> So that's something to consider.

Thanks for looking into this issue.

Could you please profile this slow operation and post the completely
unfolded profile?  I think we should try to understand what exactly
takes so much time in this case.




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Sun, 10 Sep 2023 09:50:02 GMT) Full text and rfc822 format available.

Message #19 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Mauro Aranda <maurooaranda <at> gmail.com>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 53606 <at> debbugs.gnu.org
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Sun, 10 Sep 2023 06:49:29 -0300
[Message part 1 (text/plain, inline)]
On 10/9/23 02:01, Eli Zaretskii wrote:
>> Date: Sat, 9 Sep 2023 19:51:23 -0300
>> From: Mauro Aranda <maurooaranda <at> gmail.com>
>>
>> On 9/9/23 19:23, Mauro Aranda wrote:
>>  > Based on the above results and since there's no lost in 
functionality, I
>>  > propose to make the changes to the bibtex-entry-alist widget. It is a
>>  > net gain in speed, and it might make the wait bearable.
>>
>> Hmm, spoke too soon :-(.  Using option is not as redundant as I
>> thought it was.  Using `choice's alone would set all the values that
>> are nil in the group like so: ("author" nil nil nil), while using it
>> with `option' allows for setting it as: ("author")
>>
>> So that's something to consider.
>
> Thanks for looking into this issue.
>
> Could you please profile this slow operation and post the completely
> unfolded profile?  I think we should try to understand what exactly
> takes so much time in this case.

Here it is.  I also attach the result of C-x C-w in the report buffer,
just in case.

       25262  97%  - call-interactively
       25262  97%   - funcall-interactively
       25262  97%    - eval-last-sexp
       25262  97%     - elisp--eval-last-sexp
       25262  97%      - eval
       25262  97%       - progn
       25262  97%        - progn
       25258  97%         - customize-option
       25246  97%          - custom-buffer-create
       25246  97%           - custom-buffer-create-internal
       24870  96%            - mapcar
       24854  95%             - #<compiled -0x17c1d5ffa7b0b3ca>
       24854  95%              - widget-create
       24854  95%               - widget-apply
       24854  95%                - widget-default-create
       24854  95%                 - widget-apply
       24854  95%                  - custom-variable-value-create
       24842  95%                   - widget-create-child-and-convert
       24842  95%                    - widget-apply
       24842  95%                     - widget-default-create
       24838  95%                      - widget-apply
       24834  95%                       - widget-type-value-create
       24834  95%                        - widget-create-child-value
       24834  95%                         - widget-apply
       24834  95%                          - widget-default-create
       24834  95%                           - widget-apply
       24834  95%                            - 
widget-editable-list-value-create
       24834  95%                             - 
widget-editable-list-entry-create
       24690  95%                              - widget-create-child-value
       24690  95%                               - widget-apply
       24690  95%                                - widget-default-create
       24682  95%                                 - widget-apply
       24682  95%                                  - 
widget-group-value-create
       24670  95%                                   - 
widget-create-child-value
       24670  95%                                    - widget-apply
       24670  95%                                     - 
widget-default-create
       24334  93%                                      - widget-apply
       15974  61%                                       - 
widget-checklist-value-create
       15970  61%                                        - 
widget-checklist-add-item
        7107  27%                                         - 
widget-create-child
        7099  27%                                          - widget-apply
        7099  27%                                           - 
widget-default-create
        4187  16% delete-char
        2120   8%                                            - widget-apply
        2120   8%                                             - 
widget-choice-value-create
        2112   8%                                              - 
widget-create-child-value
        2108   8%                                               - 
widget-apply
        2108   8%                                                - 
widget-default-create
        1428 5%                                                   
delete-char
         308 1%                                                   princ
           4 0% re-search-forward
           4   0% widget-put
           4   0%                                              - 
widget-inline-p
           4   0% widget-get
          12   0%                                            - 
substitute-command-keys
           4   0%                                             - 
generate-new-buffer
           4   0% get-buffer-create
           4   0% make-closure
          12   0%                                            - 
widget-specify-button
          12   0%                                             - 
widget-apply
           8   0%                                              - 
widget-default-button-face-get
           4   0% widget-get
           4   0%                                               - 
widget-apply
           4   0%                                                - 
widget-default-button-face-get
           4   0% - widget-apply
           4   0% - widget-default-button-face-get
           4 0%                                                   - 
widget-apply
           4 0%                                                    - 
widget-default-button-face-get
           4 0%                                                     - 
widget-apply
           4 0%                                                      - 
widget-default-button-face-get
           4 0%                                                       - 
widget-apply
           4 0%                                                        
- widget-default-button-face-get
           4 0%                                                         
- widget-apply
           4 
0%                                                          - 
widget-default-button-face-get
           4 
0%                                                           - widget-apply
           4 
0%                                                            - 
widget-default-button-face-get
           4 0% widget-get
           8   0% re-search-forward
           4   0% undo-auto--undoable-change
           4   0% widget-get
           4   0% widget-put
           4   0% widget-get-indirect
           4   0%                                          - widget-copy
           4   0%                                           - widget-apply
           4   0%                                            - 
widget-types-copy
           4   0%                                             - mapcar
           4   0%                                              - 
widget-copy
           4   0% widget-apply
        4027  15%                                         - apply
        4027  15%                                          - 
widget-create-child-and-convert
        4007  15%                                           - widget-apply
        4007  15%                                            - 
widget-default-create
        2712  10% delete-char
         743   2%                                             - 
widget-apply
         739   2%                                              - 
widget-toggle-value-create
         492   1%                                               - 
widget-image-insert
         492   1%                                                - 
insert-image
           4   0% - add-text-properties
           4 0% undo-auto--undoable-change
         207   0%                                               - 
widget-image-find
         199   0%                                                - 
find-image
         152   0% - apply
         152   0% - create-image
         148 0%                                                   - 
image-type
         148 0%                                                    - 
image-type-from-file-header
          68 0%                                                     - 
insert-file-contents-literally
          64 0%                                                      - 
insert-file-contents
           4 0%                                                       - 
after-insert-file-set-coding
           4 0% find-new-buffer-file-coding-system
          60 0% file-readable-p
           4 0% image-type-from-buffer
           4 0%                                                     - 
#<compiled -0x1c8e7723716d5d9f>
           4 0% kill-buffer
           4 0% set-buffer-multibyte
           4 0% image-compute-scaling-factor
          43   0% - image-search-load-path
          31 0% file-readable-p
           8 0% expand-file-name
           4 0% image--set-property
          28   0%                                               - 
substitute-command-keys
          12   0%                                                - 
#<compiled -0x1c8e7723a0f1519f>
          12   0% - kill-buffer
           8   0% - replace-buffer-in-windows
           4 0% window-normalize-buffer
           4 0%                                                   - 
unrecord-window-buffer
           4 0%                                                    - 
assq-delete-all
           4 0% assoc-delete-all
           8   0%                                                - 
generate-new-buffer
           8 0% get-buffer-create
           8   0% widget-get
           4   0%                                               - 
widget-value
           4   0% widget-apply
          24   0%                                             - 
widget-specify-button
           8   0% widget-get
           4   0% make-overlay
           4   0% overlay-put
           4   0% functionp
          20   0% re-search-forward
           4   0%                                             - 
widget-clear-undo
           4   0% buffer-disable-undo
          16   0%                                           - apply
          16   0%                                            - 
widget-convert
          12   0%                                             - 
widget-value-convert-widget
          12   0% widget-get
        2492   9%                                         - 
widget-create-child-value
        2492   9%                                          - widget-apply
        2492   9%                                           - 
widget-default-create
        1300   5% delete-char
         956   3%                                            - widget-apply
         956   3%                                             - 
widget-choice-value-create
         956   3%                                              - 
widget-create-child-value
         956   3%                                               - 
widget-apply
         948   3%                                                - 
widget-default-create
         628 2%                                                   
delete-char
          80   0% - widget-apply
          80 0% widget-field-value-create
          52 0%                                                   princ
           8 0% re-search-forward
           8   0%                                                - 
#<compiled 0x66e1b40451af649>
           8   0% - widget-sexp-value-to-internal
           4 0%                                                    
string-match
           4   0% - pp-to-string
           4 0%                                                   - 
#<compiled -0x1c8e7722b2c0b59f>
           4 0% kill-buffer
          16   0%                                            - 
substitute-command-keys
           8   0%                                             - 
#<compiled -0x1c8e77397563719f>
           8   0%                                              - 
kill-buffer
           8   0%                                               - 
replace-buffer-in-windows
           8   0%                                                - 
unrecord-window-buffer
           4 0% window-prev-buffers
           4   0% - window-normalize-window
           4 0% window-live-p
           4   0%                                             - 
generate-new-buffer
           4   0% get-buffer-create
           8   0%                                            - 
widget-specify-button
           4   0% widget-get
           4   0%                                             - 
widget-apply
           4   0%                                              - 
widget-default-mouse-face-get
           4   0% widget-get
           4   0% re-search-forward
           4   0%                                            - 
widget-clear-undo
           4   0% buffer-disable-undo
        1864   7% delete-char
           8   0% re-search-forward
           4   0%                                         - widget-apply
           4   0%                                          - 
widget-default-deactivate
           4   0%                                           - 
widget-specify-inactive
           4   0% make-overlay
           4   0% widget--should-indent-p
           4   0% widget-get
        7848  30%                                       - 
widget-editable-list-value-create
        7828  30%                                        - 
widget-editable-list-entry-create
        4112  15%                                         - 
widget-create-child-value
        4088  15%                                          - widget-apply
        4088  15%                                           - 
widget-default-create
        3576  13%                                            - widget-apply
        3576  13%                                             - 
widget-group-value-create
        2864  11%                                              - 
widget-create-child-value
        2848  10%                                               - 
widget-apply
        2840  10%                                                - 
widget-default-create
        2084 8%                                                   
delete-char
           8 0% re-search-forward
           8   0%                                               - 
widget-copy
           4   0% widget-apply
           4   0% widget-get
           4   0% widget-put
         696   2% insert-char
           8   0%                                              - 
widget-match-inline
           4   0%                                               - 
widget-inline-p
           4   0% widget-get
           4   0%                                               - 
widget-apply
           4   0%                                                - 
widget-checklist-match-inline
           4   0% - widget-match-inline
           4   0% - widget-inline-p
           4 0%                                                   - 
widget-apply
           4 0% widget-choice-inline-bubbles-p
           4   0% widget--should-indent-p
         348   1% delete-char
           4   0%                                            - 
undo-auto--undoable-change
           4   0% undo-auto--boundary-ensure-timer
          20   0%                                          - widget-copy
          20   0%                                           - widget-apply
          20   0%                                            - 
widget-types-copy
          20   0%                                             - mapcar
          20   0%                                              - 
widget-copy
          20   0%                                               - 
widget-apply
          12   0%                                                - 
widget-types-copy
          12   0% - mapcar
          12   0% - widget-copy
          12 0%                                                   - 
widget-apply
          12 0%                                                    - 
widget-types-copy
          12 0%                                                     - 
mapcar
          12 0%                                                      - 
widget-copy
          12 0%                                                       - 
widget-apply
           8 0%                                                        
- widget-types-copy
           8 0%                                                         
- mapcar
           8 
0%                                                          - widget-copy
           8 0% widget-apply
           4   0% widget-get
        2472   9%                                         - apply
        2472   9%                                          - 
widget-create-child-and-convert
        2468   9%                                           - widget-apply
        2468   9%                                            - 
widget-default-create
        1784   6% delete-char
         336   1%                                             - 
widget-apply
         336   1%                                              - 
widget-push-button-value-create
           8   0%                                               - 
substitute-command-keys
           4   0% buffer-string
          12   0%                                             - 
widget-specify-button
           8   0%                                              - 
widget-apply
           8   0%                                               - 
widget-default-mouse-face-get
           8   0%                                                - 
widget-apply
           8   0% - widget-default-mouse-face-get
           8   0% - widget-apply
           4 0%                                                   - 
widget-default-mouse-face-get
           4 0%                                                    - 
widget-apply
           4 0%                                                     - 
widget-default-mouse-face-get
           4 0% widget-get
           4   0% widget-get
           4   0% re-search-forward
           4   0% widget-get
         932   3% delete-char
         152   0% insert-char
          16   0%                                        - 
widget-match-inline
          16   0%                                         - widget-apply
           8   0%                                          - 
widget-group-match
           8   0%                                           - 
widget-group-match-inline
           4   0%                                            - 
widget-match-inline
           4   0% widget-apply
           8   0%                                          - 
widget-editable-list-match
           8   0%                                           - 
widget-editable-list-match-inline
           8   0%                                            - 
widget-match-inline
           8   0%                                             - 
widget-apply
           8   0%                                              - 
widget-group-match
           8   0%                                               - 
widget-group-match-inline
           8   0%                                                - 
widget-match-inline
           8   0% - widget-apply
           8   0% - widget-checklist-match-inline
           4 0%                                                   - 
widget-match-inline
           4 0%                                                    - 
widget-inline-p
           4 0%                                                     - 
widget-apply
           4 0%                                                      - 
widget-choice-inline-bubbles-p
           4 0% widget-get
           4 0%                                                   - 
widget-checklist-match-up
           4 0%                                                    - 
widget-match-inline
           4 0%                                                     - 
widget-apply
           4 0%                                                      - 
widget-choice-match
           4 0%                                                       - 
widget-apply
           4 0% widget-restricted-sexp-match
         388   1% widget-field-value-create
         124   0%                                       - 
widget-editable-list-format-handler
         116   0%                                        - apply
         116   0%                                         - 
widget-create-child-and-convert
         116   0%                                          - widget-apply
         116   0%                                           - 
widget-default-create
          96   0% delete-char
          20   0%                                            - widget-apply
          20   0% widget-push-button-value-create
           8   0% insert-char
         264   1% delete-char
           4   0%                                      - 
widget-specify-sample
           4   0% widget-apply
           4   0%                                      - 
undo-auto--undoable-change
           4   0% undo-auto--boundary-ensure-timer
           4   0%                                      - 
substitute-command-keys
           4   0%                                       - #<compiled 
-0x1c8e77201f7fa59f>
           4   0%                                        - kill-buffer
           4   0%                                         - 
replace-buffer-in-windows
           4   0%                                          - 
unrecord-window-buffer
           4   0% window-prev-buffers
          12   0%                                     insert-char
           4   0%                                   delete-char
          92   0%                              - apply
          92   0%                               - 
widget-create-child-and-convert
          92   0%                                - widget-apply
          92   0%                                 - widget-default-create
          64   0%                                    delete-char
          16   0%                                  - widget-apply
          16   0% widget-push-button-value-create
          40   0%                                delete-char
           4   0% custom-magic-value-create
           8   0%                   - 
widget-add-documentation-string-button
           8   0%                    - apply
           8   0%                     - widget-create-child-and-convert
           8   0%                      - widget-apply
           8   0%                       - widget-default-create
           4   0%                          delete-char
           4   0%                        - widget-apply
           4   0% widget-documentation-string-value-create
           4   0%                   - custom-add-parent-links
           4   0%                    - mapatoms
           4   0%                     - #<compiled 0x2608cc6bf83bc8>
           4   0%                      - widget-create-child-and-convert
           4   0%                       - widget-apply
           4   0%                        - widget-default-create
           4   0%                           delete-char
          16   0%             - #<compiled -0xf2f5b00c7bd4f2d>
          16   0%              - widget-apply
          16   0%               - widget-default-value-inline
          16   0%                - widget-value
          16   0%                 - widget-apply
          16   0%                  - widget-editable-list-value-get
          16   0%                   - mapcar
          16   0%                    - #<compiled -0xf2f5b00c7bd4f2d>
          16   0%                     - widget-apply
          16   0%                      - widget-default-value-inline
          16   0%                       - widget-value
          16   0%                        - widget-apply
           8   0%                         - widget-editable-list-value-get
           8   0%                          - mapcar
           8   0%                           - #<compiled 
-0xf2f5b00c7bd4f2d>
           8   0%                            - widget-apply
           8   0%                             - widget-default-value-inline
           8   0%                              - widget-value
           8   0%                               - widget-apply
           8   0%                                - 
widget-editable-list-value-get
           8   0%                                 - mapcar
           4   0%                                  - #<compiled 
-0xf2f5b00c7bd4f2d>
           4   0%                                   - widget-apply
           4   0%                                    - 
widget-default-value-inline
           4   0%                                       widget-get
           8   0%                         - widget-checklist-value-get
           4   0%                          - widget-apply
           4   0%                           - widget-child-value-inline
           4   0%                            - widget-apply
           4   0%                             - widget-default-value-inline
           4   0%                              - widget-value
           4   0%                                 widget-apply
           4   0%                          - widget-value
           4   0%                             widget-apply
         368   1%              widget-setup
           8   0%            - mapc
           8   0%             - custom-magic-reset
           8   0%              - widget-value-set
           8   0%               - widget-apply
           8   0%                - widget-default-value-set
           8   0%                 - widget-apply
           4   0%                  - widget-default-delete
           4   0%                   - widget-apply
           4   0%                    - widget-children-value-delete
           4   0%                     - mapc
           4   0%                      - widget-delete
           4   0%                       - widget-apply
           4   0%                          widget-default-delete
           4   0%                  - widget-default-create
           4   0%                   - widget-apply
           4   0%                    - custom-magic-value-create
           4   0%                     - widget-create-child-and-convert
           4   0%                      - widget-apply
           4   0%                       - widget-default-create
           4   0%                          delete-char
           8   0%          - byte-code
           8   0%           - require
           8   0%            - load-with-code-conversion
           8   0%             - eval-buffer
           8   0%                read
           4   0%            read
           4   0%         - profiler-stop
           4   0%            profiler-cpu-log
         635   2%   Automatic GC
           4   0% - ...
           4   0%  - widget-types-convert-widget
           4   0%   - mapcar
           4   0%    - widget-convert
           4   0%     - widget-types-convert-widget
           4   0%      - mapcar
           4   0%       - widget-convert
           4   0%        - widget-types-convert-widget
           4   0%         - mapcar
           4   0%          - widget-convert
           4   0%           - widget-types-convert-widget
           4   0%            - mapcar
           4   0%             - widget-convert
           4   0%              - widget-apply
           4   0%               - #<compiled 0x66e1b40451af649>
           4   0%                - widget-sexp-value-to-internal
           4   0%                   pp-to-string

[profiler-data (text/plain, attachment)]

Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Sun, 10 Sep 2023 10:44:01 GMT) Full text and rfc822 format available.

Message #22 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Mauro Aranda <maurooaranda <at> gmail.com>
Cc: 53606 <at> debbugs.gnu.org
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Sun, 10 Sep 2023 13:43:07 +0300
> Date: Sun, 10 Sep 2023 06:49:29 -0300
> Cc: 53606 <at> debbugs.gnu.org
> From: Mauro Aranda <maurooaranda <at> gmail.com>
> 
> On 10/9/23 02:01, Eli Zaretskii wrote:
>  > Could you please profile this slow operation and post the completely
>  > unfolded profile?  I think we should try to understand what exactly
>  > takes so much time in this case.
> 
> Here it is.  I also attach the result of C-x C-w in the report buffer,
> just in case.

So the hot spot seems to be widget-checklist-add-item, is that right?
And inside that widget-create-child and widget-apply?




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Sun, 10 Sep 2023 10:50:02 GMT) Full text and rfc822 format available.

Message #25 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Ihor Radchenko <yantar92 <at> posteo.net>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 53606 <at> debbugs.gnu.org, Mauro Aranda <maurooaranda <at> gmail.com>
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Sun, 10 Sep 2023 10:50:13 +0000
Eli Zaretskii <eliz <at> gnu.org> writes:

>> Here it is.  I also attach the result of C-x C-w in the report buffer,
>> just in case.
>
> So the hot spot seems to be widget-checklist-add-item, is that right?
> And inside that widget-create-child and widget-apply?

No, I think. Reverse call tree shows

       17747  68% - delete-char
       14911  57%  + widget-default-create
        1864   7%  + widget-checklist-add-item
         972   3%  + widget-editable-list-entry-create
        3320  12% + widget-default-create

which likely corresponds to ";; Parse % escapes in format." code,
present in `widget-default-create', `widget-checklist-add-item', and
`widget-editable-list-entry-create'.

-- 
Ihor Radchenko // yantar92,
Org mode contributor,
Learn more about Org mode at <https://orgmode.org/>.
Support Org development at <https://liberapay.com/org-mode>,
or support my work at <https://liberapay.com/yantar92>




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Sun, 10 Sep 2023 12:42:01 GMT) Full text and rfc822 format available.

Message #28 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Mauro Aranda <maurooaranda <at> gmail.com>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: 53606 <at> debbugs.gnu.org
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Sun, 10 Sep 2023 09:41:27 -0300
On 10/9/23 07:43, Eli Zaretskii wrote:
>> Date: Sun, 10 Sep 2023 06:49:29 -0300
>> Cc: 53606 <at> debbugs.gnu.org
>> From: Mauro Aranda <maurooaranda <at> gmail.com>
>>
>> On 10/9/23 02:01, Eli Zaretskii wrote:
>>  > Could you please profile this slow operation and post the completely
>>  > unfolded profile?  I think we should try to understand what exactly
>>  > takes so much time in this case.
>>
>> Here it is.  I also attach the result of C-x C-w in the report buffer,
>> just in case.
>
> So the hot spot seems to be widget-checklist-add-item, is that right?

I think so.  The checklist widgets were my first suspects, since
creating them is rather slow.

> And inside that widget-create-child and widget-apply?

I don't think those functions could be the bottleneck.  Most likely it
is the widget-default-create function that those functions end up
calling.  So yes, widget-default-create in general, and
widget-checklist-value-create in particular should be investigated for
speeding them up, but I don't have any ideas at the moment.





Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Mon, 18 Sep 2023 11:08:02 GMT) Full text and rfc822 format available.

Message #31 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Mauro Aranda <maurooaranda <at> gmail.com>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: Ihor Radchenko <yantar92 <at> posteo.net>, 53606 <at> debbugs.gnu.org
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Mon, 18 Sep 2023 08:07:08 -0300
[Message part 1 (text/plain, inline)]
On 10/9/23 09:41, Mauro Aranda wrote:
> On 10/9/23 07:43, Eli Zaretskii wrote:
> >> Date: Sun, 10 Sep 2023 06:49:29 -0300
> >> Cc: 53606 <at> debbugs.gnu.org
> >> From: Mauro Aranda <maurooaranda <at> gmail.com>
> >>
> >> On 10/9/23 02:01, Eli Zaretskii wrote:
> >>  > Could you please profile this slow operation and post the 
completely
> >>  > unfolded profile?  I think we should try to understand what exactly
> >>  > takes so much time in this case.
> >>
> >> Here it is.  I also attach the result of C-x C-w in the report buffer,
> >> just in case.
> >
> > So the hot spot seems to be widget-checklist-add-item, is that right?
>
> I think so.  The checklist widgets were my first suspects, since
> creating them is rather slow.
>
> > And inside that widget-create-child and widget-apply?
>
> I don't think those functions could be the bottleneck.  Most likely it
> is the widget-default-create function that those functions end up
> calling.  So yes, widget-default-create in general, and
> widget-checklist-value-create in particular should be investigated for
> speeding them up, but I don't have any ideas at the moment.

I focused on the format handling, since there's no need to insert the
escape formats in the buffer.  So I rearranged the 4 functions that
handle the format to avoid it and here are the figures I got, when
running:
(benchmark-run 5
  (customize-option 'bibtex-biblatex-entry-alist))

From master, inserting either :format or :entry-format:
(130.200276352 291 3.1221133909999996)

Without inserting it:
(38.244185927000004 266 2.795578699)

| How?                 | Total elapsed time (5 repetitions) | Avg | 
Times faster |
|----------------------+------------------------------------+-------+--------------|
| inserting format     |                             130.20 | 26.04 
|            1 |
| not inserting format |                              38.24 | 7.65 
|          3.4 |

All data is without native compilation.  I'd appreciate if someone could
at least run it once with native compilation, with and without my patch.


I attach a patch with the changes, and the new profiler report, but I'm
inclined to leave it as it is if the patch gets accepted.
[0001-Speed-up-widget-creation-Bug-53606.patch (text/x-patch, attachment)]
[profiler-data-no-inserting (text/plain, attachment)]
[profiler-results-no-inserting (text/plain, attachment)]

Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Thu, 21 Dec 2023 11:49:02 GMT) Full text and rfc822 format available.

Message #34 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Ihor Radchenko <yantar92 <at> posteo.net>
To: Mauro Aranda <maurooaranda <at> gmail.com>
Cc: Eli Zaretskii <eliz <at> gnu.org>, 53606 <at> debbugs.gnu.org
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Thu, 21 Dec 2023 11:51:14 +0000
Mauro Aranda <maurooaranda <at> gmail.com> writes:

> I focused on the format handling, since there's no need to insert the
> escape formats in the buffer.  So I rearranged the 4 functions that
> handle the format to avoid it and here are the figures I got, when
> running:
> (benchmark-run 5
>    (customize-option 'bibtex-biblatex-entry-alist))
>
>  From master, inserting either :format or :entry-format:
> (130.200276352 291 3.1221133909999996)
>
> Without inserting it:
> (38.244185927000004 266 2.795578699)
> ...
> All data is without native compilation.  I'd appreciate if someone could
> at least run it once with native compilation, with and without my patch.

I do not see much difference with native compilation:

- without the patch :: (134.779200699 247 4.294675525)
- with the patch :: (39.828912859 249 3.881637917)

But your patch is still making things faster.

-- 
Ihor Radchenko // yantar92,
Org mode contributor,
Learn more about Org mode at <https://orgmode.org/>.
Support Org development at <https://liberapay.com/org-mode>,
or support my work at <https://liberapay.com/yantar92>




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Sun, 17 Nov 2024 22:52:02 GMT) Full text and rfc822 format available.

Message #37 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Roland Winkler <winkler <at> gnu.org>
To: bug-gnu-emacs <at> gnu.org
Subject: Re: bug#53606: 29.0.50;
 Very slow Customize buffer for bibtex-biblatex-entry-alist
Date: Sun, 17 Nov 2024 16:51:07 -0600
I looked at this old bug again (while working on BibTeX mode), and I
noticed that one piece of information was missing in this thread that
could be helpful:

Lars filed this report against Emacs 29.  Back then, I had still access
to emacs 25.1 and 27.1.  On the same machine emacs 25.1 needed about 2s,
whereas 27.1 needed 20s to initialize the customize buffer for
bibtex-biblatex-entry-alist.  So it seems something in the customize or
widget library was changed that resulted in the slowdown.  Nothing
changed on the side of BibTeX mode back then.

I just filed bug #74409 that is also about the customize buffer for
bibtex-biblatex-entry-alist.  It is likewise about a problem that exists
only with more recent versions of emacs.  But I do not know whether
these problems are truly related, or some symptoms just happen to be
similar.





Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Mon, 18 Nov 2024 12:16:02 GMT) Full text and rfc822 format available.

Message #40 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Roland Winkler <winkler <at> gnu.org>
Cc: 53606 <at> debbugs.gnu.org
Subject: Re: bug#53606: 29.0.50;
 Very slow Customize buffer for bibtex-biblatex-entry-alist
Date: Mon, 18 Nov 2024 14:15:14 +0200
> From: Roland Winkler <winkler <at> gnu.org>
> Date: Sun, 17 Nov 2024 16:51:07 -0600
> 
> I looked at this old bug again (while working on BibTeX mode), and I
> noticed that one piece of information was missing in this thread that
> could be helpful:
> 
> Lars filed this report against Emacs 29.  Back then, I had still access
> to emacs 25.1 and 27.1.  On the same machine emacs 25.1 needed about 2s,
> whereas 27.1 needed 20s to initialize the customize buffer for
> bibtex-biblatex-entry-alist.  So it seems something in the customize or
> widget library was changed that resulted in the slowdown.  Nothing
> changed on the side of BibTeX mode back then.

Running the recipe after "M-x profiler-start RET RET" might show which
part(s) of the code take most of the time.




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Fri, 07 Feb 2025 10:46:01 GMT) Full text and rfc822 format available.

Message #43 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Mauro Aranda <maurooaranda <at> gmail.com>
To: 53606 <at> debbugs.gnu.org
Cc: Lars Ingebrigtsen <larsi <at> gnus.org>, Eli Zaretskii <eliz <at> gnu.org>,
 Ihor Radchenko <yantar92 <at> posteo.net>, Roland Winkler <winkler <at> gnu.org>
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Fri, 7 Feb 2025 07:45:17 -0300
[Message part 1 (text/plain, inline)]
I'm posting my patch for this bug again. It stills shows a 3-3.5
improvement over the current code in wid-edit.el, and together with the
changes Roland made, it brings the time needed to create the buffer from
20+ seconds to about 4 seconds in my machine.

Profiler data has not changed much from the ones I posted back then.
[0001-Speed-up-widget-creation-Bug-53606.patch (text/x-patch, attachment)]

Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Sat, 22 Feb 2025 09:21:03 GMT) Full text and rfc822 format available.

Message #46 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Mauro Aranda <maurooaranda <at> gmail.com>
Cc: larsi <at> gnus.org, 53606 <at> debbugs.gnu.org, yantar92 <at> posteo.net, winkler <at> gnu.org
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Sat, 22 Feb 2025 11:20:33 +0200
> Date: Fri, 7 Feb 2025 07:45:17 -0300
> Cc: Roland Winkler <winkler <at> gnu.org>, Eli Zaretskii <eliz <at> gnu.org>,
>  Lars Ingebrigtsen <larsi <at> gnus.org>, Ihor Radchenko <yantar92 <at> posteo.net>
> From: Mauro Aranda <maurooaranda <at> gmail.com>
> 
> I'm posting my patch for this bug again. It stills shows a 3-3.5
> improvement over the current code in wid-edit.el, and together with the
> changes Roland made, it brings the time needed to create the buffer from
> 20+ seconds to about 4 seconds in my machine.
> 
> Profiler data has not changed much from the ones I posted back then.

There were no further comments, so I've now installed this on the
master branch, thanks.

Can we now close this bug, or is there anything left to do here?




Information forwarded to bug-gnu-emacs <at> gnu.org:
bug#53606; Package emacs. (Sat, 22 Feb 2025 09:38:03 GMT) Full text and rfc822 format available.

Message #49 received at 53606 <at> debbugs.gnu.org (full text, mbox):

From: Mauro Aranda <maurooaranda <at> gmail.com>
To: Eli Zaretskii <eliz <at> gnu.org>
Cc: larsi <at> gnus.org, 53606 <at> debbugs.gnu.org, yantar92 <at> posteo.net, winkler <at> gnu.org
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Sat, 22 Feb 2025 06:37:10 -0300
Eli Zaretskii <eliz <at> gnu.org> writes:

>> Date: Fri, 7 Feb 2025 07:45:17 -0300
>> Cc: Roland Winkler <winkler <at> gnu.org>, Eli Zaretskii <eliz <at> gnu.org>,
>>  Lars Ingebrigtsen <larsi <at> gnus.org>, Ihor Radchenko 
<yantar92 <at> posteo.net>
>> From: Mauro Aranda <maurooaranda <at> gmail.com>
>>
>> I'm posting my patch for this bug again. It stills shows a 3-3.5
>> improvement over the current code in wid-edit.el, and together with the
>> changes Roland made, it brings the time needed to create the buffer from
>> 20+ seconds to about 4 seconds in my machine.
>>
>> Profiler data has not changed much from the ones I posted back then.
>
> There were no further comments, so I've now installed this on the
> master branch, thanks.

Thank you Eli.

> Can we now close this bug, or is there anything left to do here?

I think this can be closed.




Reply sent to Eli Zaretskii <eliz <at> gnu.org>:
You have taken responsibility. (Sat, 22 Feb 2025 11:15:02 GMT) Full text and rfc822 format available.

Notification sent to Lars Ingebrigtsen <larsi <at> gnus.org>:
bug acknowledged by developer. (Sat, 22 Feb 2025 11:15:02 GMT) Full text and rfc822 format available.

Message #54 received at 53606-done <at> debbugs.gnu.org (full text, mbox):

From: Eli Zaretskii <eliz <at> gnu.org>
To: Mauro Aranda <maurooaranda <at> gmail.com>
Cc: larsi <at> gnus.org, yantar92 <at> posteo.net, 53606-done <at> debbugs.gnu.org,
 winkler <at> gnu.org
Subject: Re: bug#53606: 29.0.50; Very slow Customize buffer for
 bibtex-biblatex-entry-alist
Date: Sat, 22 Feb 2025 13:13:50 +0200
> Date: Sat, 22 Feb 2025 06:37:10 -0300
> Cc: 53606 <at> debbugs.gnu.org, winkler <at> gnu.org, larsi <at> gnus.org,
>  yantar92 <at> posteo.net
> From: Mauro Aranda <maurooaranda <at> gmail.com>
> 
> Eli Zaretskii <eliz <at> gnu.org> writes:
> 
>  >> Date: Fri, 7 Feb 2025 07:45:17 -0300
>  >> Cc: Roland Winkler <winkler <at> gnu.org>, Eli Zaretskii <eliz <at> gnu.org>,
>  >>  Lars Ingebrigtsen <larsi <at> gnus.org>, Ihor Radchenko 
> <yantar92 <at> posteo.net>
>  >> From: Mauro Aranda <maurooaranda <at> gmail.com>
>  >>
>  >> I'm posting my patch for this bug again. It stills shows a 3-3.5
>  >> improvement over the current code in wid-edit.el, and together with the
>  >> changes Roland made, it brings the time needed to create the buffer from
>  >> 20+ seconds to about 4 seconds in my machine.
>  >>
>  >> Profiler data has not changed much from the ones I posted back then.
>  >
>  > There were no further comments, so I've now installed this on the
>  > master branch, thanks.
> 
> Thank you Eli.
> 
>  > Can we now close this bug, or is there anything left to do here?
> 
> I think this can be closed.

Done.




bug archived. Request was from Debbugs Internal Request <help-debbugs <at> gnu.org> to internal_control <at> debbugs.gnu.org. (Sat, 22 Mar 2025 11:24:05 GMT) Full text and rfc822 format available.

This bug report was last modified 47 days ago.

Previous Next


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