[FIXED] Problem nat with certified-asterisk 11.6

Hello,

I have configured my asterisk server using freepbx, I can register with my smartphone, I can also make a call but I got a retransmission timeout after 32000ms. if the called person anwser the call I can hear a sound but still the problem of timeout appears after 32s.

What is the problem? is it related to registration port because when I make sip show peers, I get port of peer different to 5060

NOTE:
1/ I have configured the localnet and externip and in general I have set nat to yes
in the peers I have activate

nat=force_rport,comedia
qualify=no
canreinvite=no
port=5060
type=friend
2/ my router is TG585, I have deactivated sip alg with router cli
I have added a rules to make port translation
nat mapadd intf=Internet type=napt outside_addr= inside_addr= protocol=udp outside_port=9090 inside_port=5060

Normally a NAT problem.

NB nat= does not configure for normal NAT cases and may not be needed for those. You need to tell Asterisk how to find out its public address. See sip.conf.sample for ways of doing this. This is included with source distributions.

Thanks,

I checked the sip.conf.sample file, I’ll try to set externhost=public_ip:external_port

And I’ll test it, I come back to you with the result

I tried it and I have the same error timeout and call hangup after 3200ms.

NB: the external configured port (napt on TG585 router) is different from 5060

is this the root cause?

It will be easier if you provide SIP INVITE, 200 OK and ACK (although the problem is likely to be that the ACK is going to the wrong place) on for the leg that is suffering the timeout. Also whether the error is at timeout on a critical request or a critical response.

Basically it is likely that the Contact header contains an address and/or port, that is incorrect for the its sender.

Here is my log X.X.X.X is represent asterisk public address (via nat), xxxxxxxx represent called number, 192.168.1.1 server local address, 197.27.60.140:57916 remote sip client:

Retransmitting #10 (NAT) to 197.27.60.140:57916:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 197.27.60.140:57916;branch=z9hG4bKPjtgBWlipxNSCXpD.13huc3Cr8r.3rn0Lo;received=197.27.60.140;rport=57916

From: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P

To: <sip:xxxxxxxx@X.X.X.X>;tag=as5de77968

Call-ID: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4

CSeq: 10461 INVITE

Server: FPBX-12.0.76.2(11.6)

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

Supported: replaces, timer

Session-Expires: 1800;refresher=uas

Contact: <sip:xxxxxxxx@X.X.X.X:5060>

Content-Type: application/sdp

Require: timer

Content-Length: 262



v=0

o=root 817538051 817538052 IN IP4 X.X.X.X

s=Asterisk PBX 11.6-cert4

c=IN IP4 X.X.X.X

t=0 0

m=audio 10800 RTP/AVP 8 101

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

a=sendrecv


---

CLI> 
[2016-03-20 16:08:37] WARNING[3067]: chan_sip.c:4184 retrans_pkt: Retransmission timeout reached on transmission 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4 for seqno 10461 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 31999ms with no response
[2016-03-20 16:08:37] WARNING[3067]: chan_sip.c:4213 retrans_pkt: Hanging up call 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
    -- Executing [h@macro-dialout-trunk:1] Macro("SIP/106-00000135", "hangupcall,") in new stack

CLI> 
    -- Executing [s@macro-hangupcall:1] ExecIf("SIP/106-00000135", "0?Set(CDR(recordingfile)=.wav)") in new stack

CLI> 
    -- Executing [s@macro-hangupcall:2] GotoIf("SIP/106-00000135", "1?theend") in new stack

CLI> 
    -- Goto (macro-hangupcall,s,4)

CLI> 
    -- Executing [s@macro-hangupcall:4] Hangup("SIP/106-00000135", "") in new stack

CLI> 
  == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/106-00000135' in macro 'hangupcall'
  == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/106-00000135'

CLI> 
Scheduling destruction of SIP dialog '44cfe8a957671e38685eaa6b77cec82c@192.168.1.1:5060' in 32000 ms (Method: INVITE)

CLI> 
set_destination: Parsing <sip:xxxxxxxx@192.168.1.250> for address/port to send to

CLI> 
set_destination: set destination to 192.168.1.250:5060

CLI> 
Reliably Transmitting (NAT) to 192.168.1.250:5060:
BYE sip:xxxxxxxx@192.168.1.250 SIP/2.0

Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK0a643320;rport

Max-Forwards: 70

From: "user 106" <sip:106@192.168.1.1>;tag=as63e2fedd

To: <sip:xxxxxxxx@192.168.1.250:5060>;tag=ab3792ab

Call-ID: 44cfe8a957671e38685eaa6b77cec82c@192.168.1.1:5060

CSeq: 103 BYE

User-Agent: FPBX-12.0.76.2(11.6)

X-Asterisk-HangupCause: Normal Clearing

X-Asterisk-HangupCauseCode: 16

Content-Length: 0




---

CLI> 
  == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on 'SIP/106-00000135' in macro 'dialout-trunk'
  == Spawn extension (from-internal, xxxxxxxx, 5) exited non-zero on 'SIP/106-00000135'

CLI> 
Scheduling destruction of SIP dialog '3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4' in 32000 ms (Method: INVITE)

CLI> 
set_destination: Parsing <sip:106@197.27.60.140:57916;ob> for address/port to send to

CLI> 
set_destination: set destination to 197.27.60.140:57916

CLI> 
Reliably Transmitting (NAT) to 197.27.60.140:57916:
BYE sip:106@197.27.60.140:57916;ob SIP/2.0

Via: SIP/2.0/UDP X.X.X.X:5060;branch=z9hG4bK3313f3b6;rport

Max-Forwards: 70

From: <sip:xxxxxxxx@X.X.X.X>;tag=as5de77968

To: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P

Call-ID: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4

CSeq: 102 BYE

User-Agent: FPBX-12.0.76.2(11.6)

Proxy-Authorization: Digest username="106", realm="asterisk", algorithm=MD5, uri="sip:X.X.X.X", nonce="6f0846b6", response="f516fced90180d5d442b61edc8fb651d"

X-Asterisk-HangupCause: No user responding

X-Asterisk-HangupCauseCode: 18

Content-Length: 0

Please re-edit your post to use preformatted, so that the bits in angle brackets aren’t treated as markup.

This is incomplete, but shows an incoming call, where the router is taking responsibility for outbound NAT. Without the INIVITE it is not possible to see what is in your Contact header, but either the router is failing to properly fixup and forward your responses or an unacceptable Contact header is reaching the UAC. I would go for the latter, if the UAC has started sending audio.

Here the first part of asterisk log:

CLI> 
Reliably Transmitting (no NAT) to 192.168.1.250:5060:
OPTIONS sip:203@192.168.1.250 SIP/2.0

Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK1f89ff24

Max-Forwards: 70

From: "Unknown" <sip:Unknown@192.168.1.1>;tag=as3d50b42f

To: <sip:203@192.168.1.250>

Contact: <sip:Unknown@192.168.1.1:5060>

Call-ID: 1b8ac7eb3cc8bb200821f32d7f2e2214@192.168.1.1:5060

CSeq: 102 OPTIONS

User-Agent: FPBX-12.0.76.2(11.6)

Date: Sun, 20 Mar 2016 15:08:03 GMT

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

Supported: replaces, timer

Content-Length: 0




---

CLI> 

<--- SIP read from UDP:192.168.1.250:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK1f89ff24;rport=5060
From: "Unknown" <sip:Unknown@192.168.1.1>;tag=as3d50b42f
To: <sip:203@192.168.1.250>;soid=17;tag=ab37ccd7
Call-ID: 1b8ac7eb3cc8bb200821f32d7f2e2214@192.168.1.1:5060
CSeq: 102 OPTIONS
Supported: in-band-dtmf, timer
User-Agent: EJOIN ACOM208 V3.4 rD647 b1224
User-Agent: EJOIN ACOM208 V3.4 rD647 b1224
Allow: INVITE, ACK, INFO, CANCEL, BYE, OPTIONS, UPDATE, MESSAGE
Accept: application/sdp
Accept-Language: en
Content-Length: 0

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

CLI> 
--- (13 headers 0 lines) ---
Really destroying SIP dialog '1b8ac7eb3cc8bb200821f32d7f2e2214@192.168.1.1:5060' Method: OPTIONS

CLI> 
Reliably Transmitting (no NAT) to 192.168.1.250:5060:
OPTIONS sip:202@192.168.1.250 SIP/2.0

Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK3db5f121

Max-Forwards: 70

From: "Unknown" <sip:Unknown@192.168.1.1>;tag=as3e9c2403

To: <sip:202@192.168.1.250>

Contact: <sip:Unknown@192.168.1.1:5060>

Call-ID: 47237c94767491fa5c51c8501fbd99ce@192.168.1.1:5060

CSeq: 102 OPTIONS

User-Agent: FPBX-12.0.76.2(11.6)

Date: Sun, 20 Mar 2016 15:08:03 GMT

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

Supported: replaces, timer

Content-Length: 0




---

CLI> 

<--- SIP read from UDP:192.168.1.250:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK3db5f121;rport=5060
From: "Unknown" <sip:Unknown@192.168.1.1>;tag=as3e9c2403
To: <sip:202@192.168.1.250>;soid=17;tag=ab378c7f
Call-ID: 47237c94767491fa5c51c8501fbd99ce@192.168.1.1:5060
CSeq: 102 OPTIONS
Supported: in-band-dtmf, timer
User-Agent: EJOIN ACOM208 V3.4 rD647 b1224
User-Agent: EJOIN ACOM208 V3.4 rD647 b1224
Allow: INVITE, ACK, INFO, CANCEL, BYE, OPTIONS, UPDATE, MESSAGE
Accept: application/sdp
Accept-Language: en
Content-Length: 0

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

CLI> 
--- (13 headers 0 lines) ---

CLI> 
Really destroying SIP dialog '47237c94767491fa5c51c8501fbd99ce@192.168.1.1:5060' Method: OPTIONS

CLI> 
Reliably Transmitting (no NAT) to 192.168.1.250:5060:
OPTIONS sip:201@192.168.1.250 SIP/2.0

Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK58525b33

Max-Forwards: 70

From: "Unknown" <sip:Unknown@192.168.1.1>;tag=as420dc19c

To: <sip:201@192.168.1.250>

Contact: <sip:Unknown@192.168.1.1:5060>

Call-ID: 730ac98926eaaf0e359ff2507d01ce33@192.168.1.1:5060

CSeq: 102 OPTIONS

User-Agent: FPBX-12.0.76.2(11.6)

Date: Sun, 20 Mar 2016 15:08:03 GMT

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

Supported: replaces, timer

Content-Length: 0




---

CLI> 

<--- SIP read from UDP:192.168.1.250:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK58525b33;rport=5060
From: "Unknown" <sip:Unknown@192.168.1.1>;tag=as420dc19c
To: <sip:201@192.168.1.250>;soid=17;tag=ab37fa95
Call-ID: 730ac98926eaaf0e359ff2507d01ce33@192.168.1.1:5060
CSeq: 102 OPTIONS
Supported: in-band-dtmf, timer
User-Agent: EJOIN ACOM208 V3.4 rD647 b1224
User-Agent: EJOIN ACOM208 V3.4 rD647 b1224
Allow: INVITE, ACK, INFO, CANCEL, BYE, OPTIONS, UPDATE, MESSAGE
Accept: application/sdp
Accept-Language: en
Content-Length: 0

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

CLI> 
--- (13 headers 0 lines) ---

CLI> 
Really destroying SIP dialog '730ac98926eaaf0e359ff2507d01ce33@192.168.1.1:5060' Method: OPTIONS

CLI> 

<--- SIP read from UDP:197.27.60.140:57916 --->
INVITE sip:xxxxxxxx@X.X.X.X SIP/2.0
v: SIP/2.0/UDP 197.27.60.140:57916;rport;branch=z9hG4bKPju2uudYhq5xrftAC7LY8y4B6CU5PFLFAw
Max-Forwards: 70
f: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P
t: <sip:xxxxxxxx@X.X.X.X>
m: "106" <sip:106@197.27.60.140:57916;ob>
i: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4
CSeq: 10460 INVITE
Route: <sip:X.X.X.X:9009;lr>
k: replaces, 100rel, timer, norefersub
x: 1800
Min-SE: 90
User-Agent: CSipSimple_cs02-17/r2457
c: application/sdp
l: 300

v=0
o=- 3667479196 3667479196 IN IP4 197.27.60.140
s=pjmedia
c=IN IP4 197.27.60.140
t=0 0
m=audio 4002 RTP/AVP 99 0 8 101
c=IN IP4 197.27.60.140
a=rtcp:4003 IN IP4 197.27.60.140
a=sendrecv
a=rtpmap:99 SILK/24000
a=fmtp:99 useinbandfec=0
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
<------------->

CLI> 
--- (15 headers 13 lines) ---

CLI> 
Sending to 197.27.60.140:57916 (NAT)

CLI> 
Sending to 197.27.60.140:57916 (NAT)

CLI> 
Using INVITE request as basis request - 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4

CLI> 
Found peer '106' for '106' from 197.27.60.140:57916

CLI> 

<--- Reliably Transmitting (NAT) to 197.27.60.140:57916 --->
SIP/2.0 401 Unauthorized

Via: SIP/2.0/UDP 197.27.60.140:57916;branch=z9hG4bKPju2uudYhq5xrftAC7LY8y4B6CU5PFLFAw;received=197.27.60.140;rport=57916

From: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P

To: <sip:xxxxxxxx@X.X.X.X>;tag=as4e471153

Call-ID: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4

CSeq: 10460 INVITE

Server: FPBX-12.0.76.2(11.6)

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

Supported: replaces, timer

WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="6f0846b6"

Content-Length: 0




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

CLI> 
Scheduling destruction of SIP dialog '3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4' in 32000 ms (Method: INVITE)

CLI> 

<--- SIP read from UDP:197.27.60.140:57916 --->
ACK sip:xxxxxxxx@X.X.X.X SIP/2.0
v: SIP/2.0/UDP 197.27.60.140:57916;rport;branch=z9hG4bKPju2uudYhq5xrftAC7LY8y4B6CU5PFLFAw
Max-Forwards: 70
f: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P
t: <sip:xxxxxxxx@X.X.X.X>;tag=as4e471153
i: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4
CSeq: 10460 ACK
Route: <sip:X.X.X.X:9009;lr>
l: 0

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

CLI> 
--- (9 headers 0 lines) ---

CLI> 

<--- SIP read from UDP:197.27.60.140:57916 --->
INVITE sip:xxxxxxxx@X.X.X.X SIP/2.0
v: SIP/2.0/UDP 197.27.60.140:57916;rport;branch=z9hG4bKPjtgBWlipxNSCXpD.13huc3Cr8r.3rn0Lo
Max-Forwards: 70
f: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P
t: <sip:xxxxxxxx@X.X.X.X>
m: "106" <sip:106@197.27.60.140:57916;ob>
i: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4
CSeq: 10461 INVITE
Route: <sip:X.X.X.X:9009;lr>
k: replaces, 100rel, timer, norefersub
x: 1800
Min-SE: 90
User-Agent: CSipSimple_cs02-17/r2457
Authorization: Digest username="106", realm="asterisk", nonce="6f0846b6", uri="sip:xxxxxxxx@X.X.X.X", response="e82042ab4c9a5818b18eb780a9551bf6", algorithm=MD5
c: application/sdp
l: 300

v=0
o=- 3667479196 3667479196 IN IP4 197.27.60.140
s=pjmedia
c=IN IP4 197.27.60.140
t=0 0
m=audio 4002 RTP/AVP 99 0 8 101
c=IN IP4 197.27.60.140
a=rtcp:4003 IN IP4 197.27.60.140
a=sendrecv
a=rtpmap:99 SILK/24000
a=fmtp:99 useinbandfec=0
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
<------------->

CLI> 
--- (16 headers 13 lines) ---

CLI> 
Sending to 197.27.60.140:57916 (NAT)
Using INVITE request as basis request - 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4

CLI> 
Found peer '106' for '106' from 197.27.60.140:57916

CLI> 
  == Using SIP RTP TOS bits 184

CLI> 
  == Using SIP RTP CoS mark 5

CLI> 
Found RTP audio format 99

CLI> 
Found RTP audio format 0

CLI> 
Found RTP audio format 8

CLI> 
Found RTP audio format 101

CLI> 
Found audio description format SILK for ID 99

CLI> 
Found audio description format telephone-event for ID 101

CLI> 
Capabilities: us - (gsm|alaw|g726), peer - audio=(ulaw|alaw|silk24)/video=(nothing)/text=(nothing), combined - (alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 197.27.60.140:4002

CLI> 
Looking for xxxxxxxx in from-internal (domain X.X.X.X)

CLI> 
list_route: hop: <sip:106@197.27.60.140:57916;ob>

CLI> 

<--- Transmitting (NAT) to 197.27.60.140:57916 --->
SIP/2.0 100 Trying

Via: SIP/2.0/UDP 197.27.60.140:57916;branch=z9hG4bKPjtgBWlipxNSCXpD.13huc3Cr8r.3rn0Lo;received=197.27.60.140;rport=57916

From: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P

To: <sip:xxxxxxxx@X.X.X.X>

Call-ID: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4

CSeq: 10461 INVITE

Server: FPBX-12.0.76.2(11.6)

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

Supported: replaces, timer

Session-Expires: 1800;refresher=uas

Contact: <sip:xxxxxxxx@X.X.X.X:5060>

Content-Length: 0

part 2:

CLI> -- Executing [xxxxxxxx@from-internal:1] Macro("SIP/106-00000135", "user-callerid,LIMIT,EXTERNAL,") in new stack

CLI> -- Executing [s@macro-user-callerid:1] Set("SIP/106-00000135", "TOUCH_MONITOR=1458486485.309") in new stack

CLI> -- Executing [s@macro-user-callerid:2] Set("SIP/106-00000135", "AMPUSER=106") in new stack

CLI> -- Executing [s@macro-user-callerid:3] GotoIf("SIP/106-00000135", "0?report") in new stack

CLI> -- Executing [s@macro-user-callerid:4] ExecIf("SIP/106-00000135", "1?Set(REALCALLERIDNUM=106)") in new stack

CLI> -- Executing [s@macro-user-callerid:5] Set("SIP/106-00000135", "AMPUSER=106") in new stack

CLI> -- Executing [s@macro-user-callerid:6] GotoIf("SIP/106-00000135", "0?limit") in new stack

CLI> -- Executing [s@macro-user-callerid:7] Set("SIP/106-00000135", "AMPUSERCIDNAME=user 106") in new stack

CLI> -- Executing [s@macro-user-callerid:8] GotoIf("SIP/106-00000135", "0?report") in new stack

CLI> -- Executing [s@macro-user-callerid:9] Set("SIP/106-00000135", "AMPUSERCID=106") in new stack

CLI> -- Executing [s@macro-user-callerid:10] Set("SIP/106-00000135", "__DIAL_OPTIONS=Ttm") in new stack

CLI> -- Executing [s@macro-user-callerid:11] Set("SIP/106-00000135", "CALLERID(all)="user 106" <106>") in new stack

CLI> -- Executing [s@macro-user-callerid:12] GotoIf("SIP/106-00000135", "0?limit") in new stack

CLI> -- Executing [s@macro-user-callerid:13] ExecIf("SIP/106-00000135", "1?Set(GROUP(concurrency_limit)=106)") in new stack

CLI> -- Executing [s@macro-user-callerid:14] GotoIf("SIP/106-00000135", "1?continue") in new stack

CLI> -- Goto (macro-user-callerid,s,27)

CLI> -- Executing [s@macro-user-callerid:27] Set("SIP/106-00000135", "CALLERID(number)=106") in new stack

CLI> -- Executing [s@macro-user-callerid:28] Set("SIP/106-00000135", "CALLERID(name)=user 106") in new stack

CLI> -- Executing [s@macro-user-callerid:29] Set("SIP/106-00000135", "CDR(cnum)=106") in new stack

CLI> -- Executing [s@macro-user-callerid:30] Set("SIP/106-00000135", "CDR(cnam)=user 106") in new stack

CLI> -- Executing [s@macro-user-callerid:31] Set("SIP/106-00000135", "CHANNEL(language)=fr") in new stack

CLI> -- Executing [xxxxxxxx@from-internal:2] Gosub("SIP/106-00000135", "sub-record-check,s,1(out,xxxxxxxx,dontcare)") in new stack

CLI> -- Executing [s@sub-record-check:1] GotoIf("SIP/106-00000135", "0?initialized") in new stack

CLI> -- Executing [s@sub-record-check:2] Set("SIP/106-00000135", "__REC_STATUS=INITIALIZED") in new stack

CLI> -- Executing [s@sub-record-check:3] Set("SIP/106-00000135", "NOW=1458486485") in new stack

CLI> -- Executing [s@sub-record-check:4] Set("SIP/106-00000135", "__DAY=20") in new stack

CLI> -- Executing [s@sub-record-check:5] Set("SIP/106-00000135", "__MONTH=03") in new stack

CLI> -- Executing [s@sub-record-check:6] Set("SIP/106-00000135", "__YEAR=2016") in new stack

CLI> -- Executing [s@sub-record-check:7] Set("SIP/106-00000135", "__TIMESTR=20160320-160805") in new stack

CLI> -- Executing [s@sub-record-check:8] Set("SIP/106-00000135", "__FROMEXTEN=106") in new stack

CLI> -- Executing [s@sub-record-check:9] Set("SIP/106-00000135", "__MON_FMT=wav") in new stack

CLI> -- Executing [s@sub-record-check:10] NoOp("SIP/106-00000135", "Recordings initialized") in new stack

CLI> -- Executing [s@sub-record-check:11] ExecIf("SIP/106-00000135", "0?Set(ARG3=dontcare)") in new stack

CLI> -- Executing [s@sub-record-check:12] Set("SIP/106-00000135", "REC_POLICY_MODE_SAVE=") in new stack

CLI> -- Executing [s@sub-record-check:13] ExecIf("SIP/106-00000135", "0?Set(REC_STATUS=NO)") in new stack

CLI> -- Executing [s@sub-record-check:14] GotoIf("SIP/106-00000135", "3?checkaction") in new stack

CLI> -- Goto (sub-record-check,s,17)

CLI> -- Executing [s@sub-record-check:17] GotoIf("SIP/106-00000135", "1?sub-record-check,out,1") in new stack

CLI> -- Goto (sub-record-check,out,1)

CLI> -- Executing [out@sub-record-check:1] NoOp("SIP/106-00000135", "Outbound Recording Check from 106 to xxxxxxxx") in new stack

CLI> -- Executing [out@sub-record-check:2] Set("SIP/106-00000135", "RECMODE=dontcare") in new stack

CLI> -- Executing [out@sub-record-check:3] ExecIf("SIP/106-00000135", "1?Goto(routewins)") in new stack

CLI> -- Goto (sub-record-check,out,7)

CLI> -- Executing [out@sub-record-check:7] Gosub("SIP/106-00000135", "recordcheck,1(dontcare,out,xxxxxxxx)") in new stack

CLI> -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/106-00000135", "Starting recording check against dontcare") in new stack

CLI> -- Executing [recordcheck@sub-record-check:2] Goto("SIP/106-00000135", "dontcare") in new stack

CLI> -- Goto (sub-record-check,recordcheck,3)

CLI> -- Executing [recordcheck@sub-record-check:3] Return("SIP/106-00000135", "") in new stack

CLI> -- Executing [out@sub-record-check:8] Return("SIP/106-00000135", "") in new stack

CLI> -- Executing [xxxxxxxx@from-internal:3] Set("SIP/106-00000135", "MOHCLASS=default") in new stack

CLI> -- Executing [xxxxxxxx@from-internal:4] Set("SIP/106-00000135", "_NODEST=") in new stack

CLI> -- Executing [xxxxxxxx@from-internal:5] Macro("SIP/106-00000135", "dialout-trunk,2,xxxxxxxx,,off") in new stack

CLI> -- Executing [s@macro-dialout-trunk:1] Set("SIP/106-00000135", "DIAL_TRUNK=2") in new stack

CLI> -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/106-00000135", "0?sub-pincheck,s,1()") in new stack

CLI> -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/106-00000135", "0?disabletrunk,1") in new stack

CLI> -- Executing [s@macro-dialout-trunk:4] Set("SIP/106-00000135", "DIAL_NUMBER=xxxxxxxx") in new stack

CLI> -- Executing [s@macro-dialout-trunk:5] Set("SIP/106-00000135", "DIAL_TRUNK_OPTIONS=Ttm") in new stack

CLI> -- Executing [s@macro-dialout-trunk:6] Set("SIP/106-00000135", "OUTBOUND_GROUP=OUT_2") in new stack

CLI> -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/106-00000135", "1?nomax") in new stack
    -- Goto (macro-dialout-trunk,s,9)

CLI> -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/106-00000135", "0?skipoutcid") in new stack

CLI> -- Executing [s@macro-dialout-trunk:10] Set("SIP/106-00000135", "DIAL_TRUNK_OPTIONS=Tt") in new stack

CLI> -- Executing [s@macro-dialout-trunk:11] Macro("SIP/106-00000135", "outbound-callerid,2") in new stack

CLI> -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/106-00000135", "0?Set(CALLERPRES()=)") in new stack

CLI> -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/106-00000135", "0?Set(REALCALLERIDNUM=106)") in new stack

CLI> -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/106-00000135", "1?normcid") in new stack

CLI> -- Goto (macro-outbound-callerid,s,6)

CLI> -- Executing [s@macro-outbound-callerid:6] Set("SIP/106-00000135", "USEROUTCID=") in new stack

CLI> -- Executing [s@macro-outbound-callerid:7] Set("SIP/106-00000135", "EMERGENCYCID=") in new stack

CLI> -- Executing [s@macro-outbound-callerid:8] Set("SIP/106-00000135", "TRUNKOUTCID=") in new stack

CLI> -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/106-00000135", "1?trunkcid") in new stack

CLI> -- Goto (macro-outbound-callerid,s,14)

CLI> -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/106-00000135", "0?Set(CALLERID(all)=)") in new stack

CLI> -- Executing [s@macro-outbound-callerid:15] ExecIf("SIP/106-00000135", "0?Set(CALLERID(all)=)") in new stack

CLI> -- Executing [s@macro-outbound-callerid:16] ExecIf("SIP/106-00000135", "0?Set(CALLERID(all)=)") in new stack

CLI> -- Executing [s@macro-outbound-callerid:17] ExecIf("SIP/106-00000135", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack

CLI> -- Executing [s@macro-outbound-callerid:18] Set("SIP/106-00000135", "CDR(outbound_cnum)=106") in new stack

CLI> -- Executing [s@macro-outbound-callerid:19] Set("SIP/106-00000135", "CDR(outbound_cnam)=user 106") in new stack

CLI> -- Executing [s@macro-dialout-trunk:12] GosubIf("SIP/106-00000135", "0?sub-flp-2,s,1()") in new stack

CLI> -- Executing [s@macro-dialout-trunk:13] Set("SIP/106-00000135", "OUTNUM=xxxxxxxx") in new stack

CLI> -- Executing [s@macro-dialout-trunk:14] Set("SIP/106-00000135", "custom=SIP/901") in new stack

CLI> -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/106-00000135", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)") in new stack

CLI> -- Executing [s@macro-dialout-trunk:16] ExecIf("SIP/106-00000135", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack

CLI> -- Executing [s@macro-dialout-trunk:17] Macro("SIP/106-00000135", "dialout-trunk-predial-hook,") in new stack
    -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/106-00000135", "") in new stack

CLI> -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/106-00000135", "0?bypass,1") in new stack

CLI> -- Executing [s@macro-dialout-trunk:19] ExecIf("SIP/106-00000135", "1?Set(CONNECTEDLINE(num,i)=xxxxxxxx)") in new stack

CLI> -- Executing [s@macro-dialout-trunk:20] ExecIf("SIP/106-00000135", "1?Set(CONNECTEDLINE(name,i)=CID:106)") in new stack

CLI> -- Executing [s@macro-dialout-trunk:21] GotoIf("SIP/106-00000135", "0?customtrunk") in new stack

CLI> -- Executing [s@macro-dialout-trunk:22] Dial("SIP/106-00000135", "SIP/901/xxxxxxxx,300,Tt") in new stack

CLI> 
  == Using SIP RTP TOS bits 184

CLI> 
  == Using SIP RTP CoS mark 5

CLI> 
Audio is at 12240

CLI> 
Adding codec 100004 (alaw) to SDP

CLI> 
Adding codec 100002 (gsm) to SDP

CLI> 
Adding codec 100011 (g726) to SDP

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

CLI> 
Reliably Transmitting (NAT) to 192.168.1.250:5060:
INVITE sip:xxxxxxxx@192.168.1.250:5060 SIP/2.0

Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK3eb5e19b;rport

Max-Forwards: 70

From: "user 106" <sip:106@192.168.1.1>;tag=as63e2fedd

To: <sip:xxxxxxxx@192.168.1.250:5060>

Contact: <sip:106@192.168.1.1:5060>

Call-ID: 44cfe8a957671e38685eaa6b77cec82c@192.168.1.1:5060

CSeq: 102 INVITE

User-Agent: FPBX-12.0.76.2(11.6)

Date: Sun, 20 Mar 2016 15:08:05 GMT

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

Supported: replaces, timer

Content-Type: application/sdp

Content-Length: 318



v=0

o=root 1837586748 1837586748 IN IP4 192.168.1.1

s=Asterisk PBX 11.6-cert4

c=IN IP4 192.168.1.1

t=0 0

m=audio 12240 RTP/AVP 8 3 111 101

a=rtpmap:8 PCMA/8000

a=rtpmap:3 GSM/8000

a=rtpmap:111 G726-32/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

a=sendrecv


---

CLI> -- Called SIP/901/xxxxxxxx

part 3:
CLI>

<--- SIP read from UDP:192.168.1.250:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK3eb5e19b;rport=5060
From: "user 106" <sip:106@192.168.1.1>;tag=as63e2fedd
To: <sip:xxxxxxxx@192.168.1.250>;soid=17;tag=ab3792ab
Contact: <sip:xxxxxxxx@192.168.1.250>
Call-ID: 44cfe8a957671e38685eaa6b77cec82c@192.168.1.1:5060
CSeq: 102 INVITE
User-Agent: EJOIN ACOM208 V3.4 rD647 b1224
Content-Length: 0

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

CLI> 
--- (9 headers 0 lines) ---

CLI> 

<--- SIP read from UDP:192.168.1.250:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK3eb5e19b;rport=5060
From: "user 106" <sip:106@192.168.1.1>;tag=as63e2fedd
To: <sip:xxxxxxxx@192.168.1.250>;soid=17;tag=ab3792ab
Contact: <sip:xxxxxxxx@192.168.1.250>
Call-ID: 44cfe8a957671e38685eaa6b77cec82c@192.168.1.1:5060
CSeq: 102 INVITE
Supported: in-band-dtmf, timer
User-Agent: EJOIN ACOM208 V3.4 rD647 b1224
Content-Type: application/sdp
Content-Length: 225

v=0
o=root 3667508133 3667508133 IN IP4 192.168.1.250
s=SIP CALL
c=IN IP4 192.168.1.250
t=0 0
m=audio 8008 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
<------------->

CLI> 
--- (11 headers 11 lines) ---

CLI> 
list_route: hop: <sip:xxxxxxxx@192.168.1.250>

CLI> 
Found RTP audio format 8

CLI> 
Found RTP audio format 101

CLI> 
Found audio description format PCMA for ID 8

CLI> 
Found audio description format telephone-event for ID 101

CLI> 
Capabilities: us - (gsm|alaw|g726), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw)

CLI> 
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)

CLI> 
Peer audio RTP is at port 192.168.1.250:8008

CLI> -- SIP/901-00000136 is making progress passing it to SIP/106-00000135

CLI> 
Audio is at 10800

CLI> 
Adding codec 100004 (alaw) to SDP

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

CLI> 

<--- Transmitting (NAT) to 197.27.60.140:57916 --->
SIP/2.0 183 Session Progress

Via: SIP/2.0/UDP 197.27.60.140:57916;branch=z9hG4bKPjtgBWlipxNSCXpD.13huc3Cr8r.3rn0Lo;received=197.27.60.140;rport=57916

From: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P

To: <sip:xxxxxxxx@X.X.X.X>;tag=as5de77968

Call-ID: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4

CSeq: 10461 INVITE

Server: FPBX-12.0.76.2(11.6)

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

Supported: replaces, timer

Session-Expires: 1800;refresher=uas

Contact: <sip:xxxxxxxx@X.X.X.X:5060>

Content-Type: application/sdp

Require: timer

Content-Length: 262



v=0

o=root 817538051 817538051 IN IP4 X.X.X.X

s=Asterisk PBX 11.6-cert4

c=IN IP4 X.X.X.X

t=0 0

m=audio 10800 RTP/AVP 8 101

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

a=sendrecv


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

CLI> 

<--- SIP read from UDP:192.168.1.250:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK3eb5e19b;rport=5060
From: "user 106" <sip:106@192.168.1.1>;tag=as63e2fedd
To: <sip:xxxxxxxx@192.168.1.250>;soid=17;tag=ab3792ab
Contact: <sip:xxxxxxxx@192.168.1.250>
Call-ID: 44cfe8a957671e38685eaa6b77cec82c@192.168.1.1:5060
CSeq: 102 INVITE
Supported: in-band-dtmf, timer
User-Agent: EJOIN ACOM208 V3.4 rD647 b1224
Allow: INVITE, ACK, INFO, CANCEL, BYE, OPTIONS, UPDATE, MESSAGE
Content-Type: application/sdp
Content-Length: 225

v=0
o=root 3667508133 3667508133 IN IP4 192.168.1.250
s=SIP CALL
c=IN IP4 192.168.1.250
t=0 0
m=audio 8008 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
<------------->

CLI> 
--- (12 headers 11 lines) ---

CLI> 
list_route: hop: <sip:xxxxxxxx@192.168.1.250>
set_destination: Parsing <sip:xxxxxxxx@192.168.1.250> for address/port to send to

CLI> 
set_destination: set destination to 192.168.1.250:5060
Transmitting (NAT) to 192.168.1.250:5060:
ACK sip:xxxxxxxx@192.168.1.250 SIP/2.0

Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK20bd49c0;rport

Max-Forwards: 70

From: "user 106" <sip:106@192.168.1.1>;tag=as63e2fedd

To: <sip:xxxxxxxx@192.168.1.250:5060>;tag=ab3792ab

Contact: <sip:106@192.168.1.1:5060>

Call-ID: 44cfe8a957671e38685eaa6b77cec82c@192.168.1.1:5060

CSeq: 102 ACK

User-Agent: FPBX-12.0.76.2(11.6)

Content-Length: 0




---
    -- SIP/901-00000136 answered SIP/106-00000135
Audio is at 10800
Adding codec 100004 (alaw) to SDP

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

CLI> 

<--- Reliably Transmitting (NAT) to 197.27.60.140:57916 --->
SIP/2.0 200 OK

Via: SIP/2.0/UDP 197.27.60.140:57916;branch=z9hG4bKPjtgBWlipxNSCXpD.13huc3Cr8r.3rn0Lo;received=197.27.60.140;rport=57916

From: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P

To: <sip:xxxxxxxx@X.X.X.X>;tag=as5de77968

Call-ID: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4

CSeq: 10461 INVITE

Server: FPBX-12.0.76.2(11.6)

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

Supported: replaces, timer

Session-Expires: 1800;refresher=uas

Contact: <sip:xxxxxxxx@X.X.X.X:5060>

Content-Type: application/sdp

Require: timer

Content-Length: 262



v=0

o=root 817538051 817538052 IN IP4 X.X.X.X

s=Asterisk PBX 11.6-cert4

c=IN IP4 X.X.X.X

t=0 0

m=audio 10800 RTP/AVP 8 101

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

a=sendrecv

part 4, I have noticed that contact first retransmit “Contact: sip:xxxxxxxx@X.X.X.X:5060” but the port is redirected in router another port (9090) and the remote client sip use rport=57916:

CLI> 
Retransmitting #1 (NAT) to 197.27.60.140:57916:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 197.27.60.140:57916;branch=z9hG4bKPjtgBWlipxNSCXpD.13huc3Cr8r.3rn0Lo;received=197.27.60.140;rport=57916

From: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P

To: <sip:xxxxxxxx@X.X.X.X>;tag=as5de77968

Call-ID: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4

CSeq: 10461 INVITE

Server: FPBX-12.0.76.2(11.6)

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

Supported: replaces, timer

Session-Expires: 1800;refresher=uas

Contact: <sip:xxxxxxxx@X.X.X.X:5060>

Content-Type: application/sdp

Require: timer

Content-Length: 262



v=0

o=root 817538051 817538052 IN IP4 X.X.X.X

s=Asterisk PBX 11.6-cert4

c=IN IP4 X.X.X.X

t=0 0

m=audio 10800 RTP/AVP 8 101

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

a=sendrecv


---

CLI> 
Retransmitting #2 (NAT) to 197.27.60.140:57916:
SIP/2.0 200 OK

Via: SIP/2.0/UDP 197.27.60.140:57916;branch=z9hG4bKPjtgBWlipxNSCXpD.13huc3Cr8r.3rn0Lo;received=197.27.60.140;rport=57916

From: "106" <sip:106@X.X.X.X>;tag=dZPNasj.udCNzxkHtBDcvIeQQr9xiQ4P

To: <sip:xxxxxxxx@X.X.X.X>;tag=as5de77968

Call-ID: 3KFLBxkjvKBu1MgwnfY0C7fIwU98x7z4

CSeq: 10461 INVITE

Server: FPBX-12.0.76.2(11.6)

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

Supported: replaces, timer

Session-Expires: 1800;refresher=uas

Contact: <sip:xxxxxxxx@X.X.X.X:5060>

Content-Type: application/sdp

Require: timer

Content-Length: 262



v=0

o=root 817538051 817538052 IN IP4 X.X.X.X

s=Asterisk PBX 11.6-cert4

c=IN IP4 X.X.X.X

t=0 0

m=audio 10800 RTP/AVP 8 101

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

a=sendrecv


---

CLI> 
Reliably Transmitting (NAT) to 192.168.1.74:5060:
OPTIONS sip:100@192.168.1.74:5060;x-ippbx-dm-supported SIP/2.0

Via: SIP/2.0/UDP 192.168.1.1:5060;branch=z9hG4bK616209a8;rport

Max-Forwards: 70

From: "Unknown" <sip:Unknown@192.168.1.1>;tag=as79176eec

To: <sip:100@192.168.1.74:5060;x-ippbx-dm-supported>

Contact: <sip:Unknown@192.168.1.1:5060>

Call-ID: 4a4538e22ca84f7250615ce77fa0b815@192.168.1.1:5060

CSeq: 102 OPTIONS

User-Agent: FPBX-12.0.76.2(11.6)

Date: Sun, 20 Mar 2016 15:08:08 GMT

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

Supported: replaces, timer

Content-Length: 0

Starts too late. You need the INVITE that matches the retransmitted 200 OK.

However, I slightly misled you. The Contact header that would have to be wrong for the ACK to go astray is the one on the OK:

Contact: <sip:xxxxxxxx@X.X.X.X:5060>

Will that address and port get back to your Asterisk through the router?

I have the following config:

asterisk ipbx @192.168.1.1 <-------> @local 192.168.1.254 (192.168.1.1:5060) router TG585 @public X.X.X.X (remote port 9090) <-internet-> @public 197.27.60.140 router @local 192.168.1.1<---> @local 192.168.1.3 smartphone (rport 57916) registered with X.X.X.X:9090

smartphone config:
user 106
proxy: X.X.X.X:9090
server: X.X.X.X:9090
auth name: X.X.X.X:9090

If I change the nat port to 5060, that resolve the problem?

it works, when I change external port to the defaut value as the local port.