I need setting up voxbeam. My outbound calls are not going through as they need pid headers which are just not working. Gateway is IP authenticated. Their SBC picks up the outbound caller-name as the outbound caller-id for some reason.
I have tested every combination of options on the gateway but to no avail.
Here are my cli logs. Be advised i have replaced the entries for my domain and caller id number with dummy data.
2024-03-11 10:38:42.544948 96.93% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/1001@domain.example.com [fcdbf448-d855-4508-84d7-9baa69d26927]
2024-03-11 10:38:42.544948 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@domain.example.com) Running State Change CS_NEW (Cur 1 Tot 7528)
2024-03-11 10:38:42.544948 96.93% [INFO] sofia.c:10459 sofia/internal/1001@domain.example.com receiving invite from 15.206.18.117:5060 version: 1.10.10 -release 64bit call-id: 16031cb1c7aaa1c6853b1ceb92f80b
2024-03-11 10:38:42.544948 96.93% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 15.206.18.117:0.
2024-03-11 10:38:42.544948 96.93% [DEBUG] sofia.c:2419 detaching session fcdbf448-d855-4508-84d7-9baa69d26927
2024-03-11 10:38:42.544948 96.93% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/1001@domain.example.com) State NEW
2024-03-11 10:38:42.564956 96.93% [DEBUG] sofia.c:2532 Re-attaching to session fcdbf448-d855-4508-84d7-9baa69d26927
2024-03-11 10:38:42.584975 96.93% [INFO] sofia.c:10459 sofia/internal/1001@domain.example.com receiving invite from 15.206.18.117:5060 version: 1.10.10 -release 64bit call-id: 16031cb1c7aaa1c6853b1ceb92f80b
2024-03-11 10:38:42.584975 96.93% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 15.206.18.117:0.
2024-03-11 10:38:42.584975 96.93% [DEBUG] sofia.c:7493 Channel sofia/internal/1001@domain.example.com entering state [received][100]
2024-03-11 10:38:42.584975 96.93% [DEBUG] sofia.c:7503 Remote SDP:
v=0
o=1001 1710153522 1 IN IP4 15.206.18.117
s=SIP Call
c=IN IP4 15.206.18.117
t=0 0
m=audio 45464 RTP/AVP 8 0 18 110 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:110 opus/48000/2
a=fmtp:110 maxptime=60; maxaveragebitrate=12000;
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:60
2024-03-11 10:38:42.584975 96.93% [DEBUG] sofia.c:7906 (sofia/internal/1001@domain.example.com) State Change CS_NEW -> CS_INIT
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@domain.example.com) Running State Change CS_INIT (Cur 1 Tot 7528)
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1001@domain.example.com) State INIT
2024-03-11 10:38:42.584975 96.93% [DEBUG] mod_sofia.c:97 sofia/internal/1001@domain.example.com SOFIA INIT
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@domain.example.com Standard INIT
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@domain.example.com) State Change CS_INIT -> CS_ROUTING
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1001@domain.example.com) State INIT going to sleep
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@domain.example.com) Running State Change CS_ROUTING (Cur 1 Tot 7528)
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_channel.c:2399 (sofia/internal/1001@domain.example.com) Callstate Change DOWN -> RINGING
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1001@domain.example.com) State ROUTING
2024-03-11 10:38:42.584975 96.93% [DEBUG] mod_sofia.c:158 sofia/internal/1001@domain.example.com SOFIA ROUTING
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:230 sofia/internal/1001@domain.example.com Standard ROUTING
2024-03-11 10:38:42.584975 96.93% [INFO] mod_dialplan_xml.c:639 Processing 1001 <1001>->7168692326 in context domain.example.com
2024-03-11 10:38:42.604947 96.93% [NOTICE] switch_cpp.cpp:1465 [xml_handler] multiple key:dialplan:domain.example.com
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->user_exists] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/1001@domain.example.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(user_exists=false)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [user_exists]=[false]
Dialplan: sofia/internal/1001@domain.example.com Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(from_user_exists=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [from_user_exists]=[true]
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->caller-details] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Action set(caller_destination=${destination_number}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(caller_destination=7168692326)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [caller_destination]=[7168692326]
Dialplan: sofia/internal/1001@domain.example.com Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(caller_id_name=1001)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [caller_id_name]=[1001]
Dialplan: sofia/internal/1001@domain.example.com Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->global-variables] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [global-variables] () =~ // break=on-false
Dialplan: sofia/internal/1001@domain.example.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->domain-variables] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [domain-variables] () =~ // break=on-false
Dialplan: sofia/internal/1001@domain.example.com Action export(origination_callee_id_name=${caller_destination})
Dialplan: sofia/internal/1001@domain.example.com Action set(operator=1000) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(operator=1000)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [operator]=[1000]
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->clear_sip_auto_answer] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->is_loopback] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->call-direction] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [call-direction] ${call_direction}() =~ /^$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Action export(call_direction=local) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com export(call_direction=local)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[local]
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->user_record] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${user_record}(all) =~ /^all$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Action set(record_session=true) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_session=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_session]=[true]
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^local$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(from_user_record=all)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [from_user_record]=[all]
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_record}(all) =~ /^all$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Action set(record_session=true) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_session=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_session]=[true]
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^local$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${record_session}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com Action set(record_path=${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_path=/var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_path]=[/var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11]
Dialplan: sofia/internal/1001@domain.example.com Action set(record_name=${uuid}.${record_ext}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_name=fcdbf448-d855-4508-84d7-9baa69d26927.wav)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_name]=[fcdbf448-d855-4508-84d7-9baa69d26927.wav]
Dialplan: sofia/internal/1001@domain.example.com Action mkdir(${record_path})
Dialplan: sofia/internal/1001@domain.example.com Action set(recording_follow_transfer=true) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(recording_follow_transfer=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [recording_follow_transfer]=[true]
Dialplan: sofia/internal/1001@domain.example.com Action bind_digit_action(local,*5,api:uuid_record,${uuid} mask ${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}/${uuid}.${record_ext},both,self)
Dialplan: sofia/internal/1001@domain.example.com Action bind_digit_action(local,*6,api:uuid_record,${uuid} unmask ${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}/${uuid}.${record_ext},both,self)
Dialplan: sofia/internal/1001@domain.example.com Action set(record_append=true) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_append=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_append]=[true]
Dialplan: sofia/internal/1001@domain.example.com Action set(record_in_progress=true) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_in_progress=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_in_progress]=[true]
Dialplan: sofia/internal/1001@domain.example.com Action set(RECORD_ANSWER_REQ=true)
Dialplan: sofia/internal/1001@domain.example.com Action record_session(${record_path}/${record_name})
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->rtp_has_crypto] continue=true
Dialplan: sofia/internal/1001@domain.example.com 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
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->redial] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [redial] destination_number(7168692326) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/1001@domain.example.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->speed_dial] continue=false
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [speed_dial] destination_number(7168692326) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->default_caller_id] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [default_caller_id] ${call_direction}(local) =~ /outbound/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->user_hold_music] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->voxbeam.10d] continue=false
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [voxbeam.10d] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [voxbeam.10d] destination_number(7168692326) =~ /^(\d{10})$/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com Action export(call_direction=outbound) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com export(call_direction=outbound)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
Dialplan: sofia/internal/1001@domain.example.com Action unset(call_timeout)
Dialplan: sofia/internal/1001@domain.example.com Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1001@domain.example.com Action set(effective_caller_id_name=${outbound_caller_id_name})
Dialplan: sofia/internal/1001@domain.example.com Action set(effective_caller_id_number=${outbound_caller_id_number})
Dialplan: sofia/internal/1001@domain.example.com Action set(inherit_codec=true)
Dialplan: sofia/internal/1001@domain.example.com Action set(ignore_display_updates=true)
Dialplan: sofia/internal/1001@domain.example.com Action set(callee_id_number=7168692326)
Dialplan: sofia/internal/1001@domain.example.com Action set(continue_on_fail=1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809)
Dialplan: sofia/internal/1001@domain.example.com Action bridge(sofia/gateway/4d7ee4e2-c233-4ff9-9c85-fb586fbb3fb1/17168692326)
Dialplan: sofia/internal/1001@domain.example.com Action bridge(sofia/gateway/fd18803b-d13a-483f-a6b1-1d69e99e5041/17168692326)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/1001@domain.example.com) State Change CS_ROUTING -> CS_EXECUTE
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1001@domain.example.com) State ROUTING going to sleep
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@domain.example.com) Running State Change CS_EXECUTE (Cur 1 Tot 7528)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/1001@domain.example.com) State EXECUTE
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_sofia.c:213 sofia/internal/1001@domain.example.com SOFIA EXECUTE
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_state_machine.c:323 sofia/internal/1001@domain.example.com Standard EXECUTE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(caller_id_number=1001)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [caller_id_number]=[1001]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(RFC2822_DATE=Mon, 11 Mar 2024 10:38:42 +0000)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [RFC2822_DATE]=[Mon, 11 Mar 2024 10:38:42 +0000]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com export(origination_callee_id_name=7168692326)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [origination_callee_id_name]=[7168692326]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com mkdir(/var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:664 sofia/internal/1001@domain.example.com MKDIR: /var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11
EXECUTE [depth=0] sofia/internal/1001@domain.example.com bind_digit_action(local,*5,api:uuid_record,fcdbf448-d855-4508-84d7-9baa69d26927 mask /var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11/fcdbf448-d855-4508-84d7-9baa69d26927.wav,both,self)
2024-03-11 10:38:42.604947 96.93% [INFO] switch_ivr_async.c:221 Digit parser DPTOOLS: Setting realm to 'local'
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *5/local/0 callback: 0x7f247b643830 data: 0x7f24840a9150
2024-03-11 10:38:42.604947 96.93% [INFO] switch_ivr_async.c:221 Digit parser DPTOOLS: Setting realm to 'local'
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *5/local/0 callback: 0x7f247b643830 data: 0x7f24840a9248
EXECUTE [depth=0] sofia/internal/1001@domain.example.com bind_digit_action(local,*6,api:uuid_record,fcdbf448-d855-4508-84d7-9baa69d26927 unmask /var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11/fcdbf448-d855-4508-84d7-9baa69d26927.wav,both,self)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *6/local/0 callback: 0x7f247b643830 data: 0x7f24840a9588
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *6/local/0 callback: 0x7f247b643830 data: 0x7f24840a9688
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(RECORD_ANSWER_REQ=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [RECORD_ANSWER_REQ]=[true]
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_session.c:2791 Application record_session Requires media! pre_answering channel sofia/internal/1001@domain.example.com
2024-03-11 10:38:42.624945 96.93% [INFO] switch_core_session.c:2793 Sending early media
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5569 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5569 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G729:18:8000:60:8000:1]/[G722:9:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G729:18:8000:60:8000:1]/[PCMU:0:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G729:18:8000:60:8000:1]/[PCMA:8:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [opus:110:48000:60:0:2]/[G722:9:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [opus:110:48000:60:0:2]/[PCMU:0:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [opus:110:48000:60:0:2]/[PCMA:8:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5640 Substituting codec PCMA@60i@8000h@1c
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:3734 Set Codec sofia/internal/1001@domain.example.com PCMA/8000 60 ms 480 samples 64000 bits 1 channels
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_codec.c:111 sofia/internal/1001@domain.example.com Original read codec set to PCMA:8
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5856 sofia/internal/1001@domain.example.com Set 2833 dtmf send payload to 101 recv payload to 101
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/internal/1001@domain.example.com] 999.999.999.999 port 25944 -> 15.206.18.117 port 45464 codec: 8 ms: 60
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_rtp.c:4373 Starting timer [soft] 480 bytes per 60ms
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:8972 sofia/internal/1001@domain.example.com Set 2833 dtmf send payload to 101
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:8979 sofia/internal/1001@domain.example.com Set 2833 dtmf receive payload to 101
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:9002 sofia/internal/1001@domain.example.com Set rtp dtmf delay to 40
2024-03-11 10:38:42.624945 96.93% [NOTICE] sofia_media.c:90 Pre-Answer sofia/internal/1001@domain.example.com!
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:3585 (sofia/internal/1001@domain.example.com) Callstate Change RINGING -> EARLY
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:8641 Audio params are unchanged for sofia/internal/1001@domain.example.com.
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_sofia.c:2607 Ring SDP:
v=0
o=FreeSWITCH 1710127578 1710127579 IN IP4 999.999.999.999
s=FreeSWITCH
c=IN IP4 999.999.999.999
t=0 0
m=audio 25944 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:60
a=sendrecv
2024-03-11 10:38:42.624945 96.93% [DEBUG] sofia.c:7493 Channel sofia/internal/1001@domain.example.com entering state [early][183]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com record_session(/var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11/fcdbf448-d855-4508-84d7-9baa69d26927.wav)
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_ivr_async.c:1504 Record session sample rate: 8000 -> 8000
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media_bug.c:976 Attaching BUG to sofia/internal/1001@domain.example.com
EXECUTE [depth=0] sofia/internal/1001@domain.example.com hash(insert/domain.example.com-last_dial/1001/7168692326)
EXECUTE [depth=0] sofia/internal/1001@domain.example.com unset(call_timeout)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1816 UNSET [call_timeout]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(hangup_after_bridge=true)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(effective_caller_id_name=Ishav Aulakh)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [effective_caller_id_name]=[Ishav Aulakh]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(effective_caller_id_number=+19876543210)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [effective_caller_id_number]=[+19876543210]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(inherit_codec=true)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [inherit_codec]=[true]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(ignore_display_updates=true)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [ignore_display_updates]=[true]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(callee_id_number=7168692326)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [callee_id_number]=[7168692326]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(continue_on_fail=1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [continue_on_fail]=[1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com bridge(sofia/gateway/4d7ee4e2-c233-4ff9-9c85-fb586fbb3fb1/17168692326)
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:1288 sofia/internal/1001@domain.example.com EXPORTING[export_vars] [domain_name]=[domain.example.com] to event
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:1288 sofia/internal/1001@domain.example.com EXPORTING[export_vars] [domain_uuid]=[7af33cca-44e5-4bc5-87b4-e3f79b61ecbc] to event
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:1288 sofia/internal/1001@domain.example.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:1288 sofia/internal/1001@domain.example.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:1288 sofia/internal/1001@domain.example.com EXPORTING[export_vars] [origination_callee_id_name]=[7168692326] to event
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_ivr_originate.c:2297 Parsing global variables
2024-03-11 10:38:42.624945 96.93% [NOTICE] switch_channel.c:1142 New Channel sofia/external/17168692326 [ef246d1b-c9e6-4bdd-9727-3743027e6f82]
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_sofia.c:5110 (sofia/external/17168692326) State Change CS_NEW -> CS_INIT
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/external/17168692326) Running State Change CS_INIT (Cur 2 Tot 7529)
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:624 (sofia/external/17168692326) State INIT
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_sofia.c:97 sofia/external/17168692326 SOFIA INIT
2024-03-11 10:38:42.624945 96.93% [INFO] sofia_glue.c:1659 sofia/external/17168692326 sending invite call-id: (null)
2024-03-11 10:38:42.624945 96.93% [DEBUG] sofia_glue.c:1662 sofia/external/17168692326 sending invite version: 1.10.10 -release 64bit
Local SDP:
v=0
o=FreeSWITCH 1710128222 1710128223 IN IP4 999.999.999.999
s=FreeSWITCH
c=IN IP4 999.999.999.999
t=0 0
m=audio 25300 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp
ff - - - -
a=ptime:60
a=sendrecv
m=audio 25300 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSuppff - - - -
a=ptime:20
a=sendrecv
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:40 sofia/external/17168692326 Standard INIT
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:48 (sofia/external/17168692326) State Change CS_INIT -> CS_ROUTING
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:624 (sofia/external/17168692326) State INIT going to sleep
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/external/17168692326) Running State Change CS_ROUTING (Cur 2 Tot 7529)
2024-03-11 10:38:42.624945 96.93% [DEBUG] sofia.c:7493 Channel sofia/external/17168692326 entering state [calling][0]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:640 (sofia/external/17168692326) State ROUTING
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_sofia.c:158 sofia/external/17168692326 SOFIA ROUTING
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_ivr_originate.c:67 (sofia/external/17168692326) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:640 (sofia/external/17168692326) State ROUTING going to sleep
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/external/17168692326) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 7529)
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:659 (sofia/external/17168692326) State CONSUME_MEDIA
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:659 (sofia/external/17168692326) State CONSUME_MEDIA going to sleep
2024-03-11 10:38:43.044961 96.93% [DEBUG] sofia.c:7493 Channel sofia/external/17168692326 entering state [terminated][403]
2024-03-11 10:38:43.044961 96.93% [NOTICE] sofia.c:8735 Hangup sofia/external/17168692326 [CS_CONSUME_MEDIA] [CALL_REJECTED]
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/external/17168692326) Running State Change CS_HANGUP (Cur 2 Tot 7529)
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:844 (sofia/external/17168692326) Callstate Change DOWN -> HANGUP
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:846 (sofia/external/17168692326) State HANGUP
2024-03-11 10:38:43.044961 96.93% [DEBUG] mod_sofia.c:469 Channel sofia/external/17168692326 hanging up, cause: CALL_REJECTED
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:59 sofia/external/17168692326 Standard HANGUP, cause: CALL_REJECTED
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:846 (sofia/external/17168692326) State HANGUP going to sleep
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:616 (sofia/external/17168692326) State Change CS_HANGUP -> CS_REPORTING
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/external/17168692326) Running State Change CS_REPORTING (Cur 2 Tot 7529)
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:932 (sofia/external/17168692326) State REPORTING
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:168 sofia/external/17168692326 Standard REPORTING, cause: CALL_REJECTED
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:932 (sofia/external/17168692326) State REPORTING going to sleep
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:607 (sofia/external/17168692326) State Change CS_REPORTING -> CS_DESTROY
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_session.c:1744 Session 7529 (sofia/external/17168692326) Locked, Waiting on external entities
2024-03-11 10:38:43.104949 96.93% [DEBUG] switch_ivr_originate.c:4052 Originate Resulted in Error Cause: 21 [CALL_REJECTED]
2024-03-11 10:38:43.104949 96.93% [INFO] mod_dptools.c:3635 Originate Failed. Cause: CALL_REJECTED
2024-03-11 10:38:43.104949 96.93% [DEBUG] switch_channel.c:4943 Continue on fail [1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809]: Cause: CALL_REJECTED
I did send an email to voxbeam. Here is the reply i got.
Dear Customer,
The account is active, however there are issues with your configuration, your From: is INVALID From: "Laura Smith" <sip:globe@sbc.voxbeam.com> this MUST contain a valid number in +E164 format which can be called back to a live answer, globe is not a number & hence CANNOT be called back. You MUST also provide a P-Asserted-Identity: header which is currently missing in +E164 format which can be called back to a live answer
There is also the matter that you have not provided us with your FCC RMD number which is a legal requirement before you can call CA/US if as you say you are already sending calls via Telnyx then providing the number should not be an issue, or you can register at https://fccprod.servicenowservices.com/rmd?id=rmd_welcome
Regards
Alan.
I have tested every combination of options on the gateway but to no avail.
Here are my cli logs. Be advised i have replaced the entries for my domain and caller id number with dummy data.
2024-03-11 10:38:42.544948 96.93% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/1001@domain.example.com [fcdbf448-d855-4508-84d7-9baa69d26927]
2024-03-11 10:38:42.544948 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@domain.example.com) Running State Change CS_NEW (Cur 1 Tot 7528)
2024-03-11 10:38:42.544948 96.93% [INFO] sofia.c:10459 sofia/internal/1001@domain.example.com receiving invite from 15.206.18.117:5060 version: 1.10.10 -release 64bit call-id: 16031cb1c7aaa1c6853b1ceb92f80b
2024-03-11 10:38:42.544948 96.93% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 15.206.18.117:0.
2024-03-11 10:38:42.544948 96.93% [DEBUG] sofia.c:2419 detaching session fcdbf448-d855-4508-84d7-9baa69d26927
2024-03-11 10:38:42.544948 96.93% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/1001@domain.example.com) State NEW
2024-03-11 10:38:42.564956 96.93% [DEBUG] sofia.c:2532 Re-attaching to session fcdbf448-d855-4508-84d7-9baa69d26927
2024-03-11 10:38:42.584975 96.93% [INFO] sofia.c:10459 sofia/internal/1001@domain.example.com receiving invite from 15.206.18.117:5060 version: 1.10.10 -release 64bit call-id: 16031cb1c7aaa1c6853b1ceb92f80b
2024-03-11 10:38:42.584975 96.93% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 15.206.18.117:0.
2024-03-11 10:38:42.584975 96.93% [DEBUG] sofia.c:7493 Channel sofia/internal/1001@domain.example.com entering state [received][100]
2024-03-11 10:38:42.584975 96.93% [DEBUG] sofia.c:7503 Remote SDP:
v=0
o=1001 1710153522 1 IN IP4 15.206.18.117
s=SIP Call
c=IN IP4 15.206.18.117
t=0 0
m=audio 45464 RTP/AVP 8 0 18 110 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:110 opus/48000/2
a=fmtp:110 maxptime=60; maxaveragebitrate=12000;
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:60
2024-03-11 10:38:42.584975 96.93% [DEBUG] sofia.c:7906 (sofia/internal/1001@domain.example.com) State Change CS_NEW -> CS_INIT
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@domain.example.com) Running State Change CS_INIT (Cur 1 Tot 7528)
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1001@domain.example.com) State INIT
2024-03-11 10:38:42.584975 96.93% [DEBUG] mod_sofia.c:97 sofia/internal/1001@domain.example.com SOFIA INIT
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@domain.example.com Standard INIT
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@domain.example.com) State Change CS_INIT -> CS_ROUTING
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1001@domain.example.com) State INIT going to sleep
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@domain.example.com) Running State Change CS_ROUTING (Cur 1 Tot 7528)
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_channel.c:2399 (sofia/internal/1001@domain.example.com) Callstate Change DOWN -> RINGING
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1001@domain.example.com) State ROUTING
2024-03-11 10:38:42.584975 96.93% [DEBUG] mod_sofia.c:158 sofia/internal/1001@domain.example.com SOFIA ROUTING
2024-03-11 10:38:42.584975 96.93% [DEBUG] switch_core_state_machine.c:230 sofia/internal/1001@domain.example.com Standard ROUTING
2024-03-11 10:38:42.584975 96.93% [INFO] mod_dialplan_xml.c:639 Processing 1001 <1001>->7168692326 in context domain.example.com
2024-03-11 10:38:42.604947 96.93% [NOTICE] switch_cpp.cpp:1465 [xml_handler] multiple key:dialplan:domain.example.com
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->user_exists] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/1001@domain.example.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(user_exists=false)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [user_exists]=[false]
Dialplan: sofia/internal/1001@domain.example.com Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(from_user_exists=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [from_user_exists]=[true]
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->caller-details] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Action set(caller_destination=${destination_number}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(caller_destination=7168692326)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [caller_destination]=[7168692326]
Dialplan: sofia/internal/1001@domain.example.com Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(caller_id_name=1001)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [caller_id_name]=[1001]
Dialplan: sofia/internal/1001@domain.example.com Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->global-variables] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [global-variables] () =~ // break=on-false
Dialplan: sofia/internal/1001@domain.example.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->domain-variables] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [domain-variables] () =~ // break=on-false
Dialplan: sofia/internal/1001@domain.example.com Action export(origination_callee_id_name=${caller_destination})
Dialplan: sofia/internal/1001@domain.example.com Action set(operator=1000) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(operator=1000)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [operator]=[1000]
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->clear_sip_auto_answer] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->is_loopback] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->call-direction] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [call-direction] ${call_direction}() =~ /^$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Action export(call_direction=local) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com export(call_direction=local)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[local]
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->user_record] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${user_record}(all) =~ /^all$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Action set(record_session=true) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_session=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_session]=[true]
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^local$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(from_user_record=all)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [from_user_record]=[all]
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_record}(all) =~ /^all$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Action set(record_session=true) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_session=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_session]=[true]
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^local$/ break=never
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [user_record] ${record_session}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com Action set(record_path=${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_path=/var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_path]=[/var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11]
Dialplan: sofia/internal/1001@domain.example.com Action set(record_name=${uuid}.${record_ext}) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_name=fcdbf448-d855-4508-84d7-9baa69d26927.wav)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_name]=[fcdbf448-d855-4508-84d7-9baa69d26927.wav]
Dialplan: sofia/internal/1001@domain.example.com Action mkdir(${record_path})
Dialplan: sofia/internal/1001@domain.example.com Action set(recording_follow_transfer=true) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(recording_follow_transfer=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [recording_follow_transfer]=[true]
Dialplan: sofia/internal/1001@domain.example.com Action bind_digit_action(local,*5,api:uuid_record,${uuid} mask ${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}/${uuid}.${record_ext},both,self)
Dialplan: sofia/internal/1001@domain.example.com Action bind_digit_action(local,*6,api:uuid_record,${uuid} unmask ${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}/${uuid}.${record_ext},both,self)
Dialplan: sofia/internal/1001@domain.example.com Action set(record_append=true) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_append=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_append]=[true]
Dialplan: sofia/internal/1001@domain.example.com Action set(record_in_progress=true) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(record_in_progress=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [record_in_progress]=[true]
Dialplan: sofia/internal/1001@domain.example.com Action set(RECORD_ANSWER_REQ=true)
Dialplan: sofia/internal/1001@domain.example.com Action record_session(${record_path}/${record_name})
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->rtp_has_crypto] continue=true
Dialplan: sofia/internal/1001@domain.example.com 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
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->redial] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [redial] destination_number(7168692326) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/1001@domain.example.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->speed_dial] continue=false
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [speed_dial] destination_number(7168692326) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->default_caller_id] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [default_caller_id] ${call_direction}(local) =~ /outbound/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->user_hold_music] continue=true
Dialplan: sofia/internal/1001@domain.example.com Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com parsing [domain.example.com->voxbeam.10d] continue=false
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [voxbeam.10d] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com Regex (PASS) [voxbeam.10d] destination_number(7168692326) =~ /^(\d{10})$/ break=on-false
Dialplan: sofia/internal/1001@domain.example.com Action export(call_direction=outbound) INLINE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com export(call_direction=outbound)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
Dialplan: sofia/internal/1001@domain.example.com Action unset(call_timeout)
Dialplan: sofia/internal/1001@domain.example.com Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1001@domain.example.com Action set(effective_caller_id_name=${outbound_caller_id_name})
Dialplan: sofia/internal/1001@domain.example.com Action set(effective_caller_id_number=${outbound_caller_id_number})
Dialplan: sofia/internal/1001@domain.example.com Action set(inherit_codec=true)
Dialplan: sofia/internal/1001@domain.example.com Action set(ignore_display_updates=true)
Dialplan: sofia/internal/1001@domain.example.com Action set(callee_id_number=7168692326)
Dialplan: sofia/internal/1001@domain.example.com Action set(continue_on_fail=1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809)
Dialplan: sofia/internal/1001@domain.example.com Action bridge(sofia/gateway/4d7ee4e2-c233-4ff9-9c85-fb586fbb3fb1/17168692326)
Dialplan: sofia/internal/1001@domain.example.com Action bridge(sofia/gateway/fd18803b-d13a-483f-a6b1-1d69e99e5041/17168692326)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/1001@domain.example.com) State Change CS_ROUTING -> CS_EXECUTE
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1001@domain.example.com) State ROUTING going to sleep
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1001@domain.example.com) Running State Change CS_EXECUTE (Cur 1 Tot 7528)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/1001@domain.example.com) State EXECUTE
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_sofia.c:213 sofia/internal/1001@domain.example.com SOFIA EXECUTE
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_state_machine.c:323 sofia/internal/1001@domain.example.com Standard EXECUTE
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(caller_id_number=1001)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [caller_id_number]=[1001]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(RFC2822_DATE=Mon, 11 Mar 2024 10:38:42 +0000)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [RFC2822_DATE]=[Mon, 11 Mar 2024 10:38:42 +0000]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com export(origination_callee_id_name=7168692326)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [origination_callee_id_name]=[7168692326]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com mkdir(/var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:664 sofia/internal/1001@domain.example.com MKDIR: /var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11
EXECUTE [depth=0] sofia/internal/1001@domain.example.com bind_digit_action(local,*5,api:uuid_record,fcdbf448-d855-4508-84d7-9baa69d26927 mask /var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11/fcdbf448-d855-4508-84d7-9baa69d26927.wav,both,self)
2024-03-11 10:38:42.604947 96.93% [INFO] switch_ivr_async.c:221 Digit parser DPTOOLS: Setting realm to 'local'
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *5/local/0 callback: 0x7f247b643830 data: 0x7f24840a9150
2024-03-11 10:38:42.604947 96.93% [INFO] switch_ivr_async.c:221 Digit parser DPTOOLS: Setting realm to 'local'
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *5/local/0 callback: 0x7f247b643830 data: 0x7f24840a9248
EXECUTE [depth=0] sofia/internal/1001@domain.example.com bind_digit_action(local,*6,api:uuid_record,fcdbf448-d855-4508-84d7-9baa69d26927 unmask /var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11/fcdbf448-d855-4508-84d7-9baa69d26927.wav,both,self)
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *6/local/0 callback: 0x7f247b643830 data: 0x7f24840a9588
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *6/local/0 callback: 0x7f247b643830 data: 0x7f24840a9688
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(RECORD_ANSWER_REQ=true)
2024-03-11 10:38:42.604947 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [RECORD_ANSWER_REQ]=[true]
2024-03-11 10:38:42.604947 96.93% [DEBUG] switch_core_session.c:2791 Application record_session Requires media! pre_answering channel sofia/internal/1001@domain.example.com
2024-03-11 10:38:42.624945 96.93% [INFO] switch_core_session.c:2793 Sending early media
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5569 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5569 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G729:18:8000:60:8000:1]/[G722:9:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G729:18:8000:60:8000:1]/[PCMU:0:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G729:18:8000:60:8000:1]/[PCMA:8:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [opus:110:48000:60:0:2]/[G722:9:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [opus:110:48000:60:0:2]/[PCMU:0:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [opus:110:48000:60:0:2]/[PCMA:8:8000:20:64000:1]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5640 Substituting codec PCMA@60i@8000h@1c
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:3734 Set Codec sofia/internal/1001@domain.example.com PCMA/8000 60 ms 480 samples 64000 bits 1 channels
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_codec.c:111 sofia/internal/1001@domain.example.com Original read codec set to PCMA:8
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:5856 sofia/internal/1001@domain.example.com Set 2833 dtmf send payload to 101 recv payload to 101
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/internal/1001@domain.example.com] 999.999.999.999 port 25944 -> 15.206.18.117 port 45464 codec: 8 ms: 60
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_rtp.c:4373 Starting timer [soft] 480 bytes per 60ms
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:8972 sofia/internal/1001@domain.example.com Set 2833 dtmf send payload to 101
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:8979 sofia/internal/1001@domain.example.com Set 2833 dtmf receive payload to 101
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:9002 sofia/internal/1001@domain.example.com Set rtp dtmf delay to 40
2024-03-11 10:38:42.624945 96.93% [NOTICE] sofia_media.c:90 Pre-Answer sofia/internal/1001@domain.example.com!
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:3585 (sofia/internal/1001@domain.example.com) Callstate Change RINGING -> EARLY
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media.c:8641 Audio params are unchanged for sofia/internal/1001@domain.example.com.
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_sofia.c:2607 Ring SDP:
v=0
o=FreeSWITCH 1710127578 1710127579 IN IP4 999.999.999.999
s=FreeSWITCH
c=IN IP4 999.999.999.999
t=0 0
m=audio 25944 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:60
a=sendrecv
2024-03-11 10:38:42.624945 96.93% [DEBUG] sofia.c:7493 Channel sofia/internal/1001@domain.example.com entering state [early][183]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com record_session(/var/lib/freeswitch/recordings/domain.example.com/archive/2024/Mar/11/fcdbf448-d855-4508-84d7-9baa69d26927.wav)
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_ivr_async.c:1504 Record session sample rate: 8000 -> 8000
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_media_bug.c:976 Attaching BUG to sofia/internal/1001@domain.example.com
EXECUTE [depth=0] sofia/internal/1001@domain.example.com hash(insert/domain.example.com-last_dial/1001/7168692326)
EXECUTE [depth=0] sofia/internal/1001@domain.example.com unset(call_timeout)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1816 UNSET [call_timeout]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(hangup_after_bridge=true)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(effective_caller_id_name=Ishav Aulakh)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [effective_caller_id_name]=[Ishav Aulakh]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(effective_caller_id_number=+19876543210)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [effective_caller_id_number]=[+19876543210]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(inherit_codec=true)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [inherit_codec]=[true]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(ignore_display_updates=true)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [ignore_display_updates]=[true]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(callee_id_number=7168692326)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [callee_id_number]=[7168692326]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com set(continue_on_fail=1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809)
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1001@domain.example.com [continue_on_fail]=[1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809]
EXECUTE [depth=0] sofia/internal/1001@domain.example.com bridge(sofia/gateway/4d7ee4e2-c233-4ff9-9c85-fb586fbb3fb1/17168692326)
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:1288 sofia/internal/1001@domain.example.com EXPORTING[export_vars] [domain_name]=[domain.example.com] to event
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:1288 sofia/internal/1001@domain.example.com EXPORTING[export_vars] [domain_uuid]=[7af33cca-44e5-4bc5-87b4-e3f79b61ecbc] to event
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:1288 sofia/internal/1001@domain.example.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:1288 sofia/internal/1001@domain.example.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_channel.c:1288 sofia/internal/1001@domain.example.com EXPORTING[export_vars] [origination_callee_id_name]=[7168692326] to event
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_ivr_originate.c:2297 Parsing global variables
2024-03-11 10:38:42.624945 96.93% [NOTICE] switch_channel.c:1142 New Channel sofia/external/17168692326 [ef246d1b-c9e6-4bdd-9727-3743027e6f82]
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_sofia.c:5110 (sofia/external/17168692326) State Change CS_NEW -> CS_INIT
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/external/17168692326) Running State Change CS_INIT (Cur 2 Tot 7529)
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:624 (sofia/external/17168692326) State INIT
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_sofia.c:97 sofia/external/17168692326 SOFIA INIT
2024-03-11 10:38:42.624945 96.93% [INFO] sofia_glue.c:1659 sofia/external/17168692326 sending invite call-id: (null)
2024-03-11 10:38:42.624945 96.93% [DEBUG] sofia_glue.c:1662 sofia/external/17168692326 sending invite version: 1.10.10 -release 64bit
Local SDP:
v=0
o=FreeSWITCH 1710128222 1710128223 IN IP4 999.999.999.999
s=FreeSWITCH
c=IN IP4 999.999.999.999
t=0 0
m=audio 25300 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp
ff - - - -a=ptime:60
a=sendrecv
m=audio 25300 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=silenceSupp
ff - - - -a=ptime:20
a=sendrecv
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:40 sofia/external/17168692326 Standard INIT
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:48 (sofia/external/17168692326) State Change CS_INIT -> CS_ROUTING
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:624 (sofia/external/17168692326) State INIT going to sleep
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/external/17168692326) Running State Change CS_ROUTING (Cur 2 Tot 7529)
2024-03-11 10:38:42.624945 96.93% [DEBUG] sofia.c:7493 Channel sofia/external/17168692326 entering state [calling][0]
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:640 (sofia/external/17168692326) State ROUTING
2024-03-11 10:38:42.624945 96.93% [DEBUG] mod_sofia.c:158 sofia/external/17168692326 SOFIA ROUTING
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_ivr_originate.c:67 (sofia/external/17168692326) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:640 (sofia/external/17168692326) State ROUTING going to sleep
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/external/17168692326) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 7529)
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:659 (sofia/external/17168692326) State CONSUME_MEDIA
2024-03-11 10:38:42.624945 96.93% [DEBUG] switch_core_state_machine.c:659 (sofia/external/17168692326) State CONSUME_MEDIA going to sleep
2024-03-11 10:38:43.044961 96.93% [DEBUG] sofia.c:7493 Channel sofia/external/17168692326 entering state [terminated][403]
2024-03-11 10:38:43.044961 96.93% [NOTICE] sofia.c:8735 Hangup sofia/external/17168692326 [CS_CONSUME_MEDIA] [CALL_REJECTED]
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/external/17168692326) Running State Change CS_HANGUP (Cur 2 Tot 7529)
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:844 (sofia/external/17168692326) Callstate Change DOWN -> HANGUP
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:846 (sofia/external/17168692326) State HANGUP
2024-03-11 10:38:43.044961 96.93% [DEBUG] mod_sofia.c:469 Channel sofia/external/17168692326 hanging up, cause: CALL_REJECTED
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:59 sofia/external/17168692326 Standard HANGUP, cause: CALL_REJECTED
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:846 (sofia/external/17168692326) State HANGUP going to sleep
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:616 (sofia/external/17168692326) State Change CS_HANGUP -> CS_REPORTING
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:581 (sofia/external/17168692326) Running State Change CS_REPORTING (Cur 2 Tot 7529)
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:932 (sofia/external/17168692326) State REPORTING
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:168 sofia/external/17168692326 Standard REPORTING, cause: CALL_REJECTED
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:932 (sofia/external/17168692326) State REPORTING going to sleep
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_state_machine.c:607 (sofia/external/17168692326) State Change CS_REPORTING -> CS_DESTROY
2024-03-11 10:38:43.044961 96.93% [DEBUG] switch_core_session.c:1744 Session 7529 (sofia/external/17168692326) Locked, Waiting on external entities
2024-03-11 10:38:43.104949 96.93% [DEBUG] switch_ivr_originate.c:4052 Originate Resulted in Error Cause: 21 [CALL_REJECTED]
2024-03-11 10:38:43.104949 96.93% [INFO] mod_dptools.c:3635 Originate Failed. Cause: CALL_REJECTED
2024-03-11 10:38:43.104949 96.93% [DEBUG] switch_channel.c:4943 Continue on fail [1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809]: Cause: CALL_REJECTED
I did send an email to voxbeam. Here is the reply i got.
Dear Customer,
The account is active, however there are issues with your configuration, your From: is INVALID From: "Laura Smith" <sip:globe@sbc.voxbeam.com> this MUST contain a valid number in +E164 format which can be called back to a live answer, globe is not a number & hence CANNOT be called back. You MUST also provide a P-Asserted-Identity: header which is currently missing in +E164 format which can be called back to a live answer
There is also the matter that you have not provided us with your FCC RMD number which is a legal requirement before you can call CA/US if as you say you are already sending calls via Telnyx then providing the number should not be an issue, or you can register at https://fccprod.servicenowservices.com/rmd?id=rmd_welcome
Regards
Alan.
