March 2025 - dovecot - dovecot.org

Re: 2.4 crashing on macOS with time moving forward?
by John Muccigrosso 04 Mar '25

04 Mar '25

OK, still crashed overnight while the laptop was closed. Here's the log. I had shut the laptop a bit before this first entry: Mar 03 00:43:13 master: Warning: Time moved forward by 4451.650853 seconds - adjusting timeouts. Mar 03 02:33:57 master: Panic: file ./time-util.h: line 40 (timeval_add_usecs): assertion failed: (usecs >= 0) Mar 03 02:33:57 master: Error: Raw backtrace: 0 libdovecot.0.dylib 0x0000000102d8f120 backtrace_append + 72 -> 1 libdovecot.0.dylib 0x0000000102d8f264 backtrace_get + 44 -> 2 libdovecot.0.dylib 0x0000000102d9dd54 default_fatal_finish + 72 -> 3 libdovecot.0.dylib 0x0000000102d9c7c4 default_error_handler + 0 -> 4 libdovecot.0.dylib 0x0000000102d9c790 fatal_handler_real + 0 -> 5 dovecot 0x0000000102ab3538 master_fatal_callback + 248 -> 6 libdovecot.0.dylib 0x0000000102d9c940 i_fatal + 0 -> 7 libdovecot.0.dylib 0x0000000102db6724 ioloop_iolist_add + 0 -> 8 libdovecot.0.dylib 0x0000000102db4a3c io_loop_handle_timeouts + 640 -> 9 libdovecot.0.dylib 0x0000000102db7438 io_loop_handler_run_internal + 392 -> 10 libdovecot.0.dylib 0x0000000102db5130 io_loop_handler_run + 224 -> 11 libdovecot.0.dylib 0x0000000102db5000 io_loop_run + 92 -> 12 libdovecot.0.dylib 0x0000000102d0e22c master_service_run + 28 -> 13 dovecot 0x0000000102ab2e28 main + 2952 -> 14 dyld 0x0000000187c9ffd8 start + 2412 Mar 03 02:33:57 log(451): Warning: Killed with signal 15 (by pid=1 uid=0 code=unknown 0) .There were a number of "Time moved forward" entries earlier as well. The one here was isolated, but often they occur in pairs with nearly identical amounts of time, differing only by the fractions of a second between them, I suppose. For example (pairs highlighted with the same color): Mar 04 13:12:38 master: Warning: Time moved forward by 9.347642 seconds - adjusting timeouts. Mar 04 13:14:31 imap(12422): Warning: Time moved forward 83.410157 seconds Mar 04 13:14:31 imap(12420): Warning: Time moved forward 83.410166 seconds Mar 04 13:19:44 imap(12422): Warning: Time moved forward 282.970564 seconds Mar 04 13:19:44 imap(12420): Warning: Time moved forward 282.970608 seconds Mar 04 13:19:44 master: Warning: Time moved forward by 366.378919 seconds - adjusting timeouts. Mar 04 13:25:27 imap(12422): Warning: Time moved forward 282.941775 seconds Mar 04 13:25:27 imap(12420): Warning: Time moved forward 282.943614 seconds Mar 04 13:25:27 master: Warning: Time moved forward by 282.937627 seconds - adjusting timeouts. Mar 04 13:30:20 imap(12422): Warning: Time moved forward 263.355743 seconds Mar 04 13:30:20 imap(12420): Warning: Time moved forward 263.350968 seconds Now that I look, I realize that most, but not all, of the imap warnings (vs master) come in pairs. J > On Mar 2, 2025, at 18:18, J wrote: > > OK, done. Will restart. Here's the new pmset info: > > System-wide power settings: > SleepDisabled 0 > Currently in use: > standby 1 > Sleep On Power Button 1 > hibernatefile /var/vm/sleepimage > powernap 1 > networkoversleep 0 > disksleep 10 > sleep 1 (sleep prevented by useractivityd, powerd, sharingd) > hibernatemode 3 > ttyskeepawake 1 > displaysleep 20 > tcpkeepalive 1 > lowpowermode 0 > womp 0 > > J > >> On Mar 2, 2025, at 16:44, Aki Tuomi via dovecot <dovecot(a)dovecot.org> wrote: >> >> Hi! >> >> Can you try disabling "low power mode" and see if that makes any difference? I don't have a mac, but try to go System Settings > Battery, select the drop-down menu next to Low Power Mode, and choose Never? >> >> Aki >> >>> On 02/03/2025 17:30 EET J wrote: >>> >>> >>> Below are the results of "pmset -g". >>> >>> Keep in mind that this >>> >>> >>> J >>> >>> >>>> On Mar 2, 2025, at 15:51, Aki Tuomi via dovecot <dovecot(a)dovecot.org> wrote: >>>> >>>> >>>> I wonder if this is some power saving feature that pauses dovecot processes? Do >>>> you have power saving enabled? >>> >>> >>> >>> System-wide power settings: >>> SleepDisabled0 >>> Currently in use: >>> standby 1 >>> Sleep On Power Button 1 >>> hibernatefile /var/vm/sleepimage >>> powernap 1 >>> networkoversleep 0 >>> disksleep 10 >>> sleep 1 (sleep prevented by powerd) >>> hibernatemode 3 >>> ttyskeepawake 1 >>> displaysleep 20 >>> tcpkeepalive 1 >>> lowpowermode 1 >>> womp 0 >> >> _______________________________________________ >> dovecot mailing list -- dovecot(a)dovecot.org >> To unsubscribe send an email to dovecot-leave(a)dovecot.org >

1 0

Re: 2.4 crashing on macOS with time moving forward?
by John Muccigrosso 03 Mar '25

03 Mar '25

OK, first here's a series of warnings while the laptop was closed, 18:43-19:04: Mar 02 18:44:02 imap(1392): Warning: Time moved forward 24.925040 seconds Mar 02 18:44:02 imap(1397): Warning: Time moved forward 24.925062 seconds Mar 02 19:01:24 imap(1397): Warning: Time moved forward 993.009103 seconds Mar 02 19:01:24 imap(1392): Warning: Time moved forward 993.023098 seconds Mar 02 19:04:57 imap(1397): Warning: Time moved forward 182.863245 seconds Mar 02 19:04:57 imap(1392): Warning: Time moved forward 182.871467 seconds But it took until overnight, when the laptop was again closed, for the crash: Mar 03 00:43:13 master: Warning: Time moved forward by 4451.650853 seconds - adjusting timeouts. Mar 03 02:33:57 master: Panic: file ./time-util.h: line 40 (timeval_add_usecs): assertion failed: (usecs >= 0) Mar 03 02:33:57 master: Error: Raw backtrace: 0 libdovecot.0.dylib 0x0000000102d8f120 backtrace_append + 72 -> 1 libdovecot.0.dylib 0x0000000102d8f264 backtrace_get + 44 -> 2 libdovecot.0.dylib 0x0000000102d9dd54 default_fatal_finish + 72 -> 3 libdovecot.0.dylib 0x0000000102d9c7c4 default_error_handler + 0 -> 4 libdovecot.0.dylib 0x0000000102d9c790 fatal_handler_real + 0 -> 5 dovecot 0x0000000102ab3538 master_fatal_callback + 248 -> 6 libdovecot.0.dylib 0x0000000102d9c940 i_fatal + 0 -> 7 libdovecot.0.dylib 0x0000000102db6724 ioloop_iolist_add + 0 -> 8 libdovecot.0.dylib 0x0000000102db4a3c io_loop_handle_timeouts + 640 -> 9 libdovecot.0.dylib 0x0000000102db7438 io_loop_handler_run_internal + 392 -> 10 libdovecot.0.dylib 0x0000000102db5130 io_loop_handler_run + 224 -> 11 libdovecot.0.dylib 0x0000000102db5000 io_loop_run + 92 -> 12 libdovecot.0.dylib 0x0000000102d0e22c master_service_run + 28 -> 13 dovecot 0x0000000102ab2e28 main + 2952 -> 14 dyld 0x0000000187c9ffd8 start + 2412 Mar 03 02:33:57 log(451): Warning: Killed with signal 15 (by pid=1 uid=0 code=unknown 0) A couple of observations: 1. There are often two warnings within a second, for time periods that are nearly, but not quite identical. 2. The time periods in question are long, minutes or tens of minutes. J > On Mar 2, 2025, at 18:18, J wrote: > > OK, done. Will restart. Here's the new pmset info: > > System-wide power settings: > SleepDisabled 0 > Currently in use: > standby 1 > Sleep On Power Button 1 > hibernatefile /var/vm/sleepimage > powernap 1 > networkoversleep 0 > disksleep 10 > sleep 1 (sleep prevented by useractivityd, powerd, sharingd) > hibernatemode 3 > ttyskeepawake 1 > displaysleep 20 > tcpkeepalive 1 > lowpowermode 0 > womp 0 > > J > >> On Mar 2, 2025, at 16:44, Aki Tuomi via dovecot <dovecot(a)dovecot.org> wrote: >> >> Hi! >> >> Can you try disabling "low power mode" and see if that makes any difference? I don't have a mac, but try to go System Settings > Battery, select the drop-down menu next to Low Power Mode, and choose Never? >> >> Aki >> >>> On 02/03/2025 17:30 EET J wrote: >>> >>> >>> Below are the results of "pmset -g". >>> >>> Keep in mind that this >>> >>> >>> J >>> >>> >>>> On Mar 2, 2025, at 15:51, Aki Tuomi via dovecot <dovecot(a)dovecot.org> wrote: >>>> >>>> >>>> I wonder if this is some power saving feature that pauses dovecot processes? Do >>>> you have power saving enabled? >>> >>> >>> >>> System-wide power settings: >>> SleepDisabled0 >>> Currently in use: >>> standby 1 >>> Sleep On Power Button 1 >>> hibernatefile /var/vm/sleepimage >>> powernap 1 >>> networkoversleep 0 >>> disksleep 10 >>> sleep 1 (sleep prevented by powerd) >>> hibernatemode 3 >>> ttyskeepawake 1 >>> displaysleep 20 >>> tcpkeepalive 1 >>> lowpowermode 1 >>> womp 0 >> >> _______________________________________________ >> dovecot mailing list -- dovecot(a)dovecot.org >> To unsubscribe send an email to dovecot-leave(a)dovecot.org > OK, first here's a series of warnings while the laptop was closed, 18:43-19:04: Mar 02 18:44:02 imap(1392): Warning: Time moved forward 24.925040 seconds Mar 02 18:44:02 imap(1397): Warning: Time moved forward 24.925062 seconds Mar 02 19:01:24 imap(1397): Warning: Time moved forward 993.009103 seconds Mar 02 19:01:24 imap(1392): Warning: Time moved forward 993.023098 seconds Mar 02 19:04:57 imap(1397): Warning: Time moved forward 182.863245 seconds Mar 02 19:04:57 imap(1392): Warning: Time moved forward 182.871467 seconds But it took until overnight, when the laptop was again closed, for the crash: Mar 03 00:43:13 master: Warning: Time moved forward by 4451.650853 seconds - adjusting timeouts. Mar 03 02:33:57 master: Panic: file ./time-util.h: line 40 (timeval_add_usecs): assertion failed: (usecs >= 0) Mar 03 02:33:57 master: Error: Raw backtrace: 0 libdovecot.0.dylib 0x0000000102d8f120 backtrace_append + 72 -> 1 libdovecot.0.dylib 0x0000000102d8f264 backtrace_get + 44 -> 2 libdovecot.0.dylib 0x0000000102d9dd54 default_fatal_finish + 72 -> 3 libdovecot.0.dylib 0x0000000102d9c7c4 default_error_handler + 0 -> 4 libdovecot.0.dylib 0x0000000102d9c790 fatal_handler_real + 0 -> 5 dovecot 0x0000000102ab3538 master_fatal_callback + 248 -> 6 libdovecot.0.dylib 0x0000000102d9c940 i_fatal + 0 -> 7 libdovecot.0.dylib 0x0000000102db6724 ioloop_iolist_add + 0 -> 8 libdovecot.0.dylib 0x0000000102db4a3c io_loop_handle_timeouts + 640 -> 9 libdovecot.0.dylib 0x0000000102db7438 io_loop_handler_run_internal + 392 -> 10 libdovecot.0.dylib 0x0000000102db5130 io_loop_handler_run + 224 -> 11 libdovecot.0.dylib 0x0000000102db5000 io_loop_run + 92 -> 12 libdovecot.0.dylib 0x0000000102d0e22c master_service_run + 28 -> 13 dovecot 0x0000000102ab2e28 main + 2952 -> 14 dyld 0x0000000187c9ffd8 start + 2412 Mar 03 02:33:57 log(451): Warning: Killed with signal 15 (by pid=1 uid=0 code=unknown 0) A couple of observations: 1. There are often two warnings within a second, for time periods that are nearly, but not quite identical. 2. The time periods in question are long, minutes or tens of minutes. J On Mar 2, 2025, at 18:18, J wrote: OK, done. Will restart. Here's the new pmset info: System-wide power settings: SleepDisabled 0 Currently in use: standby 1 Sleep On Power Button 1 hibernatefile /var/vm/sleepimage powernap 1 networkoversleep 0 disksleep 10 sleep 1 (sleep prevented by useractivityd, powerd, sharingd) hibernatemode 3 ttyskeepawake 1 displaysleep 20 tcpkeepalive 1 lowpowermode 0 womp 0 J On Mar 2, 2025, at 16:44, Aki Tuomi via dovecot <dovecot(a)dovecot.org> wrote: Hi! Can you try disabling "low power mode" and see if that makes any difference? I don't have a mac, but try to go System Settings > Battery, select the drop-down menu next to Low Power Mode, and choose Never? Aki On 02/03/2025 17:30 EET J wrote: Below are the results of "pmset -g". Keep in mind that this J On Mar 2, 2025, at 15:51, Aki Tuomi via dovecot <dovecot(a)dovecot.org> wrote: I wonder if this is some power saving feature that pauses dovecot processes? Do you have power saving enabled? System-wide power settings: SleepDisabled0 Currently in use: standby 1 Sleep On Power Button 1 hibernatefile /var/vm/sleepimage powernap 1 networkoversleep 0 disksleep 10 sleep 1 (sleep prevented by powerd) hibernatemode 3 ttyskeepawake 1 displaysleep 20 tcpkeepalive 1 lowpowermode 1 womp 0 _______________________________________________ dovecot mailing list -- dovecot(a)dovecot.org To unsubscribe send an email to dovecot-leave(a)dovecot.org

1 0

Re: 2.4 crashing on macOS with time moving forward?
by Aki Tuomi 02 Mar '25

02 Mar '25

Hi! Can you try disabling "low power mode" and see if that makes any difference? I don't have a mac, but try to go System Settings > Battery, select the drop-down menu next to Low Power Mode, and choose Never? Aki > On 02/03/2025 17:30 EET John Muccigrosso <muccigrosso(a)icloud.com> wrote: > > > Below are the results of "pmset -g". > > Keep in mind that this > > > J > > > > On Mar 2, 2025, at 15:51, Aki Tuomi via dovecot <dovecot(a)dovecot.org> wrote: > > > > > > I wonder if this is some power saving feature that pauses dovecot processes? Do > > you have power saving enabled? > > > > System-wide power settings: > SleepDisabled0 > Currently in use: > standby 1 > Sleep On Power Button 1 > hibernatefile /var/vm/sleepimage > powernap 1 > networkoversleep 0 > disksleep 10 > sleep 1 (sleep prevented by powerd) > hibernatemode 3 > ttyskeepawake 1 > displaysleep 20 > tcpkeepalive 1 > lowpowermode 1 > womp 0

1 0

2.4 crashing on macOS with time moving forward?
by John Muccigrosso 02 Mar '25

02 Mar '25

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

3 8