bug#60088: 29.0.60; Eglot loses messages from gopls

bug#60088: 29.0.60; Eglot loses messages from gopls

[João Távora]

[Eli, I have CC'ed you directly because this bug concerns a technique to
avoid recursive process filters, which seems like an area you are expert
in.]

Hi, 

In some situations, Eglot is losing some messages from the Go language
server, 'gopls'.  The problem has been reproduced and identified.

For context, this started in:

* https://github.com/joaotavora/eglot/issues/587#issuecomment-1221072833
* https://github.com/golang/go/issues/54559

(In the former link, there are reports of what seem to be other
problems.  The reports are missing clear reproduction recipes, so they
may not be the same problem I'm about to describe.)

Reproduction:

  Ensure go-mode is installed from https://melpa.org/#/go-mode
  $ go install golang.org/x/tools/gopls@latest
  $ git clone git clone https://github.com/google/nftables
  $ emacs -Q -f package-initialize nftables/nftables_test.go
  M-x eglot

The last step will connect to the server, exchange some messages.  It
will not block Emacs, but the Eglot session will be completely
non-functional.

Analysis:

Many essential JSONRPC messages have not been exchanged, they have been
lost.  The bytes of the lost messages from the gopls side can be seen in
the process buffer (M-x list-processes, then click the link to the
hidden process buffer).

The problem happens in jsonrpc.el's jsonrpc--process-filter.  The code
does not expect this function to be called recursively, but that can
happen if the client code invoked by its jsonrpc--connection-receive
callee eventually sends a follow-up message to the server.  This is a
common scenario, especially during LSP initialiation.  It has been
working fine for a number of years and a large number of servers.

However:

* if that follow-up message is large enough (this is why the largish
  nftables_test.go file is needed) AND

* the server has already sent us some output with just the right (wrong)
  timing.

then the process-send-string call that is eventually reached will in
fact cause more output to arrive from the process and a recursive
invocation of the process filter.

Resolution:

I've looked at a number of ways to solve this problem, from avoiding the
follow up message in Eglot's side to different techniques on the jsonrpc
side.  None of them are as satisfactory as the patch after my sig, which
simply re-schedules the would-be recursive call to re-run from within a
timer stack as soon as possible.

The only problem I can envision with this approach would be if multiple
recursive calls are launched from the same jsonrpc--connection-receive
stack frame and would somehow not be executed in the correct order.
That doesn't seem to be a problem after some experiments like

(progn
  (run-at-time 0 nil #'insert "a")
  (run-at-time 0 nil #'insert "b")
  (run-at-time 0 nil #'insert "c"))

which inserts the predicatbly sane "abc".  If this in-order execution is
somehow not guaranteed, there is the alternate more complex technique of
inserting the output into the process buffer immediately, and schedule a
single processing call thereafter.

I will install the following patch soon unless someone objects to this
approach.

João

diff --git a/lisp/jsonrpc.el b/lisp/jsonrpc.el
index 90833e1c1d..76bbf28138 100644
--- a/lisp/jsonrpc.el
+++ b/lisp/jsonrpc.el
@@ -548,11 +548,27 @@ jsonrpc--process-sentinel
         (delete-process proc)
         (funcall (jsonrpc--on-shutdown connection) connection)))))
 
-(defun jsonrpc--process-filter (proc string)
+(defvar jsonrpc--in-process-filter nil
+  "Non-nil if inside `jsonrpc--process-filter'.")
+
+(cl-defun jsonrpc--process-filter (proc string)
   "Called when new data STRING has arrived for PROC."
+  (when jsonrpc--in-process-filter
+    ;; Problematic recursive process filters may happen if
+    ;; `jsonrpc--connection-receive', called by us, eventually calls
+    ;; client code which calls `process-send-string' (which see) to,
+    ;; say send a follow-up message.  If that happens to writes enough
+    ;; bytes for additional output to be received, we have a problem.
+    ;;
+    ;; In that case, remove recursiveness by re-scheduling ourselves to
+    ;; run from within a timer as soon as possible.
+
+    (run-at-time 0 nil #'jsonrpc--process-filter proc string)
+    (cl-return-from jsonrpc--process-filter))
   (when (buffer-live-p (process-buffer proc))
     (with-current-buffer (process-buffer proc)
       (let* ((inhibit-read-only t)
+             (jsonrpc--in-process-filter t)
              (connection (process-get proc 'jsonrpc-connection))
              (expected-bytes (jsonrpc--expected-bytes connection)))
         ;; Insert the text, advancing the process marker.

bug#60088: 29.0.60; Eglot loses messages from gopls

[João Távora]

[-- Attachment #1: Type: text/plain, Size: 5334 bytes --]

I've now pushed the patch/bugfix to emacs-29 and bumped
version of jsonrpc.el so we should get a new GNU ELPA package
soon.

GNU ELPA Eglot users should wait for the package to be bumped
too.

João

On Thu, Dec 15, 2022 at 11:55 AM João Távora <joaotavora@gmail.com> wrote:

> [Eli, I have CC'ed you directly because this bug concerns a technique to
> avoid recursive process filters, which seems like an area you are expert
> in.]
>
> Hi,
>
> In some situations, Eglot is losing some messages from the Go language
> server, 'gopls'.  The problem has been reproduced and identified.
>
> For context, this started in:
>
> * https://github.com/joaotavora/eglot/issues/587#issuecomment-1221072833
> * https://github.com/golang/go/issues/54559
>
> (In the former link, there are reports of what seem to be other
> problems.  The reports are missing clear reproduction recipes, so they
> may not be the same problem I'm about to describe.)
>
> Reproduction:
>
>   Ensure go-mode is installed from https://melpa.org/#/go-mode
>   $ go install golang.org/x/tools/gopls@latest
>   $ git clone git clone https://github.com/google/nftables
>   $ emacs -Q -f package-initialize nftables/nftables_test.go
>   M-x eglot
>
> The last step will connect to the server, exchange some messages.  It
> will not block Emacs, but the Eglot session will be completely
> non-functional.
>
> Analysis:
>
> Many essential JSONRPC messages have not been exchanged, they have been
> lost.  The bytes of the lost messages from the gopls side can be seen in
> the process buffer (M-x list-processes, then click the link to the
> hidden process buffer).
>
> The problem happens in jsonrpc.el's jsonrpc--process-filter.  The code
> does not expect this function to be called recursively, but that can
> happen if the client code invoked by its jsonrpc--connection-receive
> callee eventually sends a follow-up message to the server.  This is a
> common scenario, especially during LSP initialiation.  It has been
> working fine for a number of years and a large number of servers.
>
> However:
>
> * if that follow-up message is large enough (this is why the largish
>   nftables_test.go file is needed) AND
>
> * the server has already sent us some output with just the right (wrong)
>   timing.
>
> then the process-send-string call that is eventually reached will in
> fact cause more output to arrive from the process and a recursive
> invocation of the process filter.
>
> Resolution:
>
> I've looked at a number of ways to solve this problem, from avoiding the
> follow up message in Eglot's side to different techniques on the jsonrpc
> side.  None of them are as satisfactory as the patch after my sig, which
> simply re-schedules the would-be recursive call to re-run from within a
> timer stack as soon as possible.
>
> The only problem I can envision with this approach would be if multiple
> recursive calls are launched from the same jsonrpc--connection-receive
> stack frame and would somehow not be executed in the correct order.
> That doesn't seem to be a problem after some experiments like
>
> (progn
>   (run-at-time 0 nil #'insert "a")
>   (run-at-time 0 nil #'insert "b")
>   (run-at-time 0 nil #'insert "c"))
>
> which inserts the predicatbly sane "abc".  If this in-order execution is
> somehow not guaranteed, there is the alternate more complex technique of
> inserting the output into the process buffer immediately, and schedule a
> single processing call thereafter.
>
> I will install the following patch soon unless someone objects to this
> approach.
>
> João
>
> diff --git a/lisp/jsonrpc.el b/lisp/jsonrpc.el
> index 90833e1c1d..76bbf28138 100644
> --- a/lisp/jsonrpc.el
> +++ b/lisp/jsonrpc.el
> @@ -548,11 +548,27 @@ jsonrpc--process-sentinel
>          (delete-process proc)
>          (funcall (jsonrpc--on-shutdown connection) connection)))))
>
> -(defun jsonrpc--process-filter (proc string)
> +(defvar jsonrpc--in-process-filter nil
> +  "Non-nil if inside `jsonrpc--process-filter'.")
> +
> +(cl-defun jsonrpc--process-filter (proc string)
>    "Called when new data STRING has arrived for PROC."
> +  (when jsonrpc--in-process-filter
> +    ;; Problematic recursive process filters may happen if
> +    ;; `jsonrpc--connection-receive', called by us, eventually calls
> +    ;; client code which calls `process-send-string' (which see) to,
> +    ;; say send a follow-up message.  If that happens to writes enough
> +    ;; bytes for additional output to be received, we have a problem.
> +    ;;
> +    ;; In that case, remove recursiveness by re-scheduling ourselves to
> +    ;; run from within a timer as soon as possible.
> +
> +    (run-at-time 0 nil #'jsonrpc--process-filter proc string)
> +    (cl-return-from jsonrpc--process-filter))
>    (when (buffer-live-p (process-buffer proc))
>      (with-current-buffer (process-buffer proc)
>        (let* ((inhibit-read-only t)
> +             (jsonrpc--in-process-filter t)
>               (connection (process-get proc 'jsonrpc-connection))
>               (expected-bytes (jsonrpc--expected-bytes connection)))
>          ;; Insert the text, advancing the process marker.
>
>
>
>
>
>
>
>
>
>
>
>
>

-- 
João Távora

[-- Attachment #2: Type: text/html, Size: 6730 bytes --]

bug#60088: 29.0.60; Eglot loses messages from gopls

[Stefan Kangas]

João Távora <joaotavora@gmail.com> writes:

> I've now pushed the patch/bugfix to emacs-29 and bumped
> version of jsonrpc.el so we should get a new GNU ELPA package
> soon.

I'm therefore closing this bug report.