From 49df468849aa3e39496d9aa308617938a9a02d77 Mon Sep 17 00:00:00 2001
From: Ihor Radchenko <yantar92@gmail.com>
Date: Thu, 25 Nov 2021 22:16:37 +0800
Subject: [PATCH] org-element-cache-map: Report pre-process time in statistics

* lisp/org-element.el (org-element-cache-map): Calculate time elapsed
while filling the cache gaps during pre-processing.
---
 lisp/org-element.el | 14 ++++++++++----
 1 file changed, 10 insertions(+), 4 deletions(-)

diff --git a/lisp/org-element.el b/lisp/org-element.el
index b5a4bf217..752912eea 100644
--- a/lisp/org-element.el
+++ b/lisp/org-element.el
@@ -7292,6 +7292,7 @@ the cache."
                  ;; Statistics
                  (time (float-time))
                  (predicate-time 0)
+                 (pre-process-time 0)
                  (count-predicate-calls-match 0)
                  (count-predicate-calls-fail 0))
             ;; Skip to first element within region.
@@ -7308,9 +7309,13 @@ the cache."
                           (and (eq granularity 'element)
                                (or next-re fail-re)))
                 (let ((org-element-cache-map--recurse t))
-                  (org-element-cache-map
-                   #'ignore
-                   :granularity granularity)
+                  (let ((before-time (float-time)))
+                    (org-element-cache-map
+                     #'ignore
+                     :granularity granularity)  
+                    (cl-incf pre-process-time
+                             (- (float-time)
+                                before-time)))
                   ;; Re-assign the cache root after filling the cache
                   ;; gaps.
                   (setq node (cache-root)))
@@ -7474,13 +7479,14 @@ the cache."
             (when (and org-element--cache-map-statistics
                        (or (not org-element--cache-map-statistics-threshold)
                            (> (- (float-time) time) org-element--cache-map-statistics-threshold)))
-              (message "Mapped over elements in %S. %d/%d predicate matches. Total time: %f sec. Time running predicates: %f sec (%f sec avg)
+              (message "Mapped over elements in %S. %d/%d predicate matches. Total time: %f sec. Pre-process time: %f sec. Time running predicates: %f sec (%f sec avg)
        Calling parameters: :granularity %S :restrict-elements %S :next-re %S :fail-re %S :from-pos %S :to-pos %S :limit-count %S :after-element %S"
                        (current-buffer)
                        count-predicate-calls-match
                        (+ count-predicate-calls-match
                           count-predicate-calls-fail)
                        (- (float-time) time)
+                       pre-process-time
                        predicate-time
                        (if (zerop (+ count-predicate-calls-match
                                      count-predicate-calls-fail))