Hi All,
I've recently started using Fusion PBX and everything so far has been great and working well. The only thing that has not worked as expected is the intercept and group intercept functions as they're called.
When I try to intercept a call going to an extension I'll dial **1545 as an example and it will just terminate the call on my end. Please see below on the Freeswitch CLI:
We're running on a postgresql but it looks like the script references Database.new(switch) which I believe is a sqlite DB. I've tried removing reference the DB in the script and elsewhere but the result is the same. All the other lua scripts that do not reference Database.new(switch) work fine.
2024-02-13 09:53:56.019508 94.07% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/1525@sip.example.com [d591ae7c-9f69-4222-9a77-720b416dab49]
2024-02-13 09:53:56.019508 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_NEW (Cur 5 Tot 3970)
2024-02-13 09:53:56.019508 94.07% [INFO] sofia.c:10459 sofia/internal/1525@sip.example.com receiving invite from 10.0.0.158:60808 version: 1.10.10 -release-24-4cb05e7f4a 64bit call-id: 88c43b8bc04b4b928bcafbb376649eaa
2024-02-13 09:53:56.019508 94.07% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 10.0.0.158:0.
2024-02-13 09:53:56.019508 94.07% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/1525@sip.example.com) State NEW
2024-02-13 09:53:56.019508 94.07% [DEBUG] sofia.c:2419 detaching session d591ae7c-9f69-4222-9a77-720b416dab49
2024-02-13 09:53:56.059105 94.07% [DEBUG] sofia.c:2532 Re-attaching to session d591ae7c-9f69-4222-9a77-720b416dab49
2024-02-13 09:53:56.079097 94.07% [INFO] sofia.c:10459 sofia/internal/1525@sip.example.com receiving invite from 10.0.0.158:60808 version: 1.10.10 -release-24-4cb05e7f4a 64bit call-id: 88c43b8bc04b4b928bcafbb376649eaa
2024-02-13 09:53:56.079097 94.07% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 10.0.0.158:0.
2024-02-13 09:53:56.079097 94.07% [DEBUG] sofia.c:7493 Channel sofia/internal/1525@sip.example.com entering state [received][100]
2024-02-13 09:53:56.079097 94.07% [DEBUG] sofia.c:7503 Remote SDP:
v=0
o=- 3916806835 3916806835 IN IP4 10.0.0.158
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4006 RTP/AVP 18 8 0 101
c=IN IP4 10.0.0.158
b=TIAS:64000
a=rtpmap:18 G729/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp:4007 IN IP4 10.0.0.158
a=ssrc:1200249510 cname:42672dce726a4b0f
2024-02-13 09:53:56.079097 94.07% [DEBUG] sofia.c:7906 (sofia/internal/1525@sip.example.com) State Change CS_NEW -> CS_INIT
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_INIT (Cur 5 Tot 3970)
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1525@sip.example.com) State INIT
2024-02-13 09:53:56.079097 94.07% [DEBUG] mod_sofia.c:97 sofia/internal/1525@sip.example.com SOFIA INIT
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:40 sofia/internal/1525@sip.example.com Standard INIT
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1525@sip.example.com) State Change CS_INIT -> CS_ROUTING
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1525@sip.example.com) State INIT going to sleep
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_ROUTING (Cur 5 Tot 3970)
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_channel.c:2399 (sofia/internal/1525@sip.example.com) Callstate Change DOWN -> RINGING
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1525@sip.example.com) State ROUTING
2024-02-13 09:53:56.079097 94.07% [DEBUG] mod_sofia.c:158 sofia/internal/1525@sip.example.com SOFIA ROUTING
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:230 sofia/internal/1525@sip.example.com Standard ROUTING
2024-02-13 09:53:56.079097 94.07% [INFO] mod_dialplan_xml.c:639 Processing Joe Blogs <1525>->**1545 in context sip.example.com
2024-02-13 09:53:56.099085 94.07% [NOTICE] switch_cpp.cpp:1465 [xml_handler] multiple key:dialplan:sip.example.com
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->user_exists] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/1525@sip.example.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(user_exists=false)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [user_exists]=[false]
Dialplan: sofia/internal/1525@sip.example.com Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(from_user_exists=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [from_user_exists]=[true]
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->caller-details] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Action set(caller_destination=${destination_number}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(caller_destination=**1545)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [caller_destination]=[**1545]
Dialplan: sofia/internal/1525@sip.example.com Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(caller_id_name=1525)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [caller_id_name]=[1525]
Dialplan: sofia/internal/1525@sip.example.com Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->global-variables] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [global-variables] () =~ // break=on-false
Dialplan: sofia/internal/1525@sip.example.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->domain-variables] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [domain-variables] () =~ // break=on-false
Dialplan: sofia/internal/1525@sip.example.com Action export(origination_callee_id_name=${caller_destination})
Dialplan: sofia/internal/1525@sip.example.com Action set(operator=1000) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(operator=1000)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [operator]=[1000]
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->clear_sip_auto_answer] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->is_loopback] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->call-direction] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [call-direction] ${call_direction}() =~ /^$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Action export(call_direction=local) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com export(call_direction=local)
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[local]
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->user_record] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${user_record}(all) =~ /^all$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Action set(record_session=true) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_session=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_session]=[true]
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^local$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(from_user_record=all)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [from_user_record]=[all]
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_record}(all) =~ /^all$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Action set(record_session=true) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_session=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_session]=[true]
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^local$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${record_session}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com Action set(record_path=${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_path=/var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_path]=[/var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13]
Dialplan: sofia/internal/1525@sip.example.com Action set(record_name=${uuid}.${record_ext}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_name=d591ae7c-9f69-4222-9a77-720b416dab49.wav)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_name]=[d591ae7c-9f69-4222-9a77-720b416dab49.wav]
Dialplan: sofia/internal/1525@sip.example.com Action mkdir(${record_path})
Dialplan: sofia/internal/1525@sip.example.com Action set(recording_follow_transfer=true) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(recording_follow_transfer=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [recording_follow_transfer]=[true]
Dialplan: sofia/internal/1525@sip.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/1525@sip.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/1525@sip.example.com Action set(record_append=true) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_append=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_append]=[true]
Dialplan: sofia/internal/1525@sip.example.com Action set(record_in_progress=true) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_in_progress=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_in_progress]=[true]
Dialplan: sofia/internal/1525@sip.example.com Action set(RECORD_ANSWER_REQ=true)
Dialplan: sofia/internal/1525@sip.example.com Action record_session(${record_path}/${record_name})
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->rtp_has_crypto] continue=true
Dialplan: sofia/internal/1525@sip.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/1525@sip.example.com parsing [sip.example.com->redial] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [redial] destination_number(**1545) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/1525@sip.example.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->speed_dial] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [speed_dial] destination_number(**1545) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->user_hold_music] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->default_caller_id] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [default_caller_id] ${call_direction}(local) =~ /outbound/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Example.0d10] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [Example.0d10] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Example.0d10] destination_number(**1545) =~ /^(?:\+?0)?(\d{10})$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Example.27d11] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [Example.27d11] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Example.27d11] destination_number(**1545) =~ /^(?:\+?27)?(\d{11})$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Helpdesk] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Helpdesk] destination_number(**1545) =~ /^9980$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Fusion IVR] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Fusion IVR] destination_number(**1545) =~ /^9999$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Joe Blogs RG to Cell test] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Joe Blogs RG to Cell test] destination_number(**1545) =~ /^9984$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Gate] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Gate] destination_number(**1545) =~ /^9983$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Accounts] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Accounts] destination_number(**1545) =~ /^9982$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Sales] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Sales] destination_number(**1545) =~ /^9981$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->agent_status] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [agent_status] destination_number(**1545) =~ /^\*22$/ break=on-true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [agent_status] destination_number(**1545) =~ /^(?:agent\+|\*22)(.+)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->agent_status_id] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [agent_status_id] destination_number(**1545) =~ /^\*23$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->agent-status-break] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [agent-status-break] destination_number(**1545) =~ /^\*24$/ break=on-true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [agent-status-break] destination_number(**1545) =~ /^(?:agent\+|\*24)(.+)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->group-intercept] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [group-intercept] destination_number(**1545) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->page-extension] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [page-extension] destination_number(**1545) =~ /^\*8(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->eavesdrop] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [eavesdrop] destination_number(**1545) =~ /^\*33(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->call_privacy] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [call_privacy] destination_number(**1545) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->call_return] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [call_return] destination_number(**1545) =~ /^\*69$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->number_queue] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [number_queue] destination_number(**1545) =~ /^\*800(.*)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->intercept-ext-polycom] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [intercept-ext-polycom] destination_number(**1545) =~ /^\*97(\d+)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->intercept-ext] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [intercept-ext] destination_number(**1545) =~ /^\*\*(\d+)$/ break=on-true
Dialplan: sofia/internal/1525@sip.example.com Action answer()
Dialplan: sofia/internal/1525@sip.example.com Action lua(intercept.lua 1545)
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/1525@sip.example.com) State Change CS_ROUTING -> CS_EXECUTE
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1525@sip.example.com) State ROUTING going to sleep
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_EXECUTE (Cur 5 Tot 3970)
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/1525@sip.example.com) State EXECUTE
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_sofia.c:213 sofia/internal/1525@sip.example.com SOFIA EXECUTE
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_state_machine.c:323 sofia/internal/1525@sip.example.com Standard EXECUTE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(caller_id_number=1525)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [caller_id_number]=[1525]
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(RFC2822_DATE=Tue, 13 Feb 2024 09:53:56 +0200)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [RFC2822_DATE]=[Tue, 13 Feb 2024 09:53:56 +0200]
EXECUTE [depth=0] sofia/internal/1525@sip.example.com export(origination_callee_id_name=**1545)
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [origination_callee_id_name]=[**1545]
EXECUTE [depth=0] sofia/internal/1525@sip.example.com mkdir(/var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:664 sofia/internal/1525@sip.example.com MKDIR: /var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13
EXECUTE [depth=0] sofia/internal/1525@sip.example.com bind_digit_action(local,*5,api:uuid_record,d591ae7c-9f69-4222-9a77-720b416dab49 mask /var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13/d591ae7c-9f69-4222-9a77-720b416dab49.wav,both,self)
2024-02-13 09:53:56.099085 94.07% [INFO] switch_ivr_async.c:221 Digit parser DPTOOLS: Setting realm to 'local'
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *5/local/0 callback: 0x7fb98390e940 data: 0x7fb9a0150490
2024-02-13 09:53:56.099085 94.07% [INFO] switch_ivr_async.c:221 Digit parser DPTOOLS: Setting realm to 'local'
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *5/local/0 callback: 0x7fb98390e940 data: 0x7fb9a0150590
EXECUTE [depth=0] sofia/internal/1525@sip.example.com bind_digit_action(local,*6,api:uuid_record,d591ae7c-9f69-4222-9a77-720b416dab49 unmask /var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13/d591ae7c-9f69-4222-9a77-720b416dab49.wav,both,self)
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *6/local/0 callback: 0x7fb98390e940 data: 0x7fb9a01508e8
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *6/local/0 callback: 0x7fb98390e940 data: 0x7fb9a01509e8
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(RECORD_ANSWER_REQ=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [RECORD_ANSWER_REQ]=[true]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_session.c:2791 Application record_session Requires media! pre_answering channel sofia/internal/1525@sip.example.com
2024-02-13 09:53:56.099085 94.07% [INFO] switch_core_session.c:2793 Sending early media
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:3734 Set Codec sofia/internal/1525@sip.example.com G729/8000 20 ms 160 samples 8000 bits 1 channels
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_codec.c:111 sofia/internal/1525@sip.example.com Original read codec set to G729:18
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5856 sofia/internal/1525@sip.example.com Set 2833 dtmf send payload to 101 recv payload to 101
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/internal/1525@sip.example.com] 10.249.0.20 port 17580 -> 10.0.0.158 port 4006 codec: 18 ms: 20
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_rtp.c:4373 Starting timer [soft] 160 bytes per 20ms
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:8880 Activating RTCP PORT 4007
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_rtp.c:4705 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 4007
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_rtp.c:2533 Setting RTCP remote addr to 10.0.0.158:4007 2
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:8972 sofia/internal/1525@sip.example.com Set 2833 dtmf send payload to 101
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:8979 sofia/internal/1525@sip.example.com Set 2833 dtmf receive payload to 101
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:9002 sofia/internal/1525@sip.example.com Set rtp dtmf delay to 40
2024-02-13 09:53:56.099085 94.07% [NOTICE] sofia_media.c:90 Pre-Answer sofia/internal/1525@sip.example.com!
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_channel.c:3585 (sofia/internal/1525@sip.example.com) Callstate Change RINGING -> EARLY
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_media.c:8641 Audio params are unchanged for sofia/internal/1525@sip.example.com.
2024-02-13 09:53:56.119081 94.07% [DEBUG] mod_sofia.c:2607 Ring SDP:
v=0
o=FreeSWITCH 1707793256 1707793257 IN IP4 10.249.0.20
s=FreeSWITCH
c=IN IP4 10.249.0.20
t=0 0
m=audio 17580 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
a=rtcp:17581 IN IP4 10.249.0.20
EXECUTE [depth=0] sofia/internal/1525@sip.example.com record_session(/var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13/d591ae7c-9f69-4222-9a77-720b416dab49.wav)
2024-02-13 09:53:56.119081 94.07% [DEBUG] sofia.c:7493 Channel sofia/internal/1525@sip.example.com entering state [early][183]
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_ivr_async.c:1504 Record session sample rate: 8000 -> 8000
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_media_bug.c:976 Attaching BUG to sofia/internal/1525@sip.example.com
EXECUTE [depth=0] sofia/internal/1525@sip.example.com hash(insert/sip.example.com-last_dial/1525/**1545)
EXECUTE [depth=0] sofia/internal/1525@sip.example.com answer()
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_media.c:8641 Audio params are unchanged for sofia/internal/1525@sip.example.com.
2024-02-13 09:53:56.119081 94.07% [DEBUG] mod_sofia.c:914 Local SDP sofia/internal/1525@sip.example.com:
v=0
o=FreeSWITCH 1707793256 1707793258 IN IP4 10.249.0.20
s=FreeSWITCH
c=IN IP4 10.249.0.20
t=0 0
m=audio 17580 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
a=rtcp:17581 IN IP4 10.249.0.20
2024-02-13 09:53:56.119081 94.07% [NOTICE] mod_dptools.c:1406 Channel [sofia/internal/1525@sip.example.com] has been answered
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_channel.c:3912 (sofia/internal/1525@sip.example.com) Callstate Change EARLY -> ACTIVE
2024-02-13 09:53:56.119081 94.07% [DEBUG] sofia.c:7493 Channel sofia/internal/1525@sip.example.com entering state [completed][200]
EXECUTE [depth=0] sofia/internal/1525@sip.example.com lua(intercept.lua 1545)
2024-02-13 09:53:56.119081 94.07% [NOTICE] switch_cpp.cpp:1465 [intercept] INTERCEPT 1545
2024-02-13 09:53:56.119081 94.07% [NOTICE] switch_cpp.cpp:1465 [intercept] Hostname: fusionpbx Call Hostname:
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_cpp.cpp:1209 sofia/internal/1525@sip.example.com destroy/unlink session from object
2024-02-13 09:53:56.119081 94.07% [NOTICE] switch_core_state_machine.c:382 sofia/internal/1525@sip.example.com has executed the last dialplan instruction, hanging up.
2024-02-13 09:53:56.119081 94.07% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/internal/1525@sip.example.com [CS_EXECUTE] [NORMAL_CLEARING]
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/1525@sip.example.com) State EXECUTE going to sleep
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_HANGUP (Cur 5 Tot 3970)
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_channel.c:3624 sofia/internal/1525@sip.example.com skip receive message [AUDIO_SYNC] (channel is hungup already)
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_ivr_async.c:1597 Stop recording file /var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13/d591ae7c-9f69-4222-9a77-720b416dab49.wav
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_ivr_async.c:1678 Channel is hung up
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_media_bug.c:1326 Removing BUG from sofia/internal/1525@sip.example.com
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/1525@sip.example.com) Callstate Change ACTIVE -> HANGUP
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/1525@sip.example.com) State HANGUP
2024-02-13 09:53:56.119081 94.07% [DEBUG] mod_sofia.c:469 Channel sofia/internal/1525@sip.example.com hanging up, cause: NORMAL_CLEARING
2024-02-13 09:53:56.139428 94.07% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/internal/1525@sip.example.com
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:59 sofia/internal/1525@sip.example.com Standard HANGUP, cause: NORMAL_CLEARING
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/1525@sip.example.com) State HANGUP going to sleep
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/1525@sip.example.com) State Change CS_HANGUP -> CS_REPORTING
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_REPORTING (Cur 5 Tot 3970)
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/1525@sip.example.com) State REPORTING
2024-02-13 09:53:56.139428 94.07% [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1525","1525","**1545","sip.example.com","2024-02-13 09:53:56","2024-02-13 09:53:56","2024-02-13 09:53:56",0,0,"NORMAL_CLEARING","d591ae7c-9f69-4222-9a77-720b416dab49","","IMPLYITFUSION")
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:168 sofia/internal/1525@sip.example.com Standard REPORTING, cause: NORMAL_CLEARING
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/1525@sip.example.com) State REPORTING going to sleep
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/1525@sip.example.com) State Change CS_REPORTING -> CS_DESTROY
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_session.c:1744 Session 3970 (sofia/internal/1525@sip.example.com) Locked, Waiting on external entities
2024-02-13 09:53:56.139428 94.07% [NOTICE] switch_core_session.c:1762 Session 3970 (sofia/internal/1525@sip.example.com) Ended
2024-02-13 09:53:56.139428 94.07% [NOTICE] switch_core_session.c:1766 Close Channel sofia/internal/1525@sip.example.com [CS_DESTROY]
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/1525@sip.example.com) Running State Change CS_DESTROY (Cur 4 Tot 3970)
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/1525@sip.example.com) State DESTROY
2024-02-13 09:53:56.139428 94.07% [DEBUG] mod_sofia.c:380 sofia/internal/1525@sip.example.com SOFIA DESTROY
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:175 sofia/internal/1525@sip.example.com Standard DESTROY
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/1525@sip.example.com) State DESTROY going to sleep
I've recently started using Fusion PBX and everything so far has been great and working well. The only thing that has not worked as expected is the intercept and group intercept functions as they're called.
When I try to intercept a call going to an extension I'll dial **1545 as an example and it will just terminate the call on my end. Please see below on the Freeswitch CLI:
We're running on a postgresql but it looks like the script references Database.new(switch) which I believe is a sqlite DB. I've tried removing reference the DB in the script and elsewhere but the result is the same. All the other lua scripts that do not reference Database.new(switch) work fine.
2024-02-13 09:53:56.019508 94.07% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/1525@sip.example.com [d591ae7c-9f69-4222-9a77-720b416dab49]
2024-02-13 09:53:56.019508 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_NEW (Cur 5 Tot 3970)
2024-02-13 09:53:56.019508 94.07% [INFO] sofia.c:10459 sofia/internal/1525@sip.example.com receiving invite from 10.0.0.158:60808 version: 1.10.10 -release-24-4cb05e7f4a 64bit call-id: 88c43b8bc04b4b928bcafbb376649eaa
2024-02-13 09:53:56.019508 94.07% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 10.0.0.158:0.
2024-02-13 09:53:56.019508 94.07% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/1525@sip.example.com) State NEW
2024-02-13 09:53:56.019508 94.07% [DEBUG] sofia.c:2419 detaching session d591ae7c-9f69-4222-9a77-720b416dab49
2024-02-13 09:53:56.059105 94.07% [DEBUG] sofia.c:2532 Re-attaching to session d591ae7c-9f69-4222-9a77-720b416dab49
2024-02-13 09:53:56.079097 94.07% [INFO] sofia.c:10459 sofia/internal/1525@sip.example.com receiving invite from 10.0.0.158:60808 version: 1.10.10 -release-24-4cb05e7f4a 64bit call-id: 88c43b8bc04b4b928bcafbb376649eaa
2024-02-13 09:53:56.079097 94.07% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 10.0.0.158:0.
2024-02-13 09:53:56.079097 94.07% [DEBUG] sofia.c:7493 Channel sofia/internal/1525@sip.example.com entering state [received][100]
2024-02-13 09:53:56.079097 94.07% [DEBUG] sofia.c:7503 Remote SDP:
v=0
o=- 3916806835 3916806835 IN IP4 10.0.0.158
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4006 RTP/AVP 18 8 0 101
c=IN IP4 10.0.0.158
b=TIAS:64000
a=rtpmap:18 G729/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp:4007 IN IP4 10.0.0.158
a=ssrc:1200249510 cname:42672dce726a4b0f
2024-02-13 09:53:56.079097 94.07% [DEBUG] sofia.c:7906 (sofia/internal/1525@sip.example.com) State Change CS_NEW -> CS_INIT
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_INIT (Cur 5 Tot 3970)
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1525@sip.example.com) State INIT
2024-02-13 09:53:56.079097 94.07% [DEBUG] mod_sofia.c:97 sofia/internal/1525@sip.example.com SOFIA INIT
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:40 sofia/internal/1525@sip.example.com Standard INIT
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1525@sip.example.com) State Change CS_INIT -> CS_ROUTING
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1525@sip.example.com) State INIT going to sleep
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_ROUTING (Cur 5 Tot 3970)
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_channel.c:2399 (sofia/internal/1525@sip.example.com) Callstate Change DOWN -> RINGING
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1525@sip.example.com) State ROUTING
2024-02-13 09:53:56.079097 94.07% [DEBUG] mod_sofia.c:158 sofia/internal/1525@sip.example.com SOFIA ROUTING
2024-02-13 09:53:56.079097 94.07% [DEBUG] switch_core_state_machine.c:230 sofia/internal/1525@sip.example.com Standard ROUTING
2024-02-13 09:53:56.079097 94.07% [INFO] mod_dialplan_xml.c:639 Processing Joe Blogs <1525>->**1545 in context sip.example.com
2024-02-13 09:53:56.099085 94.07% [NOTICE] switch_cpp.cpp:1465 [xml_handler] multiple key:dialplan:sip.example.com
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->user_exists] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/1525@sip.example.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(user_exists=false)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [user_exists]=[false]
Dialplan: sofia/internal/1525@sip.example.com Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(from_user_exists=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [from_user_exists]=[true]
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->caller-details] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Action set(caller_destination=${destination_number}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(caller_destination=**1545)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [caller_destination]=[**1545]
Dialplan: sofia/internal/1525@sip.example.com Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(caller_id_name=1525)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [caller_id_name]=[1525]
Dialplan: sofia/internal/1525@sip.example.com Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->global-variables] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [global-variables] () =~ // break=on-false
Dialplan: sofia/internal/1525@sip.example.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->domain-variables] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [domain-variables] () =~ // break=on-false
Dialplan: sofia/internal/1525@sip.example.com Action export(origination_callee_id_name=${caller_destination})
Dialplan: sofia/internal/1525@sip.example.com Action set(operator=1000) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(operator=1000)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [operator]=[1000]
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->clear_sip_auto_answer] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->is_loopback] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->call-direction] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [call-direction] ${call_direction}() =~ /^$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Action export(call_direction=local) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com export(call_direction=local)
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[local]
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->user_record] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${user_record}(all) =~ /^all$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Action set(record_session=true) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_session=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_session]=[true]
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${user_record}(all) =~ /^local$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(from_user_record=all)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [from_user_record]=[all]
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_record}(all) =~ /^all$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Action set(record_session=true) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_session=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_session]=[true]
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^inbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^outbound$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^local$/ break=never
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [user_record] ${record_session}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com Action set(record_path=${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_path=/var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_path]=[/var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13]
Dialplan: sofia/internal/1525@sip.example.com Action set(record_name=${uuid}.${record_ext}) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_name=d591ae7c-9f69-4222-9a77-720b416dab49.wav)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_name]=[d591ae7c-9f69-4222-9a77-720b416dab49.wav]
Dialplan: sofia/internal/1525@sip.example.com Action mkdir(${record_path})
Dialplan: sofia/internal/1525@sip.example.com Action set(recording_follow_transfer=true) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(recording_follow_transfer=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [recording_follow_transfer]=[true]
Dialplan: sofia/internal/1525@sip.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/1525@sip.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/1525@sip.example.com Action set(record_append=true) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_append=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_append]=[true]
Dialplan: sofia/internal/1525@sip.example.com Action set(record_in_progress=true) INLINE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(record_in_progress=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [record_in_progress]=[true]
Dialplan: sofia/internal/1525@sip.example.com Action set(RECORD_ANSWER_REQ=true)
Dialplan: sofia/internal/1525@sip.example.com Action record_session(${record_path}/${record_name})
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->rtp_has_crypto] continue=true
Dialplan: sofia/internal/1525@sip.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/1525@sip.example.com parsing [sip.example.com->redial] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [redial] destination_number(**1545) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/1525@sip.example.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->speed_dial] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [speed_dial] destination_number(**1545) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->user_hold_music] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->default_caller_id] continue=true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [default_caller_id] ${call_direction}(local) =~ /outbound/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Example.0d10] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [Example.0d10] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Example.0d10] destination_number(**1545) =~ /^(?:\+?0)?(\d{10})$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Example.27d11] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [Example.27d11] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Example.27d11] destination_number(**1545) =~ /^(?:\+?27)?(\d{11})$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Helpdesk] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Helpdesk] destination_number(**1545) =~ /^9980$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Fusion IVR] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Fusion IVR] destination_number(**1545) =~ /^9999$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Joe Blogs RG to Cell test] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Joe Blogs RG to Cell test] destination_number(**1545) =~ /^9984$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Gate] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Gate] destination_number(**1545) =~ /^9983$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Accounts] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Accounts] destination_number(**1545) =~ /^9982$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->Sales] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [Sales] destination_number(**1545) =~ /^9981$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->agent_status] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [agent_status] destination_number(**1545) =~ /^\*22$/ break=on-true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [agent_status] destination_number(**1545) =~ /^(?:agent\+|\*22)(.+)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->agent_status_id] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [agent_status_id] destination_number(**1545) =~ /^\*23$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->agent-status-break] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [agent-status-break] destination_number(**1545) =~ /^\*24$/ break=on-true
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [agent-status-break] destination_number(**1545) =~ /^(?:agent\+|\*24)(.+)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->group-intercept] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [group-intercept] destination_number(**1545) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->page-extension] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [page-extension] destination_number(**1545) =~ /^\*8(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->eavesdrop] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [eavesdrop] destination_number(**1545) =~ /^\*33(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->call_privacy] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [call_privacy] destination_number(**1545) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->call_return] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [call_return] destination_number(**1545) =~ /^\*69$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->number_queue] continue=
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [number_queue] destination_number(**1545) =~ /^\*800(.*)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->intercept-ext-polycom] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (FAIL) [intercept-ext-polycom] destination_number(**1545) =~ /^\*97(\d+)$/ break=on-false
Dialplan: sofia/internal/1525@sip.example.com parsing [sip.example.com->intercept-ext] continue=false
Dialplan: sofia/internal/1525@sip.example.com Regex (PASS) [intercept-ext] destination_number(**1545) =~ /^\*\*(\d+)$/ break=on-true
Dialplan: sofia/internal/1525@sip.example.com Action answer()
Dialplan: sofia/internal/1525@sip.example.com Action lua(intercept.lua 1545)
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/1525@sip.example.com) State Change CS_ROUTING -> CS_EXECUTE
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1525@sip.example.com) State ROUTING going to sleep
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_EXECUTE (Cur 5 Tot 3970)
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/1525@sip.example.com) State EXECUTE
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_sofia.c:213 sofia/internal/1525@sip.example.com SOFIA EXECUTE
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_state_machine.c:323 sofia/internal/1525@sip.example.com Standard EXECUTE
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(caller_id_number=1525)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [caller_id_number]=[1525]
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(RFC2822_DATE=Tue, 13 Feb 2024 09:53:56 +0200)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [RFC2822_DATE]=[Tue, 13 Feb 2024 09:53:56 +0200]
EXECUTE [depth=0] sofia/internal/1525@sip.example.com export(origination_callee_id_name=**1545)
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [origination_callee_id_name]=[**1545]
EXECUTE [depth=0] sofia/internal/1525@sip.example.com mkdir(/var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:664 sofia/internal/1525@sip.example.com MKDIR: /var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13
EXECUTE [depth=0] sofia/internal/1525@sip.example.com bind_digit_action(local,*5,api:uuid_record,d591ae7c-9f69-4222-9a77-720b416dab49 mask /var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13/d591ae7c-9f69-4222-9a77-720b416dab49.wav,both,self)
2024-02-13 09:53:56.099085 94.07% [INFO] switch_ivr_async.c:221 Digit parser DPTOOLS: Setting realm to 'local'
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *5/local/0 callback: 0x7fb98390e940 data: 0x7fb9a0150490
2024-02-13 09:53:56.099085 94.07% [INFO] switch_ivr_async.c:221 Digit parser DPTOOLS: Setting realm to 'local'
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *5/local/0 callback: 0x7fb98390e940 data: 0x7fb9a0150590
EXECUTE [depth=0] sofia/internal/1525@sip.example.com bind_digit_action(local,*6,api:uuid_record,d591ae7c-9f69-4222-9a77-720b416dab49 unmask /var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13/d591ae7c-9f69-4222-9a77-720b416dab49.wav,both,self)
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *6/local/0 callback: 0x7fb98390e940 data: 0x7fb9a01508e8
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_ivr_async.c:346 Digit parser DPTOOLS: binding *6/local/0 callback: 0x7fb98390e940 data: 0x7fb9a01509e8
EXECUTE [depth=0] sofia/internal/1525@sip.example.com set(RECORD_ANSWER_REQ=true)
2024-02-13 09:53:56.099085 94.07% [DEBUG] mod_dptools.c:1671 SET sofia/internal/1525@sip.example.com [RECORD_ANSWER_REQ]=[true]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_session.c:2791 Application record_session Requires media! pre_answering channel sofia/internal/1525@sip.example.com
2024-02-13 09:53:56.099085 94.07% [INFO] switch_core_session.c:2793 Sending early media
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:3734 Set Codec sofia/internal/1525@sip.example.com G729/8000 20 ms 160 samples 8000 bits 1 channels
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_codec.c:111 sofia/internal/1525@sip.example.com Original read codec set to G729:18
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:5856 sofia/internal/1525@sip.example.com Set 2833 dtmf send payload to 101 recv payload to 101
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/internal/1525@sip.example.com] 10.249.0.20 port 17580 -> 10.0.0.158 port 4006 codec: 18 ms: 20
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_rtp.c:4373 Starting timer [soft] 160 bytes per 20ms
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:8880 Activating RTCP PORT 4007
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_rtp.c:4705 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 4007
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_rtp.c:2533 Setting RTCP remote addr to 10.0.0.158:4007 2
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:8972 sofia/internal/1525@sip.example.com Set 2833 dtmf send payload to 101
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:8979 sofia/internal/1525@sip.example.com Set 2833 dtmf receive payload to 101
2024-02-13 09:53:56.099085 94.07% [DEBUG] switch_core_media.c:9002 sofia/internal/1525@sip.example.com Set rtp dtmf delay to 40
2024-02-13 09:53:56.099085 94.07% [NOTICE] sofia_media.c:90 Pre-Answer sofia/internal/1525@sip.example.com!
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_channel.c:3585 (sofia/internal/1525@sip.example.com) Callstate Change RINGING -> EARLY
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_media.c:8641 Audio params are unchanged for sofia/internal/1525@sip.example.com.
2024-02-13 09:53:56.119081 94.07% [DEBUG] mod_sofia.c:2607 Ring SDP:
v=0
o=FreeSWITCH 1707793256 1707793257 IN IP4 10.249.0.20
s=FreeSWITCH
c=IN IP4 10.249.0.20
t=0 0
m=audio 17580 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
a=rtcp:17581 IN IP4 10.249.0.20
EXECUTE [depth=0] sofia/internal/1525@sip.example.com record_session(/var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13/d591ae7c-9f69-4222-9a77-720b416dab49.wav)
2024-02-13 09:53:56.119081 94.07% [DEBUG] sofia.c:7493 Channel sofia/internal/1525@sip.example.com entering state [early][183]
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_ivr_async.c:1504 Record session sample rate: 8000 -> 8000
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_media_bug.c:976 Attaching BUG to sofia/internal/1525@sip.example.com
EXECUTE [depth=0] sofia/internal/1525@sip.example.com hash(insert/sip.example.com-last_dial/1525/**1545)
EXECUTE [depth=0] sofia/internal/1525@sip.example.com answer()
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_media.c:8641 Audio params are unchanged for sofia/internal/1525@sip.example.com.
2024-02-13 09:53:56.119081 94.07% [DEBUG] mod_sofia.c:914 Local SDP sofia/internal/1525@sip.example.com:
v=0
o=FreeSWITCH 1707793256 1707793258 IN IP4 10.249.0.20
s=FreeSWITCH
c=IN IP4 10.249.0.20
t=0 0
m=audio 17580 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
a=rtcp:17581 IN IP4 10.249.0.20
2024-02-13 09:53:56.119081 94.07% [NOTICE] mod_dptools.c:1406 Channel [sofia/internal/1525@sip.example.com] has been answered
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_channel.c:3912 (sofia/internal/1525@sip.example.com) Callstate Change EARLY -> ACTIVE
2024-02-13 09:53:56.119081 94.07% [DEBUG] sofia.c:7493 Channel sofia/internal/1525@sip.example.com entering state [completed][200]
EXECUTE [depth=0] sofia/internal/1525@sip.example.com lua(intercept.lua 1545)
2024-02-13 09:53:56.119081 94.07% [NOTICE] switch_cpp.cpp:1465 [intercept] INTERCEPT 1545
2024-02-13 09:53:56.119081 94.07% [NOTICE] switch_cpp.cpp:1465 [intercept] Hostname: fusionpbx Call Hostname:
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_cpp.cpp:1209 sofia/internal/1525@sip.example.com destroy/unlink session from object
2024-02-13 09:53:56.119081 94.07% [NOTICE] switch_core_state_machine.c:382 sofia/internal/1525@sip.example.com has executed the last dialplan instruction, hanging up.
2024-02-13 09:53:56.119081 94.07% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/internal/1525@sip.example.com [CS_EXECUTE] [NORMAL_CLEARING]
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/1525@sip.example.com) State EXECUTE going to sleep
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_HANGUP (Cur 5 Tot 3970)
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_channel.c:3624 sofia/internal/1525@sip.example.com skip receive message [AUDIO_SYNC] (channel is hungup already)
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_ivr_async.c:1597 Stop recording file /var/lib/freeswitch/recordings/sip.example.com/archive/2024/Feb/13/d591ae7c-9f69-4222-9a77-720b416dab49.wav
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_ivr_async.c:1678 Channel is hung up
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_media_bug.c:1326 Removing BUG from sofia/internal/1525@sip.example.com
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/1525@sip.example.com) Callstate Change ACTIVE -> HANGUP
2024-02-13 09:53:56.119081 94.07% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/1525@sip.example.com) State HANGUP
2024-02-13 09:53:56.119081 94.07% [DEBUG] mod_sofia.c:469 Channel sofia/internal/1525@sip.example.com hanging up, cause: NORMAL_CLEARING
2024-02-13 09:53:56.139428 94.07% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/internal/1525@sip.example.com
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:59 sofia/internal/1525@sip.example.com Standard HANGUP, cause: NORMAL_CLEARING
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/1525@sip.example.com) State HANGUP going to sleep
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/1525@sip.example.com) State Change CS_HANGUP -> CS_REPORTING
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1525@sip.example.com) Running State Change CS_REPORTING (Cur 5 Tot 3970)
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/1525@sip.example.com) State REPORTING
2024-02-13 09:53:56.139428 94.07% [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1525","1525","**1545","sip.example.com","2024-02-13 09:53:56","2024-02-13 09:53:56","2024-02-13 09:53:56",0,0,"NORMAL_CLEARING","d591ae7c-9f69-4222-9a77-720b416dab49","","IMPLYITFUSION")
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:168 sofia/internal/1525@sip.example.com Standard REPORTING, cause: NORMAL_CLEARING
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/1525@sip.example.com) State REPORTING going to sleep
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/1525@sip.example.com) State Change CS_REPORTING -> CS_DESTROY
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_session.c:1744 Session 3970 (sofia/internal/1525@sip.example.com) Locked, Waiting on external entities
2024-02-13 09:53:56.139428 94.07% [NOTICE] switch_core_session.c:1762 Session 3970 (sofia/internal/1525@sip.example.com) Ended
2024-02-13 09:53:56.139428 94.07% [NOTICE] switch_core_session.c:1766 Close Channel sofia/internal/1525@sip.example.com [CS_DESTROY]
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/1525@sip.example.com) Running State Change CS_DESTROY (Cur 4 Tot 3970)
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/1525@sip.example.com) State DESTROY
2024-02-13 09:53:56.139428 94.07% [DEBUG] mod_sofia.c:380 sofia/internal/1525@sip.example.com SOFIA DESTROY
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:175 sofia/internal/1525@sip.example.com Standard DESTROY
2024-02-13 09:53:56.139428 94.07% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/1525@sip.example.com) State DESTROY going to sleep
