Sound Problem - propably UDP issue - what to debug next?

General Help
1

I installed FreePBX Stable-5.211.65-11 on Microsoft Azure Virtual Machine, I created UDP endpoints range 10001 to 10005. I configured NAT to yes.
I configured two extension and they register OK. But when I make a call there is no sound and after a moment there is hangup.

[2014-04-19 08:42:47] WARNING[1769]: chan_sip.c:3984 retrans_pkt: Retransmission timeout reached on transmission OTBkYTcyMzlhNDczYjk0NWY3OTFiNDk1N2QyMTFhNTI. for seqno 2 (Critical Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[2014-04-19 08:42:47] WARNING[1769]: chan_sip.c:4013 retrans_pkt: Hanging up call OTBkYTcyMzlhNDczYjk0NWY3OTFiNDk1N2QyMTFhNTI. - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).

It seems for me for UDP transmission problem with Microsoft Azure Virtual Machine (I can use other Asterisk with public IP).

Any idea what to debug next?

FreePBX*CLI> sip show settings

Global Settings:

UDP Bindaddress: 0.0.0.0:5060
TCP SIP Bindaddress: Disabled
TLS SIP Bindaddress: Disabled
Videosupport: No
Textsupport: No
Ignore SDP sess. ver.: No
AutoCreate Peer: No
Match Auth Username: No
Allow unknown access: Yes
Allow subscriptions: Yes
Allow overlap dialing: Yes
Allow promisc. redir: No
Enable call counters: No
SIP domain support: No
Realm. auth: No
Our auth realm asterisk
Use domains as realms: No
Call to non-local dom.: Yes
URI user is phone no: No
Always auth rejects: Yes
Direct RTP setup: No
User Agent: FPBX-2.11.0(1.8.26.1)
SDP Session Name: Asterisk PBX 1.8.26.1
SDP Owner Name: root
Reg. context: (not set)
Regexten on Qualify: No
Legacy userfield parse: No
Caller ID: Unknown
From: Domain:
Record SIP history: Off
Call Events: Off
Auth. Failure Events: Off
T.38 support: No
T.38 EC mode: Unknown
T.38 MaxDtgrm: -1
SIP realtime: Disabled
Qualify Freq : 60000 ms
Q.850 Reason header: No
Store SIP_CAUSE: No

Network QoS Settings:

IP ToS SIP: CS3
IP ToS RTP audio: EF
IP ToS RTP video: AF41
IP ToS RTP text: CS0
802.1p CoS SIP: 4
802.1p CoS RTP audio: 5
802.1p CoS RTP video: 6
802.1p CoS RTP text: 5
Jitterbuffer enabled: No

Network Settings:

SIP address remapping: Disabled, no localnet list
Externhost:
Externaddr: (null)
Externrefresh: 10

Global Signalling Settings:

Codecs: 0x1c0f (g723|gsm|ulaw|alaw|g726|ilbc|g722)
Codec Order: ilbc:30,gsm:20,g726:20,g723:30,g722:20,ulaw:20,alaw:20
Relax DTMF: No
RFC2833 Compensation: No
Symmetric RTP: Yes
Compact SIP headers: No
RTP Keepalive: 0 (Disabled)
RTP Timeout: 30
RTP Hold Timeout: 300
MWI NOTIFY mime type: application/simple-message-summary
DNS SRV lookup: No
Pedantic SIP support: Yes
Reg. min duration 60 secs
Reg. max duration: 3600 secs
Reg. default duration: 120 secs
Outbound reg. timeout: 20 secs
Outbound reg. attempts: 0
Outbound reg. retry 403:0
Notify ringing state: Yes
Include CID: No
Notify hold state: Yes
SIP Transfer mode: open
Max Call Bitrate: 384 kbps
Auto-Framing: No
Outb. proxy:
Session Timers: Accept
Session Refresher: uas
Session Expires: 1800 secs
Session Min-SE: 90 secs
Timer T1: 500
Timer T1 minimum: 100
Timer B: 32000
No premature media: Yes
Max forwards: 70

Default Settings:

Allowed transports: UDP
Outbound transport: UDP
Context: from-sip-external
Force rport: Yes
DTMF: rfc2833
Qualify: 0
Use ClientCode: No
Progress inband: Never
Language:
MOH Interpret: default
MOH Suggest:
Voice Mail Extension: *97

FreePBX*CLI>

Here is a SIP debug (IPs and FQDN was replaced):

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2014.04.19 09:25:34 =~=~=~=~=~=~=~=~=~=~=~=
sip show peers

FreePBX*CLI>
Name/username Host Dyn Forcerport ACL Port Status
101/101 77.255.34.227 D N A 35526 OK (443 ms)
102/102 77.255.34.227 D N A 53015 OK (427 ms)
2 sip peers [Monitored: 2 online, 0 offline Unmonitored: 0 online, 0 offline]

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:53015 —>
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-c0692d023501900e-1–d87543-;rport
Max-Forwards: 70
Contact: sip:[email protected]:49153
To: "101"sip:[email protected]
From: "102"sip:[email protected];tag=7d109512
Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
Content-Type: application/sdp
User-Agent: X-Lite release 1006e stamp 34025
Content-Length: 332

v=0
o=- 2 2 IN IP4 192.168.159.146
s=CounterPath X-Lite 3.0
c=IN IP4 77.255.34.227
t=0 0
m=audio 36170 RTP/AVP 107 119 0 98 8 3 101
a=alt:1 1 : ZWGEK40N 2owGSLeF 192.168.159.146 36170
a=fmtp:101 0-15
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:98 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
<------------->
— (12 headers 13 lines) —
Sending to 77.255.34.227:53015 (NAT)
Using INVITE request as basis request - ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.
Found peer ‘102’ for ‘102’ from 77.255.34.227:53015

<— Reliably Transmitting (NAT) to 77.255.34.227:53015 —>
SIP/2.0 401 Unauthorized

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-c0692d023501900e-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as15e79dcb

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 1 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce=“09ba0bb6”

Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.’ in 27328 ms (Method: INVITE)

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:53015 —>
ACK sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-c0692d023501900e-1–d87543-;rport
To: "101"sip:[email protected];tag=as15e79dcb
From: "102"sip:[email protected];tag=7d109512
Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.
CSeq: 1 ACK
Content-Length: 0

<------------->
— (7 headers 0 lines) —

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:53015 —>
INVITE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;rport
Max-Forwards: 70
Contact: sip:[email protected]:49153
To: "101"sip:[email protected]
From: “102"sip:[email protected];tag=7d109512
Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.
CSeq: 2 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
Content-Type: application/sdp
User-Agent: X-Lite release 1006e stamp 34025
Authorization: Digest username=“102”,realm=“asterisk”,nonce=“09ba0bb6”,uri="sip:[email protected]”,response=“6a03ae4cc08f62b5c5337d5e6f65c6b1”,algorithm=MD5
Content-Length: 332

v=0
o=- 2 2 IN IP4 192.168.159.146
s=CounterPath X-Lite 3.0
c=IN IP4 77.255.34.227
t=0 0
m=audio 36170 RTP/AVP 107 119 0 98 8 3 101
a=alt:1 1 : ZWGEK40N 2owGSLeF 192.168.159.146 36170
a=fmtp:101 0-15
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:98 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
<------------->
— (13 headers 13 lines) —
Sending to 77.255.34.227:53015 (NAT)
Using INVITE request as basis request - ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.
Found peer ‘102’ for ‘102’ from 77.255.34.227:53015
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
Found RTP audio format 107
Found RTP audio format 119
Found RTP audio format 0
Found RTP audio format 98
Found RTP audio format 8
Found RTP audio format 3
Found RTP audio format 101
Found unknown media description format BV32 for ID 107
Found unknown media description format BV32-FEC for ID 119
Found audio description format iLBC for ID 98
Found audio description format telephone-event for ID 101
Capabilities: us - 0x1c0f (g723|gsm|ulaw|alaw|g726|ilbc|g722), peer - audio=0x40e (gsm|ulaw|alaw|ilbc)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x40e (gsm|ulaw|alaw|ilbc)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 77.255.34.227:36170
Looking for 101 in from-internal (domain domena.pol.pl)

FreePBX*CLI>
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘CHAN_START’,{ ts ‘2014-04-19 08:25:43’ },‘102’,‘102’,’’,’’,’’,‘101’,‘from-internal’,‘SIP/102-00000007’,’’,’’,’’,’’,’’,’’,3,’’,‘1397892343.7’,‘1397892343.7’,’’,’’,’’,’’)]

FreePBX*CLI>
list_route: hop: sip:[email protected]:49153

<— Transmitting (NAT) to 77.255.34.227:53015 —>
SIP/2.0 100 Trying

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected]

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Length: 0

<------------>

FreePBX*CLI>
– Executing [101@from-internal:1] Set(“SIP/102-00000007”, “__RINGTIMER=15”) in new stack

FreePBX*CLI>
– Executing [101@from-internal:2] Macro(“SIP/102-00000007”, “exten-vm,novm,101,0,0,0”) in new stack

FreePBX*CLI>
– Executing [s@macro-exten-vm:1] Macro(“SIP/102-00000007”, “user-callerid,”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:1] Set(“SIP/102-00000007”, “TOUCH_MONITOR=1397892343.7”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:2] Set(“SIP/102-00000007”, “AMPUSER=102”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:3] GotoIf(“SIP/102-00000007”, “0?report”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:4] ExecIf(“SIP/102-00000007”, “1?Set(REALCALLERIDNUM=102)”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:5] Set(“SIP/102-00000007”, “AMPUSER=102”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/102-00000007”, “0?limit”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:7] Set(“SIP/102-00000007”, “AMPUSERCIDNAME=102”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:8] GotoIf(“SIP/102-00000007”, “0?report”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:9] Set(“SIP/102-00000007”, “AMPUSERCID=102”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:10] Set(“SIP/102-00000007”, “__DIAL_OPTIONS=Ttr”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:11] Set(“SIP/102-00000007”, “CALLERID(all)=“102” <102>”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:12] GotoIf(“SIP/102-00000007”, “0?limit”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:13] ExecIf(“SIP/102-00000007”, “0?Set(GROUP(concurrency_limit)=102)”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:14] ExecIf(“SIP/102-00000007”, “0?Set(CHANNEL(language)=)”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:15] GosubIf(“SIP/102-00000007”, “7?sub-ccss,s,1(macro-exten-vm,101)”) in new stack

FreePBX*CLI>
– Executing [s@sub-ccss:1] ExecIf(“SIP/102-00000007”, “0?Return()”) in new stack

FreePBX*CLI>
– Executing [s@sub-ccss:2] Set(“SIP/102-00000007”, “CCSS_SETUP=TRUE”) in new stack

FreePBX*CLI>
– Executing [s@sub-ccss:3] GosubIf(“SIP/102-00000007”, “0?monitor_config,1(macro-exten-vm,101):monitor_default,1(macro-exten-vm,101)”) in new stack

FreePBX*CLI>
– Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/102-00000007”, “1?is_exten”) in new stack

FreePBX*CLI>
– Goto (sub-ccss,monitor_default,4)

FreePBX*CLI>
– Executing [monitor_default@sub-ccss:4] Set(“SIP/102-00000007”, “CALLCOMPLETION(cc_monitor_policy)=generic”) in new stack

FreePBX*CLI>
– Executing [monitor_default@sub-ccss:5] Set(“SIP/102-00000007”, “CALLCOMPLETION(cc_max_monitors)=5”) in new stack

FreePBX*CLI>
– Executing [monitor_default@sub-ccss:6] Return(“SIP/102-00000007”, “TRUE”) in new stack

FreePBX*CLI>
– Executing [s@sub-ccss:4] GosubIf(“SIP/102-00000007”, “7?agent_config,1():agent_default,1()”) in new stack

FreePBX*CLI>
– Executing [agent_config@sub-ccss:1] Set(“SIP/102-00000007”, “CALLCOMPLETION(cc_agent_policy)=generic”) in new stack

FreePBX*CLI>
– Executing [agent_config@sub-ccss:2] Set(“SIP/102-00000007”, “CALLCOMPLETION(cc_offer_timer)=30”) in new stack

FreePBX*CLI>
– Executing [agent_config@sub-ccss:3] Set(“SIP/102-00000007”, “CALLCOMPLETION(ccbs_available_timer)=”) in new stack

FreePBX*CLI>
– Executing [agent_config@sub-ccss:4] Set(“SIP/102-00000007”, “CALLCOMPLETION(ccnr_available_timer)=”) in new stack

FreePBX*CLI>
– Executing [agent_config@sub-ccss:5] Set(“SIP/102-00000007”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack

FreePBX*CLI>
– Executing [agent_config@sub-ccss:6] ExecIf(“SIP/102-00000007”, “1?Set(CALLCOMPLETION(cc_recall_timer)=)”) in new stack

FreePBX*CLI>
– Executing [agent_config@sub-ccss:7] ExecIf(“SIP/102-00000007”, “1?Set(CALLCOMPLETION(cc_max_agents)=)”) in new stack

FreePBX*CLI>
– Executing [agent_config@sub-ccss:8] ExecIf(“SIP/102-00000007”, “0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/102_101@from-ccss-)”) in new stack

FreePBX*CLI>
– Executing [agent_config@sub-ccss:9] Set(“SIP/102-00000007”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack

FreePBX*CLI>
– Executing [agent_config@sub-ccss:10] Return(“SIP/102-00000007”, “”) in new stack

FreePBX*CLI>
– Executing [s@sub-ccss:5] Set(“SIP/102-00000007”, “DB(AMPUSER/102/ccss/last_number)=101”) in new stack

FreePBX*CLI>
– Executing [s@sub-ccss:6] Return(“SIP/102-00000007”, “”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:16] GotoIf(“SIP/102-00000007”, “0?continue”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:17] Set(“SIP/102-00000007”, “__TTL=64”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:18] GotoIf(“SIP/102-00000007”, “1?continue”) in new stack

FreePBX*CLI>
– Goto (macro-user-callerid,s,29)

FreePBX*CLI>
– Executing [s@macro-user-callerid:29] Set(“SIP/102-00000007”, “CALLERID(number)=102”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:30] Set(“SIP/102-00000007”, “CALLERID(name)=102”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:31] Set(“SIP/102-00000007”, “CDR(cnum)=102”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:32] Set(“SIP/102-00000007”, “CDR(cnam)=102”) in new stack

FreePBX*CLI>
– Executing [s@macro-user-callerid:33] Set(“SIP/102-00000007”, “CHANNEL(language)=en”) in new stack

FreePBX*CLI>
– Executing [s@macro-exten-vm:2] Set(“SIP/102-00000007”, “RingGroupMethod=none”) in new stack

FreePBX*CLI>
– Executing [s@macro-exten-vm:3] Set(“SIP/102-00000007”, “__EXTTOCALL=101”) in new stack

FreePBX*CLI>
– Executing [s@macro-exten-vm:4] Set(“SIP/102-00000007”, “__PICKUPMARK=101”) in new stack

FreePBX*CLI>
– Executing [s@macro-exten-vm:5] Set(“SIP/102-00000007”, “RT=”) in new stack

FreePBX*CLI>
– Executing [s@macro-exten-vm:6] ExecIf(“SIP/102-00000007”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack

FreePBX*CLI>
– Executing [s@macro-exten-vm:7] ExecIf(“SIP/102-00000007”, “0?MacroExit()”) in new stack

FreePBX*CLI>
– Executing [s@macro-exten-vm:8] Gosub(“SIP/102-00000007”, “sub-record-check,s,1(exten,101,)”) in new stack

FreePBX*CLI>
– Executing [s@sub-record-check:1] Set(“SIP/102-00000007”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:2] GotoIf(“SIP/102-00000007”, “1?check”) in new stack
– Goto (sub-record-check,s,7)
– Executing [s@sub-record-check:7] Set(“SIP/102-00000007”, “__MON_FMT=wav”) in new stack
– Executing [s@sub-record-check:8] GotoIf(“SIP/102-00000007”, “1?next”) in new stack
– Goto (sub-record-check,s,11)
– Executing [s@sub-record-check:11] ExecIf(“SIP/102-00000007”, “0?Return()”) in new stack
– Executing [s@sub-record-check:12] ExecIf(“SIP/102-00000007”, “0?Set(__REC_POLICY_MODE=)”) in new stack
– Executing [s@sub-record-check:13] GotoIf(“SIP/102-00000007”, “0?exten,1”) in new stack
– Executing [s@sub-record-check:14] Set(“SIP/102-00000007”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [s@sub-record-check:15] Set(“SIP/102-00000007”, “NOW=1397892343”) in new stack
– Executing [s@sub-record-check:16] Set(“SIP/102-00000007”, “__DAY=19”) in new stack
– Executing [s@sub-record-check:17] Set(“SIP/102-00000007”, “__MONTH=04”) in new stack
– Executing [s@sub-record-check:18] Set(“SIP/102-00000007”, “__YEAR=2014”) in new stack
– Executing [s@sub-record-check:19] Set(“SIP/102-00000007”, “__TIMESTR=20140419-082543”) in new stack
– Executing [s@sub-record-check:20] Set(“SIP/102-00000007”, “__FROMEXTEN=102”) in new stack
– Executing [s@sub-record-check:21] Set(“SIP/102-00000007”, “__CALLFILENAME=exten-101-102-20140419-082543-1397892343.7”) in new stack
– Executing [s@sub-record-check:22] Goto(“SIP/102-00000007”, “exten,1”) in new stack
– Goto (sub-record-check,exten,1)
– Executing [exten@sub-record-check:1] GotoIf(“SIP/102-00000007”, “0?callee”) in new stack
– Executing [exten@sub-record-check:2] Set(“SIP/102-00000007”, “__REC_POLICY_MODE=dontcare”) in new stack
– Executing [exten@sub-record-check:3] GotoIf(“SIP/102-00000007”, “1?caller”) in new stack
– Goto (sub-record-check,exten,10)
– Executing [exten@sub-record-check:10] Set(“SIP/102-00000007”, “__REC_POLICY_MODE=dontcare”) in new stack
– Executing [exten@sub-record-check:11] GosubIf(“SIP/102-00000007”, “0?record,1(exten,101,102)”) in new stack
– Executing [exten@sub-record-check:12] Return(“SIP/102-00000007”, “”) in new stack
– Executing [s@macro-exten-vm:9] GotoIf(“SIP/102-00000007”, “1?macrodial”) in new stack
– Goto (macro-exten-vm,s,15)
– Executing [s@macro-exten-vm:15] GosubIf(“SIP/102-00000007”, “0?clrheader,1()”) in new stack
– Executing [s@macro-exten-vm:16] Macro(“SIP/102-00000007”, “dial-one,Ttr,101”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:1] Set(“SIP/102-00000007”, “DEXTEN=101”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:2] Set(“SIP/102-00000007”, “DIALSTATUS_CW=”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:3] GosubIf(“SIP/102-00000007”, “0?screen,1()”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:4] GosubIf(“SIP/102-00000007”, “0?cf,1()”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:5] GotoIf(“SIP/102-00000007”, “1?skip1”) in new stack

FreePBX*CLI>
– Goto (macro-dial-one,s,8)

FreePBX*CLI>
– Executing [s@macro-dial-one:8] GotoIf(“SIP/102-00000007”, “0?nodial”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:9] GotoIf(“SIP/102-00000007”, “0?continue”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:10] Set(“SIP/102-00000007”, “EXTHASCW=ENABLED”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:11] GotoIf(“SIP/102-00000007”, “0?next1:cwinusebusy”) in new stack

FreePBX*CLI>
– Goto (macro-dial-one,s,23)

FreePBX*CLI>
– Executing [s@macro-dial-one:23] GotoIf(“SIP/102-00000007”, “1?next3:continue”) in new stack

FreePBX*CLI>
– Goto (macro-dial-one,s,24)

FreePBX*CLI>
– Executing [s@macro-dial-one:24] ExecIf(“SIP/102-00000007”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:25] GotoIf(“SIP/102-00000007”, “0?nodial”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:26] GosubIf(“SIP/102-00000007”, “1?dstring,1():dlocal,1()”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:1] Set(“SIP/102-00000007”, “DSTRING=”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:2] Set(“SIP/102-00000007”, “DEVICES=101”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:3] ExecIf(“SIP/102-00000007”, “0?Return()”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:4] ExecIf(“SIP/102-00000007”, “0?Set(DEVICES=01)”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:5] Set(“SIP/102-00000007”, “LOOPCNT=1”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:6] Set(“SIP/102-00000007”, “ITER=1”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:7] Set(“SIP/102-00000007”, “THISDIAL=SIP/101”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:8] GosubIf(“SIP/102-00000007”, “1?zap2dahdi,1()”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/102-00000007”, “0?Return()”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/102-00000007”, “NEWDIAL=”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/102-00000007”, “LOOPCNT2=1”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/102-00000007”, “ITER2=1”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/102-00000007”, “THISPART2=SIP/101”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/102-00000007”, “0?Set(THISPART2=DAHDI/101)”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/102-00000007”, “NEWDIAL=SIP/101&”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/102-00000007”, “ITER2=2”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/102-00000007”, “0?begin2”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/102-00000007”, “THISDIAL=SIP/101”) in new stack

FreePBX*CLI>
– Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/102-00000007”, “”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:9] Set(“SIP/102-00000007”, “DSTRING=SIP/101&”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:10] Set(“SIP/102-00000007”, “ITER=2”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:11] GotoIf(“SIP/102-00000007”, “0?begin”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:12] Set(“SIP/102-00000007”, “DSTRING=SIP/101”) in new stack

FreePBX*CLI>
– Executing [dstring@macro-dial-one:13] Return(“SIP/102-00000007”, “”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:27] GotoIf(“SIP/102-00000007”, “0?nodial”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:28] GotoIf(“SIP/102-00000007”, “0?skiptrace”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:29] GosubIf(“SIP/102-00000007”, “1?ctset,1():ctclear,1()”) in new stack

FreePBX*CLI>
– Executing [ctset@macro-dial-one:1] Set(“SIP/102-00000007”, “DB(CALLTRACE/101)=102”) in new stack
– Executing [ctset@macro-dial-one:2] Return(“SIP/102-00000007”, “”) in new stack
– Executing [s@macro-dial-one:30] Set(“SIP/102-00000007”, “D_OPTIONS=Ttr”) in new stack
– Executing [s@macro-dial-one:31] ExecIf(“SIP/102-00000007”, “0?SIPAddHeader(Alert-Info: )”) in new stack
– Executing [s@macro-dial-one:32] ExecIf(“SIP/102-00000007”, “0?SIPAddHeader()”) in new stack
– Executing [s@macro-dial-one:33] ExecIf(“SIP/102-00000007”, “0?Set(CHANNEL(musicclass)=)”) in new stack
– Executing [s@macro-dial-one:34] GosubIf(“SIP/102-00000007”, “0?qwait,1()”) in new stack
– Executing [s@macro-dial-one:35] Set(“SIP/102-00000007”, “__CWIGNORE=”) in new stack
– Executing [s@macro-dial-one:36] Set(“SIP/102-00000007”, “__KEEPCID=TRUE”) in new stack
– Executing [s@macro-dial-one:37] GotoIf(“SIP/102-00000007”, “0?usegoto,1”) in new stack
– Executing [s@macro-dial-one:38] GotoIf(“SIP/102-00000007”, “0?godial”) in new stack
– Executing [s@macro-dial-one:39] Set(“SIP/102-00000007”, “CONNECTEDLINE(name,i)=101”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:40] Set(“SIP/102-00000007”, “CONNECTEDLINE(num)=101”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:41] Set(“SIP/102-00000007”, “D_OPTIONS=TtrI”) in new stack

FreePBX*CLI>
– Executing [s@macro-dial-one:42] Dial(“SIP/102-00000007”, “SIP/101,TtrI”) in new stack

FreePBX*CLI>
== Using SIP RTP TOS bits 184

FreePBX*CLI>
== Using SIP RTP CoS mark 5

FreePBX*CLI>
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘CHAN_START’,{ ts ‘2014-04-19 08:25:43’ },‘101’,‘101’,’’,’’,’’,‘s’,‘from-internal’,‘SIP/101-00000008’,’’,’’,’’,’’,’’,’’,3,’’,‘1397892343.8’,‘1397892343.7’,’’,’’,’’,’’)]

FreePBX*CLI>
Audio is at 10004

FreePBX*CLI>
Adding codec 0x400 (ilbc) to SDP

FreePBX*CLI>
Adding codec 0x2 (gsm) to SDP

FreePBX*CLI>
Adding codec 0x800 (g726) to SDP

FreePBX*CLI>
Adding codec 0x1000 (g722) to SDP

FreePBX*CLI>
Adding codec 0x4 (ulaw) to SDP

FreePBX*CLI>
Adding codec 0x8 (alaw) to SDP

FreePBX*CLI>
Adding non-codec 0x1 (telephone-event) to SDP

FreePBX*CLI>
Reliably Transmitting (NAT) to 77.255.34.227:35526:
INVITE sip:[email protected]:49154;rinstance=09507900b18f446e SIP/2.0

Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK3adc6402;rport

Max-Forwards: 70

From: “102” sip:[email protected];tag=as4dea7c58

To: sip:[email protected]:49154;rinstance=09507900b18f446e

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 INVITE

User-Agent: FPBX-2.11.0(1.8.26.1)

Date: Sat, 19 Apr 2014 07:25:43 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Type: application/sdp

Content-Length: 384

v=0

o=root 409844704 409844704 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10004 RTP/AVP 97 3 111 9 0 8 101

a=rtpmap:97 iLBC/8000

a=fmtp:97 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:111 G726-32/8000

a=rtpmap:9 G722/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

-- Called SIP/101

<— Transmitting (NAT) to 77.255.34.227:53015 —>
SIP/2.0 180 Ringing

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Length: 0

<------------>
– Connected line update to SIP/102-00000007 prevented.

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:35526 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK3adc6402;rport=5060;received=191.235.133.119
Contact: sip:[email protected]:49154;rinstance=09507900b18f446e
To: sip:[email protected]:49154;rinstance=09507900b18f446e;tag=a21ee82a
From: "102"sip:[email protected];tag=as4dea7c58
Call-ID: [email protected]:5060
CSeq: 102 INVITE
User-Agent: X-Lite release 1104o stamp 56125
Content-Length: 0

<------------->
— (9 headers 0 lines) —
list_route: hop: sip:[email protected]:49154;rinstance=09507900b18f446e

FreePBX*CLI>
– SIP/101-00000008 is ringing

<— Transmitting (NAT) to 77.255.34.227:53015 —>
SIP/2.0 180 Ringing

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Length: 0

<------------>

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:35526 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK3adc6402;rport=5060;received=191.235.133.119
Contact: sip:[email protected]:49154;rinstance=09507900b18f446e
To: sip:[email protected]:49154;rinstance=09507900b18f446e;tag=a21ee82a
From: "102"sip:[email protected];tag=as4dea7c58
Call-ID: [email protected]:5060
CSeq: 102 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
C
FreePBX*CLI>
ontent-Type: application/sdp
User-Agent: X-Lite release 1104o stamp 56125
Content-Length: 187

v=0
o=- 1 2 IN IP4 192.168.1.25
s=CounterPath X-Lite 3.0
c=IN IP4 77.255.34.227
t=0 0
m=audio 6916 RTP/AVP 3 0 8 101
a=fmtp:101 0-15
a=rtpmap:101 telephone-event/8000
a=sendrecv
<------------->
— (11 headers 9 lines) —
Found RTP audio format 3
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 101
Found audio description format telephone-event for ID 101
Capabilities: us - 0x1c0f (g723|gsm|ulaw|alaw|g726|ilbc|g722), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 77.255.34.227:6916
list_route: hop: sip:[email protected]:49154;rinstance=09507900b18f446e
set_destination: Parsing sip:[email protected]:49154;rinstance=09507900b18f446e for address/port to send to
set_destination: set destination to 77.255.34.227:49154
Transmitting (NAT) to 77.255.34.227:35526:
ACK sip:[email protected]:49154;rinstance=09507900b18f446e SIP/2.0

Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK72a35870;rport

Max-Forwards: 70

From: “102” sip:[email protected];tag=as4dea7c58

To: sip:[email protected]:49154;rinstance=09507900b18f446e;tag=a21ee82a

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 ACK

User-Agent: FPBX-2.11.0(1.8.26.1)

Content-Length: 0

FreePBX*CLI>
– Connected line update to SIP/102-00000007 prevented.
– SIP/101-00000008 answered SIP/102-00000007
Audio is at 10002
Adding codec 0x400 (ilbc) to SDP
Adding codec 0x2 (gsm) to SDP
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<— Reliably Transmitting (NAT) to 77.255.34.227:53015 —>
SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

FreePBX*CLI>
From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 329

v=0

o=root 437862138 437862138 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10002 RTP/AVP 98 3 0 8 101

a=rtpmap:98 iLBC/8000

a=fmtp:98 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

<------------>
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘ANSWER’,{ ts ‘2014-04-19 08:25:44’ },‘101’,‘101’,‘101’,’’,’’,‘101’,‘from-internal’,‘SIP/101-00000008’,’’,’’,’’,’’,‘AppDial’,’(Outgoing Line)’,3,’’,‘1397892343.8’,‘1397892343.7’,’’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘ANSWER’,{ ts ‘2014-04-19 08:25:44’ },‘102’,‘102’,‘102’,’’,‘101’,‘s’,‘macro-dial-one’,‘SIP/102-00000007’,’’,’’,’’,’’,‘Dial’,‘SIP/101,TtrI’,3,’’,‘1397892343.7’,‘1397892343.7’,’’,’’,’’,’’)]

FreePBX*CLI>
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘BRIDGE_START’,{ ts ‘2014-04-19 08:25:44’ },‘102’,‘102’,‘102’,’’,‘101’,‘s’,‘macro-dial-one’,‘SIP/102-00000007’,’’,’’,’’,’’,‘Dial’,‘SIP/101,TtrI’,3,’’,‘1397892343.7’,‘1397892343.7’,‘SIP/101-00000008’,’’,’’,’’)]

FreePBX*CLI>
Retransmitting #1 (NAT) to 77.255.34.227:53015:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 329

v=0

o=root 437862138 437862138 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10002 RTP/AVP 98 3 0 8 101

a=rtpmap:98 iLBC/8000

a=fmtp:98 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

FreePBX*CLI>
Retransmitting #2 (NAT) to 77.255.34.227:53015:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 329

v=0

o=root 437862138 437862138 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10002 RTP/AVP 98 3 0 8 101

a=rtpmap:98 iLBC/8000

a=fmtp:98 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

FreePBX*CLI>
Retransmitting #3 (NAT) to 77.255.34.227:53015:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 329

v=0

o=root 437862138 437862138 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10002 RTP/AVP 98 3 0 8 101

a=rtpmap:98 iLBC/8000

a=fmtp:98 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:53015 —>

<------------->

FreePBX*CLI>
Retransmitting #4 (NAT) to 77.255.34.227:53015:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 329

v=0

o=root 437862138 437862138 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10002 RTP/AVP 98 3 0 8 101

a=rtpmap:98 iLBC/8000

a=fmtp:98 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

FreePBX*CLI>
Retransmitting #5 (NAT) to 77.255.34.227:53015:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 329

v=0

o=root 437862138 437862138 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10002 RTP/AVP 98 3 0 8 101

a=rtpmap:98 iLBC/8000

a=fmtp:98 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:35526 —>

<------------->

FreePBX*CLI>
Reliably Transmitting (NAT) to 77.255.34.227:35526:
OPTIONS sip:[email protected]:49154;rinstance=09507900b18f446e SIP/2.0

Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK2fb92cb2;rport

Max-Forwards: 70

From: “Unknown” sip:[email protected];tag=as432d9a46

To: sip:[email protected]:49154;rinstance=09507900b18f446e

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 OPTIONS

User-Agent: FPBX-2.11.0(1.8.26.1)

Date: Sat, 19 Apr 2014 07:25:58 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Length: 0

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:35526 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK2fb92cb2;rport=5060;received=191.235.133.119
Contact: sip:77.255.34.227:49154
To: sip:[email protected]:49154;rinstance=09507900b18f446e;tag=4c2ff840
From: "Unknown"sip:[email protected];tag=as432d9a46
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
Accept: application/sdp
Accept-Language: en
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
User-Agent: X-Lite release 1104o stamp 56125
Content-Length: 0

<------------->
— (12 headers 0 lines) —
Really destroying SIP dialog ‘[email protected]:5060’ Method: OPTIONS

FreePBX*CLI>
Retransmitting #6 (NAT) to 77.255.34.227:53015:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 329

v=0

o=root 437862138 437862138 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10002 RTP/AVP 98 3 0 8 101

a=rtpmap:98 iLBC/8000

a=fmtp:98 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

FreePBX*CLI>
Retransmitting #7 (NAT) to 77.255.34.227:53015:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 329

v=0

o=root 437862138 437862138 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10002 RTP/AVP 98 3 0 8 101

a=rtpmap:98 iLBC/8000

a=fmtp:98 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

FreePBX*CLI>
Retransmitting #8 (NAT) to 77.255.34.227:53015:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 329

v=0

o=root 437862138 437862138 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10002 RTP/AVP 98 3 0 8 101

a=rtpmap:98 iLBC/8000

a=fmtp:98 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

FreePBX*CLI>
Retransmitting #9 (NAT) to 77.255.34.227:53015:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 192.168.159.146:29608;branch=z9hG4bK-d87543-e17c225b64702c4c-1–d87543-;received=77.255.34.227;rport=53015

From: "102"sip:[email protected];tag=7d109512

To: "101"sip:[email protected];tag=as658e679a

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 2 INVITE

Server: FPBX-2.11.0(1.8.26.1)

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Contact: sip:[email protected]:5060

Content-Type: application/sdp

Content-Length: 329

v=0

o=root 437862138 437862138 IN IP4 106.92.78.100

s=Asterisk PBX 1.8.26.1

c=IN IP4 106.92.78.100

t=0 0

m=audio 10002 RTP/AVP 98 3 0 8 101

a=rtpmap:98 iLBC/8000

a=fmtp:98 mode=30

a=rtpmap:3 GSM/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=ptime:20

a=sendrecv

FreePBX*CLI>
[2014-04-19 08:26:12] WARNING[1769]: chan_sip.c:3984 retrans_pkt: Retransmission timeout reached on transmission ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM. for seqno 2 (Critical Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 27328ms with no response
[2014-04-19 08:26:12] WARNING[1769]: chan_sip.c:4013 retrans_pkt: Hanging up call ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM. - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).

FreePBX*CLI>
– Executing [h@macro-dial-one:1] Macro(“SIP/102-00000007”, “hangupcall,”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“SIP/102-00000007”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [s@macro-hangupcall:3] ExecIf(“SIP/102-00000007”, “0?Set(CDR(recordingfile)=)”) in new stack
– Executing [s@macro-hangupcall:4] Hangup(“SIP/102-00000007”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/102-00000007’ in macro ‘hangupcall’
== Spawn extension (macro-dial-one, h, 1) exited non-zero on ‘SIP/102-00000007’

FreePBX*CLI>
> [INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,uniqueid,cnum,cnam) VALUES ({ ts ‘2014-04-19 08:25:43’ },’“102” <102>’,‘102’,‘101’,‘from-internal’,‘SIP/102-00000007’,‘SIP/101-00000008’,‘Dial’,‘SIP/101,TtrI’,29,28,‘ANSWERED’,3,‘1397892343.7’,‘102’,‘102’)]

FreePBX*CLI>
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘BRIDGE_END’,{ ts ‘2014-04-19 08:26:12’ },‘102’,‘102’,‘102’,’’,‘101’,‘s’,‘macro-dial-one’,‘SIP/102-00000007’,’’,’’,’’,’’,‘Dial’,‘SIP/101,TtrI’,3,’’,‘1397892343.7’,‘1397892343.7’,‘SIP/101-00000008’,’’,’’,’’)]

FreePBX*CLI>
Scheduling destruction of SIP dialog ‘[email protected]:5060’ in 28352 ms (Method: INVITE)
set_destination: Parsing sip:[email protected]:49154;rinstance=09507900b18f446e for address/port to send to
set_destination: set destination to 77.255.34.227:49154
Reliably Transmitting (NAT) to 77.255.34.227:35526:
BYE sip:[email protected]:49154;rinstance=09507900b18f446e SIP/2.0

Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK10c55af8;rport

Max-Forwards: 70

From: “102” sip:[email protected];tag=as4dea7c58

To: sip:[email protected]:49154;rinstance=09507900b18f446e;tag=a21ee82a

Call-ID: [email protected]:5060

CSeq: 103 BYE

User-Agent: FPBX-2.11.0(1.8.26.1)

X-Asterisk-HangupCause: Normal Clearing

X-Asterisk-HangupCauseCode: 16

Content-Length: 0

== Spawn extension (macro-dial-one, s, 42) exited non-zero on ‘SIP/102-00000007’ in macro ‘dial-one’
== Spawn extension (macro-exten-vm, s, 16) exited non-zero on ‘SIP/102-00000007’ in macro ‘exten-vm’
== Spawn extension (from-internal, 101, 2) exited non-zero on 'SIP/102-00000007’
Scheduling destruction of SIP dialog ‘ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.’ in 27328 ms (Method: INVITE)
set_destination: Parsing sip:[email protected]:49153 for address/port to send to
set_destination: set destination to 77.255.34.227:49153
Reliably Transmitting (NAT) to 77.255.34.227:53015:
BYE sip:[email protected]:49153 SIP/2.0

Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK6f5966df;rport

Max-Forwards: 70

From: "101"sip:[email protected];tag=as658e679a

To: "102"sip:[email protected];tag=7d109512

Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.

CSeq: 102 BYE

User-Agent: FPBX-2.11.0(1.8.26.1)

Proxy-Authorization: Digest username=“102”, realm=“asterisk”, algorithm=MD5, uri=“sip:domena.pol.pl”, nonce="", response=“5a8850868a52f8ebb83cfb69c2ca01ac”

X-Asterisk-HangupCause: No user responding

X-Asterisk-HangupCauseCode: 18

Content-Length: 0

FreePBX*CLI>
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘HANGUP’,{ ts ‘2014-04-19 08:26:12’ },‘101’,‘101’,‘101’,’’,’’,’’,‘macro-dial-one’,‘SIP/101-00000008’,’’,’’,’’,’’,‘AppDial’,’(Outgoing Line)’,3,’’,‘1397892343.8’,‘1397892343.7’,’’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘CHAN_END’,{ ts ‘2014-04-19 08:26:12’ },‘101’,‘101’,‘101’,’’,’’,’’,‘macro-dial-one’,‘SIP/101-00000008’,’’,’’,’’,’’,‘AppDial’,’(Outgoing Line)’,3,’’,‘1397892343.8’,‘1397892343.7’,’’,’’,’’,’’)]

FreePBX*CLI>
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘HANGUP’,{ ts ‘2014-04-19 08:26:12’ },‘102’,‘102’,‘102’,’’,‘101’,‘101’,‘from-internal’,‘SIP/102-00000007’,’’,’’,’’,’’,’’,’’,3,’’,‘1397892343.7’,‘1397892343.7’,’’,’’,’’,’’)]

FreePBX*CLI>
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘CHAN_END’,{ ts ‘2014-04-19 08:26:12’ },‘102’,‘102’,‘102’,’’,‘101’,‘101’,‘from-internal’,‘SIP/102-00000007’,’’,’’,’’,’’,’’,’’,3,’’,‘1397892343.7’,‘1397892343.7’,’’,’’,’’,’’)]

FreePBX*CLI>
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,src,dst,channel,dstchannel,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,eventextra,userfield) VALUES (‘LINKEDID_END’,{ ts ‘2014-04-19 08:26:12’ },‘102’,‘102’,‘102’,’’,‘101’,‘101’,‘from-internal’,‘SIP/102-00000007’,’’,’’,’’,’’,’’,’’,3,’’,‘1397892343.7’,‘1397892343.7’,’’,’’,’’,’’)]

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:35526 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK10c55af8;rport=5060;received=191.235.133.119
Contact: sip:[email protected]:49154;rinstance=09507900b18f446e
To: sip:[email protected]:49154;rinstance=09507900b18f446e;tag=a21ee82a
From: "102"sip:[email protected];tag=as4dea7c58
Call-ID: [email protected]:5060
CSeq: 103 BYE
User-Agent: X-Lite release 1104o stamp 56125
Content-Length: 0

<------------->
— (9 headers 0 lines) —
Really destroying SIP dialog ‘[email protected]:5060’ Method: INVITE

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:53015 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK6f5966df;rport=5060;received=191.235.133.119
Contact: sip:[email protected]:49153
To: "102"sip:[email protected];tag=7d109512
From: "101"sip:[email protected];tag=as658e679a
Call-ID: ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.
CSeq: 102 BYE
User-Agent: X-Lite release 1006e stamp 34025
Content-Length: 0

<------------->
— (9 headers 0 lines) —
SIP Response message for INCOMING dialog BYE arrived
Really destroying SIP dialog ‘ZjZhZTg1NTk5NzBiYjdmMTQ0MDg4MDI3Mzk4YWQ0MmM.’ Method: INVITE

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:53015 —>

<------------->

FreePBX*CLI>
Reliably Transmitting (NAT) to 77.255.34.227:53015:
OPTIONS sip:[email protected]:49153;rinstance=ac17e0a40fcd5c88 SIP/2.0

Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK2536a499;rport

Max-Forwards: 70

From: “Unknown” sip:[email protected];tag=as1d515d2a

To: sip:[email protected]:49153;rinstance=ac17e0a40fcd5c88

Contact: sip:[email protected]:5060

Call-ID: [email protected]:5060

CSeq: 102 OPTIONS

User-Agent: FPBX-2.11.0(1.8.26.1)

Date: Sat, 19 Apr 2014 07:26:22 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Length: 0

FreePBX*CLI>

<— SIP read from UDP:77.255.34.227:53015 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 106.92.78.100:5060;branch=z9hG4bK2536a499;rport=5060;received=191.235.133.119
Contact: sip:192.168.159.146:29608
To: sip:[email protected]:49153;rinstance=ac17e0a40fcd5c88;tag=74704406
From: "Unknown"sip:[email protected];tag=as1d515d2a
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
Accept: application/sdp
Accept-Language: en
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
User-Agent: X-Lite release 1006e stamp 34025
Content-Length: 0

<------------->
— (12 headers 0 lines) —
Really destroying SIP dialog ‘[email protected]:5060’ Method: OPTIONS

FreePBX*CLI>

2

rtp port range should start on an even number as that the first even port in the range is used, two sequencial ports will be use for each leg, you need to leave headroom also, why did you choose to change the defaults.

3

Microsoft Azure support only 100 open ports so I limited it from 10001 to 10005, I will change it from 10000 to 10010. I am not sure if it helps but I will try. Any other idea?

4

You might want to try limiting the ports that can be used by Asterisk. Edit the /etc/asterisk/rtp.conf file to change the range used.

5

The problem was in that Asterisk and Client was behind NAT. When I changed IP Configuration to Dynamic IP everything is working OK.