copilot-emacs / copilot.el

An unofficial Copilot plugin for Emacs.
MIT License
1.83k stars 128 forks source link

Freezing when used with company-mode #15

Closed jimeh closed 2 years ago

jimeh commented 2 years ago

Last week I was using commit 73487d682dd504fb072e21a77b6a28e40e38c8b2 without much issue. Updated today, and most instances where a single-character triggers a company-mode popup from gopls along with a suggestion from copilot, Emacs freezes and starts eating 98% CPU. Pressing C-g about 10-15 times eventually makes it wake up.

If I revert to 73487d682dd504fb072e21a77b6a28e40e38c8b2 it does not behave this way.

I don't have time to dig too deep into the issue at the moment, but happy to provide more details and/or test/debug things when I have time later today.

For now though, here's my config for various pieces:

TL;DR:

zerolfx commented 2 years ago

Thanks for your detailed feedback.

I tested my plugin against company-mode + go-mode (with LSP) before every commit. So I failed to reproduce it on my machine.

  1. Can you look at the *copilot-log* buffer? Is there anything interesting?
  2. Try to disable copilot-mode and use M-x copilot-complete to trigger completion manually. Does the problem happen again?
jimeh commented 2 years ago

Sorry for the delay, I've just tried your suggestions with commit 26a1221d90e24213ea202aab22bd12aab345cc2e, and using a nightly build of Emacs 29.x for macOS.

I edited one of my own projects to test it, specifically TestBase64 in strings_test.go:

Screen-Shot-2022-05-05-22-43-41 90-Zh44JIqMgRKa

Below is the complete log from opening the file, typing TAB to indent the line, and pressing a to trigger the lsp-mode suggestions, along with copilot suggestion. Though the company-mode popup doesn't show, and instead Emacs completely freezes. Eventually it unfreezes after about 10-15 presses of C-g.

I've included some suspicious looking output from *Messages* too.

*copilot-log*:

``` [INFO] Discard message without id: ((jsonrpc . "2.0") (method . "statusNotification") (params (status . "InProgress") (message . ""))) [Agent] [INFO] [default] [2022-05-05T21:32:09.513Z] [fetchCompletions] engine https://copilot-proxy.githubusercontent.com/v1/engines/copilot-codex [Agent] [INFO] [default] [2022-05-05T21:32:09.891Z] request.response: [https://copilot-proxy.githubusercontent.com/v1/engines/copilot-codex/completions] took 378 ms [Agent] [INFO] [streamChoices] [2022-05-05T21:32:09.892Z] solution 0 returned. finish reason: ["stop"] finishOffset: [undefined] completionId: [{cmpl-54dMvY6YKw8YjP1x0DjEqbRnpiZWO}] created: [{1651786329}] [INFO] Discard message without id: ((jsonrpc . "2.0") (method . "statusNotification") (params (status . "Normal") (message . ""))) [Agent] [INFO] [ghostText] [2022-05-05T21:32:09.893Z] Breaking, no choices [INFO] Completion: ((error) (completions . [])) [INFO] Discard message without id: ((jsonrpc . "2.0") (method . "statusNotification") (params (status . "InProgress") (message . ""))) [Agent] [INFO] [default] [2022-05-05T21:32:18.595Z] [fetchCompletions] engine https://copilot-proxy.githubusercontent.com/v1/engines/copilot-codex [Agent] [INFO] [default] [2022-05-05T21:32:18.732Z] request.response: [https://copilot-proxy.githubusercontent.com/v1/engines/copilot-codex/completions] took 137 ms [Agent] [INFO] [streamChoices] [2022-05-05T21:32:18.732Z] solution 0 returned. finish reason: ["stop"] finishOffset: [undefined] completionId: [{cmpl-54dN43TIGwBXp3njhAxCHa148fQm0}] created: [{1651786338}] [INFO] Discard message without id: ((jsonrpc . "2.0") (method . "statusNotification") (params (status . "Normal") (message . ""))) [Agent] [INFO] [ghostText] [2022-05-05T21:32:18.733Z] Breaking, no choices [INFO] Completion: ((error) (completions . [])) [INFO] Discard message without id: ((jsonrpc . "2.0") (method . "statusNotification") (params (status . "InProgress") (message . ""))) [Agent] [INFO] [default] [2022-05-05T21:32:19.167Z] [fetchCompletions] engine https://copilot-proxy.githubusercontent.com/v1/engines/copilot-codex [Agent] [INFO] [default] [2022-05-05T21:32:19.318Z] request.response: [https://copilot-proxy.githubusercontent.com/v1/engines/copilot-codex/completions] took 150 ms [Agent] [INFO] [streamChoices] [2022-05-05T21:32:19.319Z] solution 0 returned. finish reason: ["stop"] finishOffset: [undefined] completionId: [{cmpl-54dN5qGPaihp9524ameyKrxD0qWkP}] created: [{1651786339}] [INFO] Discard message without id: ((jsonrpc . "2.0") (method . "statusNotification") (params (status . "Normal") (message . ""))) [Agent] [INFO] [ghostText] [2022-05-05T21:32:19.320Z] Breaking, no choices [INFO] Completion: ((error) (completions . [])) [INFO] Discard message without id: ((jsonrpc . "2.0") (method . "statusNotification") (params (status . "InProgress") (message . ""))) [Agent] [INFO] [default] [2022-05-05T21:32:20.482Z] [fetchCompletions] engine https://copilot-proxy.githubusercontent.com/v1/engines/copilot-codex [Agent] [INFO] [default] [2022-05-05T21:32:20.785Z] request.response: [https://copilot-proxy.githubusercontent.com/v1/engines/copilot-codex/completions] took 303 ms [Agent] [INFO] [streamChoices] [2022-05-05T21:32:20.786Z] solution 0 returned. finish reason: ["stop"] finishOffset: [undefined] completionId: [{cmpl-54dN62HbodASlnShj4LJe1idTFd1E}] created: [{1651786340}] [INFO] Discard message without id: ((jsonrpc . "2.0") (method . "statusNotification") (params (status . "Normal") (message . ""))) [Agent] [INFO] [ghostText] [2022-05-05T21:32:20.786Z] Breaking, no choices [INFO] Completion: ((error) (completions . [])) [Agent] [INFO] [ghostText] [2022-05-05T21:32:20.996Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "b4a25cc3-bd9c-432b-8364-4852dbed5dfd") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) [Agent] [INFO] [ghostText] [2022-05-05T21:33:24.339Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "ab9167ff-e443-4f08-ada4-12901b964905") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) [Agent] [INFO] [ghostText] [2022-05-05T21:33:24.438Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "00779f4d-c7a4-4d2e-821f-0eca2683ff36") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) [Agent] [INFO] [ghostText] [2022-05-05T21:33:24.617Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "9f7b3ab1-1344-48c0-a593-e44bf3f1f805") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) [Agent] [INFO] [ghostText] [2022-05-05T21:33:25.959Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "5f28cd72-1dca-4e43-b57f-9d3538022e09") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) [Agent] [INFO] [ghostText] [2022-05-05T21:33:25.997Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "776b0ad6-8dc7-42fc-8ead-94ea90a036e1") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) [Agent] [INFO] [ghostText] [2022-05-05T21:33:26.032Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "b55ae437-d3bd-4e20-9918-f1aff723ada2") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) [Agent] [INFO] [ghostText] [2022-05-05T21:33:26.064Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "0c0e4bd6-54e1-4ca5-b124-d5c32b4ac719") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) [Agent] [INFO] [ghostText] [2022-05-05T21:33:26.098Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "e56f4e33-b565-453d-9edd-01fe565908b3") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) [Agent] [INFO] [ghostText] [2022-05-05T21:33:26.132Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "f5200a04-da3f-4848-bf32-8646d28a9a2e") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) [Agent] [INFO] [ghostText] [2022-05-05T21:33:26.162Z] Found inline suggestions locally [INFO] Completion: ((error) (completions . [((uuid . "647eeec4-0f78-412e-b761-0ba57847306a") (text . " assert.Len(t, b, tt.n)") (range (start (line . 50) (character . 0)) (end (line . 50) (character . 4))) (displayText . "ssert.Len(t, b, tt.n)") (position (line . 50) (character . 4)))])) ```

*Messages*:

``` error in process filter: let*: object cyclic or Lisp evaluation too deep error in process filter: object cyclic or Lisp evaluation too deep End of buffer [15 times] error in process filter: let*: object cyclic or Lisp evaluation too deep error in process filter: object cyclic or Lisp evaluation too deep error in process filter: let: Lisp nesting exceeds ‘max-lisp-eval-depth’ error in process filter: Lisp nesting exceeds ‘max-lisp-eval-depth’ ```

Disabling copilot-mode and manually triggering copilot-complete when I have a company-mode popup visible for a single character with suggestions from gopls, it does also freeze.

jimeh commented 2 years ago

Also, just to confirm, it is commit e951acfaff04f0709235de679fa78f90a2b1dc85 specifically that's causing it. In my experience that commit seems to prevent the cursor from moving when copilot suggestions are inserted.

I've also played with company-minimum-prefix-length and the length doesn't matter, it's basically most of the time that company-mode would appear with a suggestion. Even in elisp without a language server. If a copilot preview is visible it seems to freeze whenever company-mode tries to render a popup.

I wish I knew more about these specific areas of Emacs so I could help more. But happy to try and debug more if needed :)

zerolfx commented 2 years ago

It seems that this function call causes infinite recursion. But it should not happen since the length of copilot--output-buffer becomes strictly shorter after the recursive call. https://github.com/zerolfx/copilot.el/blob/26a1221d90e24213ea202aab22bd12aab345cc2e/copilot.el#L225

And https://github.com/zerolfx/copilot.el/commit/e951acfaff04f0709235de679fa78f90a2b1dc85 is only related to UI, not sure what causes the problem.

Can you enable debug by M-x toggle-debug-on-error, re-trigger the problem, and paste the top few lines of *Backtrace*?

jimeh commented 2 years ago

I had a quick go with M-x toggle-debug-on-error, but couldn't get it to error again. So the errors from *Messages* aren't the root cause, and maybe completely irrelevant :(

I'll try and put together a minimal Emacs config this week that reproduces the issue.

xqliu commented 2 years ago

This issue also happened on my side, the minibuffer shows Starting "look" process... and keep displaying this information

jimeh commented 2 years ago

@zerolfx after a bunch of trial and error, I seem to have narrowed things down. Basically disabling visual-line-mode prevents the freezes and things work like normal.

It essentially comes down to all of the below being in place when company-mode tries to display its popup:

It doesn't freeze up every time, at least not at first, but it's reliably reproducible enough.

Below is a minimal Emacs init.el that re-produces the issue for me, on a macOS Emacs 29.x nightly build (2022-05-04):

(setq straight-repository-branch "develop"
      straight-use-package-by-default t
      use-package-always-ensure nil)

(defvar bootstrap-version)
(let ((bootstrap-file
       (expand-file-name "straight/repos/straight.el/bootstrap.el" user-emacs-directory))
      (bootstrap-version 5))
  (unless (file-exists-p bootstrap-file)
    (with-current-buffer
        (url-retrieve-synchronously
         "https://raw.githubusercontent.com/raxod502/straight.el/develop/install.el"
         'silent 'inhibit-cookies)
      (goto-char (point-max))
      (eval-print-last-sexp)))
  (load bootstrap-file nil 'nomessage))

(straight-use-package 'use-package)

(use-package company
  :bind ("TAB" . company-indent-or-complete-common)
  :custom (company-minimum-prefix-length 1)
  :config (global-company-mode 1))

(use-package copilot
  :straight (:host github :repo "zerolfx/copilot.el"
                   :files ("dist" "copilot.el"))
  :hook (prog-mode . copilot-mode)
  :bind ("C-<tab>" . copilot-accept-completion))

(add-hook 'prog-mode-hook (lambda () (visual-line-mode 1)))
zerolfx commented 2 years ago

@jimeh Thank you so much. I will dive into this case today. If you happen to use Emacs GUI, I recommend you use company-box to avoid overlay confliction (the cause of this bug, I guess).

jimeh commented 2 years ago

Interesting, using company-box-mode does indeed avoid the issue while visual-line-mode is enabled :)

zerolfx commented 2 years ago

Profiler report: Screenshot_20220511_175405

Somehow company-buffer-lines enters an endless loop. I have no idea how visual-line-mode got involved in this bug. https://github.com/company-mode/company-mode/blob/783287526a791590bea4f9a23992c2bfebdb4c8d/company.el#L3171

The temporary workaround is: disabling visual-line-mode or changing to another company frontend (e.g. company-box)

zerolfx commented 2 years ago

There is another issue (#19) with the overlay compatibility problem, so I went back to using the old UI logic by default. The differences are explained in "Known Issues" section of the readme.