Subject: bug#40733: 28.0.50; Emacs locks up on paste (yank) of unicode characters

From: Will Bush <[email-masked]>
Date: Wed, 29 Apr 2020 07:42:20 -0500

Did you see my other message that I forwarded where I forgot to CC
everyone? I
was able to switch between a bunch of revisions of the master branch to see
where the performance issue started, and it appears to have started with
commit
(88efc736f5 Default cairo to enabled). I was hoping that would narrow it
down.
Maybe an upstream bug needs to be reported.

Here is the profiler report without stopping:

- command-execute                                                  29  37%
 - call-interactively                                              29  37%
  - byte-code                                                      21  27%
   - read-extended-command                                         21  27%
    - completing-read                                              21  27%
     - completing-read-default                                     21  27%
      - read-from-minibuffer                                       15  19%
       - redisplay_internal (C function)                            1   1%
        - tool-bar-make-keymap                                      1   1%
         - tool-bar-make-keymap-1                                   1   1%
          - mapcar                                                  1   1%
           - #<compiled -0xdd262bffb4f5e94>                         1   1%
            - eval                                                  1   1%
             - find-image                                           1   1%
                image-search-load-path                              1   1%
  - funcall-interactively                                           8  10%
   - execute-extended-command                                       7   9%
    - sit-for                                                       6   7%
       redisplay                                                    5   6%
    - command-execute                                               1   1%
     - call-interactively                                           1   1%
      - funcall-interactively                                       1   1%
         profiler-report                                            1   1%
   - yank                                                           1   1%
    - current-kill                                                  1   1%
     - gui-selection-value                                          1   1%
      - gui--selection-value-internal                               1   1%
       - gui-get-selection                                          1   1%
        - gui-backend-get-selection                                 1   1%
         - cl--generic-cache-miss                                   1   1%
          - cl--generic-make-next-function                          1   1%
           - cl--generic-build-combined-method                      1   1%
            - cl-generic-combine-methods                            1   1%
               cl--generic-standard-method-combination                  1
1%
- ...                                                              25  32%
   Automatic GC                                                    19  24%
 - minibuffer-complete                                              6   7%
  - completion-in-region                                            6   7%
   - completion--in-region                                          6   7%
    - #<compiled -0x1e2e37146f1969ab>                               6   7%
     - apply                                                        6   7%
      - #<compiled 0x1148c3ec647cd895>                              6   7%
       - completion--in-region-1                                    6   7%
        - completion--do-completion                                 6   7%
         - completion-try-completion                                4   5%
          - completion--nth-completion                              4   5%
           - completion--some                                       4   5%
            - #<compiled 0x193a0f848bfa1981>                        4   5%
             - completion-basic-try-completion                      4   5%
              - try-completion                                      4   5%
               - #<compiled -0x1b219ba5d00e6b5b>                    4   5%
                  complete-with-action                              4   5%
         - minibuffer-completion-help                               2   2%
          - completion-all-completions                              1   1%
           - completion--nth-completion                             1   1%
            - completion--some                                      1   1%
             - #<compiled 0x193a0460dbba5781>                       1   1%
              - completion-basic-all-completions                    1   1%
               - completion-pcm--all-completions                    1   1%
                - all-completions                                   1   1%
                 - #<compiled -0x1b219ba5d00e6b5b>                  1   1%
                    complete-with-action                            1   1%
          - temp-buffer-window-show                                 1   1%
           - display-buffer                                         1   1%
            - display-buffer-at-bottom                              1   1%
             - walk-window-tree                                     1   1%
              - walk-window-tree-1                                  1   1%
               - #<compiled -0xe1696a80dea244c>                     1   1%
                  window-in-direction                               1   1%
- mouse--click-1-maybe-follows-link                                23  29%
 - time-since                                                      11  14%
    byte-code                                                      11  14%

Ran it again with this set first (didn't seem any faster, but I didn't
measure how long):
(setq gc-cons-threshold most-positive-fixnum)

- command-execute                                                  63  80%
 - call-interactively                                              63  80%
  - funcall-interactively                                          49  62%
   - execute-extended-command                                      48  61%
    - execute-extended-command--shorter                            37  47%
     - completion-try-completion                                   37  47%
      - completion--nth-completion                                 37  47%
       - completion--some                                          37  47%
        - #<compiled 0x8040425f3c02ca8>                            37  47%
         - completion-pcm-try-completion                           29  37%
          - completion-pcm--find-all-completions                   28  35%
             completion-pcm--all-completions                       28  35%
            completion-pcm--merge-try                               1   1%
           completion-basic-try-completion                          8  10%
    - sit-for                                                      10  12%
       redisplay                                                    5   6%
    - command-execute                                               1   1%
     - call-interactively                                           1   1%
      - funcall-interactively                                       1   1%
         profiler-report                                            1   1%
   - yank                                                           1   1%
    - insert-for-yank                                               1   1%
       insert-for-yank-1                                            1   1%
  - byte-code                                                      14  17%
   - read-extended-command                                         14  17%
    - completing-read                                              14  17%
     - completing-read-default                                     14  17%
        read-from-minibuffer                                        6   7%
- ...                                                              13  16%
   Automatic GC                                                    12  15%
 - minibuffer-complete                                              1   1%
  - completion-in-region                                            1   1%
   - completion--in-region                                          1   1%
    - #<compiled -0x1e2d5057a11b69ab>                               1   1%
     - apply                                                        1   1%
      - #<compiled -0x29426ad1f232709>                              1   1%
       - completion--in-region-1                                    1   1%
        - completion--do-completion                                 1   1%
         - completion-try-completion                                1   1%
          - completion--nth-completion                              1   1%
           - completion--some                                       1   1%
            - #<compiled -0x1aaa3a826ece83ff>                       1   1%
             - completion-basic-try-completion                      1   1%
              - try-completion                                      1   1%
               - #<compiled -0x4b2d19c512e6b51>                     1   1%
                  complete-with-action                              1   1%
- redisplay_internal (C function)                                   1   1%
 - tool-bar-make-keymap                                             1   1%
  - tool-bar-make-keymap-1                                          1   1%
   - mapcar                                                         1   1%
    - #<compiled -0x73a15eecd6f5e94>                                1   1%
     - eval                                                         1   1%
      - find-image                                                  1   1%
         image-search-load-path                                     1   1%
- timer-event-handler                                               1   1%
 - timer-activate-when-idle                                         1   1%
  - timer--activate                                                 1   1%
     timer--time-less-p                                             1   1%

On Wed, Apr 29, 2020 at 7:16 AM Eli Zaretskii <[email-masked]> wrote:

> > From: Will Bush <[email-masked]>
> > Date: Wed, 29 Apr 2020 06:59:42 -0500
> > Cc: Robert Pluim <[email-masked]>, "Basil L. Contovounesios" <
> [email-masked]>, [email-masked],
> >       James Cloos <[email-masked]>
> >
> >  It would be good to know what happens in Emacs during those 88
> >  seconds.  Please try using "M-x profiler" to find out.
> >
> > Here's what I get with `M-x profiler-start`, using the default cpu
> sampling,
> > `C-y` the character into a scratch buffer, wait for the character to
> show up,
> > `M-x profiler-stop`, and start `M-x profiler-report`:
>
> You shouldn't invoke profiler-stop, it affects the profile.  Just
> profiler-start, do what you want to profile, then profiler-report.
>
> From what you posted, it looks like GC is a major player, but it's
> hard to be sure (and 88 sec is a lot of time for a GC).  Please show
> the profile collected as suggested above.
>
> Thanks.
>

On Wed, Apr 29, 2020 at 7:16 AM Eli Zaretskii <[email-masked]> wrote:

> > From: Will Bush <[email-masked]>
> > Date: Wed, 29 Apr 2020 06:59:42 -0500
> > Cc: Robert Pluim <[email-masked]>, "Basil L. Contovounesios" <
> [email-masked]>, [email-masked],
> >       James Cloos <[email-masked]>
> >
> >  It would be good to know what happens in Emacs during those 88
> >  seconds.  Please try using "M-x profiler" to find out.
> >
> > Here's what I get with `M-x profiler-start`, using the default cpu
> sampling,
> > `C-y` the character into a scratch buffer, wait for the character to
> show up,
> > `M-x profiler-stop`, and start `M-x profiler-report`:
>
> You shouldn't invoke profiler-stop, it affects the profile.  Just
> profiler-start, do what you want to profile, then profiler-report.
>
> From what you posted, it looks like GC is a major player, but it's
> hard to be sure (and 88 sec is a lot of time for a GC).  Please show
> the profile collected as suggested above.
>
> Thanks.
>