ZideStore & odd leak behaviour

[Adam Tauno Williams]

I understand that ZideStore monitors it's own size and then restarts
itself after having reached the configured limit (default 200MB, it
starts at about 36MB).   But we've done some benchmarks and found that
as ZideStore grows larger it actually gets slower;  which makes one
doubt the effectiveness of whatever caching it is supposedly doing.  So
I poked around further and found something really weird.  In this test
I'm performing the exact same folder enumeration over and over - so
theoretically I'm not adding anything to any cache after the first
request.  ZideStore answers the first 21 (yep, exactly 21) responses
without growing in size beyond the first request.  Then on the 22nd
request it starts to allocate additional memory on every request.

Anyone have a wild guess were to start looking as to why that is?  It
seems baffling to me.  Was the original author of ZideStore a Black Jack
dealer?

Also, as an aside: On my servers I've gone in to ZSBackend and removed
the SxRecordCacheManager & SxSetCacheManager and rebuilt, and have the
same results although the sizes differ slightly [of course].  From
looking at the code I don't think the cache actually worked, and my
little battery of tests shows no performance change upon removing
SxRecordCacheManager/SxSetCacheManager.  Actually the performance got
very slightly better although the difference is hard to be confident in
since it is so very small (close to being noise).

<log>
ZideStore dispatchRequest BEGIN (vmem size is 45182976)
ZideStore dispatchRequest END (vmem size is 45182976)

... 21 requests without an increase in vmem, then ...

ZideStore dispatchRequest BEGIN (vmem size is 45182976)
ZideStore dispatchRequest END (vmem size is 45453312)
Size +270336

ZideStore dispatchRequest BEGIN (vmem size is 45453312)
ZideStore dispatchRequest END (vmem size is 45723648)
Size +270,336

ZideStore dispatchRequest BEGIN (vmem size is 45723648)
ZideStore dispatchRequest END (vmem size is 45993984)
Size +270,336

ZideStore dispatchRequest BEGIN (vmem size is 45993984)
ZideStore dispatchRequest END (vmem size is 46264320)
Size +270,336

ZideStore dispatchRequest BEGIN (vmem size is 46264320)
ZideStore dispatchRequest END (vmem size is 46673920)
Size +409,600

ZideStore dispatchRequest BEGIN (vmem size is 46673920)
ZideStore dispatchRequest END (vmem size is 46956544)
Size +282,624

ZideStore dispatchRequest BEGIN (vmem size is 46956544)
ZideStore dispatchRequest END (vmem size is 47226880)
Size +270,336

ZideStore dispatchRequest BEGIN (vmem size is 47226880)
....
</log>

--
OpenGroupware.org Developer
developer@...
http://mail.opengroupware.org/mailman/listinfo/developer

[Helge Hess]

On 07.03.2009, at 16:34, Adam Tauno Williams wrote:
> ZideStore answers the first 21 (yep, exactly 21) responses
> without growing in size beyond the first request.  Then on the 22nd
> request it starts to allocate additional memory on every request.


Well, I would assume that this is just the way the glibc malloc  
allocated memory (first a big block, then in smaller increments). The  
size reported by top etc is the size allocated from the memory, not  
the actual size required by the application.

But sure, ZideStore might have a leak somewhere. I suppose if GNUstep  
declares gcc+gstep-base GC as stable, it would be another big reason  
to switch to gnustep-base.

> From looking at the code I don't think the cache actually worked,  
> and my
> little battery of tests shows no performance change upon removing
> SxRecordCacheManager/SxSetCacheManager.


Well, maybe the caches are not really used. Not sure what you are  
testing, but the eg vcard retrieval commands AFAIK have their own  
cache. The caches might have been intended for ZideLook like usage  
(WebDAV property retrievals), but can't say w/o revisiting the code.

Greets,
   Helge

PS: I'm not sure who did most of the work on the ZS, but I'm most  
likely responsible for the design in any case ;-)
--
Helge Hess
http://helgehess.eu/
--
OpenGroupware.org Developer
developer@...
http://mail.opengroupware.org/mailman/listinfo/developer

[Adam Tauno Williams]

On Sat, 2009-03-07 at 16:50 +0100, Helge Hess wrote:
> On 07.03.2009, at 16:34, Adam Tauno Williams wrote:
> > ZideStore answers the first 21 (yep, exactly 21) responses
> > without growing in size beyond the first request.  Then on the 22nd
> > request it starts to allocate additional memory on every request.
> Well, I would assume that this is just the way the glibc malloc  

Yea, that makes sense.

> But sure, ZideStore might have a leak somewhere. I suppose if GNUstep  
> declares gcc+gstep-base GC as stable, it would be another big reason  
> to switch to gnustep-base.

Does anyone know if valgrind is useful with Objective-C?  I've googled
and can't find much if anything.   Aiming it at ZideStore, or just the
OGo utilities, is interesting but I'm still trying to figure out what it
means exactly.

For example I always get a reference to PrintfFormatScanner like:

==14519== 7,454 (5,860 direct, 1,594 indirect) bytes in 290 blocks are
definitely lost in loss record 23 of 33
==14519==    at 0x4025E92: calloc
(in /usr/lib/valgrind/x86-linux/vgpreload_memcheck.so)
==14519==    by 0x45AD2FB: objc_calloc (in /usr/lib/libobjc.so.2.0.0)
==14519==    by 0x446E518: _i_NSDefaultZone__calloc_byteSize_
(NSDefaultZone.m:129)
==14519==    by 0x4465E3E: NSAllocateObject (NSZone.h:136)
==14519==    by 0x4497631: _c_NSTemporaryString__allocWithZone_
(NSString.m:1967)
==14519==    by 0x449741F: _c_NSString_NSStringCreation_allocWithZone_
(NSString.m:1379)
==14519==    by 0x4462C3F: _c_NSObject__alloc (NSObject.m:153)
==14519==    by 0x4492A03:
_c_NSString_NSStringCreation_stringWithCString_ (NSString.m:1420)
==14519==    by 0x44D5027: _i_FormatScanner__parseFormatString_context_
(FormatScanner.m:322)
==14519==    by 0x44D56E3:
_i_PrintfFormatScanner__stringWithFormat_arguments_
(PrintfFormatScanner.m:50)
==14519==    by 0x4461522: Avsprintf (common.m:369)
==14519==    by 0x4499DDB:
_i_NSTemporaryString__initWithFormat_arguments_ (NSString.m:2288)

--
OpenGroupware.org Developer
developer@...
http://mail.opengroupware.org/mailman/listinfo/developer

[Helge Hess]

On 08.03.2009, at 20:51, Adam Tauno Williams wrote:
> Does anyone know if valgrind is useful with Objective-C?


I've used KCacheGrind a lot to profile SOPE/OGo. But more for  
profiling, not for leak detection. Don't know about this.

In theory libFoundation supports BoehmGC PLUS retain counting in a  
leak-detection mode. Not sure whether this still works ... most likely  
not :-/
Its quite nice to find ObjC leaks.

Well, then of course one could try OmniObjectMeter with OGo on MacOSX  
to find leaks.

Thanks,
   Helge
--
Helge Hess
http://helgehess.eu/
--
OpenGroupware.org Developer
developer@...
http://mail.opengroupware.org/mailman/listinfo/developer

[Adam Tauno Williams]

On Sun, 2009-03-08 at 21:10 +0100, Helge Hess wrote:
> On 08.03.2009, at 20:51, Adam Tauno Williams wrote:
> > Does anyone know if valgrind is useful with Objective-C?
> I've used KCacheGrind a lot to profile SOPE/OGo. But more for  
> profiling, not for leak detection. Don't know about this.

It doesn't appear that KCacheGrind does much in regard to finding leaks.

> In theory libFoundation supports BoehmGC PLUS retain counting in a  
> leak-detection mode. Not sure whether this still works ... most likely  
> not :-/
> Its quite nice to find ObjC leaks.

I've googled about for this but only found dead links;  any chance you
have some pointers?

> Well, then of course one could try OmniObjectMeter with OGo on MacOSX  
> to find leaks.

Sadly, no Macs here.

==23038== 1,672,776 (383,216 direct, 1,289,560 indirect) bytes in 17,154
blocks are definitely lost in loss record 36 of 55
==23038==    at 0x4025E92: calloc
(in /usr/lib/valgrind/x86-linux/vgpreload_memcheck.so)
==23038==    by 0x490A2FB: objc_calloc (in /usr/lib/libobjc.so.2.0.0)
==23038==    by 0x47CB518: _i_NSDefaultZone__calloc_byteSize_
(NSDefaultZone.m:129)
==23038==    by 0x47C2E3E: NSAllocateObject (NSZone.h:136)
==23038==    by 0x47F4631: _c_NSTemporaryString__allocWithZone_
(NSString.m:1967)
==23038==    by 0x47F441F: _c_NSString_NSStringCreation_allocWithZone_
(NSString.m:1379)
==23038==    by 0x47BFC3F: _c_NSObject__alloc (NSObject.m:153)
==23038==    by 0x47EFA03:
_c_NSString_NSStringCreation_stringWithCString_ (NSString.m:1420)
==23038==    by 0x4831FF7: _i_FormatScanner__parseFormatString_context_
(FormatScanner.m:322)
==23038==    by 0x48326B3:
_i_PrintfFormatScanner__stringWithFormat_arguments_
(PrintfFormatScanner.m:50)
==23038==    by 0x47BE522: Avsprintf (common.m:369)
==23038==    by 0x47F6DDB:
_i_NSTemporaryString__initWithFormat_arguments_ (NSString.m:2288)

NSString.m:2288
-----------------------
- (id)initWithFormat:(NSString *)format arguments:(va_list)argList
{
    id str = Avsprintf(format, argList);
    str = [str copyWithZone:_zone];
    _collectTemporary(self);
    return str;
}

common.m:369
---------------------------
NSString* Avsprintf(NSString* format, va_list args)
{
    // THREADING
    static id ofmt = nil;
    id objectFormat, formatScanner, string;

    if (ofmt) {
        objectFormat = ofmt;
        ofmt = nil;
    }
    else
        objectFormat = [[FSObjectFormat alloc] init];

    formatScanner = [[PrintfFormatScanner alloc] init];

    [formatScanner setFormatScannerHandler:objectFormat];
    string = [formatScanner stringWithFormat:format arguments:args];

    if (ofmt == nil) ofmt = objectFormat;
    else RELEASE(objectFormat);
    RELEASE(formatScanner);

    return string;
}


--
OpenGroupware.org Developer
developer@...
http://mail.opengroupware.org/mailman/listinfo/developer

[Helge Hess]

On 14.09.2009, at 22:43, Adam Tauno Williams wrote:
>> In theory libFoundation supports BoehmGC PLUS retain counting in a  
>> leak-detection mode. Not sure whether this still works ... most  
>> likely not :-/
>> Its quite nice to find ObjC leaks.
> I've googled about for this but only found dead links;  any chance  
> you have some pointers?

Well, no. I guess its not too easy to make it working again.

Not sure what the following is saying. From an RC perspective the code  
seems to look fine.

> ==23038== 1,672,776 (383,216 direct, 1,289,560 indirect) bytes in  
> 17,154
> blocks are definitely lost in loss record 36 of 55
> ==23038==    at 0x4025E92: calloc
> (in /usr/lib/valgrind/x86-linux/vgpreload_memcheck.so)
> ==23038==    by 0x490A2FB: objc_calloc (in /usr/lib/libobjc.so.2.0.0)
> ==23038==    by 0x47CB518: _i_NSDefaultZone__calloc_byteSize_
> (NSDefaultZone.m:129)
> ==23038==    by 0x47C2E3E: NSAllocateObject (NSZone.h:136)
> ==23038==    by 0x47F4631: _c_NSTemporaryString__allocWithZone_
> (NSString.m:1967)
> ==23038==    by 0x47F441F: _c_NSString_NSStringCreation_allocWithZone_
> (NSString.m:1379)
> ==23038==    by 0x47BFC3F: _c_NSObject__alloc (NSObject.m:153)
> ==23038==    by 0x47EFA03:
> _c_NSString_NSStringCreation_stringWithCString_ (NSString.m:1420)
> ==23038==    by 0x4831FF7:  
> _i_FormatScanner__parseFormatString_context_
> (FormatScanner.m:322)
> ==23038==    by 0x48326B3:
> _i_PrintfFormatScanner__stringWithFormat_arguments_
> (PrintfFormatScanner.m:50)
> ==23038==    by 0x47BE522: Avsprintf (common.m:369)
> ==23038==    by 0x47F6DDB:
> _i_NSTemporaryString__initWithFormat_arguments_ (NSString.m:2288)
>
> NSString.m:2288
> -----------------------
> - (id)initWithFormat:(NSString *)format arguments:(va_list)argList
> {
>    id str = Avsprintf(format, argList);
>    str = [str copyWithZone:_zone];
>    _collectTemporary(self);
>    return str;
> }
>
> common.m:369
> ---------------------------
> NSString* Avsprintf(NSString* format, va_list args)
> {
>    // THREADING
>    static id ofmt = nil;
>    id objectFormat, formatScanner, string;
>
>    if (ofmt) {
>        objectFormat = ofmt;
>        ofmt = nil;
>    }
>    else
>        objectFormat = [[FSObjectFormat alloc] init];
>
>    formatScanner = [[PrintfFormatScanner alloc] init];
>
>    [formatScanner setFormatScannerHandler:objectFormat];
>    string = [formatScanner stringWithFormat:format arguments:args];
>
>    if (ofmt == nil) ofmt = objectFormat;
>    else RELEASE(objectFormat);
>    RELEASE(formatScanner);
>
>    return string;
> }

--
OpenGroupware.org Developer
developer@...
http://mail.opengroupware.org/mailman/listinfo/developer