Hi guys,
I've been trying to troubleshoot why inbound calls are not working. I can make outbound calls from my Fusion PBX with no issues, but incoming calls don't work.
Below is the log:
Below my inbound dial plan route:
Any ideas?
Thank you!
I've been trying to troubleshoot why inbound calls are not working. I can make outbound calls from my Fusion PBX with no issues, but incoming calls don't work.
Below is the log:
Code:
2019-06-19 13:51:44.350574 [NOTICE] switch_channel.c:1104 New Channel sofia/external/+1415619XXXX@sip.signalwire.com [d557e157-6190-4e15-bef3-36286bce0368]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+1415619XXXX@sip.signalwire.com) Running State Change CS_NEW (Cur 1 Tot 91)
2019-06-19 13:51:44.350574 [DEBUG] sofia.c:10092 sofia/external/+1415619XXXX@sip.signalwire.com receiving invite from 104.248.176.184:5060 version: 1.8.5 -6-31281a0 64bit
2019-06-19 13:51:44.350574 [DEBUG] sofia.c:10208 IP 104.248.176.184 Approved by acl "domains[]". Access Granted.
2019-06-19 13:51:44.350574 [DEBUG] sofia.c:7291 Channel sofia/external/+1415619XXXX@sip.signalwire.com entering state [received][100]
2019-06-19 13:51:44.350574 [DEBUG] sofia.c:7301 Remote SDP:
v=0
o=SignalWire-STACK 1560960034 1560960035 IN IP4 178.128.235.231
s=SignalWire-STACK
c=IN IP4 178.128.235.231
t=0 0
m=audio 17470 RTP/SAVP 0 102 9 8 18 101 13 103 104
a=rtpmap:0 PCMU/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:9 G722/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-16
a=rtpmap:13 CN/8000
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtpmap:104 CN/48000
a=crypto:1 AEAD_AES_256_GCM_8 inline:DHpP7b41upMW3zmg9nV9cysPOdow7aB4FjsCxa6ySaDncwgc6WzztXebqkE=
a=crypto:3 AES_256_CM_HMAC_SHA1_80 inline:cbSsP8KPZzTdROR50nc/AqzdTJEwlGzImWhRwY1XMcfFEUr1NBrG3TbSgSw0pw==
a=crypto:5 AES_CM_128_HMAC_SHA1_80 inline:DpOLn4DxsdsxZJ50Tc1ulpz5wZcXuQ3+8wt1X3p8
a=crypto:6 AES_256_CM_HMAC_SHA1_32 inline:hTv8ne+OHgxwgNJKo+4Yut4Z8fjK9Dm/pNOjQhiMOoGzu/HHLqX7GYwFNQxYZw==
a=crypto:8 AES_CM_128_HMAC_SHA1_32 inline:lGwxUCUr7f3DRSn3RU869xztRpgCo10v6M0GGZ1U
a=ptime:20
m=audio 17470 RTP/AVP 0 102 9 8 18 101 13 103 104
a=rtpmap:0 PCMU/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:9 G722/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-16
a=rtpmap:13 CN/8000
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtpmap:104 CN/48000
a=ptime:20
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:1804 looking for crypto suite [AEAD_AES_256_GCM_8]alias=[] in [1 AEAD_AES_256_GCM_8 inline:DHpP7b41upMW3zmg9nV9cysPOdow7aB4FjsCxa6ySaDncwgc6WzztXebqkE=]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:1813 Found suite AEAD_AES_256_GCM_8
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:1883 Set Remote Key [1 AEAD_AES_256_GCM_8 inline:DHpP7b41upMW3zmg9nV9cysPOdow7aB4FjsCxa6ySaDncwgc6WzztXebqkE=]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:1209 Set Local audio crypto Key [1 AEAD_AES_256_GCM_8 inline:wxb7Zn++R+1815O4MQayK5YHjmamluTpOFF1qKfKxruKythgRBGECSMEXHQ=]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [opus:102:48000:20:0:2]/[G722:9:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [opus:102:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [opus:102:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [CN:104:48000:20:0:1]/[G722:9:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [CN:104:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [CN:104:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:3781 Set Codec sofia/external/+1415619XXXX@sip.signalwire.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-06-19 13:51:44.350574 [DEBUG] switch_core_codec.c:111 sofia/external/+1415619XXXX@sip.signalwire.com Original read codec set to PCMU:0
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5737 Set telephone-event payload to 101@8000
2019-06-19 13:51:44.350574 [DEBUG] switch_core_media.c:5795 sofia/external/+1415619XXXX@sip.signalwire.com Set 2833 dtmf send payload to 101 recv payload to 101
2019-06-19 13:51:44.350574 [DEBUG] sofia.c:7716 (sofia/external/+1415619XXXX@sip.signalwire.com) State Change CS_NEW -> CS_INIT
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:603 (sofia/external/+1415619XXXX@sip.signalwire.com) State NEW
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+1415619XXXX@sip.signalwire.com) Running State Change CS_INIT (Cur 1 Tot 91)
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+1415619XXXX@sip.signalwire.com) State INIT
2019-06-19 13:51:44.350574 [DEBUG] mod_sofia.c:93 sofia/external/+1415619XXXX@sip.signalwire.com SOFIA INIT
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:40 sofia/external/+1415619XXXX@sip.signalwire.com Standard INIT
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+1415619XXXX@sip.signalwire.com) State Change CS_INIT -> CS_ROUTING
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+1415619XXXX@sip.signalwire.com) State INIT going to sleep
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+1415619XXXX@sip.signalwire.com) Running State Change CS_ROUTING (Cur 1 Tot 91)
2019-06-19 13:51:44.350574 [DEBUG] switch_channel.c:2249 (sofia/external/+1415619XXXX@sip.signalwire.com) Callstate Change DOWN -> RINGING
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+1415619XXXX@sip.signalwire.com) State ROUTING
2019-06-19 13:51:44.350574 [DEBUG] mod_sofia.c:154 sofia/external/+1415619XXXX@sip.signalwire.com SOFIA ROUTING
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:236 sofia/external/+1415619XXXX@sip.signalwire.com Standard ROUTING
2019-06-19 13:51:44.350574 [INFO] mod_dialplan_xml.c:637 Processing +1415619XXXX <+1415619XXXX>->pbx1 in context public
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com parsing [public->caller-details] continue=true
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com Regex (PASS) [caller-details] () =~ // break=never
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com Action export(call_direction=inbound) INLINE
EXECUTE sofia/external/+1415619XXXX@sip.signalwire.com export(call_direction=inbound)
2019-06-19 13:51:44.350574 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com Action set(caller_destination=${destination_number}) INLINE
EXECUTE sofia/external/+1415619XXXX@sip.signalwire.com set(caller_destination=pbx1)
2019-06-19 13:51:44.350574 [DEBUG] mod_dptools.c:1598 SET sofia/external/+1415619XXXX@sip.signalwire.com [caller_destination]=[pbx1]
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE sofia/external/+1415619XXXX@sip.signalwire.com set(caller_id_name=+1415619XXXX)
2019-06-19 13:51:44.350574 [DEBUG] mod_dptools.c:1598 SET sofia/external/+1415619XXXX@sip.signalwire.com [caller_id_name]=[+1415619XXXX]
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com parsing [public->3108070836] continue=false
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com Regex (FAIL) [3108070836] destination_number(pbx1) =~ /^(3108070836)$/ break=on-false
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com parsing [public->not-found] continue=false
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com Regex (PASS) [not-found] () =~ // break=on-false
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com Action export(call_direction=inbound) INLINE
EXECUTE sofia/external/+1415619XXXX@sip.signalwire.com export(call_direction=inbound)
2019-06-19 13:51:44.350574 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com Action set(call_direction=inbound) INLINE
EXECUTE sofia/external/+1415619XXXX@sip.signalwire.com set(call_direction=inbound)
2019-06-19 13:51:44.350574 [DEBUG] mod_dptools.c:1598 SET sofia/external/+1415619XXXX@sip.signalwire.com [call_direction]=[inbound]
Dialplan: sofia/external/+1415619XXXX@sip.signalwire.com Action log([inbound routes] 404 not found ${sip_network_ip})
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:286 (sofia/external/+1415619XXXX@sip.signalwire.com) State Change CS_ROUTING -> CS_EXECUTE
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+1415619XXXX@sip.signalwire.com) State ROUTING going to sleep
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+1415619XXX@sip.signalwire.com) Running State Change CS_EXECUTE (Cur 1 Tot 91)
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+1415619XXXX@sip.signalwire.com) State EXECUTE
2019-06-19 13:51:44.350574 [DEBUG] mod_sofia.c:209 sofia/external/+1415619XXXX@sip.signalwire.com SOFIA EXECUTE
2019-06-19 13:51:44.350574 [DEBUG] switch_core_state_machine.c:328 sofia/external/+1415619XXXX@sip.signalwire.com Standard EXECUTE
EXECUTE sofia/external/+1415619XXXX@sip.signalwire.com set(caller_id_number=+1415619XXXX)
2019-06-19 13:51:44.350574 [DEBUG] mod_dptools.c:1598 SET sofia/external/+1415619XXXX@sip.signalwire.com [caller_id_number]=[+1415619XXXX]
EXECUTE sofia/external/+1415619XXXX@sip.signalwire.com log([inbound routes] 404 not found 104.248.176.184)
2019-06-19 13:51:44.370502 [DEBUG] mod_dptools.c:1792 routes] 404 not found 104.248.176.184
2019-06-19 13:51:44.370502 [NOTICE] switch_core_state_machine.c:385 sofia/external/+1415619XXXX@sip.signalwire.com has executed the last dialplan instruction, hanging up.
2019-06-19 13:51:44.370502 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external/+1415619XXXX@sip.signalwire.com [CS_EXECUTE] [NORMAL_CLEARING]
2019-06-19 13:51:44.370502 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+1415619XXXX@sip.signalwire.com) State EXECUTE going to sleep
2019-06-19 13:51:44.370502 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+1415619XXXX@sip.signalwire.com) Running State Change CS_HANGUP (Cur 1 Tot 91)
2019-06-19 13:51:44.370502 [DEBUG] switch_core_state_machine.c:847 (sofia/external/+1415619XXXX@sip.signalwire.com) Callstate Change RINGING -> HANGUP
2019-06-19 13:51:44.370502 [DEBUG] switch_core_state_machine.c:849 (sofia/external/+1415619XXXX@sip.signalwire.com) State HANGUP
2019-06-19 13:51:44.370502 [DEBUG] mod_sofia.c:449 Channel sofia/external/+1415619XXXX@sip.signalwire.com hanging up, cause: NORMAL_CLEARING
2019-06-19 13:51:44.370502 [DEBUG] mod_sofia.c:589 Responding to INVITE with: 480
2019-06-19 13:51:44.370502 [DEBUG] switch_core_state_machine.c:60 sofia/external/+1415619XXXX@sip.signalwire.com Standard HANGUP, cause: NORMAL_CLEARING
2019-06-19 13:51:44.370502 [DEBUG] switch_core_state_machine.c:849 (sofia/external/+1415619XXXX@sip.signalwire.com) State HANGUP going to sleep
2019-06-19 13:51:44.370502 [DEBUG] switch_core_state_machine.c:619 (sofia/external/+1415619XXXX@sip.signalwire.com) State Change CS_HANGUP -> CS_REPORTING
2019-06-19 13:51:44.370502 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+1415619XXXX@sip.signalwire.com) Running State Change CS_REPORTING (Cur 1 Tot 91)
2019-06-19 13:51:44.370502 [DEBUG] switch_core_state_machine.c:935 (sofia/external/+1415619XXXX@sip.signalwire.com) State REPORTING
2019-06-19 13:51:44.410497 [DEBUG] switch_core_state_machine.c:174 sofia/external/+1415619XXXX@sip.signalwire.com Standard REPORTING, cause: NORMAL_CLEARING
2019-06-19 13:51:44.410497 [DEBUG] switch_core_state_machine.c:935 (sofia/external/+1415619XXXX@sip.signalwire.com) State REPORTING going to sleep
2019-06-19 13:51:44.410497 [DEBUG] switch_core_state_machine.c:610 (sofia/external/+1415619XXXX@sip.signalwire.com) State Change CS_REPORTING -> CS_DESTROY
2019-06-19 13:51:44.410497 [DEBUG] switch_core_session.c:1715 Session 91 (sofia/external/+1415619XXXX@sip.signalwire.com) Locked, Waiting on external entities
2019-06-19 13:51:44.410497 [NOTICE] switch_core_session.c:1733 Session 91 (sofia/external/+1415619XXXX@sip.signalwire.com) Ended
2019-06-19 13:51:44.410497 [NOTICE] switch_core_session.c:1737 Close Channel sofia/external/+1415619XXXX@sip.signalwire.com [CS_DESTROY]
2019-06-19 13:51:44.410497 [DEBUG] switch_core_state_machine.c:738 (sofia/external/+1415619XXXX@sip.signalwire.com) Running State Change CS_DESTROY (Cur 0 Tot 91)
2019-06-19 13:51:44.410497 [DEBUG] switch_core_state_machine.c:748 (sofia/external/+1415619XXXX@sip.signalwire.com) State DESTROY
2019-06-19 13:51:44.410497 [DEBUG] mod_sofia.c:354 sofia/external/+1415619XXXX@sip.signalwire.com SOFIA DESTROY
2019-06-19 13:51:44.410497 [DEBUG] switch_core_state_machine.c:181 sofia/external/+1415619XXXX@sip.signalwire.com Standard DESTROY
2019-06-19 13:51:44.410497 [DEBUG] switch_core_state_machine.c:748 (sofia/external/+1415619XXXX@sip.signalwire.com) State DESTROY going to sleep
2019-06-19 13:53:45.430564 [DEBUG] sofia_reg.c:2462 Changing expire time to 600 by request of proxy sip:ifactor-bf49d192ac00.sip.signalwire.com
2019-06-19 13:55:31.650575 [NOTICE] mod_signalwire.c:378 Go to https://signalwire.com to set up your Connector now! Enter connection token 3ea7db40-73b7-4c22-9430-a22a8814d8b5
2019-06-19 13:55:31.650575 [INFO] mod_signalwire.c:1001 Next SignalWire adoption check in 15 minutes
2019-06-19 13:59:10.510548 [DEBUG] sofia_reg.c:2462 Changing expire time to 600 by request of proxy sip:ifactor-bf49d192ac00.sip.signalwire.com
2019-06-19 14:02:08.370546 [DEBUG] sofia_reg.c:2462 Changing expire time to 600 by request of proxy sip:ifactor-bf49d192ac00.sip.signalwire.comBelow my inbound dial plan route:
Any ideas?
Thank you!
