Hi all
Hello again, it's been a long time since I last followed this list
regularly or posted regularly (until 2019, code contributions until
2016).
Now I would like to report issues with the performance of property
drawers in Org cache. The time it takes to open an Org file with a
useful amount of property drawers like in test_1.org has increased too
much for me to update from Org mode 9.5, see the table below.
Org loading performance has also degraded a bit but I assume and hope
that the amount is not more than necessary for the convenience of
having more Org features preloaded.
To do some homework I looked in Org news, the mailing list, the
Commentary of org-element-ast.el and an overview of
org-element-ast.el. The beginning of the result of
~(org-element-cache-map #'car :granularity 'element)~ (as found in
test-org-element.el) and its length of 3003 for test_1.org look
completely reasonable to me. ~org-element--cache-map-statistic t~ does
not reveal where the by far large rest of the total time goes: "Total
time: 10.668449 sec. Pre-process time: 0.000000 sec. Predicate time:
0.014772 sec. Re-search time: 0.000000 sec.". I am surprised that a
repeated use of ~org-element-cache-map~ is still quite slow: 2.0 s
without statistic for iterating over 3003 cached AST nodes to collect
their ~car~?. Obviously I am a bit overchallenged with the Org cache
and hope that someone can look into this.
Out of curiosity: What consumes time during killing an Org buffer that
seems to scale with the buffer/cache size? What has to be done more
than just garbage collection that can be deferred to after killing has
finished?
Michael
* Test procedure
----------------
Benchmarking started do get complicated because of the different time
sinks, so I automated the following steps 3) to 5) with
~benchmark-elapse~ etc. See the source block with the Emacs Lisp code
below.
1) Change Org version and ~$ make cleanall uncompiled~
2) ~$ emacs -Q --eval '(add-to-list (quote load-path)
"~/path/to/org-mode/lisp")'~
3) First just load Org by opening an empty Org file and kill the
buffer (table column "Load Org")
4) Then open test_1.org and kill the buffer (table column "test_1.org")
5) Then open test_2.org and kill the buffer (table column "test_2.org")
The times in seconds [s] are for opening the file and in parenthesis
for killing the buffer, rows in reverse chronological order:
| Org version | Load Org | test_1.org | test_2.org |
| | [s] | size: 1000 | size: 400 |
| | | [s] | [s] |
| | <r> | <r> | <r> |
|-------------+-----------+------------+------------|
| eebc9be7ca | 3.3 (0.0) | 13.3 (5.4) | 1.7 (0.7) |
| ... | | | |
| 924a64da39 | 3.1 (0.0) | 10.7 (0.2) | 1.3 (0.1) |
| 924a64da39^ | 2.6 (0.0) | 5.4 (0.2) | 0.7 (0.1) |
| ... | | | |
| release_9.6 | 2.9 (0.0) | 6.9 (0.0) | 1.8 (0.0) |
| ... | | | |
| release_9.5 | 2.3 (0.0) | 0.2 (0.0) | 12.1 (0.0) |
Commit eebc9be7ca: The main branch as of [2024-12-16 Mon].
Commit 924a64da39:
- Author: Ihor Radchenko <yanta...@posteo.net>
- Date: Sat May 20 13:29:04 2023 +0200
- Title: org-element: Use the new org-element-ast library
All with Emacs 29.4 on macOS.
* Minimal working examples
--------------------------
test_1.org depends on ~overview~ and drawers that may be property
drawers or just drawers and may be empty. Shell command for size 1000:
: $ (echo '#+startup: overview' && for ((i = 1; i <= 1000; i++)); do
printf '* %d\n:PROPERTIES:\n:END:\n' $i; done ; ) > test_1.org
test_2.org depends on ~overview~, the drawers may be empty. Shell
command for different size 400:
: $ (echo '#+startup: overview' && for ((i = 1; i <= 400; i++)); do
printf ':MY_DRAWER_%d:\n:END:\n' $i; done ; ) > test_2.org
* Test automation
-----------------
#+begin_src emacs-lisp :eval no
(let ((test-0-open-file -1.0) (test-0-kill-buffer -1.0)
(test-1-open-file -1.0) (test-1-kill-buffer -1.0)
(test-2-open-file -1.0) (test-2-kill-buffer -1.0))
(require 'benchmark)
;; ,test_0.org
(when t
(setq test-0-open-file (benchmark-elapse (find-file "~/z/,test_0.org")))
(switch-to-buffer "*Messages*")
(message (concat "INF: test-0-open-file = "
(number-to-string test-0-open-file))))
(when t
(setq test-0-kill-buffer (benchmark-elapse (kill-buffer ",test_0.org")))
(switch-to-buffer "*Messages*")
(message (concat "INF: test-0-kill-buffer = "
(number-to-string test-0-kill-buffer))))
;; ,test_1.org
(when t
(setq test-1-open-file (benchmark-elapse (find-file "~/z/,test_1.org")))
(switch-to-buffer "*Messages*")
(message (concat "INF: test-1-open-file = "
(number-to-string test-1-open-file))))
(when t
(setq test-1-kill-buffer (benchmark-elapse (kill-buffer ",test_1.org")))
(switch-to-buffer "*Messages*")
(message (concat "INF: test-1-kill-buffer = "
(number-to-string test-1-kill-buffer))))
;; ,test_2.org
(when t
(setq test-2-open-file (benchmark-elapse (find-file "~/z/,test_2.org")))
(switch-to-buffer "*Messages*")
(message (concat "INF: test-2-open-file = "
(number-to-string test-2-open-file))))
(when t
(setq test-2-kill-buffer (benchmark-elapse (kill-buffer ",test_2.org")))
(switch-to-buffer "*Messages*")
(message (concat "INF: test-2-kill-buffer = "
(number-to-string test-2-kill-buffer))))
(kill-new (concat " " (format "%.1f" test-0-open-file)
" (" (format "%.1f" test-0-kill-buffer) ") |"
" " (format "%.1f" test-1-open-file)
" (" (format "%.1f" test-1-kill-buffer) ") |"
" " (format "%.1f" test-2-open-file)
" (" (format "%.1f" test-2-kill-buffer) ") |")))
#+end_src
