Asterisk drops calls originated by A580IP

Asterisk Asterisk Support
1

Using Asterisk 1-8-9-1 with Freepbx.
Internal to internal calls work seamlessly with several softphones for iphone and ipad.
No problem in registering a physical Siemens Gigaset A580 IP, it works wonderfully if CALLEd by another internal.
If it originates a call, it is forcedly hanged up by Asterisk after 6,4 seconds for retransmission timeout.
Before the timeout occurs the conversation is fine (both channels, forth and back).
The trace follows.
What’s wrong with my config?
Maybe is this solved by one of the modifications to channels/chan_sip.c introduced by 1.8.9.2 and 1.8.9.3?

In the trace the gigaset is ext. 40, it is on the internal network, no nat. The other side of the call is NATted (41), but the same test made with a third internal client showed basically the same trace.

Thanks in advance for anybody willing to help.

[ul]<— SIP read from UDP:192.168.254.252:5060 —>
INVITE sip:41@192.168.254.251;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bKc5fd6c0b8040a0a24da4a03c6641ab3;rport
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone
Call-ID: 2624490068@192_168_254_252
CSeq: 2 INVITE
Contact: sip:40@192.168.254.252:5060
Max-Forwards: 70
User-Agent: A580 IP/022270000000
Supported: replaces
Allow-Events: message-summary, refer
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 362

v=0
o=0240043561 10826 69 IN IP4 192.168.254.252
s=Mapping
c=IN IP4 192.168.254.252
t=0 0
m=audio 10826 RTP/AVP 8 0 96 97 2 18 9 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 G726-32/8000
a=rtpmap:97 AAL2-G726-32/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:18 G729/8000
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
<------------->
— (14 headers 15 lines) —
Sending to 192.168.254.252:5060 (NAT)
Using INVITE request as basis request - 2624490068@192_168_254_252
Found peer ‘40’ for ‘40’ from 192.168.254.252:5060

<— Reliably Transmitting (NAT) to 192.168.254.252:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bKc5fd6c0b8040a0a24da4a03c6641ab3;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as73d96cf3
Call-ID: 2624490068@192_168_254_252
CSeq: 2 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="7ac7cf7a"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog ‘2624490068@192_168_254_252’ in 6400 ms (Method: INVITE)

<— SIP read from UDP:192.168.254.252:5060 —>
ACK sip:41@192.168.254.251;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bKc5fd6c0b8040a0a24da4a03c6641ab3;rport
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as73d96cf3
Call-ID: 2624490068@192_168_254_252
CSeq: 2 ACK
Contact: sip:40@192.168.254.252:5060
Max-Forwards: 70
User-Agent: A580 IP/022270000000
Content-Length: 0

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

<— SIP read from UDP:192.168.254.252:5060 —>
INVITE sip:41@192.168.254.251;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;rport
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Contact: sip:40@192.168.254.252:5060
Authorization: Digest username=“40”, realm=“asterisk”, algorithm=MD5, uri="sip:41@192.168.254.251;user=phone", nonce=“7ac7cf7a”, response="71cadfeab137dc8ad15b5d548793ffcc"
Max-Forwards: 70
User-Agent: A580 IP/022270000000
Supported: replaces
Allow-Events: message-summary, refer
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 362

v=0
o=0240043561 10826 69 IN IP4 192.168.254.252
s=Mapping
c=IN IP4 192.168.254.252
t=0 0
m=audio 10826 RTP/AVP 8 0 96 97 2 18 9 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:96 G726-32/8000
a=rtpmap:97 AAL2-G726-32/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:18 G729/8000
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
<------------->
— (15 headers 15 lines) —
Sending to 192.168.254.252:5060 (NAT)
Using INVITE request as basis request - 2624490068@192_168_254_252
Found peer ‘40’ for ‘40’ from 192.168.254.252:5060
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
Found RTP audio format 8
Found RTP audio format 0
Found RTP audio format 96
Found RTP audio format 97
Found RTP audio format 2
Found RTP audio format 18
Found RTP audio format 9
Found RTP audio format 101
Found audio description format PCMA for ID 8
Found audio description format PCMU for ID 0
Found audio description format G726-32 for ID 96
Found audio description format AAL2-G726-32 for ID 97
Found audio description format G726-32 for ID 2
Found audio description format G729 for ID 18
Found audio description format G722 for ID 9
Found audio description format telephone-event for ID 101
Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x191c (ulaw|alaw|g726|g729|g726aal2|g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 192.168.254.252:10826
Looking for 41 in from-internal (domain 192.168.254.251)
list_route: hop: sip:40@192.168.254.252:5060

<— Transmitting (NAT) to 192.168.254.252:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:41@82.84.141.85:5060
Content-Length: 0

<------------>
– Executing [41@from-internal:1] Set(“SIP/40-00000011”, “__RINGTIMER=15”) in new stack
– Executing [41@from-internal:2] Macro(“SIP/40-00000011”, “exten-vm,novm,41,0,0,0”) in new stack
– Executing [s@macro-exten-vm:1] Macro(“SIP/40-00000011”, “user-callerid,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/40-00000011”, “AMPUSER=40”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“SIP/40-00000011”, “0?report”) in new stack
– Executing [s@macro-user-callerid:3] ExecIf(“SIP/40-00000011”, “1?Set(REALCALLERIDNUM=40)”) in new stack
– Executing [s@macro-user-callerid:4] Set(“SIP/40-00000011”, “AMPUSER=40”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/40-00000011”, “AMPUSERCIDNAME=Carlo Rogialli”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/40-00000011”, “0?report”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/40-00000011”, “AMPUSERCID=40”) in new stack
– Executing [s@macro-user-callerid:8] Set(“SIP/40-00000011”, “CALLERID(all)=“Carlo Rogialli” <40>”) in new stack
– Executing [s@macro-user-callerid:9] GotoIf(“SIP/40-00000011”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:10] ExecIf(“SIP/40-00000011”, “0?Set(GROUP(concurrency_limit)=40)”) in new stack
– Executing [s@macro-user-callerid:11] GosubIf(“SIP/40-00000011”, “7?sub-ccss,s,1(macro-exten-vm,41)”) in new stack
– Executing [s@sub-ccss:1] ExecIf(“SIP/40-00000011”, “0?Return()”) in new stack
– Executing [s@sub-ccss:2] Set(“SIP/40-00000011”, “CCSS_SETUP=TRUE”) in new stack
– Executing [s@sub-ccss:3] GosubIf(“SIP/40-00000011”, “0?monitor_config,1(macro-exten-vm,41):monitor_default,1(macro-exten-vm,41)”) in new stack
– Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/40-00000011”, “1?is_exten”) in new stack
– Goto (sub-ccss,monitor_default,4)
– Executing [monitor_default@sub-ccss:4] Set(“SIP/40-00000011”, “CALLCOMPLETION(cc_monitor_policy)=generic”) in new stack
– Executing [monitor_default@sub-ccss:5] Set(“SIP/40-00000011”, “CALLCOMPLETION(cc_max_monitors)=5”) in new stack
– Executing [monitor_default@sub-ccss:6] Return(“SIP/40-00000011”, “TRUE”) in new stack
– Executing [s@sub-ccss:4] GosubIf(“SIP/40-00000011”, “7?agent_config,1():agent_default,1()”) in new stack
– Executing [agent_config@sub-ccss:1] Set(“SIP/40-00000011”, “CALLCOMPLETION(cc_agent_policy)=generic”) in new stack
– Executing [agent_config@sub-ccss:2] Set(“SIP/40-00000011”, “CALLCOMPLETION(cc_offer_timer)=30”) in new stack
– Executing [agent_config@sub-ccss:3] Set(“SIP/40-00000011”, “CALLCOMPLETION(ccbs_available_timer)=”) in new stack
– Executing [agent_config@sub-ccss:4] Set(“SIP/40-00000011”, “CALLCOMPLETION(ccnr_available_timer)=”) in new stack
– Executing [agent_config@sub-ccss:5] Set(“SIP/40-00000011”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
– Executing [agent_config@sub-ccss:6] ExecIf(“SIP/40-00000011”, “1?Set(CALLCOMPLETION(cc_recall_timer)=)”) in new stack
– Executing [agent_config@sub-ccss:7] ExecIf(“SIP/40-00000011”, “1?Set(CALLCOMPLETION(cc_max_agents)=)”) in new stack
– Executing [agent_config@sub-ccss:8] ExecIf(“SIP/40-00000011”, “0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/40_41@from-ccss-)”) in new stack
– Executing [agent_config@sub-ccss:9] Set(“SIP/40-00000011”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
– Executing [agent_config@sub-ccss:10] Return(“SIP/40-00000011”, “”) in new stack
– Executing [s@sub-ccss:5] Set(“SIP/40-00000011”, “DB(AMPUSER/40/ccss/last_number)=41”) in new stack
– Executing [s@sub-ccss:6] Return(“SIP/40-00000011”, “”) in new stack
– Executing [s@macro-user-callerid:12] ExecIf(“SIP/40-00000011”, “0?Set(CHANNEL(language)=)”) in new stack
– Executing [s@macro-user-callerid:13] GotoIf(“SIP/40-00000011”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:14] Set(“SIP/40-00000011”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:15] GotoIf(“SIP/40-00000011”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,26)
– Executing [s@macro-user-callerid:26] Set(“SIP/40-00000011”, “CALLERID(number)=40”) in new stack
– Executing [s@macro-user-callerid:27] Set(“SIP/40-00000011”, “CALLERID(name)=Carlo Rogialli”) in new stack
– Executing [s@macro-user-callerid:28] Set(“SIP/40-00000011”, “CHANNEL(language)=en”) in new stack
– Executing [s@macro-exten-vm:2] Set(“SIP/40-00000011”, “RingGroupMethod=none”) in new stack
– Executing [s@macro-exten-vm:3] Set(“SIP/40-00000011”, “__EXTTOCALL=41”) in new stack
– Executing [s@macro-exten-vm:4] Set(“SIP/40-00000011”, “__PICKUPMARK=41”) in new stack
– Executing [s@macro-exten-vm:5] Set(“SIP/40-00000011”, “RT=”) in new stack
– Executing [s@macro-exten-vm:6] Gosub(“SIP/40-00000011”, “sub-record-check,s,1(exten,41,)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“SIP/40-00000011”, “1?check”) in new stack
– Goto (sub-record-check,s,3)
– Executing [s@sub-record-check:3] Set(“SIP/40-00000011”, “MON_FMT=wav”) in new stack
– Executing [s@sub-record-check:4] GotoIf(“SIP/40-00000011”, “1?next”) in new stack
– Goto (sub-record-check,s,7)
– Executing [s@sub-record-check:7] ExecIf(“SIP/40-00000011”, “0?Return()”) in new stack
– Executing [s@sub-record-check:8] GotoIf(“SIP/40-00000011”, “0?exten,1”) in new stack
– Executing [s@sub-record-check:9] Set(“SIP/40-00000011”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [s@sub-record-check:10] ExecIf(“SIP/40-00000011”, “0?Set(__REC_POLICY_MODE=)”) in new stack
– Executing [s@sub-record-check:11] Set(“SIP/40-00000011”, “NOW=1330211295”) in new stack
– Executing [s@sub-record-check:12] Set(“SIP/40-00000011”, “__DAY=26”) in new stack
– Executing [s@sub-record-check:13] Set(“SIP/40-00000011”, “__MONTH=02”) in new stack
– Executing [s@sub-record-check:14] Set(“SIP/40-00000011”, “__YEAR=2012”) in new stack
– Executing [s@sub-record-check:15] Set(“SIP/40-00000011”, “__TIMESTR=20120226-000815”) in new stack
– Executing [s@sub-record-check:16] Set(“SIP/40-00000011”, “__FROMEXTEN=40”) in new stack
– Executing [s@sub-record-check:17] Set(“SIP/40-00000011”, “__CALLFILENAME=exten-41-40-20120226-000815-1330211295.17”) in new stack
– Executing [s@sub-record-check:18] Goto(“SIP/40-00000011”, “exten,1”) in new stack
– Goto (sub-record-check,exten,1)
– Executing [exten@sub-record-check:1] GotoIf(“SIP/40-00000011”, “0?callee”) in new stack
– Executing [exten@sub-record-check:2] Set(“SIP/40-00000011”, “__REC_POLICY_MODE=dontcare”) in new stack
– Executing [exten@sub-record-check:3] GotoIf(“SIP/40-00000011”, “1?caller”) in new stack
– Goto (sub-record-check,exten,10)
– Executing [exten@sub-record-check:10] Set(“SIP/40-00000011”, “REC_POLICY_MODE=dontcare”) in new stack
– Executing [exten@sub-record-check:11] GosubIf(“SIP/40-00000011”, “0?record,1(exten,41,40)”) in new stack
– Executing [exten@sub-record-check:12] Return(“SIP/40-00000011”, “”) in new stack
– Executing [s@macro-exten-vm:7] GotoIf(“SIP/40-00000011”, “1?macrodial”) in new stack
– Goto (macro-exten-vm,s,13)
– Executing [s@macro-exten-vm:13] GosubIf(“SIP/40-00000011”, “0?clrheader,1()”) in new stack
– Executing [s@macro-exten-vm:14] Macro(“SIP/40-00000011”, “dial-one,tr,41”) in new stack
– Executing [s@macro-dial-one:1] Set(“SIP/40-00000011”, “DEXTEN=41”) in new stack
– Executing [s@macro-dial-one:2] Set(“SIP/40-00000011”, “DIALSTATUS_CW=”) in new stack
– Executing [s@macro-dial-one:3] GosubIf(“SIP/40-00000011”, “0?screen,1()”) in new stack
– Executing [s@macro-dial-one:4] GosubIf(“SIP/40-00000011”, “0?cf,1()”) in new stack
– Executing [s@macro-dial-one:5] GotoIf(“SIP/40-00000011”, “1?skip1”) in new stack
– Goto (macro-dial-one,s,8)
– Executing [s@macro-dial-one:8] GotoIf(“SIP/40-00000011”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:9] GotoIf(“SIP/40-00000011”, “0?continue”) in new stack
– Executing [s@macro-dial-one:10] Set(“SIP/40-00000011”, “EXTHASCW=ENABLED”) in new stack
– Executing [s@macro-dial-one:11] GotoIf(“SIP/40-00000011”, “0?next1:cwinusebusy”) in new stack
– Goto (macro-dial-one,s,23)
– Executing [s@macro-dial-one:23] GotoIf(“SIP/40-00000011”, “1?next3:continue”) in new stack
– Goto (macro-dial-one,s,24)
– Executing [s@macro-dial-one:24] ExecIf(“SIP/40-00000011”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack
– Executing [s@macro-dial-one:25] GotoIf(“SIP/40-00000011”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:26] GosubIf(“SIP/40-00000011”, “1?dstring,1():dlocal,1()”) in new stack
– Executing [dstring@macro-dial-one:1] Set(“SIP/40-00000011”, “DSTRING=”) in new stack
– Executing [dstring@macro-dial-one:2] Set(“SIP/40-00000011”, “DEVICES=41”) in new stack
– Executing [dstring@macro-dial-one:3] ExecIf(“SIP/40-00000011”, “0?Return()”) in new stack
– Executing [dstring@macro-dial-one:4] ExecIf(“SIP/40-00000011”, “0?Set(DEVICES=1)”) in new stack
– Executing [dstring@macro-dial-one:5] Set(“SIP/40-00000011”, “LOOPCNT=1”) in new stack
– Executing [dstring@macro-dial-one:6] Set(“SIP/40-00000011”, “ITER=1”) in new stack
– Executing [dstring@macro-dial-one:7] Set(“SIP/40-00000011”, “THISDIAL=SIP/41”) in new stack
– Executing [dstring@macro-dial-one:8] GosubIf(“SIP/40-00000011”, “1?zap2dahdi,1()”) in new stack
– Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/40-00000011”, “0?Return()”) in new stack
– Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/40-00000011”, “NEWDIAL=”) in new stack
– Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/40-00000011”, “LOOPCNT2=1”) in new stack
– Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/40-00000011”, “ITER2=1”) in new stack
– Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/40-00000011”, “THISPART2=SIP/41”) in new stack
– Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/40-00000011”, “0?Set(THISPART2=DAHDI/41)”) in new stack
– Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/40-00000011”, “NEWDIAL=SIP/41&”) in new stack
– Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/40-00000011”, “ITER2=2”) in new stack
– Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/40-00000011”, “0?begin2”) in new stack
– Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/40-00000011”, “THISDIAL=SIP/41”) in new stack
– Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/40-00000011”, “”) in new stack
– Executing [dstring@macro-dial-one:9] Set(“SIP/40-00000011”, “DSTRING=SIP/41&”) in new stack
– Executing [dstring@macro-dial-one:10] Set(“SIP/40-00000011”, “ITER=2”) in new stack
– Executing [dstring@macro-dial-one:11] GotoIf(“SIP/40-00000011”, “0?begin”) in new stack
– Executing [dstring@macro-dial-one:12] Set(“SIP/40-00000011”, “DSTRING=SIP/41”) in new stack
– Executing [dstring@macro-dial-one:13] Return(“SIP/40-00000011”, “”) in new stack
– Executing [s@macro-dial-one:27] GotoIf(“SIP/40-00000011”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:28] GotoIf(“SIP/40-00000011”, “0?skiptrace”) in new stack
– Executing [s@macro-dial-one:29] GosubIf(“SIP/40-00000011”, “1?ctset,1():ctclear,1()”) in new stack
– Executing [ctset@macro-dial-one:1] Set(“SIP/40-00000011”, “DB(CALLTRACE/41)=40”) in new stack
– Executing [ctset@macro-dial-one:2] Return(“SIP/40-00000011”, “”) in new stack
– Executing [s@macro-dial-one:30] Set(“SIP/40-00000011”, “D_OPTIONS=tr”) in new stack
– Executing [s@macro-dial-one:31] ExecIf(“SIP/40-00000011”, “0?SIPAddHeader(Alert-Info: )”) in new stack
– Executing [s@macro-dial-one:32] ExecIf(“SIP/40-00000011”, “0?SIPAddHeader()”) in new stack
– Executing [s@macro-dial-one:33] ExecIf(“SIP/40-00000011”, “0?Set(CHANNEL(musicclass)=)”) in new stack
– Executing [s@macro-dial-one:34] GosubIf(“SIP/40-00000011”, “0?qwait,1()”) in new stack
– Executing [s@macro-dial-one:35] Set(“SIP/40-00000011”, “__CWIGNORE=”) in new stack
– Executing [s@macro-dial-one:36] Set(“SIP/40-00000011”, “__KEEPCID=TRUE”) in new stack
– Executing [s@macro-dial-one:37] GotoIf(“SIP/40-00000011”, “0?usegoto,1”) in new stack
– Executing [s@macro-dial-one:38] GotoIf(“SIP/40-00000011”, “0?godial”) in new stack
– Executing [s@macro-dial-one:39] Set(“SIP/40-00000011”, “CONNECTEDLINE(name,i)=Carlo iPad”) in new stack
– Executing [s@macro-dial-one:40] Set(“SIP/40-00000011”, “CONNECTEDLINE(num)=41”) in new stack
– Executing [s@macro-dial-one:41] Set(“SIP/40-00000011”, “D_OPTIONS=trI”) in new stack
– Executing [s@macro-dial-one:42] Dial(“SIP/40-00000011”, “SIP/41,trI”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
Audio is at 5060
Adding codec 0x8 (alaw) to SDP
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x2 (gsm) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (NAT) to 109.112.32.152:2071:
INVITE sip:41@109.112.32.152:2071 SIP/2.0
Via: SIP/2.0/UDP 82.84.141.85:5060;branch=z9hG4bK51d04f16;rport
Max-Forwards: 70
From: “Carlo Rogialli” sip:40@82.84.141.85;tag=as09a91840
To: sip:41@109.112.32.152:2071
Contact: sip:40@82.84.141.85:5060
Call-ID: 3da371da2839a80e5db690d4619a770b@82.84.141.85:5060
CSeq: 102 INVITE
User-Agent: FPBX-2.10.0rc1(1.8.8.0)
Date: Sat, 25 Feb 2012 23:08:15 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 281

v=0
o=root 598717751 598717751 IN IP4 82.84.141.85
s=Asterisk PBX 1.8.8.0
c=IN IP4 82.84.141.85
t=0 0
m=audio 10282 RTP/AVP 8 0 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

-- Called SIP/41

<— Transmitting (NAT) to 192.168.254.252:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as74be2866
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:41@82.84.141.85:5060
Content-Length: 0

<------------>
– Connected line update to SIP/40-00000011 prevented.
Retransmitting #1 (NAT) to 109.112.32.152:2071:
INVITE sip:41@109.112.32.152:2071 SIP/2.0
Via: SIP/2.0/UDP 82.84.141.85:5060;branch=z9hG4bK51d04f16;rport
Max-Forwards: 70
From: “Carlo Rogialli” sip:40@82.84.141.85;tag=as09a91840
To: sip:41@109.112.32.152:2071
Contact: sip:40@82.84.141.85:5060
Call-ID: 3da371da2839a80e5db690d4619a770b@82.84.141.85:5060
CSeq: 102 INVITE
User-Agent: FPBX-2.10.0rc1(1.8.8.0)
Date: Sat, 25 Feb 2012 23:08:15 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 281

v=0
o=root 598717751 598717751 IN IP4 82.84.141.85
s=Asterisk PBX 1.8.8.0
c=IN IP4 82.84.141.85
t=0 0
m=audio 10282 RTP/AVP 8 0 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<— SIP read from UDP:109.112.32.152:2071 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 82.84.141.85:5060;rport=5060;received=82.84.141.85;branch=z9hG4bK51d04f16
Call-ID: 3da371da2839a80e5db690d4619a770b@82.84.141.85:5060
From: “Carlo Rogialli” sip:40@82.84.141.85;tag=as09a91840
To: sip:41@109.112.32.152
CSeq: 102 INVITE
Content-Length: 0

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

<— SIP read from UDP:109.112.32.152:2071 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 82.84.141.85:5060;rport=5060;received=82.84.141.85;branch=z9hG4bK51d04f16
Call-ID: 3da371da2839a80e5db690d4619a770b@82.84.141.85:5060
From: “Carlo Rogialli” sip:40@82.84.141.85;tag=as09a91840
To: sip:41@109.112.32.152;tag=Uf86e4oXMAle34jUQYAvU.37K4va88hc
CSeq: 102 INVITE
Contact: “Carlo Rogialli iPad” sip:41@109.112.32.152:2071
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Length: 0

<------------->
— (9 headers 0 lines) —
– SIP/41-00000012 is ringing

<— Transmitting (NAT) to 192.168.254.252:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as74be2866
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:41@82.84.141.85:5060
Content-Length: 0

<------------>
Really destroying SIP dialog ‘559dce7009675c046e544ae2067810e8@127.0.0.1’ Method: REGISTER
Really destroying SIP dialog ‘13e3723d742262a70d04a11d0f74145d@127.0.0.1’ Method: REGISTER

<— SIP read from UDP:109.112.32.152:2071 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 82.84.141.85:5060;rport=5060;received=82.84.141.85;branch=z9hG4bK51d04f16
Call-ID: 3da371da2839a80e5db690d4619a770b@82.84.141.85:5060
From: “Carlo Rogialli” sip:40@82.84.141.85;tag=as09a91840
To: sip:41@109.112.32.152;tag=Uf86e4oXMAle34jUQYAvU.37K4va88hc
CSeq: 102 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Contact: “Carlo Rogialli iPad” sip:41@109.112.32.152:2071
Supported: replaces, 100rel, timer, norefersub
Content-Type: application/sdp
Content-Length: 210

v=0
o=- 3539203762 3539203763 IN IP4 192.168.0.100
s=cpc_med
c=IN IP4 192.168.0.100
t=0 0
m=audio 10002 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
<------------->
— (11 headers 10 lines) —
Found RTP audio format 8
Found RTP audio format 101
Found audio description format PCMA for ID 8
Found audio description format telephone-event for ID 101
Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 192.168.0.100:10002
list_route: hop: sip:41@109.112.32.152:2071
set_destination: Parsing sip:41@109.112.32.152:2071 for address/port to send to
set_destination: set destination to 109.112.32.152:2071
Transmitting (NAT) to 109.112.32.152:2071:
ACK sip:41@109.112.32.152:2071 SIP/2.0
Via: SIP/2.0/UDP 82.84.141.85:5060;branch=z9hG4bK1e7b88d7;rport
Max-Forwards: 70
From: “Carlo Rogialli” sip:40@82.84.141.85;tag=as09a91840
To: sip:41@109.112.32.152:2071;tag=Uf86e4oXMAle34jUQYAvU.37K4va88hc
Contact: sip:40@82.84.141.85:5060
Call-ID: 3da371da2839a80e5db690d4619a770b@82.84.141.85:5060
CSeq: 102 ACK
User-Agent: FPBX-2.10.0rc1(1.8.8.0)
Content-Length: 0

-- Connected line update to SIP/40-00000011 prevented.
-- SIP/41-00000012 answered SIP/40-00000011

Audio is at 5060
Adding codec 0x8 (alaw) to SDP
Adding codec 0x4 (ulaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<— Reliably Transmitting (NAT) to 192.168.254.252:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as74be2866
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:41@82.84.141.85:5060
Content-Type: application/sdp
Content-Length: 260

v=0
o=root 1968089850 1968089850 IN IP4 82.84.141.85
s=Asterisk PBX 1.8.8.0
c=IN IP4 82.84.141.85
t=0 0
m=audio 10244 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------>
Retransmitting #1 (NAT) to 192.168.254.252:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as74be2866
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:41@82.84.141.85:5060
Content-Type: application/sdp
Content-Length: 260

v=0
o=root 1968089850 1968089850 IN IP4 82.84.141.85
s=Asterisk PBX 1.8.8.0
c=IN IP4 82.84.141.85
t=0 0
m=audio 10244 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

Retransmitting #2 (NAT) to 192.168.254.252:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as74be2866
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:41@82.84.141.85:5060
Content-Type: application/sdp
Content-Length: 260

v=0
o=root 1968089850 1968089850 IN IP4 82.84.141.85
s=Asterisk PBX 1.8.8.0
c=IN IP4 82.84.141.85
t=0 0
m=audio 10244 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

Retransmitting #3 (NAT) to 192.168.254.252:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as74be2866
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:41@82.84.141.85:5060
Content-Type: application/sdp
Content-Length: 260

v=0
o=root 1968089850 1968089850 IN IP4 82.84.141.85
s=Asterisk PBX 1.8.8.0
c=IN IP4 82.84.141.85
t=0 0
m=audio 10244 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

Retransmitting #4 (NAT) to 192.168.254.252:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as74be2866
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:41@82.84.141.85:5060
Content-Type: application/sdp
Content-Length: 260

v=0
o=root 1968089850 1968089850 IN IP4 82.84.141.85
s=Asterisk PBX 1.8.8.0
c=IN IP4 82.84.141.85
t=0 0
m=audio 10244 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

Retransmitting #5 (NAT) to 192.168.254.252:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as74be2866
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:41@82.84.141.85:5060
Content-Type: application/sdp
Content-Length: 260

v=0
o=root 1968089850 1968089850 IN IP4 82.84.141.85
s=Asterisk PBX 1.8.8.0
c=IN IP4 82.84.141.85
t=0 0
m=audio 10244 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

Retransmitting #6 (NAT) to 192.168.254.252:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.254.252:5060;branch=z9hG4bK19f25a7f8871fc5521d171ee942c51b4;received=192.168.254.252;rport=5060
From: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
To: sip:41@192.168.254.251;user=phone;tag=as74be2866
Call-ID: 2624490068@192_168_254_252
CSeq: 3 INVITE
Server: FPBX-2.10.0rc1(1.8.8.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:41@82.84.141.85:5060
Content-Type: application/sdp
Content-Length: 260

v=0
o=root 1968089850 1968089850 IN IP4 82.84.141.85
s=Asterisk PBX 1.8.8.0
c=IN IP4 82.84.141.85
t=0 0
m=audio 10244 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

[2012-02-26 00:08:25] WARNING[2703]: chan_sip.c:3629 retrans_pkt: Retransmission timeout reached on transmission 2624490068@192_168_254_252 for seqno 3 (Critical Response) – See wiki.asterisk.org/wiki/display/ … nsmissions
Packet timed out after 6400ms with no response
[2012-02-26 00:08:25] WARNING[2703]: chan_sip.c:3658 retrans_pkt: Hanging up call 2624490068@192_168_254_252 - no reply to our critical packet (see wiki.asterisk.org/wiki/display/ … nsmissions).
– Executing [h@macro-dial-one:1] Macro(“SIP/40-00000011”, “hangupcall,”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“SIP/40-00000011”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [s@macro-hangupcall:3] Hangup(“SIP/40-00000011”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 3) exited non-zero on ‘SIP/40-00000011’ in macro ‘hangupcall’
== Spawn extension (macro-dial-one, h, 1) exited non-zero on 'SIP/40-00000011’
Scheduling destruction of SIP dialog ‘3da371da2839a80e5db690d4619a770b@82.84.141.85:5060’ in 57728 ms (Method: INVITE)
set_destination: Parsing sip:41@109.112.32.152:2071 for address/port to send to
set_destination: set destination to 109.112.32.152:2071
Reliably Transmitting (NAT) to 109.112.32.152:2071:
BYE sip:41@109.112.32.152:2071 SIP/2.0
Via: SIP/2.0/UDP 82.84.141.85:5060;branch=z9hG4bK2696254b;rport
Max-Forwards: 70
From: “Carlo Rogialli” sip:40@82.84.141.85;tag=as09a91840
To: sip:41@109.112.32.152:2071;tag=Uf86e4oXMAle34jUQYAvU.37K4va88hc
Call-ID: 3da371da2839a80e5db690d4619a770b@82.84.141.85:5060
CSeq: 103 BYE
User-Agent: FPBX-2.10.0rc1(1.8.8.0)
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

== Spawn extension (macro-dial-one, s, 42) exited non-zero on ‘SIP/40-00000011’ in macro ‘dial-one’
== Spawn extension (macro-exten-vm, s, 14) exited non-zero on ‘SIP/40-00000011’ in macro ‘exten-vm’
== Spawn extension (from-internal, 41, 2) exited non-zero on 'SIP/40-00000011’
Scheduling destruction of SIP dialog ‘2624490068@192_168_254_252’ in 6400 ms (Method: INVITE)
set_destination: Parsing sip:40@192.168.254.252:5060 for address/port to send to
set_destination: set destination to 192.168.254.252:5060
Reliably Transmitting (NAT) to 192.168.254.252:5060:
BYE sip:40@192.168.254.252:5060 SIP/2.0
Via: SIP/2.0/UDP 82.84.141.85:5060;branch=z9hG4bK6bd1f3cb;rport
Max-Forwards: 70
From: sip:41@192.168.254.251;user=phone;tag=as74be2866
To: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
Call-ID: 2624490068@192_168_254_252
CSeq: 102 BYE
User-Agent: FPBX-2.10.0rc1(1.8.8.0)
Proxy-Authorization: Digest username=“40”, realm=“asterisk”, algorithm=MD5, uri=“sip:192.168.254.251”, nonce="", response="acd8cf5a4ccc10863c026f50e365190a"
X-Asterisk-HangupCause: Protocol error, unspecified
X-Asterisk-HangupCauseCode: 111
Content-Length: 0

Retransmitting #1 (NAT) to 192.168.254.252:5060:
BYE sip:40@192.168.254.252:5060 SIP/2.0
Via: SIP/2.0/UDP 82.84.141.85:5060;branch=z9hG4bK6bd1f3cb;rport
Max-Forwards: 70
From: sip:41@192.168.254.251;user=phone;tag=as74be2866
To: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
Call-ID: 2624490068@192_168_254_252
CSeq: 102 BYE
User-Agent: FPBX-2.10.0rc1(1.8.8.0)
Proxy-Authorization: Digest username=“40”, realm=“asterisk”, algorithm=MD5, uri=“sip:192.168.254.251”, nonce="", response="acd8cf5a4ccc10863c026f50e365190a"
X-Asterisk-HangupCause: Protocol error, unspecified
X-Asterisk-HangupCauseCode: 111
Content-Length: 0

<— SIP read from UDP:109.112.32.152:2071 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 82.84.141.85:5060;rport=5060;received=82.84.141.85;branch=z9hG4bK2696254b
Call-ID: 3da371da2839a80e5db690d4619a770b@82.84.141.85:5060
From: “Carlo Rogialli” sip:40@82.84.141.85;tag=as09a91840
To: sip:41@109.112.32.152;tag=Uf86e4oXMAle34jUQYAvU.37K4va88hc
CSeq: 103 BYE
Content-Length: 0

<------------->
— (7 headers 0 lines) —
Really destroying SIP dialog ‘3da371da2839a80e5db690d4619a770b@82.84.141.85:5060’ Method: INVITE

<— SIP read from UDP:192.168.254.252:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 82.84.141.85:5060;branch=z9hG4bK6bd1f3cb;rport=5060;received=192.168.254.251
From: sip:41@192.168.254.251;user=phone;tag=as74be2866
To: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
Call-ID: 2624490068@192_168_254_252
CSeq: 102 BYE
Contact: sip:40@192.168.254.252:5060
Supported: replaces
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0

<------------->
— (10 headers 0 lines) —
SIP Response message for INCOMING dialog BYE arrived
Really destroying SIP dialog ‘2624490068@192_168_254_252’ Method: INVITE

<— SIP read from UDP:192.168.254.252:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 82.84.141.85:5060;branch=z9hG4bK6bd1f3cb;rport=5060;received=192.168.254.251
From: sip:41@192.168.254.251;user=phone;tag=as74be2866
To: “Carlo Rogialli” sip:40@192.168.254.251;tag=1904198690
Call-ID: 2624490068@192_168_254_252
CSeq: 102 BYE
Contact: sip:40@192.168.254.252:5060
Supported: replaces
Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, INFO, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0

<------------->
— (10 headers 0 lines) —
localhost*CLI> sip set debug off
SIP Debugging Disabled
[2012-02-26 00:09:44] NOTICE[2703]: chan_sip.c:25665 sip_poke_noanswer: Peer ‘41’ is now UNREACHABLE! Last qualify: 163
[2012-02-26 00:0[/list][/ul]

2

There is no ACK to Asterisk’s 200 OK, but, if you had two way audio, the other side must have seen the 200 OK, otherwise it wouldn’t know to where to send the audio.

3

Thanks, David,
I agree to the diagnostic. However, I don’t know why it should behave like this, since A50IP is on the same network of the asterisk PBX, physically cabled on the same switch, and I don’t understand why the 200 Ok is lost.

I’m currently running 1.8.9.1.
On the asterisk change record for 1.8.9.3 I saw what you find in the following.
Do you (or anyone else think) my problem is related to this (specially the second of the two issues mentioned)?

Currently I can’t test 1.8.9.3 since no binary packages seem to be available and I didn’t setup a suitable compile environment.

Thanks a lot.

[code]* Asterisk 1.8.9.3 Released.

* channels/chan_sip.c: Fix ACK routing for non-2xx responses.

  When we send an ACK for a 2xx response to an INVITE, we are supposed
  to use the learned route set. However, when we receive a non-2xx
  final response to an INVITE, we are supposed to send the ACK to the
  same place we initially sent the INVITE.

  We had been doing this up until the changes went in that would build
  a route set from provisional responses. That introduced a regression
  where we would use the learned route set under all circumstances.

  With this change, we now will set the destination of our ACK based on
  the invitestate. If it is INV_COMPLETED then that means that we have
  received a non-2xx final response (INV_TERMINATED indicates a 2xx
  response was received).  If it is INV_CANCELLED, then that means the
  call is being canceled, which means that we should be ACKing a 487
  response.

  The other change introduced here is setting the invitestate to
  INV_CONFIRMED when we send an ACK *after* the reqprep instead of
  before. This way, we can tell in reqprep more easily what the
  invitestate is prior to sending the ACK.

  (closes issue ASTERISK-19389)
  reported by Karsten Wemheuer
  patches:
    ASTERISK-19389v2.patch uploaded by Mark Michelson (license #5049)

[color=#FF0000]* channels/chan_sip.c: Fix regressions with regards to route-set
  creation on early dialogs.

  This fixes two main issues:
  1. Asterisk would send a CANCEL to the route created by the provisional
     response instead of using the same destination it did in the initial
     INVITE.
  2. If a new route set arrives in a 200 OK than was in the 1XX response
     (perfectly possible if our outbound INVITE gets forked), then the
     route set in the 200 OK needs to overwrite the route set in the 1XX
     response.[/color]
  (closes issue ASTERISK-19358)
  Reported by: Karsten Wemheuer
  Tested by: Karsten Wemheuer
  patches:
   ASTERISK-19358.patch uploaded by Mark Michelson (license 5049)
   ASTERISK-19358.patch uploaded by Stefan Schmidt (license 6034)

  Review: https://reviewboard.asterisk.org/r/1749[/code]
4

If you have a good call, i.e. two way audio, for the first 6.4 seconds, the 200 OK has not got lost.

The bug fix you refer to relates to outgoing calls, and only to ones that fail to connect. It is not relevant to this case.

However, it looks like the 200 OK is being sent with your public address, which probably means localnets is set wrongly.

5

Dear David, you’re right.
I was just making a wireshark capture to assess the problem and yes, the phone sends the 200 ACK to the external (dynamic) adsderss of the PBX, and it does it because it is instructed to do so by Asterisk itself.

I mean, the first transaction (status 200 OK) is from Asterisk Internal IP (192.168.254.251) to A580 internal ip (192.168.254.252), but in the connection information in the message body, you find “Connection Information ©: IN IP4 62.10.11.xyz”.
… and in fact the phone replies TO 62.10.11.xyz with a beautiful ACK… that never reaches the server.

If I substitute the A580IP with a softphone (e.g. Counterpath Bria), the transaction is ok, since the softphone seems to disregard rhe information enclosed in the Connection Information.

But [size=200]unfortunately[/size], the [size=200]Localnet seems to be set up correctly[/size]:

nat=yes
externhost=pbx.mycompany.mysuffix
externrefresh=120
localnet=192.168.254.0/255.255.255.192

Then: is it a bug when asterisk deals with sub-class-C Networks?
it is me? I’m missing something?

I’ve tried to set nat in sip.conf in ANY allowed manner, tried directmedia=yes,no,nonat, udate and whatever…
No change in behaviour!

Thanks again

6

(251 & 192) != 0

7

Yes, I dunno how I was so dumb not to see it…
… I’ve just fixed it whilst you wer answering me, 'cause I was reflecting on the mistake.

localnet=192.168.254.192/255.255.255.192

And it works (obviously)
I was disoriented by the fact that Counterpath and other softphones were working apparently correctly.

I have no words for having you to lose time on a so trivial issue.

Thanks again very much