[asterisk-dev] asterisk craches on chan_sip monitor (my bad I guess)

[Juan Ramírez]

Hi, I'm having this weird situation here:

- I have two servers with asterisk 1.4.36 installed, plus a module that I
created myself
   Asterisk is compiled with DONT_OPTIMIZE, DEBUG_THREADS and
DEBUG_CHANNEL_LOCKS

- On the first server my module handles an incoming extension (registered as
an application) an then:
   - Answers
   - Reads text from the channel using ast_recvtext  (the phone number to
dial)
   - Makes a call to a local SIP phone
   - Bridges the incoming channel with the new channel (the local SIP phone)
        This blocks the thread until the bridge ends, and then returns
control to the pbx_run method
This is a virtual machine running CentOS 5.5 on VirtualBox 3.2.10 (gcc 4.1)

- On the second server my module makes the call to the first server using a
SIP trunk
   - Send text to the channel using ast_sendtext (the phone number read on
the other side)
   - If the call could be bridged with the remote phone creates a thread and
waits until the call ends
This is my personal laptop running Ubuntu 10.10 64 bit (gcc 4.4)

It works very well until 10~15 calls are running simultaneously

If there are more calls at the same time the first server crashes trying to
lock a channel on the do_monitor thread (chan_sip.c)

I think my channel is being destroyed somewhere but I can't find how

I'm attaching the full back-trace of the crash but don't know if will
be helpful

Any help is welcome, I'm very new to asterisk but reading the source code
and some books I'm learning fast (but sadly not enough)

Thanks!


Saludos
     Juan
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-dev/attachments/20101021/5322aa36/attachment.htm 
-------------- next part --------------
Core was generated by `asterisk -cvvvvvvvvvvvvvvvvvg'.
Program terminated with signal 11, Segmentation fault.
#0  0x0065d412 in __ast_pthread_mutex_lock (filename=0x6b9834 "chan_sip.c", lineno=1975, func=0x6b9d58 "retrans_pkt", mutex_name=0x6b9d64 "&pkt->owner->lock", 
    t=0x65626563) at /root/desarrollo/packages/asterisk/1.4.36/src/include/asterisk/lock.h:360
360             int canlog = strcmp(filename, "logger.c") & t->track;
(gdb) bt full
#0  0x0065d412 in __ast_pthread_mutex_lock (filename=0x6b9834 "chan_sip.c", lineno=1975, func=0x6b9d58 "retrans_pkt", mutex_name=0x6b9d64 "&pkt->owner->lock", 
    t=0x65626563) at /root/desarrollo/packages/asterisk/1.4.36/src/include/asterisk/lock.h:360
        res = 7051317
        canlog = -1216598168
        __PRETTY_FUNCTION__ = "__ast_pthread_mutex_lock"
#1  0x0065c6ef in retrans_pkt (data=0x8ff2000) at chan_sip.c:1975
        pkt = 0x8ff2000
        prev = 0x8120626
        cur = 0x0
        reschedule = 1000
        xmitres = 0
        __PRETTY_FUNCTION__ = "retrans_pkt"
#2  0x0810e98b in ast_sched_runq (con=0x8ec55d8) at sched.c:363
        current = 0x910a708
        tv = {tv_sec = 1287676743, tv_usec = 892972}
        numevents = 0
        res = 1
        __PRETTY_FUNCTION__ = "ast_sched_runq"
#3  0x006a9871 in do_monitor (data=0x0) at chan_sip.c:17130
        res = 0
        sip = 0x0
        peer = 0x0
        t = 1287676743
        fastrestart = 0
        lastpeernum = -1
        curpeernum = 0
        reloading = 0
        __PRETTY_FUNCTION__ = "do_monitor"
#4  0x0811fbf6 in dummy_start (data=0x8ec8d98) at utils.c:856
        __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {9097204, 0, -1216595056, -1216597048, 568833011, -1635091881}, __mask_was_saved = 0}}, __pad = {
            0xb77c3480, 0x0, 0x0, 0x0}}
        __cancel_routine = 0x8068ecd <ast_unregister_thread>
        __cancel_arg = 0xb77c3b90
        not_first_call = 0
        ret = 0x0
        a = {start_routine = 0x6a8eb9 <do_monitor>, data = 0x0, 
          name = 0x8ec8fe0 "do_monitor", ' ' <repeats 11 times>, "started at [17183] chan_sip.c restart_monitor()"}
Core was generated by `asterisk -cvvvvvvvvvvvvvvvvvg'.
Program terminated with signal 11, Segmentation fault.
#0  0x0065d412 in __ast_pthread_mutex_lock (filename=0x6b9834 "chan_sip.c", lineno=1975, func=0x6b9d58 "retrans_pkt", mutex_name=0x6b9d64 "&pkt->owner->lock", 
    t=0x65626563) at /root/desarrollo/packages/asterisk/1.4.36/src/include/asterisk/lock.h:360
360             int canlog = strcmp(filename, "logger.c") & t->track;
(gdb) bt full
#0  0x0065d412 in __ast_pthread_mutex_lock (filename=0x6b9834 "chan_sip.c", lineno=1975, func=0x6b9d58 "retrans_pkt", mutex_name=0x6b9d64 "&pkt->owner->lock", 
    t=0x65626563) at /root/desarrollo/packages/asterisk/1.4.36/src/include/asterisk/lock.h:360
        res = 7051317
        canlog = -1216598168
        __PRETTY_FUNCTION__ = "__ast_pthread_mutex_lock"
#1  0x0065c6ef in retrans_pkt (data=0x8ff2000) at chan_sip.c:1975
        pkt = 0x8ff2000
        prev = 0x8120626
        cur = 0x0
        reschedule = 1000
        xmitres = 0
        __PRETTY_FUNCTION__ = "retrans_pkt"
#2  0x0810e98b in ast_sched_runq (con=0x8ec55d8) at sched.c:363
        current = 0x910a708
        tv = {tv_sec = 1287676743, tv_usec = 892972}
        numevents = 0
        res = 1
        __PRETTY_FUNCTION__ = "ast_sched_runq"
#3  0x006a9871 in do_monitor (data=0x0) at chan_sip.c:17130
        res = 0
        sip = 0x0
        peer = 0x0
        t = 1287676743
        fastrestart = 0
        lastpeernum = -1
        curpeernum = 0
        reloading = 0
        __PRETTY_FUNCTION__ = "do_monitor"
#4  0x0811fbf6 in dummy_start (data=0x8ec8d98) at utils.c:856
        __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {9097204, 0, -1216595056, -1216597048, 568833011, -1635091881}, __mask_was_saved = 0}}, __pad = {
            0xb77c3480, 0x0, 0x0, 0x0}}
        __cancel_routine = 0x8068ecd <ast_unregister_thread>
        __cancel_arg = 0xb77c3b90
        not_first_call = 0
        ret = 0x0
        a = {start_routine = 0x6a8eb9 <do_monitor>, data = 0x0, 
          name = 0x8ec8fe0 "do_monitor", ' ' <repeats 11 times>, "started at [17183] chan_sip.c restart_monitor()"}