View Issue Details
| ID | Project | Category | View Status | Date Submitted | Last Update |
|---|---|---|---|---|---|
| 0005872 | SOGo | ActiveSync | public | 2023-09-20 12:09 | 2026-10-26 22:25 |
| Reporter | SilvanNagl | Assigned To | qhivert | ||
| Priority | normal | Severity | minor | Reproducibility | always |
| Status | assigned | Resolution | open | ||
| Product Version | 5.8.4 | ||||
| Summary | 0005872: high cpu load and some looping behavior of apple devices connecting to sogo / mailcow | ||||
| Description | |||||
| Steps To Reproduce | Connect some Apple devices to mailcow. | ||||
| Tags | No tags attached. | ||||
|
|
|
|
For months this problem now eats our resources. |
|
|
Hello,
|
|
|
Yes, the bug is identically to mentioned comment. |
|
|
Any news? |
|
|
I really would appreciate some collaboration. If there is anything I can provide to speed up the debug process please tell. https://github.com/mailcow/mailcow-dockerized/issues/5045#issuecomment-1615833182 |
|
|
Hello,
|
|
|
For privacy reasons I can not give you the full log but like already mentioned the logs are as follow:
follwed by the xml content with private data. Than it repeats again with the line "Error processing log message". |
|
|
This repeats probably as fast as the TLS handshake can get. |
|
|
The information needed can be seen in |
|
|
Any news? |
|
|
Hello, |
|
|
Maybe it helps to find out what request is hammering the server... check logs for fast repeating requests: Maybe you can identify a specific DeviceId= and Cmd= causing the load. Then it might help to see the some examples of the payload of such repeating requests: |
|
|
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: May 28 11:31:59 fadc6a0236ba sogod [63]: <0x0x5560b2b0d430[SOGoActiveSyncDispatcher]> EAS - request for device XXX: <?xml version="1.0"?> No response this request just comes over and over. POST /Microsoft-Server-ActiveSync?User=XXX@XXX.com&DeviceId=XXX&DeviceType=iPhone&Cmd=Sync HTTP/2.0" 200 0 "-" "Apple-iPhone16C1/2105.236 This spams over and over again. |
|
|
maild on apple phone says: "Folder item sync task 0x500988280 is using key (null) for folder mail%2FShared" This aligns to the above error message. |
|
|
Still reproducible on SOGo 5.12.12 (mailcow-dockerized 2026-10, image ghcr.io/mailcow/sogo:5.12.12-1), iOS ActiveSync (Apple-iPhone Mail, EAS via /Microsoft-Server-ActiveSync). Setup: users have full access (ACL) to a shared mailbox exposed by Dovecot's shared namespace (prefix "Shared/%u/", subscriptions=no, list=children). In the EAS folder list the device sees the virtual parent "Shared" and "Shared/<shared-mailbox>" plus its four real subfolders. Symptom: affected iPhones send Cmd=Sync at 0000082:0000050-170 requests/min per device (no Ping), each answered HTTP 200 with an empty body. With EASDebug enabled, 0000113:0000100% of these requests are initial syncs for the two non-selectable parents only:
SOGo never returns a new SyncKey or a Status for them, so the client retries every ~0.4 s. The real folders (Inbox, Sent, subfolders of the shared mailbox, etc.) sync normally with advancing SyncKeys. nginx access log excerpt (placeholders):
(repeated ~100x per minute). The iOS-side message matches the original report: "using key (null) for folder mail%2FShared". What we checked: Hypothesis (NOT confirmed): in ActiveSync/SOGoActiveSyncDispatcher+Sync.m, processSyncCollection, when no folderMetadata exists for a folder the code asks for FolderSync (Status 12), except for roots of shared mailboxes (SOGoMailNamespace), where it returns without writing anything ("We skip root-folders for shared mailboxes", from the change for 0003460). That would yield exactly a 200 response with no <Collection>, SyncKey or Status. We did not see the log line "no folderMetadata found" in our debug output, so this may be a different code path, and "Shared/<shared-mailbox>" is a SOGoMailFolder rather than a namespace root, so it may not be the same branch. Suggestion: either do not advertise these non-selectable virtual parents in FolderSync, or answer their initial Sync with a valid empty Collection (SyncKey 1, Status 1) so clients stop retrying. Happy to provide more debug output (sanitized) if useful. |
|
|
Still reproducible on SOGo 5.12.12 (mailcow-dockerized 2026-10, image ghcr.io/mailcow/sogo:5.12.12-1), iOS ActiveSync (Apple-iPhone Mail, EAS via /Microsoft-Server-ActiveSync). ENVIRONMENT SOGo 5.12.12, mailcow-dockerized 2026-10, Dovecot as IMAP server. Users have full access (ACL) to a shared mailbox exposed by Dovecot's shared namespace (prefix "Shared/%u/", subscriptions=no, list=children). In the EAS folder list the device sees the virtual parent "Shared" and "Shared/<shared-mailbox>" plus its four real subfolders. Clients: iPhone (native Mail, EAS). SYMPTOM Affected iPhones send Cmd=Sync at 0000082:0000050-170 requests/min per device (no Ping), each answered HTTP 200 with an empty body. With EASDebug enabled, 0000113:0000100% of these requests are initial syncs for the two non-selectable parents only:
SOGo never returns a new SyncKey or a Status for them, so the client retries every ~0.4 s. The real folders (Inbox, Sent, subfolders of the shared mailbox, etc.) sync normally with advancing SyncKeys. nginx access log excerpt (placeholders):
(repeated ~100x per minute). The iOS-side message matches the original report: "using key (null) for folder mail%2FShared". WHAT WE CHECKED "sogo-tool manage-eas listfolders <user> <device>" lists both "Shared" and "Shared/<shared-mailbox>" (and the subfolders) for the affected device. The loop is network/device dependent (not all devices of the same user loop at the same time) and a SOGo restart pauses it temporarily. Removing the share stops it, which is not an option for us. We did not see the debug line "EAS - processSyncCollection: no folderMetadata found" for these requests. ANALYSIS (source read: tag SOGo-5.12.12, line numbers refer to that tag) CONFIRMED from reading the source (not from a runtime trace):
HYPOTHESIS (not confirmed at runtime): For the Dovecot shared-namespace parents ("Shared", "Shared/<shared-mailbox>", LIST flags \NonExistent/\Noselect), the IMAP STATUS fails, -exists returns NO, collectionFromId: returns nil and processSyncCollection takes branch (a) above. This fits our observations: no "no folderMetadata found" log line (that line is only reached when collection != nil, i.e. it is not branch (b)) and an empty HTTP 200 for SyncKey 0. We have not verified the IMAP STATUS result or the branch taken with a debugger/extra logging; if the SOPE hierarchy cache happens to report these folders as existing, the flow would be different (collection != nil, folderMetadata present from FolderSync) and this patch would not apply to that case. Please correct us if the flow is not what we describe. Note that the earlier hypothesis about the SOGoMailNamespace branch ("We skip root-folders...") alone does not explain "Shared/<shared-mailbox>", because that one is looked up as a SOGoMailFolder, not a SOGoMailNamespace (SOGoMailAccount.m -lookupName:inContext:acquire: only returns SOGoMailNamespace for the namespace prefixes reported by IMAP NAMESPACE); branch (a) covers both. PROPOSED FIX Smallest change we could think of: when the collection cannot be opened but the folder is currently listed by -imapFolderGUIDs (i.e. FolderSync advertises it), answer the initial Sync (SyncKey 0) with a valid, empty <Collection> (Class Email, SyncKey 1, CollectionId, Status 1, no commands) and set *changeDetected so the response is actually written. All other cases keep the previous behaviour (stale/deleted folders that are not in the current listing still return silently, so the "next folderSync will do the cleanup" logic and the Outlook behaviour are untouched). The patch is against tag SOGo-5.12.12:
The same file is attached as sogo-bug5872-proposed.patch (git apply, -p1 from the source root). VALIDATION What was done: the diff was generated against a fresh checkout of tag SOGo-5.12.12 and "git apply --check" on a clean tree succeeds. The relevant functions were read in full. RISKS / ALTERNATIVES
WORKAROUND None that is acceptable for us so far. Removing the share stops the loop, and restarting SOGo only pauses it temporarily. Happy to provide more debug output (sanitized) or to test a build with the patch if someone can point us to the preferred way for the mailcow image. |
|
| Date Modified | Username | Field | Change |
|---|---|---|---|
| 2023-09-20 12:09 | SilvanNagl | New Issue | |
| 2023-09-28 07:13 | SilvanNagl | Note Added: 0017317 | |
| 2023-09-28 07:13 | SilvanNagl | File Added: 2023-09-28-091318_grim.png | |
| 2023-09-28 07:49 | SilvanNagl | Note Added: 0017318 | |
| 2023-09-28 10:00 | qhivert | Note Added: 0017320 | |
| 2023-09-28 10:00 | qhivert | Assigned To | => qhivert |
| 2023-09-28 10:00 | qhivert | Status | new => feedback |
| 2023-10-25 12:50 | SilvanNagl | Note Added: 0017400 | |
| 2023-10-25 12:50 | SilvanNagl | Status | feedback => assigned |
| 2023-12-07 11:26 | SilvanNagl | Note Added: 0017491 | |
| 2023-12-15 09:17 | SilvanNagl | Note Added: 0017504 | |
| 2023-12-15 09:54 | qhivert | Note Added: 0017505 | |
| 2023-12-15 09:55 | qhivert | Status | assigned => feedback |
| 2024-01-09 16:12 | SilvanNagl | Note Added: 0017530 | |
| 2024-01-09 16:12 | SilvanNagl | Status | feedback => assigned |
| 2024-01-09 16:13 | SilvanNagl | Note Added: 0017531 | |
| 2024-02-14 11:02 | SilvanNagl | Note Added: 0017587 | |
| 2024-04-18 13:40 | SilvanNagl | Note Added: 0017711 | |
| 2024-04-29 12:26 | qhivert | Note Added: 0017717 | |
| 2024-04-30 19:09 | tfu | Note Added: 0017720 | |
| 2024-05-28 09:38 | SilvanNagl | Note Added: 0017741 | |
| 2024-10-17 14:18 | SilvanNagl | Note Added: 0017916 | |
| 2026-10-26 17:06 | jorgeavlobo | Note Added: 0018594 | |
| 2026-10-26 22:25 | jorgeavlobo | Note Added: 0018595 |