Package: emacs;
Reported by: Nick OBrien <nick4f42 <at> proton.me>
Date: Sun, 18 Feb 2024 18:31:02 UTC
Severity: normal
Found in version 30.0.50
View this message in rfc822 format
From: Nick OBrien <nick4f42 <at> proton.me> To: Eli Zaretskii <eliz <at> gnu.org> Cc: 69246 <at> debbugs.gnu.org Subject: bug#69246: 30.0.50; persistent key input delay after using vc commands in pgtk Date: Wed, 21 Feb 2024 02:19:11 +0000
> Thanks, but I don't see anything here which gives a hint why you see
> the lags, nor even evidence that there was a lag. Maybe try leaning
> on a key for 20 seconds, so that the keyboard auto-repeat produces
> keypresses at high frequency -- maybe then the profile will tell
> something.
I followed the steps in the original bug report to reproduce the lag, then I did
the following:
C-x b bar RET
C-u 1000 C-q C-j
M-<
M-x profiler-start RET RET
C-f ; held down for about 25 seconds
M-x profiler-stop RET
552 82% - redisplay_internal (C function)
18 2% - eval
11 1% - if
8 1% frame-parameter
2 0% - display-graphic-p
1 0% framep-on-display
5 0% - mode-line-eol-desc
3 0% coding-system-eol-type-mnemonic
1 0% mode-line-window-control
5 0% file-remote-p
4 0% - mode-line-default-help-echo
3 0% - window-at-side-p
2 0% - window-pixel-edges
2 0% window-edges
1 0% window-normalize-window
1 0% minibuffer-window-active-p
3 0% - redisplay--pre-redisplay-functions
1 0% window-buffer
53 7% - command-execute
40 5% - byte-code
40 5% - read-extended-command
40 5% - read-extended-command-1
40 5% - completing-read-default
9 1% redisplay_internal (C function)
3 0% - funcall-interactively
2 0% execute-extended-command
3 0% interactive-form
3 0% handle-shift-selection
42 6% Automatic GC
9 1% - undo-auto--add-boundary
8 1% - undo-auto--boundaries
3 0% add-to-list
2 0% - undo-auto--ensure-boundary
1 0% undo-auto--needs-boundary-p
5 0% - tooltip-hide
2 0% tooltip-cancel-delayed-tip
4 0% clear-minibuffer-message
2 0% internal-timer-start-idle
2 0% - internal-echo-keystrokes-prefix
1 0% #<compiled -0x13309019554cae09>
0 0% ...
I did the same thing but longer (after restarting Emacs and reproducing the lag):
C-x b bar RET
C-u 2000 C-q C-j
M-<
M-x profiler-start RET RET
C-f ; held down for about 60 seconds
M-x profiler-stop RET
1644 89% - redisplay_internal (C function)
28 1% - eval
18 0% - if
14 0% - frame-parameter
1 0% quote
3 0% - display-graphic-p
3 0% framep-on-display
5 0% - mode-line-eol-desc
2 0% coding-system-eol-type-mnemonic
2 0% - unless
2 0% #<compiled -0x1d70b361daad23ef>
1 0% mode-line-window-control
24 1% file-remote-p
10 0% - mode-line-default-help-echo
3 0% - window-at-side-p
1 0% - window-pixel-edges
1 0% window-edges
2 0% minibuffer-window-active-p
9 0% - redisplay--pre-redisplay-functions
3 0% - run-hook-with-args
2 0% redisplay--update-region-highlight
1 0% selected-window
1 0% window-buffer
96 5% Automatic GC
57 3% - command-execute
41 2% - byte-code
41 2% - read-extended-command
41 2% - read-extended-command-1
41 2% - completing-read-default
7 0% redisplay_internal (C function)
1 0% - minibuffer-mode
1 0% - run-mode-hooks
1 0% - run-hooks
1 0% - global-eldoc-mode-enable-in-buffers
1 0% - turn-on-eldoc-mode
1 0% eldoc--supported-p
3 0% interactive-form
3 0% handle-shift-selection
2 0% - funcall-interactively
1 0% forward-char
15 0% - clear-minibuffer-message
1 0% timerp
11 0% - undo-auto--add-boundary
11 0% - undo-auto--boundaries
6 0% - undo-auto--ensure-boundary
3 0% undo-auto--needs-boundary-p
5 0% add-to-list
6 0% - internal-echo-keystrokes-prefix
1 0% #<compiled -0x13309019554cae09>
3 0% - internal-timer-start-idle
3 0% timerp
3 0% - tooltip-hide
1 0% tooltip-cancel-delayed-tip
2 0% - help-command-error-confusable-suggestions
2 0% - substitute-command-keys
1 0% generate-new-buffer
1 0% - #<compiled 0x119bbf11827c0b18>
1 0% - kill-buffer
1 0% - replace-buffer-in-windows
1 0% window-normalize-buffer
0 0% ...
Just to be clear about the lag I'm observing, here's a couple scenarios:
In the first one, say "abc" is already in a buffer. At time 0, I press the "d"
key and hold it. After 300 ms, I release the "d" key. Here's what the buffer
looks like at various times (the times aren't exact, they're for demonstration):
| Time (ms) | Key Event | Buffer (no lag) | Buffer (lag) |
|-----------+-----------+-----------------+--------------|
| 0 | "d" down | abc | abc |
| 1 | | abcd | abc |
| 100 | | abcd | abc |
| 200 | | abcd | abcd | <- "d" appears after lag
| 300 | "d" up | abcd | abcd |
However, "d" always appears immediately when I release the key. In the second
scenario, I release "d" after 10 ms:
| Time (ms) | Key Event | Buffer (no lag) | Buffer (lag) |
|-----------+-----------+-----------------+--------------|
| 0 | "d" down | abc | abc |
| 1 | | abcd | abc |
| 10 | "d" up | abcd | abc |
| 11 | | abcd | abcd | <- "d" appears as soon
| 100 | | abcd | abcd | as the key is released
In other words, if I press and release a key at the same time, the lag isn't
noticeable. I only see the lag when I press a key and don't release it. When a
key is held down and auto-repeating, I don't notice a drastic speed difference
with or without the lag. The appearing characters just look choppier when the
lag is occurring.
I realize this is an awkward bug to explain and reproduce, thanks for bearing
with me. More suggestions on how to narrow down the cause would be appreciated.
GNU bug tracking system
Copyright (C) 1999 Darren O. Benham,
1997,2003 nCipher Corporation Ltd,
1994-97 Ian Jackson.