View Issue Details

IDProjectCategoryView StatusLast Update
0003035SOGoActiveSyncpublic2014-12-19 19:22
ReporterSigurd Holter Assigned Toludovic  
PrioritynormalSeveritymajorReproducibilityalways
Status resolvedResolutionno change required 
Platform[Server] LinuxOSRHEL/CentOSOS Version7
Product Version2.2.12a 
Summary0003035: SOGo hangs after "Change detected"
Description

After sorting for 8 minutes, SOGo hangs with 100% CPU usage for at least 35 minutes (and counting) after "Change detected, we push the content".
Client is Outlook 2013 which stays at "Waiting for server".
All machines on the same local network and in production.
Mailbox is large.
There is 4GB RAM free when this happens, no other CPU-hogging processes, enough disk space left etc.

TagsNo tags attached.

Activities

ludovic

ludovic

2014-12-19 18:31

administrator   ~0007894

Attach to the process using gdb and check where it hangs.

Sigurd Holter

Sigurd Holter

2014-12-19 18:41

reporter   ~0007895

#0 0x00007fc6cf103c28 in XML_GetBuffer () from /usr/lib64/libexpat.so.1
0000001 0x00007fc6cf103dfe in XML_Parse () from /usr/lib64/libexpat.so.1
0000002 0x00007fc6cf341758 in wbxml_tree_from_xml () from /usr/lib64/libwbxml2.so.1
0000003 0x00007fc6cf3384bc in wbxml_conv_xml2wbxml_run () from /usr/lib64/libwbxml2.so.1
0000004 0x00007fc6cf5757e3 in -[NSData(ActiveSync) xml2wbxml] (self=0x7fc6e3c52ff0, _cmd=0x7fc6cf7a6e10 <_OBJC_SELECTOR_TABLE+1712>) at NSData+ActiveSync.m:128
0000005 0x00007fc6cf58d3df in -[SOGoActiveSyncDispatcher(Sync) processSync:inResponse:] (self=0x7fc6e3ba45e0, _cmd=0x7fc6e40f4960, theDocumentElement=0x7fc6e40939e0, theResponse=0x7fc6e3f8be90)
at SOGoActiveSyncDispatcher+Sync.m:1393
0000006 0x00007fc6cf5878e0 in -[SOGoActiveSyncDispatcher dispatchRequest:inResponse:context:] (self=0x7fc6e3ba45e0, _cmd=0x7fc6cfbe3480 <_OBJC_SELECTOR_TABLE+96>, theRequest=0x7fc6e409caa0,
theResponse=0x7fc6e3f8be90, theContext=0x7fc6e40d4090) at SOGoActiveSyncDispatcher.m:2505
0000007 0x00007fc6cf9dca7b in -[SOGoMicrosoftActiveSyncActions microsoftServerActiveSyncAction] (self=0x7fc6e3c04980, _cmd=0x7fc6e40f4980) at SOGoMicrosoftActiveSyncActions.m:55
0000008 0x00007fc6e225f714 in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000009 0x00007fc6e225ae38 in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000010 0x00007fc6e225ce09 in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000011 0x00007fc6e21f7850 in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000012 0x00007fc6e21c11e8 in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000013 0x00007fc6e355297d in -[SOGo dispatchRequest:] (self=0x7fc6e3b3d3c0, _cmd=0x7fc6e256a660, _request=0x7fc6e409caa0) at SOGo.m:453
0000014 0x00007fc6e224dafd in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000015 0x00007fc6e224f1c7 in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000016 0x00007fc6e224a2a0 in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000017 0x00007fc6e224b092 in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000018 0x00007fc6e224b40a in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000019 0x00007fc6e224a5f8 in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000020 0x00007fc6e09ef51f in -[NSNotificationCenter _postAndRelease:] (self=0x7fc6e38d2af0, _cmd=<optimized out>, notification=0x7fc6e424c0d0) at NSNotificationCenter.m:1191
0000021 0x00007fc6e0aebe9a in -[GSRunLoopCtxt pollUntil:within:] (self=<optimized out>, _cmd=0x7fc6e0ec6420 <_OBJC_SELECTOR_TABLE+1216>, milliseconds=<optimized out>, contexts=<optimized out>)
at GSRunLoopCtxt.m:642
0000022 0x00007fc6e0a369f0 in -[NSRunLoop acceptInputForMode:beforeDate:] (self=0x7fc6e3bef620, _cmd=0x7fc6e0ec6460 <_OBJC_SELECTOR_TABLE+1280>, mode=0x7fc6e0ec7230 <_OBJC_INSTANCE_2>, limit_date=<optimized out>)
at NSRunLoop.m:1214
0000023 0x00007fc6e0a36e69 in -[NSRunLoop runMode:beforeDate:] (self=0x7fc6e3bef620, _cmd=0x7fc6e24d4dc0, mode=0x7fc6e0ec7230 <_OBJC_INSTANCE_2>, date=0x7fc6e3b6b730) at NSRunLoop.m:1275
0000024 0x00007fc6e21c253e in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000025 0x00007fc6e3552092 in -[SOGo run] (self=0x7fc6e3b3d3c0, _cmd=0x7fc6e2511d00) at SOGo.m:277
0000026 0x00007fc6e21fff1b in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000027 0x00007fc6e21fedce in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000028 0x00007fc6e2200632 in ?? () from /usr/lib64/libNGObjWeb.so.4.9
0000029 0x00007fc6e2200b97 in WOWatchDogApplicationMain () from /usr/lib64/libNGObjWeb.so.4.9
0000030 0x00007fc6e35513c1 in main (argc=7, argv=0x7fff01375b88, env=0x7fff01375bc8) at sogod.m:53

Sigurd Holter

Sigurd Holter

2014-12-19 18:42

reporter   ~0007896

This is for a new process, which only has been going for 1-2 minutes after "Change detected ..."

ludovic

ludovic

2014-12-19 18:43

administrator   ~0007897

Do again after more mitnutes.

As you can see, nothing we can do, it's converting the response from XML to WBXML right now.

Reduce the window size for the sync process, it'll make the response smaller.

Sigurd Holter

Sigurd Holter

2014-12-19 18:44

reporter   ~0007898

SOGoMaximumSyncWindowSize = 50 is what I have now.

Shall I post a new backtrace in 15 minutes or so ?

ludovic

ludovic

2014-12-19 18:45

administrator   ~0007899

Sure.

If you got 50, and 50 folders, that can generate 2500 messages. If each message averages 1 MB for example, that's 2.5GB of data to convert.

Sigurd Holter

Sigurd Holter

2014-12-19 18:54

reporter   ~0007900

Stuck at the same place, it seems. I'll kill the process and set SOGoMaximumSyncWindowSize = 10 and then try again.

Sigurd Holter

Sigurd Holter

2014-12-19 19:17

reporter   ~0007901

Ok, some data comes through now.

So how should we interpret SOGoMaximumSyncWindowSize - is it the number of mails returned per folder, and the number of folders is potentially all folders in the mailbox structure ?

Or does this number also limit the number of folders that are synced ?

ludovic

ludovic

2014-12-19 19:18

administrator   ~0007902

Per folder. Where folder == a mail folder, a calendar or an address book.

Sigurd Holter

Sigurd Holter

2014-12-19 19:21

reporter   ~0007903

Ok, thanks, that makes it more clear here how SOGo/EAS behaves.
I'll let Outlook download mails over the weekend and see what happens.

Issue History

Date Modified Username Field Change
2014-12-19 18:29 Sigurd Holter New Issue
2014-12-19 18:31 ludovic Note Added: 0007894
2014-12-19 18:41 Sigurd Holter Note Added: 0007895
2014-12-19 18:42 Sigurd Holter Note Added: 0007896
2014-12-19 18:43 ludovic Note Added: 0007897
2014-12-19 18:44 Sigurd Holter Note Added: 0007898
2014-12-19 18:45 ludovic Note Added: 0007899
2014-12-19 18:54 Sigurd Holter Note Added: 0007900
2014-12-19 19:17 Sigurd Holter Note Added: 0007901
2014-12-19 19:18 ludovic Note Added: 0007902
2014-12-19 19:21 Sigurd Holter Note Added: 0007903
2014-12-19 19:22 ludovic Status new => resolved
2014-12-19 19:22 ludovic Resolution open => no change required
2014-12-19 19:22 ludovic Assigned To => ludovic