Summary:ASTERISK-15602: problems with high call frequency and more than 300 calls at the same time
Reporter:Marco Loewl (marco_wc)Labels:
Date Opened:2010-02-10 08:38:27.000-0600Date Closed:2011-06-07 14:00:52
Versions:Frequency of
Description:asterisk-1.4.29 works without problem i have test with 480 Calls

what traces do you need ?


[Feb  5 17:13:41] ERROR[24535]: astobj2.c:110 INTERNAL_OBJ: user_data is NULL
[Feb  5 17:13:41] ERROR[24535]: astobj2.c:110 INTERNAL_OBJ: user_data is NULL

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x4204d950 (LWP 24535)]
__ast_read (chan=0x0, dropaudio=0) at channel.c:2645
2645                            if (chan->timingfunc) {
(gdb) backtrace
#0  __ast_read (chan=0x0, dropaudio=0) at channel.c:2645
#1  0x000000000043b763 in autoservice_run (ign=<value optimized out>) at autoservice.c:121
#2  0x00000000004f91bc in dummy_start (data=<value optimized out>) at utils.c:968
#3  0x00007f5246e38fc7 in start_thread () from /lib/libpthread.so.0
#4  0x00007f524732159d in clone () from /lib/libc.so.6
ASTERISK-1  0x0000000000000000 in ?? ()
Comments:By: Leif Madsen (lmadsen) 2010-02-10 15:17:40.000-0600

Please provide a console trace with 'core set debug 10' and 'core set verbose 10' with debug level logging enabled via logger.conf.

Also provide a proper backtrace per the doc/backtrace.txt documentation within your Asterisk source.

By: Marco Loewl (marco_wc) 2010-03-12 12:45:47.000-0600
Pass: never.killme.1

By: Alec Davis (alecdavis) 2010-03-13 03:03:00.000-0600

Interesting, the following dialplan also segfaults with trunk after 480 looped calls :(

exten => _1XXXX,1,Set(i=${MATH(${EXTEN}+1,int)})
exten => _1XXXX,n,NoOp(i='${i}')
exten => _1XXXX,n,Dial(Local/${i}@phones)

console output:
Connected to Asterisk SVN-trunk-r252133 currently running on asterix (pid = 30850)
Verbosity was 0 and is now 4
 == Primary D-Channel on span 1 up
   -- Executing [10000@phones:1] Set("SIP/cisco4-00000000", "i=10001") in new stack
   -- Executing [10000@phones:2] NoOp("SIP/cisco4-00000000", "i='10001") in new stack
   -- Executing [10000@phones:3] Dial("SIP/cisco4-00000000", "Local/10001@phones") in new stack
   -- Called 10001@phones
   -- Called 10481@phones
   -- Executing [10481@phones:1] Set("Local/10481@phones-90a4;2", "i=10482") in new stack
   -- Executing [10481@phones:2] NoOp("Local/10481@phones-90a4;2", "i='10482") in new stack
   -- Executing [10481@phones:3] Dial("Local/10481@phones-90a4;2", "Local/10482@phones") in new stack
[Mar 13 22:01:00] WARNING[31933]: channel.c:861 __ast_channel_alloc_ap: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n

By: Alec Davis (alecdavis) 2010-03-13 04:31:40.000-0600

console output when running asterisk -gcvvv

  -- Called 10482@phones
   -- Executing [10482@phones:1] Set("Local/10482@phones-2220;2", "i=10483") in new stack
   -- Executing [10482@phones:2] NoOp("Local/10482@phones-2220;2", "i='10483") in new stack
   -- Executing [10482@phones:3] Dial("Local/10482@phones-2220;2", "Local/10483@phones") in new stack
*** glibc detected *** asterisk: munmap_chunk(): invalid pointer: 0x0894ca08 ***
[Mar 13 23:30:11] WARNING[12384]: channel.c:861 __ast_channel_alloc_ap: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
Aborted (core dumped)

backtrace gives no useful information.
(gdb) bt
#0  0xb7f18424 in __kernel_vsyscall ()
#1  0xb7c43640 in raise () from /lib/i686/cmov/libc.so.6
#2  0xb7c45018 in abort () from /lib/i686/cmov/libc.so.6
#3  0xb7c8034d in ?? () from /lib/i686/cmov/libc.so.6
#4  0xaf2a15c4 in ?? ()
ASTERISK-1  0x00000040 in ?? ()
ASTERISK-2  0x00000000 in ?? ()

By: Marco Loewl (marco_wc) 2010-03-15 13:30:19

i have tested with more descriptors, but i think they are lost. I will test agin this week ...

By: Paul Belanger (pabelanger) 2010-04-28 15:58:56

Ping!  Any update on this?  Cleaning up the issue tracker.

By: Marco Loewl (marco_wc) 2010-04-29 00:51:40

sorry, i'm in the release stress :-(
but the trace what i have send you is make with higher descriptors (ulimit -n)
this solved not the problem !

By: David Woolley (davidw) 2010-04-29 02:10:29

No-one seems to have noticed the most serious error message here:

*** glibc detected *** asterisk: munmap_chunk(): invalid pointer: 0x0894ca08 ***

Looks like there is memory corruption.  With the caveat that it can sometimes make the system run too slowly even to do the test, I believe the debugging protocol requires the use of the procedure in doc/valgrind.txt, at this point.

(The abort, rather than segmentation fault, in the last backtrace, also tells you that you are dealing with some sort of memory management problem

By: Leif Madsen (lmadsen) 2010-04-30 13:48:17

Thanks for the information davidw!

marco_wc: per davidw, you will need to follow the instructions in doc/valgrind.txt in order to move this issue forward.

By: Paul Belanger (pabelanger) 2010-06-01 13:21:25

Suspended due to lack of activity. Please request a bug marshal in #asterisk-bugs on the IRC network irc.freenode.net to reopen the issue should you have the additional information requested.

Further information can be found at http://www.asterisk.org/developers/bug-guidelines

By: Marco Loewl (marco_wc) 2010-06-07 03:46:29

sorry, why do close this :-(
i will send you next week after my release the new information !

sorry, but this is not OK !

all version from 1.6.x is very unstable :-(

By: Leif Madsen (lmadsen) 2010-06-09 10:20:27

I notice you're using res_timing_pthread -- please try using something like res_timing_dahdi instead and see if that helps.

For some reason res_timing_pthread is not very stable right now.

Additional debug information while using res_timing_pthread would be greatly appreciated. This includes valgrind output along with a backtrace while DONT_OPTIMIZE has been selected (and subsequently compiled) in menuselect.

Please attach the results of that information to this issue.

By: Leif Madsen (lmadsen) 2010-06-14 13:41:08

Closed due to a lack of response.