No audio using remote PJSIP behind NAT, CHANSIP works fine

argentek · February 3, 2019, 9:48pm

Hi,
I want to move to self hosted FreePBX. For my extension, I have an endpoint in the office and one at home. For that reason, I want to use PJSIP.

I created the extension and configured my audiocodes 440HD phone. Phone registers and makes calls, but there is no audio at all.

I have the UDP port 5060 and UDP Range 10000 to 20000 forwarded to the FreePBX.

For testing purposes, I set up CHANSIP and configured the endpoint at home and it worked fine.
I also used a softphone at home using PJSIP and it worked fine.
Lastly, DMZ’d my audiocodes endpoint at home and then I had one way audio working using PJSIP.

From my reading, PJSIP requires NAT to be enabled on the endpoint, but I see nothing in the configuration of the Audiocodes 440hd to change NAT settings.

Any ideas what I should do at this point to get my phone working with PJSIP?

Edit: Current Asterisk Version: 13.19.1

PitzKey · February 3, 2019, 11:06pm

Try enabling ICE Support in the extension advanced settings.

Also, under Settings > SIP Settings > PJSIP is allow reload set to yes?

argentek · February 3, 2019, 11:32pm

Enabling ICE did not solve the issue.

Allow Transports Reload is set to yes.

Any other thoughts?

BlazeStudios · February 4, 2019, 12:37am

asterisk -r
pjsip set logger on

Make the call, get the full debug and post it.

philparker · February 4, 2019, 1:43am

I had a similar situation as yours on an older deployment and everything was set correctly. Needed to restart asterisk in order to correct the “no audio”. Can remember if I used “fwconsole restart” or “asterisk core reload” though.

BlazeStudios · February 4, 2019, 3:17am

If you would have read the full post you would see that when the OP uses a softphone at the same remote location over PJSIP there are no issues. When the problem phone is DMZ’d there is one way instead of no. This is clearly a NAT/network settings issue at the remote location. Randomly restarting Asterisk isnt an answer.

argentek · February 4, 2019, 3:58am

Part 1:
[2019-02-04 03:45:17] WARNING[20491] res_pjsip_registrar.c: Endpoint ‘anonymous’ has no configured AORs

[2019-02-04 03:45:25] VERBOSE[20490] res_pjsip_logger.c: <— Received SIP request (1292 bytes) from UDP:38.26.23.34:5060 —>

INVITE sip:17183076648@companyurlurl:5060 SIP/2.0

From: "Company"<sip:120@companyurlurl>;tag=855690-1501a8c0-13c4-55013-3ee0-656a1b21-3ee0

To: <sip:17183076648@companyurlurl:5060>

Call-ID: 85a128-1501a8c0-13c4-55013-3ee0-994944b-3ee0

CSeq: 1 INVITE

Via: SIP/2.0/UDP 38.26.23.34:5060;rport;branch=z9hG4bK-3ee0-f59bc7-20be0196

Max-Forwards: 70

Supported: replaces,100rel,eventlist,timer

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

User-Agent: AUDC-IPPhone/2.2.16.142.12 (440HDG-Rev1; 00908F61344B)

Contact: <sip:[email protected]:5060>

Session-Expires: 1800

Min-SE: 90

Content-Type: application/sdp

Content-Length: 584

v=0

o=120 1549251987 1549251987 IN IP4 38.26.23.34

s=-

c=IN IP4 38.26.23.34

t=0 0

m=audio 4006 RTP/AVP 9 0 8 111 18 102 101

a=rtpmap:9 G722/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:111 opus/48000/2

a=fmtp:111 maxplaybackrate=16000; sprop-maxcapturerate=16000; maxaveragebitrate=50000; minptime=10; stereo=0; sprop-stereo=0; cbr=0; useinbandfec=1; usedtx=0; smaxpr=50;

a=ptime:20

a=maxptime:120

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:102 telephone-event/48000

a=fmtp:102 0-15

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=sendrecv

[2019-02-04 03:45:25] VERBOSE[20491] res_pjsip_logger.c: <— Transmitting SIP response (572 bytes) to UDP:38.26.23.34:5060 —>

SIP/2.0 401 Unauthorized

Via: SIP/2.0/UDP 38.26.23.34:5060;rport=5060;received=38.26.23.34;branch=z9hG4bK-3ee0-f59bc7-20be0196

Call-ID: 85a128-1501a8c0-13c4-55013-3ee0-994944b-3ee0

From: "Company" <sip:120@companyurlurl>;tag=855690-1501a8c0-13c4-55013-3ee0-656a1b21-3ee0

To: <sip:17183076648@companyurlurl>;tag=z9hG4bK-3ee0-f59bc7-20be0196

CSeq: 1 INVITE

WWW-Authenticate: Digest realm="asterisk",nonce="1549251925/09055d9979a00df7e7cd3da8cc336e33",opaque="335d5b964e03d691",algorithm=md5,qop="auth"

Server: FPBX-14.0.5.25(13.19.1)

Content-Length: 0

[2019-02-04 03:45:25] VERBOSE[20490] res_pjsip_logger.c: <— Received SIP request (618 bytes) from UDP:38.26.23.34:5060 —>

ACK sip:17183076648@companyurlurl:5060 SIP/2.0

From: "Company"<sip:120@companyurlurl>;tag=855690-1501a8c0-13c4-55013-3ee0-656a1b21-3ee0

To: <sip:17183076648@companyurlurl>;tag=z9hG4bK-3ee0-f59bc7-20be0196

Call-ID: 85a128-1501a8c0-13c4-55013-3ee0-994944b-3ee0

CSeq: 1 ACK

Via: SIP/2.0/UDP 38.26.23.34:5060;rport;branch=z9hG4bK-3ee0-f59bc7-20be0196

Max-Forwards: 70

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

User-Agent: AUDC-IPPhone/2.2.16.142.12 (440HDG-Rev1; 00908F61344B)

Contact: <sip:[email protected]:5060>

Content-Length: 0

[2019-02-04 03:45:25] VERBOSE[20490] res_pjsip_logger.c: <— Received SIP request (1605 bytes) from UDP:38.26.23.34:5060 —>

INVITE sip:17183076648@companyurlurl:5060 SIP/2.0

From: "Company"<sip:120@companyurlurl>;tag=855690-1501a8c0-13c4-55013-3ee0-656a1b21-3ee0

To: <sip:17183076648@companyurlurl:5060>

Call-ID: 85a128-1501a8c0-13c4-55013-3ee0-994944b-3ee0

CSeq: 2 INVITE

Via: SIP/2.0/UDP 192.168.1.21:5060;rport;branch=z9hG4bK-3ee0-f59c4e-4f215294

Max-Forwards: 70

Supported: replaces,100rel,eventlist,timer

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

User-Agent: AUDC-IPPhone/2.2.16.142.12 (440HDG-Rev1; 00908F61344B)

Allow-Events: talk,hold,conference

Contact: <sip:[email protected]:5060>

Authorization: Digest username="120",realm="asterisk",nonce="1549251925/09055d9979a00df7e7cd3da8cc336e33",uri="sip:17183076648@companyurlurl:5060",response="eef00e86f3676c643ede69120b7b0b96",algorithm=MD5,cnonce="f59c4f",opaque="335d5b964e03d691",qop=auth,nc=00000001

Session-Expires: 1800

Min-SE: 90

Content-Type: application/sdp

Content-Length: 586

v=0

o=120 1549251987 1549251987 IN IP4 192.168.1.21

s=-

c=IN IP4 192.168.1.21

t=0 0

m=audio 4006 RTP/AVP 9 0 8 111 18 102 101

a=rtpmap:9 G722/8000

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:111 opus/48000/2

a=fmtp:111 maxplaybackrate=16000; sprop-maxcapturerate=16000; maxaveragebitrate=50000; minptime=10; stereo=0; sprop-stereo=0; cbr=0; useinbandfec=1; usedtx=0; smaxpr=50;

a=ptime:20

a=maxptime:120

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:102 telephone-event/48000

a=fmtp:102 0-15

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=sendrecv

[2019-02-04 03:45:25] VERBOSE[20491] pbx_variables.c: Setting global variable ‘SIPDOMAIN’ to ‘companyurlurl’

[2019-02-04 03:45:25] VERBOSE[20491] res_pjsip_logger.c: <— Transmitting SIP response (387 bytes) to UDP:38.26.23.34:5060 —>

SIP/2.0 100 Trying

Via: SIP/2.0/UDP 192.168.1.21:5060;rport=5060;received=38.26.23.34;branch=z9hG4bK-3ee0-f59c4e-4f215294

Call-ID: 85a128-1501a8c0-13c4-55013-3ee0-994944b-3ee0

From: "Company" <sip:120@companyurlurl>;tag=855690-1501a8c0-13c4-55013-3ee0-656a1b21-3ee0

To: <sip:17183076648@companyurlurl>

CSeq: 2 INVITE

Server: FPBX-14.0.5.25(13.19.1)

Content-Length: 0

[2019-02-04 03:45:25] VERBOSE[20491] netsock2.c: Using SIP RTP Audio TOS bits 184

[2019-02-04 03:45:25] VERBOSE[20491] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.

[2019-02-04 03:45:25] VERBOSE[20491] netsock2.c: Using SIP RTP Audio CoS mark 5

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [17183076648@from-internal:1] Macro("PJSIP/120-00000160", "user-callerid,LIMIT,EXTERNAL,") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/120-00000160", "TOUCH_MONITOR=1549251925.355") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/120-00000160", "AMPUSER=120") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("PJSIP/120-00000160", "0?report") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("PJSIP/120-00000160", "1?Set(REALCALLERIDNUM=120)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:5] Set("PJSIP/120-00000160", "AMPUSER=120") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("PJSIP/120-00000160", "0?limit") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:7] Set("PJSIP/120-00000160", "AMPUSERCIDNAME=My name") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:8] ExecIf("PJSIP/120-00000160", "0?Set(__CIDMASQUERADING=TRUE)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:9] GotoIf("PJSIP/120-00000160", "0?report") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:10] Set("PJSIP/120-00000160", "AMPUSERCID=120") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:11] Set("PJSIP/120-00000160", "__DIAL_OPTIONS=HhTtr") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:12] Set("PJSIP/120-00000160", "CALLERID(all)="My name" <120>") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:13] GotoIf("PJSIP/120-00000160", "0?limit") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:14] ExecIf("PJSIP/120-00000160", "1?Set(GROUP(concurrency_limit)=120)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:15] ExecIf("PJSIP/120-00000160", "0?Set(CHANNEL(language)=)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:16] NoOp("PJSIP/120-00000160", "Macro Depth is 1") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:17] GotoIf("PJSIP/120-00000160", "1?report2:macroerror") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx_builtins.c: Goto (macro-user-callerid,s,18)

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("PJSIP/120-00000160", "1?continue") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx_builtins.c: Goto (macro-user-callerid,s,37)

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:37] Set("PJSIP/120-00000160", "CALLERID(number)=120") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:38] Set("PJSIP/120-00000160", "CALLERID(name)=My name") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:39] GotoIf("PJSIP/

120-00000160", "0?cnum") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:40] Set("PJSIP/120-00000160", "CDR(cnam)=My name") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:41] Set("PJSIP/120-00000160", "CDR(cnum)=120") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-user-callerid:42] Set("PJSIP/120-00000160", "CHANNEL(language)=en") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [17183076648@from-internal:2] Gosub("PJSIP/120-00000160", "sub-record-check,s,1(out,17183076648,dontcare)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/120-00000160", "0?initialized") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:2] Set("PJSIP/120-00000160", "__REC_STATUS=INITIALIZED") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:3] Set("PJSIP/120-00000160", "NOW=1549251925") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:4] Set("PJSIP/120-00000160", "__DAY=04") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:5] Set("PJSIP/120-00000160", "__MONTH=02") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:6] Set("PJSIP/120-00000160", "__YEAR=2019") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/120-00000160", "__TIMESTR=20190204-034525") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:8] Set("PJSIP/120-00000160", "__FROMEXTEN=120") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:9] Set("PJSIP/120-00000160", "__MON_FMT=wav") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/120-00000160", "Recordings initialized") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/120-00000160", "0?Set(ARG3=dontcare)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/120-00000160", "REC_POLICY_MODE_SAVE=") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/120-00000160", "0?Set(REC_STATUS=NO)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/120-00000160", "3?checkaction") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx_builtins.c: Goto (sub-record-check,s,17)

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/120-00000160", "1?sub-record-check,out,1") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx_builtins.c: Goto (sub-record-check,out,1)

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [out@sub-record-check:1] NoOp("PJSIP/120-00000160", "Outbound Recording Check from 120 to 17183076648") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [out@sub-record-check:2] Set("PJSIP/120-00000160", "RECMODE=dontcare") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [out@sub-record-check:3] ExecIf("PJSIP/120-00000160", "1?Goto(routewins)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx_builtins.c: Goto (sub-record-check,out,7)

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [out@sub-record-check:7] Gosub("PJSIP/120-00000160", "recordcheck,1(dontcare,out,17183076648)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/120-00000160", "Starting recording check against dontcare") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/120-00000160", "dontcare") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [recordcheck@sub-record-check:3] Return("PJSIP/120-00000160", "") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [out@sub-record-check:8] Return("PJSIP/120-00000160", "") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [17183076648@from-internal:3] ExecIf("PJSIP/120-00000160", "0 ?Set(CDR(accountcode)=)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [17183076648@from-internal:4] Set("PJSIP/120-00000160", "MOHCLASS=default") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [17183076648@from-internal:5] ExecIf("PJSIP/120-00000160", "1?Set(TRUNKCIDOVERRIDE=7183076648)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [17183076648@from-internal:6] Set("PJSIP/120-00000160", "_NODEST=") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [17183076648@from-internal:7] Macro("PJSIP/120-00000160", "dialout-trunk,1,17183076648,off") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:1] Set("PJSIP/120-00000160", "DIAL_TRUNK=1") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:2] ExecIf("PJSIP/120-00000160", "0?Set(DIAL_OPTIONS=Hhtr)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:3] GosubIf("PJSIP/120-00000160", "0?sub-pincheck,s,1()") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:4] ExecIf("PJSIP/120-00000160", "0?Set(CALLERID(num)=120)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:5] GotoIf("PJSIP/120-00000160", "0?disabletrunk,1") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:6] Set("PJSIP/120-00000160", "DIAL_NUMBER=17183076648") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:7] Set("PJSIP/120-00000160", "DIAL_TRUNK_OPTIONS=HhTtr") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:8] Set("PJSIP/120-00000160", "OUTBOUND_GROUP=OUT_1") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:9] Set("PJSIP/120-00000160", "DIAL_TRUNK_OPTIONS=T") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:10] GotoIf("PJSIP/120-00000160", "0?nomax") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:11] GotoIf("PJSIP/120-00000160", "0?chanfull") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:12] GotoIf("PJSIP/120-00000160", "0?skipoutcid") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:13] Macro("PJSIP/120-00000160", "outbound-callerid,1") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:1] NoOp("PJSIP/120-00000160", "120") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:2] NoOp("PJSIP/120-00000160", "") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:3] NoOp("PJSIP/120-00000160", "off") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:4] ExecIf("PJSIP/120-00000160", "0?Set(CALLERPRES(name-pres)=)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:5] ExecIf("PJSIP/120-00000160", "0?Set(CALLERPRES(num-pres)=)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:6] ExecIf("PJSIP/120-00000160", "0?Set(REALCALLERIDNUM=120)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:7] ExecIf("PJSIP/120-00000160", "0?Set(AMPUSER=120)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:8] GotoIf("PJSIP/120-00000160", "1?normcid") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx_builtins.c: Goto (macro-outbound-callerid,s,12)

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:12] Set("PJSIP/120-00000160", "USEROUTCID=") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:13] Set("PJSIP/120-00000160", "EMERGENCYCID=") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:14] Set("PJSIP/120-00000160", "TRUNKOUTCID=7183076648") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:15] GotoIf("PJSIP/120-00000160", "1?trunkcid") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx_builtins.c: Goto (macro-outbound-callerid,s,20)

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:20] ExecIf("PJSIP/120-00000160", "1?Set(CALLERID(all)=7183076648)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:21] ExecIf("PJSIP/120-00000160", "0?Set(CALLERID(all)=)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:22] ExecIf("PJSIP/120-00000160", "1?Set(CALLERID(all)=7183076648)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:23] ExecIf("PJSIP/120-00000160", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:24] ExecIf("PJSIP/120-00000160", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:25] Set("PJSIP/120-00000160", "CDR(outbound_cnum)=7183076648") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-outbound-callerid:26] Set("PJSIP/120-00000160", "CDR(outbound_cnam)=") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:14] GosubIf("PJSIP/120-00000160", "0?sub-flp-1,s,1()") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:15] Set("PJSIP/120-00000160", "OUTNUM=17183076648") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:16] Set("PJSIP/120-00000160", "custom=SIP/Anveo_Trunk") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:17] ExecIf("PJSIP/120-00000160", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:18] ExecIf("PJSIP/120-00000160", "0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:19] Macro("PJSIP/120-00000160", "dialout-trunk-predial-hook,") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("PJSIP/120-00000160", "") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:20] GotoIf("PJSIP/120-00000160", "0?skipcrm") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:21] Set("PJSIP/120-00000160", "__CRM_DIRECTION=OUTBOUND") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:22] Set("PJSIP/120-00000160", "__CRM_DESTINATION=17183076648") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:23] Set("PJSIP/120-00000160", "__CRM_SOURCE=120") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:24] AGI("PJSIP/120-00000160", "sangomacrm.agi") in new stack

[2019-02-04 03:45:25] VERBOSE[30099][C-00000160] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] res_agi.c: <PJSIP/120-00000160>AGI Script sangomacrm.agi completed, returning 0

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:25] Set("PJSIP/120-00000160", "CHANNEL(hangup_handler_push)=crm-hangup,s,1") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:26] NoOp("PJSIP/120-00000160", "CRM Finished") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:27] GotoIf("PJSIP/120-00000160", "0?bypass,1") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:28] ExecIf("PJSIP/120-00000160", "1?Set(CONNECTEDLINE(num,i)=17183076648)") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:29] ExecIf("PJSIP/120-00000160", "1?Set(CONNECTEDLINE(name,i)=CID:7183076648)") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:30] ExecIf("PJSIP/120-00000160", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)7183076648)") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:31] GotoIf("PJSIP/120-00000160", "0?customtrunk") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@macro-dialout-trunk:32] Dial("PJSIP/120-00000160", "SIP/Anveo_Trunk/17183076648,300,Tb(func-apply-sipheaders^s^1,(1))") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] netsock2.c: Using SIP RTP TOS bits 184

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] netsock2.c: Using SIP RTP CoS mark 5

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] app_stack.c: SIP/Anveo_Trunk-00000003 Internal Gosub(func-apply-sipheaders,s,1(1)) start

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/Anveo_Trunk-00000003", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/Anveo_Trunk-00000003", "Applying SIP Headers to channel 1") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/Anveo_Trunk-00000003", "SIPHEADERKEYS=") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@func-apply-sipheaders:4] ExecIf("SIP/Anveo_Trunk-00000003", "0?Set(Rheader=1)") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/Anveo_Trunk-00000003", "0") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] app_while.c: Jumping to priority 9

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@func-apply-sipheaders:10] ExecIf("SIP/Anveo_Trunk-00000003", "0?SIPRemoveHeader(Alert-Info:)") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@func-apply-sipheaders:11] ExecIf("SIP/Anveo_Trunk-00000003", "0?Set(PJSIP_HEADER(remove,Alert-Info)=)") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] pbx.c: Executing [s@func-apply-sipheaders:12] Return("SIP/Anveo_Trunk-00000003", "") in new stack

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] app_stack.c: Spawn extension (from-trunk, 17183076648, 1) exited non-zero on ‘SIP/Anveo_Trunk-00000003’

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] app_stack.c: SIP/Anveo_Trunk-00000003 Internal Gosub(func-apply-sipheaders,s,1(1)) complete GOSUB_RETVAL=

[2019-02-04 03:45:26] VERBOSE[30099][C-00000160] app_dial.c: Called SIP/Anveo_Trunk/17183076648

[2019-02-04 03:45:27] VERBOSE[30099][C-00000160] app_dial.c: SIP/Anveo_Trunk-00000003 is ringing

[2019-02-04 03:45:27] VERBOSE[20491] res_pjsip_logger.c: <— Transmitting SIP response (650 bytes) to UDP:38.26.23.34:5060 —>

SIP/2.0 180 Ringing

Via: SIP/2.0/UDP 192.168.1.21:5060;rport=5060;received=38.26.23.34;branch=z9hG4bK-3ee0-f59c4e-4f215294

Call-ID: 85a128-1501a8c0-13c4-55013-3ee0-994944b-3ee0

From: "Company" <sip:120@companyurlurl>;tag=855690-1501a8c0-13c4-55013-3ee0-656a1b21-3ee0

To: <sip:17183076648@companyurlurl>;tag=76ea6ccc-e0da-42aa-9b2b-af6e13814a5b

CSeq: 2 INVITE

Server: FPBX-14.0.5.25(13.19.1)

Contact: <sip:96.246.226.29:5060>

Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, MESSAGE, REFER

P-Asserted-Identity: "CID:7183076648" <sip:17183076648@companyurlurl>

Content-Length: 0

[2019-02-04 03:45:27] VERBOSE[20528][C-00000161] netsock2.c: Using SIP RTP TOS bits 184

[2019-02-04 03:45:27] VERBOSE[20528][C-00000161] netsock2.c: Using SIP RTP CoS mark 5

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@from-trunk:1] Set("SIP/Anveo_Trunk-00000004", "__DIRECTION=INBOUND") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@from-trunk:2] Gosub("SIP/Anveo_Trunk-00000004", "sub-record-check,s,1(in,s,dontcare)") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/Anveo_Trunk-00000004", "0?initialized") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:2] Set("SIP/Anveo_Trunk-00000004", "__REC_STATUS=INITIALIZED") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:3] Set("SIP/Anveo_Trunk-00000004", "NOW=1549251927") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:4] Set("SIP/Anveo_Trunk-00000004", "__DAY=04") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:5] Set("SIP/Anveo_Trunk-00000004", "__MONTH=02") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:6] Set("SIP/Anveo_Trunk-00000004", "__YEAR=2019") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:7] Set("SIP/Anveo_Trunk-00000004", "__TIMESTR=20190204-034527") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:8] Set("SIP/Anveo_Trunk-00000004", "__FROMEXTEN=unknown") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:9] Set("SIP/Anveo_Trunk-00000004", "__MON_FMT=wav") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/Anveo_Trunk-00000004", "Recordings initialized") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/Anveo_Trunk-00000004", "0?Set(ARG3=dontcare)") in new stack

[2019-02-04 03:45:27] VERBOSE[30120][C-00000161] pbx.c: Executing [s@sub-record-check:12] Set("SIP/Anveo_Trunk-00000004", "REC_POLICY_MODE_SAVE=") in new stack

dicko · February 4, 2019, 4:01am

You shouldn’t alliw anonymous connections , but you do need an inbound route that matches

17183076648

argentek · February 4, 2019, 4:01am

Forum gives me a message about new users not posting new links. I’ll go through it and see what looks like a url and replace it.

In the meantime, is this the log you are referring to?

argentek · February 4, 2019, 4:09am

In the General SIP settings I have Allow Anonymous Inbound SIP Calls set to off. What other steps should I take to disallow anonymous connections?

Are you referring to the DID number on the inbound route?

dicko · February 4, 2019, 4:13am

Yes someone sent a call to 17183076648 but you directed it to extension s (synononymous with I don’t handle that did)

BlazeStudios · February 4, 2019, 4:14am

So your initial INVITE has the proper details in the two important parts highlighted above. However, when your phone is sending the second INVITE with auth details (as it should) it is using the LAN details in those exact same settings (see below). So the system is trying to send your audio to an IP that can’t route over the Internet. So this is looking like an issue with this phone.

argentek · February 4, 2019, 4:18am

I was under the impression that you wanted to leave one route as a default or “catch all” so if any calls came in without a DID for some whatever reason then it doesn’t get lost. If that isn’t best practice, I’ll change it.
Also, that’s the phone number I called for the test call. The call was from and to that number.

Side note, I read in one of your other posts that you don’t like using port 5060, should I use a random port and have the router translate it internally to 5060?

argentek · February 4, 2019, 4:23am

Thank you for the info. I can try reaching out to Audiocodes but everyone says their support is not very good, I figured I’d try here first.

I’ll look through the phone settings again and see if I missed something. Is there anything I should be looking for specifically?

dicko · February 4, 2019, 4:25am

It would behove you to not use anything between 5000 and 5999 for any inbound SIP connection, almost noboby is trying to make calls on your machine outside that range, if any one disagrees, please show proof

argentek · February 4, 2019, 4:26am

I’ll follow this advice and change it to something outside of that range.

dicko · February 4, 2019, 4:29am

You can still ‘register’ to your trunk on 5060 of you need to. Pinhole other known sources of 5060 through your pnat

Stewart1 · February 4, 2019, 4:33am

Though I agree with @BlazeStudios diagnosis, my prescription is the opposite. A naïve SIP endpoint would send only its private address in Via, Contact and SDP. pjsip handles that quite well, substituting the public IP from which it received the request. But either your phone or the router it’s behind is trying to do it’s own NAT traversal but as Tom pointed out, it is doing it incorrectly.

Try turning off any NAT-related settings in the phone or any SIP ALG or similar settings in the router. If the router is the culprit, using ports other than 5060 may fool it into not mangling packets. Change the local port on the phone to another value.

On the pjsip end, change the port to something else, forward that port and adjust the settings in your devices to connect to the new port. Translating ports in the router can cause various issues.

argentek · February 4, 2019, 4:33am

Can you further clarify?

dicko · February 4, 2019, 4:35am

Not really, just try it after you stop binding to 5060 if you need to. but you probably wont