|
|
|
|
For months this problem now eats our resources.
We would really appreciate to find a solution for this. |
|
|
Hello,
|
|
|
Yes, the bug is identically to mentioned comment.
mailcowdockerized-sogo-mailcow-1 | Oct 25 14:49:47 4991662df76e sogod [57]: <0x0x56383afe8b40[SOGoActiveSyncDispatcher]> EAS - request for device 72T5A34GMH0MP16ASAC83JT8UG: <?xml version="1.0"?>
mailcowdockerized-sogo-mailcow-1 | Oct 25 14:49:47 4991662df76e syslog-ng[11]: Error processing log message: <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "http://www.microsoft.com/">
mailcowdockerized-sogo-mailcow-1 | <Sync xmlns="AirSync:">
mailcowdockerized-sogo-mailcow-1 | <Collections>
mailcowdockerized-sogo-mailcow-1 | <Collection>
mailcowdockerized-sogo-mailcow-1 | <SyncKey>0</SyncKey>
mailcowdockerized-sogo-mailcow-1 | <CollectionId>mail%2FShared</CollectionId> |
|
|
Any news? |
|
|
I really would appreciate some collaboration.
This Problem eats basically 600% CPU on an 8 Core mailcow docker server only because some people connect with their IOS-Devices.
Connecting IOS Devices basically limits down the whole server for everyone causing not only really high power consumption but also killing the user experience.
If there is anything I can provide to speed up the debug process please tell.
If this is not a SoGo bug please also tell.
The mail server runs for months now on maximum load.
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:
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: Jan 9 16:53:11 6454ffe7fa29 syslog-ng[10]: Error processing log message: <Ping xmlns="Ping:">
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Status>1</Status>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Ping>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: /HeartbeatInterval>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Folders>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Folder>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Id>mail%2F349e8a121fa0d4611b200000eb6a2ee8</Id>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Class>Email</Class>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Folder>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Folder>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Id>mail%2F9c212839e01dd76126310000eb6a2ee8</Id>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Class>Email</Class>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Folder>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Folder>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Id>mail%2Fd05fcc211fa0d4611b200000eb6a2ee8</Id>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Class>Email</Class>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Folder>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Folder>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Id>vevent%2Fpersonal</Id>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Class>Calendar</Class>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Folder>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Folders>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Ping>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: s>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Collection>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Collections>
Jan 09 16:53:11 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Sync>
follwed by the xml content with private data. Than it repeats again with the line "Error processing log message".
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: Jan 9 17:05:17 6454ffe7fa29 syslog-ng[10]: Error processing log message: <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "http://www.microsoft.com/">
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Ping xmlns="Ping:">
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Status>1</Status>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Ping>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: ", "mail%2Fdb6b2903b25d7864adf923003b3b2f75")
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: '{DAV:}write-content' already exists in DAV permissions table
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: s>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Folder>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Folder>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Id>mail%2F9c212839e01dd76126310000eb6a2ee8</Id>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Class>Email</Class>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Folder>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Folder>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Id>mail%2Fd05fcc211fa0d4611b200000eb6a2ee8</Id>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Class>Email</Class>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Folder>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Folder>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Id>vevent%2Fpersonal</Id>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: <Class>Calendar</Class>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Folder>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Folders>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Ping>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Options>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Collection>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Collections>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Sync>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Collection>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Collections>
Jan 09 17:05:17 mail-host docker/mailcowdockerized-sogo-mailcow-1[959]: </Sync> |
|
|
This repeats probably as fast as the TLS handshake can get.
Again and again, no more error logs in the debug lvl. |
|
|
The information needed can be seen in
https://github.com/mailcow/mailcow-dockerized/issues/5045#issuecomment-1912275247 |
|
|
Any news? |
|
|
Hello,
We haven't forget about this but our (Alinto's) hands are full for now. |
|
|
Maybe it helps to find out what request is hammering the server... check logs for fast repeating requests:
POST /SOGo/Microsoft-Server-ActiveSync?User=...&DeviceId=....&DeviceType=...&Cmd=... HTTP/1.1" 200
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:
EAS - request for device ...: <?xml
and its
EAS - response for device ....: <?xml |
|
|
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"?>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: May 28 11:31:59 fadc6a0236ba syslog-ng[10]: Error processing log message: <!DOCTYPE ActiveSync PUBLIC "-//MICROSOFT//DTD ActiveSync//EN" "http://www.microsoft.com/">
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <Sync xmlns="AirSync:">
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <Collections>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <Collection>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <SyncKey>0</SyncKey>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <CollectionId>mail%2FShared</CollectionId>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <Options>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <FilterType>5</FilterType>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <MIMETruncation>1</MIMETruncation>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <MIMESupport>0</MIMESupport>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <BodyPreference xmlns="AirSyncBase:">
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <Type>1</Type>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <TruncationSize>500</TruncationSize>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: </BodyPreference>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: </Options>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: </Collection>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: </Collections>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: </Sync>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: <Class>Calendar</Class>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: </Folder>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: </Folders>
May 28 11:31:59 mail-host docker/mailcowdockerized-sogo-mailcow-1[971]: </Ping>
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.
With direct disconnect after it than it connects back again and disconnects directly after it.
Again and again and again and 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. |
|