Re: 2.7 suspected memory leak.

To check for memory leaks please compile with valgrind support
(configure option). Then after triggering the leak while running on
valgrind, go to the memory usage page in cachemgr (squidclient mgr:mem).

Valgrind summary is reported in cachemgr, leaks on stderr.

Regards
Henrik

On lör, 2008-01-05 at 04:46 +0100, Pawel Worach wrote:
> Hi all,
>
> Running 2.7.DEVEL0-20080104 in the real world for a while made the
> process size grow to about 1.5GB with 320MB cache_mem, this is
> significantly larger than what the 2.6 squid stayed at, around 800-850MB.
>
> I started to play a bit with valgrind and here is what it says, no idea
> if these are false positives or not, that's why I'm asking here :)
>
> These messages come 5-10 seconds after every startup:
> 2008/01/05 04:23:46| storeLateRelease: released 0 objects
> ==65296== Invalid read of size 4
> ==65296== at 0x80A0FC4: pconnPop (pconn.c:252)
> ==65296== by 0x8079191: fwdConnectStart (forward.c:592)
> ==65296== by 0x80A27A6: peerSelectFoo (peer_select.c:202)
> ==65296== by 0x804D57A: aclCheckCallback (acl.c:2283)
> ==65296== by 0x80A27EF: peerSelectFoo (peer_select.c:263)
> ==65296== by 0x8078E68: fwdStart (forward.c:980)
> ==65296== by 0x806472D: clientProcessMiss (client_side.c:3561)
> ==65296== by 0x8064B6D: clientProcessRequest (client_side.c:3477)
> ==65296== by 0x8066339: clientCheckNoCache (client_side.c:567)
> ==65296== by 0x806BD1D: clientStoreURLRewriteStart
> (client_side_storeurl_rewrite.c:57)
> ==65296== by 0x806BB8D: clientRedirectStart (client_side_rewrite.c:57)
> ==65296== by 0x804D57A: aclCheckCallback (acl.c:2283)
> ==65296== Address 0xBDED50 is 16 bytes inside a block of size 20 free'd
> ==65296== at 0x1C435: free (vg_replace_malloc.c:233)
> ==65296== by 0x809BA85: memPoolFree (MemPool.c:341)
> ==65296== by 0x80A0E9C: pconnRemoveFD (pconn.c:102)
> ==65296== by 0x80A0F7C: pconnPop (pconn.c:248)
> ==65296== by 0x8079191: fwdConnectStart (forward.c:592)
> ==65296== by 0x80A27A6: peerSelectFoo (peer_select.c:202)
> ==65296== by 0x804D57A: aclCheckCallback (acl.c:2283)
> ==65296== by 0x80A27EF: peerSelectFoo (peer_select.c:263)
> ==65296== by 0x8078E68: fwdStart (forward.c:980)
> ==65296== by 0x806472D: clientProcessMiss (client_side.c:3561)
> ==65296== by 0x8064B6D: clientProcessRequest (client_side.c:3477)
> ==65296== by 0x8066339: clientCheckNoCache (client_side.c:567)
>
> This came up in the middle of the 15 minute run:
> ==65296==
> ==65296== Invalid read of size 4
> ==65296== at 0x80A0FC4: pconnPop (pconn.c:252)
> ==65296== by 0x8079191: fwdConnectStart (forward.c:592)
> ==65296== by 0x8074928: eventRun (event.c:148)
> ==65296== by 0x8099D54: main (main.c:854)
> ==65296== Address 0xC5A870 is 16 bytes inside a block of size 20 free'd
> ==65296== at 0x1C435: free (vg_replace_malloc.c:233)
> ==65296== by 0x809BA85: memPoolFree (MemPool.c:341)
> ==65296== by 0x80A0E9C: pconnRemoveFD (pconn.c:102)
> ==65296== by 0x80A0F7C: pconnPop (pconn.c:248)
> ==65296== by 0x8079191: fwdConnectStart (forward.c:592)
> ==65296== by 0x8074928: eventRun (event.c:148)
> ==65296== by 0x8099D54: main (main.c:854)
>
> And here are some claimed memory leaks:
> 2008/01/05 04:44:28| storeDirWriteCleanLogs: Starting...
> 2008/01/05 04:44:28| Finished. Wrote 0 entries.
> 2008/01/05 04:44:28| Took 0.0 seconds ( 0.0 entries/sec).
> 2008/01/05 04:44:28| Logfile: closing log /export/log/access.log
> 2008/01/05 04:44:28| Squid Cache (Version 2.7.DEVEL0-20080104): Exiting
> normally.
> ==65296==
> ==65296== ERROR SUMMARY: 690 errors from 2 contexts (suppressed: 0 from 0)
> ==65296== malloc/free: in use at exit: 356,348 bytes in 5,257 blocks.
> ==65296== malloc/free: 733,480 allocs, 728,223 frees, 198,498,942 bytes
> allocated.
> ==65296== For counts of detected errors, rerun with: -v
> ==65296== searching for pointers to 5,257 not-freed blocks.
> ==65296== checked 1,394,008 bytes.
> ==65296==
> ==65296==
> ==65296== 32 bytes in 1 blocks are possibly lost in loss record 6 of 21
> ==65296== at 0x1BABA: calloc (vg_replace_malloc.c:279)
> ==65296== by 0x80CBFAC: xcalloc (util.c:561)
> ==65296== by 0x809BD4F: memPoolAlloc (MemPool.c:303)
> ==65296== by 0x808AA01: httpHdrCcCreate (HttpHdrCc.c:82)
> ==65296== by 0x808AA7D: httpHdrCcParseCreate (HttpHdrCc.c:91)
> ==65296== by 0x808D9B1: httpHeaderGetCc (HttpHeader.c:1114)
> ==65296== by 0x8063939: clientInterpretRequestHeaders
> (client_side.c:1315)
> ==65296== by 0x806B86C: clientRedirectDone (client_side_rewrite.c:149)
> ==65296== by 0x806BB8D: clientRedirectStart (client_side_rewrite.c:57)
> ==65296== by 0x804D57A: aclCheckCallback (acl.c:2283)
> ==65296== by 0x80666B1: clientCheckFollowXForwardedFor
> (client_side.c:383)
> ==65296== by 0x8067141: clientTryParseRequest (client_side.c:4023)
> ==65296==
> ==65296==
> ==65296== 915 bytes in 29 blocks are definitely lost in loss record 13 of 21
> ==65296== at 0x1C835: malloc (vg_replace_malloc.c:149)
> ==65296== by 0x80CC0EB: xmalloc (util.c:437)
> ==65296== by 0x805FE3A: cbdataInitType (cbdata.c:140)
> ==65296== by 0x805FF15: cbdataInit (cbdata.c:170)
> ==65296== by 0x80996C3: main (main.c:760)
> ==65296==
> ==65296==
> ==65296== 129,084 (127,874 direct, 1,210 indirect) bytes in 3,997 blocks
> are definitely lost in loss record 20 of 21
> ==65296== at 0x1BABA: calloc (vg_replace_malloc.c:279)
> ==65296== by 0x80CBFAC: xcalloc (util.c:561)
> ==65296== by 0x809BD4F: memPoolAlloc (MemPool.c:303)
> ==65296== by 0x808AA01: httpHdrCcCreate (HttpHdrCc.c:82)
> ==65296== by 0x808AA7D: httpHdrCcParseCreate (HttpHdrCc.c:91)
> ==65296== by 0x808D9B1: httpHeaderGetCc (HttpHeader.c:1114)
> ==65296== by 0x8063939: clientInterpretRequestHeaders
> (client_side.c:1315)
> ==65296== by 0x806B86C: clientRedirectDone (client_side_rewrite.c:149)
> ==65296== by 0x806BB8D: clientRedirectStart (client_side_rewrite.c:57)
> ==65296== by 0x804D57A: aclCheckCallback (acl.c:2283)
> ==65296== by 0x80666B1: clientCheckFollowXForwardedFor
> (client_side.c:383)
> ==65296== by 0x8067141: clientTryParseRequest (client_side.c:4023)
> ==65296==
> ==65296== LEAK SUMMARY:
> ==65296== definitely lost: 128,789 bytes in 4,026 blocks.
> ==65296== indirectly lost: 1,210 bytes in 8 blocks.
> ==65296== possibly lost: 32 bytes in 1 blocks.
> ==65296== still reachable: 226,317 bytes in 1,222 blocks.
> ==65296== suppressed: 0 bytes in 0 blocks.
>
> # uname -sr
> FreeBSD 7.0-RC1
> # /opt/squid/sbin/squid -v
> Squid Cache: Version 2.7.DEVEL0-20080104
> configure options: '--prefix=/opt/squid-2.7.DEVEL0-20080104'
> '--sysconfdir=/opt/apps/squid/etc' '--enable-storeio=null,ufs'
> '--disable-wccp' '--disable-wccpv2' '--enable-err-languages=English'
> '--disable-ident-lookups' '--enable-auth=basic,negotiate,ntlm'
> '--with-large-files' '--with-valgrind-debug' '--disable-unlinkd'
> 'CFLAGS=-O2 -I/opt/valgrind/include -fno-strict-aliasing -pipe
> -march=pentiumpro -g'
>
> (unlinkd was breaking valgrind in strange ways so I disabled it)
>