Busy synchronization

[Alexander-Shukaev]

- timer-event-handler                                           43366  81%
 - apply                                                        43366  81%
  - deferred:worker                                             43357  81%
   - deferred:exec-task                                         43357  81%
    - deferred:call-lambda                                      43357  81%
     - #<compiled 0x183d51d>                                    43357  81%
      - ycmd-semantic-completer-available-p                     43357  81%
       - ycmd--send-completer-available-request                 43357  81%
        - ycmd-deferred:sync!                                   43282  81%
         - accept-process-output                                  237   0%
          - timer-event-handler                                   235   0%
           - apply                                                226   0%
            + savehist-autosave                                   215   0%
            + jit-lock-stealth-fontify                              8   0%
            + minibuffer-line--update                               1   0%
              auto-revert-buffers                                   1   0%
           + timer-inc-time                                         3   0%
        + ycmd--request                                             3   0%
  + auto-revert-buffers                                             5   0%
- ...                                                            9218  17%
   Automatic GC                                                  9217  17%

I don't know how but sometimes the above happens, and the only thing I see is Garbage collecting...done, while input it locked. The only way to escape that is to <C-g> three times. However, moving the point a couple of times again triggers the same scenario. I tried ycmd-open to restart it but it ends up with the same problem. Only ycmd-close stops it of course. Not sure if this is environment-related or a regression. I haven't seen this a couple of months ago for sure.

[abingham]

I'm really not sure what's going on here. Unfortunately, I've got to focus my time and energy on other projects, and I won't be spending any time on my emacs stuff.

[Alexander-Shukaev]

Again hitting the same scenario and want to share more observations. First of all, the code of that function:

(defun ycmd-deferred:sync! (d)
  "Wait for the given deferred task.
Error is raised if it is not processed within deferred chain D.
This is a slightly modified version of the original
`deferred:sync!' function, with using `accept-process-output'
wrapped with `with-current-buffer' for waiting instead of a
combination of `sit-for' and `sleep-for' and with a shorter wait
time."
  (progn
    (let ((last-value 'deferred:undefined*)
          uncaught-error)
      (deferred:try
        (deferred:nextc d
          (lambda (x) (setq last-value x)))
        :catch
        (lambda (err) (setq uncaught-error err)))
      (with-local-quit
        (while (and (eq 'deferred:undefined* last-value)
                    (not uncaught-error))
          (accept-process-output nil 0.01))
        (when uncaught-error
          (deferred:resignal uncaught-error))
        last-value))))

So if I switch any buffer where YCMD is not active, there is no problem. As soon as I choose a buffer where YCMD is active, Emacs freezes. Now as I understand, thanks to with-local-quit, I can C-g and that's what I do to escape that freeze. However, as soon as I do some movement, it freezes again suggesting that the same function is triggered again. The interesting part is that as soon as I hit C-g, then *ycmd-server* buffer displays one more

2019-02-28 16:29:39,392 - INFO - Received filetype completion available request

message. If I freeze again and again C-g, then another same message is printed and so on.

From the documentation string I see that ycmd-deferred:sync! is a rewrite of deferred:sync! with some adjustments. Could it be that something is wrong with ycmd-deferred:sync! itself? Any ideas what to experiment with to understand that issue further?

Adding other experts, @ptrv and @kiwanami.

[Alexander-Shukaev]

I know what's going on now. Basically, the way deferred works in general is by scheduling a timer event to be executed some time in the future. The evil part about Emacs is that timer events run by timer-event-handler can be triggered either at top-level or at recursive-edit (which is already nested into top-level at least) or as part of sit-for (see input-pending-p) or accept-process-output or even message (which triggers redisplay and subsequently C function redisplay_internal that invokes Lisp interpreter machine yet again and hence potentially timer-event-handler).

With such plethora of possibilities for timer-event-handler to run especially in a nested manner one could even observe an interesting peculiarity:

• Event A scheduled to run ASAP.
• Event B scheduled to run ASAP.
• The expectation is that B strictly runs after A finishes execution.
• Well, if A calls message, then according to the above, A could indirectly run timer-event-handler (nested) which, as a result, will run B now essentially somewhere in the middle of A.
• Clearly, unless taken care of this may result in side effects and nasty bugs, which are difficult to track down.

For now these were just examples of the potential complexity, I'm not yet claiming that emacs-ycmd suffers exactly from those at the moment. However, now to the actual point, ycmd-eldoc, though being a buffer-local minor mode in the first place, does not keep track of the current-buffer between various stages of deferred executions. It all starts from ycmd-eldoc--documentation-function, where current-buffer should have been let-bound at the very top and then restored in every deferred execution using with-current-buffer (similar to how it was done in ycmd--conditional-parse). The same should be implemented in ycmd-eldoc--check-if-semantic-completer-exists-for-mode as well as any other function that internally calls deferred routines which have buffer-local semantics (e.g. buffer-local variables access or modification). Plus, ycmd-semantic-completer-available-p is missing a check whether ycmd-mode is still enabled (as it could have been disabled at any point between deferred executions) and skip sending requests to the actual server (which might be shut down anyway).

So because of the absence of the above measures, the following happens:

• find-file for a file, where ycmd-mode is supposed to be enabled;
• ycmd-mode gets enabled;
• ycmd-eldoc-mode gets enabled;
• ycmd-eldoc--documentation-function transitively schedules ycmd-semantic-completer-available-p to run some time soon;
• some other timer event arrives first (for a completely different task and package) and is being run by timer-event-handler;
• but during its execution it calls accept-process-output (in its own dedicated hidden buffer whose name starts with space as per Emacs convention for hidden buffer names);
• this in turn triggers another nested call to timer-event-handler, which now runs our deferred task to call ycmd-semantic-completer-available-p;
• unfortunately, since the buffer where it is supposed to be run is not tracked (see the above recommendation), that function is now being run in some random inappropriate buffer where it is not supposed to be run at all;
• you can imagine what kind of garbage it may now send to the YCMD server from that inappropriate buffer;
• in fact, at times it simply hangs waiting for the response because something unexpected is happening with respect to communication now, while sometimes it returns some weird errors from the server as it clearly cannot process such requests.

[Alexander-Shukaev]

@ptrv, do you still maintain ycmd-eldoc?