SOS - Inbound calls work but NOT outbound calls

Status
Not open for further replies.
R

rfc1920

New Member
Jul 1, 2021
16
0
1
59
I have a test setup at home using VOIP.ms and a setup at work pointing to an asterisk system which is our very poor man's SBC. I have been able to get inbound calls, hold music, etc. to work just fine. So far I am working with one number (mine).

I have setup two gateways: the aforementioned asterisk server as well as Vitelity as a backup provider. FusionPBX is behind our NAT firewall with no ports forwarded, etc. We register to Vitelity and NOREG to asterisk. I currently have domain ACL set to allow with no entries.

However, outbound calls appear to instantly be re-rerouted as inbound calls and fail immediately. They never leave FusionPBX so I am sure I have screwed something up.

Below, 7135554444 is the called number, 7134445555 is the calling number as well as a destination for extension 11264, att.local.domain is the servername/domain of FusionPBX, and phone.client.ip.address is the calling phone client (3CX):

2021-07-12 15:07:43.534144 [DEBUG] switch_core_media.c:3847 Set Codec sofia/internal/11264@att.local.domain:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2021-07-12 15:07:43.534144 [DEBUG] switch_core_codec.c:111 sofia/internal/11264@att.local.domain:5060 Original read codec set to PCMU:0
2021-07-12 15:07:43.534144 [DEBUG] switch_core_media.c:5860 Set telephone-event payload to 101@8000
2021-07-12 15:07:43.534144 [DEBUG] switch_core_media.c:5918 sofia/internal/11264@att.local.domain:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2021-07-12 15:07:43.534144 [DEBUG] sofia.c:7840 (sofia/internal/11264@att.local.domain:5060) State Change CS_NEW -> CS_INIT
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:604 (sofia/internal/11264@att.local.domain:5060) State NEW
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/11264@att.local.domain:5060) Running State Change CS_INIT (Cur 1 Tot 219)
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/11264@att.local.domain:5060) State INIT
2021-07-12 15:07:43.534144 [DEBUG] mod_sofia.c:93 sofia/internal/11264@att.local.domain:5060 SOFIA INIT
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:40 sofia/internal/11264@att.local.domain:5060 Standard INIT
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/11264@att.local.domain:5060) State Change CS_INIT -> CS_ROUTING
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/11264@att.local.domain:5060) State INIT going to sleep
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/11264@att.local.domain:5060) Running State Change CS_ROUTING (Cur 1 Tot 219)
2021-07-12 15:07:43.534144 [DEBUG] switch_channel.c:2332 (sofia/internal/11264@att.local.domain:5060) Callstate Change DOWN -> RINGING
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/11264@att.local.domain:5060) State ROUTING
2021-07-12 15:07:43.534144 [DEBUG] mod_sofia.c:154 sofia/internal/11264@att.local.domain:5060 SOFIA ROUTING
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:236 sofia/internal/11264@att.local.domain:5060 Standard ROUTING
2021-07-12 15:07:43.534144 [INFO] mod_dialplan_xml.c:637 Processing First Last <11264>->97135554444 in context public
Dialplan: sofia/internal/11264@att.local.domain:5060 parsing [public->caller-details] continue=true
Dialplan: sofia/internal/11264@att.local.domain:5060 Regex (PASS) [caller-details] () =~ // break=never
Dialplan: sofia/internal/11264@att.local.domain:5060 Action export(call_direction=inbound) INLINE
EXECUTE [depth=0] sofia/internal/11264@att.local.domain:5060 export(call_direction=inbound)
2021-07-12 15:07:43.534144 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/internal/11264@att.local.domain:5060 Action set(caller_destination=${sip_to_user}) INLINE
EXECUTE [depth=0] sofia/internal/11264@att.local.domain:5060 set(caller_destination=97135554444)
2021-07-12 15:07:43.534144 [DEBUG] mod_dptools.c:1685 SET sofia/internal/11264@att.local.domain:5060 [caller_destination]=[97135554444]
Dialplan: sofia/internal/11264@att.local.domain:5060 Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/11264@att.local.domain:5060 set(caller_id_name=First Last)
2021-07-12 15:07:43.534144 [DEBUG] mod_dptools.c:1685 SET sofia/internal/11264@att.local.domain:5060 [caller_id_name]=[First Last]
Dialplan: sofia/internal/11264@att.local.domain:5060 Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/11264@att.local.domain:5060 parsing [public->8324445555] continue=false
Dialplan: sofia/internal/11264@att.local.domain:5060 Regex (FAIL) [8324445555] destination_number(97135554444) =~ /^\+?1?(8324445555)$/ break=on-false
Dialplan: sofia/internal/11264@att.local.domain:5060 parsing [public->not-found] continue=false
Dialplan: sofia/internal/11264@att.local.domain:5060 Regex (PASS) [not-found] () =~ // break=on-false
Dialplan: sofia/internal/11264@att.local.domain:5060 Action export(call_direction=inbound) INLINE
EXECUTE [depth=0] sofia/internal/11264@att.local.domain:5060 export(call_direction=inbound)
2021-07-12 15:07:43.534144 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/internal/11264@att.local.domain:5060 Action set(call_direction=inbound) INLINE
EXECUTE [depth=0] sofia/internal/11264@att.local.domain:5060 set(call_direction=inbound)
2021-07-12 15:07:43.534144 [DEBUG] mod_dptools.c:1685 SET sofia/internal/11264@att.local.domain:5060 [call_direction]=[inbound]
Dialplan: sofia/internal/11264@att.local.domain:5060 Action log(WARNING [inbound routes] 404 not found ${sip_network_ip})
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/11264@att.local.domain:5060) State Change CS_ROUTING -> CS_EXECUTE
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/11264@att.local.domain:5060) State ROUTING going to sleep
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/11264@att.local.domain:5060) Running State Change CS_EXECUTE (Cur 1 Tot 219)
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/11264@att.local.domain:5060) State EXECUTE
2021-07-12 15:07:43.534144 [DEBUG] mod_sofia.c:209 sofia/internal/11264@att.local.domain:5060 SOFIA EXECUTE
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:329 sofia/internal/11264@att.local.domain:5060 Standard EXECUTE
EXECUTE [depth=0] sofia/internal/11264@att.local.domain:5060 set(caller_id_number=11264)
2021-07-12 15:07:43.534144 [DEBUG] mod_dptools.c:1685 SET sofia/internal/11264@att.local.domain:5060 [caller_id_number]=[11264]
EXECUTE [depth=0] sofia/internal/11264@att.local.domain:5060 log(WARNING [inbound routes] 404 not found phone.client.ip.address)
2021-07-12 15:07:43.534144 [WARNING] mod_dptools.c:1879 [inbound routes] 404 not found phone.client.ip.address
2021-07-12 15:07:43.534144 [NOTICE] switch_core_state_machine.c:386 sofia/internal/11264@att.local.domain:5060 has executed the last dialplan instruction, hanging up.
2021-07-12 15:07:43.534144 [NOTICE] switch_core_state_machine.c:388 Hangup sofia/internal/11264@att.local.domain:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/11264@att.local.domain:5060) State EXECUTE going to sleep
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/11264@att.local.domain:5060) Running State Change CS_HANGUP (Cur 1 Tot 219)
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/11264@att.local.domain:5060) Callstate Change RINGING -> HANGUP
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/11264@att.local.domain:5060) State HANGUP
2021-07-12 15:07:43.534144 [DEBUG] mod_sofia.c:453 Channel sofia/internal/11264@att.local.domain:5060 hanging up, cause: NORMAL_CLEARING
2021-07-12 15:07:43.534144 [DEBUG] mod_sofia.c:598 Responding to INVITE with: 480
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:60 sofia/internal/11264@att.local.domain:5060 Standard HANGUP, cause: NORMAL_CLEARING
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/11264@att.local.domain:5060) State HANGUP going to sleep
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/11264@att.local.domain:5060) State Change CS_HANGUP -> CS_REPORTING
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/11264@att.local.domain:5060) Running State Change CS_REPORTING (Cur 1 Tot 219)
2021-07-12 15:07:43.534144 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/11264@att.local.domain:5060) State REPORTING
2021-07-12 15:07:43.594141 [DEBUG] switch_core_state_machine.c:174 sofia/internal/11264@att.local.domain:5060 Standard REPORTING, cause: NORMAL_CLEARING
2021-07-12 15:07:43.594141 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/11264@att.local.domain:5060) State REPORTING going to sleep
2021-07-12 15:07:43.594141 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/11264@att.local.domain:5060) State Change CS_REPORTING -> CS_DESTROY
2021-07-12 15:07:43.594141 [DEBUG] switch_core_session.c:1736 Session 219 (sofia/internal/11264@att.local.domain:5060) Locked, Waiting on external entities
2021-07-12 15:07:43.594141 [NOTICE] switch_core_session.c:1754 Session 219 (sofia/internal/11264@att.local.domain:5060) Ended
2021-07-12 15:07:43.594141 [NOTICE] switch_core_session.c:1758 Close Channel sofia/internal/11264@att.local.domain:5060 [CS_DESTROY]
2021-07-12 15:07:43.594141 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/11264@att.local.domain:5060) Running State Change CS_DESTROY (Cur 0 Tot 219)
2021-07-12 15:07:43.594141 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/11264@att.local.domain:5060) State DESTROY
2021-07-12 15:07:43.594141 [DEBUG] mod_sofia.c:364 sofia/internal/11264@att.local.domain:5060 SOFIA DESTROY
2021-07-12 15:07:43.594141 [DEBUG] switch_core_state_machine.c:181 sofia/internal/11264@att.local.domain:5060 Standard DESTROY
2021-07-12 15:07:43.594141 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/11264@att.local.domain:5060) State DESTROY going to sleep

The outbound route ends with the following:
2021-07-12_451545126-xc454i-4537.png
That is our local asterisk gateway at the top, although it never gets there. When I had ACL set to deny with an allow for asterisk, I think the reverse was the case (inbound broken, outbound working).
 
FWIW, the only reason I mentioned the home setup and VOIP.ms is that I appear to have made it down the same rabbit hole there.
 
Once again, asking for help is the quickest way to fix it yourself. I simply re-enabled ACL with default deny and a single allow for the upstream asterisk server ip/32 and left the right side blank. Inbound and outbound are both working now.
 
I currently have domain ACL set to allow with no entries
Click to expand...

I don't think you want to do that, only your carriers advertised IP Addresses. Your internal extensions are going to end up using the wrong context otherwise.
 
Status
Not open for further replies.
Top Bottom