Outbound Calling

Status
Not open for further replies.
J

jeffa1792

New Member
May 3, 2021
6
0
1
52
Inbound calling and internal calling works however Outbound calls terminate with NORMAL_TEMPORARY_FAILURE.

Outbound Route seems to be selected correctly as it attempts to call the destination SIP trunk.

Any help would be greatly appreciated.
-Jeff




Log
===
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.660000 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/222@{MY_PBX_DOMAIN} [38e2618d-8bf6-401e-8acb-df4537a3b3e8]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.660000 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/222@{MY_PBX_DOMAIN}) Running State Change CS_NEW (Cur 1 Tot 3)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.660000 [INFO] sofia.c:10362 sofia/internal/222@{MY_PBX_DOMAIN} receiving invite from {DEST_PBX_IP}:13258 version: 1.10.6 -release-18-1ff9d0a60e 64bit call-id: 37644e94-7a33-4483-a7e4-c5f931b15599
2021-05-04 20:51:48.660000 [DEBUG] sofia.c:10456 verifying acl "domains" for ip/port {DEST_PBX_IP}:0.
2021-05-04 20:51:48.660000 [DEBUG] sofia.c:2447 detaching session 38e2618d-8bf6-401e-8acb-df4537a3b3e8
2021-05-04 20:51:48.660000 [WARNING] sofia_reg.c:1795 SIP auth challenge (INVITE) on sofia profile 'internal' for [{DEST_PHONE}@{MY_PBX_DOMAIN}] from ip {DEST_PBX_IP}
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.660000 [DEBUG] switch_core_state_machine.c:604 (sofia/internal/222@{MY_PBX_DOMAIN}) State NEW
2021-05-04 20:51:48.740000 [DEBUG] sofia.c:2562 Re-attaching to session 38e2618d-8bf6-401e-8acb-df4537a3b3e8
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [INFO] sofia.c:10362 sofia/internal/222@{MY_PBX_DOMAIN} receiving invite from {DEST_PBX_IP}:13258 version: 1.10.6 -release-18-1ff9d0a60e 64bit call-id: 37644e94-7a33-4483-a7e4-c5f931b15599
2021-05-04 20:51:48.740000 [DEBUG] sofia.c:10456 verifying acl "domains" for ip/port {DEST_PBX_IP}:0.
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] sofia.c:11564 Setting NAT mode based on via received
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] sofia.c:7406 Channel sofia/internal/222@{MY_PBX_DOMAIN} entering state [received][100]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] sofia.c:7416 Remote SDP:
38e2618d-8bf6-401e-8acb-df4537a3b3e8 v=0
38e2618d-8bf6-401e-8acb-df4537a3b3e8 o=- 3829150307 3829150307 IN IP4 192.0.0.4
38e2618d-8bf6-401e-8acb-df4537a3b3e8 s=pjmedia
38e2618d-8bf6-401e-8acb-df4537a3b3e8 b=AS:84
38e2618d-8bf6-401e-8acb-df4537a3b3e8 t=0 0
38e2618d-8bf6-401e-8acb-df4537a3b3e8 a=X-nat:0
38e2618d-8bf6-401e-8acb-df4537a3b3e8 m=audio 4010 RTP/AVP 8 0 3 9 18 96
38e2618d-8bf6-401e-8acb-df4537a3b3e8 c=IN IP4 192.0.0.4
38e2618d-8bf6-401e-8acb-df4537a3b3e8 b=TIAS:64000
38e2618d-8bf6-401e-8acb-df4537a3b3e8 a=rtpmap:8 PCMA/8000
38e2618d-8bf6-401e-8acb-df4537a3b3e8 a=rtpmap:0 PCMU/8000
38e2618d-8bf6-401e-8acb-df4537a3b3e8 a=rtpmap:3 GSM/8000
38e2618d-8bf6-401e-8acb-df4537a3b3e8 a=rtpmap:9 G722/8000
38e2618d-8bf6-401e-8acb-df4537a3b3e8 a=rtpmap:18 G729/8000
38e2618d-8bf6-401e-8acb-df4537a3b3e8 a=fmtp:18 annexb=no
38e2618d-8bf6-401e-8acb-df4537a3b3e8 a=rtpmap:96 telephone-event/8000
38e2618d-8bf6-401e-8acb-df4537a3b3e8 a=fmtp:96 0-16
38e2618d-8bf6-401e-8acb-df4537a3b3e8 a=rtcp:4011 IN IP4 192.0.0.4
38e2618d-8bf6-401e-8acb-df4537a3b3e8
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5656 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5656 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5656 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5517 Set telephone-event payload to 96@8000
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:3847 Set Codec sofia/internal/222@{MY_PBX_DOMAIN} PCMA/8000 20 ms 160 samples 64000 bits 1 channels
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_codec.c:111 sofia/internal/222@{MY_PBX_DOMAIN} Original read codec set to PCMA:8
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5860 Set telephone-event payload to 96@8000
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_media.c:5918 sofia/internal/222@{MY_PBX_DOMAIN} Set 2833 dtmf send payload to 96 recv payload to 96
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] sofia.c:7840 (sofia/internal/222@{MY_PBX_DOMAIN}) State Change CS_NEW -> CS_INIT
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/222@{MY_PBX_DOMAIN}) Running State Change CS_INIT (Cur 1 Tot 3)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/222@{MY_PBX_DOMAIN}) State INIT
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] mod_sofia.c:93 sofia/internal/222@{MY_PBX_DOMAIN} SOFIA INIT
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_state_machine.c:40 sofia/internal/222@{MY_PBX_DOMAIN} Standard INIT
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/222@{MY_PBX_DOMAIN}) State Change CS_INIT -> CS_ROUTING
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/222@{MY_PBX_DOMAIN}) State INIT going to sleep
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/222@{MY_PBX_DOMAIN}) Running State Change CS_ROUTING (Cur 1 Tot 3)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_channel.c:2332 (sofia/internal/222@{MY_PBX_DOMAIN}) Callstate Change DOWN -> RINGING
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/222@{MY_PBX_DOMAIN}) State ROUTING
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] mod_sofia.c:154 sofia/internal/222@{MY_PBX_DOMAIN} SOFIA ROUTING
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [DEBUG] switch_core_state_machine.c:236 sofia/internal/222@{MY_PBX_DOMAIN} Standard ROUTING
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.740000 [INFO] mod_dialplan_xml.c:637 Processing 222 <222>->{DEST_PHONE} in context {MY_PBX_DOMAIN}
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->user_exists] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [user_exists] () =~ // break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(user_exists=false)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.799984 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [user_exists]=[false]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(from_user_exists=true)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.799984 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [from_user_exists]=[true]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->call-direction] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} ANTI-Action export(call_direction=local) INLINE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} export(call_direction=local)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.799984 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[local]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->caller-details] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(caller_destination=${destination_number}) INLINE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(caller_destination={DEST_PHONE})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.799984 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [caller_destination]=[{DEST_PHONE}]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(caller_id_name=${caller_id_name}) INLINE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(caller_id_name=222)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.799984 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [caller_id_name]=[222]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(caller_id_number=${caller_id_number})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->global-variables] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [global-variables] () =~ // break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->domain-variables] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [domain-variables] () =~ // break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action export(origination_callee_id_name=${destination_number})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->is_loopback] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->user_record] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(from_user_record=)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [from_user_record]=[UNDEF]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->rtp_has_crypto] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [rtp_has_crypto] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->redial] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [redial] destination_number({DEST_PHONE}) =~ /^(redial|\*870)$/ break=on-true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [redial] () =~ // break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->speed_dial] continue=false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [speed_dial] destination_number({DEST_PHONE}) =~ /^\*0(.*)$/ break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->default_caller_id] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [default_caller_id] ${emergency_caller_id_name}() =~ /^$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(emergency_caller_id_name=)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [emergency_caller_id_name]=[UNDEF]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(emergency_caller_id_number=)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [emergency_caller_id_number]=[UNDEF]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [default_caller_id] ${outbound_caller_id_name}() =~ /^$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(outbound_caller_id_name=${default_outbound_caller_id_name}) INLINE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(outbound_caller_id_name=)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [outbound_caller_id_name]=[UNDEF]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [default_caller_id] ${outbound_caller_id_number}() =~ /^$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(outbound_caller_id_number=${default_outbound_caller_id_number}) INLINE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(outbound_caller_id_number=)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [outbound_caller_id_number]=[UNDEF]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->user_hold_music] continue=true
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_hold_music] ${hold_music}(local_stream://default) =~ /^$/ break=never
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} parsing [{MY_PBX_DOMAIN}->voipms.1d10] continue=false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [voipms.1d10] ${user_exists}(false) =~ /false/ break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Regex (PASS) [voipms.1d10] destination_number({DEST_PHONE}) =~ /^\+?1?(\d{10})$/ break=on-false
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(sip_h_X-accountcode=${accountcode})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action export(call_direction=outbound)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action unset(call_timeout)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(hangup_after_bridge=true)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(effective_caller_id_name=${outbound_caller_id_name})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(effective_caller_id_number=${outbound_caller_id_number})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(inherit_codec=true)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(ignore_display_updates=true)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(callee_id_number={DEST_PHONE})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action set(continue_on_fail=true)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 Dialplan: sofia/internal/222@{MY_PBX_DOMAIN} Action bridge(sofia/gateway/1fc1b62b-1724-41ed-827a-99beaf16a8f8/{DEST_PHONE})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/222@{MY_PBX_DOMAIN}) State Change CS_ROUTING -> CS_EXECUTE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/222@{MY_PBX_DOMAIN}) State ROUTING going to sleep
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/222@{MY_PBX_DOMAIN}) Running State Change CS_EXECUTE (Cur 1 Tot 3)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/222@{MY_PBX_DOMAIN}) State EXECUTE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_sofia.c:209 sofia/internal/222@{MY_PBX_DOMAIN} SOFIA EXECUTE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:329 sofia/internal/222@{MY_PBX_DOMAIN} Standard EXECUTE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(caller_id_number=222)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [caller_id_number]=[222]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(RFC2822_DATE=Tue, 04 May 2021 20:51:48 +0000)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [RFC2822_DATE]=[Tue, 04 May 2021 20:51:48 +0000]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} export(origination_callee_id_name={DEST_PHONE})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [origination_callee_id_name]=[{DEST_PHONE}]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} hash(insert/{MY_PBX_DOMAIN}-last_dial/222/{DEST_PHONE})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(sip_h_X-accountcode=)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [sip_h_X-accountcode]=[UNDEF]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} export(call_direction=outbound)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[outbound]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} unset(call_timeout)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1830 UNSET [call_timeout]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(hangup_after_bridge=true)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [hangup_after_bridge]=[true]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(effective_caller_id_name=)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [effective_caller_id_name]=[UNDEF]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(effective_caller_id_number=)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [effective_caller_id_number]=[UNDEF]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(inherit_codec=true)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [inherit_codec]=[true]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(ignore_display_updates=true)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [ignore_display_updates]=[true]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(callee_id_number={DEST_PHONE})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [callee_id_number]=[{DEST_PHONE}]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} set(continue_on_fail=true)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] mod_dptools.c:1685 SET sofia/internal/222@{MY_PBX_DOMAIN} [continue_on_fail]=[true]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 EXECUTE [depth=0] sofia/internal/222@{MY_PBX_DOMAIN} bridge(sofia/gateway/1fc1b62b-1724-41ed-827a-99beaf16a8f8/{DEST_PHONE})
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_channel.c:1264 sofia/internal/222@{MY_PBX_DOMAIN} EXPORTING[export_vars] [domain_name]=[{MY_PBX_DOMAIN}] to event
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_channel.c:1264 sofia/internal/222@{MY_PBX_DOMAIN} EXPORTING[export_vars] [call_direction]=[outbound] to event
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_channel.c:1264 sofia/internal/222@{MY_PBX_DOMAIN} EXPORTING[export_vars] [origination_callee_id_name]=[{DEST_PHONE}] to event
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_channel.c:1264 sofia/internal/222@{MY_PBX_DOMAIN} EXPORTING[export_vars] [call_direction]=[outbound] to event
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.819979 [DEBUG] switch_ivr_originate.c:2272 Parsing global variables
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [NOTICE] switch_channel.c:1118 New Channel sofia/external/{DEST_PHONE} [7a5a267e-5ec1-4277-a828-054213da7fcd]
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] mod_sofia.c:5102 (sofia/external/{DEST_PHONE}) State Change CS_NEW -> CS_INIT
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:585 (sofia/external/{DEST_PHONE}) Running State Change CS_INIT (Cur 2 Tot 4)
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:628 (sofia/external/{DEST_PHONE}) State INIT
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] mod_sofia.c:93 sofia/external/{DEST_PHONE} SOFIA INIT
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [INFO] sofia_glue.c:1621 sofia/external/{DEST_PHONE} sending invite call-id: (null)
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] sofia_glue.c:1624 sofia/external/{DEST_PHONE} sending invite version: 1.10.6 -release-18-1ff9d0a60e 64bit
7a5a267e-5ec1-4277-a828-054213da7fcd Local SDP:
7a5a267e-5ec1-4277-a828-054213da7fcd v=0
7a5a267e-5ec1-4277-a828-054213da7fcd o=FreeSWITCH 1620144524 1620144525 IN IP4 {MY_PBX_IP}
7a5a267e-5ec1-4277-a828-054213da7fcd s=FreeSWITCH
7a5a267e-5ec1-4277-a828-054213da7fcd c=IN IP4 {MY_PBX_IP}
7a5a267e-5ec1-4277-a828-054213da7fcd t=0 0
7a5a267e-5ec1-4277-a828-054213da7fcd m=audio 16984 RTP/AVP 8 0 101
7a5a267e-5ec1-4277-a828-054213da7fcd a=rtpmap:8 PCMA/8000
7a5a267e-5ec1-4277-a828-054213da7fcd a=rtpmap:0 PCMU/8000
7a5a267e-5ec1-4277-a828-054213da7fcd a=rtpmap:101 telephone-event/8000
7a5a267e-5ec1-4277-a828-054213da7fcd a=fmtp:101 0-16
7a5a267e-5ec1-4277-a828-054213da7fcd a=silenceSupp:eek:ff - - - -
7a5a267e-5ec1-4277-a828-054213da7fcd a=ptime:20
7a5a267e-5ec1-4277-a828-054213da7fcd a=sendrecv
7a5a267e-5ec1-4277-a828-054213da7fcd
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:40 sofia/external/{DEST_PHONE} Standard INIT
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:48 (sofia/external/{DEST_PHONE}) State Change CS_INIT -> CS_ROUTING
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:628 (sofia/external/{DEST_PHONE}) State INIT going to sleep
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:585 (sofia/external/{DEST_PHONE}) Running State Change CS_ROUTING (Cur 2 Tot 4)
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] sofia.c:7406 Channel sofia/external/{DEST_PHONE} entering state [calling][0]
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:644 (sofia/external/{DEST_PHONE}) State ROUTING
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] mod_sofia.c:154 sofia/external/{DEST_PHONE} SOFIA ROUTING
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_ivr_originate.c:67 (sofia/external/{DEST_PHONE}) State Change CS_ROUTING -> CS_CONSUME_MEDIA
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:644 (sofia/external/{DEST_PHONE}) State ROUTING going to sleep
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:585 (sofia/external/{DEST_PHONE}) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 4)
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:663 (sofia/external/{DEST_PHONE}) State CONSUME_MEDIA
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.819979 [DEBUG] switch_core_state_machine.c:663 (sofia/external/{DEST_PHONE}) State CONSUME_MEDIA going to sleep
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.879977 [DEBUG] sofia.c:7406 Channel sofia/external/{DEST_PHONE} entering state [calling][0]
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] sofia.c:7406 Channel sofia/external/{DEST_PHONE} entering state [terminated][503]
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [NOTICE] sofia.c:8641 Hangup sofia/external/{DEST_PHONE} [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:585 (sofia/external/{DEST_PHONE}) Running State Change CS_HANGUP (Cur 2 Tot 4)
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:848 (sofia/external/{DEST_PHONE}) Callstate Change DOWN -> HANGUP
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:850 (sofia/external/{DEST_PHONE}) State HANGUP
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] mod_sofia.c:453 Channel sofia/external/{DEST_PHONE} hanging up, cause: NORMAL_TEMPORARY_FAILURE
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:60 sofia/external/{DEST_PHONE} Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:850 (sofia/external/{DEST_PHONE}) State HANGUP going to sleep
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:620 (sofia/external/{DEST_PHONE}) State Change CS_HANGUP -> CS_REPORTING
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:585 (sofia/external/{DEST_PHONE}) Running State Change CS_REPORTING (Cur 2 Tot 4)
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:936 (sofia/external/{DEST_PHONE}) State REPORTING
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:174 sofia/external/{DEST_PHONE} Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:936 (sofia/external/{DEST_PHONE}) State REPORTING going to sleep
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_state_machine.c:611 (sofia/external/{DEST_PHONE}) State Change CS_REPORTING -> CS_DESTROY
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.919942 [DEBUG] switch_core_session.c:1736 Session 4 (sofia/external/{DEST_PHONE}) Locked, Waiting on external entities
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] switch_ivr_originate.c:4026 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [INFO] mod_dptools.c:3643 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [NOTICE] switch_core_state_machine.c:386 sofia/internal/222@{MY_PBX_DOMAIN} has executed the last dialplan instruction, hanging up.
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [NOTICE] switch_core_state_machine.c:388 Hangup sofia/internal/222@{MY_PBX_DOMAIN} [CS_EXECUTE] [NORMAL_CLEARING]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/222@{MY_PBX_DOMAIN}) State EXECUTE going to sleep
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/222@{MY_PBX_DOMAIN}) Running State Change CS_HANGUP (Cur 2 Tot 4)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/222@{MY_PBX_DOMAIN}) Callstate Change RINGING -> HANGUP
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/222@{MY_PBX_DOMAIN}) State HANGUP
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] mod_sofia.c:447 sofia/internal/222@{MY_PBX_DOMAIN} Overriding SIP cause 480 with 503 from the other leg
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] mod_sofia.c:453 Channel sofia/internal/222@{MY_PBX_DOMAIN} hanging up, cause: NORMAL_CLEARING
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] mod_sofia.c:598 Responding to INVITE with: 503
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:60 sofia/internal/222@{MY_PBX_DOMAIN} Standard HANGUP, cause: NORMAL_CLEARING
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/222@{MY_PBX_DOMAIN}) State HANGUP going to sleep
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/222@{MY_PBX_DOMAIN}) State Change CS_HANGUP -> CS_REPORTING
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/222@{MY_PBX_DOMAIN}) Running State Change CS_REPORTING (Cur 2 Tot 4)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/222@{MY_PBX_DOMAIN}) State REPORTING
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.939979 [NOTICE] switch_core_session.c:1754 Session 4 (sofia/external/{DEST_PHONE}) Ended
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.939979 [NOTICE] switch_core_session.c:1758 Close Channel sofia/external/{DEST_PHONE} [CS_DESTROY]
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:739 (sofia/external/{DEST_PHONE}) Running State Change CS_DESTROY (Cur 1 Tot 4)
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:749 (sofia/external/{DEST_PHONE}) State DESTROY
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.939979 [DEBUG] mod_sofia.c:364 sofia/external/{DEST_PHONE} SOFIA DESTROY
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:181 sofia/external/{DEST_PHONE} Standard DESTROY
7a5a267e-5ec1-4277-a828-054213da7fcd 2021-05-04 20:51:48.939979 [DEBUG] switch_core_state_machine.c:749 (sofia/external/{DEST_PHONE}) State DESTROY going to sleep
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [DEBUG] switch_core_state_machine.c:174 sofia/internal/222@{MY_PBX_DOMAIN} Standard REPORTING, cause: NORMAL_CLEARING
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/222@{MY_PBX_DOMAIN}) State REPORTING going to sleep
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/222@{MY_PBX_DOMAIN}) State Change CS_REPORTING -> CS_DESTROY
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [DEBUG] switch_core_session.c:1736 Session 3 (sofia/internal/222@{MY_PBX_DOMAIN}) Locked, Waiting on external entities
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [NOTICE] switch_core_session.c:1754 Session 3 (sofia/internal/222@{MY_PBX_DOMAIN}) Ended
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [NOTICE] switch_core_session.c:1758 Close Channel sofia/internal/222@{MY_PBX_DOMAIN} [CS_DESTROY]
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/222@{MY_PBX_DOMAIN}) Running State Change CS_DESTROY (Cur 0 Tot 4)
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/222@{MY_PBX_DOMAIN}) State DESTROY
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [DEBUG] mod_sofia.c:364 sofia/internal/222@{MY_PBX_DOMAIN} SOFIA DESTROY
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [DEBUG] switch_core_state_machine.c:181 sofia/internal/222@{MY_PBX_DOMAIN} Standard DESTROY
38e2618d-8bf6-401e-8acb-df4537a3b3e8 2021-05-04 20:51:48.979981 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/222@{MY_PBX_DOMAIN}) State DESTROY going to sleep
 
A

ad5ou

Active Member
Jun 12, 2018
884
197
43
I see you are using voip.ms
Double check your gateway settings to include rpid
1620163054141.png
Otherwise, a packet trace would be required to shed more light on why the remote is refusing your call.
 
J

jeffa1792

New Member
May 3, 2021
6
0
1
52
Thank you! I added rpid and followed voip.ms sample config for freeSwitch PBX. I found that I needed to include the realm as well. However, I still can't place outbound calls.

Attached is the packet dump. You may need to rename to .pcap
 

Attachments

  • sample.txt
    4.9 KB · Views: 24
J

jeffa1792

New Member
May 3, 2021
6
0
1
52
I was playing with my outbound CID and I discovered if I set the DID correctly then the calls get through. Some sort of anti-spoofing?

Problem solved!
 
Status
Not open for further replies.
Top Bottom