bug#75209: 30.0.93; Emacs reader failed to read data in "/home/nlj/.cache/org-persist/gc-lock.eld"

[N. Jackson]

At 17:14 +0000 on Friday 2025-04-25, Ihor Radchenko wrote:
>
> "N. Jackson" <njackson@posteo.net> writes:
>
>>>>> -  (let ((write-region-inhibit-fsync t)
>>>>> +  (let ((write-region-inhibit-fsync nil)
>>>>>          ;; We set UTF-8 here and in `org-persist--read-elisp-file'
>>>>>          ;; to avoid the overhead from `find-auto-coding'.
>>>>>          (coding-system-for-write 'emacs-internal)
>>
>> I haven't seen the bug since installing the change quoted above that
>> let binds `write-region-inhibit-fsync' to nil.
>>
>> Unfortunately, however, there is a confounding factor because around
>> the same time as I made this change, I switched from mainly using a
>> very slow desktop system to using a considerably faster laptop.
>
> Hmm. Then, may you go back to no patches at all?
>
> If we find that `write-region-inhibit-fsync' has undesired side
> effects, it will be an important piece of information - its
> default value has been changed in the whole Emacs recently on the
> grounds that fsync makes no difference on modern systems.

Yes, after I made my last post here I built a fresh Emacs 30.1 on
this faster system.  I wanted to see if the bug happens on this
system without any of the patches.

After lunch today I set the system into suspend and on resume this
evening I saw the bug, the same as I was seeing it on my other
system before the patches:

  ⛔ Warning (emacs): Emacs reader failed to read data in
  "/home/nlj/.cache/org-persist/gc-lock.eld". The error was: "End of
  file during parsing"

(This was after my main Emacs session had been up for about 1 day,
8 hours, 16 minutes, 25 seconds.)


FWIW, I still have my advice around org-persist--refresh-gc-lock and
below I report the timings of the timer.  The part of the logs shown
show the last regular firing before suspending and the catch up
firings on resume, one of which caused the warning.

Of the two sessions reported below, in this case it was my normal
Emacs session ("Norm") in which the warning appeared, not the Gnus
session.  (Back when I was seeing the bug fairly often, sometimes
the warning would be in the Gnus session, sometimes in my normal
session, and once it was in both.)

In the Gnus session:

  2025-04-26 14:53:59.424097 Gnus entering org-persist--refresh-gc-lock:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In 3599.9813794 s (26637 14807 405558 759000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil
    2025-04-26 14:53:59.429168 Gnus leaving org-persist--refresh-gc-lock 
normally:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In 3599.976262068 s (26637 14807 405558 759000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil

  2025-04-26 17:16:13.333838 Gnus entering org-persist--refresh-gc-lock:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In -1333.928314059 s (26637 18407 405558 759000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil
    2025-04-26 17:16:13.335319 Gnus leaving org-persist--refresh-gc-lock 
normally:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In -1333.929791253 s (26637 18407 405558 759000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil

  2025-04-26 17:16:13.336025 Gnus entering org-persist--refresh-gc-lock:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In 2266.069505628 s (26637 22007 405558 759000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil
    2025-04-26 17:16:13.514180 Gnus leaving org-persist--refresh-gc-lock 
normally:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In 2265.89133824 s (26637 22007 405558 759000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil

In the normal session:

  2025-04-26 14:03:01.561952 Norm entering org-persist--refresh-gc-lock:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In 3599.998112807 s (26637 11749 560131 555000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil
    2025-04-26 14:03:01.564459 Norm leaving org-persist--refresh-gc-lock 
normally:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In 3599.9956178 s (26637 11749 560131 555000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil

  2025-04-26 17:16:13.443913 Norm entering org-persist--refresh-gc-lock:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In -4391.883804868 s (26637 15349 560131 555000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil
    2025-04-26 17:16:13.561083 Norm leaving org-persist--refresh-gc-lock 
normally:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In -4392.000986789 s (26637 15349 560131 555000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil

  2025-04-26 17:16:13.561702 Norm entering org-persist--refresh-gc-lock:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In -792.001585113 s (26637 18949 560131 555000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil
    2025-04-26 17:16:13.562635 Norm leaving org-persist--refresh-gc-lock 
normally:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In -792.002523338 s (26637 18949 560131 555000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil

  2025-04-26 17:16:13.563119 Norm entering org-persist--refresh-gc-lock:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In 2807.996994882 s (26637 22549 560131 555000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil
    2025-04-26 17:16:15.764233 Norm leaving org-persist--refresh-gc-lock 
normally:
    Timer: org-persist--refresh-gc-lock (nil)
    Due: In 2805.795855986 s (26637 22549 560131 555000)
    Triggered: t                Integral Multiple: nil
    Repeat Delay: 3600  Idle Delay: nil

I must have suspended between about 14:43 and 15:03ish so that on
resume at about 17:16 the normal session had three timers to catch
up but the Gnus session had only two -- so the discrepancy there is
easy to explain.

What I'm surprised by is that all the timers returned normally.
Previously, whenever I've seen the bug and checked this log, there
was a timer that failed to return.  (That is, my "after" advice in
org-persist--refresh-gc-lock failed to run.)

I hope some of this helps.


Going forward, now that it's established that this system _is_
susceptible to the bug (with an unpatched Emacs 30.1), what is the
best test to do next?  Should I restore the atomic write patch or
restore the patch that let binds `write-region-inhibit-fsync' to
nil?

Thanks.