Subject: bug#69246: 30.0.50; persistent key input delay after using vc commands in pgtk

From: Nick OBrien <[email-masked]>
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.