[BUG] org-element--cache: (org-agenda) Cached element is incorrect [9.6 (release_9.6-90-gf49ee9 @ /home/stefan/.emacs.d/contrib/org-mode/lisp/)]

[BUG] org-element--cache: (org-agenda) Cached element is incorrect [9.6 (release_9.6-90-gf49ee9 @ /home/stefan/.emacs.d/contrib/org-mode/lisp/)]

[Stefan]

While trying to reproduce the "Org parser error" error issue (see other thread), I got multiple "Cached element is incorrect" warnings (backtrace excerpt below).

Here is one that appeared when trying to loading the =t= agenda:

-- quote --

Warning (org-element-cache): org-element--cache: (org-agenda) Cached element is incorrect in Media.org. (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 \"Podcasts\" :begin 684093 :end 741628 :pre-blank 0 :contents-begin 684104 :contents-end 741627 :robust-begin 684148 :robust-end 741625 :level 1 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684093 :ID \"podcasts\" :title \"Podcasts\" :mode nil :granularity element :cached t :parent (org-data (:begin 1 :contents-begin 1 :contents-end 746346 :end 746346 :robust-begin 3 :robust-end 746344 :post-blank 0 :post-affiliated 1 :path \"/home/stefan/PRIVATE/journal/org/Media.org\" :mode org-data :CATEGORY \"Media\" :cached t))))"
 The real element is: "(headline (:raw-value \"Podcasts\" :begin 684093 :end 740615 :pre-blank 0 :contents-begin 684104 :contents-end 740614 :robust-begin 684148 :robust-end 740612 :level 1 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684093 :ID \"podcasts\" :title \"Podcasts\" :mode nil :granularity element :parent nil))"
 Cache around :begin:
nil
nil
nil Disable showing Disable logging

Warning (org-element-cache): org-element--cache: (org-agenda) Cached element is incorrect in Media.org. (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 \"My Podcast Recommendations\" :begin 684150 :end 692232 :pre-blank 1 :contents-begin 684181 :contents-end 692231 :robust-begin 684183 :robust-end 692229 :level 2 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684150 :title \"My Podcast Recommendations\" :mode nil :granularity element :cached t :parent (headline (:raw-value \"Podcasts\" :begin 684093 :end 741628 :pre-blank 0 :contents-begin 684104 :contents-end 741627 :robust-begin 684148 :robust-end 741625 :level 1 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684093 :ID \"podcasts\" :title \"Podcasts\" :mode nil :granularity element :cached t :parent (org-data ...)))))"
 The real element is: "(headline (:raw-value \"My Podcast Recommendations\" :begin 684150 :end 691219 :pre-blank 1 :contents-begin 684181 :contents-end 691218 :robust-begin 684183 :robust-end 691216 :level 2 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684150 :title \"My Podcast Recommendations\" :mode nil :granularity element :parent (headline (:raw-value \"Podcasts\" :begin 684093 :end 740615 :pre-blank 0 :contents-begin 684104 :contents-end 740614 :robust-begin 684148 :robust-end 740612 :level 1 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684093 :ID \"podcasts\" :title \"Podcasts\"))))"
 Cache around :begin:
nil
nil
nil Disable showing Disable logging

Warning (org-element-cache): org-element--cache: (org-agenda) Cached element is incorrect in Media.org. (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 \"Stefan's Podcast List 1\" :begin 684191 :end 692232 :pre-blank 1 :contents-begin 684220 :contents-end 692231 :robust-begin 684222 :robust-end 692229 :level 3 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684191 :title \"Stefan's Podcast List 1\" :mode nil :granularity element :cached t :parent (headline (:raw-value \"My Podcast Recommendations\" :begin 684150 :end 692232 :pre-blank 1 :contents-begin 684181 :contents-end 692231 :robust-begin 684183 :robust-end 692229 :level 2 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684150 :title \"My Podcast Recommendations\" :mode nil :granularity element :cached t :parent (headline ...)))))"
 The real element is: "(headline (:raw-value \"Stefan's Podcast List 1\" :begin 684191 :end 691219 :pre-blank 1 :contents-begin 684220 :contents-end 691218 :robust-begin 684222 :robust-end 691216 :level 3 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684191 :title \"Stefan's Podcast List 1\" :mode nil :granularity element :parent (headline (:raw-value \"My Podcast Recommendations\" :begin 684150 :end 691219 :pre-blank 1 :contents-begin 684181 :contents-end 691218 :robust-begin 684183 :robust-end 691216 :level 2 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684150 :title \"My Podcast Recommendations\"))))"
 Cache around :begin:
nil
nil
nil

-- end quote --

Here are the headings in question:
https://gist.githubusercontent.com/stefan2904/7aa63b9c14cdb5ad954984f2b65eed95/raw/1ef7ed57b4d81f88fc3108df3fb4cbdf8ee9828f/excerpt%2520of%2520Media.org



Here is the relevant part from the backtrace:

-- quote --

  org-element-cache diagnostics(Media.org): Added new element with nil key: "(section (:begin 684220 :end 684271 :contents-begin 684220 :contents-end 684270 :robust-begin 684220 :robust-end 684268 :post-blank 1 :post-affiliated 684220 :mode section :granularity element))"

  org-element-cache diagnostics(Media.org): Added new element with nil key: "(headline (:raw-value \"Stefan's Podcast List 1\" :begin 684191 :end 692232 :pre-blank 1 :contents-begin 684220 :contents-end 692231 :robust-begin 684222 :robust-end 692229 :level 3 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684191 :title \"Stefan's Podcast List 1\" :mode nil :granularity element))"

  org-element-cache diagnostics(Media.org): Added new element with nil key: "(section (:begin 684181 :end 684191 :contents-begin 684181 :contents-end 684190 :robust-begin 684181 :robust-end 684188 :post-blank 1 :post-affiliated 684181 :mode section :granularity element))"

  org-element-cache diagnostics(Media.org): Added new element with nil key: "(headline (:raw-value \"My Podcast Recommendations\" :begin 684150 :end 692232 :pre-blank 1 :contents-begin 684181 :contents-end 692231 :robust-begin 684183 :robust-end 692229 :level 2 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684150 :title \"My Podcast Recommendations\" :mode nil :granularity element))"

  org-element-cache diagnostics(Media.org): Added new element with nil key: "(section (:begin 684104 :end 684150 :contents-begin 684104 :contents-end 684149 :robust-begin 684104 :robust-end 684147 :post-blank 1 :post-affiliated 684104 :mode section :granularity element))"

  org-element-cache diagnostics(Media.org): Added new element with nil key: "(headline (:raw-value \"Podcasts\" :begin 684093 :end 741628 :pre-blank 0 :contents-begin 684104 :contents-end 741627 :robust-begin 684148 :robust-end 741625 :level 1 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684093 :ID \"podcasts\" :title \"Podcasts\" :mode nil :granularity element))"

-- end quote --



Maybe related:
For the last heading (one of the sub headings inside "Podcasts") I get " Cached element has wrong parent" warning:

--- quote ---

Warning (org-element-cache): org-element--cache: Warning(Media.org): Cached element has wrong parent in Media.org. 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 \"Ö1 doublecheck downloaden\" :begin 691219 :end 691753 :pre-blank 0 :contents-begin 691261 :contents-end 691752 :robust-begin 691469 :robust-end 691750 :level 2 :priority nil :tags (#(\"habit\" 0 5 (fontified nil isearch-open-invisible-temporary org-fold-core--isearch-show-temporary isearch-open-invisible org-fold-core--isearch-show org-fold--spec-org-fold-outline--1228103939896017750 org-fold-outline))) :todo-keyword #(\"TODO\" 0 4 (org-fold--spec-org-fold-outline--1228103939896017750 org-fold-outline isearch-open-invisible org-fold-core--isearch-show isearch-open-invisible-temporary org-fold-core--isearch-show-temporary fontified nil)) :todo-type todo :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 691219 :scheduled (timestamp (:type active :raw-value \"<2023-01-04 Wed ++1m>\" :year-start 2023 :month-start 1 :day-start 4 :hour-start nil :minute-start nil :year-end 2023 :month-end 1 :day-end 4 :hour-end nil :minute-end nil :begin 691275 :end 691296 :post-blank 0 :repeater-type catch-up :repeater-value 1 :repeater-unit month)) :CREATED \"[2022-10-05 Wed 12:48]\" :STYLE \"habit\" :ID \"9ee202d6-ea62-412c-8d3f-eef4b810ce85\" :LAST_REPEAT \"[2022-12-04 Sun 04:37]\" :title \"Ö1 doublecheck downloaden\" :mode nil ...))"
 The parent is: "(headline (:raw-value \"Stefan's Podcast List 1\" :begin 684191 :end 692232 :pre-blank 1 :contents-begin 684220 :contents-end 692231 :robust-begin 684222 :robust-end 692229 :level 3 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684191 :title \"Stefan's Podcast List 1\" :mode nil :granularity element :cached t :parent (headline (:raw-value \"My Podcast Recommendations\" :begin 684150 :end 692232 :pre-blank 1 :contents-begin 684181 :contents-end 692231 :robust-begin 684183 :robust-end 692229 :level 2 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684150 :title \"My Podcast Recommendations\" :mode nil :granularity element :cached t :parent (headline ...)))))"
 The real parent is: "(headline (:raw-value \"Podcasts\" :begin 684093 :end 740615 :pre-blank 0 :contents-begin 684104 :contents-end 740614 :robust-begin 684148 :robust-end 740612 :level 1 :priority nil :tags nil :todo-keyword nil :todo-type nil :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 684093 :ID \"podcasts\" :title (#(\"Podcasts\" 0 8 (:parent #0))) :mode nil :granularity nil))"


Backtrace:
  org-element-cache diagnostics(Media.org): Added new element with nil key: "(headline (:raw-value \"Ö1 doublecheck downloaden\" :begin 691219 :end 691753 :pre-blank 0 :contents-begin 691261 :contents-end 691752 :robust-begin 691469 :robust-end 691750 :level 2 :priority nil :tags (#(\"habit\" 0 5 (fontified nil isearch-open-invisible-temporary org-fold-core--isearch-show-temporary isearch-open-invisible org-fold-core--isearch-show org-fold--spec-org-fold-outline--1228103939896017750 org-fold-outline))) :todo-keyword #(\"TODO\" 0 4 (org-fold--spec-org-fold-outline--1228103939896017750 org-fold-outline isearch-open-invisible org-fold-core--isearch-show isearch-open-invisible-temporary org-fold-core--isearch-show-temporary fontified nil)) :todo-type todo :post-blank 1 :footnote-section-p nil :archivedp nil :commentedp nil :post-affiliated 691219 :scheduled (timestamp (:type active :raw-value \"<2023-01-04 Wed ++1m>\" :year-start 2023 :month-start 1 :day-start 4 :hour-start nil :minute-start nil :year-end 2023 :month-end 1 :day-end 4 :hour-end nil :minute-end nil :begin 691275 :end 691296 :post-blank 0 :repeater-type catch-up :repeater-value 1 :repeater-unit month)) :CREATED \"[2022-10-05 Wed 12:48]\" :STYLE \"habit\" :ID \"9ee202d6-ea62-412c-8d3f-eef4b810ce85\" :LAST_REPEAT \"[2022-12-04 Sun 04:37]\" :title \"Ö1 doublecheck downloaden\" :mode nil ...))"
--- end quote ---


Emacs  : GNU Emacs 28.1 (build 1, x86_64-pc-linux-gnu, GTK+ Version 3.24.33, cairo version 1.16.0)
 of 2022-05-31
Package: Org mode version 9.6 (release_9.6-90-gf49ee9 @ /home/stefan/.emacs.d/contrib/org-mode/lisp/)



Best,
 Stefan

Re: [BUG] org-element--cache: (org-agenda) Cached element is incorrect [9.6 (release_9.6-90-gf49ee9 @ /home/stefan/.emacs.d/contrib/org-mode/lisp/)]

[Ihor Radchenko]

Stefan <org@stefan.failing.systems> writes:

> While trying to reproduce the "Org parser error" error issue (see other thread), I got multiple "Cached element is incorrect" warnings (backtrace excerpt below).
>
> Here is one that appeared when trying to loading the =t= agenda:

Thanks, but a small portion of the backtrace is not helpful here.
"Cached element is incorrect" appears to be related to some buffer edits
being missed by the cache, which can only be visible by looking at the
full history of registered cache edits.

There is a reason why this much backtrace is generated. The real problem
often appears long time before the actual issue is caught by
self-verification code.

-- 
Ihor Radchenko // yantar92,
Org mode contributor,
Learn more about Org mode at <https://orgmode.org/>.
Support Org development at <https://liberapay.com/org-mode>,
or support my work at <https://liberapay.com/yantar92>

Re: [BUG] org-element--cache: (org-agenda) Cached element is incorrect [9.6 (release_9.6-90-gf49ee9 @ /home/stefan/.emacs.d/contrib/org-mode/lisp/)]

[Stefan]

Hello,

sorry, I was not aware of that. I am sending the full backtrace unredacted to you directly. 

The respective org files are in a git repo, and there I don't see any edits in the files since starting emacs (also not after manually saving all org buffers).

Let me know if you need anything else.

Best,
 Stefan


On Thu, Dec 15, 2022, at 09:14, Ihor Radchenko wrote:
> Thanks, but a small portion of the backtrace is not helpful here.
> "Cached element is incorrect" appears to be related to some buffer edits
> being missed by the cache, which can only be visible by looking at the
> full history of registered cache edits.
>
> There is a reason why this much backtrace is generated. The real problem
> often appears long time before the actual issue is caught by
> self-verification code.

Re: [BUG] org-element--cache: (org-agenda) Cached element is incorrect [9.6 (release_9.6-90-gf49ee9 @ /home/stefan/.emacs.d/contrib/org-mode/lisp/)]

[Ihor Radchenko]

Stefan <org@stefan.failing.systems> writes:

> sorry, I was not aware of that. I am sending the full backtrace unredacted to you directly. 
>
> The respective org files are in a git repo, and there I don't see any edits in the files since starting emacs (also not after manually saving all org buffers).
>
> Let me know if you need anything else.

Thanks!

This still looks quite strange.

Can you please:

1. Check the value of `org-element--cache-change-tic' right after
   opening an Org file and the values of `after-change-functions' and
   `after-change-functions' in Org buffer after you see the warning.

2. If you can, try to load Emacs with minimal Org-related settings.
   Then, try to load agenda and let me know if you see the warning.

   It looks to me like you have something unusual in your Org setup or
   some third-party package interfering.

-- 
Ihor Radchenko // yantar92,
Org mode contributor,
Learn more about Org mode at <https://orgmode.org/>.
Support Org development at <https://liberapay.com/org-mode>,
or support my work at <https://liberapay.com/yantar92>

Re: [BUG] org-element--cache: (org-agenda) Cached element is incorrect [9.6 (release_9.6-90-gf49ee9 @ /home/stefan/.emacs.d/contrib/org-mode/lisp/)]

[Stefan]

Hi,

On Thu, Dec 15, 2022, at 13:16, Ihor Radchenko wrote:
> 1. Check the value of `org-element--cache-change-tic' right after
>    opening an Org file 

first its 1, 

(when I start fresh and add 1 byte to the buffer the value is 13955)

> and the values of `after-change-functions' and
>    `after-change-functions' in Org buffer after you see the warning.

after starting the =t= agenda (which results in the warnings):

the value of org-element--cache-change-tic is still 1,

the value of after-change-functions is
`(org-element--cache-after-change jit-lock-after-change flyspell-after-change-function org-fold-core--fix-folded-region t ws-butler-after-change)`

(I disabled `ws-butler` because that sounded suspicious, but that did not resolve the warnings)


> 2. If you can, try to load Emacs with minimal Org-related settings.
>    Then, try to load agenda and let me know if you see the warning.

I did some manual bisecting of my config, and I noticed that the warnings in "Media.org" go away when I remove `(org-startup-align-all-tables t)` from my config.  

So I did some more digging, reduced 
my config to just contain `org-startup-align-all-tables` set to t, 
my agendas limited to Media.org, 
and removed most headings from Media.org.

With a minimal Media.org I get a "Org parser error",
see here for sample and backtrace:
https://gist.github.com/stefan2904/5a2b33d42a947f36402b548d9b186b67

(here the parser error turns into an incorrect error when I change the length of the URL ...)


With a very minimal Media.org I get a "Cached element is incorrect",
apparently because the table is not aligned?
see here for sample file and backtrace:
https://gist.github.com/stefan2904/688afdc2ebfeece8e0fa19a24d9ca321

Both errors go away when I set `(org-startup-align-all-tables nil)`.

>    It looks to me like you have something unusual in your Org setup or
>    some third-party package interfering.


Best,
 Stefan

Re: [BUG] org-element--cache: (org-agenda) Cached element is incorrect [9.6 (release_9.6-90-gf49ee9 @ /home/stefan/.emacs.d/contrib/org-mode/lisp/)]

[Ihor Radchenko]

Bastien, I need your comment on the old commit of yours.

Stefan <org@stefan.failing.systems> writes:

>> 2. If you can, try to load Emacs with minimal Org-related settings.
>>    Then, try to load agenda and let me know if you see the warning.
>
> I did some manual bisecting of my config, and I noticed that the warnings in "Media.org" go away when I remove `(org-startup-align-all-tables t)` from my config.  
>
> So I did some more digging, reduced 
> my config to just contain `org-startup-align-all-tables` set to t, 
> my agendas limited to Media.org, 
> and removed most headings from Media.org.

Thanks! It looks like you found the culprit.

`org-startup-align-all-tables' triggers a function that changes buffer
contents (tables) during Org loading. For same reason, this function is
executed with modification hooks being suppressed and cache missing the
edits as a result.

The problematic commit is
https://git.savannah.gnu.org/cgit/emacs/org-mode.git/commit/?id=9c4d403ada376dca771d9c2dadd7e9eebf4d5f7f

The commit seems to be applied around the time when we did some
aggressive optimizations for agenda views. However, I do not see any
email thread relevant to this particular commit.

Bastien, do you remember the rationale behind the linked commit? The
commit message is not particularly informative.

It appears to me that removing `org-unmodified' around table alignment
should be safe, but I may be missing something.

-- 
Ihor Radchenko // yantar92,
Org mode contributor,
Learn more about Org mode at <https://orgmode.org/>.
Support Org development at <https://liberapay.com/org-mode>,
or support my work at <https://liberapay.com/yantar92>

Re: [BUG] org-element--cache: (org-agenda) Cached element is incorrect [9.6 (release_9.6-90-gf49ee9 @ /home/stefan/.emacs.d/contrib/org-mode/lisp/)]

[Ihor Radchenko]

Ihor Radchenko <yantar92@posteo.net> writes:

> Thanks! It looks like you found the culprit.
>
> `org-startup-align-all-tables' triggers a function that changes buffer
> contents (tables) during Org loading. For same reason, this function is
> executed with modification hooks being suppressed and cache missing the
> edits as a result.
>
> The problematic commit is
> https://git.savannah.gnu.org/cgit/emacs/org-mode.git/commit/?id=9c4d403ada376dca771d9c2dadd7e9eebf4d5f7f

I now moved table alignment code out of `org-unmodified'.
Fixed.
https://git.savannah.gnu.org/cgit/emacs/org-mode.git/commit/?id=1cd39c9e3

-- 
Ihor Radchenko // yantar92,
Org mode contributor,
Learn more about Org mode at <https://orgmode.org/>.
Support Org development at <https://liberapay.com/org-mode>,
or support my work at <https://liberapay.com/yantar92>