Ring group strategy

Status
Not open for further replies.
V

vivoras

New Member
Feb 23, 2020
5
1
3
38
I read in the fusionpbx docs that the destinations in a ring group can only be local registered endpoints or external numbers. But if one of the extensions is not registered, the other extensions do not ring. Is there a way to fix this? I have tried the ring strategy in simultaneous and enterprise
 
V

vivoras

New Member
Feb 23, 2020
5
1
3
38
DigitalDaz said:
This should not be the case, post a log.
Click to expand...

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
 
DigitalDaz

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,045
566
113
On the first one that failed, it failed with ALLOTTED TIMEOUT. It looks like it was sending to extension 1000 and then gacve up due to no answer: [DEBUG] mod_sofia.c:521 Sending CANCEL to sofia/internal/1000@192.168.1.23:5060
 
Status
Not open for further replies.
Top Bottom