[Home]

Summary:ASTERISK-07866: [patch] possible double free on app_voicemail.c
Reporter:Fernanda Calvo Barragan (cetus)Labels:
Date Opened:2006-10-03 16:30:30Date Closed:2006-11-01 15:24:25.000-0600
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Applications/app_voicemail
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 8083.diff
Description:We cannot reproduce it and we don't know when it happens. This happens
once every week or so. We are currently handling about 6000 calls a day.
He have just updated everything to the latest and greatest asterisk,
libpri, etc.

We also use several addons (mostly to work with mysql)

$ cat /etc/issue
CentOS release 4.2 (Final)

uname -a
Linux asterisk1.local 2.6.16.19cetus #1 Sat Jun 3 12:45:26 EDT 2006 i686
i686 i386 GNU/Linux

sudo /usr/sbin/asterisk -vr
Asterisk 1.2.12.1, Copyright (C) 1999 - 2006 Digium, Inc. and others.

I'm new to gdb and i tried to put as much relevant information as possible

(gdb) bt
#0  0xffffe410 in __kernel_vsyscall ()
#1  0x005d07d5 in raise () from /lib/tls/libc.so.6
#2  0x005d2149 in abort () from /lib/tls/libc.so.6
#3  0x0060440a in __libc_message () from /lib/tls/libc.so.6
#4  0x0060ab3f in _int_free () from /lib/tls/libc.so.6
ASTERISK-1  0x0060aeba in free () from /lib/tls/libc.so.6
ASTERISK-2  0xb759dbae in vm_execmain (chan=0xb71140b8, data=0xb6df10a0)
   at app_voicemail.c:5521
ASTERISK-3  0x0809142d in pbx_extension_helper (c=0xb71140b8, con=Variable "con"
is not available.
) at pbx.c:553
ASTERISK-4  0x080926f6 in __ast_pbx_run (c=0xb71140b8) at pbx.c:2230
ASTERISK-5  0x0809425c in pbx_thread (data=0x0) at pbx.c:2517
ASTERISK-6 0x0076f341 in start_thread () from /lib/tls/libpthread.so.0
ASTERISK-7 0x006706fe in clone () from /lib/tls/libc.so.6
(gdb) info f
Stack level 0, frame at 0xb6deb894:
eip = 0xffffe410 in __kernel_vsyscall; saved eip 0x5d07d5
called by frame at 0xb6deb8ac
Arglist at 0xb6deb88c, args:
Locals at 0xb6deb88c, Previous frame's sp is 0xb6deb894
Saved registers:
 ebp at 0xb6deb884, eip at 0xb6deb890
(gdb) up
#1  0x005d07d5 in raise () from /lib/tls/libc.so.6
(gdb) info f
Stack level 1, frame at 0xb6deb8ac:
eip = 0x5d07d5 in raise; saved eip 0x5d2149
called by frame at 0xb6deb9dc, caller of frame at 0xb6deb894
Arglist at 0xb6deb8a4, args:
Locals at 0xb6deb8a4, Previous frame's sp is 0xb6deb8ac
Saved registers:
 ebp at 0xb6deb8a4, eip at 0xb6deb8a8
(gdb) up
#2  0x005d2149 in abort () from /lib/tls/libc.so.6
(gdb) info f
Stack level 2, frame at 0xb6deb9dc:
eip = 0x5d2149 in abort; saved eip 0x60440a
called by frame at 0xb6debadc, caller of frame at 0xb6deb8ac
Arglist at 0xb6deb9d4, args:
Locals at 0xb6deb9d4, Previous frame's sp is 0xb6deb9dc
Saved registers:
 ebx at 0xb6deb9c8, ebp at 0xb6deb9d4, esi at 0xb6deb9cc, edi at 0xb6deb9d0,
 eip at 0xb6deb9d8
(gdb) up
#3  0x0060440a in __libc_message () from /lib/tls/libc.so.6
(gdb) info f
Stack level 3, frame at 0xb6debadc:
eip = 0x60440a in __libc_message; saved eip 0x60ab3f
called by frame at 0xb6debb74, caller of frame at 0xb6deb9dc
Arglist at 0xb6debad4, args:
Locals at 0xb6debad4, Previous frame's sp is 0xb6debadc
Saved registers:
 ebx at 0xb6deb9c8, ebp at 0xb6debad4, esi at 0xb6deb9cc, edi at 0xb6deb9d0,
 eip at 0xb6debad8
(gdb) info f
Stack level 4, frame at 0xb6debb74:
eip = 0x60ab3f in _int_free; saved eip 0x60aeba
called by frame at 0xb6debb90, caller of frame at 0xb6debadc
Arglist at 0xb6debb6c, args:
Locals at 0xb6debb6c, Previous frame's sp is 0xb6debb74
Saved registers:
 ebx at 0xb6debb60, ebp at 0xb6debb6c, esi at 0xb6debb64, edi at 0xb6debb68,
 eip at 0xb6debb70
(gdb) up
ASTERISK-1  0x0060aeba in free () from /lib/tls/libc.so.6
(gdb) info f
Stack level 5, frame at 0xb6debb90:
eip = 0x60aeba in free; saved eip 0xb759dbae
called by frame at 0xb6decee0, caller of frame at 0xb6debb74
Arglist at 0xb6debb88, args:
Locals at 0xb6debb88, Previous frame's sp is 0xb6debb90
Saved registers:
 ebx at 0xb6debb60, ebp at 0xb6debb88, esi at 0xb6debb64, edi at 0xb6debb68,
 eip at 0xb6debb8c
(gdb) up
ASTERISK-2  0xb759dbae in vm_execmain (chan=0xb71140b8, data=0xb6df10a0)
   at app_voicemail.c:5521
5521                    free(vms.deleted);
(gdb) info f
Stack level 6, frame at 0xb6decee0:
eip = 0xb759dbae in vm_execmain (app_voicemail.c:5521); saved eip 0x809142d
called by frame at 0xb6df32c0, caller of frame at 0xb6debb90
source language c.
Arglist at 0xb6deced8, args: chan=0xb71140b8, data=0xb6df10a0
Locals at 0xb6deced8, Previous frame's sp is 0xb6decee0
Saved registers:
 ebx at 0xb6dececc, ebp at 0xb6deced8, esi at 0xb6deced0, edi at 0xb6deced4,
 eip at 0xb6decedc

(gdb) x 0xb71140b8
0xb71140b8:     0x2f504953
(gdb) x 0xb6df10a0
0xb6df10a0:     0x40323532
(gdb) x 0x2f504953
0x2f504953:     Cannot access memory at address 0x2f504953
(gdb) x 0x40323532
0x40323532:     Cannot access memory at address 0x40323532

Thanks in advance
Comments:By: Serge Vecher (serge-v) 2006-10-03 16:38:36

this may have been fixed in 1.2 branch post 1.2.12.1 release. Can you please check out the svn 1.2 branch?
By: Anthony LaMantia (alamantia) 2006-10-04 15:27:31

did you build the copy of asterisk that you generated  problem with make  dont optimize?

also, from the backtrace that you put it, the issue really seems not to be a double free() problem.. all of the heap-allocated variables are checked before they are free()'d in that function. the only possible cause i can see for this is vms.curmsg being incrimented to a value that would cause some of the heap to be croupted and then causing free() to fail and asterisk to segfault.


By: Fernanda Calvo Barragan (cetus) 2006-10-06 08:34:00

I installed svn branch 1.2  and now my system crashes even more often

This is all the relevant information i could get

#0  0xffffe410 in __kernel_vsyscall ()
#1  0x005d07d5 in raise () from /lib/tls/libc.so.6
#2  0x005d2149 in abort () from /lib/tls/libc.so.6
#3  0x0060440a in __libc_message () from /lib/tls/libc.so.6
#4  0x0060ab3f in _int_free () from /lib/tls/libc.so.6
ASTERISK-1  0x0060aeba in free () from /lib/tls/libc.so.6
ASTERISK-2  0x08056dcc in ast_verbose (fmt=0xb7da5d7d "%s %s: %s\n") at logger.c:884
ASTERISK-3  0xb7da25a9 in handle_verbose (chan=0x0, agi=0x0, argc=3, argv=0xb73547b0)
   at res_agi.c:1236
ASTERISK-4  0xb7da4052 in agi_exec_full (chan=0xb6d2b130, data=Variable "data" is
not available.
) at res_agi.c:1828
ASTERISK-5  0x080914ed in pbx_extension_helper (c=0xb6d2b130, con=Variable "con"
is not available.
) at pbx.c:553
ASTERISK-6 0x08091a9c in ast_spawn_extension (c=0x0, context=0x6 <Address 0x6 out
of bounds>,
   exten=0x6 <Address 0x6 out of bounds>, priority=6,
   callerid=0x6 <Address 0x6 out of bounds>) at pbx.c:2230
ASTERISK-7 0xb76a666c in macro_exec (chan=0xb6d2b130, data=0xb73607e0) at
app_macro.c:215
ASTERISK-8 0x080914ed in pbx_extension_helper (c=0xb6d2b130, con=Variable "con"
is not available.
) at pbx.c:553
ASTERISK-9 0x08091a9c in ast_spawn_extension (c=0x0, context=0x6 <Address 0x6 out
of bounds>,
   exten=0x6 <Address 0x6 out of bounds>, priority=6,
   callerid=0x6 <Address 0x6 out of bounds>) at pbx.c:2230
ASTERISK-10 0xb76a666c in macro_exec (chan=0xb6d2b130, data=0xb73670a0) at
app_macro.c:215
ASTERISK-11 0x080914ed in pbx_extension_helper (c=0xb6d2b130, con=Variable "con"
is not available.
) at pbx.c:553
ASTERISK-12 0x080927b6 in __ast_pbx_run (c=0xb6d2b130) at pbx.c:2230
ASTERISK-13 0x0809432c in pbx_thread (data=0x0) at pbx.c:2517
ASTERISK-14 0x0076f341 in start_thread () from /lib/tls/libpthread.so.0
ASTERISK-15 0x006706fe in clone () from /lib/tls/libc.so.6

Does anyone have any idea how can i solve this??

Thanks a lot
By: jmls (jmls) 2006-10-06 11:28:50

just a couple of points, (1) a bt full is much better and (2) they should be attached, rather than entered into the comments.
By: Anthony LaMantia (alamantia) 2006-10-09 14:39:38

please update us with a btfull from you most recent crash and any relevant console logs..
By: Fernanda Calvo Barragan (cetus) 2006-10-12 15:13:26

thanks, hope that this helps

(gdb) bt full
#0  0xffffe410 in __kernel_vsyscall ()
No symbol table info available.
#1  0x005d07d5 in raise () from /lib/tls/libc.so.6
No symbol table info available.
#2  0x005d2149 in abort () from /lib/tls/libc.so.6
No symbol table info available.
#3  0x0060440a in __libc_message () from /lib/tls/libc.so.6
No symbol table info available.
#4  0x0060ab3f in _int_free () from /lib/tls/libc.so.6
No symbol table info available.
ASTERISK-1  0x0060aeba in free () from /lib/tls/libc.so.6
No symbol table info available.
ASTERISK-2  0x08056dcc in ast_verbose (fmt=0xb7da5d7d "%s %s: %s\n") at logger.c:878
       stuff = "    --  dialparties.agi: Added extension 225 to extension
map\n\000TE\n\000i\n\0000;37;40m\",
\"\033[1;35;40mdialparties.agi\033[0;37;40m\") in new
stack\n\000\n\000k\n\000[0;37;40m\") in new
stack\n\000k\n\000\000= (g729),\n       > priority = m"...
       len = 62
       replacelast = 0
       complete = 7145504
       olen = 137132952
       m = Variable "m" is not available.
By: Anthony LaMantia (alamantia) 2006-10-18 15:38:45

please try the patch that was just uploaded and report back.
By: Anthony LaMantia (alamantia) 2006-10-31 10:17:01.000-0600

cetus any updates?
By: Fernanda Calvo Barragan (cetus) 2006-11-01 08:37:06.000-0600

I installed the patch and so far it is working great, thanks a lot for all the help!!!
By: Matt O'Gorman (mogorman) 2006-11-01 15:24:24.000-0600

committed in 1.2 branch revision 46838