Help Getting Outbound/Inbound to Voip.MS on AWS LightSail

Status
Not open for further replies.
B

BigDuke6

New Member
Jun 7, 2021
7
0
1
47
Hello, I am new to FusionPBX. Trying to get Outbound or Inbound for that matter working on AWS LIghtsail. I had Inbound and never got Outbound to work. In trying to fix Outbound I broke Inbound. Let's try to get Outbound working first. I have a LightSail VM running Debian 10.8. Here are my FW rules:

1623200284745.png

I have a Yealink T46G on my local network at home registered as an extension. I have worked through endless 407 errors and think I have that fixed but having 480 Unavailable errors now.



Here is Fusionpbx log.

########## - Dialed Number
XXX.XX.X.XXX - Private IP where Yealink T46G is registered.
YYY.YY.Y.YYY - Local Domain IP for LightSail VM (Defined in FusionPBX domains)
ZZ.ZZZ.ZZZ.ZZ - Public IP for LightSail VM (Also Defined in FusionPBX domains)


recv 913 bytes from udp/[XXX.XX.X.XXX]:5060 at 16:47:06.578801:
------------------------------------------------------------------------
INVITE sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080 SIP/2.0
Via: SIP/2.0/UDP YYY.YYY.Y.YYY:5060;branch=z9hG4bK2816192182
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=3888214355
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080>
Call-ID: 0_65059309@YYY.YYY.Y.YYY
CSeq: 1 INVITE
Contact: <sip:700@YYY.YYY.Y.YYY:5060>
Content-Type: application/sdp
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
Max-Forwards: 70
User-Agent: Yealink SIP-T46G 28.83.0.120
Allow-Events: talk,hold,conference,refer,check-sync
Supported: replaces
Content-Length: 308

v=0
o=- 20086 20086 IN IP4 YYY.YYY.Y.YYY
s=SDP data
c=IN IP4 YYY.YYY.Y.YYY
t=0 0
m=audio 12466 RTP/AVP 9 0 8 18 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2021-06-07 16:47:06.577132 [NOTICE] switch_channel.c:1118 New Channel sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [bc7e251c-c7de-4569-b5f2-36f1351945f2]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_NEW (Cur 1 Tot 60)
2021-06-07 16:47:06.577132 [INFO] sofia.c:10362 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 receiving invite from XXX.XX.X.XXX:5060 version: 1.10.6 -release-18-1ff9d0a60e 64bit call-id: 0_65059309@YYY.YYY.Y.YYY
2021-06-07 16:47:06.577132 [DEBUG] sofia.c:10456 verifying acl "domains" for ip/port XXX.XX.X.XXX:0.
2021-06-07 16:47:06.577132 [DEBUG] sofia.c:11564 Setting NAT mode based on nat.auto
2021-06-07 16:47:06.577132 [DEBUG] sofia.c:7406 Channel sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 entering state [received][100]
2021-06-07 16:47:06.577132 [DEBUG] sofia.c:7416 Remote SDP:
v=0
o=- 20086 20086 IN IP4 YYY.YYY.Y.YYY
s=SDP data
c=IN IP4 YYY.YYY.Y.YYY
t=0 0
m=audio 12466 RTP/AVP 9 0 8 18 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5656 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5656 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5656 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5517 Set telephone-event payload to 101@8000
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:3847 Set Codec sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 G722/8000 20 ms 160 samples 64000 bits 1 channels
2021-06-07 16:47:06.577132 [DEBUG] switch_core_codec.c:111 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Original read codec set to G722:9
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5860 Set telephone-event payload to 101@8000
2021-06-07 16:47:06.577132 [DEBUG] switch_core_media.c:5918 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Set 2833 dtmf send payload to 101 recv payload to 101
2021-06-07 16:47:06.577132 [DEBUG] sofia.c:7840 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State Change CS_NEW -> CS_INIT
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:604 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State NEW
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_INIT (Cur 1 Tot 60)
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:628 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State INIT
2021-06-07 16:47:06.577132 [DEBUG] mod_sofia.c:93 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 SOFIA INIT
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:40 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard INIT
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:48 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State Change CS_INIT -> CS_ROUTING
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:628 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State INIT going to sleep
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_ROUTING (Cur 1 Tot 60)
2021-06-07 16:47:06.577132 [DEBUG] switch_channel.c:2332 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Callstate Change DOWN -> RINGING
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:644 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State ROUTING
send 298 bytes to udp/[XXX.XX.X.XXX]:5060 at 16:47:06.579997:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP YYY.YYY.Y.YYY:5060;branch=z9hG4bK2816192182;received=XXX.XX.X.XXX
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=3888214355
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080>
Call-ID: 0_65059309@YYY.YYY.Y.YYY
CSeq: 1 INVITE
User-Agent: FreeSWITCH
Content-Length: 0

2021-06-07 16:47:06.577132 [DEBUG] mod_sofia.c:154 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 SOFIA ROUTING
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:236 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard ROUTING
2021-06-07 16:47:06.577132 [INFO] mod_dialplan_xml.c:637 Processing 700 <700>->########## in context public
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 parsing [public->caller-details] continue=true
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Regex (PASS) [caller-details] () =~ // break=never
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Action export(call_direction=inbound) INLINE
EXECUTE [depth=0] sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 export(call_direction=inbound)
2021-06-07 16:47:06.577132 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Action set(caller_destination=${sip_to_user}) INLINE
EXECUTE [depth=0] sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 set(caller_destination=##########)
2021-06-07 16:47:06.577132 [DEBUG] mod_dptools.c:1685 SET sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [caller_destination]=[##########]
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 set(caller_id_name=700)
2021-06-07 16:47:06.577132 [DEBUG] mod_dptools.c:1685 SET sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [caller_id_name]=[700]
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 parsing [public->272565] continue=false
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Regex (FAIL) [272565] destination_number(##########) =~ /^(272565)$/ break=on-false
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 parsing [public->not-found] continue=false
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Regex (PASS) [not-found] () =~ // break=on-false
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Action export(call_direction=inbound) INLINE
EXECUTE [depth=0] sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 export(call_direction=inbound)
2021-06-07 16:47:06.577132 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Action set(call_direction=inbound) INLINE
EXECUTE [depth=0] sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 set(call_direction=inbound)
2021-06-07 16:47:06.577132 [DEBUG] mod_dptools.c:1685 SET sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [call_direction]=[inbound]
Dialplan: sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Action log(WARNING [inbound routes] 404 not found ${sip_network_ip})
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:287 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State Change CS_ROUTING -> CS_EXECUTE
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:644 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State ROUTING going to sleep
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_EXECUTE (Cur 1 Tot 60)
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:651 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State EXECUTE
2021-06-07 16:47:06.577132 [DEBUG] mod_sofia.c:209 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 SOFIA EXECUTE
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:329 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard EXECUTE
EXECUTE [depth=0] sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 set(caller_id_number=700)
2021-06-07 16:47:06.577132 [DEBUG] mod_dptools.c:1685 SET sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [caller_id_number]=[700]
EXECUTE [depth=0] sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 log(WARNING [inbound routes] 404 not found XXX.XX.X.XXX)
2021-06-07 16:47:06.577132 [WARNING] mod_dptools.c:1879 [inbound routes] 404 not found XXX.XX.X.XXX
2021-06-07 16:47:06.577132 [NOTICE] switch_core_state_machine.c:386 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 has executed the last dialplan instruction, hanging up.
2021-06-07 16:47:06.577132 [NOTICE] switch_core_state_machine.c:388 Hangup sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [CS_EXECUTE] [NORMAL_CLEARING]
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:651 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State EXECUTE going to sleep
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_HANGUP (Cur 1 Tot 60)
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:848 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Callstate Change RINGING -> HANGUP
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:850 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State HANGUP
2021-06-07 16:47:06.577132 [DEBUG] mod_sofia.c:453 Channel sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 hanging up, cause: NORMAL_CLEARING
2021-06-07 16:47:06.577132 [DEBUG] mod_sofia.c:598 Responding to INVITE with: 480
send 690 bytes to udp/[XXX.XX.X.XXX]:5060 at 16:47:06.589887:
------------------------------------------------------------------------
SIP/2.0 480 Temporarily Unavailable
Via: SIP/2.0/UDP YYY.YYY.Y.YYY:5060;branch=z9hG4bK2816192182;received=XXX.XX.X.XXX
Max-Forwards: 70
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=3888214355
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=K133rSF9tB97r
Call-ID: 0_65059309@YYY.YYY.Y.YYY
CSeq: 1 INVITE
User-Agent: FreeSWITCH
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
Remote-Party-ID: "##########" <sip:##########@ZZ.ZZZ.ZZZ.ZZ>;party=calling;privacy=off;screen=no

2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:60 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard HANGUP, cause: NORMAL_CLEARING
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:850 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State HANGUP going to sleep
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:620 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State Change CS_HANGUP -> CS_REPORTING
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_REPORTING (Cur 1 Tot 60)
2021-06-07 16:47:06.577132 [DEBUG] switch_core_state_machine.c:936 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State REPORTING
recv 294 bytes from udp/[XXX.XX.X.XXX]:5060 at 16:47:06.616743:
------------------------------------------------------------------------
ACK sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080 SIP/2.0
Via: SIP/2.0/UDP YYY.YYY.Y.YYY:5060;branch=z9hG4bK2816192182
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=3888214355
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=K133rSF9tB97r
Call-ID: 0_65059309@YYY.YYY.Y.YYY
CSeq: 1 ACK
Content-Length: 0

2021-06-07 16:47:06.657117 [DEBUG] switch_core_state_machine.c:174 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard REPORTING, cause: NORMAL_CLEARING
2021-06-07 16:47:06.657117 [DEBUG] switch_core_state_machine.c:936 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State REPORTING going to sleep
2021-06-07 16:47:06.657117 [DEBUG] switch_core_state_machine.c:611 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State Change CS_REPORTING -> CS_DESTROY
2021-06-07 16:47:06.657117 [DEBUG] switch_core_session.c:1736 Session 60 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Locked, Waiting on external entities
2021-06-07 16:47:06.657117 [NOTICE] switch_core_session.c:1754 Session 60 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Ended
2021-06-07 16:47:06.657117 [NOTICE] switch_core_session.c:1758 Close Channel sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [CS_DESTROY]
2021-06-07 16:47:06.657117 [DEBUG] switch_core_state_machine.c:739 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_DESTROY (Cur 0 Tot 60)
2021-06-07 16:47:06.657117 [DEBUG] switch_core_state_machine.c:749 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State DESTROY
2021-06-07 16:47:06.657117 [DEBUG] mod_sofia.c:364 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 SOFIA DESTROY
2021-06-07 16:47:06.657117 [DEBUG] switch_core_state_machine.c:181 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard DESTROY
2021-06-07 16:47:06.657117 [DEBUG] switch_core_state_machine.c:749 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State DESTROY going to sleep


Gateway (less the Username in the Screenshot)
1623200625306.png
Outbound Routes. The marked out ip addresses are the Public IP for the AWS VM. (Defined in Domains)


1623201096011.png

External profile. The marked out ip addresses are the Public IP for the AWS VM. (Defined in Domains)

1623201282081.png


Any insight/help would be greatly appreciated.

Thanks!
 
A

ad5ou

Active Member
Jun 12, 2018
892
205
43
I'll start with first thing I see but mostly unrelated to problems. RTP ports should normally be 16384-32768 unless changed in FS config

Your 700 extension is landing in the public dial plan. This is from adding the wrong IP's in Advanced>Access Controls>domains Typically you would only add the IP addresses (in CIDR format) of your gateways/providers not your phone/office network.

Access Controls — FusionPBX Docs documentation

docs.fusionpbx.com docs.fusionpbx.com

Example voip.ms entry
1623273759808.png
 
Last edited:
B

BigDuke6

New Member
Jun 7, 2021
7
0
1
47
Thank you for looking at this. I made the ACL change to remove the private network IP where the phone is registered. I don't see much changing in the logs. Here is a new call. There reason why I added the IP there was because of this line:

2021-06-10 00:42:26.096802 [DEBUG] sofia.c:10456 verifying acl "domains" for ip/port XXX.XX.X.XXX:0.
2021-06-10 00:42:26.096802 [WARNING] sofia.c:10569 IP XXX.XX.X.XXX Rejected by acl "domains"


same convention below:

########## - Dialed Number
XXX.XX.X.XXX - Private IP where Yealink T46G is registered.
YYY.YY.Y.YYY - Local Domain IP for LightSail VM (Defined in FusionPBX domains)
ZZ.ZZZ.ZZZ.ZZ - Public IP for LightSail VM (Also Defined in FusionPBX domains)




recv 914 bytes from udp/[XXX.XX.X.XXX]:5060 at 00:42:26.106788:
------------------------------------------------------------------------
INVITE sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080 SIP/2.0
Via: SIP/2.0/UDP YYY.YY.Y.YYY:5060;branch=z9hG4bK1311968031
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=1532589078
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080>
Call-ID: 0_263837877@YYY.YY.Y.YYY
CSeq: 1 INVITE
Contact: <sip:700@YYY.YY.Y.YYY:5060>
Content-Type: application/sdp
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
Max-Forwards: 70
User-Agent: Yealink SIP-T46G 28.83.0.120
Allow-Events: talk,hold,conference,refer,check-sync
Supported: replaces
Content-Length: 308
v=0
o=- 20092 20092 IN IP4 YYY.YY.Y.YYY
s=SDP data
c=IN IP4 YYY.YY.Y.YYY
t=0 0
m=audio 12478 RTP/AVP 9 0 8 18 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2021-06-10 00:42:26.096802 [NOTICE] switch_channel.c:1118 New Channel sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [d1125aac-5f30-4342-92b3-e379b9d7978b]
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_NEW (Cur 1 Tot 24380)
2021-06-10 00:42:26.096802 [INFO] sofia.c:10362 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 receiving invite from XXX.XX.X.XXX:5060 version: 1.10.6 -release-18-1ff9d0a60e 64bit call-id: 0_263837877@YYY.YY.Y.YYY
2021-06-10 00:42:26.096802 [DEBUG] sofia.c:10456 verifying acl "domains" for ip/port XXX.XX.X.XXX:0.
2021-06-10 00:42:26.096802 [WARNING] sofia.c:10569 IP XXX.XX.X.XXX Rejected by acl "domains"
send 514 bytes to udp/[XXX.XX.X.XXX]:5060 at 00:42:26.107378:
------------------------------------------------------------------------
SIP/2.0 403 Forbidden
Via: SIP/2.0/UDP YYY.YY.Y.YYY:5060;branch=z9hG4bK1311968031;received=XXX.XX.X.XXX
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=1532589078
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=BvyXKBFjQBHUr
Call-ID: 0_263837877@YYY.YY.Y.YYY
CSeq: 1 INVITE
User-Agent: FreeSWITCH
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Length: 0
2021-06-10 00:42:26.096802 [NOTICE] sofia.c:2445 Hangup sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [CS_NEW] [CALL_REJECTED]
2021-06-10 00:42:26.096802 [DEBUG] sofia.c:1549 Channel is already hungup.
2021-06-10 00:42:26.096802 [DEBUG] sofia.c:1549 Channel is already hungup.
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:604 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State NEW
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_HANGUP (Cur 1 Tot 24380)
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:848 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Callstate Change DOWN -> HANGUP
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:850 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State HANGUP
2021-06-10 00:42:26.096802 [DEBUG] mod_sofia.c:453 Channel sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 hanging up, cause: CALL_REJECTED
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:60 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard HANGUP, cause: CALL_REJECTED
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:850 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State HANGUP going to sleep
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:620 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State Change CS_HANGUP -> CS_REPORTING
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_REPORTING (Cur 1 Tot 24380)
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:936 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State REPORTING
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:174 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard REPORTING, cause: CALL_REJECTED
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:936 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State REPORTING going to sleep
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:611 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State Change CS_REPORTING -> CS_DESTROY
2021-06-10 00:42:26.096802 [DEBUG] switch_core_session.c:1736 Session 24380 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Locked, Waiting on external entities
2021-06-10 00:42:26.096802 [NOTICE] switch_core_session.c:1754 Session 24380 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Ended
2021-06-10 00:42:26.096802 [NOTICE] switch_core_session.c:1758 Close Channel sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [CS_DESTROY]
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:739 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_DESTROY (Cur 0 Tot 24380)
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:749 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State DESTROY
2021-06-10 00:42:26.096802 [DEBUG] mod_sofia.c:364 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 SOFIA DESTROY
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:181 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard DESTROY
2021-06-10 00:42:26.096802 [DEBUG] switch_core_state_machine.c:749 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State DESTROY going to sleep
recv 295 bytes from udp/[XXX.XX.X.XXX]:5060 at 00:42:26.134506:
------------------------------------------------------------------------
ACK sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080 SIP/2.0
Via: SIP/2.0/UDP YYY.YY.Y.YYY:5060;branch=z9hG4bK1311968031
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=1532589078
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=BvyXKBFjQBHUr
Call-ID: 0_263837877@YYY.YY.Y.YYY
CSeq: 1 ACK
Content-Length: 0
recv 331 bytes from udp/[193.187.88.197]:50221 at 00:43:13.546063:
------------------------------------------------------------------------
REGISTER sip:ZZ.ZZZ.ZZZ.ZZ SIP/2.0
Via: SIP/2.0/UDP 10.15.15.35:50221;branch=z9hG4bK632437643
Max-Forwards: 70
From: <sip:8979@ZZ.ZZZ.ZZZ.ZZ>;tag=1372273352
To: <sip:8979@ZZ.ZZZ.ZZZ.ZZ>
Call-ID: 1783257470-345202059-251190428
CSeq: 1 REGISTER
Contact: <sip:8979@10.15.15.35:50221>
Content-Length: 0
User-Agent: GXP2130
send 574 bytes to udp/[193.187.88.197]:50221 at 00:43:13.546470:
------------------------------------------------------------------------
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.15.15.35:50221;branch=z9hG4bK632437643;received=193.187.88.197
From: <sip:8979@ZZ.ZZZ.ZZZ.ZZ>;tag=1372273352
To: <sip:8979@ZZ.ZZZ.ZZZ.ZZ>;tag=85N1rpDH7gBSH
Call-ID: 1783257470-345202059-251190428
CSeq: 1 REGISTER
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
WWW-Authenticate: Digest realm="ZZ.ZZZ.ZZZ.ZZ", nonce="96580f87-c763-4ad8-a671-04fe3cfad83f", algorithm=MD5, qop="auth"
Content-Length: 0
2021-06-10 00:43:13.536794 [WARNING] sofia_reg.c:1795 SIP auth challenge (REGISTER) on sofia profile 'internal' for [8979@ZZ.ZZZ.ZZZ.ZZ] from ip 193.187.88.197
recv 560 bytes from udp/[193.187.88.197]:50221 at 00:43:13.685494:
------------------------------------------------------------------------
REGISTER sip:ZZ.ZZZ.ZZZ.ZZ SIP/2.0
Via: SIP/2.0/UDP 10.15.15.35:50221;branch=z9hG4bK555342125
Max-Forwards: 70
From: <sip:8979@ZZ.ZZZ.ZZZ.ZZ>;tag=1372273352
To: <sip:8979@ZZ.ZZZ.ZZZ.ZZ>
Call-ID: 1783257470-345202059-251190428
CSeq: 2 REGISTER
Contact: <sip:8979@10.15.15.35:50221>
Content-Length: 0
Authorization: Digest username="8979",uri="sip:ZZ.ZZZ.ZZZ.ZZ",algorithm=MD5,realm="ZZ.ZZZ.ZZZ.ZZ",nonce="96580f87-c763-4ad8-a671-04fe3cfad83f",response="6fdd267ed1526a49aae3aee3f66cdaba",qop=auth,nc=00000001, cnonce="924240154"
User-Agent: GXP2130
2021-06-10 00:43:13.677296 [WARNING] sofia_reg.c:2932 Can't find user [8979@ZZ.ZZZ.ZZZ.ZZ] from 193.187.88.197
You must define a domain called 'ZZ.ZZZ.ZZZ.ZZ' in your directory and add a user with the id="8979" attribute
and you must configure your device to use the proper domain in its authentication credentials.
send 450 bytes to udp/[193.187.88.197]:50221 at 00:43:13.696317:
------------------------------------------------------------------------
SIP/2.0 403 Forbidden
Via: SIP/2.0/UDP 10.15.15.35:50221;branch=z9hG4bK555342125;received=193.187.88.197
From: <sip:8979@ZZ.ZZZ.ZZZ.ZZ>;tag=1372273352
To: <sip:8979@ZZ.ZZZ.ZZZ.ZZ>;tag=9eFttHym4S1BD
Call-ID: 1783257470-345202059-251190428
CSeq: 2 REGISTER
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
2021-06-10 00:43:13.677296 [WARNING] sofia_reg.c:1740 SIP auth failure (REGISTER) on sofia profile 'internal' for [8979@ZZ.ZZZ.ZZZ.ZZ] from ip 193.187.88.197
recv 332 bytes from udp/[193.187.88.197]:51134 at 00:43:14.510088:
------------------------------------------------------------------------
REGISTER sip:ZZ.ZZZ.ZZZ.ZZ SIP/2.0
Via: SIP/2.0/UDP 10.15.15.35:51134;branch=z9hG4bK1183046837
Max-Forwards: 70
From: <sip:1724@ZZ.ZZZ.ZZZ.ZZ>;tag=1992528635
To: <sip:1724@ZZ.ZZZ.ZZZ.ZZ>
Call-ID: 904661874-564065229-1361742702
CSeq: 1 REGISTER
Contact: <sip:1724@10.15.15.35:51134>
Content-Length: 0
User-Agent: GXP2130
send 575 bytes to udp/[193.187.88.197]:51134 at 00:43:14.510512:
------------------------------------------------------------------------
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.15.15.35:51134;branch=z9hG4bK1183046837;received=193.187.88.197
From: <sip:1724@ZZ.ZZZ.ZZZ.ZZ>;tag=1992528635
To: <sip:1724@ZZ.ZZZ.ZZZ.ZZ>;tag=ar8jvcFr12Qyr
Call-ID: 904661874-564065229-1361742702
CSeq: 1 REGISTER
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
WWW-Authenticate: Digest realm="ZZ.ZZZ.ZZZ.ZZ", nonce="f439a8ab-846d-4ab0-b8a0-0e4d57f40cc1", algorithm=MD5, qop="auth"
Content-Length: 0
2021-06-10 00:43:14.476802 [WARNING] sofia_reg.c:1795 SIP auth challenge (REGISTER) on sofia profile 'internal' for [1724@ZZ.ZZZ.ZZZ.ZZ] from ip 193.187.88.197
recv 560 bytes from udp/[193.187.88.197]:51134 at 00:43:14.648687:
------------------------------------------------------------------------
REGISTER sip:ZZ.ZZZ.ZZZ.ZZ SIP/2.0
Via: SIP/2.0/UDP 10.15.15.35:51134;branch=z9hG4bK13309932
Max-Forwards: 70
From: <sip:1724@ZZ.ZZZ.ZZZ.ZZ>;tag=1992528635
To: <sip:1724@ZZ.ZZZ.ZZZ.ZZ>
Call-ID: 904661874-564065229-1361742702
CSeq: 2 REGISTER
Contact: <sip:1724@10.15.15.35:51134>
Content-Length: 0
Authorization: Digest username="1724",uri="sip:ZZ.ZZZ.ZZZ.ZZ",algorithm=MD5,realm="ZZ.ZZZ.ZZZ.ZZ",nonce="f439a8ab-846d-4ab0-b8a0-0e4d57f40cc1",response="48b06dfa5c4c039ec3b969cd9fc81ad4",qop=auth,nc=00000001, cnonce="1188022094"
User-Agent: GXP2130
2021-06-10 00:43:14.636799 [WARNING] sofia_reg.c:2932 Can't find user [1724@ZZ.ZZZ.ZZZ.ZZ] from 193.187.88.197
You must define a domain called 'ZZ.ZZZ.ZZZ.ZZ' in your directory and add a user with the id="1724" attribute
and you must configure your device to use the proper domain in its authentication credentials.
send 449 bytes to udp/[193.187.88.197]:51134 at 00:43:14.653130:
------------------------------------------------------------------------
SIP/2.0 403 Forbidden
Via: SIP/2.0/UDP 10.15.15.35:51134;branch=z9hG4bK13309932;received=193.187.88.197
From: <sip:1724@ZZ.ZZZ.ZZZ.ZZ>;tag=1992528635
To: <sip:1724@ZZ.ZZZ.ZZZ.ZZ>;tag=B11By7ZUyBeHm
Call-ID: 904661874-564065229-1361742702
CSeq: 2 REGISTER
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0
2021-06-10 00:43:14.636799 [WARNING] sofia_reg.c:1740 SIP auth failure (REGISTER) on sofia profile 'internal' for [1724@ZZ.ZZZ.ZZZ.ZZ] from ip 193.187.88.197
 
B

BigDuke6

New Member
Jun 7, 2021
7
0
1
47
I will also add, removing the IP address of the office phone causes the phone not to register with FS.
 
A

ad5ou

Active Member
Jun 12, 2018
892
205
43
The initial “rejected by domains ACL” is expected behavior. Next Freeswitch is sending a 401 to trigger the phone to reply with authentication. Either your phones have wrong password, or there is another error happening.
 
B

BigDuke6

New Member
Jun 7, 2021
7
0
1
47
OK, thanks.

I removed all the entries in the ACL except for the carrier. New error. Much shorter log. No idea why I am getting forbidden now.

recv 914 bytes from udp/[XXX.XX.X.XXX]:5060 at 13:09:44.584888:
------------------------------------------------------------------------
INVITE sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080 SIP/2.0
Via: SIP/2.0/UDP 192.168.7.126:5060;branch=z9hG4bK1890875013
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=857552051
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080>
Call-ID: 0_1100972769@192.168.7.126
CSeq: 1 INVITE
Contact: <sip:700@192.168.7.126:5060>
Content-Type: application/sdp
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
Max-Forwards: 70
User-Agent: Yealink SIP-T46G 28.83.0.120
Allow-Events: talk,hold,conference,refer,check-sync
Supported: replaces
Content-Length: 308
v=0
o=- 20123 20123 IN IP4 192.168.7.126
s=SDP data
c=IN IP4 192.168.7.126
t=0 0
m=audio 12552 RTP/AVP 9 0 8 18 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2021-06-10 13:09:44.576808 [NOTICE] switch_channel.c:1118 New Channel sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [5ab7f178-3dd1-4c2a-b192-725446e61aaf]
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_NEW (Cur 1 Tot 24473)
2021-06-10 13:09:44.576808 [INFO] sofia.c:10362 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 receiving invite from XXX.XX.X.XXX:5060 version: 1.10.6 -release-18-1ff9d0a60e 64bit call-id: 0_1100972769@192.168.7.126
2021-06-10 13:09:44.576808 [DEBUG] sofia.c:10456 verifying acl "domains" for ip/port XXX.XX.X.XXX:0.
2021-06-10 13:09:44.576808 [WARNING] sofia.c:10569 IP XXX.XX.X.XXX Rejected by acl "domains"
send 514 bytes to udp/[XXX.XX.X.XXX]:5060 at 13:09:44.590403:
------------------------------------------------------------------------
SIP/2.0 403 Forbidden
Via: SIP/2.0/UDP 192.168.7.126:5060;branch=z9hG4bK1890875013;received=XXX.XX.X.XXX
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=857552051
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=QFv89p9BF1DNe
Call-ID: 0_1100972769@192.168.7.126
CSeq: 1 INVITE
User-Agent: FreeSWITCH
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Length: 0
2021-06-10 13:09:44.576808 [NOTICE] sofia.c:2445 Hangup sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [CS_NEW] [CALL_REJECTED]
2021-06-10 13:09:44.576808 [DEBUG] sofia.c:1549 Channel is already hungup.
2021-06-10 13:09:44.576808 [DEBUG] sofia.c:1549 Channel is already hungup.
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:604 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State NEW
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_HANGUP (Cur 1 Tot 24473)
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:848 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Callstate Change DOWN -> HANGUP
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:850 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State HANGUP
2021-06-10 13:09:44.576808 [DEBUG] mod_sofia.c:453 Channel sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 hanging up, cause: CALL_REJECTED
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:60 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard HANGUP, cause: CALL_REJECTED
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:850 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State HANGUP going to sleep
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:620 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State Change CS_HANGUP -> CS_REPORTING
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:585 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_REPORTING (Cur 1 Tot 24473)
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:936 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State REPORTING
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:174 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard REPORTING, cause: CALL_REJECTED
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:936 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State REPORTING going to sleep
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:611 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State Change CS_REPORTING -> CS_DESTROY
2021-06-10 13:09:44.576808 [DEBUG] switch_core_session.c:1736 Session 24473 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Locked, Waiting on external entities
2021-06-10 13:09:44.576808 [NOTICE] switch_core_session.c:1754 Session 24473 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Ended
2021-06-10 13:09:44.576808 [NOTICE] switch_core_session.c:1758 Close Channel sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 [CS_DESTROY]
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:739 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) Running State Change CS_DESTROY (Cur 0 Tot 24473)
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:749 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State DESTROY
2021-06-10 13:09:44.576808 [DEBUG] mod_sofia.c:364 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 SOFIA DESTROY
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:181 sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080 Standard DESTROY
2021-06-10 13:09:44.576808 [DEBUG] switch_core_state_machine.c:749 (sofia/external/700@ZZ.ZZZ.ZZZ.ZZ:5080) State DESTROY going to sleep
recv 295 bytes from udp/[XXX.XX.X.XXX]:5060 at 13:09:44.618786:
------------------------------------------------------------------------
ACK sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080 SIP/2.0
Via: SIP/2.0/UDP 192.168.7.126:5060;branch=z9hG4bK1890875013
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=857552051
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5080>;tag=QFv89p9BF1DNe
Call-ID: 0_1100972769@192.168.7.126
CSeq: 1 ACK
Content-Length: 0
 
hfoster

hfoster

Active Member
Jan 28, 2019
685
82
28
34
Am I reading it right that your phones are trying to use the external profile on 5080? Really they should be using the internal profile.

Also, have you got rport enabled on the handsets?
 
B

BigDuke6

New Member
Jun 7, 2021
7
0
1
47
Thanks for looking.

I have rport enabled.

1623333300727.png


I have also corrected the port on the phone to 5060. Same result really.... Everything seems to fail from my remote phone coming in to my Fusion server.

recv 921 bytes from udp/[XXX.XX.X.XXX]:5060 at 13:49:48.028859:
------------------------------------------------------------------------
INVITE sip:##########@ZZ.ZZZ.ZZZ.ZZ:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.7.126:5060;branch=z9hG4bK2987110278;rport
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5060>;tag=1661848879
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5060>
Call-ID: 0_3908260588@192.168.7.126
CSeq: 1 INVITE
Contact: <sip:700@192.168.7.126:5060>
Content-Type: application/sdp
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
Max-Forwards: 70
User-Agent: Yealink SIP-T46G 28.83.0.120
Allow-Events: talk,hold,conference,refer,check-sync
Supported: replaces
Content-Length: 308

v=0
o=- 20129 20129 IN IP4 192.168.7.126
s=SDP data
c=IN IP4 192.168.7.126
t=0 0
m=audio 12564 RTP/AVP 9 0 8 18 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2021-06-10 13:49:47.996844 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060 [866522af-bbf0-4894-a4d1-959fa0403e5e]
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) Running State Change CS_NEW (Cur 1 Tot 24482)
2021-06-10 13:49:47.996844 [INFO] sofia.c:10362 sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060 receiving invite from XXX.XX.X.XXX:5060 version: 1.10.6 -release-18-1ff9d0a60e 64bit call-id: 0_3908260588@192.168.7.126
2021-06-10 13:49:47.996844 [DEBUG] sofia.c:10456 verifying acl "domains" for ip/port XXX.XX.X.XXX:0.
2021-06-10 13:49:47.996844 [WARNING] sofia.c:10569 IP XXX.XX.X.XXX Rejected by acl "domains"
send 672 bytes to udp/[XXX.XX.X.XXX]:5060 at 13:49:48.031937:
------------------------------------------------------------------------
SIP/2.0 403 Forbidden
Via: SIP/2.0/UDP 192.168.7.126:5060;branch=z9hG4bK2987110278;rport=5060;received=XXX.XX.X.XXX
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5060>;tag=1661848879
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5060>;tag=0St8ZreDUcBXD
Call-ID: 0_3908260588@192.168.7.126
CSeq: 1 INVITE
User-Agent: FreeSWITCH
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0

2021-06-10 13:49:47.996844 [NOTICE] sofia.c:2445 Hangup sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060 [CS_NEW] [CALL_REJECTED]
2021-06-10 13:49:47.996844 [DEBUG] sofia.c:1549 Channel is already hungup.
2021-06-10 13:49:47.996844 [DEBUG] sofia.c:1549 Channel is already hungup.
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:604 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) State NEW
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) Running State Change CS_HANGUP (Cur 1 Tot 24482)
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) Callstate Change DOWN -> HANGUP
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) State HANGUP
2021-06-10 13:49:47.996844 [DEBUG] mod_sofia.c:453 Channel sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060 hanging up, cause: CALL_REJECTED
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:60 sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060 Standard HANGUP, cause: CALL_REJECTED
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) State HANGUP going to sleep
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) State Change CS_HANGUP -> CS_REPORTING
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) Running State Change CS_REPORTING (Cur 1 Tot 24482)
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) State REPORTING
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:174 sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060 Standard REPORTING, cause: CALL_REJECTED
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) State REPORTING going to sleep
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) State Change CS_REPORTING -> CS_DESTROY
2021-06-10 13:49:47.996844 [DEBUG] switch_core_session.c:1736 Session 24482 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) Locked, Waiting on external entities
2021-06-10 13:49:47.996844 [NOTICE] switch_core_session.c:1754 Session 24482 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) Ended
2021-06-10 13:49:47.996844 [NOTICE] switch_core_session.c:1758 Close Channel sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060 [CS_DESTROY]
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) Running State Change CS_DESTROY (Cur 0 Tot 24482)
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) State DESTROY
2021-06-10 13:49:47.996844 [DEBUG] mod_sofia.c:364 sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060 SOFIA DESTROY
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:181 sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060 Standard DESTROY
2021-06-10 13:49:47.996844 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/700@ZZ.ZZZ.ZZZ.ZZ:5060) State DESTROY going to sleep
recv 302 bytes from udp/[XXX.XX.X.XXX]:5060 at 13:49:48.064782:
------------------------------------------------------------------------
ACK sip:##########@ZZ.ZZZ.ZZZ.ZZ:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.7.126:5060;branch=z9hG4bK2987110278;rport
From: "700" <sip:700@ZZ.ZZZ.ZZZ.ZZ:5060>;tag=1661848879
To: <sip:##########@ZZ.ZZZ.ZZZ.ZZ:5060>;tag=0St8ZreDUcBXD
Call-ID: 0_3908260588@192.168.7.126
CSeq: 1 ACK
Content-Length: 0
 
A

ad5ou

Active Member
Jun 12, 2018
892
205
43
You don't have anything in CIDR or ACL for the extension setting? (beyond the advanced button) It should be empty normally.
1623334522849.png
 
hfoster

hfoster

Active Member
Jan 28, 2019
685
82
28
34
And the phone is definitely registered at this point? It's quite odd that the internal profile is not doing auth-calls, and just straight up rejecting. Bit of a doozy this one. Out of the box on Lightsail, I only need to change the ext-rtp-ip and ext-sip-ip to the public address and everything is clean sailing.

Slap my provider's IP prefixes in the domains ACL, and the gateway side is pretty much done too.
 
B

BigDuke6

New Member
Jun 7, 2021
7
0
1
47
hfoster said:
And the phone is definitely registered at this point? It's quite odd that the internal profile is not doing auth-calls, and just straight up rejecting. Bit of a doozy this one. Out of the box on Lightsail, I only need to change the ext-rtp-ip and ext-sip-ip to the public address and everything is clean sailing.

Slap my provider's IP prefixes in the domains ACL, and the gateway side is pretty much done too.
Click to expand...
Yep, did that for both internal and external profiles at setup.
 
A

ad5ou

Active Member
Jun 12, 2018
892
205
43
Have you changed anything other than SIP/RTP IP setting in sip profiles? Usually those are only changes needed unless adding TLS or multi registration support etc.
The first few important settings are shown below
1623345042908.png
 
Status
Not open for further replies.
Top Bottom