received signal SIGSEGV, Segmentation fault. malloc_consolidate (av=0x7ffff5e2de80) at malloc.c:5196

[Arran Cudbard-Bell]

> thanks for the answer.

Nice assert! But that's not really related to the issue :(

>> *sigh* probably memory corruption could you run it under valgrind and see if there's any useful info?
> Complete output of valgrind is about 10000 lines. It's hard to me to find out which lines are the useful ones but I give it a try. See at the end of this post.

Could you post the full valgrind output anyway, just in case there is something else, either send it as an attachment to my email or put it in a gist.

>> Also when you build your RPMs could you make sure to pass --enable-developer to turn off optimization so we don't get all those <value optimized out> messages.
> I have built a new package with this configure parameter but there are still optimized out messages.

Weird, try: CFLAGS='-g3 -O0' ./configure <args>

> (1) krb5 : Successfully retrieved and decrypted TGT
> ==1937== Invalid free() / delete / delete[] / realloc()
> ==1937==    at 0x4C273F0: free (vg_replace_malloc.c:446)
> ==1937==    by 0x7830B2D: krb5_free_context (in /lib64/libkrb5.so.3.3)
> ==1937==    by 0xD0274BD: krb5_auth (rlm_krb5.c:569)
> ==1937==    by 0x41E709: modcall_recurse (modcall.c:311)
> ==1937==    by 0x41F9F3: modcall_child (modcall.c:414)
> ==1937==    by 0x41E3A6: modcall_recurse (modcall.c:780)
> ==1937==    by 0x41F91C: modcall (modcall.c:1036)
> ==1937==    by 0x41A8A2: indexed_modcall (modules.c:747)
> ==1937==    by 0x40CFD0: rad_authenticate (auth.c:252)
> ==1937==    by 0x42A96B: request_running (process.c:1211)
> ==1937==    by 0x42A4DC: request_queue_or_run (process.c:851)
> ==1937==    by 0x42C7C0: request_receive (process.c:1414)
> ==1937==  Address 0x908a9b0 is 0 bytes inside a block of size 24 free'd
> ==1937==    at 0x4C273F0: free (vg_replace_malloc.c:446)
> ==1937==    by 0x7830B2D: krb5_free_context (in /lib64/libkrb5.so.3.3)
> ==1937==    by 0xD0274BD: krb5_auth (rlm_krb5.c:569)
> ==1937==    by 0x41E709: modcall_recurse (modcall.c:311)
> ==1937==    by 0x41F9F3: modcall_child (modcall.c:414)
> ==1937==    by 0x41E3A6: modcall_recurse (modcall.c:780)
> ==1937==    by 0x41F91C: modcall (modcall.c:1036)
> ==1937==    by 0x41A8A2: indexed_modcall (modules.c:747)
> ==1937==    by 0x40CFD0: rad_authenticate (auth.c:252)
> ==1937==    by 0x42A96B: request_running (process.c:1211)
> ==1937==    by 0x42A4DC: request_queue_or_run (process.c:851)
> ==1937==    by 0x42C7C0: request_receive (process.c:1414)
> ==1937== 

Hm, double free, and you see it again later when the destructor is freeing the main krb5 context.

==1937== Invalid free() / delete / delete[] / realloc()
==1937==    at 0x4C273F0: free (vg_replace_malloc.c:446)
==1937==    by 0x7830B2D: krb5_free_context (in /lib64/libkrb5.so.3.3)
==1937==    by 0xD027993: krb5_detach (rlm_krb5.c:117)
==1937==    by 0x58B95A3: ??? (in /usr/lib64/libtalloc.so.2.0.7)
==1937==    by 0x58B9322: ??? (in /usr/lib64/libtalloc.so.2.0.7)
==1937==    by 0x5067E7C: FreeWalker (rbtree.c:76)
==1937==    by 0x5067E5C: FreeWalker (rbtree.c:73)
==1937==    by 0x5067E5C: FreeWalker (rbtree.c:73)
==1937==    by 0x5067E5C: FreeWalker (rbtree.c:73)
==1937==    by 0x5067E6D: FreeWalker (rbtree.c:74)
==1937==    by 0x5067E6D: FreeWalker (rbtree.c:74)
==1937==    by 0x5067E5C: FreeWalker (rbtree.c:73)
==1937==  Address 0x908a9b0 is 0 bytes inside a block of size 24 free'd
==1937==    at 0x4C273F0: free (vg_replace_malloc.c:446)
==1937==    by 0x7830B2D: krb5_free_context (in /lib64/libkrb5.so.3.3)
==1937==    by 0xD0274BD: krb5_auth (rlm_krb5.c:569)
==1937==    by 0x41E709: modcall_recurse (modcall.c:311)
==1937==    by 0x41F9F3: modcall_child (modcall.c:414)
==1937==    by 0x41E3A6: modcall_recurse (modcall.c:780)
==1937==    by 0x41F91C: modcall (modcall.c:1036)
==1937==    by 0x41A8A2: indexed_modcall (modules.c:747)
==1937==    by 0x40CFD0: rad_authenticate (auth.c:252)
==1937==    by 0x42A96B: request_running (process.c:1211)
==1937==    by 0x42A4DC: request_queue_or_run (process.c:851)
==1937==    by 0x42C7C0: request_receive (process.c:1414)
==1937== 

Interestingly and importantly if you look at the calls on detach, the block of memory being freed twice, was originally freed by a request! My guess is krb5_copy_context isn't duplicating a bit of memory it needs to.

Could you comment out krb5_free_context(context) at line 448 in rlm_krb5.c? Rebuild, and run a few requests through it.

My guess is it won't SEGV anymore. It shouldn't be that hard to figure out what's not being duplicated if that's really the problem.

-Arran

Arran Cudbard-Bell <a.cudbardb at freeradius.org>
FreeRADIUS Development Team

FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 881 bytes
Desc: Message signed with OpenPGP using GPGMail
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20131212/017f0ae8/attachment-0001.pgp>