add-hook's memory usage

[kamoii]

Using consult-buffer frequently, I noticed it somtimes has this little delay before it show its candidate. I assumed it was because of GC, so I profiled consult-buffer by starting profiler and invoking consult-buffer a few times. Following is part of the memory profile result:

    140,068,687  92%       - consult-buffer
    140,068,687  92%        - consult--buffer
    140,068,687  92%         - consult--multi
    138,933,527  91%          - consult--read
    138,933,527  91%           - apply
    138,933,527  91%            - #<subr consult--read>
     99,916,347  65%             - consult--with-async-1
     99,916,347  65%              - #<compiled 0x3e02774d5b1a3f7>
     99,912,203  65%               - consult--with-preview-1
     80,735,735  53%                - #<compiled -0xbfb98ad3a8adf1c>
     80,735,735  53%                 - completing-read
     80,735,735  53%                  - selectrum-completing-read
     62,909,765  41%                   - selectrum-read
     58,826,659  38%                    + add-hook
      1,077,206   0%                    + selectrum--minibuffer-post-command-hook
        336,172   0%                    + redisplay_internal (C function)
         73,200   0%                    + dimmer-command-handler
         26,112   0%                      selectrum--remove-default-from-prompt
          5,580   0%                    + minibuffer-inactive-mode
            176   0%                    + timer-event-handler
            104   0%                    + undo-auto--undoable-change
             96   0%                      command-execute
             80   0%                      consult--preview-post-command
             80   0%                      consult--preview-post-command
             80   0%                      consult--preview-post-command
             80   0%                      consult--preview-post-command
             80   0%                      consult--preview-post-command
             80   0%                      consult--preview-post-command
     19,176,468  12%                + add-hook
     39,017,180  25%             + add-hook

add-hook's total memory usage is 75% of the total consumed memory, which is quite high. I don't know why we need add-hook and why it consumes so much memory. Is add-hook supposed to consume such memory or maybe this is some kind of performance bug?

[minad]

I have also observed that add-hook appears in the memory profile and I don't understand it yet to be honest. There seems to be some weird copying/memory-leak going on in add-hook.

[minad]

Ping @clemera, this also happens for the Selectrum add-hook it seems. Any idea?

[clemera]

No, this seems strange :man_shrugging:

[minad]

Btw, what does this memory profiler measure. I don't understand this. Is it an allocation profiler? Or does it measure the amount of live data? But the consult/selectrum data should be gone after closing the completing-read session.

EDIT: Just checked, it measures allocations as expected.

[clemera]

I'm not an profiling expert myself, maybe someone else is able to provide a more detailed explanation.

[minad]

I did a few experiments.

1. When I remove the (:append ...) and simply prepend the hooks the problem goes away since then no sorting takes place.

2. Furthermore using the following macro instead of minibuffer-with-setup-hook fixes the issue, since I am not adding lambdas to the hooks but symbols. For some reason the add-hook function has problem with lambda values and seems to perform deep copies of those.

(defmacro my-minibuffer-with-setup-hook (fun &rest body)
  (declare (indent 1) (debug t))
  (let ((hook (make-symbol "setup-hook"))
        (funsym (make-symbol "fun"))
        (append nil))
    (when (eq (car-safe fun) :append)
      (setq append '(t) fun (cadr fun)))
    `(let ((,hook (make-symbol "hook-sym"))
           (,funsym ,fun))
       (fset ,hook
             (lambda ()
               ;; Clear out this hook so it does not interfere
               ;; with any recursive minibuffer usage.
               (remove-hook 'minibuffer-setup-hook ,hook)
               (funcall ,funsym)))
       (unwind-protect
           (progn
             (add-hook 'minibuffer-setup-hook ,hook ,@append)
             ,@body)
         (remove-hook 'minibuffer-setup-hook ,hook)))))

4. Lambdas have made problems before in combination with Evil, see #152. For this reason I am already using fset symbols in Consult for the post-command-hooks. The fset trick is something I found in set-transient-map.

5. Elisp is broken.

[clemera]

Thank you for looking into this, this should also be reported upstream I guess. I will steal your macro for Selectrum and use it for now :+1:

[minad]

@clemera Do you suggest we use this my-minibuffer macro in Consult and Selectrum for now?

[kamoii]

@clemera @minad Thansk a lot! Updated consult and its so snappy now. Took memory proffile and the add-hook is gone. Also the total memory allocation reduced alot.

     56,846,572  89%       - consult-buffer
     56,846,572  89%        - consult--buffer
     56,846,572  89%         - consult--multi
     53,076,020  83%          - consult--read
     53,076,020  83%           - apply
     53,076,020  83%            - #<compiled -0x1bf0d3486ff553f9>
     53,076,020  83%             - consult--with-async-1
     53,076,020  83%              - #<compiled 0x3e0275e58912bf7>
     53,076,020  83%               - consult--with-preview-1
     53,074,964  83%                - #<compiled -0xbfb98ce1324d29c>
     53,074,964  83%                 - completing-read
     53,074,964  83%                  - selectrum-completing-read
      5,530,436   8%                   + selectrum-read
         70,240   0%          + consult--multi-candidates
          4,360   0%            consult--multi-predicate
          1,056   0%          + consult--multi-preprocess

[minad]

@clemera Thank you for pushing the fix to selectrum too. @kamoii Thank you for the report and checking again.

Now the problem should still be reported upstream. It should be pretty easy to reproduce.

• Good: https://github.com/minad/consult/commit/27e055e7c75e2148449e7b0be4d464b03c36a1bd https://github.com/raxod502/selectrum/commit/8fd18284a7e2a9d02031d541de719d7134ba7588
• Bad: https://github.com/minad/consult/commit/2a197310923a732033bdb757b20c6f90cfad784a https://github.com/raxod502/selectrum/commit/a8bae8387b557bbb4a648e41217a18d5e9521d36

Start memory profiler and invoke consult-buffer a few times.

[minad]

Upstream bugreport:

Mail: https://lists.gnu.org/archive/html/bug-gnu-emacs/2021-02/msg00329.html Tracker: https://debbugs.gnu.org/cgi/bugreport.cgi?bug=46326

[jakanakaevangeli]

For those interested in the technicalities of why this issue occurred, I've finally figured it out.

(consult-buffer) makes a big closure A, adds it to minibuffer-setup-hook and then removes it from there. Even though add/remove-hook use equal for their function comparisons, this all happens quickly since (equal A A) is inexpensive to compute, equal short-circuits on objects that are eq.

Removing A from the hook will not remove it from its hook--depth-alist. You can check this by evaluating (get 'minibuffer-setup-hook 'hook--depth-alist), see Emacs bug#46414.

The second call to (consult-buffer) makes a closure B, which isn't eq to A. It is however equal to A. Add-hook will look for B in the hook--depth-alist with equal, leading to evaluation of (equal A B) which is expensive to compute. For objects exceeding depth of 10, equal allocates a hash table and does some consing for the purpose of loop detection, which is what we see in the memory profiler.

[minad]

Great, thank you for figuring this out! I agree with you regarding the steps to fix the problem:

1. Fix minibuffer-with-setup-hook as I proposed using symbols (as part of Emacs 28)
2. Fix the problem at the root by using eq in add-hook/remove-hook. Maybe as part of Emacs 28, but this seems unlikely? Revert the minibuffer-with-setup-hook fix and also revert the set-transient-map fix. There is no need to use symbols anymore.