[asterisk-bugs] [JIRA] (ASTERISK-23979) IAX2 trunk dial status and hangup cause not sent to SIP endpoint
Rusty Newton (JIRA)
noreply at issues.asterisk.org
Tue Jul 1 20:14:57 CDT 2014
[ https://issues.asterisk.org/jira/browse/ASTERISK-23979?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Rusty Newton updated ASTERISK-23979:
------------------------------------
Assignee: David Herselman
Status: Waiting for Feedback (was: Triage)
Can you post your configuration for the IAX trunks and SIP endpoints so that the scenario can be easily replicated? That means, please simplify the configuration and if you can test it without your provider involved to make sure the same behavior happens.
> IAX2 trunk dial status and hangup cause not sent to SIP endpoint
> ----------------------------------------------------------------
>
> Key: ASTERISK-23979
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-23979
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Channels/chan_sip/General
> Affects Versions: 11.9.0
> Environment: IAX2 trunk with SIP end points
> Reporter: David Herselman
> Assignee: David Herselman
> Severity: Critical
>
> This is a long standing issue, with an existing bug report dating back to Asterisk 1.4, being reported in 2010 (ASTERISK-15925).
> IAX2 trunk call termination status (DIALSTATUS and HANGUPCAUSE) received from upstream system is not translated to SIP end points. Calling a busy number results in SIP end point simply hanging up the call with normal clearing.
> {noformat}
> SIP provider ----- Asterisk A ===IAX2=== Asterisk B ----- SIP end point
> {noformat}
> SIP provider: ECN
> Asterisk A: IP of 192.25.69.236
> Asterisk B: 0117211900 as IAX2 trunk
> SIP end point: 'David Herselman' extension 1904 on lair.co.za
> Busy destination: (+27 | 0) 110509058
> Asterisk A appears to correctly translate correct DIALSTATUS and HANGUPCAUSE from SIP provider via IAX2 trunk (ie SIP to IAX2 appears to work correctly):
> {noformat}
> -- Executing [27110509058 at custom-freepbx-a2billing:1] DeadAGI("IAX2/0117211900-2043", "a2billing.php,1") in new stack
> [2014-07-01 02:17:16] WARNING[8957][C-0006a204]: res_agi.c:4005 deadagi_exec: DeadAGI has been deprecated, please use AGI in all cases!
> -- Launched AGI Script /var/lib/asterisk/agi-bin/a2billing.php
> -- AGI Script Executing Application: (DIAL) Options: (SIP/ECN/0110509058,60,HRL(36000000:61000:30000))
> > Limit Data for this call:
> > timelimit = 36000000 ms (36000.000 s)
> > play_warning = 61000 ms (61.000 s)
> > play_to_caller = yes
> > play_to_callee = no
> > warning_freq = 30000 ms (30.000 s)
> > start_sound =
> > warning_sound = timeleft
> > end_sound =
> == Using SIP RTP TOS bits 184
> == Using SIP RTP CoS mark 5
> -- Called SIP/ECN/0110509058
> -- Got SIP response 486 "Busy here" back from 14.122.0.33:5060
> -- SIP/ECN-0006ca27 is busy
> == Everyone is busy/congested at this time (1:1/0/0)
> -- AGI Script Executing Application: (Busy) Options: (1)
> -- <IAX2/0117211900-2043>AGI Script a2billing.php completed, returning 4
> == Spawn extension (custom-freepbx-a2billing, 27110509058, 1) exited non-zero on 'IAX2/0117211900-2043'
> -- Executing [h at custom-freepbx-a2billing:1] NoOp("IAX2/0117211900-2043", "h: Dial status: BUSY Hangup cause: 17") in new stack
> -- Executing [h at custom-freepbx-a2billing:2] Set("IAX2/0117211900-2043", "RC=17") in new stack
> -- Executing [h at custom-freepbx-a2billing:3] ExecIf("IAX2/0117211900-2043", "1?Playtones(busy)") in new stack
> -- Executing [h at custom-freepbx-a2billing:4] ExecIf("IAX2/0117211900-2043", "1?Wait(20)") in new stack
> == Spawn extension (custom-freepbx-a2billing, h, 4) exited non-zero on 'IAX2/0117211900-2043'
> -- Hungup 'IAX2/0117211900-2043'
> {noformat}
> Asterisk B appears to correct identify 'CAUSE CODE' as 17 on the IAX2 trunk but SIP end point gets HANGUP CAUSE 16 (normal clearing). The interesting bits:
> {noformat}
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: CONTROL Subclass: BUSY
> Timestamp: 01391ms SCall: 02043 DCall: 24152 [192.25.69.236:4569]
> Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 005 Type: IAX Subclass: ACK
> Timestamp: 01391ms SCall: 24152 DCall: 02043 [192.25.69.236:4569]
> -- Executing [h at macro-dialout-trunk:1] NoOp("SIP/1904-00009c84", "h: Dial status: ANSWER Hangup cause: 16") in new stack
> <snip>
> Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 005 Type: IAX Subclass: HANGUP
> Timestamp: 01419ms SCall: 24152 DCall: 02043 [192.25.69.236:4569]
> CAUSE CODE : 17
> {noformat}
> Full debug on both IAX2 and SIP traffic, on Asterisk B system. Please note that I had attempted to add busy call handling (the '0?Goto(macro-dialout-trunk,s-BUSY,1)' piece) but this doesn't work as the call had already been hungup:
> {noformat}
> -- Executing [s at macro-dialout-trunk:22] Dial("SIP/1904-00009c84", "IAX2/Syrex/0110509058,300,tL(10800000:300000)") in new stack
> > Limit Data for this call:
> > timelimit = 10800000 ms (10800.000 s)
> > play_warning = 300000 ms (300.000 s)
> > play_to_caller = yes
> > play_to_callee = no
> > warning_freq = 0 ms (0.000 s)
> > start_sound =
> > warning_sound = timeleft
> > end_sound =
> -- Called IAX2/Syrex/0110509058
> Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW
> Timestamp: 00003ms SCall: 24152 DCall: 00000 [192.25.69.236:4569]
> VERSION : 2
> CALLED NUMBER : 0110509058
> CODEC_PREFS : (g729)
> CALLING NUMBER : 0861179739
> CALLING PRESNTN : 0
> CALLING TYPEOFN : 0
> CALLING TRANSIT : 0
> CALLING NAME : Syrex
> LANGUAGE : en
> USERNAME : 0117211900
> FORMAT : 256
> FORMAT2 : g729
> CAPABILITY : 256
> CAPABILITY2 : g729
> ADSICPE : 2
> DATE TIME : 2014-07-01 02:17:16
> VARIABLE : X-CallerID="Syrex" <0861179739>
> Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: CTOKEN
> Timestamp: 00003ms SCall: 00001 DCall: 24152 [192.25.69.236:4569]
> CALLTOKEN : 51 bytes
> Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW
> Timestamp: 00009ms SCall: 24152 DCall: 00000 [192.25.69.236:4569]
> VERSION : 2
> CALLED NUMBER : 0110509058
> CODEC_PREFS : (g729)
> CALLING NUMBER : 0861179739
> CALLING PRESNTN : 0
> CALLING TYPEOFN : 0
> CALLING TRANSIT : 0
> CALLING NAME : Syrex
> LANGUAGE : en
> USERNAME : 0117211900
> FORMAT : 256
> FORMAT2 : g729
> CAPABILITY : 256
> CAPABILITY2 : g729
> ADSICPE : 2
> DATE TIME : 2014-07-01 02:17:16
> VARIABLE : X-CallerID="Syrex" <0861179739>
> CALLTOKEN : 51 bytes
> Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: AUTHREQ
> Timestamp: 00014ms SCall: 02043 DCall: 24152 [192.25.69.236:4569]
> AUTHMETHODS : 3
> CHALLENGE : \x37\x38\x33\x33\x32\x30\x38\x34\x38
> USERNAME : 0117211900
> Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: AUTHREP
> Timestamp: 00019ms SCall: 24152 DCall: 02043 [192.25.69.236:4569]
> MD5 RESULT : bc48027f52791960c81018f71a8e17e2
> Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: ACCEPT
> Timestamp: 00022ms SCall: 02043 DCall: 24152 [192.25.69.236:4569]
> FORMAT : 256
> FORMAT2 : g729
> -- Call accepted by 192.25.69.236 (format g729)
> -- Format for call is (g729)
> Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK
> Timestamp: 00022ms SCall: 24152 DCall: 02043 [192.25.69.236:4569]
> Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass: ANSWER
> Timestamp: 00025ms SCall: 02043 DCall: 24152 [192.25.69.236:4569]
> Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 003 Type: IAX Subclass: ACK
> Timestamp: 00025ms SCall: 24152 DCall: 02043 [192.25.69.236:4569]
> Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 002 Type: CONTROL Subclass: (255?)
> Timestamp: 00028ms SCall: 02043 DCall: 24152 [192.25.69.236:4569]
> Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 004 Type: IAX Subclass: ACK
> Timestamp: 00028ms SCall: 24152 DCall: 02043 [192.25.69.236:4569]
> -- IAX2/Syrex-24152 answered SIP/1904-00009c84
> Audio is at 13120
> Adding codec 100004 (alaw) to SDP
> Adding codec 100003 (ulaw) to SDP
> Adding codec 100008 (g729) to SDP
> Adding non-codec 0x1 (telephone-event) to SDP
> <--- Reliably Transmitting (NAT) to 192.168.10.53:11468 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 192.168.10.53:11468;branch=z9hG4bK-d8754z-f01dde7fb476187a-1---d8754z-;received=192.168.10.53;rport=11468
> From: "David Herselman"<sip:1904 at lair.co.za>;tag=455f2257
> To: "0110509058"<sip:0110509058 at lair.co.za>;tag=as3b114d0c
> Call-ID: NTBkYjFmYTYwNmNiMDZmN2E5ZWU1ZDkwM2JiNWExMGU.
> CSeq: 2 INVITE
> Server: FPBX-2.11.0(11.9.0)
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
> Supported: replaces, timer
> Contact: <sip:0110509058 at 192.168.1.11:5060>
> P-Asserted-Identity: "CID:0861179739" <sip:0110509058 at lair.co.za>
> Content-Type: application/sdp
> Content-Length: 306
> v=0
> o=root 1222277392 1222277392 IN IP4 192.168.1.11
> s=Asterisk PBX 11.9.0
> c=IN IP4 192.168.1.11
> t=0 0
> m=audio 13120 RTP/AVP 8 0 18 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
> a=sendrecv
> <------------>
> > 0x534b9d0 -- Probation passed - setting RTP source address to 192.168.10.53:28102
> Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 004 Type: VOICE Subclass: 136
> Timestamp: 00242ms SCall: 24152 DCall: 02043 [192.25.69.236:4569]
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: IAX Subclass: ACK
> Timestamp: 00242ms SCall: 02043 DCall: 24152 [192.25.69.236:4569]
> Retransmitting #1 (NAT) to 192.168.10.53:11468:
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 192.168.10.53:11468;branch=z9hG4bK-d8754z-f01dde7fb476187a-1---d8754z-;received=192.168.10.53;rport=11468
> From: "David Herselman"<sip:1904 at lair.co.za>;tag=455f2257
> To: "0110509058"<sip:0110509058 at lair.co.za>;tag=as3b114d0c
> Call-ID: NTBkYjFmYTYwNmNiMDZmN2E5ZWU1ZDkwM2JiNWExMGU.
> CSeq: 2 INVITE
> Server: FPBX-2.11.0(11.9.0)
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
> Supported: replaces, timer
> Contact: <sip:0110509058 at 192.168.1.11:5060>
> P-Asserted-Identity: "CID:0861179739" <sip:0110509058 at lair.co.za>
> Content-Type: application/sdp
> Content-Length: 306
> v=0
> o=root 1222277392 1222277392 IN IP4 192.168.1.11
> s=Asterisk PBX 11.9.0
> c=IN IP4 192.168.1.11
> t=0 0
> m=audio 13120 RTP/AVP 8 0 18 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=ptime:20
> a=sendrecv
> ---
> <--- SIP read from UDP:192.168.10.53:11468 --->
> ACK sip:0110509058 at 192.168.1.11:5060 SIP/2.0
> Via: SIP/2.0/UDP 192.168.10.53:11468;branch=z9hG4bK-d8754z-196e134d872d0263-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:1904 at 192.168.10.53:11468>
> To: "0110509058"<sip:0110509058 at lair.co.za>;tag=as3b114d0c
> From: "David Herselman"<sip:1904 at lair.co.za>;tag=455f2257
> Call-ID: NTBkYjFmYTYwNmNiMDZmN2E5ZWU1ZDkwM2JiNWExMGU.
> CSeq: 2 ACK
> User-Agent: eyeBeam release 1102u stamp 52344
> Authorization: Digest username="1904",realm="asterisk",nonce="66728a2b",uri="sip:0110509058 at lair.co.za",response="fcee593a5da05f1858473837077ed8a4",algorithm=MD5
> Content-Length: 0
> <------------->
> --- (11 headers 0 lines) ---
> <--- SIP read from UDP:192.168.10.53:11468 --->
> ACK sip:0110509058 at 192.168.1.11:5060 SIP/2.0
> Via: SIP/2.0/UDP 192.168.10.53:11468;branch=z9hG4bK-d8754z-196e134d872d0263-1---d8754z-;rport
> Max-Forwards: 70
> Contact: <sip:1904 at 192.168.10.53:11468>
> To: "0110509058"<sip:0110509058 at lair.co.za>;tag=as3b114d0c
> From: "David Herselman"<sip:1904 at lair.co.za>;tag=455f2257
> Call-ID: NTBkYjFmYTYwNmNiMDZmN2E5ZWU1ZDkwM2JiNWExMGU.
> CSeq: 2 ACK
> User-Agent: eyeBeam release 1102u stamp 52344
> Authorization: Digest username="1904",realm="asterisk",nonce="66728a2b",uri="sip:0110509058 at lair.co.za",response="fcee593a5da05f1858473837077ed8a4",algorithm=MD5
> Content-Length: 0
> <------------->
> --- (11 headers 0 lines) ---
> Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: CONTROL Subclass: BUSY
> Timestamp: 01391ms SCall: 02043 DCall: 24152 [192.25.69.236:4569]
> Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 005 Type: IAX Subclass: ACK
> Timestamp: 01391ms SCall: 24152 DCall: 02043 [192.25.69.236:4569]
> -- Executing [h at macro-dialout-trunk:1] NoOp("SIP/1904-00009c84", "h: Dial status: ANSWER Hangup cause: 16") in new stack
> -- Executing [h at macro-dialout-trunk:2] ExecIf("SIP/1904-00009c84", "0?Goto(macro-dialout-trunk,s-BUSY,1)") in new stack
> -- Executing [h at macro-dialout-trunk:3] Macro("SIP/1904-00009c84", "hangupcall,") in new stack
> -- Executing [s at macro-hangupcall:1] GotoIf("SIP/1904-00009c84", "1?theend") in new stack
> -- Goto (macro-hangupcall,s,3)
> -- Executing [s at macro-hangupcall:3] ExecIf("SIP/1904-00009c84", "0?Set(CDR(recordingfile)=)") in new stack
> -- Executing [s at macro-hangupcall:4] Hangup("SIP/1904-00009c84", "") in new stack
> == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/1904-00009c84' in macro 'hangupcall'
> == Spawn extension (macro-dialout-trunk, h, 3) exited non-zero on 'SIP/1904-00009c84'
> -- Hungup 'IAX2/Syrex-24152'
> Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 005 Type: IAX Subclass: HANGUP
> Timestamp: 01419ms SCall: 24152 DCall: 02043 [192.25.69.236:4569]
> CAUSE CODE : 17
> == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on 'SIP/1904-00009c84' in macro 'dialout-trunk'
> == Spawn extension (from-internal, 0110509058, 6) exited non-zero on 'SIP/1904-00009c84'
> Scheduling destruction of SIP dialog 'NTBkYjFmYTYwNmNiMDZmN2E5ZWU1ZDkwM2JiNWExMGU.' in 6400 ms (Method: ACK)
> set_destination: Parsing <sip:1904 at 192.168.10.53:11468> for address/port to send to
> set_destination: set destination to 192.168.10.53:11468
> Reliably Transmitting (NAT) to 192.168.10.53:11468:
> BYE sip:1904 at 192.168.10.53:11468 SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.11:5060;branch=z9hG4bK0950d4f3;rport
> Max-Forwards: 70
> From: "0110509058"<sip:0110509058 at lair.co.za>;tag=as3b114d0c
> To: "David Herselman"<sip:1904 at lair.co.za>;tag=455f2257
> Call-ID: NTBkYjFmYTYwNmNiMDZmN2E5ZWU1ZDkwM2JiNWExMGU.
> CSeq: 102 BYE
> User-Agent: FPBX-2.11.0(11.9.0)
> Proxy-Authorization: Digest username="1904", realm="asterisk", algorithm=MD5, uri="sip:lair.co.za", nonce="66728a2b", response="749618b1eff00313deaf0f456f32dc70"
> X-Asterisk-HangupCause: Normal Clearing
> X-Asterisk-HangupCauseCode: 16
> Content-Length: 0
> ---
> == Extension Changed 1904[ext-local] new state Idle for Notify User 1964
> == MixMonitor close filestream (mixed)
> == End MixMonitor Recording SIP/1904-00009c84
> == Extension Changed 1904[ext-local] new state Idle for Notify User 1966
> == Extension Changed 1904[ext-local] new state Idle for Notify User 1927
> == Extension Changed 1904[ext-local] new state Idle for Notify User 1946
> Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: IAX Subclass: ACK
> Timestamp: 01419ms SCall: 02043 DCall: 24152 [192.25.69.236:4569]
> Retransmitting #1 (NAT) to 192.168.10.53:11468:
> BYE sip:1904 at 192.168.10.53:11468 SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.11:5060;branch=z9hG4bK0950d4f3;rport
> Max-Forwards: 70
> From: "0110509058"<sip:0110509058 at lair.co.za>;tag=as3b114d0c
> To: "David Herselman"<sip:1904 at lair.co.za>;tag=455f2257
> Call-ID: NTBkYjFmYTYwNmNiMDZmN2E5ZWU1ZDkwM2JiNWExMGU.
> CSeq: 102 BYE
> User-Agent: FPBX-2.11.0(11.9.0)
> Proxy-Authorization: Digest username="1904", realm="asterisk", algorithm=MD5, uri="sip:lair.co.za", nonce="66728a2b", response="749618b1eff00313deaf0f456f32dc70"
> X-Asterisk-HangupCause: Normal Clearing
> X-Asterisk-HangupCauseCode: 16
> Content-Length: 0
> ---
> <--- SIP read from UDP:192.168.10.53:11468 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 192.168.1.11:5060;branch=z9hG4bK0950d4f3;rport=5060
> Contact: <sip:1904 at 192.168.10.53:11468>
> To: "David Herselman"<sip:1904 at lair.co.za>;tag=455f2257
> From: "0110509058"<sip:0110509058 at lair.co.za>;tag=as3b114d0c
> Call-ID: NTBkYjFmYTYwNmNiMDZmN2E5ZWU1ZDkwM2JiNWExMGU.
> CSeq: 102 BYE
> User-Agent: eyeBeam release 1102u stamp 52344
> Content-Length: 0
> <------------->
> --- (9 headers 0 lines) ---
> SIP Response message for INCOMING dialog BYE arrived
> Really destroying SIP dialog 'NTBkYjFmYTYwNmNiMDZmN2E5ZWU1ZDkwM2JiNWExMGU.' Method: ACK
> <--- SIP read from UDP:192.168.10.53:11468 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 192.168.1.11:5060;branch=z9hG4bK0950d4f3;rport=5060
> Contact: <sip:1904 at 192.168.10.53:11468>
> To: "David Herselman"<sip:1904 at lair.co.za>;tag=455f2257
> From: "0110509058"<sip:0110509058 at lair.co.za>;tag=as3b114d0c
> Call-ID: NTBkYjFmYTYwNmNiMDZmN2E5ZWU1ZDkwM2JiNWExMGU.
> CSeq: 102 BYE
> User-Agent: eyeBeam release 1102u stamp 52344
> Content-Length: 0
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list