Thanks Daniel for your reply. But I think problem has been now identified.
It seems to be related to a user activesync synchronization via Android 5.1. I asked the user to remove his exchange account on his phone, and no more crazy sogod process running at 100%. If he enables again the synchronization, he can see his mails, but no calendar and sogod process start running at 100% CPU. I don't know if it's connected with https://code.google.com/p/android/issues/detail?id=79389 threads, telling that people with Android 5.1 can see their mails, but not the calendars. Has someone experienced successful calendar synchronizations with SOGo last version and Android 5.1 ? And regarding SOGo developers, is it useful to fill up a bug regarding sogod process looping at 100% CPU ? Thanks for your comments. Regards, Emmanuel Le mardi 05 mai 2015 à 10:20 +0200, "Daniel Müller" a écrit : > So if SOGo behave like that in my environment there is a user which > is misconfigured. Find out that user and delete all settings ex.: > sogo-tool remove username. > And all will be fine again. > > Greetings > Daniel > > > Gesendet: Montag, 04. Mai 2015 um 12:47 Uhr > Von: "Emmanuel d'Humières" <[email protected]> > An: [email protected] > Betreff: [SOGo] 100% CPU sogod > Hi guys, > > first of all, many thanks to SOGo team for this brilliant project. > I used SOGo for several years and I install it for my customers who > are very happy with this exchange alternative ;-) > > Unfortunately, I have recently installed SOGo for one of my customers > and we have a very strange behaviour. > We start SOGo service and after a "random" time (few minutes or few > hours), we observe via top linux command one, then several sogod > processus running at 100% cpu. We see in SOGo log "pid xxxx has been > hanging in the same request for x minutes" > and then watchdog messages : > "safety belt -- sending KILL signal to pid xxxx" > child xxxx exited > (terminated due to signal 9) > child spawned with pid xxxx' > > I know the meaning of previous messages which are finally quite > normal, but in the meantime, 5 or 7 process SOGOd running at the same > time at 100 % seem to be strange. I never encounter this kind of issue > so I started to make some analysis. > > I first check with strace command to see system calls made by SOGOd > process : nothing was displayed except the kill system call made by > the watchdog. So it's 100% "pure" cpu usage. > > I have installed the debug tools in order to provide you some > backtrace. You will find below 2 different backtraces done at 2 > different moments. > They are a little bit different, but the others traces I've made look > similar. > > Please can you help me as I try to push this solution for this > customer ? > There are right now 5 test users and 5 activesync enabled. > > Thanks for your help, especially to indicate me if I need to open a > bug. > > Regards, > > Emmanuel > > ______________________________________________________________________ > > > > Here are 2 backtraces of the 100% sogod process : > > =========================== trace 1 ============================= > #0 0x00007fc8c8e87df1 in _wordcopy_fwd_dest_aligned (dstp=<optimized > out>, srcp=<optimized out>, len=1964944) > at wordcopy.c:207 > #1 0x00007fc8c8e82417 in __memmove_sse2 (dest=0x7fc8ac4bec00, > src=<optimized out>, len=33734901) at ../string/memmove.c:79 > #2 0x00007fc8c9c93dd7 in memmove (__len=<optimized out>, > __src=<optimized out>, __dest=<optimized out>) > at /usr/include/x86_64-linux-gnu/bits/string3.h:57 > #3 fillHole (size=1, index=977904, self=0x7fc8cefc34b8) at > GSString.m:2161 > #4 -[GSMutableString replaceCharactersInRange:withString:] > (self=0x7fc8cefc34b8, _cmd=<optimized out>, aRange=..., > aString=0x7fc8bd7c2620 <_OBJC_INSTANCE_3>) at GSString.m:4998 > #5 0x00007fc8c9e4b019 in -[NSMutableString(GNUstepBase) > replaceString:withString:] (self=0x7fc8cefc34b8, > _cmd=<optimized out>, replace=0x7fc8bd7c2600 <_OBJC_INSTANCE_2>, > by=0x7fc8bd7c2620 <_OBJC_INSTANCE_3>) > at NSMutableString+GNUstepBase.m:300 > #6 0x00007fc8c9e4c036 in -[NSString(GNUstepBase) > stringByReplacingString:withString:] (self=0x7fc8cece46c8, > _cmd=<optimized out>, replace=0x7fc8bd7c2600 <_OBJC_INSTANCE_2>, > by=0x7fc8bd7c2620 <_OBJC_INSTANCE_3>) > at NSString+GNUstepBase.m:216 > #7 0x00007fc8bd5987af in -[NSData(ActiveSync) > activeSyncRepresentationInContext:] (self=0x7fc8ceff7218, > _cmd=0x7fc8bd7ca970 <_OBJC_SELECTOR_TABLE+1648>, > context=0x7fc8ceb1a608) at NSData+ActiveSync.m:60 > #8 0x00007fc8bd5a4eea in -[SOGoActiveSyncDispatcher > processItemOperations:inResponse:] (self=0x7fc8cecf5208, > _cmd=0x7fc8ceac7c00, theDocumentElement=0x7fc8cecc5738, > theResponse=0x7fc8cf04b2b8) at SOGoActiveSyncDispatcher.m:1303 > #9 0x00007fc8bd5ab91a in -[SOGoActiveSyncDispatcher > dispatchRequest:inResponse:context:] (self=0x7fc8cecf5208, > _cmd=0x7fc8be25c8a0 <_OBJC_SELECTOR_TABLE+96>, > theRequest=0x7fc8cea9dfb8, theResponse=0x7fc8cf04b2b8, > theContext=0x7fc8ceb1a608) at SOGoActiveSyncDispatcher.m:2638 > #10 0x00007fc8be055675 in -[SOGoMicrosoftActiveSyncActions > microsoftServerActiveSyncAction] (self=0x7fc8ceccd738, > _cmd=0x7fc8ceac7c40) at SOGoMicrosoftActiveSyncActions.m:57 > #11 0x00007fc8cb5c74d4 in -[SoActionInvocation > callOnObject:withPositionalParametersWhenNotNil:inContext:] () > from /usr/lib/libNGObjWeb.so.4.9 > #12 0x00007fc8cb5c2bf8 in -[SoObjectMethodDispatcher > dispatchInContext:] () from /usr/lib/libNGObjWeb.so.4.9 > #13 0x00007fc8cb5c4bc9 in -[SoObjectRequestHandler > handleRequest:inContext:session:application:] () > ---Type <return> to continue, or q <return> to quit--- > from /usr/lib/libNGObjWeb.so.4.9 > #14 0x00007fc8cb55acde in -[WORequestHandler handleRequest:] > (self=0x7fc8ceaf1308, _cmd=<optimized out>, > _request=0x7fc8cea9dfb8) at WORequestHandler.m:237 > #15 0x00007fc8cb52268c in -[WOCoreApplication > dispatchRequest:usingHandler:] (self=0x7fc8ce9e5048, _cmd=<optimized > out>, > _request=0x7fc8cea9dfb8, handler=0x7fc8ceaf1308) at > WOCoreApplication.m:712 > #16 0x00007fc8cc8d0822 in -[SOGo dispatchRequest:] > (self=0x7fc8ce9e5048, _cmd=0x7fc8cb8cf8b0 <_OBJC_SELECTOR_TABLE+1840>, > _request=0x7fc8cea9dfb8) at SOGo.m:453 > #17 0x00007fc8cb5b596d in -[WOHttpTransaction _run] > (self=0x7fc8ced5b228, _cmd=<optimized out>) at WOHttpTransaction.m:596 > #18 0x00007fc8cb5b6e38 in -[WOHttpTransaction run] > (self=0x7fc8ced5b228, _cmd=<optimized out>) at WOHttpTransaction.m:649 > #19 0x00007fc8cb5b1eda in -[WOHttpAdaptor runConnection:] > (self=0x7fc8cea589d8, _cmd=<optimized out>, _socket=<optimized out>) > at WOHttpAdaptor.m:367 > #20 0x00007fc8cb5b2d16 in -[WOHttpAdaptor _handleAcceptedConnection:] > (self=0x7fc8cea589d8, _cmd=<optimized out>, > _connection=0x7fc8cefbe0e8) at WOHttpAdaptor.m:401 > #21 0x00007fc8cb5b30aa in -[WOHttpAdaptor _handleConnection:] > (self=0x7fc8cea589d8, _cmd=<optimized out>, > connection=0x7fc8cefbe0e8) at WOHttpAdaptor.m:460 > #22 0x00007fc8cb5b2258 in -[WOHttpAdaptor acceptControlMessage:] > (self=0x7fc8cea589d8, _cmd=<optimized out>, > aNotification=<optimized out>) at WOHttpAdaptor.m:499 > #23 0x00007fc8c9d5843d in -[NSNotificationCenter _postAndRelease:] > (self=0x7fc8ce794778, _cmd=<optimized out>, > notification=0x7fc8cea61228) at NSNotificationCenter.m:1223 > #24 0x00007fc8c9e52487 in -[GSRunLoopCtxt pollUntil:within:] > (self=0x7fc8ce904b48, _cmd=<optimized out>, > milliseconds=<optimized out>, contexts=<optimized out>) at > GSRunLoopCtxt.m:632 > #25 0x00007fc8c9d9dd70 in -[NSRunLoop acceptInputForMode:beforeDate:] > (self=0x7fc8ce9c2ba8, _cmd=<optimized out>, > mode=0x7fc8ca21f520 <_OBJC_INSTANCE_2>, limit_date=<optimized > out>) at NSRunLoop.m:1195 > #26 0x00007fc8c9d9cb8c in -[NSRunLoop runMode:beforeDate:] > (self=0x7fc8ce9c2ba8, > _cmd=0x7fc8cb838e30 <_OBJC_SELECTOR_TABLE+1360>, > mode=0x7fc8ca21f520 <_OBJC_INSTANCE_2>, date=0x7fc8ce9bb278) > at NSRunLoop.m:1263 > #27 0x00007fc8cb523a6e in -[WOCoreApplication run] > (self=0x7fc8ce9e5048, _cmd=<optimized out>) at WOCoreApplication.m:584 > ---Type <return> to continue, or q <return> to quit--- > #28 0x00007fc8cc8cff2d in -[SOGo run] (self=0x7fc8ce9e5048, > _cmd=0x7fc8cb876240 <_OBJC_SELECTOR_TABLE+608>) at SOGo.m:277 > #29 0x00007fc8cb5635e4 in -[WOWatchDog _spawnChild:] > (self=0x7fc8ce9ab408, _cmd=<optimized out>, child=0x7fc8ce9b7798) > at WOWatchDogApplicationMain.m:595 > #30 0x00007fc8cb562426 in -[WOWatchDog _ensureChildren] > (self=0x7fc8ce9ab408, _cmd=<optimized out>) > at WOWatchDogApplicationMain.m:685 > #31 0x00007fc8cb563d12 in -[WOWatchDog run:argc:argv:] > (self=0x7fc8ce9ab408, _cmd=<optimized out>, newAppName=<optimized > out>, > newArgC=<optimized out>, newArgV=<optimized out>) at > WOWatchDogApplicationMain.m:936 > #32 0x00007fc8cb56428b in WOWatchDogApplicationMain > (appName=0x7fc8ccad6140 <_OBJC_INSTANCE_0>, argc=7, > argv=0x7fff9d6d02f8) > at WOWatchDogApplicationMain.m:1050 > #33 0x00007fc8cc8cf25e in main (argc=7, argv=0x7fff9d6d02f8, > env=0x7fff9d6d0338) at sogod.m:53 > > > > =========================== trace 2 ============================= > #0 _wordcopy_fwd_dest_aligned (dstp=140663607000616, > srcp=140663607000632, len=4152100) at wordcopy.c:201 > #1 0x00007feee78bb417 in __memmove_sse2 (dest=0x7feecc400100, > src=<optimized out>, len=34526805) at ../string/memmove.c:79 > #2 0x00007feee86ccdd7 in memmove (__len=<optimized out>, > __src=<optimized out>, __dest=<optimized out>) > at /usr/include/x86_64-linux-gnu/bits/string3.h:57 > #3 fillHole (size=1, index=196848, self=0x7feeec4f9cf8) at > GSString.m:2161 > #4 -[GSMutableString replaceCharactersInRange:withString:] > (self=0x7feeec4f9cf8, _cmd=<optimized out>, aRange=..., > aString=0x7feedc1fb620) at GSString.m:4998 > #5 0x00007feee8884019 in -[NSMutableString(GNUstepBase) > replaceString:withString:] (self=0x7feeec4f9cf8, > _cmd=<optimized out>, replace=0x7feedc1fb600, by=0x7feedc1fb620) > at NSMutableString+GNUstepBase.m:300 > #6 0x00007feee8885036 in -[NSString(GNUstepBase) > stringByReplacingString:withString:] (self=0x7feeec4fae48, > _cmd=<optimized out>, replace=0x7feedc1fb600, by=0x7feedc1fb620) > at NSString+GNUstepBase.m:216 > #7 0x00007feedbfd17af in ?? () > from /usr/lib/GNUstep/SOGo/ActiveSync.SOGo/./ActiveSync > #8 0x00007feedbfddeea in ?? () > from /usr/lib/GNUstep/SOGo/ActiveSync.SOGo/./ActiveSync > #9 0x00007feedbfe491a in ?? () > from /usr/lib/GNUstep/SOGo/ActiveSync.SOGo/./ActiveSync > #10 0x00007feedca8e675 in ?? () > from /usr/lib/GNUstep/SOGo/MainUI.SOGo/./MainUI > #11 0x00007feeea0004d4 in -[SoActionInvocation > callOnObject:withPositionalParametersWhenNotNil:inContext:] () > from /usr/lib/libNGObjWeb.so.4.9 > #12 0x00007feee9ffbbf8 in -[SoObjectMethodDispatcher > dispatchInContext:] () from /usr/lib/libNGObjWeb.so.4.9 > #13 0x00007feee9ffdbc9 in -[SoObjectRequestHandler > handleRequest:inContext:session:application:] () > from /usr/lib/libNGObjWeb.so.4.9 > #14 0x00007feee9f93cde in -[WORequestHandler handleRequest:] > (self=0x7feeec1dd838, _cmd=<optimized out>, > _request=0x7feeebf53c48) at WORequestHandler.m:237 > #15 0x00007feee9f5b68c in -[WOCoreApplication > dispatchRequest:usingHandler:] (self=0x7feeec17b6b8, _cmd=<optimized > out>, > _request=0x7feeebf53c48, handler=0x7feeec1dd838) at > WOCoreApplication.m:712 > #16 0x00007feeeb309822 in ?? () > ---Type <return> to continue, or q <return> to quit--- > #17 0x00007feee9fee96d in -[WOHttpTransaction _run] > (self=0x7feeec21bee8, _cmd=<optimized out>) at WOHttpTransaction.m:596 > #18 0x00007feee9fefe38 in -[WOHttpTransaction run] > (self=0x7feeec21bee8, _cmd=<optimized out>) at WOHttpTransaction.m:649 > #19 0x00007feee9feaeda in -[WOHttpAdaptor runConnection:] > (self=0x7feeec21cb88, _cmd=<optimized out>, _socket=<optimized out>) > at WOHttpAdaptor.m:367 > #20 0x00007feee9febd16 in -[WOHttpAdaptor _handleAcceptedConnection:] > (self=0x7feeec21cb88, _cmd=<optimized out>, > _connection=0x7feeec21c918) at WOHttpAdaptor.m:401 > #21 0x00007feee9fec0aa in -[WOHttpAdaptor _handleConnection:] > (self=0x7feeec21cb88, _cmd=<optimized out>, > connection=0x7feeec21c918) at WOHttpAdaptor.m:460 > #22 0x00007feee9feb258 in -[WOHttpAdaptor acceptControlMessage:] > (self=0x7feeec21cb88, _cmd=<optimized out>, > aNotification=<optimized out>) at WOHttpAdaptor.m:499 > #23 0x00007feee879143d in -[NSNotificationCenter _postAndRelease:] > (self=0x7feeebf58778, _cmd=<optimized out>, > notification=0x7feeec21c8e8) at NSNotificationCenter.m:1223 > #24 0x00007feee888b487 in -[GSRunLoopCtxt pollUntil:within:] > (self=0x7feeec0c87f8, _cmd=<optimized out>, > milliseconds=<optimized out>, contexts=<optimized out>) at > GSRunLoopCtxt.m:632 > #25 0x00007feee87d6d70 in -[NSRunLoop acceptInputForMode:beforeDate:] > (self=0x7feeec186848, _cmd=<optimized out>, > mode=0x7feee8c58520 <_OBJC_INSTANCE_2>, limit_date=<optimized > out>) at NSRunLoop.m:1195 > #26 0x00007feee87d5b8c in -[NSRunLoop runMode:beforeDate:] > (self=0x7feeec186848, > _cmd=0x7feeea271e30 <_OBJC_SELECTOR_TABLE+1360>, > mode=0x7feee8c58520 <_OBJC_INSTANCE_2>, date=0x7feeec0c6708) > at NSRunLoop.m:1263 > #27 0x00007feee9f5ca6e in -[WOCoreApplication run] > (self=0x7feeec17b6b8, _cmd=<optimized out>) at WOCoreApplication.m:584 > #28 0x00007feeeb308f2d in ?? () > #29 0x00007feee9f9c5e4 in -[WOWatchDog _spawnChild:] > (self=0x7feeec16f0a8, _cmd=<optimized out>, child=0x7feeec15bc48) > at WOWatchDogApplicationMain.m:595 > #30 0x00007feee9f9b426 in -[WOWatchDog _ensureChildren] > (self=0x7feeec16f0a8, _cmd=<optimized out>) > at WOWatchDogApplicationMain.m:685 > ---Type <return> to continue, or q <return> to quit--- > #31 0x00007feee9f9cd12 in -[WOWatchDog run:argc:argv:] > (self=0x7feeec16f0a8, _cmd=<optimized out>, > newAppName=<optimized out>, newArgC=<optimized out>, > newArgV=<optimized out>) at WOWatchDogApplicationMain.m:936 > #32 0x00007feee9f9d28b in WOWatchDogApplicationMain > (appName=0x7feeeb50f140, argc=7, argv=0x7ffefd005588) > at WOWatchDogApplicationMain.m:1050 > #33 0x00007feeeb30825e in main () > > >
