Package: emacs;
Reported by: Robert Thorpe <rt <at> robertthorpeconsulting.com>
Date: Fri, 13 Nov 2020 02:52:02 UTC
Severity: normal
Found in version 27.1
Message #14 received at 44610 <at> debbugs.gnu.org (full text, mbox):
From: Jean Louis <bugs <at> gnu.support> To: Eli Zaretskii <eliz <at> gnu.org> Cc: Robert Thorpe <rt <at> robertthorpeconsulting.com>, 44610 <at> debbugs.gnu.org Subject: Re: bug#44610: 27.1; Keyboard Macro Performance Problem Date: Sat, 14 Nov 2020 19:03:11 +0300
* Eli Zaretskii <eliz <at> gnu.org> [2020-11-14 17:27]:
> > From: Robert Thorpe <rt <at> robertthorpeconsulting.com>
> > Date: Fri, 13 Nov 2020 02:51:12 +0000
> >
> >
> > This bug report comes from a discussion on Emacs reddit.
> >
> > Start with a blank buffer and create about ~300 lines of the string:
> >
> > ffffffffffffffffffff (pppppppppppppppppppp);
> >
> > This will be turned into:
> >
> > 'ffffffffffffffffffff':
> >
> > That can be done using the following keyboard macro: M-m ' M-f ' : C-k
> > C-n
> >
> > You can apply that to every line in the buffer using C-u 300 f4.
> >
> > Now here's the strange bit. In a fundamental-mode buffer this is
> > extremely fast, nearly instantaneous. But, in a python-mode buffer it
> > takes 20 to 30 seconds. If the mode is c-mode then it is also much
> > slower than fundamental-mode. It will also exceed the variable binding
> > depth in some cases. Oddly it is faster if you use forward-line instead
> > of C-n.
>
> I suggest to produce and present a profile of this. Invoke this macro
> after "M-x profiler-start RET RET", then "M-x profiler-report RET",
> expand the profile fully by "C-u RET" on the top line, and post the
> result here. That should give some clues.
That is great advise to learn from. Macro took just about less than 2
seconds on my notebook Lenovo Thinkpad T410.
I am not the initial reporter. I have tested it in python-mode in
plain emacs -Q with the latest development version:
- command-execute 20,601,881 99%
- call-interactively 20,601,881 99%
- funcall-interactively 19,934,160 96%
- kmacro-end-or-call-macro 15,337,767 74%
- kmacro-call-macro 15,337,767 74%
- call-last-kbd-macro 15,242,727 73%
- command-execute 15,102,838 73%
- call-interactively 15,021,006 72%
- funcall-interactively 14,985,294 72%
- next-line 13,970,433 67%
- line-move 13,968,321 67%
- line-move-visual 12,842,225 62%
- vertical-motion 9,925,619 48%
- jit-lock-function 9,925,619 48%
- jit-lock-fontify-now 9,925,619 48%
- jit-lock--run-functions 7,165,300 34%
- run-hook-wrapped 7,157,012 34%
- #<compiled 0x5b100c193163db5> 7,157,012 34%
- font-lock-fontify-region 7,157,012 34%
- font-lock-default-fontify-region 7,153,844 34%
- font-lock-fontify-keywords-region 5,169,903 25%
#<compiled 0x19a45f465d8aaf17> 369,664 1%
#<compiled -0x1210e8980f7ecafc> 308,861 1%
- python--font-lock-f-strings 306,448 1%
syntax-ppss 11,536 0%
- font-lock-fontify-syntactically-region 1,975,653 9%
- python-font-lock-syntactic-face-function 1,889,981 9%
- python-info-docstring-p 1,878,263 9%
- python-nav-backward-sexp 1,150,110 5%
- python-nav-forward-sexp 1,144,830 5%
- python-nav--forward-sexp 1,144,830 5%
- python-info-beginning-of-block-p 519,389 2%
- python-info-statement-starts-block-p 407,940 1%
- python-nav-beginning-of-statement 100,032 0%
- syntax-ppss 46,400 0%
#<compiled 0x1c65d0f034163548> 4,320 0%
- python-info-line-ends-backslash-p 45,344 0%
- syntax-ppss 45,344 0%
#<compiled 0x1c65d0f034163548> 4,320 0%
- python-info-beginning-of-statement-p 103,161 0%
- python-nav-beginning-of-statement 103,161 0%
- syntax-ppss 54,825 0%
make-byte-code 4,377 0%
- python-info-line-ends-backslash-p 35,904 0%
syntax-ppss 35,904 0%
- python-info-current-line-empty-p 307,473 1%
beginning-of-line 4,377 0%
- python-info-end-of-block-p 130,384 0%
- python-info-end-of-statement-p 130,384 0%
- python-nav-end-of-statement 130,384 0%
syntax-ppss 91,472 0%
- python-info-line-ends-backslash-p 34,768 0%
syntax-ppss 34,768 0%
- python-info-beginning-of-statement-p 116,336 0%
- python-nav-beginning-of-statement 116,336 0%
- python-info-line-ends-backslash-p 55,648 0%
syntax-ppss 55,648 0%
syntax-ppss 44,112 0%
- python-nav-beginning-of-statement 53,456 0%
- python-info-line-ends-backslash-p 21,040 0%
syntax-ppss 21,040 0%
syntax-ppss 19,984 0%
- python-syntax-context-type 9,504 0%
syntax-ppss 9,504 0%
- python-info-assignment-statement-p 314,499 1%
- python-nav-beginning-of-statement 19,587 0%
- python-info-line-ends-backslash-p 7,392 0%
syntax-ppss 7,392 0%
syntax-ppss 6,336 0%
- python-nav-beginning-of-statement 36,902 0%
- syntax-ppss 22,595 0%
#<compiled 0x1c65d0f034163548> 5,859 0%
- python-info-line-ends-backslash-p 8,448 0%
syntax-ppss 8,448 0%
syntax-ppss 27,216 0%
replace-regexp-in-string 2,112 0%
font-lock-unfontify-region 4,144 0%
- run-with-timer 2,730,692 13%
- apply 2,730,692 13%
- run-at-time 2,729,636 13%
- timer-activate 2,717,252 13%
- timer--activate 2,716,196 13%
- timer--time-less-p 2,716,196 13%
timer--time 36,054 0%
time-less-p 24,036 0%
- timer-set-time 12,384 0%
timer--time-setter 12,384 0%
make-byte-code 5,859 0%
- posn-at-point 2,878,318 13%
file-remote-p 2,360,868 11%
- jit-lock-function 340,326 1%
- jit-lock-fontify-now 340,326 1%
- jit-lock--run-functions 335,086 1%
- run-hook-wrapped 330,942 1%
- #<compiled 0x5b100c193163db5> 330,942 1%
- font-lock-fontify-region 330,942 1%
- font-lock-default-fontify-region 329,886 1%
- font-lock-fontify-keywords-region 202,469 0%
#<compiled 0x19a45f465d8aaf17> 15,872 0%
- python--font-lock-f-strings 15,456 0%
syntax-ppss 3,168 0%
#<compiled -0x1210e8980f7ecafc> 12,288 0%
- font-lock-fontify-syntactically-region 123,273 0%
- python-font-lock-syntactic-face-function 99,145 0%
- python-info-docstring-p 99,145 0%
- python-nav-backward-sexp 49,329 0%
- python-nav-forward-sexp 48,273 0%
- python-nav--forward-sexp 48,273 0%
- python-info-beginning-of-block-p 15,105 0%
python-info-statement-starts-block-p 15,105 0%
- python-nav-beginning-of-statement 12,512 0%
syntax-ppss 8,368 0%
python-info-current-line-empty-p 12,288 0%
- python-syntax-context-type 4,224 0%
syntax-ppss 4,224 0%
- python-info-beginning-of-statement-p 4,144 0%
python-nav-beginning-of-statement 4,144 0%
- python-info-assignment-statement-p 20,784 0%
- python-nav-beginning-of-statement 8,368 0%
- python-info-line-ends-backslash-p 3,168 0%
syntax-ppss 3,168 0%
syntax-ppss 1,056 0%
- python-nav-beginning-of-statement 8,368 0%
syntax-ppss 2,112 0%
- python-info-line-ends-backslash-p 2,112 0%
syntax-ppss 2,112 0%
syntax-ppss 8,368 0%
replace-regexp-in-string 4,144 0%
font-lock-unfontify-region 4,144 0%
- eval 144,979 0%
if 132,784 0%
unless 6,336 0%
- default-line-height 1,089,216 5%
default-font-height 1,089,216 5%
- window-inside-pixel-edges 21,120 0%
- window-edges 15,840 0%
window-current-scroll-bars 11,616 0%
- kill-line 498,749 2%
- kill-region 498,749 2%
- kill-new 424,312 2%
menu-bar-update-yank-menu 340,984 1%
- gui-select-text 74,880 0%
- gui-set-selection 74,880 0%
- gui-backend-set-selection 73,824 0%
- apply 73,824 0%
#<compiled -0x1ef4cefd5124968d> 73,824 0%
- filter-buffer-substring 74,437 0%
- buffer-substring--filter 68,101 0%
- #<compiled -0x1e2a987f6542516b> 68,101 0%
- apply 68,101 0%
- #<compiled 0xd88b599ee0a5190> 63,957 0%
- delete-and-extract-region 21,901 0%
- jit-lock-after-change 9,666 0%
- run-hook-with-args 4,833 0%
- font-lock-extend-jit-lock-region-after-change 4,833 0%
get-text-property 4,833 0%
- self-insert-command 485,032 2%
- python-indent-post-self-insert-function 421,304 2%
- syntax-ppss 421,304 2%
- syntax-propertize 325,688 1%
#<compiled 0x14be23ea75627c25> 311,064 1%
- run-hook-wrapped 1,056 0%
#<compiled -0x10385ae61af9e5a6> 1,056 0%
- electric-indent-post-self-insert-function 22,016 0%
- syntax-ppss 22,016 0%
- syntax-propertize 3,168 0%
- run-hook-wrapped 1,056 0%
#<compiled -0x1038556930f9e5a6> 1,056 0%
- jit-lock-after-change 12,432 0%
run-hook-with-args 4,144 0%
- undo-auto--undoable-change 32 0%
- undo-auto--boundary-ensure-timer 32 0%
- run-at-time 32 0%
- timer-set-time 32 0%
timer--time-setter 32 0%
- jit-lock--antiblink-post-command 113,809 0%
- syntax-ppss 79,729 0%
vconcat 4,833 0%
syntax-propertize 2,112 0%
- run-with-idle-timer 29,936 0%
- timer-activate-when-idle 25,712 0%
- timer--activate 25,712 0%
timer--time-less-p 25,712 0%
- timer-set-idle-time 4,224 0%
timer--time-setter 4,224 0%
- undo-auto--add-boundary 4,224 0%
undo-auto--boundaries 4,224 0%
- execute-extended-command 4,593,217 22%
- command-execute 3,494,291 16%
- call-interactively 3,494,291 16%
- funcall-interactively 3,494,275 16%
- profiler-report 3,491,303 16%
profiler-memory-running-p 5,863 0%
- profiler-start 2,972 0%
message 2,341 0%
- sit-for 745,896 3%
- redisplay 744,768 3%
- redisplay_internal (C function) 277,761 1%
- tool-bar-make-keymap 271,923 1%
- tool-bar-make-keymap-1 271,923 1%
- mapcar 271,923 1%
- #<compiled -0xe8295ef54b23da6> 271,923 1%
- eval 17,416 0%
- find-image 17,416 0%
image-search-load-path 17,416 0%
- find-image 1,048 0%
image-search-load-path 1,048 0%
kill-this-buffer-enabled-p 1,024 0%
- menu-bar-update-buffers 672 0%
menu-bar-update-buffers-1 672 0%
- substitute-command-keys 21 0%
generate-new-buffer 21 0%
- read-event 16 0%
- command-execute 16 0%
call-interactively 16 0%
- execute-extended-command--shorter 195,259 0%
- completion-try-completion 187,931 0%
- completion--nth-completion 186,883 0%
- completion--some 186,883 0%
- #<compiled 0x81c0cf17cf07668> 185,827 0%
- completion-pcm-try-completion 184,779 0%
- completion-pcm--merge-try 148,675 0%
- completion-pcm--merge-completions 23,355 0%
string-match 2,099 0%
completion-pcm--pattern->regex 2,096 0%
completion-pcm--pattern->string 1,048 0%
- completion-pcm--find-all-completions 35,048 0%
- completion-pcm--all-completions 20,568 0%
completion-pcm--pattern->regex 1,048 0%
completion-pcm--optimize-pattern 1,056 0%
completion-pcm--string->pattern 1,024 0%
- execute-extended-command--shorter-1 7,328 0%
- execute-extended-command--shorter-1 5,232 0%
- execute-extended-command--shorter-1 2,096 0%
- execute-extended-command--shorter-1 2,096 0%
mapcar 1,048 0%
- execute-extended-command--shorter-1 1,048 0%
- execute-extended-command--shorter-1 1,048 0%
mapcar 1,048 0%
mapcar 1,048 0%
commandp 5,863 0%
#<compiled -0x1910b770d84f49d5> 42 0%
- handle-focus-in 2,112 0%
- #<compiled 0x189e2a0a0dde442> 2,112 0%
- apply 2,112 0%
- blink-cursor--rescan-frames 2,112 0%
- blink-cursor-check 2,112 0%
- blink-cursor--should-blink 2,112 0%
frame-focus-state 2,112 0%
- digit-argument 1,064 0%
- universal-argument--mode 1,064 0%
set-transient-map 1,064 0%
- byte-code 667,721 3%
- read-extended-command 667,721 3%
- completing-read 667,721 3%
- completing-read-default 667,721 3%
- read-from-minibuffer 663,459 3%
- redisplay_internal (C function) 208,291 1%
- tool-bar-make-keymap 206,571 1%
- tool-bar-make-keymap-1 206,571 1%
- mapcar 206,571 1%
- #<compiled -0xe8295ef54b23da6> 206,571 1%
- eval 1,048 0%
- find-image 1,048 0%
image-search-load-path 1,048 0%
- find-image 1,048 0%
image-search-load-path 1,048 0%
- menu-bar-update-buffers 672 0%
menu-bar-update-buffers-1 672 0%
- command-execute 1,320 0%
- call-interactively 1,320 0%
- funcall-interactively 1,080 0%
- self-insert-command 1,080 0%
#<compiled 0x23be74412ab8ae> 1,048 0%
- undo-auto--undoable-change 32 0%
- undo-auto--boundary-ensure-timer 32 0%
- run-at-time 32 0%
- timer-set-time 32 0%
timer--time-setter 32 0%
+ redisplay_internal (C function) 33,424 0%
+ internal-echo-keystrokes-prefix 15,490 0%
+ timer-event-handler 2,662 0%
... 0 0%
GNU bug tracking system
Copyright (C) 1999 Darren O. Benham,
1997,2003 nCipher Corporation Ltd,
1994-97 Ian Jackson.