I need to correct myself. The backtraces are only identical up to line 16.
It seems that this is not code from SOGo. So it may be a bug in gnustep
or libc.
Since this server is still running debian lenny, it may be fixed in
squeeze.
Upgrade is planned anyway. I'll write again if the problem still exists
after the upgrade.
Cheers
Raffael
On 07/25/2011 07:03 PM, Raffael Bachmann wrote:
Hi,
I tried different numbers of sogod workers. Nothing worked. Since this
happens in our production server i can't investigate the problem if it
happens through the day.
Fortunately is right now happening an everyone already left the
office. This means 2 things:
1. There is not really any load on the server.
2. I can wait and do some debugging without being forced to restart SOGo.
Here what i found so far.
Parent process consuming full cpu.
6 child processes doing nothing with almost identical backtrace:
#0 0x00007f42540ce02e in __lll_lock_wait_private () from /lib/libc.so.6
#1 0x00007f425406bb43 in _L_lock_4488 () from /lib/libc.so.6
#2 0x00007f4254068aab in free () from /lib/libc.so.6
#3 0x00007f4254ec73c0 in default_free (zone=0x7f42552eae00,
ptr=0x8cb540) at NSZone.m:501
#4 0x00007f4254d48a57 in NSZoneFree (zone=0x7f42552eae00,
ptr=0x8cb540) at ../Headers/Foundation/NSZone.h:373
#5 0x00007f4254d492f3 in GSIMapMoreNodes (map=0xb2fb18, required=0)
at ../Headers/Additions/GNUstepBase/GSIMap.h:442
#6 0x00007f4254d4950f in GSIMapNewNode (map=0xb2fb18, key={addr =
139922873388096, obj = 0x7f42552a0c40, nso = 0x7f42552a0c40},
value={addr = 139922652533808, obj = 0x7f4248001430, nso =
0x7f4248001430}) at ../Headers/Additions/GNUstepBase/GSIMap.h:484
#7 0x00007f4254d49962 in GSIMapAddPair (map=0xb2fb18, key={addr =
139922873388096, obj = 0x7f42552a0c40, nso = 0x7f42552a0c40},
value={addr = 139922652533808, obj = 0x7f4248001430, nso =
0x7f4248001430}) at ../Headers/Additions/GNUstepBase/GSIMap.h:774
#8 0x00007f4254d4a3ae in -[GSMutableDictionary setObject:forKey:]
(self=0xb2fb10, _cmd=0x7f42552a11c0, anObject=0x7f4248001430,
aKey=0x7f42552a0c40) at GSDictionary.m:419
#9 0x00007f4254e2b3f5 in +[NSNotificationQueue defaultQueue]
(self=0x7f42552a0f60, _cmd=0x7f4256b2b6d0) at NSNotificationQueue.m:314
#10 0x00007f425681051b in signalHandlerFunction (signum=<value
optimized out>) at UnixSignalHandler.m:186
#11 <signal handler called>
#12 0x00007f42540690a1 in _int_malloc () from /lib/libc.so.6
#13 0x00007f425406aad8 in malloc () from /lib/libc.so.6
#14 0x00007f42547ee91a in objc_malloc () from /usr/lib/libobjc.so.2
#15 0x00007f4254ec7243 in default_malloc (zone=0x7f42552eae00, size=3)
at NSZone.m:466
#16 0x00007f4254d67957 in NSZoneMalloc (zone=0x7f42552eae00, size=3)
at ../Headers/Foundation/NSZone.h:316
#17 0x00007f4254d7eb52 in -[GSMutableString initWithCapacity:]
(self=0x9344600, _cmd=0x7f42552ca050, capacity=2) at GSString.m:3890
#18 0x00007f4254e92392 in +[NSMutableString string]
(self=0x7f42552c8a80, _cmd=0x7f4256e30100) at NSString.m:4769
#19 0x00007f4256c0b7c6 in -[CardVersitRenderer renderElement:]
(self=0x9335290, _cmd=0x7f4256e300e0, anElement=0x9334ec0) at
CardVersitRenderer.m:64
#20 0x00007f4256c0b749 in -[CardVersitRenderer render:]
(self=0x9335290, _cmd=0x7f4256e30290, anElement=0x9334ec0) at
CardVersitRenderer.m:49
#21 0x00007f4256c0bf55 in -[CardVersitRenderer renderGroup:]
(self=0x9335290, _cmd=0x7f4256e300d0, aGroup=0x9334e70) at
CardVersitRenderer.m:146
#22 0x00007f4256c0b720 in -[CardVersitRenderer render:]
(self=0x9335290, _cmd=0x7f4256e2e590, anElement=0x9334e70) at
CardVersitRenderer.m:49
#23 0x00007f4256c09726 in -[CardElement versitString] (self=0x9334e70,
_cmd=0x7f4256e33580) at CardElement.m:491
#24 0x00007f4256c0f557 in -[iCalCalendar versitString]
(self=0x9334e70, _cmd=0x7f424fbcdd20) at iCalCalendar.m:210
#25 0x00007f424f99d832 in -[SOGoCalendarComponent
secureContentAsString] (self=0x930e750, _cmd=0x7f424fbcdf40) at
SOGoCalendarComponent.m:261
#26 0x00007f424f99e30b in -[SOGoCalendarComponent contentAsString]
(self=0x930e750, _cmd=0x7f424fbcdf70) at SOGoCalendarComponent.m:444
#27 0x00007f424f99e3a5 in -[SOGoCalendarComponent davCalendarData]
(self=0x930e750, _cmd=0x6931d0) at SOGoCalendarComponent.m:456
#28 0x00007f4254e3845a in -[NSObject performSelector:]
(self=0x930e750, _cmd=0x7f4257afe270, aSelector=0x6931d0) at
NSObject.m:1954
#29 0x00007f42578ac162 in ?? () from /usr/lib/libSOGo.so.1
#30 0x00007f42578ac654 in ?? () from /usr/lib/libSOGo.so.1
#31 0x00007f42578ac9c6 in ?? () from /usr/lib/libSOGo.so.1
#32 0x00007f42578ad01a in ?? () from /usr/lib/libSOGo.so.1
#33 0x00007f4254e3857a in -[NSObject performSelector:withObject:]
(self=0xcd63a0, _cmd=0x7f4256bc7600, aSelector=0x68ed80,
anObject=0x74c040) at NSObject.m:1980
#34 0x00007f42568a55fe in -[SoSelectorInvocation
primaryCallSelector:withArguments:] (self=0xa0b8f0, _cmd=<value
optimized out>, _sel=0x68ed80, _args=0xcccc90) at
SoSelectorInvocation.m:226
#35 0x00007f42568b8d66 in -[SoObjectWebDAVDispatcher doREPORT:]
(self=0x1149c60, _cmd=<value optimized out>, _ctx=0x74c040) at
SoObjectWebDAVDispatcher.m:1596
#36 0x00007f4254e3857a in -[NSObject performSelector:withObject:]
(self=0x1149c60, _cmd=0x7f4256bda420, aSelector=0x6aa0c0,
anObject=0x74c040) at NSObject.m:1980
#37 0x00007f42568b941c in -[SoObjectWebDAVDispatcher
dispatchInContext:] (self=0x1149c60, _cmd=<value optimized out>,
_ctx=0x74c040) at SoObjectWebDAVDispatcher.m:1776
#38 0x00007f4256896b2c in -[SoObjectRequestHandler
handleRequest:inContext:session:application:] (self=0x9c90f0,
_cmd=<value optimized out>, _rq=<value optimized out>, _ctx=0x74c040,
_sn=0x0, app=0x9a8d30) at SoObjectRequestHandler.m:591
#39 0x00007f425682645e in -[WORequestHandler handleRequest:]
(self=0x9c90f0, _cmd=<value optimized out>, _request=0xd154e0) at
WORequestHandler.m:241
#40 0x00007f42567eba7c in -[WOCoreApplication
dispatchRequest:usingHandler:] (self=0x9a8d30, _cmd=<value optimized
out>, _request=0xd154e0, handler=0x9c90f0) at WOCoreApplication.m:704
#41 0x0000000000403027 in -[SOGo dispatchRequest:] (self=0x9a8d30,
_cmd=0x7f4256ba53e0, _request=0xd154e0) at SOGo.m:451
#42 0x00007f4256886585 in -[WOHttpTransaction _run] (self=0xf1c830,
_cmd=<value optimized out>) at WOHttpTransaction.m:546
#43 0x00007f4256886778 in -[WOHttpTransaction run] (self=0xf1c830,
_cmd=<value optimized out>) at WOHttpTransaction.m:599
#44 0x00007f4256882929 in -[WOHttpAdaptor runConnection:]
(self=0x7093f0, _cmd=<value optimized out>, _socket=<value optimized
out>) at WOHttpAdaptor.m:384
#45 0x00007f4256882b3e in -[WOHttpAdaptor _handleAcceptedConnection:]
(self=0x7093f0, _cmd=<value optimized out>, _connection=0x774cc0) at
WOHttpAdaptor.m:418
#46 0x00007f4256882fb9 in -[WOHttpAdaptor _handleConnection:]
(self=0x7093f0, _cmd=<value optimized out>, connection=0x774cc0) at
WOHttpAdaptor.m:477
#47 0x00007f4256883201 in -[WOHttpAdaptor acceptControlMessage:]
(self=0x7093f0, _cmd=<value optimized out>, aNotification=<value
optimized out>) at WOHttpAdaptor.m:516
#48 0x00007f4254e2a3c5 in -[NSNotificationCenter _postAndRelease:]
(self=0x70ec10, _cmd=0x7f42552a0630, notification=0xa1f630) at
NSNotificationCenter.m:1070
#49 0x00007f4254e2ac9c in -[NSNotificationCenter
postNotificationName:object:userInfo:] (self=0x70ec10,
_cmd=0x7f42552a0640, name=0x7f4255eb97e0, object=0x99c6f0, info=0x0)
at NSNotificationCenter.m:1129
#50 0x00007f4254e2ab51 in -[NSNotificationCenter
postNotificationName:object:] (self=0x70ec10, _cmd=0x7f4255eb96d0,
name=0x7f4255eb97e0, object=0x99c6f0) at NSNotificationCenter.m:1109
#51 0x00007f4254f1e4aa in -[GSRunLoopCtxt pollUntil:within:]
(self=0x759d60, _cmd=0x7f42552bb8e0, milliseconds=29997,
contexts=0x9b23e0) at GSRunLoopCtxt.m:598
#52 0x00007f4254e6c138 in -[NSRunLoop acceptInputForMode:beforeDate:]
(self=0xa3cca0, _cmd=0x7f42552bb930, mode=0x7f42552ba860,
limit_date=0xd5fe60) at NSRunLoop.m:1164
#53 0x00007f4254e6c52d in -[NSRunLoop runMode:beforeDate:]
(self=0xa3cca0, _cmd=0x7f4256b0b540, mode=0x7f42552ba860,
date=0x99c000) at NSRunLoop.m:1239
#54 0x00007f42567eb3e9 in -[WOCoreApplication run] (self=0x9a8d30,
_cmd=<value optimized out>) at WOCoreApplication.m:576
#55 0x00000000004027a0 in -[SOGo run] (self=0x9a8d30,
_cmd=0x7f4256b4adf0) at SOGo.m:275
#56 0x00007f425683043b in -[WOWatchDog _spawnChild:] (self=0x772a00,
_cmd=<value optimized out>, child=0x718180) at
WOWatchDogApplicationMain.m:563
#57 0x00007f425682f5b6 in -[WOWatchDog _ensureChildren]
(self=0x772a00, _cmd=<value optimized out>) at
WOWatchDogApplicationMain.m:653
#58 0x00007f425682fc8e in -[WOWatchDog run:argc:argv:] (self=0x772a00,
_cmd=<value optimized out>, newAppName=<value optimized out>,
newArgC=<value optimized out>, newArgV=<value optimized out>) at
WOWatchDogApplicationMain.m:927
#59 0x00007f4256830cb4 in WOWatchDogApplicationMain (appName=0x6084a0,
argc=7, argv=0x7fff86b420c8) at WOWatchDogApplicationMain.m:1036
#60 0x0000000000401ab3 in main (argc=7, argv=0x7fff86b420c8,
env=0x7fff86b42108) at sogod.m:53
Any ideas on this?
Thanks
Raffael
On 07/18/2011 02:34 PM, Ludovic Marcotte wrote:
On 18/07/11 07:13, Raffael Bachmann wrote:
From time to time (sometimes twice a day) the parent process
consumes full cpu.
That happens when all sogod workers are doing some work - the parent
process will spin very quickly trying to find an available worker.
Increase the number of sogod workers.
--
[email protected]
https://inverse.ca/sogo/lists
