[BUG] org-element-cache warning while capturing [9.6 (release_9.6-204-g2f7052.dirty @ /home/grfz/src/org-mode/lisp/)]

[Gregor Zattler]

Dear org-mode developers, I caught this org-element--cache:
Warning(*Capture*) with `max-lisp-eval-depth` set to 32000.
With a value of 16000 I got
org-capture: Capture abort: Lisp nesting exceeds ‘max-lisp-eval-depth’: 16001
With a value of 160000 I got a segfault and the backtrace
was so huge it took too long to generate it.



So this is with 

Emacs  : GNU Emacs 30.0.50 (build 3, x86_64-pc-linux-gnu, cairo version 1.16.0)
 of 2023-01-04
Package: Org mode version 9.6 (release_9.6-204-g2f7052.dirty @ 
/home/grfz/src/org-mode/lisp/)

and max-lisp-eval-depth set to 32000:


 ■  Warning (org-element-cache): org-element--cache: Warning(*Capture*): (nil) 
Cached element is incorrect in *Capture*. (Cache tic up to date: "yes") 
Resetting.
If this warning appears regularly, please report the warning text to Org mode 
mailing list (M-x org-submit-bug-report).
The element is: "(headline (:raw-value \"7f8d26507d7a6f4104411c314ed8adcf\" 
:begin 1 :end 267 :pre-blank 0 :contents-begin 17 :contents-end 267 
:robust-begin 60 :robust-end 265 :level 1 :priority nil :tags nil :todo-keyword 
\"TODO\" :todo-type todo :post-blank 0 :footnote-section-p nil :archivedp nil 
:commentedp nil :post-affiliated 1 :ID \"%(org-id-new)\" :title 
\"7f8d26507d7a6f4104411c314ed8adcf\" :mode first-section :granularity element 
:cached t :parent (org-data (:begin 1 :contents-begin 1 :contents-end 267 :end 
267 :robust-begin 3 :robust-end 265 :post-blank 0 :post-affiliated 1 :path nil 
:mode org-data :CATEGORY nil :cached t)) :org-element--cache-sync-key (1 . 1)))"
 The real element is: "(headline (:raw-value 
\"7f8d26507d7a6f4104411c314ed8adcf\" :begin 1 :end 265 :pre-blank 0 
:contents-begin 17 :contents-end 265 :robust-begin 60 :robust-end 263 :level 1 
:priority nil :tags nil :todo-keyword #(\"TODO\" 0 4 (face (org-todo 
org-level-1) fontified t)) :todo-type todo :post-blank 0 :footnote-section-p 
nil :archivedp nil :commentedp nil :post-affiliated 1 :ID \"%(org-id-new)\" 
:title \"7f8d26507d7a6f4104411c314ed8adcf\" :mode first-section :granularity 
element :parent (org-data (:begin 1 :contents-begin 1 :contents-end 265 :end 
265 :robust-begin 3 :robust-end 263 :post-blank 0 :post-affiliated 1 :path nil 
:mode org-data :CATEGORY nil))))"
 Cache around :begin:
nil
(headline (:raw-value "%? %^{}G" :begin 1 :end 267 :pre-blank 0 :contents-begin 
17 :contents-end 267 :robust-begin 60 :robust-end 265 :level 1 :priority nil 
:tags nil :todo-keyword "TODO" :todo-type todo :post-blank 0 
:footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 1 :ID 
"%(org-id-new)" :title "%? %^{}G" :mode first-section :granularity element 
:cached t :parent (org-data (:begin 1 :contents-begin 1 :contents-end 267 :end 
267 :robust-begin 3 :robust-end 265 :post-blank 0 :post-affiliated 1 :path nil 
:mode org-data :CATEGORY nil :cached t)) :org-element--cache-sync-key (1 . 1)))
nil
Backtrace:
  org-element-cache diagnostics(*Capture*): org-element-cache: Finished 
process. The cache size is 2. The remaining sync requests: "([16 17 107 160 ... 
0])"
  org-element-cache diagnostics(*Capture*): Phase 0 deleted all elements in 
cache after 16!
  org-element-cache diagnostics(*Capture*): Decreasing cache size to 2
  org-element-cache diagnostics(*Capture*): removing (1 . 16)::"(section 
(:begin 17 :end 107 :contents-begin 17 :contents-end 107 :robust-begin 17 
:robust-end 105 :post-blank 0 :post-affiliated 17 :mode section :granularity 
element :cached t :parent (headline (:raw-value \"%? %^{}G\" :begin 1 :end 267 
:pre-blank 0 :contents-begin 17 :contents-end 267 :robust-begin 60 :robust-end 
265 :level 1 :priority nil :tags nil :todo-keyword \"TODO\" :todo-type todo 
:post-blank 0 :footnote-section-p nil :archivedp nil :commentedp nil 
:post-affiliated 1 :ID \"%(org-id-new)\" :title \"%? %^{}G\" :mode 
first-section :granularity element :cached t :parent (org-data ...) 
:org-element--cache-sync-key (1 . 1))) :org-element--cache-sync-key (1 . 16)))"
  org-element-cache diagnostics(*Capture*): Phase 0
  org-element-cache diagnostics(*Capture*): org-element-cache: Processing 
request [16 17 107 160 (headline (:raw-value "%? %^{}G" :begin 1 :end 267 
:pre-blank 0 :contents-begin 17 ...)) 0] up to 85-267, next: nil
  org-element-cache diagnostics(*Capture*): Syncing down to 85-267
  org-element-cache diagnostics(*Capture*): Adding new phase 0 request
  org-element-cache diagnostics(*Capture*): Submitting new synchronization 
request for [85..267]𝝙-2
  org-element-cache diagnostics(*Capture*): org-capture is about to modify 
text: warning nil
  org-element-cache diagnostics(*Capture*): After change
  org-element-cache diagnostics(*Capture*): org-capture is about to modify 
text: warning nil
  org-element-cache diagnostics(*Capture*): Extending to non-robust element 
"(section (:begin 17 :end 107 :contents-begin 17 :contents-end 107 
:robust-begin 17 :robust-end 105 :post-blank 0 :post-affiliated 17 :mode 
section :granularity element :cached t :parent (headline (:raw-value \"%? 
%^{}G\" :begin 1 :end 267 :pre-blank 0 :contents-begin 17 :contents-end 267 
:robust-begin 60 :robust-end 265 :level 1 :priority nil :tags nil :todo-keyword 
\"TODO\" :todo-type todo :post-blank 0 :footnote-section-p nil :archivedp nil 
:commentedp nil :post-affiliated 1 :ID \"%(org-id-new)\" :title \"%? %^{}G\" 
:mode first-section :granularity element :cached t :parent (org-data ...) 
:org-element--cache-sync-key (0 . 1))) :org-element--cache-sync-key (0 . 16)))"
  org-element-cache diagnostics(*Capture*): Shifting end positions of robust 
parent: "(org-data (:begin 1 :contents-begin 1 :contents-end 267 :end 267 
:robust-begin 3 :robust-end 265 :post-blank 0 :post-affiliated 1 :path nil 
:mode org-data :CATEGORY nil :cached t))"
  org-element-cache diagnostics(*Capture*): Shifting end positions of robust 
parent: "(headline (:raw-value \"7f8d26507d7a6f4104411c314ed8adcf\" :begin 1 
:end 267 :pre-blank 0 :contents-begin 17 :contents-end 267 :robust-begin 60 
:robust-end 265 :level 1 :priority nil :tags nil :todo-keyword \"TODO\" 
:todo-type todo :post-blank 0 :footnote-section-p nil :archivedp nil 
:commentedp nil :post-affiliated 1 :ID \"%(org-id-new)\" :title 
\"7f8d26507d7a6f4104411c314ed8adcf\" :mode first-section :granularity element 
:cached t :parent (org-data (:begin 1 :contents-begin 1 :contents-end 107 :end 
107 :robust-begin 3 :robust-end 105 :post-blank 0 :post-affiliated 1 :path nil 
:mode org-data :CATEGORY nil :cached t)) :org-element--cache-sync-key (0 . 1)))"
  org-element-cache diagnostics(*Capture*): Found non-robust element: "(section 
(:begin 17 :end 107 :contents-begin 17 :contents-end 107 :robust-begin 17 
:robust-end 105 :post-blank 0 :post-affiliated 17 :mode section :granularity 
element :cached t :parent (headline (:raw-value \"%? %^{}G\" :begin 1 :end 107 
:pre-blank 0 :contents-begin 17 :contents-end 107 :robust-begin 60 :robust-end 
105 :level 1 :priority nil :tags nil :todo-keyword \"TODO\" :todo-type todo 
:post-blank 0 :footnote-section-p nil :archivedp nil :commentedp nil 
:post-affiliated 1 :ID \"%(org-id-new)\" :title \"%? %^{}G\" :mode 
first-section :granularity element :cached t :parent (org-data ...) 
:org-element--cache-sync-key (0 . 1))) :org-element--cache-sync-key (0 . 16)))"
  org-element-cache diagnostics(*Capture*): Adding new phase 0 request
  org-element-cache diagnostics(*Capture*): Submitting new synchronization 
request for [85..87]𝝙160
  org-element-cache diagnostics(*Capture*): org-capture is about to modify 
text: warning t
  org-element-cache diagnostics(*Capture*): After change
  org-element-cache diagnostics(*Capture*): org-capture is about to modify 
text: warning t
  org-element-cache diagnostics(*Capture*): Nothing to remove. No elements in 
cache after 89. Terminating.
  org-element-cache diagnostics(*Capture*): Shifting end positions of robust 
parent: "(org-data (:begin 1 :contents-begin 1 :contents-end 107 :end 107 
:robust-begin 3 :robust-end 105 :post-blank 0 :post-affiliated 1 :path nil 
:mode org-data :CATEGORY nil :cached t))"
  org-element-cache diagnostics(*Capture*): Shifting end positions of robust 
parent: "(headline (:raw-value \"7f8d26507d7a6f4104411c314ed8adcf\" :begin 1 
:end 107 :pre-blank 0 :contents-begin 17 :contents-end 107 :robust-begin 60 
:robust-end 105 :level 1 :priority nil :tags nil :todo-keyword \"TODO\" 
:todo-type todo :post-blank 0 :footnote-section-p nil :archivedp nil 
:commentedp nil :post-affiliated 1 :ID \"%(org-id-new)\" :title 
\"7f8d26507d7a6f4104411c314ed8adcf\" :mode first-section :granularity element 
:cached t :parent (org-data (:begin 1 :contents-begin 1 :contents-end 109 :end 
109 :robust-begin 3 :robust-end 107 :post-blank 0 :post-affiliated 1 :path nil 
:mode org-data :CATEGORY nil :cached t)) :org-element--cache-sync-key (0 . 1)))"
  org-element-cache diagnostics(*Capture*): Shifting end positions of robust 
parent: "(section (:begin 17 :end 107 :contents-begin 17 :contents-end 107 
:robust-begin 17 :robust-end 105 :post-blank 0 :post-affiliated 17 :mode 
section :granularity element :cached t :parent (headline (:raw-value \"%? 
%^{}G\" :begin 1 :end 109 :pre-blank 0 :contents-begin 17 :contents-end 109 
:robust-begin 60 :robust-end 107 :level 1 :priority nil :tags nil :todo-keyword 
\"TODO\" :todo-type todo :post-blank 0 :footnote-section-p nil :archivedp nil 
:commentedp nil :post-affiliated 1 :ID \"%(org-id-new)\" :title \"%? %^{}G\" 
:mode first-section :granularity element :cached t :parent (org-data ...) 
:org-element--cache-sync-key (0 . 1))) :org-element--cache-sync-key (0 . 16)))"
  org-element-cache diagnostics(*Capture*): org-element-cache: Finished 
process. The cache size is 3. The remaining sync requests: "([17 17 62 -2 ... 
0])"
  org-element-cache diagnostics(*Capture*): Phase 0 deleted all elements in 
cache after 17!
  org-element-cache diagnostics(*Capture*): Decreasing cache size to 3
  org-element-cache diagnostics(*Capture*): removing (0 . 
17)::"(property-drawer (:begin 17 :end 62 :contents-begin 32 :contents-end 53 
:post-blank 1 :post-affiliated 17 :mode planning :granularity element :cached t 
:parent (section (:begin 17 :end 109 :contents-begin 17 :contents-end 109 
:robust-begin 17 :robust-end 107 :post-blank 0 :post-affiliated 17 :mode 
section :granularity element :cached t :parent (headline ...) 
:org-element--cache-sync-key (0 . 16))) :org-element--cache-sync-key (0 . 17)))"
  org-element-cache diagnostics(*Capture*): Phase 0
  org-element-cache diagnostics(*Capture*): org-element-cache: Processing 
request [17 17 62 -2 (property-drawer (:begin 17 :end 62 :contents-begin 32 
:contents-end 53 :post-blank 1 ...)) 0] up to 85-89, next: nil
  org-element-cache diagnostics(*Capture*): Syncing down to 85-89
  org-element-cache diagnostics(*Capture*): Adding new phase 0 request
  org-element-cache diagnostics(*Capture*): Submitting new synchronization 
request for [85..89]𝝙-2
  org-element-cache diagnostics(*Capture*): org-capture is about to modify 
text: warning t
  org-element-cache diagnostics(*Capture*): After change
  org-element-cache diagnostics(*Capture*): org-capture is about to modify 
text: warning nil
  org-element-cache diagnostics(*Capture*): Extending to all elements between:
 1: "(property-drawer (:begin 17 :end 62 :contents-begin 32 :contents-end 53 
:post-blank 1 :post-affiliated 17 :mode planning :granularity element :cached t 
:parent (section (:begin 17 :end 109 :contents-begin 17 :contents-end 109 
:robust-begin 17 :robust-end 107 :post-blank 0 :post-affiliated 17 :mode 
section :granularity element :cached t :parent (headline ...)))))"
 2: "(property-drawer (:begin 17 :end 62 :contents-begin 32 :contents-end 53 
:post-blank 1 :post-affiliated 17 :mode planning :granularity element :cached t 
:parent (section (:begin 17 :end 109 :contents-begin 17 :contents-end 109 
:robust-begin 17 :robust-end 107 :post-blank 0 :post-affiliated 17 :mode 
section :granularity element :cached t :parent (headline ...)))))"
  org-element-cache diagnostics(*Capture*): Shifting end positions of robust 
parent: "(org-data (:begin 1 :contents-begin 1 :contents-end 109 :end 109 
:robust-begin 3 :robust-end 107 :post-blank 0 :post-affiliated 1 :path nil 
:mode org-data :CATEGORY nil :cached t))"
  org-element-cache diagnostics(*Capture*): Shifting end positions of robust 
parent: "(headline (:raw-value \"7f8d26507d7a6f4104411c314ed8adcf\" :begin 1 
:end 109 :pre-blank 0 :contents-begin 17 :contents-end 109 :robust-begin 60 
:robust-end 107 :level 1 :priority nil :tags nil :todo-keyword \"TODO\" 
:todo-type todo :post-blank 0 :footnote-section-p nil :archivedp nil 
:commentedp nil :post-affiliated 1 :ID \"%(org-id-new)\" :title 
\"7f8d26507d7a6f4104411c314ed8adcf\" :mode first-section :granularity element 
:cached t :parent (org-data (:begin 1 :contents-begin 1 :contents-end 111 :end 
111 :robust-begin 3 :robust-end 109 :post-blank 0 :post-affiliated 1 :path nil 
:mode org-data :CATEGORY nil :cached t))))"
  org-element-cache diagnostics(*Capture*): Shifting end positions of robust 
parent: "(section (:begin 17 :end 109 :contents-begin 17 :contents-end 109 
:robust-begin 17 :robust-end 107 :post-blank 0 :post-affiliated 17 :mode 
section :granularity element :cached t :parent (headline (:raw-value \"%? 
%^{}G\" :begin 1 :end 111 :pre-blank 0 :contents-begin 17 :contents-end 111 
:robust-begin 60 :robust-end 109 :level 1 :priority nil :tags nil :todo-keyword 
\"TODO\" :todo-type todo :post-blank 0 :footnote-section-p nil :archivedp nil 
:commentedp nil :post-affiliated 1 :ID \"%(org-id-new)\" :title \"%? %^{}G\" 
:mode first-section :granularity element :cached t :parent (org-data ...)))))"
  org-element-cache diagnostics(*Capture*): Found non-robust element: 
"(property-drawer (:begin 17 :end 62 :contents-begin 32 :contents-end 53 
:post-blank 1 :post-affiliated 17 :mode planning :granularity element :cached t 
:parent (section (:begin 17 :end 111 :contents-begin 17 :contents-end 111 
:robust-begin 17 :robust-end 109 :post-blank 0 :post-affiliated 17 :mode 
section :granularity element :cached t :parent (headline ...)))))"
  org-element-cache diagnostics(*Capture*): Adding new phase 0 request
  org-element-cache diagnostics(*Capture*): Submitting new synchronization 
request for [62..66]𝝙-2
  org-element-cache diagnostics(*Capture*): org-capture is about to modify 
text: warning nil
  org-element-cache diagnostics(*Capture*): After change
  org-element-cache diagnostics(*Capture*): org-capture is about to modify 
text: warning nil
  org-element-cache diagnostics(*Capture*): org-capture is about to modify 
text: warning nil
  org-element-cache diagnostics(*Capture*): Added new element with nil key: 
"(property-drawer (:begin 17 :end 62 :contents-begin 32 :contents-end 53 
:post-blank 1 :post-affiliated 17 :mode planning :granularity element))"
  org-element-cache diagnostics(*Capture*): Added new element with nil key: 
"(section (:begin 17 :end 111 :contents-begin 17 :contents-end 111 
:robust-begin 17 :robust-end 109 :post-blank 0 :post-affiliated 17 :mode 
section :granularity element))"
  org-element-cache diagnostics(*Capture*): Added new element with nil key: 
"(headline (:raw-value \"7f8d26507d7a6f4104411c314ed8adcf\" :begin 1 :end 111 
:pre-blank 0 :contents-begin 17 :contents-end 111 :robust-begin 60 :robust-end 
109 :level 1 :priority nil :tags nil :todo-keyword \"TODO\" :todo-type todo 
:post-blank 0 :footnote-section-p nil :archivedp nil :commentedp nil 
:post-affiliated 1 :ID \"%(org-id-new)\" :title 
\"7f8d26507d7a6f4104411c314ed8adcf\" :mode first-section :granularity element))"
  org-element-cache diagnostics(*Capture*): Added new element with nil key: 
"(org-data (:begin 1 :contents-begin 1 :contents-end 111 :end 111 :robust-begin 
3 :robust-end 109 :post-blank 0 :post-affiliated 1 :path nil :mode org-data 
:CATEGORY nil))"
  org-element-cache diagnostics(*Capture*): Nothing in cache. Adding org-data: 
"(org-data (:begin 1 :contents-begin 1 :contents-end 111 :end 111 :robust-begin 
3 :robust-end 109 :post-blank 0 :post-affiliated 1 :path nil :mode org-data 
:CATEGORY nil))"




HTH, and thanks for your attention, Gregor