Copilot randomly stops working

[sollidsnake]

First, let me say a huge thanks for this package. It's awesome!

I'm having issues with Copilot randomly stop working. It simply won't complete anything, but it starts working again if I just disable and reenable copilot-mode, but only for a short time. After that, I have to restart it again and again. When I run copilot-diagnose, I get the following error:

[jsonrpc] Server exited with status 9
Copilot agent started. [2 times]
Copilot error: (:code -32602 :message "Document for URI could not be found: file:///, URIs of the known document are: ")

Even so, if I restart the mode, it starts working again for a short time. I tried to debug and find a possible culprit, but I had no success so far. It's hard to debug since it happens random and I don't have much elisp knowledge. If there's any more debug information that I can get just let me know.

My setup: Doom Emacs (version 29.2) Arch Linux

[emil-vdw]

The error mentioned when running copilot-diagnose should no longer occur after #177. Could you confirm that for me?

Would you mind enabling logging (see the Readme on how if uncertain) and send that attach the events (*copilot events*) before you stopped getting completions as well as *copilot stderr* and *copilot output*.

[sollidsnake]

Yes, I can confirm that #177 indeed fixed the copilot-diagnose.

Here are the logs:

(:jsonrpc "2.0" :id 221 :result
          (:completions
           [(:uuid "d2869e76-a3e8-44aa-9627-b73de2c2438d" :text "public class Fibonacci" :range
                   (:start
                    (:line 3 :character 0)
                    :end
                    (:line 3 :character 0))
                   :displayText "public class Fibonacci" :position
                   (:line 3 :character 0)
                   :docVersion 99)]))
[client-notification] Wed Sep  6 14:25:55 2023:
(:jsonrpc "2.0" :method "textDocument/didChange" :params
          (:textDocument
           (:uri "file:///tmp/Fibonacci.cs" :version 100)
           :contentChanges
           [(:range
             (:start
              (:line 4 :character 0)
              :end
              (:line 5 :character 0))
             :text "")]))
[client-notification] Wed Sep  6 14:25:55 2023:
(:jsonrpc "2.0" :method "textDocument/didChange" :params
          (:textDocument
           (:uri "file:///tmp/Fibonacci.cs" :version 101)
           :contentChanges
           [(:range
             (:start
              (:line 4 :character 0)
              :end
              (:line 4 :character 0))
             :text "\n")]))
[client-notification] Wed Sep  6 14:25:55 2023:
(:jsonrpc "2.0" :method "textDocument/didChange" :params
          (:textDocument
           (:uri "file:///tmp/Fibonacci.cs" :version 102)
           :contentChanges
           [(:range
             (:start
              (:line 4 :character 0)
              :end
              (:line 4 :character 0))
             :text "        ")]))
[client-request] (id:222) Wed Sep  6 14:25:55 2023:
(:jsonrpc "2.0" :id 222 :method "getCompletions" :params
          (:doc
           (:version 102 :tabSize 4 :indentSize 4 :insertSpaces t :path "/tmp/Fibonacci.cs" :uri "file:///tmp/Fibonacci.cs" :relativePath "Fibonacci.cs" :languageId "csharp" :position
                     (:line 4 :character 8))))
[server-notification] Wed Sep  6 14:25:55 2023:
(:jsonrpc "2.0" :method "LogMessage" :params
          (:level 0 :message "[DEBUG] [getCompletions] [2023-09-06T17:25:55.805Z] Requesting completion at position 4:8, between \"\\n    publ\" and \"ic void PrintFibonacci(int n)\\n    {\\n\"." :metadataStr "[DEBUG] [getCompletions] [2023-09-06T17:25:55.805Z]" :extra
                  ["Requesting completion at position 4:8, between \"\\n    publ\" and \"ic void PrintFibonacci(int n)\\n    {\\n\"."]))
[server-reply] (id:222) Wed Sep  6 14:25:55 2023:
(:jsonrpc "2.0" :id 222 :result
          (:completions
           []
           :cancellationReason "RequestCancelled"))
[client-notification] Wed Sep  6 14:26:01 2023:
(:jsonrpc "2.0" :method "textDocument/didChange" :params
          (:textDocument
           (:uri "file:///tmp/Fibonacci.cs" :version 103)
           :contentChanges
           [(:range
             (:start
              (:line 4 :character 0)
              :end
              (:line 4 :character 8))
             :text "")]))

[raymond-w-ko]

I am also getting this issue, but nothing appears to be obviously wrong in the logs.

[raymond-w-ko]

Hmm, I reverted back to 1.10.1 copilot.vim files to see if this fixes it, but it also stopped working. I noticed something I haven't seen before. I wonder if it's related.

[stderr] (node:228579) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 change listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit
[stderr] (Use `node --trace-warnings ...` to show where the warning was created)

[stderr] ApplicationInsights:Sender [
[stderr]   'Ingestion endpoint could not be reached. This batch of telemetry items has been lost. Use Disk Retry Caching to enable resending of failed telemetry. Error:',
[stderr]   [
[stderr]     "[object Error]{ stack: 'Error: socket hang up\n" +
[stderr]       '    at connResetException (node:internal/errors:720:14)\n' +
[stderr]       '    at TLSSocket.socketCloseListener (node:_http_client:474:25)\n' +
[stderr]       '    at TLSSocket.emit (node:events:526:35)\n' +
[stderr]       '    at node:net:323:12\n' +
[stderr]       "    at TCP.done (node:_tls_wrap:588:7)', message: 'socket hang up', name: 'Error'"
[stderr]   ]
[stderr] ]

[emil-vdw]

Is it possible that this could be because of network issues?

I have encountered one case where completions stop working and that was when running black (from a terminal) on an open python buffer. This makes changes to the buffer without triggering the hooks used by copilot mode.

[sollidsnake]

I was using a wifi connection, so I tried with a cable to see if it made any difference, but the issue persists.

I don't think it's a network issue. I've never noticed any instability in my connection.

[ultronozm]

I'll chime in that I've noticed this too, that it's a consistent issue now, and that it wasn't an issue a couple months ago. Will try to dig in further when I get the chance

[mikej96]

I am running into this exact issue as well where copiliot will randomly stop working and I need to restart it with 'copilot-diagnose'. (I haven't noticed the socket errors previously mentioned, but will keep an eye out for them. I am on a 1Gbps fiber connection and do not suspect a network issue to be the cause.)

Happy to help diagnose but my lisp skills are weak... emacs 29.1 running on Ubuntu 22.04 LTS.
Copilot.el is on commit c5160f6bb323b7e86674993df3453cf68e9537f3 from Oct 3rd.

[emil-vdw]

@ultronozm @mikej96 enable event logging as per the Readme and have a look/share the events (from the events buffer) just before the issue occurs?

[colehaus]

I turned on event logging and finally got some possibly useful info. Copilot.el is no longer proposing any completions in the buffer, but it looks like it is still communicating with the server successfully. I can edit the buffer and each edit will produce a different message in *copilot events* like:

(:jsonrpc "2.0" :method "LogMessage" :params
          (:level 0 :message "[DEBUG] [getCompletions] [2023-10-18T23:12:45.677Z] Requesting completion at position 323:8, between \"[…]\"." :metadataStr "[DEBUG] [getCompletions] [2023-10-18T23:12:45.677Z]" :extra
                  ["Requesting completion at position 323:8, between \"[...]\"."]))
[server-reply] (id:2144) Wed Oct 18 16:12:45 2023:
(:jsonrpc "2.0" :id 2144 :result
          (:completions
           []
           :cancellationReason "RequestCancelled"))

Completions still appear in other buffers. It's just this one buffer that seems to have problems ATM.

(I set copilot log max to 1000 but it still seems like *copilot events* gets frequently wiped. There are never more than 10 or 20 lines the buffer. Does that make sense?)

[Paethon]

Unfortunately, I have the same problem. For me CoPilot often only works for a few minutes and then it stops working until I disable and enable CoPilot mode again. It also seems to be a newer problem for me. A few weeks ago I never had any problem.

[Paethon]

FYI: Since I noticed that I only had this problem after I updated to a newer version, I reverted to commit c942a52 and this fixes the problem. So seems to be something that was introduced after that. I haven't yet tested if a newer commit also works.

[rakotomandimby]

@Paethon , thank you for your experimentation. Unfortunately, I am not able to propose a fix for the moment, as I still learn Lisp (it's a side project) I think within 2 or 3 months I will be able to write usefull things for this package.

[Paethon]

I'll see if I can find out which commit exactly introduced the bug. Unfortunately, I am also not very versed in ELisp 😂

[rakotomandimby]

@Paethon , strong opinionated probability to be this one: https://github.com/zerolfx/copilot.el/commit/b8a32ff6b9757a84320da003eeb672036d49d91e

But that's just probability

If we look at copilot/vim changes, there are much.

[emil-vdw]

@Paethon, @sollidsnake are you perhaps editing very large buffers when this happens? What is the value of copilot-max-char?

[sollidsnake]

@Paethon, @sollidsnake are you perhaps editing very large buffers when this happens? What is the value of copilot-max-char?

I don't usually work with very large buffers, but I do open dozens of buffers. I'm not sure if this max char limit considers the background buffers as well for context, but I'll try increasing this variable and see if it helps

[Paethon]

I think my buffers are not unreasonably large. On the bigger end maybe 2k LOC, but I also see this problem with files with far less (<100 LOC). copilot-max-char is 100000 (when using the version that works, I have to check if this changes when using a more current version)

[Paethon]

@emil-vdw You were right! I used git bisect to find what commit caused the issue and it's 82d52b0 where copilot-max-chars is increased to 100000

So my info from the previous post that it works with 100000 was wrong. Manually setting this to 30000 fixes the problem and the main version of copilot.el works again. So 100000 might be more than the copilot service can actually handle?

[Paethon]

Unfortunately, this was a false alarm as well. I still have the same problems. I am at my wit's end here ... :cry:

[emil-vdw]

What do you mean it was a false alarm? Could you summarize the information you've gathered so far? :smile:

[Paethon]

Yeah sure. Pretty confusing, I agree :grin:

Using git bisect, I tried to find the first commit that breaks copilot.el for me. Using this I found the commit 82d52b0 that seems to be causing the problem. This commit increases copilot-max-chars from 30000 to 100000, so I thought the changed copilot-max-chars was the problem. But with the current version of the main branch and the copilot-max-chars fixed to 30000, I still have the same problems I had before.

So either it was actually not this commit that caused the problem, or there is another commit that breaks something else along the way where the problem just looks the same. So I guess it is back to git bisect with fixed copilot-max-chars and see what I can find out ...