Wondering if there's anyone who can help with this, which is still happening. Yesterday's crash in the logs:
Feb 26 15:55:07 imap(82011): Panic: file ./time-util.h: line 40 (timeval_add_usecs): assertion failed: (usecs >= 0)
Thanks.
J
On Feb 15, 2025, at 11:18, John Muccigrosso <muccigrosso@icloud.com>
wrote:
Thanks.
It happens in various scenarios, including when I'm actively working on the computer (or it's at least not sleeping). It also happens overnight when the computer should be sleeping. It doesn't seem to happen on resuming.
For example, here's this morning's (or late last night's) when the laptop was closed and sleeping:
Feb 14 22:58:02 master: Warning: Time moved forward by 282.937462
seconds - adjusting timeouts.
Feb 15 00:05:28 master: Panic: file ./time-util.h: line 40
(timeval_add_usecs): assertion failed: (usecs >= 0)
Feb 15 00:05:28 master: Error: Raw backtrace: 0 libdovecot.0.dylib
0x00000001009bb120 backtrace_append + 72 -> 1
libdovecot.0.dylib 0x00000001009bb264 backtrace_get
+ 44 -> 2 libdovecot.0.dylib 0x00000001009c9d54
default_fatal_finish + 72 -> 3 libdovecot.0.dylib
0x00000001009c87c4 default_error_handler + 0 -> 4
libdovecot.0.dylib 0x00000001009c8790
fatal_handler_real + 0 -> 5 dovecot
0x00000001006df538 master_fatal_callback + 248 -> 6
libdovecot.0.dylib 0x00000001009c8940 i_fatal + 0 -
> 7 libdovecot.0.dylib 0x00000001009e2724
ioloop_iolist_add + 0 -> 8 libdovecot.0.dylib
0x00000001009e0a3c io_loop_handle_timeouts + 640 -> 9
libdovecot.0.dylib 0x00000001009e3438
io_loop_handler_run_internal + 392 -> 10 libdovecot.0.dylib
0x00000001009e1130 io_loop_handler_run + 224 -> 11
libdovecot.0.dylib 0x00000001009e1000 io_loop_run +
92 -> 12 libdovecot.0.dylib 0x000000010093a22c
master_service_run + 28 -> 13 dovecot
0x00000001006dee28 main + 2952 -> 14 dyld
0x00000001a4747fd8 start + 2412
Feb 15 00:05:28 log(73755): Warning: Killed with signal 15 (by pid=1
uid=0 code=unknown 0)Crash log below.
J
On Feb 15, 2025, at 10:32, Aki Tuomi <aki.tuomi@open-xchange.com>
wrote:Does this occur when resuming from suspend/hibernate? Also, we do read this
list, it just sometimes takes time to react.
Aki
On 15/02/2025 11:13 EET J via dovecot <dovecot@dovecot.org> wrote:
As this continues to happen and the list seems uninterested, how
exactly should I report this bug?
Thanks.
J
On Feb 11, 2025, at 12:18, J wrote:
Further info: this whole "time moved forward" thing had a
long discussion and eventual fix in 2.3:
https://forums.freebsd.org/threads/dovecot-time-moved-
forwards.82886/page-2
For the record, how my clock compares with a standard:
sntp time.euro.apple.com
+0.109836 +/- 0.031550 time.euro.apple.com
17.253.14.251
So, first there seems to be a bug in this somewhere since
dovecot is clearly getting wrong time info. Then this also
seems related to dovecot eventually crashing on me.
J
On Feb 10, 2025, at 11:15, J wrote:
After last week's struggle with the new version
and my conf file, I got everything working. Now
however dovecot crashes on me every few hours.
The logs show a bunch of this kind of warning,
which I find mention of on the internets:
Feb 07 15:13:47 imap(58317): Warning:
Time moved forward 48.803640 seconds
Feb 07 16:30:27 master: Warning: Time
moved forward by 694.039203 seconds -
adjusting timeouts.
Feb 07 16:52:47 imap(61246): Warning:
Time moved forward 293.443011 seconds
Feb 07 16:52:47 master: Warning: Time
moved forward by 1279.423507 seconds -
adjusting timeouts.
Feb 07 17:25:39 imap(61286): Warning:
Time moved forward 1942.575589 seconds
Feb 07 17:25:39 imap(61288): Warning:
Time moved forward 172.563346 seconds
Feb 07 17:25:39 master: Warning: Time
moved forward by 1912.666999 seconds -
adjusting timeouts.
Feb 07 17:49:32 imap(61286): Warning:
Time moved forward 1402.761862 seconds
Feb 07 17:51:13 master: Warning: Time
moved forward by 1473.582569 seconds -
adjusting timeouts.
Feb 07 17:51:13 imap(61286): Warning:
Time moved forward 70.823888 seconds
Feb 07 17:53:07 master: Warning: Time
moved forward by 53.843767 seconds -
adjusting timeouts.
Feb 07 18:44:22 imap(61286): Warning:
Time moved forward 1386.259444 seconds
Feb 07 19:11:41 master: Warning: Time
moved forward by 615.609964 seconds -
adjusting timeouts.
Note the very large jump dovecot claims is
happening in all of these, up to half an hour,
with a minimum of 48 seconds in this bunch. You
can see that it even does a pair of these in
rapid succession, like at 17:25:39 above, and
will do >10 within the space of an hour.
These seem eventually to be followed by a crash
("eventually" because I'm running this on my
laptop which isn't always open and running). The
crash log entries all start with something like
this:
Feb 07 16:17:53 imap(58315): Panic:
file ./time-util.h: line 40
(timeval_add_usecs): assertion failed:
(usecs >= 0)
The reports will end with one of these:
Feb 06 17:45:07 log(48089): Warning:
Killed with signal 15 (by pid=1 uid=0
code=unknown 0)
Feb 07 16:17:53 imap(58317): Fatal:
master: service(imap): child 58317
killed with signal 6 (core dumps
disabled - https://dovecot.org/
bugreport.html#coredumps)
One more detail, I usually do sudo brew services start dovecot to run dovecot and this results in
the crashes. When I was testing this on Saturday,
I started it with sudo dovecot -F instead, so
that I would see problems in the terminal. It
went all day without crashing and I finally
stopped and restarted it with the brew method.
That's not a rigorous test, but it is suggestive.
Happy to provide more info, but I'm hoping this
is sufficient to suggest a course of action.
dovecot 2.4.0 installed via homebrew
macOS 13.6.9
J