[asterisk-bugs] [Asterisk 0014762]: Asterisk exits randomly when on Originate command

Asterisk Bug Tracker noreply at bugs.digium.com
Thu Mar 26 07:59:15 CDT 2009


A NOTE has been added to this issue. 
====================================================================== 
http://bugs.digium.com/view.php?id=14762 
====================================================================== 
Reported By:                neutrino88
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   14762
Category:                   Channels/chan_local
Reproducibility:            random
Severity:                   crash
Priority:                   normal
Status:                     new
Asterisk Version:           1.4.19 
Regression:                 No 
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Request Review:              
====================================================================== 
Date Submitted:             2009-03-26 07:57 CDT
Last Modified:              2009-03-26 07:59 CDT
====================================================================== 
Summary:                    Asterisk exits randomly when on Originate command
Description: 
Hello,

Our Asterisk platform exits spontanously twice a day.
This happends under the following conditions:

1- an external application issues an Originate Manager command with a
Local 
2- THe Dialplan associated with the Local channel calls an outside SIP
trunk carrier
3- when the call is answered, in some cases, Astersik exits;

There is no core file and from the GDB Capture, we can see that the
process actually exits.
====================================================================== 

---------------------------------------------------------------------- 
 (0102231) neutrino88 (reporter) - 2009-03-26 07:59
 http://bugs.digium.com/view.php?id=14762#c102231 
---------------------------------------------------------------------- 
Here are some traces of such a stop


<--- SIP read from 217.64.49.10:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP
86.66.0.18:5090;branch=z9hG4bK3da591a0;received=86.66.0.18;rport=5090
From: "xxxxxxxxx" <sip:anonymous at acropolis.fr>;tag=as3088bb3a
To: <sip:0562919249 at 217.64.49.10>;tag=as18d76027
Call-ID: 2176cbaa3be91d33437b376f2a7ca63f at acropolis.fr
CSeq: 102 INVITE
User-Agent: MARS
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:0562919249 at 217.64.49.10>
Content-Type: application/sdp
Content-Length: 237

v=0
o=root 3151 3152 IN IP4 217.64.49.10
s=session
c=IN IP4 217.64.49.10
t=0 0
m=audio 8444 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

<------------->
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 0:
SIP/2.0 200 OK (14)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 1:
Via: SIP/2.0/UDP
86.66.0.18:5090;branch=z9hG4bK3da591a0;received=86.66.0.18;rport=5090 (86)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 2:
From: "xxxxxxxxxx" <sip:anonymous at acropolis.fr>;tag=as3088bb3a (65)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 3:
To: <sip:0562919249 at 217.64.49.10>;tag=as18d76027 (48)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 4:
Call-ID: 2176cbaa3be91d33437b376f2a7ca63f at acropolis.fr (54)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 5:
CSeq: 102 INVITE (16)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 6:
User-Agent: MARS (16)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 7:
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 8:
Contact: <sip:0562919249 at 217.64.49.10> (38)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 9:
Content-Type: application/sdp (29)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 10:
Content-Length: 237 (19)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5237 parse_request: Header 11: 
(0)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line: v=0
(3)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line: o=root
3151 3152 IN IP4 217.64.49.10 (36)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line:
s=session (9)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line: c=IN
IP4 217.64.49.10 (21)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line: t=0 0
(5)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line:
m=audio 8444 RTP/AVP 0 8 101 (28)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line:
a=rtpmap:0 PCMU/8000 (20)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line:
a=rtpmap:8 PCMA/8000 (20)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line:
a=rtpmap:101 telephone-event/8000 (33)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line:
a=fmtp:101 0-16 (15)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:5269 parse_request: Line:
a=silenceSupp:off - - - - (25)
--- (11 headers 11 lines) ---
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:2239 __sip_ack: Acked pending
invite 102
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:2275 __sip_ack: Stopping
retransmission on '2176cbaa3be91d33437b376f2a7ca63f at acropolis.fr' of
Request 102: Match Found
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:13417 handle_response_invite:
SIP response 200 to standard invite
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 101
Found audio codec with Dynamic payload : 101.
Peer audio RTP is at port 217.64.49.10:8444
Found description format PCMU for codec ID 0
Found audio description format PCMU for ID 0
Found description format PCMA for codec ID 8
Found audio description format PCMA for ID 8
Found description format telephone-event for codec ID 101
Found audio description format telephone-event for ID 101
[Mar 26 13:27:23] WARNING[9798]: chan_sip.c:5538 parse_video_fmtp: Got
unsupported audio a:fmtp in SDP offer for codec ID 101
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:6074 process_sdp: T38 state
changed to 0 on channel SIP/acropolis-0138b5e0
[Mar 26 13:27:23] DEBUG[9798]: capability.c:398 ast_compute_max_audio_bw:
Computing max bandwidth for format 0000000c.
[Mar 26 13:27:23] DEBUG[9798]: capability.c:418 ast_compute_max_audio_bw:
Max bandwidth for format 0000000c is 64000 bps.
Peer audio RTP is at port 217.64.49.10:8444
Peer text RTP is at port 217.64.49.10:27651
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:6218 process_sdp: GDM : Peer
text RTP is at port 217.64.49.10:27651
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:6224 process_sdp: We're settling
with these formats: 0xc (ulaw|alaw)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:6231 process_sdp: We have an
owner, now see if we need to change this call
[Mar 26 13:27:23] DEBUG[9798]: channel.c:2768 set_format:
chan=SIP/acropolis-0138b5e0 format=00000004 (with video & text = 00000004)
native=00000004 in dir. read
[Mar 26 13:27:23] DEBUG[9798]: channel.c:2768 set_format:
chan=SIP/acropolis-0138b5e0 format=00000004 (with video & text = 00000004)
native=00000004 in dir. write
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:6254 process_sdp: Finally native
format for chan is 0x4 (ulaw)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:6255 process_sdp: Finally
jointcapability format for chan is 0xc (ulaw|alaw)
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:3342 update_call_counter:
Updating call counter for outgoing call
[Mar 26 13:27:23] DEBUG[9798]: devicestate.c:304
__ast_device_state_changed_literal: Notification of state change to be
queued on device/channel SIP/acropolis
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:9404 build_route: build_route:
Contact hop: <sip:0562919249 at 217.64.49.10>
list_route: hop: <sip:0562919249 at 217.64.49.10>
[Mar 26 13:27:23] DEBUG[9798]: chan_sip.c:6648 reqprep: Strict routing
enforced for session 2176cbaa3be91d33437b376f2a7ca63f at acropolis.fr
set_destination: Parsing <sip:0562919249 at 217.64.49.10> for address/port to
send to
set_destination: set destination to 217.64.49.10, port 5060
Transmitting (NAT) to 217.64.49.10:5060:
ACK sip:0562919249 at 217.64.49.10 SIP/2.0
Via: SIP/2.0/UDP 86.66.0.18:5090;branch=z9hG4bK7c0ca055;rport
From: "xxxxxxxx" <sip:anonymous at acropolis.fr>;tag=as3088bb3a
To: <sip:0562919249 at 217.64.49.10>;tag=as18d76027
Contact: <sip:anonymous at 86.66.0.18:5090>
Call-ID: 2176cbaa3be91d33437b376f2a7ca63f at acropolis.fr
CSeq: 102 ACK
User-Agent: Visio 4
Max-Forwards: 70
Content-Length: 0


---
[Mar 26 13:27:23] DEBUG[9780]: devicestate.c:161 ast_device_state: No
provider found, checking channel drivers for SIP - acropolis
[Mar 26 13:27:23] DEBUG[9780]: chan_sip.c:17301 sip_devicestate: Checking
device state for peer acropolis
[Mar 26 13:27:23] DEBUG[9780]: devicestate.c:287 do_state_change: Changing
state for SIP/acropolis - state 2 (In use)
[Mar 26 13:27:23] DEBUG[9782]: app_queue.c:668 handle_statechange: Device
'SIP/acropolis' changed to state '2' (In use) but we don't care because
they're not a member of any queu.
[Mar 26 13:27:23] DEBUG[15162]: devicestate.c:304
__ast_device_state_changed_literal: Notification of state change to be
queued on device/channel SIP/acropolis-0138b5e0
[Mar 26 13:27:23] DEBUG[15162]: devicestate.c:304
__ast_device_state_changed_literal: Notification of state change to be
queued on device/channel SIP/acropolis
[Mar 26 13:27:23] DEBUG[9780]: devicestate.c:161 ast_device_state: No
provider found, checking channel drivers for SIP - acropolis-0138b5e0
[Mar 26 13:27:23] DEBUG[15162]: cdr.c:709 ast_cdr_answer: CDR answer:
sending packet for channel SIP/acropolis-0138b5e0
    -- SIP/acropolis-0138b5e0 answered Local/0562919249 at filterNat-b067,2
[Mar 26 13:27:23] DEBUG[15162]: rtp.c:1523 ast_rtp_early_bridge: Channel
'Local/0562919249 at filterNat-b067,2' has no RTP, not doing anything
    -- Stopped music on hold on Local/0562919249 at filterNat-b067,2
[Mar 26 13:27:23] DEBUG[9780]: chan_sip.c:17301 sip_devicestate: Checking
device state for peer acropolis-0138b5e0
[Mar 26 13:27:23] DEBUG[15162]: channel.c:2768 set_format:
chan=Local/0562919249 at filterNat-b067,2 format=00000040 (with video & text =
00000040) native=00200040 in dir. write
[Mar 26 13:27:23] DEBUG[15162]: channel.c:3201
ast_channel_make_compatible: src chan Local/0562919249 at filterNat-b067,2
with format 00200040 to dst chan SIP/acropolis-0138b5e0 wit format
00000004
[Mar 26 13:27:23] DEBUG[15162]: channel.c:2768 set_format:
chan=Local/0562919249 at filterNat-b067,2 format=00000004 (with video & text =
00000004) native=00200040 in dir. read
[Mar 26 13:27:23] DEBUG[15162]: translate.c:275 ast_translator_build_path:
Building translator path from 00000040 to 00000004
[Mar 26 13:27:23] DEBUG[15162]: translate.c:284 ast_translator_build_path:
Step from path from 6 to 2
[Mar 26 13:27:23] DEBUG[15162]: channel.c:2807 set_format: Set channel
Local/0562919249 at filterNat-b067,2 to read format ulaw
[Mar 26 13:27:23] DEBUG[15162]: channel.c:2768 set_format:
chan=SIP/acropolis-0138b5e0 format=00000004 (with video & text = 00000004)
native=00000004 in dir. write
[Mar 26 13:27:23] DEBUG[15162]: channel.c:2768 set_format:
chan=SIP/acropolis-0138b5e0 format=00000040 (with video & text = 00000040)
native=00000004 in dir. read
[Mar 26 13:27:23] DEBUG[15162]: translate.c:275 ast_translator_build_path:
Building translator path from 00000004 to 00000040
[Mar 26 13:27:23] DEBUG[15162]: translate.c:284 ast_translator_build_path:
Step from path from 2 to 6
[Mar 26 13:27:23] DEBUG[15162]: channel.c:2807 set_format: Set channel
SIP/acropolis-0138b5e0 to read format slin
[Mar 26 13:27:23] DEBUG[15162]: channel.c:2768 set_format:
chan=Local/0562919249 at filterNat-b067,2 format=00000040 (with video & text =
00000040) native=00200040 in dir. write
[Mar 26 13:27:23] DEBUG[15162]: channel.c:3306 ast_channel_masquerade:
Planning to masquerade channel SIP/acropolis-0138b5e0 into the structure of
Local/0562919249 at filterNat-b0671
[Mar 26 13:27:23] DEBUG[15163]: channel.c:2575 ast_write: Deadlock avoided
for write to channel 'Local/0562919249 at filterNat-b067,1'
[Mar 26 13:27:23] DEBUG[15162]: channel.c:3320 ast_channel_masquerade:
Done planning to masquerade channel SIP/acropolis-0138b5e0 into the
structure of Local/0562919249 at filterNatb067,1
[Mar 26 13:27:23] DEBUG[15163]: channel.c:3429 ast_do_masquerade: Actually
Masquerading SIP/acropolis-0138b5e0(6) into the structure of
Local/0562919249 at filterNat-b067,1(6)
[Mar 26 13:27:23] DEBUG[15163]: channel.c:3441 ast_do_masquerade: Got
clone lock for masquerade on 'SIP/acropolis-0138b5e0' at 0x138fc40
[Mar 26 13:27:23] DEBUG[15162]: chan_local.c:312 local_write: Not posting
to queue since already masked on 'Local/0562919249 at filterNat-b067,2'
visio4*CLI>
Disconnected from Asterisk server 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2009-03-26 07:59 neutrino88     Note Added: 0102231                          
======================================================================




More information about the asterisk-bugs mailing list