This should not be the case, post a log.
My ring group is extension 6400 and it includes 2 extensions, 1000 and 1001.
This is the log when extension 1001 is not registered:
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:19.886480 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/
1002@mydomain.com [349f54de-808d-454e-9eed-91f1d2b431d4]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:19.886480 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_NEW (Cur 1 Tot 66179)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:19.886480 [DEBUG] sofia.c:10255 sofia/internal/
1002@mydomain.com receiving invite from CLIENTEXTERNALIP:51965 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-04-11 13:28:19.886480 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port CLIENTEXTERNALIP:0.
2020-04-11 13:28:19.886480 [DEBUG] sofia.c:2434 detaching session 349f54de-808d-454e-9eed-91f1d2b431d4
2020-04-11 13:28:19.886480 [WARNING] sofia_reg.c:1793 SIP auth challenge (INVITE) on sofia profile 'internal' for [
6400@mydomain.com] from ip CLIENTEXTERNALIP
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:19.886480 [DEBUG] switch_core_state_machine.c:604 (sofia/internal/
1002@mydomain.com) State NEW
2020-04-11 13:28:20.903303 [WARNING] sofia_reg.c:1793 SIP auth challenge (REGISTER) on sofia profile 'internal' for [
1002@mydomain.com] from ip CLIENTEXTERNALIP
2020-04-11 13:28:20.943318 [DEBUG] sofia.c:2544 Re-attaching to session 349f54de-808d-454e-9eed-91f1d2b431d4
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.943318 [DEBUG] sofia.c:10255 sofia/internal/
1002@mydomain.com receiving invite from CLIENTEXTERNALIP:51965 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-04-11 13:28:20.943318 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port CLIENTEXTERNALIP:0.
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] sofia.c:11452 Setting NAT mode based on via received
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] sofia.c:7301 Channel sofia/internal/
1002@mydomain.com entering state [received][100]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] sofia.c:7311 Remote SDP:
349f54de-808d-454e-9eed-91f1d2b431d4 v=0
349f54de-808d-454e-9eed-91f1d2b431d4 o=1002 123456 654321 IN IP4 192.168.1.21
349f54de-808d-454e-9eed-91f1d2b431d4 s=A conversation
349f54de-808d-454e-9eed-91f1d2b431d4 c=IN IP4 192.168.1.21
349f54de-808d-454e-9eed-91f1d2b431d4 t=0 0
349f54de-808d-454e-9eed-91f1d2b431d4 m=audio 7078 RTP/AVP 0 8 101
349f54de-808d-454e-9eed-91f1d2b431d4 a=rtpmap:0 PCMU/8000/1
349f54de-808d-454e-9eed-91f1d2b431d4 a=rtpmap:8 PCMA/8000/1
349f54de-808d-454e-9eed-91f1d2b431d4 a=rtpmap:101 telephone-event/8000/1
349f54de-808d-454e-9eed-91f1d2b431d4 a=fmtp:101 0-11
349f54de-808d-454e-9eed-91f1d2b431d4
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5508 Set telephone-event payload to 101@8000
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:3837 Set Codec sofia/internal/
1002@mydomain.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_codec.c:111 sofia/internal/
1002@mydomain.com Original read codec set to PCMU:0
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5851 Set telephone-event payload to 101@8000
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_media.c:5909 sofia/internal/
1002@mydomain.com Set 2833 dtmf send payload to 101 recv payload to 101
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] sofia.c:7735 (sofia/internal/
1002@mydomain.com) State Change CS_NEW -> CS_INIT
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_INIT (Cur 1 Tot 66179)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/
1002@mydomain.com) State INIT
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] mod_sofia.c:93 sofia/internal/
1002@mydomain.com SOFIA INIT
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_state_machine.c:40 sofia/internal/
1002@mydomain.com Standard INIT
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/
1002@mydomain.com) State Change CS_INIT -> CS_ROUTING
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/
1002@mydomain.com) State INIT going to sleep
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_ROUTING (Cur 1 Tot 66179)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_channel.c:2332 (sofia/internal/
1002@mydomain.com) Callstate Change DOWN -> RINGING
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/
1002@mydomain.com) State ROUTING
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] mod_sofia.c:154 sofia/internal/
1002@mydomain.com SOFIA ROUTING
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] switch_core_state_machine.c:236 sofia/internal/
1002@mydomain.com Standard ROUTING
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [INFO] mod_dialplan_xml.c:637 Processing 1002 <1002>->6400 in context mydomain.com
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->user_exists] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_exists] () =~ // break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(user_exists=false)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [user_exists]=[false]
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(from_user_exists=true)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [from_user_exists]=[true]
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->caller-details] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(caller_destination=${destination_number}) INLINE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(caller_destination=6400)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.963303 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [caller_destination]=[6400]
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(caller_id_name=${caller_id_name}) INLINE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(caller_id_name=1002)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [caller_id_name]=[1002]
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(caller_id_number=${caller_id_number})
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->call-direction] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com ANTI-Action export(call_direction=local) INLINE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com export(call_direction=local)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[local]
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->domain-variables] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [domain-variables] () =~ // break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action export(origination_callee_id_name=${destination_number})
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->is_loopback] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->user_record] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(from_user_record=)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [from_user_record]=[UNDEF]
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->redial] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [redial] destination_number(6400) =~ /^(redial|\*870)$/ break=on-true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [redial] () =~ // break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->speed_dial] continue=false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [speed_dial] destination_number(6400) =~ /^\*0(.*)$/ break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->default_caller_id] continue=true
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(emergency_caller_id_name=)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [emergency_caller_id_name]=[UNDEF]
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(emergency_caller_id_number=)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [emergency_caller_id_number]=[UNDEF]
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [default_caller_id] ${outbound_caller_id_number}() =~ /^$/ break=never
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(outbound_caller_id_name=${default_outbound_caller_id_name}) INLINE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(outbound_caller_id_name=)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [outbound_caller_id_name]=[UNDEF]
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(outbound_caller_id_number=${default_outbound_caller_id_number}) INLINE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(outbound_caller_id_number=)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [outbound_caller_id_number]=[UNDEF]
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->Llamadas_Nacionales] continue=false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [Llamadas_Nacionales] ${user_exists}(false) =~ /false/ break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [Llamadas_Nacionales] ${toll_allow}() =~ /Nacionales/ break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->Llamadas_Europa] continue=false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [Llamadas_Europa] ${user_exists}(false) =~ /false/ break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [Llamadas_Europa] ${toll_allow}() =~ /Europa/ break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->Interfonos] continue=
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [Interfonos] destination_number(6400) =~ /^6400$/ break=on-false
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action ring_ready()
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action set(ring_group_uuid=d6d63ca5-57ad-460d-bdce-de9a1893c745)
349f54de-808d-454e-9eed-91f1d2b431d4 Dialplan: sofia/internal/
1002@mydomain.com Action lua(app.lua ring_groups)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/
1002@mydomain.com) State Change CS_ROUTING -> CS_EXECUTE
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/
1002@mydomain.com) State ROUTING going to sleep
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_EXECUTE (Cur 1 Tot 66179)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/
1002@mydomain.com) State EXECUTE
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_sofia.c:209 sofia/internal/
1002@mydomain.com SOFIA EXECUTE
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] switch_core_state_machine.c:329 sofia/internal/
1002@mydomain.com Standard EXECUTE
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(caller_id_number=1002)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [caller_id_number]=[1002]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 13:28:20 +0200)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 13:28:20 +0200]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com export(origination_callee_id_name=6400)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [origination_callee_id_name]=[6400]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 13:28:20 +0200)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 13:28:20 +0200]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 13:28:20 +0200)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 13:28:20 +0200]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 13:28:20 +0200)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 13:28:20 +0200]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 13:28:20 +0200)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 13:28:20 +0200]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 13:28:20 +0200)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 13:28:20 +0200]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com hash(insert/mydomain.com-last_dial/1002/6400)
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com ring_ready()
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [NOTICE] mod_sofia.c:2498 Ring-Ready sofia/internal/
1002@mydomain.com!
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] sofia.c:7301 Channel sofia/internal/
1002@mydomain.com entering state [early][180]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [NOTICE] mod_dptools.c:1122 Ring Ready sofia/internal/
1002@mydomain.com!
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(ring_group_uuid=d6d63ca5-57ad-460d-bdce-de9a1893c745)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [ring_group_uuid]=[d6d63ca5-57ad-460d-bdce-de9a1893c745]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com lua(app.lua ring_groups)
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com ring_ready()
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:20.983292 [NOTICE] mod_dptools.c:1122 Ring Ready sofia/internal/
1002@mydomain.com!
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.003306 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(call_timeout, 300)
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring_group] sofia_contact */
1001@mydomain.com
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring_group] user_data
1001@mydomain.com var forward_user_not_registered_enabled
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring group] domain_name: mydomain.com
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_number: 1000
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_delay: 0
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_timeout: 30
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_prompt:
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring group] domain_name: mydomain.com
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_number: 1001
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_delay: 0
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_timeout: 30
2020-04-11 13:28:21.023301 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_prompt:
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.043302 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(ringback, tone_stream://%(1500,3000,425);loops=-1)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.043302 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(transfer_ringback, tone_stream://%(1500,3000,425);loops=-1)
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(uuids=cef2404c-267c-41e1-8aec-e178c9b1ec30)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.043302 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [uuids]=[cef2404c-267c-41e1-8aec-e178c9b1ec30]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com export(sip_h_Alert-Info=)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.043302 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(group_confirm_key=exec)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.043302 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [group_confirm_key]=[exec]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.043302 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(ringback, tone_stream://%(1500,3000,425);loops=-1)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(transfer_ringback, tone_stream://%(1500,3000,425);loops=-1)
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(uuids=cef2404c-267c-41e1-8aec-e178c9b1ec30,366743db-5297-4a4a-9034-722e9474842c)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [uuids]=[cef2404c-267c-41e1-8aec-e178c9b1ec30,366743db-5297-4a4a-9034-722e9474842c]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com export(sip_h_Alert-Info=)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(group_confirm_key=exec)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [group_confirm_key]=[exec]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(ignore_early_media=true)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [ignore_early_media]=[true]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(hangup_after_bridge=true)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [hangup_after_bridge]=[true]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(continue_on_fail=true)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [continue_on_fail]=[true]
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com bind_digit_action(local,*2,exec:record_session,/var/lib/freeswitch/recordings/mydomain.com/archive/2020/Apr/11/349f54de-808d-454e-9eed-91f1d2b431d4.wav,both)
2020-04-11 13:28:21.063301 [INFO] switch_ivr_async.c:219 Digit parser DPTOOLS: Setting realm to 'local'
2020-04-11 13:28:21.063301 [DEBUG] switch_ivr_async.c:344 Digit parser DPTOOLS: binding *2/local/0 callback: 0x7f284a956e00 data: 0x7f285c02ab30
2020-04-11 13:28:21.063301 [INFO] switch_ivr_async.c:219 Digit parser DPTOOLS: Setting realm to 'local'
2020-04-11 13:28:21.063301 [DEBUG] switch_ivr_async.c:344 Digit parser DPTOOLS: binding *2/local/0 callback: 0x7f284a956e00 data: 0x7f285c02ac20
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com digit_action_set_realm(local)
2020-04-11 13:28:21.063301 [INFO] switch_ivr_async.c:219 Digit parser DPTOOLS: Setting realm to 'local'
2020-04-11 13:28:21.063301 [NOTICE] switch_cpp.cpp:1443 [ring group] app_data: {ignore_early_media=true}[sip_invite_domain=mydomain.com,domain_name=mydomain.com,call_direction=local,confirm=false,leg_timeout=30,leg_delay_start=0,dialed_extension=1000,extension_uuid=e74c05ca-3950-4297-9dff-d149d632c7a0]user/
1000@mydomain.com,[sip_invite_domain=mydomain.com,domain_name=mydomain.com,call_direction=local,confirm=false,leg_timeout=30,leg_delay_start=0,dialed_extension=1001,extension_uuid=4ebb4289-c2c6-42b9-bbd8-62224dfd631c]user/
1001@mydomain.com
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com bridge({ignore_early_media=true}[sip_invite_domain=mydomain.com,domain_name=mydomain.com,call_direction=local,confirm=false,leg_timeout=30,leg_delay_start=0,dialed_extension=1000,extension_uuid=e74c05ca-3950-4297-9dff-d149d632c7a0]user/
1000@mydomain.com,[sip_invite_domain=mydomain.com,domain_name=mydomain.com,call_direction=local,confirm=false,leg_timeout=30,leg_delay_start=0,dialed_extension=1001,extension_uuid=4ebb4289-c2c6-42b9-bbd8-62224dfd631c]user/
1001@mydomain.com)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [domain_name]=[mydomain.com] to event
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [call_direction]=[local] to event
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [origination_callee_id_name]=[6400] to event
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.063301 [DEBUG] switch_ivr_originate.c:2760 Parsing session specific variables
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [domain_name]=[mydomain.com] to event
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [call_direction]=[local] to event
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [origination_callee_id_name]=[6400] to event
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/1000@192.168.1.23:5060 [05f8e8d5-cc75-45df-9c76-c0db8253b93d]
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] mod_sofia.c:5089 (sofia/internal/1000@192.168.1.23:5060) State Change CS_NEW -> CS_INIT
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_ivr_originate.c:3067 sofia/internal/1000@192.168.1.23:5060 Setting leg timeout to 30
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_ivr_originate.c:3067 sofia/internal/1000@192.168.1.23:5060 Setting leg timeout to 30
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_ivr_originate.c:2760 Parsing session specific variables
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [domain_name]=[mydomain.com] to event
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [call_direction]=[local] to event
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [origination_callee_id_name]=[6400] to event
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [NOTICE] switch_ivr_originate.c:2955 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [DEBUG] switch_ivr_originate.c:3952 Originate Resulted in Error Cause: 606 [USER_NOT_REGISTERED]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.083303 [NOTICE] switch_ivr_originate.c:2955 Cannot create outgoing channel of type [user] cause: [USER_NOT_REGISTERED]
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_INIT (Cur 2 Tot 66180)
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/1000@192.168.1.23:5060) State INIT
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] mod_sofia.c:93 sofia/internal/1000@192.168.1.23:5060 SOFIA INIT
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] sofia_glue.c:1587 sip:1000@CLIENTEXTERNALIP:54390;transport=tcp Setting proxy route to sofia/internal/1000@192.168.1.23:5060
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] sofia_glue.c:1618 sofia/internal/1000@192.168.1.23:5060 sending invite version: 1.10.2 -release-14-f7bdd3845a 64bit
05f8e8d5-cc75-45df-9c76-c0db8253b93d Local SDP:
05f8e8d5-cc75-45df-9c76-c0db8253b93d v=0
05f8e8d5-cc75-45df-9c76-c0db8253b93d o=FreeSWITCH 1586586311 1586586312 IN IP4 FUSIONPBXIP
05f8e8d5-cc75-45df-9c76-c0db8253b93d s=FreeSWITCH
05f8e8d5-cc75-45df-9c76-c0db8253b93d c=IN IP4 FUSIONPBXIP
05f8e8d5-cc75-45df-9c76-c0db8253b93d t=0 0
05f8e8d5-cc75-45df-9c76-c0db8253b93d m=audio 18190 RTP/AVP 0 18 9 8 101 13
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtpmap:0 PCMU/8000
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtpmap:18 G729/8000
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtpmap:9 G722/8000
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtpmap:8 PCMA/8000
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtpmap:101 telephone-event/8000
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=fmtp:101 0-16
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtpmap:13 CN/8000
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=ptime:20
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=sendrecv
05f8e8d5-cc75-45df-9c76-c0db8253b93d m=video 20936 RTP/AVP 102
05f8e8d5-cc75-45df-9c76-c0db8253b93d b=AS:1024
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtpmap:102 H264/90000
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=sendrecv
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtcp-fb:102 ccm fir
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtcp-fb:102 ccm tmmbr
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtcp-fb:102 nack
05f8e8d5-cc75-45df-9c76-c0db8253b93d a=rtcp-fb:102 nack pli
05f8e8d5-cc75-45df-9c76-c0db8253b93d
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.1.23:5060 Standard INIT
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.1.23:5060) State Change CS_INIT -> CS_ROUTING
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/1000@192.168.1.23:5060) State INIT going to sleep
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_ROUTING (Cur 2 Tot 66180)
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] sofia.c:7301 Channel sofia/internal/1000@192.168.1.23:5060 entering state [calling][0]
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/1000@192.168.1.23:5060) State ROUTING
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] mod_sofia.c:154 sofia/internal/1000@192.168.1.23:5060 SOFIA ROUTING
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@192.168.1.23:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/1000@192.168.1.23:5060) State ROUTING going to sleep
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 66180)
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/1000@192.168.1.23:5060) State CONSUME_MEDIA
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.083303 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/1000@192.168.1.23:5060) State CONSUME_MEDIA going to sleep
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.243303 [DEBUG] sofia.c:7301 Channel sofia/internal/1000@192.168.1.23:5060 entering state [proceeding][180]
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.243303 [NOTICE] sofia.c:7412 Ring-Ready sofia/internal/1000@192.168.1.23:5060!
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:21.243303 [DEBUG] switch_channel.c:3437 (sofia/internal/1000@192.168.1.23:5060) Callstate Change DOWN -> RINGING
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [INFO] switch_ivr_originate.c:1246 Sending early media
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/internal/
1002@mydomain.com] FUSIONPBXIP port 19060 -> 192.168.1.21 port 7078 codec: 0 ms: 20
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] switch_rtp.c:4408 Starting timer [soft] 160 bytes per 20ms
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] switch_core_media.c:8973 sofia/internal/
1002@mydomain.com Set 2833 dtmf send payload to 101
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] switch_core_media.c:8980 sofia/internal/
1002@mydomain.com Set 2833 dtmf receive payload to 101
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] switch_core_media.c:9003 sofia/internal/
1002@mydomain.com Set rtp dtmf delay to 40
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] mod_sofia.c:2593 Ring SDP:
349f54de-808d-454e-9eed-91f1d2b431d4 v=0
349f54de-808d-454e-9eed-91f1d2b431d4 o=FreeSWITCH 1586585441 1586585442 IN IP4 FUSIONPBXIP
349f54de-808d-454e-9eed-91f1d2b431d4 s=FreeSWITCH
349f54de-808d-454e-9eed-91f1d2b431d4 c=IN IP4 FUSIONPBXIP
349f54de-808d-454e-9eed-91f1d2b431d4 t=0 0
349f54de-808d-454e-9eed-91f1d2b431d4 m=audio 19060 RTP/AVP 0 101
349f54de-808d-454e-9eed-91f1d2b431d4 a=rtpmap:0 PCMU/8000
349f54de-808d-454e-9eed-91f1d2b431d4 a=rtpmap:101 telephone-event/8000
349f54de-808d-454e-9eed-91f1d2b431d4 a=fmtp:101 0-16
349f54de-808d-454e-9eed-91f1d2b431d4 a=ptime:20
349f54de-808d-454e-9eed-91f1d2b431d4 a=sendrecv
349f54de-808d-454e-9eed-91f1d2b431d4
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [NOTICE] mod_sofia.c:2596 Pre-Answer sofia/internal/
1002@mydomain.com!
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] switch_channel.c:3565 (sofia/internal/
1002@mydomain.com) Callstate Change RINGING -> EARLY
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] sofia.c:7301 Channel sofia/internal/
1002@mydomain.com entering state [early][183]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] switch_ivr_originate.c:1304 Raw Codec Activation Success L16@8000hz 1 channel 20ms
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] switch_core_codec.c:223 sofia/internal/
1002@mydomain.com Push codec L16:100
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:21.243303 [DEBUG] switch_ivr_originate.c:1336 Play Ringback File [tone_stream://%(1500,3000,425);loops=-1]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:22.143313 [INFO] switch_rtp.c:7680 Auto Changing audio port from 192.168.1.21:7078 to CLIENTEXTERNALIP:7078
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [NOTICE] switch_ivr_originate.c:353 Hangup sofia/internal/1000@192.168.1.23:5060 [CS_CONSUME_MEDIA] [ALLOTTED_TIMEOUT]
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_HANGUP (Cur 2 Tot 66180)
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/1000@192.168.1.23:5060) Callstate Change RINGING -> HANGUP
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.1.23:5060) State HANGUP
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] mod_sofia.c:453 Channel sofia/internal/1000@192.168.1.23:5060 hanging up, cause: ALLOTTED_TIMEOUT
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] mod_sofia.c:521 Sending CANCEL to sofia/internal/1000@192.168.1.23:5060
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.1.23:5060 Standard HANGUP, cause: ALLOTTED_TIMEOUT
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.1.23:5060) State HANGUP going to sleep
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/1000@192.168.1.23:5060) State Change CS_HANGUP -> CS_REPORTING
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_REPORTING (Cur 2 Tot 66180)
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/1000@192.168.1.23:5060) State REPORTING
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@192.168.1.23:5060 Standard REPORTING, cause: ALLOTTED_TIMEOUT
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/1000@192.168.1.23:5060) State REPORTING going to sleep
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/1000@192.168.1.23:5060) State Change CS_REPORTING -> CS_DESTROY
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.003343 [DEBUG] switch_core_session.c:1726 Session 66180 (sofia/internal/1000@192.168.1.23:5060) Locked, Waiting on external entities
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_codec.c:248 sofia/internal/
1002@mydomain.com Restore previous codec PCMU:0.
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_ivr_originate.c:3952 Originate Resulted in Error Cause: 602 [ALLOTTED_TIMEOUT]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [INFO] mod_dptools.c:3631 Originate Failed. Cause: ALLOTTED_TIMEOUT
349f54de-808d-454e-9eed-91f1d2b431d4 EXECUTE [depth=0] sofia/internal/
1002@mydomain.com hangup()
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [NOTICE] mod_dptools.c:1380 Hangup sofia/internal/
1002@mydomain.com [CS_EXECUTE] [NORMAL_CLEARING]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_session.c:2905 sofia/internal/
1002@mydomain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_cpp.cpp:1187 sofia/internal/
1002@mydomain.com destroy/unlink session from object
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_session.c:2905 sofia/internal/
1002@mydomain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/
1002@mydomain.com) State EXECUTE going to sleep
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_HANGUP (Cur 2 Tot 66180)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/
1002@mydomain.com) Callstate Change EARLY -> HANGUP
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/
1002@mydomain.com) State HANGUP
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] mod_sofia.c:453 Channel sofia/internal/
1002@mydomain.com hanging up, cause: NORMAL_CLEARING
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] mod_sofia.c:598 Responding to INVITE with: 480
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_state_machine.c:60 sofia/internal/
1002@mydomain.com Standard HANGUP, cause: NORMAL_CLEARING
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/
1002@mydomain.com) State HANGUP going to sleep
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/
1002@mydomain.com) State Change CS_HANGUP -> CS_REPORTING
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_REPORTING (Cur 2 Tot 66180)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.023306 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/
1002@mydomain.com) State REPORTING
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.023306 [NOTICE] switch_core_session.c:1744 Session 66180 (sofia/internal/1000@192.168.1.23:5060) Ended
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.023306 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/1000@192.168.1.23:5060 [CS_DESTROY]
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.043301 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_DESTROY (Cur 1 Tot 66180)
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.043301 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/1000@192.168.1.23:5060) State DESTROY
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.043301 [DEBUG] mod_sofia.c:364 sofia/internal/1000@192.168.1.23:5060 SOFIA DESTROY
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.043301 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@192.168.1.23:5060 Standard DESTROY
05f8e8d5-cc75-45df-9c76-c0db8253b93d 2020-04-11 13:28:52.043301 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/1000@192.168.1.23:5060) State DESTROY going to sleep
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [DEBUG] switch_core_state_machine.c:174 sofia/internal/
1002@mydomain.com Standard REPORTING, cause: NORMAL_CLEARING
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/
1002@mydomain.com) State REPORTING going to sleep
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/
1002@mydomain.com) State Change CS_REPORTING -> CS_DESTROY
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [DEBUG] switch_core_session.c:1726 Session 66179 (sofia/internal/
1002@mydomain.com) Locked, Waiting on external entities
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [NOTICE] switch_core_session.c:1744 Session 66179 (sofia/internal/
1002@mydomain.com) Ended
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/
1002@mydomain.com [CS_DESTROY]
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/
1002@mydomain.com) Running State Change CS_DESTROY (Cur 0 Tot 66180)
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/
1002@mydomain.com) State DESTROY
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [DEBUG] mod_sofia.c:364 sofia/internal/
1002@mydomain.com SOFIA DESTROY
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [DEBUG] switch_core_state_machine.c:181 sofia/internal/
1002@mydomain.com Standard DESTROY
349f54de-808d-454e-9eed-91f1d2b431d4 2020-04-11 13:28:52.123320 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/
1002@mydomain.com) State DESTROY going to sleep
And this is the log when the 2 extensions are registered and the call is successful:
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:26.323345 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/
1002@mydomain.com [b3b38503-5acc-4f6c-994d-b213a4e044cd]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:26.323345 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_NEW (Cur 1 Tot 66207)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:26.323345 [DEBUG] sofia.c:10255 sofia/internal/
1002@mydomain.com receiving invite from CLIENTEXTERNALIP:51965 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-04-11 14:01:26.323345 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port CLIENTEXTERNALIP:0.
2020-04-11 14:01:26.323345 [DEBUG] sofia.c:2434 detaching session b3b38503-5acc-4f6c-994d-b213a4e044cd
2020-04-11 14:01:26.323345 [WARNING] sofia_reg.c:1793 SIP auth challenge (INVITE) on sofia profile 'internal' for [
6400@mydomain.com] from ip CLIENTEXTERNALIP
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:26.323345 [DEBUG] switch_core_state_machine.c:604 (sofia/internal/
1002@mydomain.com) State NEW
2020-04-11 14:01:27.303343 [DEBUG] sofia.c:2544 Re-attaching to session b3b38503-5acc-4f6c-994d-b213a4e044cd
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.303343 [DEBUG] sofia.c:10255 sofia/internal/
1002@mydomain.com receiving invite from CLIENTEXTERNALIP:51965 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-04-11 14:01:27.303343 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port CLIENTEXTERNALIP:0.
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.303343 [DEBUG] sofia.c:11452 Setting NAT mode based on via received
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.303343 [DEBUG] sofia.c:7301 Channel sofia/internal/
1002@mydomain.com entering state [received][100]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.303343 [DEBUG] sofia.c:7311 Remote SDP:
b3b38503-5acc-4f6c-994d-b213a4e044cd v=0
b3b38503-5acc-4f6c-994d-b213a4e044cd o=1002 123456 654321 IN IP4 192.168.1.21
b3b38503-5acc-4f6c-994d-b213a4e044cd s=A conversation
b3b38503-5acc-4f6c-994d-b213a4e044cd c=IN IP4 192.168.1.21
b3b38503-5acc-4f6c-994d-b213a4e044cd t=0 0
b3b38503-5acc-4f6c-994d-b213a4e044cd m=audio 7078 RTP/AVP 0 8 101
b3b38503-5acc-4f6c-994d-b213a4e044cd a=rtpmap:0 PCMU/8000/1
b3b38503-5acc-4f6c-994d-b213a4e044cd a=rtpmap:8 PCMA/8000/1
b3b38503-5acc-4f6c-994d-b213a4e044cd a=rtpmap:101 telephone-event/8000/1
b3b38503-5acc-4f6c-994d-b213a4e044cd a=fmtp:101 0-11
b3b38503-5acc-4f6c-994d-b213a4e044cd
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5508 Set telephone-event payload to 101@8000
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:3837 Set Codec sofia/internal/
1002@mydomain.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_codec.c:111 sofia/internal/
1002@mydomain.com Original read codec set to PCMU:0
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5851 Set telephone-event payload to 101@8000
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_media.c:5909 sofia/internal/
1002@mydomain.com Set 2833 dtmf send payload to 101 recv payload to 101
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] sofia.c:7735 (sofia/internal/
1002@mydomain.com) State Change CS_NEW -> CS_INIT
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_INIT (Cur 1 Tot 66207)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/
1002@mydomain.com) State INIT
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] mod_sofia.c:93 sofia/internal/
1002@mydomain.com SOFIA INIT
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_state_machine.c:40 sofia/internal/
1002@mydomain.com Standard INIT
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/
1002@mydomain.com) State Change CS_INIT -> CS_ROUTING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/
1002@mydomain.com) State INIT going to sleep
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_ROUTING (Cur 1 Tot 66207)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_channel.c:2332 (sofia/internal/
1002@mydomain.com) Callstate Change DOWN -> RINGING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/
1002@mydomain.com) State ROUTING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] mod_sofia.c:154 sofia/internal/
1002@mydomain.com SOFIA ROUTING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_core_state_machine.c:236 sofia/internal/
1002@mydomain.com Standard ROUTING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [INFO] mod_dialplan_xml.c:637 Processing 1002 <1002>->6400 in context mydomain.com
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->user_exists] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_exists] () =~ // break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(user_exists=false)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [user_exists]=[false]
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(from_user_exists=true)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [from_user_exists]=[true]
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->caller-details] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(caller_destination=${destination_number}) INLINE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(caller_destination=6400)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [caller_destination]=[6400]
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(caller_id_name=${caller_id_name}) INLINE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(caller_id_name=1002)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [caller_id_name]=[1002]
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(caller_id_number=${caller_id_number})
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->call-direction] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com ANTI-Action export(call_direction=local) INLINE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com export(call_direction=local)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[local]
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->domain-variables] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [domain-variables] () =~ // break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action export(origination_callee_id_name=${destination_number})
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->global-variables] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [global-variables] () =~ // break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->is_loopback] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->user_record] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(from_user_record=)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [from_user_record]=[UNDEF]
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->redial] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [redial] destination_number(6400) =~ /^(redial|\*870)$/ break=on-true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [redial] () =~ // break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->speed_dial] continue=false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [speed_dial] destination_number(6400) =~ /^\*0(.*)$/ break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->default_caller_id] continue=true
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(emergency_caller_id_name=)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.323302 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [emergency_caller_id_name]=[UNDEF]
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(emergency_caller_id_number=)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [emergency_caller_id_number]=[UNDEF]
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [default_caller_id] ${outbound_caller_id_number}() =~ /^$/ break=never
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(outbound_caller_id_name=${default_outbound_caller_id_name}) INLINE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(outbound_caller_id_name=)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [outbound_caller_id_name]=[UNDEF]
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(outbound_caller_id_number=${default_outbound_caller_id_number}) INLINE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(outbound_caller_id_number=)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [outbound_caller_id_number]=[UNDEF]
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->Llamadas_Nacionales] continue=false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [Llamadas_Nacionales] ${user_exists}(false) =~ /false/ break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [Llamadas_Nacionales] ${toll_allow}() =~ /Nacionales/ break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->Llamadas_Europa] continue=false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [Llamadas_Europa] ${user_exists}(false) =~ /false/ break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (FAIL) [Llamadas_Europa] ${toll_allow}() =~ /Europa/ break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com parsing [mydomain.com->Interfonos] continue=
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Regex (PASS) [Interfonos] destination_number(6400) =~ /^6400$/ break=on-false
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action ring_ready()
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action set(ring_group_uuid=d6d63ca5-57ad-460d-bdce-de9a1893c745)
b3b38503-5acc-4f6c-994d-b213a4e044cd Dialplan: sofia/internal/
1002@mydomain.com Action lua(app.lua ring_groups)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/
1002@mydomain.com) State Change CS_ROUTING -> CS_EXECUTE
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/
1002@mydomain.com) State ROUTING going to sleep
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_EXECUTE (Cur 1 Tot 66207)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/
1002@mydomain.com) State EXECUTE
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_sofia.c:209 sofia/internal/
1002@mydomain.com SOFIA EXECUTE
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] switch_core_state_machine.c:329 sofia/internal/
1002@mydomain.com Standard EXECUTE
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(caller_id_number=1002)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [caller_id_number]=[1002]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 14:01:27 +0200)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 14:01:27 +0200]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com export(origination_callee_id_name=6400)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [origination_callee_id_name]=[6400]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 14:01:27 +0200)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 14:01:27 +0200]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 14:01:27 +0200)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 14:01:27 +0200]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 14:01:27 +0200)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 14:01:27 +0200]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 14:01:27 +0200)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 14:01:27 +0200]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(RFC2822_DATE=Sat, 11 Apr 2020 14:01:27 +0200)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [RFC2822_DATE]=[Sat, 11 Apr 2020 14:01:27 +0200]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com hash(insert/mydomain.com-last_dial/1002/6400)
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com ring_ready()
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [NOTICE] mod_sofia.c:2498 Ring-Ready sofia/internal/
1002@mydomain.com!
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] sofia.c:7301 Channel sofia/internal/
1002@mydomain.com entering state [early][180]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [NOTICE] mod_dptools.c:1122 Ring Ready sofia/internal/
1002@mydomain.com!
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(ring_group_uuid=d6d63ca5-57ad-460d-bdce-de9a1893c745)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [ring_group_uuid]=[d6d63ca5-57ad-460d-bdce-de9a1893c745]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com lua(app.lua ring_groups)
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com ring_ready()
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [NOTICE] mod_dptools.c:1122 Ring Ready sofia/internal/
1002@mydomain.com!
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.343299 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(call_timeout, 300)
2020-04-11 14:01:27.383304 [NOTICE] switch_cpp.cpp:1443 [ring group] domain_name: mydomain.com
2020-04-11 14:01:27.383304 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_number: 1000
2020-04-11 14:01:27.383304 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_delay: 0
2020-04-11 14:01:27.383304 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_timeout: 30
2020-04-11 14:01:27.383304 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_prompt:
2020-04-11 14:01:27.383304 [NOTICE] switch_cpp.cpp:1443 [ring group] domain_name: mydomain.com
2020-04-11 14:01:27.383304 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_number: 1001
2020-04-11 14:01:27.383304 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_delay: 0
2020-04-11 14:01:27.383304 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_timeout: 30
2020-04-11 14:01:27.383304 [NOTICE] switch_cpp.cpp:1443 [ring group] destination_prompt:
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.404972 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(ringback, tone_stream://%(1500,3000,425);loops=-1)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.404972 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(transfer_ringback, tone_stream://%(1500,3000,425);loops=-1)
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(uuids=33a86e03-e1e9-46c4-bf43-ae362688fbf0)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.404972 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [uuids]=[33a86e03-e1e9-46c4-bf43-ae362688fbf0]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com export(sip_h_Alert-Info=)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.404972 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(group_confirm_key=exec)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.404972 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [group_confirm_key]=[exec]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.404972 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(ringback, tone_stream://%(1500,3000,425);loops=-1)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable(transfer_ringback, tone_stream://%(1500,3000,425);loops=-1)
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(uuids=33a86e03-e1e9-46c4-bf43-ae362688fbf0,3b3b2136-97f9-4648-838e-f2149311d66c)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [uuids]=[33a86e03-e1e9-46c4-bf43-ae362688fbf0,3b3b2136-97f9-4648-838e-f2149311d66c]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com export(sip_h_Alert-Info=)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(group_confirm_key=exec)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [group_confirm_key]=[exec]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(ignore_early_media=true)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [ignore_early_media]=[true]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(hangup_after_bridge=true)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [hangup_after_bridge]=[true]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com set(continue_on_fail=true)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] mod_dptools.c:1672 SET sofia/internal/
1002@mydomain.com [continue_on_fail]=[true]
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com bind_digit_action(local,*2,exec:record_session,/var/lib/freeswitch/recordings/mydomain.com/archive/2020/Apr/11/b3b38503-5acc-4f6c-994d-b213a4e044cd.wav,both)
2020-04-11 14:01:27.423301 [INFO] switch_ivr_async.c:219 Digit parser DPTOOLS: Setting realm to 'local'
2020-04-11 14:01:27.423301 [DEBUG] switch_ivr_async.c:344 Digit parser DPTOOLS: binding *2/local/0 callback: 0x7f284a956e00 data: 0x7f283c0978f0
2020-04-11 14:01:27.423301 [INFO] switch_ivr_async.c:219 Digit parser DPTOOLS: Setting realm to 'local'
2020-04-11 14:01:27.423301 [DEBUG] switch_ivr_async.c:344 Digit parser DPTOOLS: binding *2/local/0 callback: 0x7f284a956e00 data: 0x7f283c0979e0
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com digit_action_set_realm(local)
2020-04-11 14:01:27.423301 [INFO] switch_ivr_async.c:219 Digit parser DPTOOLS: Setting realm to 'local'
2020-04-11 14:01:27.423301 [NOTICE] switch_cpp.cpp:1443 [ring group] app_data: {ignore_early_media=true}[sip_invite_domain=mydomain.com,domain_name=mydomain.com,call_direction=local,confirm=false,leg_timeout=30,leg_delay_start=0,dialed_extension=1000,extension_uuid=e74c05ca-3950-4297-9dff-d149d632c7a0]user/
1000@mydomain.com,[sip_invite_domain=mydomain.com,domain_name=mydomain.com,call_direction=local,confirm=false,leg_timeout=30,leg_delay_start=0,dialed_extension=1001,extension_uuid=4ebb4289-c2c6-42b9-bbd8-62224dfd631c]user/
1001@mydomain.com
b3b38503-5acc-4f6c-994d-b213a4e044cd EXECUTE [depth=0] sofia/internal/
1002@mydomain.com bridge({ignore_early_media=true}[sip_invite_domain=mydomain.com,domain_name=mydomain.com,call_direction=local,confirm=false,leg_timeout=30,leg_delay_start=0,dialed_extension=1000,extension_uuid=e74c05ca-3950-4297-9dff-d149d632c7a0]user/
1000@mydomain.com,[sip_invite_domain=mydomain.com,domain_name=mydomain.com,call_direction=local,confirm=false,leg_timeout=30,leg_delay_start=0,dialed_extension=1001,extension_uuid=4ebb4289-c2c6-42b9-bbd8-62224dfd631c]user/
1001@mydomain.com)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [domain_name]=[mydomain.com] to event
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [call_direction]=[local] to event
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [origination_callee_id_name]=[6400] to event
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.423301 [DEBUG] switch_ivr_originate.c:2760 Parsing session specific variables
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [domain_name]=[mydomain.com] to event
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [call_direction]=[local] to event
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [origination_callee_id_name]=[6400] to event
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/1000@192.168.1.23:5060 [63e2e7cf-bc64-4ed3-9eea-be55fda712c8]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] mod_sofia.c:5089 (sofia/internal/1000@192.168.1.23:5060) State Change CS_NEW -> CS_INIT
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_ivr_originate.c:3067 sofia/internal/1000@192.168.1.23:5060 Setting leg timeout to 30
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_ivr_originate.c:3067 sofia/internal/1000@192.168.1.23:5060 Setting leg timeout to 30
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_ivr_originate.c:2760 Parsing session specific variables
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [domain_name]=[mydomain.com] to event
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [call_direction]=[local] to event
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_channel.c:1264 sofia/internal/
1002@mydomain.com EXPORTING[export_vars] [origination_callee_id_name]=[6400] to event
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/1001@192.168.1.43:42032 [fee04115-f13b-4306-9540-eb972e56032e]
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] mod_sofia.c:5089 (sofia/internal/1001@192.168.1.43:42032) State Change CS_NEW -> CS_INIT
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_ivr_originate.c:3067 sofia/internal/1001@192.168.1.43:42032 Setting leg timeout to 30
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.443304 [DEBUG] switch_ivr_originate.c:3067 sofia/internal/1001@192.168.1.43:42032 Setting leg timeout to 30
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_INIT (Cur 3 Tot 66209)
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/1000@192.168.1.23:5060) State INIT
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] mod_sofia.c:93 sofia/internal/1000@192.168.1.23:5060 SOFIA INIT
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] sofia_glue.c:1587 sip:1000@CLIENTEXTERNALIP:54390;transport=tcp Setting proxy route to sofia/internal/1000@192.168.1.23:5060
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] sofia_glue.c:1618 sofia/internal/1000@192.168.1.23:5060 sending invite version: 1.10.2 -release-14-f7bdd3845a 64bit
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 Local SDP:
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 v=0
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 o=FreeSWITCH 1586587085 1586587086 IN IP4 FUSIONPBXIP
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 s=FreeSWITCH
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 c=IN IP4 FUSIONPBXIP
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 t=0 0
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 m=audio 19402 RTP/AVP 0 18 9 8 101 13
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:0 PCMU/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:18 G729/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:9 G722/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:8 PCMA/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:101 telephone-event/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=fmtp:101 0-16
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:13 CN/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=ptime:20
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=sendrecv
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 m=video 23884 RTP/AVP 102
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 b=AS:1024
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:102 H264/90000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=sendrecv
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtcp-fb:102 ccm fir
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtcp-fb:102 ccm tmmbr
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtcp-fb:102 nack
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtcp-fb:102 nack pli
63e2e7cf-bc64-4ed3-9eea-be55fda712c8
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.1.23:5060 Standard INIT
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.1.23:5060) State Change CS_INIT -> CS_ROUTING
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/1000@192.168.1.23:5060) State INIT going to sleep
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_ROUTING (Cur 3 Tot 66209)
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] sofia.c:7301 Channel sofia/internal/1000@192.168.1.23:5060 entering state [calling][0]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/1000@192.168.1.23:5060) State ROUTING
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] mod_sofia.c:154 sofia/internal/1000@192.168.1.23:5060 SOFIA ROUTING
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@192.168.1.23:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/1000@192.168.1.23:5060) State ROUTING going to sleep
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 66209)
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/1000@192.168.1.23:5060) State CONSUME_MEDIA
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/1000@192.168.1.23:5060) State CONSUME_MEDIA going to sleep
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1001@192.168.1.43:42032) Running State Change CS_INIT (Cur 3 Tot 66209)
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/1001@192.168.1.43:42032) State INIT
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] mod_sofia.c:93 sofia/internal/1001@192.168.1.43:42032 SOFIA INIT
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] sofia_glue.c:1587 sip:1001@CLIENTEXTERNALIP:42032;transport=tcp Setting proxy route to sofia/internal/1001@192.168.1.43:42032
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] sofia_glue.c:1618 sofia/internal/1001@192.168.1.43:42032 sending invite version: 1.10.2 -release-14-f7bdd3845a 64bit
fee04115-f13b-4306-9540-eb972e56032e Local SDP:
fee04115-f13b-4306-9540-eb972e56032e v=0
fee04115-f13b-4306-9540-eb972e56032e o=FreeSWITCH 1586587115 1586587116 IN IP4 FUSIONPBXIP
fee04115-f13b-4306-9540-eb972e56032e s=FreeSWITCH
fee04115-f13b-4306-9540-eb972e56032e c=IN IP4 FUSIONPBXIP
fee04115-f13b-4306-9540-eb972e56032e t=0 0
fee04115-f13b-4306-9540-eb972e56032e m=audio 19372 RTP/AVP 0 18 9 8 101 13
fee04115-f13b-4306-9540-eb972e56032e a=rtpmap:0 PCMU/8000
fee04115-f13b-4306-9540-eb972e56032e a=rtpmap:18 G729/8000
fee04115-f13b-4306-9540-eb972e56032e a=rtpmap:9 G722/8000
fee04115-f13b-4306-9540-eb972e56032e a=rtpmap:8 PCMA/8000
fee04115-f13b-4306-9540-eb972e56032e a=rtpmap:101 telephone-event/8000
fee04115-f13b-4306-9540-eb972e56032e a=fmtp:101 0-16
fee04115-f13b-4306-9540-eb972e56032e a=rtpmap:13 CN/8000
fee04115-f13b-4306-9540-eb972e56032e a=ptime:20
fee04115-f13b-4306-9540-eb972e56032e a=sendrecv
fee04115-f13b-4306-9540-eb972e56032e m=video 28612 RTP/AVP 102
fee04115-f13b-4306-9540-eb972e56032e b=AS:1024
fee04115-f13b-4306-9540-eb972e56032e a=rtpmap:102 H264/90000
fee04115-f13b-4306-9540-eb972e56032e a=sendrecv
fee04115-f13b-4306-9540-eb972e56032e a=rtcp-fb:102 ccm fir
fee04115-f13b-4306-9540-eb972e56032e a=rtcp-fb:102 ccm tmmbr
fee04115-f13b-4306-9540-eb972e56032e a=rtcp-fb:102 nack
fee04115-f13b-4306-9540-eb972e56032e a=rtcp-fb:102 nack pli
fee04115-f13b-4306-9540-eb972e56032e
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@192.168.1.43:42032 Standard INIT
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@192.168.1.43:42032) State Change CS_INIT -> CS_ROUTING
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/1001@192.168.1.43:42032) State INIT going to sleep
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1001@192.168.1.43:42032) Running State Change CS_ROUTING (Cur 3 Tot 66209)
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] sofia.c:7301 Channel sofia/internal/1001@192.168.1.43:42032 entering state [calling][0]
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/1001@192.168.1.43:42032) State ROUTING
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] mod_sofia.c:154 sofia/internal/1001@192.168.1.43:42032 SOFIA ROUTING
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1001@192.168.1.43:42032) State Change CS_ROUTING -> CS_CONSUME_MEDIA
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/1001@192.168.1.43:42032) State ROUTING going to sleep
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1001@192.168.1.43:42032) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 66209)
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/1001@192.168.1.43:42032) State CONSUME_MEDIA
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:27.443304 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/1001@192.168.1.43:42032) State CONSUME_MEDIA going to sleep
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.603302 [DEBUG] sofia.c:7301 Channel sofia/internal/1000@192.168.1.23:5060 entering state [proceeding][180]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.603302 [NOTICE] sofia.c:7412 Ring-Ready sofia/internal/1000@192.168.1.23:5060!
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:27.603302 [DEBUG] switch_channel.c:3437 (sofia/internal/1000@192.168.1.23:5060) Callstate Change DOWN -> RINGING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.603302 [INFO] switch_ivr_originate.c:1246 Sending early media
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.603302 [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/internal/
1002@mydomain.com] FUSIONPBXIP port 27076 -> 192.168.1.21 port 7078 codec: 0 ms: 20
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.603302 [DEBUG] switch_rtp.c:4408 Starting timer [soft] 160 bytes per 20ms
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.623294 [DEBUG] switch_core_media.c:8973 sofia/internal/
1002@mydomain.com Set 2833 dtmf send payload to 101
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.623294 [DEBUG] switch_core_media.c:8980 sofia/internal/
1002@mydomain.com Set 2833 dtmf receive payload to 101
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.623294 [DEBUG] switch_core_media.c:9003 sofia/internal/
1002@mydomain.com Set rtp dtmf delay to 40
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.623294 [DEBUG] mod_sofia.c:2593 Ring SDP:
b3b38503-5acc-4f6c-994d-b213a4e044cd v=0
b3b38503-5acc-4f6c-994d-b213a4e044cd o=FreeSWITCH 1586579411 1586579412 IN IP4 FUSIONPBXIP
b3b38503-5acc-4f6c-994d-b213a4e044cd s=FreeSWITCH
b3b38503-5acc-4f6c-994d-b213a4e044cd c=IN IP4 FUSIONPBXIP
b3b38503-5acc-4f6c-994d-b213a4e044cd t=0 0
b3b38503-5acc-4f6c-994d-b213a4e044cd m=audio 27076 RTP/AVP 0 101
b3b38503-5acc-4f6c-994d-b213a4e044cd a=rtpmap:0 PCMU/8000
b3b38503-5acc-4f6c-994d-b213a4e044cd a=rtpmap:101 telephone-event/8000
b3b38503-5acc-4f6c-994d-b213a4e044cd a=fmtp:101 0-16
b3b38503-5acc-4f6c-994d-b213a4e044cd a=ptime:20
b3b38503-5acc-4f6c-994d-b213a4e044cd a=sendrecv
b3b38503-5acc-4f6c-994d-b213a4e044cd
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.623294 [NOTICE] mod_sofia.c:2596 Pre-Answer sofia/internal/
1002@mydomain.com!
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.623294 [DEBUG] switch_channel.c:3565 (sofia/internal/
1002@mydomain.com) Callstate Change RINGING -> EARLY
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.623294 [DEBUG] sofia.c:7301 Channel sofia/internal/
1002@mydomain.com entering state [early][183]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.623294 [DEBUG] switch_ivr_originate.c:1304 Raw Codec Activation Success L16@8000hz 1 channel 20ms
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.623294 [DEBUG] switch_core_codec.c:223 sofia/internal/
1002@mydomain.com Push codec L16:100
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:27.623294 [DEBUG] switch_ivr_originate.c:1336 Play Ringback File [tone_stream://%(1500,3000,425);loops=-1]
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:28.003328 [DEBUG] sofia.c:7301 Channel sofia/internal/1001@192.168.1.43:42032 entering state [proceeding][180]
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:28.003328 [NOTICE] sofia.c:7412 Ring-Ready sofia/internal/1001@192.168.1.43:42032!
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:28.003328 [DEBUG] switch_channel.c:3437 (sofia/internal/1001@192.168.1.43:42032) Callstate Change DOWN -> RINGING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:28.583346 [INFO] switch_rtp.c:7680 Auto Changing audio port from 192.168.1.21:7078 to CLIENTEXTERNALIP:7078
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] sofia.c:7301 Channel sofia/internal/1000@192.168.1.23:5060 entering state [completing][200]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] sofia.c:7311 Remote SDP:
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 v=0
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 o=1000 8000 8000 IN IP4 192.168.1.23
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 s=SIP Call
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 c=IN IP4 192.168.1.23
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 t=0 0
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 m=audio 5004 RTP/AVP 0 18 9 8 101
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:0 PCMU/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:18 G729/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:9 G722/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:8 PCMA/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:101 telephone-event/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=fmtp:101 0-15
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=ptime:20
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 m=video 0 RTP/AVP 102
63e2e7cf-bc64-4ed3-9eea-be55fda712c8
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] sofia.c:7301 Channel sofia/internal/1000@192.168.1.23:5060 entering state [ready][200]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G722:9:8000:20:64000:1]/[G729:18:8000:20:8000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5508 Set telephone-event payload to 101@8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:3837 Set Codec sofia/internal/1000@192.168.1.23:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@192.168.1.23:5060 Original read codec set to PCMU:0
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5851 Set telephone-event payload to 101@8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:5909 sofia/internal/1000@192.168.1.23:5060 Set 2833 dtmf send payload to 101 recv payload to 101
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/internal/1000@192.168.1.23:5060] FUSIONPBXIP port 19402 -> 192.168.1.23 port 5004 codec: 0 ms: 20
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_rtp.c:4408 Starting timer [soft] 160 bytes per 20ms
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:8973 sofia/internal/1000@192.168.1.23:5060 Set 2833 dtmf send payload to 101
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:8980 sofia/internal/1000@192.168.1.23:5060 Set 2833 dtmf receive payload to 101
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_core_media.c:9003 sofia/internal/1000@192.168.1.23:5060 Set rtp dtmf delay to 40
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [NOTICE] sofia.c:8479 Channel [sofia/internal/1000@192.168.1.23:5060] has been answered
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.823312 [DEBUG] switch_channel.c:3865 (sofia/internal/1000@192.168.1.23:5060) Callstate Change RINGING -> ACTIVE
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 EXECUTE [depth=0] sofia/internal/1000@192.168.1.23:5060 lua(/usr/share/freeswitch/scripts/confirm.lua)
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.843302 [DEBUG] switch_cpp.cpp:1187 sofia/internal/1000@192.168.1.23:5060 destroy/unlink session from object
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:30.843302 [DEBUG] switch_core_codec.c:248 sofia/internal/
1002@mydomain.com Restore previous codec PCMU:0.
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.843302 [NOTICE] switch_ivr_originate.c:3716 Hangup sofia/internal/1001@192.168.1.43:42032 [CS_CONSUME_MEDIA] [LOSE_RACE]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:30.843302 [DEBUG] switch_core_media.c:8641 Audio params are unchanged for sofia/internal/
1002@mydomain.com.
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:30.843302 [DEBUG] mod_sofia.c:898 Local SDP sofia/internal/
1002@mydomain.com:
b3b38503-5acc-4f6c-994d-b213a4e044cd v=0
b3b38503-5acc-4f6c-994d-b213a4e044cd o=FreeSWITCH 1586579411 1586579413 IN IP4 FUSIONPBXIP
b3b38503-5acc-4f6c-994d-b213a4e044cd s=FreeSWITCH
b3b38503-5acc-4f6c-994d-b213a4e044cd c=IN IP4 FUSIONPBXIP
b3b38503-5acc-4f6c-994d-b213a4e044cd t=0 0
b3b38503-5acc-4f6c-994d-b213a4e044cd m=audio 27076 RTP/AVP 0 101
b3b38503-5acc-4f6c-994d-b213a4e044cd a=rtpmap:0 PCMU/8000
b3b38503-5acc-4f6c-994d-b213a4e044cd a=rtpmap:101 telephone-event/8000
b3b38503-5acc-4f6c-994d-b213a4e044cd a=fmtp:101 0-16
b3b38503-5acc-4f6c-994d-b213a4e044cd a=ptime:20
b3b38503-5acc-4f6c-994d-b213a4e044cd a=sendrecv
b3b38503-5acc-4f6c-994d-b213a4e044cd
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:30.863506 [DEBUG] sofia.c:7301 Channel sofia/internal/
1002@mydomain.com entering state [completed][200]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:30.863506 [NOTICE] switch_ivr_originate.c:3751 Channel [sofia/internal/
1002@mydomain.com] has been answered
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:30.863506 [DEBUG] switch_channel.c:3865 (sofia/internal/
1002@mydomain.com) Callstate Change EARLY -> ACTIVE
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:30.863506 [DEBUG] switch_ivr_originate.c:3809 Originate Resulted in Success: [sofia/internal/1000@192.168.1.23:5060]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.863506 [DEBUG] switch_ivr_bridge.c:1796 (sofia/internal/1000@192.168.1.23:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1001@192.168.1.43:42032) Running State Change CS_HANGUP (Cur 3 Tot 66209)
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/1001@192.168.1.43:42032) Callstate Change RINGING -> HANGUP
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1001@192.168.1.43:42032) State HANGUP
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] mod_sofia.c:453 Channel sofia/internal/1001@192.168.1.43:42032 hanging up, cause: LOSE_RACE
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] mod_sofia.c:521 Sending CANCEL to sofia/internal/1001@192.168.1.43:42032
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001@192.168.1.43:42032 Standard HANGUP, cause: LOSE_RACE
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1001@192.168.1.43:42032) State HANGUP going to sleep
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/1001@192.168.1.43:42032) State Change CS_HANGUP -> CS_REPORTING
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1001@192.168.1.43:42032) Running State Change CS_REPORTING (Cur 3 Tot 66209)
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/1001@192.168.1.43:42032) State REPORTING
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1001@192.168.1.43:42032 Standard REPORTING, cause: LOSE_RACE
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/1001@192.168.1.43:42032) State REPORTING going to sleep
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/1001@192.168.1.43:42032) State Change CS_REPORTING -> CS_DESTROY
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_session.c:1726 Session 66209 (sofia/internal/1001@192.168.1.43:42032) Locked, Waiting on external entities
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [NOTICE] switch_core_session.c:1744 Session 66209 (sofia/internal/1001@192.168.1.43:42032) Ended
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/1001@192.168.1.43:42032 [CS_DESTROY]
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/1001@192.168.1.43:42032) Running State Change CS_DESTROY (Cur 2 Tot 66209)
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/1001@192.168.1.43:42032) State DESTROY
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] mod_sofia.c:364 sofia/internal/1001@192.168.1.43:42032 SOFIA DESTROY
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1001@192.168.1.43:42032 Standard DESTROY
fee04115-f13b-4306-9540-eb972e56032e 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/1001@192.168.1.43:42032) State DESTROY going to sleep
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 66209)
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.863506 [DEBUG] switch_core_state_machine.c:654 (sofia/internal/1000@192.168.1.23:5060) State EXCHANGE_MEDIA
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:30.863506 [DEBUG] mod_sofia.c:656 SOFIA EXCHANGE_MEDIA
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:30.883329 [DEBUG] switch_rtp.c:7720 Correct audio ip/port confirmed.
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.203339 [INFO] switch_rtp.c:7680 Auto Changing audio port from 192.168.1.23:5004 to CLIENTEXTERNALIP:5004
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:31.303320 [DEBUG] sofia.c:7301 Channel sofia/internal/
1002@mydomain.com entering state [ready][200]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.323307 [DEBUG] sofia.c:7301 Channel sofia/internal/1000@192.168.1.23:5060 entering state [calling][0]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] sofia.c:7301 Channel sofia/internal/1000@192.168.1.23:5060 entering state [ready][200]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] sofia.c:7311 Remote SDP:
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 v=0
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 o=1000 8000 8001 IN IP4 192.168.1.23
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 s=SIP Call
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 c=IN IP4 192.168.1.23
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 t=0 0
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 m=audio 5004 RTP/AVP 0 18 9 8 101
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:0 PCMU/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:18 G729/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:9 G722/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:8 PCMA/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=rtpmap:101 telephone-event/8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=fmtp:101 0-15
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 a=ptime:20
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 m=video 0 RTP/AVP 102
63e2e7cf-bc64-4ed3-9eea-be55fda712c8
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G722:9:8000:20:64000:1]/[G729:18:8000:20:8000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5508 Set telephone-event payload to 101@8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5851 Set telephone-event payload to 101@8000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:5909 sofia/internal/1000@192.168.1.23:5060 Set 2833 dtmf send payload to 101 recv payload to 101
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] sofia.c:8320 Processing updated SDP
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.743310 [DEBUG] switch_core_media.c:8641 Audio params are unchanged for sofia/internal/1000@192.168.1.23:5060.
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.923339 [DEBUG] switch_rtp.c:7963 RTP RECV DTMF 1:1280
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.923339 [INFO] switch_channel.c:522 RECV DTMF 1:1280
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.923339 [DEBUG] mod_dptools.c:132 sofia/internal/1000@192.168.1.23:5060 Digit NOT match binding [1]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.923339 [INFO] switch_channel.c:522 RECV DTMF 1:2000
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:31.923339 [DEBUG] switch_channel.c:618 sofia/internal/1000@192.168.1.23:5060 Queue dtmf
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 digit=1 ms=250 samples=2000
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:31.923339 [DEBUG] switch_rtp.c:5542 Send start packet for [1] ts=6240 dur=160/160/2000 seq=53567 lw=6240
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:31.943310 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=320/320/2000 seq=53568 lw=6400
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:31.963306 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=480/480/2000 seq=53569 lw=6560
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:31.983305 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=640/640/2000 seq=53570 lw=6720
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.003307 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=800/800/2000 seq=53571 lw=6880
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.023305 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=960/960/2000 seq=53572 lw=7040
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.043306 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=1120/1120/2000 seq=53573 lw=7200
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.063305 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=1280/1280/2000 seq=53574 lw=7360
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.083305 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=1440/1440/2000 seq=53575 lw=7520
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.103306 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=1600/1600/2000 seq=53576 lw=7680
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.123307 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=1760/1760/2000 seq=53577 lw=7840
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.143304 [DEBUG] switch_rtp.c:5441 Send middle packet for [1] ts=6240 dur=1920/1920/2000 seq=53578 lw=8000
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.163305 [DEBUG] switch_rtp.c:5441 Send end packet for [1] ts=6240 dur=2080/2080/2000 seq=53579 lw=8000
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.163305 [DEBUG] switch_rtp.c:5441 Send end packet for [1] ts=6240 dur=2080/2080/2000 seq=53580 lw=8000
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.163305 [DEBUG] switch_rtp.c:5441 Send end packet for [1] ts=6240 dur=2080/2080/2000 seq=53581 lw=8000
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:32.163305 [DEBUG] switch_rtp.c:5389 Queue digit delay of 40ms
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [NOTICE] sofia.c:1089 Hangup sofia/internal/1000@192.168.1.23:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_ivr_bridge.c:915 BRIDGE THREAD DONE [sofia/internal/1000@192.168.1.23:5060]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:654 (sofia/internal/1000@192.168.1.23:5060) State EXCHANGE_MEDIA going to sleep
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_HANGUP (Cur 2 Tot 66209)
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/1000@192.168.1.23:5060) Callstate Change ACTIVE -> HANGUP
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.1.23:5060) State HANGUP
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] mod_sofia.c:453 Channel sofia/internal/1000@192.168.1.23:5060 hanging up, cause: NORMAL_CLEARING
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.1.23:5060 Standard HANGUP, cause: NORMAL_CLEARING
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.1.23:5060) State HANGUP going to sleep
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/1000@192.168.1.23:5060) State Change CS_HANGUP -> CS_REPORTING
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_REPORTING (Cur 2 Tot 66209)
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/1000@192.168.1.23:5060) State REPORTING
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@192.168.1.23:5060 Standard REPORTING, cause: NORMAL_CLEARING
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/1000@192.168.1.23:5060) State REPORTING going to sleep
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/1000@192.168.1.23:5060) State Change CS_REPORTING -> CS_DESTROY
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.003328 [DEBUG] switch_core_session.c:1726 Session 66208 (sofia/internal/1000@192.168.1.23:5060) Locked, Waiting on external entities
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.003328 [DEBUG] switch_ivr_bridge.c:823 sofia/internal/1000@192.168.1.23:5060 ending bridge by request from write function
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.003328 [DEBUG] switch_ivr_bridge.c:915 BRIDGE THREAD DONE [sofia/internal/
1002@mydomain.com]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.003328 [NOTICE] switch_ivr_bridge.c:1947 Hangup sofia/internal/
1002@mydomain.com [CS_EXECUTE] [NORMAL_CLEARING]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_session.c:2905 sofia/internal/
1002@mydomain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_cpp.cpp:1187 sofia/internal/
1002@mydomain.com destroy/unlink session from object
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_session.c:2905 sofia/internal/
1002@mydomain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/
1002@mydomain.com) State EXECUTE going to sleep
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_HANGUP (Cur 2 Tot 66209)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/
1002@mydomain.com) Callstate Change ACTIVE -> HANGUP
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/
1002@mydomain.com) State HANGUP
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] mod_sofia.c:447 sofia/internal/
1002@mydomain.com Overriding SIP cause 480 with 200 from the other leg
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] mod_sofia.c:453 Channel sofia/internal/
1002@mydomain.com hanging up, cause: NORMAL_CLEARING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] mod_sofia.c:507 Sending BYE to sofia/internal/
1002@mydomain.com
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:60 sofia/internal/
1002@mydomain.com Standard HANGUP, cause: NORMAL_CLEARING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/
1002@mydomain.com) State HANGUP going to sleep
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/
1002@mydomain.com) State Change CS_HANGUP -> CS_REPORTING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/
1002@mydomain.com) Running State Change CS_REPORTING (Cur 2 Tot 66209)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/
1002@mydomain.com) State REPORTING
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.023301 [NOTICE] switch_core_session.c:1744 Session 66208 (sofia/internal/1000@192.168.1.23:5060) Ended
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.023301 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/1000@192.168.1.23:5060 [CS_DESTROY]
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/1000@192.168.1.23:5060) Running State Change CS_DESTROY (Cur 1 Tot 66209)
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/1000@192.168.1.23:5060) State DESTROY
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.023301 [DEBUG] mod_sofia.c:364 sofia/internal/1000@192.168.1.23:5060 SOFIA DESTROY
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@192.168.1.23:5060 Standard DESTROY
63e2e7cf-bc64-4ed3-9eea-be55fda712c8 2020-04-11 14:01:34.023301 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/1000@192.168.1.23:5060) State DESTROY going to sleep
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [DEBUG] switch_core_state_machine.c:174 sofia/internal/
1002@mydomain.com Standard REPORTING, cause: NORMAL_CLEARING
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/
1002@mydomain.com) State REPORTING going to sleep
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/
1002@mydomain.com) State Change CS_REPORTING -> CS_DESTROY
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [DEBUG] switch_core_session.c:1726 Session 66207 (sofia/internal/
1002@mydomain.com) Locked, Waiting on external entities
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [NOTICE] switch_core_session.c:1744 Session 66207 (sofia/internal/
1002@mydomain.com) Ended
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/
1002@mydomain.com [CS_DESTROY]
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/
1002@mydomain.com) Running State Change CS_DESTROY (Cur 0 Tot 66209)
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/
1002@mydomain.com) State DESTROY
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [DEBUG] mod_sofia.c:364 sofia/internal/
1002@mydomain.com SOFIA DESTROY
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [DEBUG] switch_core_state_machine.c:181 sofia/internal/
1002@mydomain.com Standard DESTROY
b3b38503-5acc-4f6c-994d-b213a4e044cd 2020-04-11 14:01:34.103302 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/
1002@mydomain.com) State DESTROY going to sleep