[asterisk-bugs] [JIRA] (ASTERISK-23979) IAX2 trunk dial status and hangup cause not sent to SIP endpoint

David Herselman (JIRA) noreply at issues.asterisk.org
Tue Jul 1 17:00:56 CDT 2014


     [ https://issues.asterisk.org/jira/browse/ASTERISK-23979?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

David Herselman updated ASTERISK-23979:
---------------------------------------

    Description: 
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}

  was:
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 B: 0117211900 as IAX2 trunk
Busy destination: (+27 | 0) 110509058

Asterisk A appears to correctly translate correct DIALSTATUS and HANGUPCAUSE from SIP provider via IAX2 trunk:
{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 but SIP end point gets HANGUP CAUSE of 16 (normal clearing):
{noformat}
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: CONTROL Subclass: BUSY
   Timestamp: 01391ms  SCall: 02043  DCall: 24152 [196.25.69.236:4569]
Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 005 Type: IAX     Subclass: ACK
   Timestamp: 01391ms  SCall: 24152  DCall: 02043 [196.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 [196.25.69.236:4569]
   CAUSE CODE      : 17
{noformat}


Full debug on both IAX2 and SIP from Asterisk B system (I had tried to specify '0?Goto(macro-dialout-trunk,s-BUSY,1)' but this doesn't work as the call has already been terminated:
{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 [196.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 [196.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 [196.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 [196.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 [196.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 [196.25.69.236:4569]
   FORMAT          : 256
   FORMAT2         : g729

    -- Call accepted by 196.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 [196.25.69.236:4569]
Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 002 Type: CONTROL Subclass: ANSWER
   Timestamp: 00025ms  SCall: 02043  DCall: 24152 [196.25.69.236:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 003 Type: IAX     Subclass: ACK
   Timestamp: 00025ms  SCall: 24152  DCall: 02043 [196.25.69.236:4569]
Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 002 Type: CONTROL Subclass: (255?)
   Timestamp: 00028ms  SCall: 02043  DCall: 24152 [196.25.69.236:4569]
Tx-Frame Retry[-01] -- OSeqno: 002 ISeqno: 004 Type: IAX     Subclass: ACK
   Timestamp: 00028ms  SCall: 24152  DCall: 02043 [196.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 [196.25.69.236:4569]
Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: IAX     Subclass: ACK
   Timestamp: 00242ms  SCall: 02043  DCall: 24152 [196.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 [196.25.69.236:4569]
Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 005 Type: IAX     Subclass: ACK
   Timestamp: 01391ms  SCall: 24152  DCall: 02043 [196.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 [196.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 [196.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}


> 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
>            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