bug#73041: 30.0.90; track-changes-mode logs warnings (#70541 regression? not actually fixed?)

[Stefan Monnier via "Bug reports for GNU Emacs, the Swiss army knife of text editors" <bug-gnu-emacs@gnu.org>]

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

>> I wish I could describe exactly what happened.  I found
>> https://debbugs.gnu.org/cgi/bugreport.cgi?bug=70541 which sounds
>> very much like what I'm seeing, but I don't use any input method.

Thanks for your description of the problem.  A reproducible recipe is of
course better, but sadly, we can't always have what we want.
Let's hope we find that eventually we'll get what we need.

>> Eventually, this pops into *Messages*:
>> 
>> #+begin_quote
>> cl--assertion-failed: Assertion failed: (or track-changes--before-no (<=
>> track-changes--before-beg (track-changes--state-beg track-changes--state)
>> beg end (track-changes--state-end track-changes--state)
>> track-changes--before-end))
>> #+end_quote

Hmm... this clearly points to a bug in track-changes.

>> #+begin_quote
>> ⛔ Warning (emacs): Missing/incorrect calls to ‘before/after-change-functions’!!
>> Details logged to ‘track-changes--error-log’
>> #+end_quote

Barring bugs in track-changes, this points to a bug in some other part
of Emacs, which prevents track-changes from getting the info it needs.
Track-changes (and Eglot) are supposedly equipped to deal with such
problems, because we know we still have many of them.

>> Over time, they just keep repeating,

Hmm... `track-changes--recover-from-error` should (as the name suggests)
"recover" so they shouldn't just keep repeating, unless the source of
the problem keeps repeating as well.  Or unless there's a bug in
track-changes.

>> although I think killing the
>> buffer and reopening the file makes it stop.
>>
>> If I have inspected ‘track-changes--error-log’ correctly, this is
>> what it contains (looks like some binary, hope it comes through
>> in some useful fashion or another):

It's a list of debug info, one per "recovery".  Each debug info is made
of the buffer name, the inconsistency encountered, then a backtrace, and
an extract of (raw) `view-lossage`.  Here's your data reformatted:

    (("lib.rs" (buffer-size 5254 5218)
      ((t track-changes--recover-from-error ... nil)
       (t track-changes-fetch ... nil)
       (t eglot--track-changes-fetch ... nil)
       (t eglot--signal-textDocument/didChange nil nil)
       (t eglot--signal-textDocument/didSave nil nil)
       (t run-hooks ... nil)
       (t basic-save-buffer ... nil)
       (t save-buffer ... nil)
       (t funcall-interactively ... nil)
       (t call-interactively ... nil)
       (t command-execute ... nil))
      [111 (nil . other-window)
       103 (nil . recompile)
       121 (nil . undefined)
       24 96 (nil . next-error)
       1 (nil . move-beginning-of-line)
       11 ...])
     ("lib.rs" (buffer-size 5256 5254)
      ((t track-changes--recover-from-error ... nil)
       (t track-changes-fetch ... nil)
       (t eglot--track-changes-fetch ... nil)
       (t eglot--signal-textDocument/didChange nil nil)
       (t eglot--signal-textDocument/didSave nil nil)
       (t run-hooks ... nil)
       (t basic-save-buffer ... nil)
       (t save-buffer nil nil)
       (t #[257 "r\211q\210\300 )\207" [save-buffer] 2 ...]
       (t map-y-or-n-p ... nil)
       (t save-some-buffers ... nil)
       (t recompile ... nil)
       ...)
      [19 (nil . save-buffer)
       24 24 (nil . exchange-point-and-mark)
       23 (nil . kill-region)
       24 19 (nil . save-buffer)
       backspace (nil . delete-backward-char) ...])
     ("lib.rs" (buffer-size 5278 5256)
      ((t track-changes--recover-from-error ... nil)
       (t track-changes-fetch ... nil)
       (t eglot--track-changes-fetch ... nil)
       (t eglot--signal-textDocument/didChange nil nil)
       (t eglot--signal-textDocument/didSave nil nil)
       (t run-hooks ... nil)
       (t basic-save-buffer ... nil)
       (t save-buffer ... nil)
       (t funcall-interactively ... nil)
       (t call-interactively ... nil)
       (t command-execute ... nil))
      [(nil . backward-word)
       2 (nil . backward-char)
       67108896 (nil . set-mark-command)
       134217734 (nil . forward-sexp)
       23 (nil . kill-region)
       24 19 (nil . save-buffer)
       ...])
     ("lib.rs" (buffer-size 5324 5278)
      ((t track-changes--recover-from-error ... nil)
       (t track-changes-fetch ... nil)
       (t eglot--track-changes-fetch ... nil)
       (t eglot--track-changes-signal ... nil)
       (t #[771 "\211^BZ\211^HG^E] ...)
       ...)
      ...)
     ...)

This suggests the error is always detected "late" when we find that the
buffer-size is not the one we expected, so some buffer change presumably
happened without informing track-changes.
That doesn't explain the assertion failure.

Also, I don't see anything "unusual" in the view-lossage.

>> I wish I could reliably repeat it.  Given that it occurs after
>> many hours of work, `emacs -Q` isn't an option.

Thanks.
I stared at the code for a bit trying to see how that assertion failure
can occur, but nothing came to mind yet.  I think we'll need more data.

Can you try to install the patch below, then run with
`debug-on-error` enabled?
Hopefully when the error occurs, this will give us more info (ideally
including a backtrace).


        Stefan

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: track-changes.patch --]
[-- Type: text/x-diff, Size: 5150 bytes --]

diff --git a/lisp/emacs-lisp/track-changes.el b/lisp/emacs-lisp/track-changes.el
index 92d14959763..325a92317ca 100644
--- a/lisp/emacs-lisp/track-changes.el
+++ b/lisp/emacs-lisp/track-changes.el
@@ -229,6 +229,7 @@ track-changes-register
     (push tracker track-changes--clean-trackers)
     (when disjoint
       (push tracker track-changes--disjoint-trackers))
+    (cl-assert (track-changes--sane-state-p))
     tracker))
 
 (defun track-changes-unregister (id)
@@ -253,7 +254,8 @@ track-changes-unregister
             track-changes--buffer-size
             track-changes--before-clean
             track-changes--state))
-    (remove-hook 'after-change-functions  #'track-changes--after  t)))
+    (remove-hook 'after-change-functions  #'track-changes--after  t))
+  (cl-assert (track-changes--sane-state-p)))
 
 (defun track-changes-fetch (id func)
   "Fetch the pending changes for tracker ID pass them to FUNC.
@@ -372,7 +374,8 @@ track-changes-fetch
           (funcall func beg end (or before lenbefore)))
       ;; Re-enable the tracker's signal only after running `func', so
       ;; as to avoid nested invocations.
-      (cl-pushnew id track-changes--clean-trackers))))
+      (cl-pushnew id track-changes--clean-trackers)
+      (cl-assert (track-changes--sane-state-p)))))
 
 (defun track-changes-inconsistent-state-p ()
   "Return whether the current buffer is in an inconsistent state.
@@ -387,6 +390,19 @@ track-changes-inconsistent-state-p
 
 ;;;; Auxiliary functions.
 
+(defun track-changes--sane-state-p ()
+  (and (equal track-changes--buffer-size (buffer-size))
+       (or track-changes--before-no
+           (pcase track-changes--before-clean
+             ('unset t)
+             ('set (<= track-changes--before-beg track-changes--before-end))
+             ('nil
+              (<= track-changes--before-beg
+                  (track-changes--state-beg track-changes--state)
+                  (track-changes--state-end track-changes--state)
+                  track-changes--before-end))
+             (_ nil)))))
+
 (defun track-changes--clean-state ()
   (cond
    ((null track-changes--state)
@@ -551,7 +567,8 @@ track-changes--before
                                      (length track-changes--before-string))))))
               (setf track-changes--before-end new-bend)
               (cl-callf concat track-changes--before-string
-                (buffer-substring-no-properties old-bend new-bend)))))))))
+                (buffer-substring-no-properties old-bend new-bend))))))))
+  (cl-assert (track-changes--sane-state-p)))
 
 (defun track-changes--after (beg end len)
   (cl-assert track-changes--state)
@@ -576,10 +593,26 @@ track-changes--after
         ;; BEG..END is not covered by previous `before-change-functions'!!
         (track-changes--recover-from-error `(unexpected-after ,beg ,end ,len))
       ;; Note the new changes.
+      (let ((orig-beg (track-changes--state-beg track-changes--state))
+            (orig-end (track-changes--state-end track-changes--state)))
       (when (< beg (track-changes--state-beg track-changes--state))
         (setf (track-changes--state-beg track-changes--state) beg))
       (cl-callf (lambda (old-end) (max end (+ old-end offset)))
           (track-changes--state-end track-changes--state))
+      (cl-assert (or track-changes--before-no
+                     (<= track-changes--before-beg
+                         (track-changes--state-beg track-changes--state)))
+                 nil "<=? %S %S (was %S)"
+                 track-changes--before-beg
+                 (track-changes--state-beg track-changes--state)
+                 orig-beg)
+      (cl-assert (or track-changes--before-no
+                     (<= (track-changes--state-end track-changes--state)
+                         track-changes--before-end))
+                 nil "<=? %S %S (was %S)"
+                 (track-changes--state-end track-changes--state)
+                 track-changes--before-end
+                 orig-end))
       (cl-assert (or track-changes--before-no
                      (<= track-changes--before-beg
                          (track-changes--state-beg track-changes--state)
@@ -591,7 +624,8 @@ track-changes--after
       (if (track-changes--tracker-immediate tracker)
           (funcall (track-changes--tracker-signal tracker) tracker)
         (run-with-timer 0 nil #'track-changes--call-signal
-                        (current-buffer) tracker)))))
+         (current-buffer) tracker))))
+  (cl-assert (track-changes--sane-state-p)))
 
 (defun track-changes--call-signal (buf tracker)
   (when (buffer-live-p buf)
diff --git a/lisp/progmodes/eglot.el b/lisp/progmodes/eglot.el
index 82e99a2c920..a2c9f73fc73 100644
--- a/lisp/progmodes/eglot.el
+++ b/lisp/progmodes/eglot.el
@@ -2813,6 +2813,8 @@ eglot--signal-textDocument/didChange
 
 (defun eglot--signal-textDocument/didOpen ()
   "Send textDocument/didOpen to server."
+  ;; Flush any potential pending change.
+  (eglot--track-changes-fetch eglot--track-changes)
   (setq eglot--recent-changes nil
         eglot--versioned-identifier 0
         eglot--TextDocumentIdentifier-cache nil)