[Home]

Summary:ASTERISK-15082: Crash of Outgoing Call
Reporter:Alessandro (alex70)Labels:
Date Opened:2009-11-05 06:26:20.000-0600Date Closed:2011-06-07 14:01:07
Priority:MajorRegression?Yes
Status:Closed/CompleteComponents:Channels/chan_sip/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) asterisk_log.txt
( 1) verbosity.txt
Description:Everyday our asterisk system updates itself with the most recent svn branch.
Last night asterisk update to revision r227947 and every outbound call falls as soon as the called pick up the phone.

Our suspect is there is something wrong with the patch uploaded by mnicholson  to resolve issue ASTERISK-14924 with:
R227829 | mnicholson | 2009-11-04 15:03:33 -0600 (Wed, 04 Nov 2009) | 17 lines - "This patch modifies the Dial application to monitor the calling channel for hangups while playing back announcements"

Please see also attached verbosity file

****** ADDITIONAL INFORMATION ******

OS Version:
Linux ghelis.it 2.6.30.8-64.fc11.i686.PAE #1 SMP Fri Sep 25 04:56:58 EDT 2009 i686 i686 i386 GNU/Linux

Asterisk Build:
Asterisk/SVN-branch-1.6.2-r227947
Asterisk GUI-version : SVN-branch-2.0-r4991
Comments:By: Alessandro (alex70) 2009-11-10 14:23:59.000-0600

The present note just to inform you that I have had to downgrade to 1.6.1.9 and asterisk system works like a charm.
By: Walter Klomp (xblurone) 2009-11-10 23:44:02.000-0600

I am having exactly the same issue... here an excerpt from the full log file... As soon as the call is answered, asterisk hangs-up the call... unfortunately I can't downgrade to 1.6.1.9 as asterisk then dies at random every day after a few hours.

Sip client -> Dahdi/PRI PSTN works fine
Sip client -> Sip provider PSTN hangs up after answer. (90% of the time)

[2009-11-11 13:24:08] DEBUG[5001] pbx.c: Launching 'Dial'
[2009-11-11 13:24:08] VERBOSE[5001] pbx.c: [2009-11-11 13:24:08]     -- Executing [98765432@aglow:1] Dial("SIP/63115000-00000034", "SIP/#1146598765432@xxx.yyy.zzz.177,40") in new stack
[2009-11-11 13:24:08] DEBUG[5001] chan_sip.c: Asked to create a SIP channel with formats: 0x1 (g723)
[2009-11-11 13:24:08] VERBOSE[5001] netsock.c: [2009-11-11 13:24:08]   == Using SIP RTP TOS bits 184
[2009-11-11 13:24:08] VERBOSE[5001] netsock.c: [2009-11-11 13:24:08]   == Using SIP RTP CoS mark 5
[2009-11-11 13:24:08] VERBOSE[5001] netsock.c: [2009-11-11 13:24:08]   == Using SIP VRTP TOS bits 136
[2009-11-11 13:24:08] VERBOSE[5001] netsock.c: [2009-11-11 13:24:08]   == Using SIP VRTP CoS mark 6
[2009-11-11 13:24:08] VERBOSE[5001] netsock.c: [2009-11-11 13:24:08]   == Using UDPTL TOS bits 184
[2009-11-11 13:24:08] VERBOSE[5001] netsock.c: [2009-11-11 13:24:08]   == Using UDPTL CoS mark 5
[2009-11-11 13:24:08] DEBUG[5001] chan_sip.c: Allocating new SIP dialog for 75ba8b8570a885191c51f28675e8356f@202.42.66.17 - INVITE (With RTP)
[2009-11-11 13:24:08] DEBUG[5001] chan_sip.c: Setting NAT on RTP to Off
[2009-11-11 13:24:08] DEBUG[5001] chan_sip.c: Setting NAT on UDPTL to Off
[2009-11-11 13:24:08] DEBUG[5001] channel.c: Not copying variable DIALEDTIME.
[2009-11-11 13:24:08] DEBUG[5001] channel.c: Not copying variable ANSWEREDTIME.
[2009-11-11 13:24:08] DEBUG[5001] channel.c: Not copying variable DIALEDPEERNAME.
[2009-11-11 13:24:08] DEBUG[5001] channel.c: Not copying variable DIALEDPEERNUMBER.
[2009-11-11 13:24:08] DEBUG[5001] channel.c: Not copying variable DIALSTATUS.
[2009-11-11 13:24:08] DEBUG[5001] channel.c: Not copying variable SIPCALLID.
[2009-11-11 13:24:08] DEBUG[5001] channel.c: Not copying variable SIPDOMAIN.
[2009-11-11 13:24:08] DEBUG[5001] channel.c: Not copying variable SIPURI.
[2009-11-11 13:24:08] DEBUG[5001] chan_sip.c: Outgoing Call for #1146598765432
[2009-11-11 13:24:08] DEBUG[5001] chan_sip.c: ** Our capability: 0x100 (g729) Video flag: False Text flag: False
[2009-11-11 13:24:08] DEBUG[5001] chan_sip.c: ** Our prefcodec: 0x1 (g723)
[2009-11-11 13:24:08] DEBUG[5001] chan_sip.c: Initializing initreq for method INVITE - callid 6dfc0e524a7a2805201a3c470c008a98@xxx.yyy.zzz.134
[2009-11-11 13:24:08] DEBUG[5001] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for xxx.yyy.zzz.177:5060
[2009-11-11 13:24:08] VERBOSE[5001] app_dial.c: [2009-11-11 13:24:08]     -- Called #1146598765432@xxx.yyy.zzz.177
[2009-11-11 13:24:14] VERBOSE[5001] app_dial.c: [2009-11-11 13:24:14]     -- SIP/xxx.yyy.zzz.177-00000035 is making progress passing it to SIP/63115000-00000034
[2009-11-11 13:24:14] DEBUG[5001] chan_sip.c: ** Our capability: 0x1 (g723) Video flag: True Text flag: True
[2009-11-11 13:24:14] DEBUG[5001] chan_sip.c: ** Our prefcodec: 0x0 (nothing)
[2009-11-11 13:24:14] DEBUG[5001] chan_sip.c: Trying to put 'SIP/2.0 183' onto UDP socket destined for xxx.yyy.zzz.168:5060
[2009-11-11 13:24:14] DEBUG[5001] rtp.c: Ooh, format changed from unknown to g729
[2009-11-11 13:24:14] DEBUG[5001] rtp.c: Created smoother: format: 256 ms: 20 len: 20
[2009-11-11 13:24:14] DEBUG[5001] rtp.c: Ooh, format changed from unknown to g723
[2009-11-11 13:24:14] DEBUG[5001] rtp.c: Got RTCP report of 112 bytes
[2009-11-11 13:24:17] DEBUG[5001] rtp.c: Got RTCP report of 112 bytes
[2009-11-11 13:24:17] VERBOSE[5001] app_dial.c: [2009-11-11 13:24:17]     -- SIP/xxx.yyy.zzz.177-00000035 answered SIP/63115000-00000034
[2009-11-11 13:24:17] DEBUG[5001] chan_sip.c: SIP answering channel: SIP/63115000-00000034
[2009-11-11 13:24:17] DEBUG[5001] chan_sip.c: ** Our capability: 0x1 (g723) Video flag: True Text flag: True
[2009-11-11 13:24:17] DEBUG[5001] chan_sip.c: ** Our prefcodec: 0x0 (nothing)
[2009-11-11 13:24:17] DEBUG[5001] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for xxx.yyy.zzz.168:5060
[2009-11-11 13:24:22] DEBUG[5001] channel.c: Didn't get a frame from channel: SIP/63115000-00000034
[2009-11-11 13:24:22] DEBUG[5001] channel.c: Bridge stops bridging channels SIP/63115000-00000034 and SIP/xxx.yyy.zzz.177-00000035
[2009-11-11 13:24:22] DEBUG[5001] channel.c: Hanging up channel 'SIP/xxx.yyy.zzz.177-00000035'
[2009-11-11 13:24:22] DEBUG[5001] chan_sip.c: Hangup call SIP/xxx.yyy.zzz.177-00000035, SIP callid 6dfc0e524a7a2805201a3c470c008a98@xxx.yyy.zzz.134
[2009-11-11 13:24:22] DEBUG[5001] chan_sip.c: Trying to put 'BYE sip:116' onto UDP socket destined for xxx.yyy.zzz.177:5060
[2009-11-11 13:24:22] DEBUG[5001] rtp.c: Channel '<unspecified>' has no RTP, not doing anything
[2009-11-11 13:24:22] DEBUG[5001] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[2009-11-11 13:24:22] DEBUG[5001] pbx.c: Spawn extension (aglow,98765432,1) exited non-zero on 'SIP/63115000-00000034'
[2009-11-11 13:24:22] VERBOSE[5001] pbx.c: [2009-11-11 13:24:22]   == Spawn extension (aglow, 98765432, 1) exited non-zero on 'SIP/63115000-00000034'
[2009-11-11 13:24:22] DEBUG[5001] channel.c: Soft-Hanging up channel 'SIP/63115000-00000034'
[2009-11-11 13:24:22] DEBUG[5001] channel.c: Hanging up channel 'SIP/63115000-00000034'
[2009-11-11 13:24:22] DEBUG[5001] chan_sip.c: Hangup call SIP/63115000-00000034, SIP callid e3617b44-8d4fcd2b@xxx.yyy.zzz.168
By: Walter Klomp (xblurone) 2009-11-10 23:48:49.000-0600

incidentally exactly the same thing happens when I try to initiate a callback call with a .call file. If I use Dahdi, all is dandy, but if I use SIP providers (same providers work fine with 1.4.26.2) it disconnects immediately after answer, and then still tries to dial the destination, answering that one gives silence and instant disconnect as well...

Using a SIP client I do hear the real ringing tone.
By: Walter Klomp (xblurone) 2009-11-10 23:50:11.000-0600

Sorry, forgot to add, my linux version: 2.6.23.17-88.fc7
and asterisk version: Asterisk SVN-branch-1.6.1-r229364
By: Alessandro (alex70) 2009-11-11 11:35:06.000-0600

I have just uploaded the log file related to an outbound call under asterisk 1.6.2 r227947. Hoping that it is of help.

I would like also to advise to change the severity of this bug from majority to block as asterisk system cannot be used at all to call but just to receive.
By: Ziga Pirnar (zpirnar) 2009-11-16 05:21:17.000-0600

I am afraid we are experiencing the exact same problem (even under 1.6.2rc6 released a few days ago), all outgoing calls get dropped as soon as the call is answered.

[2009-11-16 11:59:52.687] WARNING[24675]: chan_sip.c:3973 __sip_autodestruct: Autodestruct on dialog '049cb08574fd696617fb06130f16df33@10.142.0.89' with owner in place (Method: INVITE)

Although you have chosen to downgrade the severity of this bug to major I still believe it should be set to blocked as the system can not be used to make outgoing sip calls at all, hence we had to downgrade to 1.6.1.9.
By: Ziga Pirnar (zpirnar) 2009-11-16 13:56:11.000-0600

Thank you for providing the information regarding the related issue (0016238).
Adding ignoresdpversion=yes to sip.conf solved the problem with outgoing calls.
By: Alessandro (alex70) 2009-11-16 16:16:38.000-0600

Thank you for the advise. I have re-upgraded to Asterisk/SVN-branch-1.6.2-r230384 and set ignoresdpversion=yes. Now outgoing calls work properly.

I would like to understand if this is just a momentary workaround or is a correct procedure to keep for the future.
By: Andy Brodmann (macbrody) 2009-11-25 05:31:23.000-0600

We face the same problem here with an asterisk-1.6.2-rc6 / ignoredspversion=yes
also works.

As alex70 I would like to know if the ignoredspversion=yes is a temporary
workaround or if this means there is something wrong between us and our carrier
and ignoring the dspversion works around it and it is not regarded as real issue.
By: Tilghman Lesher (tilghman) 2009-11-30 10:54:24.000-0600

As evidenced by the SIP dialog, "ignoresdpversion" is indeed the correct fix, as we would otherwise ignore SDP offers where the version has not changed.  A correctly implemented client should increment the version number each time there is a change in the SDP offer.