|
|
The "MimeType" errors keep spewing into the log, until it finally stops with this. Seems Sogo crashes and re-starts.
Jun 06 13:31:51 sogod [1953]: |SOGo| terminating app, vMem size limit (384 MB) has been reached (currently 425 MB)
<data>:1: element div: validity error : ID _originalContent already defined
55, 255);"></div><br><div id="_originalContent" style="background-color: white;"
^
<data>:1: element div: validity error : ID _originalContent already defined
55, 255);"></div><br><div id="_originalContent" style="background-color: white;"
^
<data>:54: element div: validity error : ID _originalContent already defined
ody></table><p class="MsoNormal"><o:p> </o:p></p><div id="_originalContent"
^
<data>:54: element div: validity error : ID _originalContent already defined
Normal" style="background:white"> <o:p></o:p></p><div id="_originalContent"
^
Jun 06 13:31:52 sogod [1826]: <0x0x7fc1052143a8[WOWatchDogChild]> child 1953 exited
Jun 06 13:31:52 sogod [1826]: <0x0x7fc104fe2ce8[WOWatchDog]> child spawned with pid 8330
Jun 06 13:32:56 sogod [8330]: <0x0x7fc10546b288[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Jun 06 13:32:56 sogod [8330]: <0x0x7fc10546b288[SOGoCache]> Using host(s) '127.0.0.1' as server(s)
Jun 06 13:32:57 sogod [8330]: localhost "OPTIONS /SOGo/Microsoft-Server-ActiveSync HTTP/1.0" 200 0/0 0.269 - - 1M
And if this helps, here's the sogo.log from opening and closing Outlook 2013, syncing a very small test mailbox (about half a dozen messages). This small box syncs fine but there are still errors in the log... see below. (I replaced the email address with a bogus one.)
Jun 06 13:36:14 sogod [8330]: localhost "OPTIONS /SOGo/Microsoft-Server-ActiveSync HTTP/1.0" 200 0/0 0.052 - - 80K
Jun 06 13:36:15 sogod [8330]: [WARN] <0x0x7fc10557cdd8[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAVpermissions table
Jun 06 13:36:15 sogod [8330]: [WARN] <0x0x7fc10557cdd8[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table
Jun 06 13:36:15 sogod [8330]: [WARN] <0x0x7fc10557cdd8[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table
Jun 06 13:36:15 sogod [8330]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=FolderSync&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 43/31 0.501 - - 1M
Jun 06 13:36:15 sogod [8330]: <0x0x7fc1055501c8[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:36:16 sogod [8330]: <0x0x7fc1055501c8[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:36:16 sogod [8330]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 0/591 1.667 - - 1M
Jun 06 13:36:17 sogod [8330]: <0x0x7fc10558f788[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:36:18 sogod [8330]: <0x0x7fc10558f788[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:36:18 sogod [8330]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 0/591 1.673 - - 0
Jun 06 13:36:19 sogod [8330]: <0x0x7fc105599108[SOGoActiveSyncDispatcher]> Sleeping 10 seconds while detecting changes...
Jun 06 13:36:29 sogod [8330]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Ping&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 19/334 10.734 - - 0
Jun 06 13:36:30 sogod [8330]: <0x0x7fc1054cfa98[SOGoActiveSyncDispatcher]> Sleeping 10 seconds while detecting changes...
Jun 06 13:36:40 sogod [8330]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Ping&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 13/332 10.730 - - 80K
Jun 06 13:36:40 sogod [8330]: <0x0x7fc105587328[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:36:41 sogod [8330]: <0x0x7fc105587328[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:36:41 sogod [8330]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 0/591 1.662 - - 0
Jun 06 13:36:42 sogod [8330]: <0x0x7fc105501b88[SOGoActiveSyncDispatcher]> Sleeping 10 seconds while detecting changes...
Jun 06 13:36:52 sogod [8330]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Ping&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 13/332 10.734 - - 0
Jun 06 13:36:53 sogod [8330]: <0x0x7fc105300568[SOGoActiveSyncDispatcher]> Sleeping 10 seconds while detecting changes...
Jun 06 13:36:54 sogod [1826]: [ERROR] <0x0x7fc1052143a8[WOWatchDogChild]> FAILURE receiving status for child 8330
Jun 06 13:36:54 sogod [1826]: [ERROR] <0x0x7fc1052143a8[WOWatchDogChild]> socket: <NGActiveSocket[0x0x7fc105249bc8]: mode=rw address=(null) connectedTo=<0x0x7fc105189e08[NGLocalSocketAddress]: /tmp/_ngsocket_0x722_0x7fc104fc7e18_000> receive-timeout=1.000s>
Jun 06 13:36:54 sogod [1826]: [ERROR] <0x0x7fc1052143a8[WOWatchDogChild]> exception: <NGSocketTimedOutException: 0x7fc1051a8a88> NAME:NGSocketTimedOutException REASON:the socket was shutdown INFO:{errno = 11; error = "Resource temporarily unavailable"; stream = "{object = <NGActiveSocket[0x0x7fc105249bc8]: mode=rw address=(null) connectedTo=<0x0x7fc105189e08[NGLocalSocketAddress]: /tmp/_ngsocket_0x722_0x7fc104fc7e18_000> receive-timeout=1.000s>;}"; }
Jun 06 13:36:54 sogod [1826]: <0x0x7fc1052143a8[WOWatchDogChild]> sending terminate signal to pid 8330
Jun 06 13:36:54 sogod [1826]: [ERROR] <0x0x7fc1052143a8[WOWatchDogChild]> FAILURE notifying child 8330
Jun 06 13:36:54 sogod [1826]: <0x0x7fc1052143a8[WOWatchDogChild]> sending terminate signal to pid 8330
Jun 06 13:36:54 sogod [8330]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Ping&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 13/332 2.016 - - 0
Jun 06 13:36:54 sogod [1826]: <0x0x7fc1052143a8[WOWatchDogChild]> child 8330 exited
Jun 06 13:36:54 sogod [1826]: <0x0x7fc104fe2ce8[WOWatchDog]> child spawned with pid 8438
Jun 06 13:36:55 sogod [10057]: <0x0x7fc108e83978[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:36:56 sogod [10057]: <0x0x7fc108e83978[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:36:56 sogod [10057]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 0/591 1.683 - - 2M
Jun 06 13:36:56 sogod [8438]: <0x0x7fc10545f1c8[SOGoCache]> Cache cleanup interval set every 300.000000 seconds
Jun 06 13:36:56 sogod [8438]: <0x0x7fc10545f1c8[SOGoCache]> Using host(s) '127.0.0.1' as server(s)
Jun 06 13:36:56 sogod [8438]: [WARN] <0x0x7fc105580598[SOGoWebDAVAclManager]> entry '{DAV:}write' already exists in DAV permissions table
Jun 06 13:36:56 sogod [8438]: [WARN] <0x0x7fc105580598[SOGoWebDAVAclManager]> entry '{DAV:}write-properties' already exists in DAV permissions table
Jun 06 13:36:56 sogod [8438]: [WARN] <0x0x7fc105580598[SOGoWebDAVAclManager]> entry '{DAV:}write-content' already exists in DAV permissions table
Jun 06 13:36:56 sogod [10057]: <0x0x7fc108dc5aa8[SOGoActiveSyncDispatcher]> Sleeping 10 seconds while detecting changes...
Jun 06 13:36:57 sogod [8438]: <0x0x7fc105527318[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:36:57 sogod [8438]: <0x0x7fc105527318[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:36:57 sogod [8438]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 0/591 1.693 - - 4M
Jun 06 13:37:06 sogod [10057]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Ping&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 13/332 10.736 - - 0
Jun 06 13:37:07 sogod [10057]: <0x0x7fc108981888[SOGoActiveSyncDispatcher]> Sleeping 10 seconds while detecting changes...
Jun 06 13:37:07 sogod [8438]: <0x0x7fc105503b38[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:37:08 sogod [8438]: <0x0x7fc105503b38[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:37:08 sogod [8438]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 0/591 1.663 - - 0
Jun 06 13:37:17 sogod [10057]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Ping&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 13/332 10.650 - - 0
Jun 06 13:37:18 sogod [10057]: <0x0x7fc108d83618[SOGoActiveSyncDispatcher]> Sleeping 10 seconds while detecting changes...
Jun 06 13:37:18 sogod [8438]: <0x0x7fc105504048[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:37:19 sogod [8438]: <0x0x7fc105504048[NGImap4Client]> Note: no key found for sorting, using 'DATE': (null)
Jun 06 13:37:19 sogod [8438]: [ERROR] <0x0x7fc10547e038[WOHttpTransaction]> client disconnected during delivery of response for <WORequest[0x0x7fc1054516e8]: method=POST uri=/SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 app=SOGo rqKey=Microsoft-Server-ActiveSync rqPath=(null)> (len=0): the socket was shutdown
Jun 06 13:37:19 sogod [8438]: localhost "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=user@example.com&DeviceId=C5954A34F7B64919A8ADB0969575BCAB&DeviceType=WindowsOutlook15 HTTP/1.0" 200 0/591 1.666 - - 0 |
|
|
|
Reproduced today with another fresh install on Ubuntu Server 14.04. Selected Apache instead of Nginx, just for "anyhow." Precisely the same behavior -- Outlook 2013 can not sync large mail folders. Same kinds of error messages. Repro yourself and get the logs you need. |
|
|
|
I myself discovered same problem, when I had duplicate emails in folders. For example same message was in inbox folder and in folder called "inbox_backup". Outlook downloaded first 5 messages and then same behaviour as yours. Deleted the backup folder and then Outlook donwloaded all messages like it should. |
|
|
|
Thanks, Raido. But note that sync works just fine on a BlackBerry 10 smartphone, no problems at all. Very little log activity; just notices of "pushing new content" etc. None of that "filling the log with thousands of lines of errors" thing.
I know there are some duplicate messages, but I sure hope I don't have to find them all. And, this thing doesn't even download ONE message. It just refuses to start downloading at all.
If BB10 can talk to Sogo perfectly fine and Outlook can't... well for one thing maybe BlackBerry got it better than Microsoft! :) but there must be some changes needed in Sogo to handle Outlook better. |
|
|
|
From the logs above, SOGo does NOT crash, it terminates itself (child process) as it should when reaching its memory limit. It does so after sending the response, so it's harmless.
What are the EAS related settings in your sogo.conf file? |
|
|
|
There's this:
WOWorkersCount = 1;
That's all I can find EAS-related, other than the commented-out debug line:
//SOGoEASDebugEnabled = YES; |
|
|
|
Read the documentation:
http://www.sogo.nu/files/docs/SOGo%20Installation%20Guide.pdf
"Microsoft EnterpriseActiveSync Tuning" |
|
|
|
Thanks, but I don't have success even by adding parameters as shown in that section. I am beginning to wonder, does Apache handle Activesync better than Nginx? Or are there nginx settings I should be aware of? The docs are helpful with apache reverse proxying but totally silent on nginx... |
|
|
|
You could try to recreate the eas profile in outlook with SOGoMaximumSyncResponseSize=512. |
|
|
|
This landed up being the most successful for us, we still have issues with mailboxes over 3GB.
Your dovecot needs the word size increased to 4096
SOGoMaximumSyncResponseSize= 2048
SOGoMaximumSyncInterval = should be 30 seconds less than the nginx/apache timeout value
SOGoMaximumPingInterval and SOGoInternalSyncInterval need to be identical and less than SOGoMaximumSyncInterval .. ie 60seconds
Try using SOGoMaximumSyncWindowSize of 30
Set the memory limit to 1024mb and make sure your server has enough ram for the woworkercount.. ie ram / 768 = worker count ;-P
The ideal way to use sogo, is to have it completely standalone from the iredmail server.
Currently there are still issues with not all folders syncing.. ie out of 100 folders 20 will be empty.
There is also an issue, appearing in the logs.
Jul 02 22:45:18 sogod [898]: 196.210.12.184 "POST /SOGo/Microsoft-Server-ActiveSync?Cmd=Sync&User=xxx@xxx.com&DeviceId=63B2B7D43DB7493C881133FA01F02A0B&DeviceType=WindowsOutlook15 HTTP/1.1" 200 4120446/13297 42.023 - - 73M
Jul 02 22:45:51 sogod [898]: [ERROR] <0x0x7f36024e0148[WOHttpAdaptor]> http server caught: (null
Not sure if thats caused by nginx, or a buffer not being filled/used via the proxied request. |
|
|
|
Well I have tried replying to this several times. Test, test! can I post??? |
|
|
|
"The ideal way to use sogo, is to have it completely standalone from the iredmail server."
Care to elaborate a bit more what you mean?
Also, by dovecot word size, are you referring to mail_max_keyword_length in 10-mail.conf?
Currently, sogo.conf has this:
WOWatchDogRequestTimeout = 60;
WOWorkersCount = 20;
SOGoMaximumPingInterval = 3540;
SOGoMaximumSyncInterval = 3540;
SOGoInternalSyncInterval = 30;
SOGoMaximumSyncResponseSize = 1024;
SOGoMaximumSyncWindowSize = 512;
Outlook has downloaded hundreds of emails, but hundreds remain to go and it cheerfully reports "All folders are up to date."
I'm also getting a lot of this in sogo.log:
Aug 01 16:41:47 sogod [8771]: [WARN] <0x0x7fa46c68aa18[WOWatchDogChild]> pid 8776 has been hanging in the same request for 7 minutes
Aug 01 16:41:47 sogod [8771]: [WARN] <0x0x7fa46c680868[WOWatchDogChild]> pid 8782 has been hanging in the same request for 6 minutes
Any further suggestions?
Version: 2.3.1-1 |
|
|
|
Just a small update. I changed
SOGoMaximumSyncResponseSize = 1024;
to
SOGoMaximumSyncResponseSize = 4096;
Inspiration to change this param came from this part of the docs:
"Note that if you set the value too low and a mail message or any other object surpasses it, it will still be synced, but only this item will be."
Now that's just a wee bit cryptic. Suppose I have emails with attachments greater than 4MB; am I going to have to bump this setting even higher?
Anyhow, that got Outlook downloading messages again (at least, it seems that's what did it). It's still working at it. I'll leave it open for a couple hours and see what happens. Every once in a while Outlook says All folders are up to date; then after a bit it buckles down and downloads some more. The cycle is, "Waiting for server response... Downloading from server... Updating (folder name)... All folders are up to date... (wait a while) Waiting for server response..." and so on it repeats. But as I said, it seems to be downloading, and sync between sogo and outlook seems to be working nicely.
And the "hanging in same request" error does not seem to be running as wild, for some reason. I've not seen more than 4 minutes yet; before, it ran up to 47 minutes and beyond. |
|
|
|
Well, though this is working better than I've ever seen before I still have some empty folders. And with that being the case, I don't know how reasonably sure I can be that all folders updated completely. Outlook refuses to download more, or else Sogo EAS fails to realize it has not synced them all. |
|
|
|
Just to clarify the settings SOGoMaximumSyncResponseSize and SOGoMaximumSyncWindowSize.
They are used to restrict the size of one single sync response.
This is necessary especially on initial syncs.
Else it would sync e.g. all emails in one folder at once.
With big email folders this would consume all your memory on the server.
You have two settings, because they restrict two different aspects of the sync.
SOGoMaximumSyncWindowSize defines the maximum count of objects send in one response.
So when set to 512 then you will at most get 512 objects in one sync response.
SOGoMaximumSyncResponseSize defines how big one sync response should get at max.
This value is in KiB, so when set to 1024 one sync response should be less than 1 MiB.
What does this mean?
This means if you have 100 emails each 256 KiB big, then it will only sync 4 of these at once, even if SOGoMaximumSyncWindowSize is set to a bigger value!
This is because it will only add additional objects to the response, if this size is not reached yet.
This means also if there is an email bigger than 1 MiB, then it will only sync this one email!
So when you set SOGoMaximumSyncResponseSize to a really low value, you will sync each email on its own, which will take really long on big accounts.
Be aware, if you set it too big, then the watchdog will kill your server process after each sync, because you run over SxVMemLimit which is set to 768 MiB per default. |
|
|
|
Dear Christian, ludovic,
Any update on this issue? We experienced the same issue, it syncs mail folders, but no email. |
|
|
|
After hours of fiddling, I seem to have (accidentally?) discovered settings that work. Here's my current ActiveSync section of sogo.conf:
WOWatchDogRequestTimeout = 10;
SOGoMaximumPingInterval = 354;
SOGoMaximumSyncInterval = 354;
SOGoInternalSyncInterval = 30;
SOGoMaximumSyncResponseSize = 512;
SOGoMaximumSyncWindowSize = 256;
And in nginx.conf:
keepalive_timout 600;
And, /etc/dovecot/conf.d/10-imap.conf:
mail_max_keyword_length = 4096
One more. /etc/dovecot/dovecot.conf:
imap_max_line_length = 4M
This last param in dovecot.conf was added; it was not there to begin with. Just be sure to put it within the {imap} section. In my case, I inserted it right under the "mail_max_user_ip_connections" line. (Note that you still need to be sure you're in the right place, as the {pop} protocol section has an identical line.)
Now, just a word on web server and WOWatchDogRequest timeouts. The Sogo docs recommend setting these to an hour. I tried that, and simply could not get enough Sogo workers to satisfy the Outlook clients. And wow did it hog RAM. We finally gave this mail server 10GB of RAM and experimentally specified more and more workers... I think I got as high as PREFORK = 35 in /etc/default/sogo. It happily filled the RAM in a day or two. And the mail clients kept disconnecting from the server, mails disappeard and reappeared at random from various folders, and so on. Seemingly we were bringing the server to its knees with just two or three activesync clients! The Sogo log indicated "No child available to handle incoming request." With such a small number of ActiveSync clients (the rest IMAP), I thought this was crazy.
After setting files as shown above, the client reports that his Outlook workstations are staying in sync -- and staying connected. He's not seeing the "disconnected from server" error any more. (Thank God I have a very patient client!) Also the server isn't running away with RAM any longer. As I am writing this, I'm watching htop on the server. We're sitting at just a wee bit less than 2GB of RAM used, and 64MB of swap. Still 8GB of RAM free! CPU usage certainly is higher when using ActiveSync; it keeps periodically jumping as high as 12 or 13% on either core, then settling back to near zero. This cycle repeats every couple seconds.
So to summarize. I am not sure why I'm having such good luck with 10 minute timeout rather than 60 minutes as indicated in the official docs. But I'm very happy to finally have a client who has a functional mail server.
@Christian Mack, thanks so much for your very insightful clarification of the Response and Sync params. That was very helpful.
@zhb, give these settings a shot and report back whether or not it works for you. I'd be interested to know how others make out. And any improvements to config are always welcome. |
|
|
|
Please try again with the upcoming nightly builds.
We've added a good amount of optimizations for Outlook which should increase speed and greatly reduce memory usage.
It'll be all part of v2.3.3. |
|
