Re: Possible cache problems

[Nicolas Goaziou <mail@nicolasgoaziou.fr>]

Hello,

Suvayu Ali <fatkasuvayu+linux@gmail.com> writes:

> I have been noticing a strange heisenbug.  From time to time, Org starts
> eating CPU for certain specific tasks: org-end-of-line, fill-paragraph,
> folding or unfolding trees, or adding/changing properties with
> org-set-property.  However these happen only after I have been using Org
> for a while.

This is typical for cache breakage.

> I think I also see similar CPU eating symptoms when I have buffers
> editing version controlled files.  I have auto-revert-mode enabled for
> files under version control, I think that is related.  I'm not entirely
> sure though, I don't know how to narrow it down either.
>
> I say it is cache related since all this magically goes away, once I go
> to the top of my current tree, and call org-element-cache-reset.
> However, once the symptoms start showing, it happens more frequently
> despite my cache resets.

Usually, a cache breakage is a specific action applied to some specific
document structure that induces an incorrect computation of the parts of
the cache to clear and to update.

If you encountered the problem, it means the problematic document
structure is already in the current buffer. So, the chances are high
that you will repeat the problematic editing action on it again, even
after resetting the cache. IOW, all the ingredients are there for the
problem to repeat again and again.

Finding the problematic action is not easy. I wrote a basic minor mode
(element-debug-mode) for that: after each change to the buffer, it
checks if the cache and pending updates match the parse tree. It sends
a message anytime they differ, which happens as soon as a problematic
action was triggered.

Obviously, it is unusable if the buffer is not small. You may want to
try it on small parts of your document, repeating your usual editing
actions.

--8<---------------cut here---------------start------------->8---
(defun element-check-cache (&rest ignore)
  (when (org-element--cache-active-p)
    (save-match-data
      (let ((cache (copy-tree org-element--cache t))
            (requests (copy-tree org-element--cache-sync-requests t))
            (buffer-contents (org-with-wide-buffer (buffer-string)))
            (translations (make-hash-table :test #'eq))
            (structures (make-hash-table :test #'eq))
            (keys (make-hash-table :test #'eq)))
        ;; Fix parents.
        (loop for key in (avl-tree-flatten org-element--cache)
              for value in (avl-tree-flatten cache)
              do (let ((struct (and (memq (org-element-type key)
                                          '(plain-list item))
                                    (gethash (org-element-property :structure key)
                                             structures 'missing))))
                   (progn
                     (puthash key value translations)
                     (let ((k (gethash key org-element--cache-sync-keys)))
                       (when k (puthash value k keys)))
                     (puthash
                      key
                      (org-element-put-property
                       value :parent
                       (gethash (org-element-property :parent key)
                                translations))
                      translations)
                     (when (eq struct 'missing)
                       (setq struct
                             (puthash (org-element-property :structure key)
                                      (org-element-property :structure value)
                                      structures)))
                     (when struct
                       (puthash
                        key
                        (org-element-put-property value :structure struct)
                        translations)))))
        ;; Fix requests.
        (loop for original in org-element--cache-sync-requests
              for copy in requests
              do (progn (aset copy 4 (gethash (aref original 4) translations))
                        (aset copy 5 (gethash (aref original 5) translations))))
        (with-temp-buffer
          (let ((org-element-use-cache nil)) (insert buffer-contents))
          (let ((org-inhibit-startup t)) (org-mode))
          (setq org-element--cache cache
                org-element--cache-sync-requests requests
                org-element--cache-sync-keys keys)
          (org-element--cache-sync (current-buffer) (point-max))
          (let ((seen '()))
            (avl-tree-mapc
             (lambda (element)
               (let ((beg (org-element-property :begin element))
                     (type (org-element-type element)))
                 (let ((real (let (org-element-use-cache)
                               (goto-char
                                (if (memq type '(item table-row)) (1+ beg)
                                  beg))
                               (org-element-at-point))))
                   (cond
                    ((member real seen)
                     (message
                      "======\nWARNING. Two entries for the same element\n\n %s"
                      element))
                    ((not (equal real element))
                     (message
                      "======\nWARNING. Corrupted element (%s) at %d\n\nReal: %s\n\nCached: %s\nLast request: %s"
                      (org-element-type element) beg real element (car requests)))
                    (t (push real seen))))))
             org-element--cache)))))))

(define-minor-mode element-debug-mode
  "Minor mode to debug Org Element cache."
  nil " OrgCacheD" nil
  (if ngz-debug-mode
      (progn (setq org-element-cache-sync-idle-time 3600)
             (add-hook 'after-change-functions 'element-check-cache t t))
    (setq org-element-cache-sync-idle-time 0.6)
    (remove-hook 'after-change-functions 'element-check-cache t)))
--8<---------------cut here---------------end--------------->8---


Regards,

-- 
Nicolas Goaziou