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 <mailto: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 dovecotto run dovecot and this results in the crashes. When I was testing this on Saturday, I started it withsudo dovecot -Finstead, 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
dovecot mailing list -- dovecot@dovecot.org <mailto:dovecot@dovecot.org> To unsubscribe send an email to dovecot-leave@dovecot.org <mailto:dovecot-leave@dovecot.org>
Translated Report (Full Report Below)
Process: dovecot [73750] Path: /opt/homebrew/*/dovecot Identifier: dovecot Version: ??? Code Type: ARM-64 (Native) Parent Process: launchd [1] User ID: 0
Date/Time: 2025-02-15 00:05:28.3917 +0100 OS Version: macOS 13.6.9 (22G830) Report Version: 12 Anonymous UUID: 29B23C20-57B1-887B-2EE7-7DCE47D4DF79
Sleep/Wake UUID: 5FB9AF1F-E715-4B9E-B04D-DBDF5D0CF7A3
Time Awake Since Boot: 430000 seconds Time Since Wake: 16 seconds
System Integrity Protection: enabled
Crashed Thread: 0 Dispatch queue: com.apple.main-thread
Exception Type: EXC_CRASH (SIGABRT) Exception Codes: 0x0000000000000000, 0x0000000000000000
Termination Reason: Namespace SIGNAL, Code 6 Abort trap: 6 Terminating Process: dovecot [73750]
Application Specific Information: abort() called
Thread 0 Crashed:: Dispatch queue: com.apple.main-thread 0 libsystem_kernel.dylib 0x1a4a68704 __pthread_kill + 8 1 libsystem_pthread.dylib 0x1a4a9fc28 pthread_kill + 288 2 libsystem_c.dylib 0x1a49adae8 abort + 180 3 libdovecot.0.dylib 0x1009c9db4 default_fatal_finish + 168 4 libdovecot.0.dylib 0x1009c87c4 fatal_handler_real + 52 5 libdovecot.0.dylib 0x1009c8790 default_fatal_handler + 40 6 dovecot 0x1006df538 master_fatal_callback + 248 7 libdovecot.0.dylib 0x1009c8940 i_panic + 80 8 libdovecot.0.dylib 0x1009e2724 io_loops_timeouts_update + 396 9 libdovecot.0.dylib 0x1009e0a3c io_loop_handle_timeouts + 640 10 libdovecot.0.dylib 0x1009e3438 io_loop_handler_run_internal + 392 11 libdovecot.0.dylib 0x1009e1130 io_loop_handler_run + 224 12 libdovecot.0.dylib 0x1009e1000 io_loop_run + 92 13 libdovecot.0.dylib 0x10093a22c master_service_run + 28 14 dovecot 0x1006dee28 main + 2952 15 dyld 0x1a4747fd8 start + 2412
Thread 0 crashed with ARM Thread State (64-bit): x0: 0x0000000000000000 x1: 0x0000000000000000 x2: 0x0000000000000000 x3: 0x0000000000000000 x4: 0xfffffffffffff23a x5: 0x000000000000000a x6: 0x0000000000000020 x7: 0x0000000000000b00 x8: 0x5c36c162b2174aa8 x9: 0x5c36c160b208aba8 x10: 0x00000000000069d8 x11: 0x0000000000000003 x12: 0x00000000000004ed x13: 0x00000b0100000bc0 x14: 0x00000c0100000c80 x15: 0x0000000000000054 x16: 0x0000000000000148 x17: 0x0000000204d5ec60 x18: 0x0000000000000000 x19: 0x0000000000000006 x20: 0x00000002001fe100 x21: 0x0000000000000103 x22: 0x00000002001fe1e0 x23: 0x00000000000f423f x24: 0x0000000012656a5e x25: 0x0000000000000134 x26: 0x000000000009b55e x27: 0x0000000000000f92 x28: 0x0000000000050d22 fp: 0x000000016f723160 lr: 0x00000001a4a9fc28 sp: 0x000000016f723140 pc: 0x00000001a4a68704 cpsr: 0x40001000 far: 0x0000000000000000 esr: 0x56000080 Address size fault
Binary Images: 0x1006dc000 - 0x1006ebfff dovecot (*) <89fbcf7d-4107-30e9-81dd-37e7d3a2480e> /opt/homebrew/*/dovecot 0x1008fc000 - 0x100a53fff libdovecot.0.dylib (*) <6e9c4759-86b7-3ad4-9d8f-f0a98f795cb8> /opt/homebrew/*/libdovecot.0.dylib 0x1a4a5f000 - 0x1a4a98ff7 libsystem_kernel.dylib (*) <826ec6d5-d1b5-3c71-8b4a-f52782b01a7f> /usr/lib/system/libsystem_kernel.dylib 0x1a4a99000 - 0x1a4aa5fff libsystem_pthread.dylib (*) <7acb080f-eabe-3a59-8d9f-7459f33bb263> /usr/lib/system/libsystem_pthread.dylib 0x1a4937000 - 0x1a49b5ff7 libsystem_c.dylib (*) <840fe68c-8175-347b-bfb1-3b6bce431935> /usr/lib/system/libsystem_c.dylib 0x1a4742000 - 0x1a47d0d13 dyld (*) <79b0cd10-fb62-30ef-9aeb-87e4a596b006> /usr/lib/dyld
External Modification Summary: Calls made by other processes targeting this process: task_for_pid: 0 thread_create: 0 thread_set_state: 0 Calls made by this process: task_for_pid: 0 thread_create: 0 thread_set_state: 0 Calls made by all processes on this machine: task_for_pid: 0 thread_create: 0 thread_set_state: 0
VM Region Summary: ReadOnly portion of Libraries: Total=811.3M resident=0K(0%) swapped_out_or_unallocated=811.3M(100%) Writable regions: Total=974.6M written=0K(0%) resident=0K(0%) swapped_out=0K(0%) unallocated=974.6M(100%)
VIRTUAL REGION REGION TYPE SIZE COUNT (non-coalesced) =========== ======= ======= Activity Tracing 256K 1 Kernel Alloc Once 32K 1 MALLOC 222.2M 26 MALLOC guard page 96K 5 MALLOC_MEDIUM (reserved) 360.0M 3 reserved VM address space (unallocated) MALLOC_NANO (reserved) 384.0M 1 reserved VM address space (unallocated) STACK GUARD 56.0M 1 Stack 8176K 1 __AUTH 46K 11 __AUTH_CONST 77K 40 __DATA 209K 40 __DATA_CONST 231K 43 __DATA_DIRTY 78K 22 __LINKEDIT 803.8M 3 __OBJC_RO 66.4M 1 __OBJC_RW 2012K 1 __TEXT 7692K 45 dyld private memory 272K 2 mapped file 64K 1 shared memory 32K 2 =========== ======= ======= TOTAL 1.9G 250 TOTAL, minus reserved VM space 1.1G 250
Full Report
{"app_name":"dovecot","timestamp":"2025-02-15 00:05:29.00 +0100","app_version":"","slice_uuid":"89fbcf7d-4107-30e9-81dd-37e7d3a2480e","build_version":"","platform":1,"share_with_app_devs":0,"is_first_party":1,"bug_type":"309","os_version":"macOS 13.6.9 (22G830)","roots_installed":0,"incident_id":"A5A9524D-3FAE-4C97-A7F3-83D9B0B920AA","name":"dovecot"} { "uptime" : 430000, "procRole" : "Unspecified", "version" : 2, "userID" : 0, "deployVersion" : 210, "modelCode" : "Mac14,7", "coalitionID" : 42789, "osVersion" : { "train" : "macOS 13.6.9", "build" : "22G830", "releaseType" : "User" }, "captureTime" : "2025-02-15 00:05:28.3917 +0100", "incident" : "A5A9524D-3FAE-4C97-A7F3-83D9B0B920AA", "pid" : 73750, "translated" : false, "cpuType" : "ARM-64", "roots_installed" : 0, "bug_type" : "309", "procLaunch" : "2025-02-14 09:08:53.4251 +0100", "procStartAbsTime" : 9728718032712, "procExitAbsTime" : 10422691932867, "procName" : "dovecot", "procPath" : "\/opt\/homebrew\/*\/dovecot", "parentProc" : "launchd", "parentPid" : 1, "coalitionName" : "homebrew.mxcl.dovecot", "crashReporterKey" : "29B23C20-57B1-887B-2EE7-7DCE47D4DF79", "codeSigningID" : "dovecot-5555494489fbcf7d410730e981dd37e7d3a2480e", "codeSigningTeamID" : "", "codeSigningFlags" : 570425857, "codeSigningValidationCategory" : 10, "codeSigningTrustLevel" : 0, "wakeTime" : 16, "sleepWakeUUID" : "5FB9AF1F-E715-4B9E-B04D-DBDF5D0CF7A3", "sip" : "enabled", "exception" : {"codes":"0x0000000000000000, 0x0000000000000000","rawCodes":[0,0],"type":"EXC_CRASH","signal":"SIGABRT"}, "termination" : {"flags":0,"code":6,"namespace":"SIGNAL","indicator":"Abort trap: 6","byProc":"dovecot","byPid":73750}, "asi" : {"libsystem_c.dylib":["abort() called"]}, "extMods" : {"caller":{"thread_create":0,"thread_set_state":0,"task_for_pid":0},"system":{"thread_create":0,"thread_set_state":0,"task_for_pid":0},"targeted":{"thread_create":0,"thread_set_state":0,"task_for_pid":0},"warnings":0}, "faultingThread" : 0, "threads" : [{"triggered":true,"id":5990211,"threadState":{"x":[{"value":0},{"value":0},{"value":0},{"value":0},{"value":18446744073709548090},{"value":10},{"value":32},{"value":2816},{"value":6644710929870572200},{"value":6644710921279679400},{"value":27096},{"value":3},{"value":1261},{"value":12098922875840},{"value":13198434503808},{"value":84},{"value":328},{"value":8671063136},{"value":0},{"value":6},{"value":8592023808,"symbolLocation":0,"symbol":"_main_thread"},{"value":259},{"value":8592024032,"symbolLocation":224,"symbol":"_main_thread"},{"value":999999},{"value":308636254},{"value":308},{"value":636254},{"value":3986},{"value":331042}],"flavor":"ARM_THREAD_STATE64","lr":{"value":7057570856},"cpsr":{"value":1073745920},"fp":{"value":6164722016},"sp":{"value":6164721984},"esr":{"value":1442840704,"description":" Address size fault"},"pc":{"value":7057344260,"matchesCrashFrame":1},"far":{"value":0}},"queue":"com.apple.main-thread","frames":[{"imageOffset":38660,"symbol":"__pthread_kill","symbolLocation":8,"imageIndex":2},{"imageOffset":27688,"symbol":"pthread_kill","symbolLocation":288,"imageIndex":3},{"imageOffset":486120,"symbol":"abort","symbolLocation":180,"imageIndex":4},{"imageOffset":843188,"symbol":"default_fatal_finish","symbolLocation":168,"imageIndex":1},{"imageOffset":837572,"symbol":"fatal_handler_real","symbolLocation":52,"imageIndex":1},{"imageOffset":837520,"symbol":"default_fatal_handler","symbolLocation":40,"imageIndex":1},{"imageOffset":13624,"symbol":"master_fatal_callback","symbolLocation":248,"imageIndex":0},{"imageOffset":837952,"symbol":"i_panic","symbolLocation":80,"imageIndex":1},{"imageOffset":943908,"symbol":"io_loops_timeouts_update","symbolLocation":396,"imageIndex":1},{"imageOffset":936508,"symbol":"io_loop_handle_timeouts","symbolLocation":640,"imageIndex":1},{"imageOffset":947256,"symbol":"io_loop_handler_run_internal","symbolLocation":392,"imageIndex":1},{"imageOffset":938288,"symbol":"io_loop_handler_run","symbolLocation":224,"imageIndex":1},{"imageOffset":937984,"symbol":"io_loop_run","symbolLocation":92,"imageIndex":1},{"imageOffset":254508,"symbol":"master_service_run","symbolLocation":28,"imageIndex":1},{"imageOffset":11816,"symbol":"main","symbolLocation":2952,"imageIndex":0},{"imageOffset":24536,"symbol":"start","symbolLocation":2412,"imageIndex":5}]}], "usedImages" : [ { "source" : "P", "arch" : "arm64", "base" : 4302159872, "size" : 65536, "uuid" : "89fbcf7d-4107-30e9-81dd-37e7d3a2480e", "path" : "\/opt\/homebrew\/*\/dovecot", "name" : "dovecot" }, { "source" : "P", "arch" : "arm64", "base" : 4304388096, "size" : 1409024, "uuid" : "6e9c4759-86b7-3ad4-9d8f-f0a98f795cb8", "path" : "\/opt\/homebrew\/*\/libdovecot.0.dylib", "name" : "libdovecot.0.dylib" }, { "source" : "P", "arch" : "arm64e", "base" : 7057305600, "size" : 237560, "uuid" : "826ec6d5-d1b5-3c71-8b4a-f52782b01a7f", "path" : "\/usr\/lib\/system\/libsystem_kernel.dylib", "name" : "libsystem_kernel.dylib" }, { "source" : "P", "arch" : "arm64e", "base" : 7057543168, "size" : 53248, "uuid" : "7acb080f-eabe-3a59-8d9f-7459f33bb263", "path" : "\/usr\/lib\/system\/libsystem_pthread.dylib", "name" : "libsystem_pthread.dylib" }, { "source" : "P", "arch" : "arm64e", "base" : 7056093184, "size" : 520184, "uuid" : "840fe68c-8175-347b-bfb1-3b6bce431935", "path" : "\/usr\/lib\/system\/libsystem_c.dylib", "name" : "libsystem_c.dylib" }, { "source" : "P", "arch" : "arm64e", "base" : 7054041088, "size" : 584980, "uuid" : "79b0cd10-fb62-30ef-9aeb-87e4a596b006", "path" : "\/usr\/lib\/dyld", "name" : "dyld" } ], "sharedCache" : { "base" : 7053377536, "size" : 3586080768, "uuid" : "5b429225-625d-316a-b915-35ab8cd166f8" }, "vmSummary" : "ReadOnly portion of Libraries: Total=811.3M resident=0K(0%) swapped_out_or_unallocated=811.3M(100%)\nWritable regions: Total=974.6M written=0K(0%) resident=0K(0%) swapped_out=0K(0%) unallocated=974.6M(100%)\n\n VIRTUAL REGION \nREGION TYPE SIZE COUNT (non-coalesced) \n=========== ======= ======= \nActivity Tracing 256K 1 \nKernel Alloc Once 32K 1 \nMALLOC 222.2M 26 \nMALLOC guard page 96K 5 \nMALLOC_MEDIUM (reserved) 360.0M 3 reserved VM address space (unallocated)\nMALLOC_NANO (reserved) 384.0M 1 reserved VM address space (unallocated)\nSTACK GUARD 56.0M 1 \nStack 8176K 1 \n__AUTH 46K 11 \n__AUTH_CONST 77K 40 \n__DATA 209K 40 \n__DATA_CONST 231K 43 \n__DATA_DIRTY 78K 22 \n__LINKEDIT 803.8M 3 \n__OBJC_RO 66.4M 1 \n__OBJC_RW 2012K 1 \n__TEXT 7692K 45 \ndyld private memory 272K 2 \nmapped file 64K 1 \nshared memory 32K 2 \n=========== ======= ======= \nTOTAL 1.9G 250 \nTOTAL, minus reserved VM space 1.1G 250 \n", "legacyInfo" : { "threadTriggered" : { "queue" : "com.apple.main-thread" } }, "logWritingSignature" : "cc4bcac5503d3f2204421c18e49285cbf1ca4c0b" }