span style="color: cornflowerblue; font-weight: bold;"> dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [NOTICE] switch_channel.c:1118 New Channel sofia/external/100@hpbx043.telecomsvc.com [dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_NEW (Cur 1 Tot 99)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] sofia.c:10280 sofia/external/100@hpbx043.telecomsvc.com receiving invite from 72.53.173.29:5060 version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [received][100]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] sofia.c:7336 Remote SDP:
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a v=0
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a o=- 1 1 IN IP4 72.53.173.29
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a s=SIP call
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a c=IN IP4 72.53.173.29
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a t=0 0
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=sendrecv
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a m=audio 60342 RTP/AVP 9 0 18 8 101
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=rtpmap:9 G722/8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=rtpmap:0 PCMU/8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=rtpmap:18 G729/8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=fmtp:18 annexb=no
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=rtpmap:8 PCMA/8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=rtpmap:101 telephone-event/8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=ptime:20
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] sofia.c:7739 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_NEW -> CS_INIT
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:604 (sofia/external/100@hpbx043.telecomsvc.com) State NEW
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_INIT (Cur 1 Tot 99)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:628 (sofia/external/100@hpbx043.telecomsvc.com) State INIT
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] mod_sofia.c:93 sofia/external/100@hpbx043.telecomsvc.com SOFIA INIT
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:40 sofia/external/100@hpbx043.telecomsvc.com Standard INIT
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:48 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_INIT -> CS_ROUTING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:628 (sofia/external/100@hpbx043.telecomsvc.com) State INIT going to sleep
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_ROUTING (Cur 1 Tot 99)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_channel.c:2332 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change DOWN -> RINGING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:644 (sofia/external/100@hpbx043.telecomsvc.com) State ROUTING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] mod_sofia.c:154 sofia/external/100@hpbx043.telecomsvc.com SOFIA ROUTING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:236 sofia/external/100@hpbx043.telecomsvc.com Standard ROUTING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [INFO] mod_dialplan_xml.c:637 Processing Jim Concannon <100>->5031 in context public
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->unloop] continue=false
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->outside_call] continue=true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Absolute Condition [outside_call]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(outside_call=true)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action log(CRIT ***** naked in public from ${sip_from_user} to ${destination_number} ***** )
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action log(CRIT ***** caller_name = ${caller_id_name}; ICLID = ${caller_id_number} ***** )
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->from Consumer Celluloid] continue=true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [from Consumer Celluloid] ${caller_id_number}(100) =~ /^(19542352653)$/ break=never
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->junk block] continue=false
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${sip_to_user}(65749684) =~ /obi_fjh/ break=never
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_name}(Jim Concannon) =~ /^V\d+/ break=on-true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_name}(Jim Concannon) =~ /[Pp]olice[Oo]fficer\d+/ break=on-true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(923008355903)$/ break=on-true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(14156358962)$/ break=on-true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(17542193980)$/ break=on-true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(13012881384)$/ break=on-true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(1408689\d{4})$/ break=on-true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->callcentric_did] continue=false
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [callcentric_did] ${sip_to_user}(65749684) =~ /^(12023809008)$/ break=on-true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->Jim Concannon] continue=false
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (PASS) [Jim Concannon] ${destination_number}(5031) =~ /^(5031)$/ break=never
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (PASS) [Jim Concannon] ${sip_from_user}(100) =~ /^(100)$/ break=on-true
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action log(CRIT ***** JIM CONCANNON EXT100 from ${sip_from_user} to ${destination_number} ***** )
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(ringback=${us-ring})
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(call_timeout=48)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(hangup_after_bridge=true)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(continue_on_fail=true)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action bridge(${sofia_contact(user/2104)},${sofia_contact(user/2107)},${sofia_contact(user/2103)},${sofia_contact(user/2105)}:_:{sip_cid_type=rpid,ignore_early_media=true}sofia/gateway/callcentric/19542352653)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:287 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_ROUTING -> CS_EXECUTE
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:644 (sofia/external/100@hpbx043.telecomsvc.com) State ROUTING going to sleep
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_EXECUTE (Cur 1 Tot 99)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:651 (sofia/external/100@hpbx043.telecomsvc.com) State EXECUTE
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] mod_sofia.c:209 sofia/external/100@hpbx043.telecomsvc.com SOFIA EXECUTE
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:329 sofia/external/100@hpbx043.telecomsvc.com Standard EXECUTE
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(outside_call=true)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [outside_call]=[true]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com export(RFC2822_DATE=Mon, 30 Jan 2023 11:10:30 -0500)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [RFC2822_DATE]=[Mon, 30 Jan 2023 11:10:30 -0500]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com log(CRIT ***** naked in public from 100 to 5031 ***** )
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [CRIT] mod_dptools.c:1866 ***** naked in public from 100 to 5031 *****
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com log(CRIT ***** caller_name = Jim Concannon; ICLID = 100 ***** )
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [CRIT] mod_dptools.c:1866 ***** caller_name = Jim Concannon; ICLID = 100 *****
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com log(CRIT ***** JIM CONCANNON EXT100 from 100 to 5031 ***** )
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [CRIT] mod_dptools.c:1866 ***** JIM CONCANNON EXT100 from 100 to 5031 *****
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(ringback=%(2000,4000,440,480))
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [ringback]=[%(2000,4000,440,480)]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(call_timeout=48)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [call_timeout]=[48]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(hangup_after_bridge=true)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [hangup_after_bridge]=[true]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(continue_on_fail=true)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [continue_on_fail]=[true]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com bridge(error/user_not_registered,sofia/internal/sip:2107@192.168.65.94,error/user_not_registered,error/user_not_registered:_:{sip_cid_type=rpid,ignore_early_media=true}sofia/gateway/callcentric/19542352653)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_channel.c:1264 sofia/external/100@hpbx043.telecomsvc.com EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 30 Jan 2023 11:10:30 -0500] to event
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_ivr_originate.c:1618 Parsing ultra-global variables
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [INFO] switch_ivr_originate.c:1684 Sending early media
2023-01-30 11:10:30.623782 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
2023-01-30 11:10:30.623782 [NOTICE] switch_ivr_originate.c:2999 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/2107@192.168.65.94 [a86f7630-ef31-4acb-bfa1-d2018a0cc34d]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] mod_sofia.c:5089 (sofia/internal/2107@192.168.65.94) State Change CS_NEW -> CS_INIT
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:3839 Set Codec sofia/external/100@hpbx043.telecomsvc.com G722/8000 20 ms 160 samples 64000 bits 1 channels
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_codec.c:111 sofia/external/100@hpbx043.telecomsvc.com Original read codec set to G722:9
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_INIT (Cur 2 Tot 100)
2023-01-30 11:10:30.623782 [NOTICE] switch_ivr_originate.c:2999 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2023-01-30 11:10:30.623782 [NOTICE] switch_ivr_originate.c:2999 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:5911 sofia/external/100@hpbx043.telecomsvc.com Set 2833 dtmf send payload to 101 recv payload to 101
2023-01-30 11:10:30.623782 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/external/100@hpbx043.telecomsvc.com] 192.168.65.20 port 18462 -> 72.53.173.29 port 60342 codec: 9 ms: 20
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/2107@192.168.65.94) State INIT
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] mod_sofia.c:93 sofia/internal/2107@192.168.65.94 SOFIA INIT
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [NOTICE] switch_channel.c:1118 New Channel sofia/external/19542352653 [6ca9d392-578d-42e1-8617-229c015e29f5]
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] mod_sofia.c:5089 (sofia/external/19542352653) State Change CS_NEW -> CS_INIT
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] sofia_glue.c:1618 sofia/internal/2107@192.168.65.94 sending invite version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit
a86f7630-ef31-4acb-bfa1-d2018a0cc34d Local SDP:
a86f7630-ef31-4acb-bfa1-d2018a0cc34d v=0
a86f7630-ef31-4acb-bfa1-d2018a0cc34d o=FreeSWITCH 1675068826 1675068827 IN IP4 192.168.65.20
a86f7630-ef31-4acb-bfa1-d2018a0cc34d s=FreeSWITCH
a86f7630-ef31-4acb-bfa1-d2018a0cc34d c=IN IP4 192.168.65.20
a86f7630-ef31-4acb-bfa1-d2018a0cc34d t=0 0
a86f7630-ef31-4acb-bfa1-d2018a0cc34d m=audio 26204 RTP/AVP 0 102 9 101 103
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=rtpmap:0 PCMU/8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=rtpmap:102 opus/48000/2
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=rtpmap:9 G722/8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=rtpmap:101 telephone-event/8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=fmtp:101 0-16
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=rtpmap:103 telephone-event/48000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=fmtp:103 0-16
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=ptime:20
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=sendrecv
a86f7630-ef31-4acb-bfa1-d2018a0cc34d
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:40 sofia/internal/2107@192.168.65.94 Standard INIT
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/2107@192.168.65.94) State Change CS_INIT -> CS_ROUTING
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/2107@192.168.65.94) State INIT going to sleep
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_INIT (Cur 3 Tot 101)
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_ROUTING (Cur 3 Tot 101)
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:628 (sofia/external/19542352653) State INIT
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] mod_sofia.c:93 sofia/external/19542352653 SOFIA INIT
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/2107@192.168.65.94) State ROUTING
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] mod_sofia.c:154 sofia/internal/2107@192.168.65.94 SOFIA ROUTING
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/2107@192.168.65.94) State Change CS_ROUTING -> CS_CONSUME_MEDIA
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/2107@192.168.65.94) State ROUTING going to sleep
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 101)
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [calling][0]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/2107@192.168.65.94) State CONSUME_MEDIA
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] sofia_glue.c:1618 sofia/external/19542352653 sending invite version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit
6ca9d392-578d-42e1-8617-229c015e29f5 Local SDP:
6ca9d392-578d-42e1-8617-229c015e29f5 v=0
6ca9d392-578d-42e1-8617-229c015e29f5 o=FreeSWITCH 1675064688 1675064689 IN IP4 192.168.65.20
6ca9d392-578d-42e1-8617-229c015e29f5 s=FreeSWITCH
6ca9d392-578d-42e1-8617-229c015e29f5 c=IN IP4 192.168.65.20
6ca9d392-578d-42e1-8617-229c015e29f5 t=0 0
6ca9d392-578d-42e1-8617-229c015e29f5 m=audio 30342 RTP/AVP 0 9 101
6ca9d392-578d-42e1-8617-229c015e29f5 a=rtpmap:0 PCMU/8000
6ca9d392-578d-42e1-8617-229c015e29f5 a=rtpmap:9 G722/8000
6ca9d392-578d-42e1-8617-229c015e29f5 a=rtpmap:101 telephone-event/8000
6ca9d392-578d-42e1-8617-229c015e29f5 a=fmtp:101 0-16
6ca9d392-578d-42e1-8617-229c015e29f5 a=ptime:20
6ca9d392-578d-42e1-8617-229c015e29f5 a=sendrecv
6ca9d392-578d-42e1-8617-229c015e29f5
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/2107@192.168.65.94) State CONSUME_MEDIA going to sleep
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:40 sofia/external/19542352653 Standard INIT
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:48 (sofia/external/19542352653) State Change CS_INIT -> CS_ROUTING
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:628 (sofia/external/19542352653) State INIT going to sleep
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_ROUTING (Cur 3 Tot 101)
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:644 (sofia/external/19542352653) State ROUTING
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] mod_sofia.c:154 sofia/external/19542352653 SOFIA ROUTING
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_ivr_originate.c:67 (sofia/external/19542352653) State Change CS_ROUTING -> CS_CONSUME_MEDIA
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:644 (sofia/external/19542352653) State ROUTING going to sleep
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 101)
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:663 (sofia/external/19542352653) State CONSUME_MEDIA
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] switch_core_state_machine.c:663 (sofia/external/19542352653) State CONSUME_MEDIA going to sleep
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.623782 [DEBUG] sofia.c:7326 Channel sofia/external/19542352653 entering state [calling][0]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:8977 sofia/external/100@hpbx043.telecomsvc.com Set 2833 dtmf send payload to 101
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:8984 sofia/external/100@hpbx043.telecomsvc.com Set 2833 dtmf receive payload to 101
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:9007 sofia/external/100@hpbx043.telecomsvc.com Set rtp dtmf delay to 40
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/100@hpbx043.telecomsvc.com!
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_channel.c:3565 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change RINGING -> EARLY
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/external/100@hpbx043.telecomsvc.com.
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.623782 [DEBUG] mod_sofia.c:2593 Ring SDP:
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a v=0
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a o=FreeSWITCH 1675076568 1675076569 IN IP4 192.168.65.20
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a s=FreeSWITCH
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a c=IN IP4 192.168.65.20
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a t=0 0
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a m=audio 18462 RTP/AVP 9 101
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=rtpmap:9 G722/8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=rtpmap:101 telephone-event/8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=fmtp:101 0-16
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=ptime:20
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=sendrecv
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.643781 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [early][183]
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:30.663728 [DEBUG] sofia.c:7326 Channel sofia/external/19542352653 entering state [calling][0]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.703673 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [proceeding][180]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.703673 [NOTICE] sofia.c:7437 Ring-Ready sofia/internal/2107@192.168.65.94!
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:30.703673 [DEBUG] switch_channel.c:3437 (sofia/internal/2107@192.168.65.94) Callstate Change DOWN -> RINGING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:30.863783 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [completing][200]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] sofia.c:7336 Remote SDP:
a86f7630-ef31-4acb-bfa1-d2018a0cc34d v=0
a86f7630-ef31-4acb-bfa1-d2018a0cc34d o=- 1675095033 1675095033 IN IP4 192.168.65.94
a86f7630-ef31-4acb-bfa1-d2018a0cc34d s=Polycom IP Phone
a86f7630-ef31-4acb-bfa1-d2018a0cc34d c=IN IP4 192.168.65.94
a86f7630-ef31-4acb-bfa1-d2018a0cc34d t=0 0
a86f7630-ef31-4acb-bfa1-d2018a0cc34d m=audio 2294 RTP/AVP 0 101
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=rtpmap:0 PCMU/8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=rtpmap:101 telephone-event/8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [ready][200]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:3839 Set Codec sofia/internal/2107@192.168.65.94 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_codec.c:111 sofia/internal/2107@192.168.65.94 Original read codec set to PCMU:0
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:5911 sofia/internal/2107@192.168.65.94 Set 2833 dtmf send payload to 101 recv payload to 101
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/internal/2107@192.168.65.94] 192.168.65.20 port 26204 -> 192.168.65.94 port 2294 codec: 0 ms: 20
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:8977 sofia/internal/2107@192.168.65.94 Set 2833 dtmf send payload to 101
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:8984 sofia/internal/2107@192.168.65.94 Set 2833 dtmf receive payload to 101
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_core_media.c:9007 sofia/internal/2107@192.168.65.94 Set rtp dtmf delay to 40
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [NOTICE] sofia.c:8504 Channel [sofia/internal/2107@192.168.65.94] has been answered
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.523676 [DEBUG] switch_channel.c:3865 (sofia/internal/2107@192.168.65.94) Callstate Change RINGING -> ACTIVE
2023-01-30 11:10:33.523676 [DEBUG] switch_ivr_originate.c:3852 Originate Resulted in Success: [sofia/internal/2107@192.168.65.94]
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [NOTICE] switch_ivr_originate.c:3759 Hangup sofia/external/19542352653 [CS_CONSUME_MEDIA] [LOSE_RACE]
2023-01-30 11:10:33.563675 [DEBUG] switch_ivr_originate.c:3984 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_HANGUP (Cur 3 Tot 101)
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:848 (sofia/external/19542352653) Callstate Change DOWN -> HANGUP
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:850 (sofia/external/19542352653) State HANGUP
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] mod_sofia.c:453 Channel sofia/external/19542352653 hanging up, cause: LOSE_RACE
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] mod_sofia.c:521 Sending CANCEL to sofia/external/19542352653
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:60 sofia/external/19542352653 Standard HANGUP, cause: LOSE_RACE
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:850 (sofia/external/19542352653) State HANGUP going to sleep
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:620 (sofia/external/19542352653) State Change CS_HANGUP -> CS_REPORTING
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_REPORTING (Cur 3 Tot 101)
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:936 (sofia/external/19542352653) State REPORTING
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:174 sofia/external/19542352653 Standard REPORTING, cause: LOSE_RACE
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:936 (sofia/external/19542352653) State REPORTING going to sleep
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:611 (sofia/external/19542352653) State Change CS_REPORTING -> CS_DESTROY
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_session.c:1726 Session 101 (sofia/external/19542352653) Locked, Waiting on external entities
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [NOTICE] switch_core_session.c:1744 Session 101 (sofia/external/19542352653) Ended
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/19542352653 [CS_DESTROY]
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:739 (sofia/external/19542352653) Running State Change CS_DESTROY (Cur 2 Tot 101)
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:749 (sofia/external/19542352653) State DESTROY
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] mod_sofia.c:364 sofia/external/19542352653 SOFIA DESTROY
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:181 sofia/external/19542352653 Standard DESTROY
6ca9d392-578d-42e1-8617-229c015e29f5 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:749 (sofia/external/19542352653) State DESTROY going to sleep
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:33.563675 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/external/100@hpbx043.telecomsvc.com.
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:33.563675 [DEBUG] mod_sofia.c:898 Local SDP sofia/external/100@hpbx043.telecomsvc.com:
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a v=0
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a o=FreeSWITCH 1675076568 1675076570 IN IP4 192.168.65.20
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a s=FreeSWITCH
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a c=IN IP4 192.168.65.20
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a t=0 0
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a m=audio 18462 RTP/AVP 9 101
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=rtpmap:9 G722/8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=rtpmap:101 telephone-event/8000
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=fmtp:101 0-16
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=ptime:20
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a a=sendrecv
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:33.563675 [NOTICE] switch_ivr_bridge.c:1670 Channel [sofia/external/100@hpbx043.telecomsvc.com] has been answered
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:33.563675 [DEBUG] switch_channel.c:3865 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change EARLY -> ACTIVE
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:33.563675 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [completed][200]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.563675 [DEBUG] switch_ivr_bridge.c:1793 (sofia/internal/2107@192.168.65.94) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 101)
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.563675 [DEBUG] switch_core_state_machine.c:654 (sofia/internal/2107@192.168.65.94) State EXCHANGE_MEDIA
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.563675 [DEBUG] mod_sofia.c:656 SOFIA EXCHANGE_MEDIA
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.603674 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:33.603674 [NOTICE] switch_core_media.c:15845 Activating write resampler
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:33.603674 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.603674 [NOTICE] switch_core_media.c:15845 Activating write resampler
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:10:33.623675 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [ready][200]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [calling][0]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [ready][200]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] sofia.c:7333 Duplicate SDP
a86f7630-ef31-4acb-bfa1-d2018a0cc34d v=0
a86f7630-ef31-4acb-bfa1-d2018a0cc34d o=- 1675095033 1675095033 IN IP4 192.168.65.94
a86f7630-ef31-4acb-bfa1-d2018a0cc34d s=Polycom IP Phone
a86f7630-ef31-4acb-bfa1-d2018a0cc34d c=IN IP4 192.168.65.94
a86f7630-ef31-4acb-bfa1-d2018a0cc34d t=0 0
a86f7630-ef31-4acb-bfa1-d2018a0cc34d m=audio 2294 RTP/AVP 0 101
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=rtpmap:0 PCMU/8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d a=rtpmap:101 telephone-event/8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] switch_core_media.c:5911 sofia/internal/2107@192.168.65.94 Set 2833 dtmf send payload to 101 recv payload to 101
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] sofia.c:8345 Processing updated SDP
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:10:33.663675 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/internal/2107@192.168.65.94.
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.043657 [NOTICE] sofia.c:1089 Hangup sofia/external/100@hpbx043.telecomsvc.com [CS_EXECUTE] [NORMAL_CLEARING]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.043657 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/external/100@hpbx043.telecomsvc.com]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_ivr_bridge.c:820 sofia/external/100@hpbx043.telecomsvc.com ending bridge by request from write function
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/internal/2107@192.168.65.94]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [NOTICE] switch_ivr_bridge.c:1029 Hangup sofia/internal/2107@192.168.65.94 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:654 (sofia/internal/2107@192.168.65.94) State EXCHANGE_MEDIA going to sleep
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_HANGUP (Cur 2 Tot 101)
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/2107@192.168.65.94) Callstate Change ACTIVE -> HANGUP
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/2107@192.168.65.94) State HANGUP
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] mod_sofia.c:447 sofia/internal/2107@192.168.65.94 Overriding SIP cause 480 with 200 from the other leg
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] mod_sofia.c:453 Channel sofia/internal/2107@192.168.65.94 hanging up, cause: NORMAL_CLEARING
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] mod_sofia.c:507 Sending BYE to sofia/internal/2107@192.168.65.94
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:60 sofia/internal/2107@192.168.65.94 Standard HANGUP, cause: NORMAL_CLEARING
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/2107@192.168.65.94) State HANGUP going to sleep
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/2107@192.168.65.94) State Change CS_HANGUP -> CS_REPORTING
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_REPORTING (Cur 2 Tot 101)
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/2107@192.168.65.94) State REPORTING
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:174 sofia/internal/2107@192.168.65.94 Standard REPORTING, cause: NORMAL_CLEARING
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/2107@192.168.65.94) State REPORTING going to sleep
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/2107@192.168.65.94) State Change CS_REPORTING -> CS_DESTROY
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_session.c:1726 Session 100 (sofia/internal/2107@192.168.65.94) Locked, Waiting on external entities
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_ivr_bridge.c:1895 sofia/external/100@hpbx043.telecomsvc.com skip receive message [UNBRIDGE] (channel is hungup already)
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [NOTICE] switch_core_session.c:1744 Session 100 (sofia/internal/2107@192.168.65.94) Ended
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/2107@192.168.65.94 [CS_DESTROY]
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/2107@192.168.65.94) Running State Change CS_DESTROY (Cur 1 Tot 101)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_session.c:2905 sofia/external/100@hpbx043.telecomsvc.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/2107@192.168.65.94) State DESTROY
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] mod_sofia.c:364 sofia/internal/2107@192.168.65.94 SOFIA DESTROY
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:651 (sofia/external/100@hpbx043.telecomsvc.com) State EXECUTE going to sleep
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:181 sofia/internal/2107@192.168.65.94 Standard DESTROY
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_HANGUP (Cur 1 Tot 101)
a86f7630-ef31-4acb-bfa1-d2018a0cc34d 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/2107@192.168.65.94) State DESTROY going to sleep
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:848 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change ACTIVE -> HANGUP
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:850 (sofia/external/100@hpbx043.telecomsvc.com) State HANGUP
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] mod_sofia.c:453 Channel sofia/external/100@hpbx043.telecomsvc.com hanging up, cause: NORMAL_CLEARING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:60 sofia/external/100@hpbx043.telecomsvc.com Standard HANGUP, cause: NORMAL_CLEARING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:850 (sofia/external/100@hpbx043.telecomsvc.com) State HANGUP going to sleep
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:620 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_HANGUP -> CS_REPORTING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_REPORTING (Cur 1 Tot 101)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:936 (sofia/external/100@hpbx043.telecomsvc.com) State REPORTING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:174 sofia/external/100@hpbx043.telecomsvc.com Standard REPORTING, cause: NORMAL_CLEARING
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:936 (sofia/external/100@hpbx043.telecomsvc.com) State REPORTING going to sleep
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:611 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_REPORTING -> CS_DESTROY
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_session.c:1726 Session 99 (sofia/external/100@hpbx043.telecomsvc.com) Locked, Waiting on external entities
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [NOTICE] switch_core_session.c:1744 Session 99 (sofia/external/100@hpbx043.telecomsvc.com) Ended
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/100@hpbx043.telecomsvc.com [CS_DESTROY]
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:739 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_DESTROY (Cur 0 Tot 101)
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:749 (sofia/external/100@hpbx043.telecomsvc.com) State DESTROY
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] mod_sofia.c:364 sofia/external/100@hpbx043.telecomsvc.com SOFIA DESTROY
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:181 sofia/external/100@hpbx043.telecomsvc.com Standard DESTROY
dd5f9059-8bfe-4b53-b762-d1c52ecdcb7a 2023-01-30 11:13:51.063658 [DEBUG] switch_core_state_machine.c:749 (sofia/external/100@hpbx043.telecomsvc.com) State DESTROY going to sleep
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [NOTICE] switch_channel.c:1118 New Channel sofia/external/100@hpbx043.telecomsvc.com [75685b3c-6d46-4a25-a1dd-79b325dddcc8]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_NEW (Cur 1 Tot 102)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] sofia.c:10280 sofia/external/100@hpbx043.telecomsvc.com receiving invite from 72.53.173.29:5060 version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [received][100]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] sofia.c:7336 Remote SDP:
75685b3c-6d46-4a25-a1dd-79b325dddcc8 v=0
75685b3c-6d46-4a25-a1dd-79b325dddcc8 o=- 1 1 IN IP4 72.53.173.29
75685b3c-6d46-4a25-a1dd-79b325dddcc8 s=SIP call
75685b3c-6d46-4a25-a1dd-79b325dddcc8 c=IN IP4 72.53.173.29
75685b3c-6d46-4a25-a1dd-79b325dddcc8 t=0 0
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=sendrecv
75685b3c-6d46-4a25-a1dd-79b325dddcc8 m=audio 36186 RTP/AVP 9 0 18 8 101
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=rtpmap:9 G722/8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=rtpmap:0 PCMU/8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=rtpmap:18 G729/8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=fmtp:18 annexb=no
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=rtpmap:8 PCMA/8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=rtpmap:101 telephone-event/8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=ptime:20
75685b3c-6d46-4a25-a1dd-79b325dddcc8
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] sofia.c:7739 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_NEW -> CS_INIT
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:604 (sofia/external/100@hpbx043.telecomsvc.com) State NEW
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_INIT (Cur 1 Tot 102)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:628 (sofia/external/100@hpbx043.telecomsvc.com) State INIT
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] mod_sofia.c:93 sofia/external/100@hpbx043.telecomsvc.com SOFIA INIT
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:40 sofia/external/100@hpbx043.telecomsvc.com Standard INIT
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:48 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_INIT -> CS_ROUTING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:628 (sofia/external/100@hpbx043.telecomsvc.com) State INIT going to sleep
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_ROUTING (Cur 1 Tot 102)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_channel.c:2332 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change DOWN -> RINGING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:644 (sofia/external/100@hpbx043.telecomsvc.com) State ROUTING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] mod_sofia.c:154 sofia/external/100@hpbx043.telecomsvc.com SOFIA ROUTING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:236 sofia/external/100@hpbx043.telecomsvc.com Standard ROUTING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [INFO] mod_dialplan_xml.c:637 Processing Jim Concannon <100>->5031 in context public
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->unloop] continue=false
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->outside_call] continue=true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Absolute Condition [outside_call]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(outside_call=true)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action log(CRIT ***** naked in public from ${sip_from_user} to ${destination_number} ***** )
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action log(CRIT ***** caller_name = ${caller_id_name}; ICLID = ${caller_id_number} ***** )
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->from Consumer Celluloid] continue=true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [from Consumer Celluloid] ${caller_id_number}(100) =~ /^(19542352653)$/ break=never
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->junk block] continue=false
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${sip_to_user}(65749684) =~ /obi_fjh/ break=never
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_name}(Jim Concannon) =~ /^V\d+/ break=on-true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_name}(Jim Concannon) =~ /[Pp]olice[Oo]fficer\d+/ break=on-true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(923008355903)$/ break=on-true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(14156358962)$/ break=on-true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(17542193980)$/ break=on-true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(13012881384)$/ break=on-true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(1408689\d{4})$/ break=on-true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->callcentric_did] continue=false
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [callcentric_did] ${sip_to_user}(65749684) =~ /^(12023809008)$/ break=on-true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->Jim Concannon] continue=false
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (PASS) [Jim Concannon] ${destination_number}(5031) =~ /^(5031)$/ break=never
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (PASS) [Jim Concannon] ${sip_from_user}(100) =~ /^(100)$/ break=on-true
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action log(CRIT ***** JIM CONCANNON EXT100 from ${sip_from_user} to ${destination_number} ***** )
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(ringback=${us-ring})
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(call_timeout=48)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(hangup_after_bridge=true)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(continue_on_fail=true)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action bridge(${sofia_contact(user/2104)},${sofia_contact(user/2107)},${sofia_contact(user/2103)},${sofia_contact(user/2105)}:_:{sip_cid_type=rpid,ignore_early_media=true}sofia/gateway/callcentric/19542352653)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:287 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_ROUTING -> CS_EXECUTE
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:644 (sofia/external/100@hpbx043.telecomsvc.com) State ROUTING going to sleep
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_EXECUTE (Cur 1 Tot 102)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:651 (sofia/external/100@hpbx043.telecomsvc.com) State EXECUTE
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] mod_sofia.c:209 sofia/external/100@hpbx043.telecomsvc.com SOFIA EXECUTE
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:329 sofia/external/100@hpbx043.telecomsvc.com Standard EXECUTE
75685b3c-6d46-4a25-a1dd-79b325dddcc8 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(outside_call=true)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [outside_call]=[true]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com export(RFC2822_DATE=Mon, 30 Jan 2023 11:14:57 -0500)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [RFC2822_DATE]=[Mon, 30 Jan 2023 11:14:57 -0500]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com log(CRIT ***** naked in public from 100 to 5031 ***** )
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [CRIT] mod_dptools.c:1866 ***** naked in public from 100 to 5031 *****
75685b3c-6d46-4a25-a1dd-79b325dddcc8 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com log(CRIT ***** caller_name = Jim Concannon; ICLID = 100 ***** )
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [CRIT] mod_dptools.c:1866 ***** caller_name = Jim Concannon; ICLID = 100 *****
75685b3c-6d46-4a25-a1dd-79b325dddcc8 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com log(CRIT ***** JIM CONCANNON EXT100 from 100 to 5031 ***** )
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [CRIT] mod_dptools.c:1866 ***** JIM CONCANNON EXT100 from 100 to 5031 *****
75685b3c-6d46-4a25-a1dd-79b325dddcc8 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(ringback=%(2000,4000,440,480))
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [ringback]=[%(2000,4000,440,480)]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(call_timeout=48)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [call_timeout]=[48]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(hangup_after_bridge=true)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [hangup_after_bridge]=[true]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(continue_on_fail=true)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [continue_on_fail]=[true]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com bridge(error/user_not_registered,sofia/internal/sip:2107@192.168.65.94,error/user_not_registered,error/user_not_registered:_:{sip_cid_type=rpid,ignore_early_media=true}sofia/gateway/callcentric/19542352653)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_channel.c:1264 sofia/external/100@hpbx043.telecomsvc.com EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 30 Jan 2023 11:14:57 -0500] to event
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_ivr_originate.c:1618 Parsing ultra-global variables
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [INFO] switch_ivr_originate.c:1684 Sending early media
2023-01-30 11:14:57.623686 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
2023-01-30 11:14:57.623686 [NOTICE] switch_ivr_originate.c:2999 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/2107@192.168.65.94 [590e91be-1fb9-4c34-a412-38e47f03c303]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] mod_sofia.c:5089 (sofia/internal/2107@192.168.65.94) State Change CS_NEW -> CS_INIT
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:3839 Set Codec sofia/external/100@hpbx043.telecomsvc.com G722/8000 20 ms 160 samples 64000 bits 1 channels
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_codec.c:111 sofia/external/100@hpbx043.telecomsvc.com Original read codec set to G722:9
2023-01-30 11:14:57.623686 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:5911 sofia/external/100@hpbx043.telecomsvc.com Set 2833 dtmf send payload to 101 recv payload to 101
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/external/100@hpbx043.telecomsvc.com] 192.168.65.20 port 22260 -> 72.53.173.29 port 36186 codec: 9 ms: 20
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [NOTICE] switch_channel.c:1118 New Channel sofia/external/19542352653 [b93b9181-3327-44c0-8ba3-b23da75ee807]
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] mod_sofia.c:5089 (sofia/external/19542352653) State Change CS_NEW -> CS_INIT
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_INIT (Cur 3 Tot 104)
2023-01-30 11:14:57.623686 [NOTICE] switch_ivr_originate.c:2999 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2023-01-30 11:14:57.623686 [NOTICE] switch_ivr_originate.c:2999 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/2107@192.168.65.94) State INIT
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] mod_sofia.c:93 sofia/internal/2107@192.168.65.94 SOFIA INIT
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_INIT (Cur 3 Tot 104)
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:628 (sofia/external/19542352653) State INIT
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] mod_sofia.c:93 sofia/external/19542352653 SOFIA INIT
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] sofia_glue.c:1618 sofia/internal/2107@192.168.65.94 sending invite version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit
590e91be-1fb9-4c34-a412-38e47f03c303 Local SDP:
590e91be-1fb9-4c34-a412-38e47f03c303 v=0
590e91be-1fb9-4c34-a412-38e47f03c303 o=FreeSWITCH 1675074811 1675074812 IN IP4 192.168.65.20
590e91be-1fb9-4c34-a412-38e47f03c303 s=FreeSWITCH
590e91be-1fb9-4c34-a412-38e47f03c303 c=IN IP4 192.168.65.20
590e91be-1fb9-4c34-a412-38e47f03c303 t=0 0
590e91be-1fb9-4c34-a412-38e47f03c303 m=audio 20486 RTP/AVP 0 102 9 101 103
590e91be-1fb9-4c34-a412-38e47f03c303 a=rtpmap:0 PCMU/8000
590e91be-1fb9-4c34-a412-38e47f03c303 a=rtpmap:102 opus/48000/2
590e91be-1fb9-4c34-a412-38e47f03c303 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
590e91be-1fb9-4c34-a412-38e47f03c303 a=rtpmap:9 G722/8000
590e91be-1fb9-4c34-a412-38e47f03c303 a=rtpmap:101 telephone-event/8000
590e91be-1fb9-4c34-a412-38e47f03c303 a=fmtp:101 0-16
590e91be-1fb9-4c34-a412-38e47f03c303 a=rtpmap:103 telephone-event/48000
590e91be-1fb9-4c34-a412-38e47f03c303 a=fmtp:103 0-16
590e91be-1fb9-4c34-a412-38e47f03c303 a=ptime:20
590e91be-1fb9-4c34-a412-38e47f03c303 a=sendrecv
590e91be-1fb9-4c34-a412-38e47f03c303
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:40 sofia/internal/2107@192.168.65.94 Standard INIT
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/2107@192.168.65.94) State Change CS_INIT -> CS_ROUTING
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/2107@192.168.65.94) State INIT going to sleep
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_ROUTING (Cur 3 Tot 104)
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/2107@192.168.65.94) State ROUTING
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] mod_sofia.c:154 sofia/internal/2107@192.168.65.94 SOFIA ROUTING
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/2107@192.168.65.94) State Change CS_ROUTING -> CS_CONSUME_MEDIA
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/2107@192.168.65.94) State ROUTING going to sleep
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 104)
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] sofia_glue.c:1618 sofia/external/19542352653 sending invite version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit
b93b9181-3327-44c0-8ba3-b23da75ee807 Local SDP:
b93b9181-3327-44c0-8ba3-b23da75ee807 v=0
b93b9181-3327-44c0-8ba3-b23da75ee807 o=FreeSWITCH 1675067845 1675067846 IN IP4 192.168.65.20
b93b9181-3327-44c0-8ba3-b23da75ee807 s=FreeSWITCH
b93b9181-3327-44c0-8ba3-b23da75ee807 c=IN IP4 192.168.65.20
b93b9181-3327-44c0-8ba3-b23da75ee807 t=0 0
b93b9181-3327-44c0-8ba3-b23da75ee807 m=audio 27452 RTP/AVP 0 9 101
b93b9181-3327-44c0-8ba3-b23da75ee807 a=rtpmap:0 PCMU/8000
b93b9181-3327-44c0-8ba3-b23da75ee807 a=rtpmap:9 G722/8000
b93b9181-3327-44c0-8ba3-b23da75ee807 a=rtpmap:101 telephone-event/8000
b93b9181-3327-44c0-8ba3-b23da75ee807 a=fmtp:101 0-16
b93b9181-3327-44c0-8ba3-b23da75ee807 a=ptime:20
b93b9181-3327-44c0-8ba3-b23da75ee807 a=sendrecv
b93b9181-3327-44c0-8ba3-b23da75ee807
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/2107@192.168.65.94) State CONSUME_MEDIA
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/2107@192.168.65.94) State CONSUME_MEDIA going to sleep
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:40 sofia/external/19542352653 Standard INIT
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:48 (sofia/external/19542352653) State Change CS_INIT -> CS_ROUTING
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:628 (sofia/external/19542352653) State INIT going to sleep
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.623686 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [calling][0]
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_ROUTING (Cur 3 Tot 104)
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:644 (sofia/external/19542352653) State ROUTING
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] mod_sofia.c:154 sofia/external/19542352653 SOFIA ROUTING
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_ivr_originate.c:67 (sofia/external/19542352653) State Change CS_ROUTING -> CS_CONSUME_MEDIA
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:644 (sofia/external/19542352653) State ROUTING going to sleep
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 104)
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] sofia.c:7326 Channel sofia/external/19542352653 entering state [calling][0]
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:663 (sofia/external/19542352653) State CONSUME_MEDIA
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.623686 [DEBUG] switch_core_state_machine.c:663 (sofia/external/19542352653) State CONSUME_MEDIA going to sleep
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:8977 sofia/external/100@hpbx043.telecomsvc.com Set 2833 dtmf send payload to 101
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:8984 sofia/external/100@hpbx043.telecomsvc.com Set 2833 dtmf receive payload to 101
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:9007 sofia/external/100@hpbx043.telecomsvc.com Set rtp dtmf delay to 40
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/100@hpbx043.telecomsvc.com!
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_channel.c:3565 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change RINGING -> EARLY
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/external/100@hpbx043.telecomsvc.com.
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.623686 [DEBUG] mod_sofia.c:2593 Ring SDP:
75685b3c-6d46-4a25-a1dd-79b325dddcc8 v=0
75685b3c-6d46-4a25-a1dd-79b325dddcc8 o=FreeSWITCH 1675073037 1675073038 IN IP4 192.168.65.20
75685b3c-6d46-4a25-a1dd-79b325dddcc8 s=FreeSWITCH
75685b3c-6d46-4a25-a1dd-79b325dddcc8 c=IN IP4 192.168.65.20
75685b3c-6d46-4a25-a1dd-79b325dddcc8 t=0 0
75685b3c-6d46-4a25-a1dd-79b325dddcc8 m=audio 22260 RTP/AVP 9 101
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=rtpmap:9 G722/8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=rtpmap:101 telephone-event/8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=fmtp:101 0-16
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=ptime:20
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=sendrecv
75685b3c-6d46-4a25-a1dd-79b325dddcc8
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.643688 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [early][183]
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:57.663688 [DEBUG] sofia.c:7326 Channel sofia/external/19542352653 entering state [calling][0]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.703688 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [proceeding][180]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.703688 [NOTICE] sofia.c:7437 Ring-Ready sofia/internal/2107@192.168.65.94!
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:57.703688 [DEBUG] switch_channel.c:3437 (sofia/internal/2107@192.168.65.94) Callstate Change DOWN -> RINGING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:57.943687 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [completing][200]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] sofia.c:7336 Remote SDP:
590e91be-1fb9-4c34-a412-38e47f03c303 v=0
590e91be-1fb9-4c34-a412-38e47f03c303 o=- 1675095298 1675095298 IN IP4 192.168.65.94
590e91be-1fb9-4c34-a412-38e47f03c303 s=Polycom IP Phone
590e91be-1fb9-4c34-a412-38e47f03c303 c=IN IP4 192.168.65.94
590e91be-1fb9-4c34-a412-38e47f03c303 t=0 0
590e91be-1fb9-4c34-a412-38e47f03c303 m=audio 2298 RTP/AVP 0 101
590e91be-1fb9-4c34-a412-38e47f03c303 a=rtpmap:0 PCMU/8000
590e91be-1fb9-4c34-a412-38e47f03c303 a=rtpmap:101 telephone-event/8000
590e91be-1fb9-4c34-a412-38e47f03c303
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [ready][200]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:3839 Set Codec sofia/internal/2107@192.168.65.94 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_codec.c:111 sofia/internal/2107@192.168.65.94 Original read codec set to PCMU:0
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:5911 sofia/internal/2107@192.168.65.94 Set 2833 dtmf send payload to 101 recv payload to 101
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/internal/2107@192.168.65.94] 192.168.65.20 port 20486 -> 192.168.65.94 port 2298 codec: 0 ms: 20
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:8977 sofia/internal/2107@192.168.65.94 Set 2833 dtmf send payload to 101
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:8984 sofia/internal/2107@192.168.65.94 Set 2833 dtmf receive payload to 101
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_core_media.c:9007 sofia/internal/2107@192.168.65.94 Set rtp dtmf delay to 40
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [NOTICE] sofia.c:8504 Channel [sofia/internal/2107@192.168.65.94] has been answered
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.763689 [DEBUG] switch_channel.c:3865 (sofia/internal/2107@192.168.65.94) Callstate Change RINGING -> ACTIVE
2023-01-30 11:14:58.763689 [DEBUG] switch_ivr_originate.c:3852 Originate Resulted in Success: [sofia/internal/2107@192.168.65.94]
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [NOTICE] switch_ivr_originate.c:3759 Hangup sofia/external/19542352653 [CS_CONSUME_MEDIA] [LOSE_RACE]
2023-01-30 11:14:58.783687 [DEBUG] switch_ivr_originate.c:3984 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_HANGUP (Cur 3 Tot 104)
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:848 (sofia/external/19542352653) Callstate Change DOWN -> HANGUP
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:850 (sofia/external/19542352653) State HANGUP
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] mod_sofia.c:453 Channel sofia/external/19542352653 hanging up, cause: LOSE_RACE
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] mod_sofia.c:521 Sending CANCEL to sofia/external/19542352653
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:60 sofia/external/19542352653 Standard HANGUP, cause: LOSE_RACE
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:850 (sofia/external/19542352653) State HANGUP going to sleep
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:620 (sofia/external/19542352653) State Change CS_HANGUP -> CS_REPORTING
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_REPORTING (Cur 3 Tot 104)
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:936 (sofia/external/19542352653) State REPORTING
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:174 sofia/external/19542352653 Standard REPORTING, cause: LOSE_RACE
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:936 (sofia/external/19542352653) State REPORTING going to sleep
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:611 (sofia/external/19542352653) State Change CS_REPORTING -> CS_DESTROY
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_session.c:1726 Session 104 (sofia/external/19542352653) Locked, Waiting on external entities
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [NOTICE] switch_core_session.c:1744 Session 104 (sofia/external/19542352653) Ended
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/19542352653 [CS_DESTROY]
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:739 (sofia/external/19542352653) Running State Change CS_DESTROY (Cur 2 Tot 104)
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:749 (sofia/external/19542352653) State DESTROY
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] mod_sofia.c:364 sofia/external/19542352653 SOFIA DESTROY
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:181 sofia/external/19542352653 Standard DESTROY
b93b9181-3327-44c0-8ba3-b23da75ee807 2023-01-30 11:14:58.783687 [DEBUG] switch_core_state_machine.c:749 (sofia/external/19542352653) State DESTROY going to sleep
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:58.803664 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/external/100@hpbx043.telecomsvc.com.
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:58.803664 [DEBUG] mod_sofia.c:898 Local SDP sofia/external/100@hpbx043.telecomsvc.com:
75685b3c-6d46-4a25-a1dd-79b325dddcc8 v=0
75685b3c-6d46-4a25-a1dd-79b325dddcc8 o=FreeSWITCH 1675073037 1675073039 IN IP4 192.168.65.20
75685b3c-6d46-4a25-a1dd-79b325dddcc8 s=FreeSWITCH
75685b3c-6d46-4a25-a1dd-79b325dddcc8 c=IN IP4 192.168.65.20
75685b3c-6d46-4a25-a1dd-79b325dddcc8 t=0 0
75685b3c-6d46-4a25-a1dd-79b325dddcc8 m=audio 22260 RTP/AVP 9 101
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=rtpmap:9 G722/8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=rtpmap:101 telephone-event/8000
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=fmtp:101 0-16
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=ptime:20
75685b3c-6d46-4a25-a1dd-79b325dddcc8 a=sendrecv
75685b3c-6d46-4a25-a1dd-79b325dddcc8
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:58.803664 [NOTICE] switch_ivr_bridge.c:1670 Channel [sofia/external/100@hpbx043.telecomsvc.com] has been answered
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:58.803664 [DEBUG] switch_channel.c:3865 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change EARLY -> ACTIVE
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:58.803664 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [completed][200]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.803664 [DEBUG] switch_ivr_bridge.c:1793 (sofia/internal/2107@192.168.65.94) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.803664 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 104)
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.803664 [DEBUG] switch_core_state_machine.c:654 (sofia/internal/2107@192.168.65.94) State EXCHANGE_MEDIA
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.803664 [DEBUG] mod_sofia.c:656 SOFIA EXCHANGE_MEDIA
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.843688 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:58.843688 [NOTICE] switch_core_media.c:15845 Activating write resampler
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:58.863688 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [ready][200]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [calling][0]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [ready][200]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] sofia.c:7333 Duplicate SDP
590e91be-1fb9-4c34-a412-38e47f03c303 v=0
590e91be-1fb9-4c34-a412-38e47f03c303 o=- 1675095298 1675095298 IN IP4 192.168.65.94
590e91be-1fb9-4c34-a412-38e47f03c303 s=Polycom IP Phone
590e91be-1fb9-4c34-a412-38e47f03c303 c=IN IP4 192.168.65.94
590e91be-1fb9-4c34-a412-38e47f03c303 t=0 0
590e91be-1fb9-4c34-a412-38e47f03c303 m=audio 2298 RTP/AVP 0 101
590e91be-1fb9-4c34-a412-38e47f03c303 a=rtpmap:0 PCMU/8000
590e91be-1fb9-4c34-a412-38e47f03c303 a=rtpmap:101 telephone-event/8000
590e91be-1fb9-4c34-a412-38e47f03c303
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] switch_core_media.c:5911 sofia/internal/2107@192.168.65.94 Set 2833 dtmf send payload to 101 recv payload to 101
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] sofia.c:8345 Processing updated SDP
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/internal/2107@192.168.65.94.
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:14:58.903687 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:14:58.903687 [NOTICE] switch_core_media.c:15845 Activating write resampler
2023-01-30 11:40:33.763688 [WARNING] switch_core_db.c:92 SQLite is BUSY, sane=299 [select nonce,last_nc from sip_authentication where nonce='add10586-9ced-4964-884c-304bad5b12ef' and last_nc < 283734]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.043688 [NOTICE] sofia.c:1089 Hangup sofia/external/100@hpbx043.telecomsvc.com [CS_EXECUTE] [NORMAL_CLEARING]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.043688 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/external/100@hpbx043.telecomsvc.com]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_ivr_bridge.c:820 sofia/external/100@hpbx043.telecomsvc.com ending bridge by request from write function
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/internal/2107@192.168.65.94]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [NOTICE] switch_ivr_bridge.c:1029 Hangup sofia/internal/2107@192.168.65.94 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:654 (sofia/internal/2107@192.168.65.94) State EXCHANGE_MEDIA going to sleep
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_HANGUP (Cur 2 Tot 104)
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_ivr_bridge.c:1892 sofia/internal/2107@192.168.65.94 skip receive message [UNBRIDGE] (channel is hungup already)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_ivr_bridge.c:1895 sofia/external/100@hpbx043.telecomsvc.com skip receive message [UNBRIDGE] (channel is hungup already)
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/2107@192.168.65.94) Callstate Change ACTIVE -> HANGUP
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_session.c:2905 sofia/external/100@hpbx043.telecomsvc.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:651 (sofia/external/100@hpbx043.telecomsvc.com) State EXECUTE going to sleep
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_HANGUP (Cur 2 Tot 104)
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/2107@192.168.65.94) State HANGUP
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] mod_sofia.c:447 sofia/internal/2107@192.168.65.94 Overriding SIP cause 480 with 200 from the other leg
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] mod_sofia.c:453 Channel sofia/internal/2107@192.168.65.94 hanging up, cause: NORMAL_CLEARING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:848 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change ACTIVE -> HANGUP
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:850 (sofia/external/100@hpbx043.telecomsvc.com) State HANGUP
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] mod_sofia.c:453 Channel sofia/external/100@hpbx043.telecomsvc.com hanging up, cause: NORMAL_CLEARING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:60 sofia/external/100@hpbx043.telecomsvc.com Standard HANGUP, cause: NORMAL_CLEARING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:850 (sofia/external/100@hpbx043.telecomsvc.com) State HANGUP going to sleep
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:620 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_HANGUP -> CS_REPORTING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_REPORTING (Cur 2 Tot 104)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:936 (sofia/external/100@hpbx043.telecomsvc.com) State REPORTING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:174 sofia/external/100@hpbx043.telecomsvc.com Standard REPORTING, cause: NORMAL_CLEARING
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:936 (sofia/external/100@hpbx043.telecomsvc.com) State REPORTING going to sleep
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:611 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_REPORTING -> CS_DESTROY
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_session.c:1726 Session 102 (sofia/external/100@hpbx043.telecomsvc.com) Locked, Waiting on external entities
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [NOTICE] switch_core_session.c:1744 Session 102 (sofia/external/100@hpbx043.telecomsvc.com) Ended
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/100@hpbx043.telecomsvc.com [CS_DESTROY]
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:739 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_DESTROY (Cur 1 Tot 104)
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:749 (sofia/external/100@hpbx043.telecomsvc.com) State DESTROY
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] mod_sofia.c:364 sofia/external/100@hpbx043.telecomsvc.com SOFIA DESTROY
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:181 sofia/external/100@hpbx043.telecomsvc.com Standard DESTROY
75685b3c-6d46-4a25-a1dd-79b325dddcc8 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:749 (sofia/external/100@hpbx043.telecomsvc.com) State DESTROY going to sleep
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] mod_sofia.c:507 Sending BYE to sofia/internal/2107@192.168.65.94
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:60 sofia/internal/2107@192.168.65.94 Standard HANGUP, cause: NORMAL_CLEARING
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/2107@192.168.65.94) State HANGUP going to sleep
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/2107@192.168.65.94) State Change CS_HANGUP -> CS_REPORTING
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_REPORTING (Cur 1 Tot 104)
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/2107@192.168.65.94) State REPORTING
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:174 sofia/internal/2107@192.168.65.94 Standard REPORTING, cause: NORMAL_CLEARING
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/2107@192.168.65.94) State REPORTING going to sleep
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/2107@192.168.65.94) State Change CS_REPORTING -> CS_DESTROY
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_session.c:1726 Session 103 (sofia/internal/2107@192.168.65.94) Locked, Waiting on external entities
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [NOTICE] switch_core_session.c:1744 Session 103 (sofia/internal/2107@192.168.65.94) Ended
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/2107@192.168.65.94 [CS_DESTROY]
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/2107@192.168.65.94) Running State Change CS_DESTROY (Cur 0 Tot 104)
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/2107@192.168.65.94) State DESTROY
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] mod_sofia.c:364 sofia/internal/2107@192.168.65.94 SOFIA DESTROY
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:181 sofia/internal/2107@192.168.65.94 Standard DESTROY
590e91be-1fb9-4c34-a412-38e47f03c303 2023-01-30 11:47:18.063698 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/2107@192.168.65.94) State DESTROY going to sleep
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [NOTICE] switch_channel.c:1118 New Channel sofia/external/100@hpbx043.telecomsvc.com [062ca2cd-d581-43d5-baf0-102d69b63cd7]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_NEW (Cur 1 Tot 105)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] sofia.c:10280 sofia/external/100@hpbx043.telecomsvc.com receiving invite from 72.53.173.29:5060 version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [received][100]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] sofia.c:7336 Remote SDP:
062ca2cd-d581-43d5-baf0-102d69b63cd7 v=0
062ca2cd-d581-43d5-baf0-102d69b63cd7 o=- 1 1 IN IP4 72.53.173.29
062ca2cd-d581-43d5-baf0-102d69b63cd7 s=SIP call
062ca2cd-d581-43d5-baf0-102d69b63cd7 c=IN IP4 72.53.173.29
062ca2cd-d581-43d5-baf0-102d69b63cd7 t=0 0
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=sendrecv
062ca2cd-d581-43d5-baf0-102d69b63cd7 m=audio 35950 RTP/AVP 9 0 18 8 101
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=rtpmap:9 G722/8000
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=rtpmap:0 PCMU/8000
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=rtpmap:18 G729/8000
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=fmtp:18 annexb=no
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=rtpmap:8 PCMA/8000
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=rtpmap:101 telephone-event/8000
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=ptime:20
062ca2cd-d581-43d5-baf0-102d69b63cd7
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] sofia.c:7739 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_NEW -> CS_INIT
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:604 (sofia/external/100@hpbx043.telecomsvc.com) State NEW
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_INIT (Cur 1 Tot 105)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:628 (sofia/external/100@hpbx043.telecomsvc.com) State INIT
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] mod_sofia.c:93 sofia/external/100@hpbx043.telecomsvc.com SOFIA INIT
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:40 sofia/external/100@hpbx043.telecomsvc.com Standard INIT
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:48 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_INIT -> CS_ROUTING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:628 (sofia/external/100@hpbx043.telecomsvc.com) State INIT going to sleep
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_ROUTING (Cur 1 Tot 105)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_channel.c:2332 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change DOWN -> RINGING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:644 (sofia/external/100@hpbx043.telecomsvc.com) State ROUTING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] mod_sofia.c:154 sofia/external/100@hpbx043.telecomsvc.com SOFIA ROUTING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:236 sofia/external/100@hpbx043.telecomsvc.com Standard ROUTING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [INFO] mod_dialplan_xml.c:637 Processing Jim Concannon <100>->5031 in context public
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->unloop] continue=false
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->outside_call] continue=true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Absolute Condition [outside_call]
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(outside_call=true)
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action log(CRIT ***** naked in public from ${sip_from_user} to ${destination_number} ***** )
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action log(CRIT ***** caller_name = ${caller_id_name}; ICLID = ${caller_id_number} ***** )
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->from Consumer Celluloid] continue=true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [from Consumer Celluloid] ${caller_id_number}(100) =~ /^(19542352653)$/ break=never
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->junk block] continue=false
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${sip_to_user}(65749684) =~ /obi_fjh/ break=never
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_name}(Jim Concannon) =~ /^V\d+/ break=on-true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_name}(Jim Concannon) =~ /[Pp]olice[Oo]fficer\d+/ break=on-true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(923008355903)$/ break=on-true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(14156358962)$/ break=on-true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(17542193980)$/ break=on-true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(13012881384)$/ break=on-true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [junk block] ${caller_id_number}(100) =~ /^(1408689\d{4})$/ break=on-true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->callcentric_did] continue=false
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (FAIL) [callcentric_did] ${sip_to_user}(65749684) =~ /^(12023809008)$/ break=on-true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com parsing [public->Jim Concannon] continue=false
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (PASS) [Jim Concannon] ${destination_number}(5031) =~ /^(5031)$/ break=never
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Regex (PASS) [Jim Concannon] ${sip_from_user}(100) =~ /^(100)$/ break=on-true
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action log(CRIT ***** JIM CONCANNON EXT100 from ${sip_from_user} to ${destination_number} ***** )
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(ringback=${us-ring})
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(call_timeout=48)
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(hangup_after_bridge=true)
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action set(continue_on_fail=true)
062ca2cd-d581-43d5-baf0-102d69b63cd7 Dialplan: sofia/external/100@hpbx043.telecomsvc.com Action bridge(${sofia_contact(user/2104)},${sofia_contact(user/2107)},${sofia_contact(user/2103)},${sofia_contact(user/2105)}:_:{sip_cid_type=rpid,ignore_early_media=true}sofia/gateway/callcentric/19542352653)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:287 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_ROUTING -> CS_EXECUTE
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:644 (sofia/external/100@hpbx043.telecomsvc.com) State ROUTING going to sleep
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_EXECUTE (Cur 1 Tot 105)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:651 (sofia/external/100@hpbx043.telecomsvc.com) State EXECUTE
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] mod_sofia.c:209 sofia/external/100@hpbx043.telecomsvc.com SOFIA EXECUTE
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:329 sofia/external/100@hpbx043.telecomsvc.com Standard EXECUTE
062ca2cd-d581-43d5-baf0-102d69b63cd7 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(outside_call=true)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [outside_call]=[true]
062ca2cd-d581-43d5-baf0-102d69b63cd7 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com export(RFC2822_DATE=Mon, 30 Jan 2023 16:07:15 -0500)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [RFC2822_DATE]=[Mon, 30 Jan 2023 16:07:15 -0500]
062ca2cd-d581-43d5-baf0-102d69b63cd7 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com log(CRIT ***** naked in public from 100 to 5031 ***** )
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [CRIT] mod_dptools.c:1866 ***** naked in public from 100 to 5031 *****
062ca2cd-d581-43d5-baf0-102d69b63cd7 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com log(CRIT ***** caller_name = Jim Concannon; ICLID = 100 ***** )
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [CRIT] mod_dptools.c:1866 ***** caller_name = Jim Concannon; ICLID = 100 *****
062ca2cd-d581-43d5-baf0-102d69b63cd7 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com log(CRIT ***** JIM CONCANNON EXT100 from 100 to 5031 ***** )
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [CRIT] mod_dptools.c:1866 ***** JIM CONCANNON EXT100 from 100 to 5031 *****
062ca2cd-d581-43d5-baf0-102d69b63cd7 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(ringback=%(2000,4000,440,480))
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [ringback]=[%(2000,4000,440,480)]
062ca2cd-d581-43d5-baf0-102d69b63cd7 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(call_timeout=48)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [call_timeout]=[48]
062ca2cd-d581-43d5-baf0-102d69b63cd7 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(hangup_after_bridge=true)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [hangup_after_bridge]=[true]
062ca2cd-d581-43d5-baf0-102d69b63cd7 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com set(continue_on_fail=true)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@hpbx043.telecomsvc.com [continue_on_fail]=[true]
062ca2cd-d581-43d5-baf0-102d69b63cd7 EXECUTE [depth=0] sofia/external/100@hpbx043.telecomsvc.com bridge(error/user_not_registered,sofia/internal/sip:2107@192.168.65.94,error/user_not_registered,error/user_not_registered:_:{sip_cid_type=rpid,ignore_early_media=true}sofia/gateway/callcentric/19542352653)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_channel.c:1264 sofia/external/100@hpbx043.telecomsvc.com EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 30 Jan 2023 16:07:15 -0500] to event
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_ivr_originate.c:1618 Parsing ultra-global variables
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [INFO] switch_ivr_originate.c:1684 Sending early media
2023-01-30 16:07:15.223660 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
2023-01-30 16:07:15.223660 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
2023-01-30 16:07:15.223660 [NOTICE] switch_ivr_originate.c:2999 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/2107@192.168.65.94 [2026466d-1dfe-4183-8e19-25e4c3fc8898]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] mod_sofia.c:5089 (sofia/internal/2107@192.168.65.94) State Change CS_NEW -> CS_INIT
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:3839 Set Codec sofia/external/100@hpbx043.telecomsvc.com G722/8000 20 ms 160 samples 64000 bits 1 channels
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_codec.c:111 sofia/external/100@hpbx043.telecomsvc.com Original read codec set to G722:9
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [NOTICE] switch_channel.c:1118 New Channel sofia/external/19542352653 [e5d72229-ce5d-4c7d-984f-7a3641541932]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] mod_sofia.c:5089 (sofia/external/19542352653) State Change CS_NEW -> CS_INIT
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:5911 sofia/external/100@hpbx043.telecomsvc.com Set 2833 dtmf send payload to 101 recv payload to 101
2023-01-30 16:07:15.223660 [NOTICE] switch_ivr_originate.c:2999 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/external/100@hpbx043.telecomsvc.com] 192.168.65.20 port 17144 -> 72.53.173.29 port 35950 codec: 9 ms: 20
2023-01-30 16:07:15.223660 [NOTICE] switch_ivr_originate.c:2999 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_INIT (Cur 3 Tot 107)
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_INIT (Cur 3 Tot 107)
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:628 (sofia/external/19542352653) State INIT
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] mod_sofia.c:93 sofia/external/19542352653 SOFIA INIT
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/2107@192.168.65.94) State INIT
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] mod_sofia.c:93 sofia/internal/2107@192.168.65.94 SOFIA INIT
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] sofia_glue.c:1618 sofia/internal/2107@192.168.65.94 sending invite version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit
2026466d-1dfe-4183-8e19-25e4c3fc8898 Local SDP:
2026466d-1dfe-4183-8e19-25e4c3fc8898 v=0
2026466d-1dfe-4183-8e19-25e4c3fc8898 o=FreeSWITCH 1675090321 1675090322 IN IP4 192.168.65.20
2026466d-1dfe-4183-8e19-25e4c3fc8898 s=FreeSWITCH
2026466d-1dfe-4183-8e19-25e4c3fc8898 c=IN IP4 192.168.65.20
2026466d-1dfe-4183-8e19-25e4c3fc8898 t=0 0
2026466d-1dfe-4183-8e19-25e4c3fc8898 m=audio 22514 RTP/AVP 0 102 9 101 103
2026466d-1dfe-4183-8e19-25e4c3fc8898 a=rtpmap:0 PCMU/8000
2026466d-1dfe-4183-8e19-25e4c3fc8898 a=rtpmap:102 opus/48000/2
2026466d-1dfe-4183-8e19-25e4c3fc8898 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
2026466d-1dfe-4183-8e19-25e4c3fc8898 a=rtpmap:9 G722/8000
2026466d-1dfe-4183-8e19-25e4c3fc8898 a=rtpmap:101 telephone-event/8000
2026466d-1dfe-4183-8e19-25e4c3fc8898 a=fmtp:101 0-16
2026466d-1dfe-4183-8e19-25e4c3fc8898 a=rtpmap:103 telephone-event/48000
2026466d-1dfe-4183-8e19-25e4c3fc8898 a=fmtp:103 0-16
2026466d-1dfe-4183-8e19-25e4c3fc8898 a=ptime:20
2026466d-1dfe-4183-8e19-25e4c3fc8898 a=sendrecv
2026466d-1dfe-4183-8e19-25e4c3fc8898
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:40 sofia/internal/2107@192.168.65.94 Standard INIT
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/2107@192.168.65.94) State Change CS_INIT -> CS_ROUTING
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/2107@192.168.65.94) State INIT going to sleep
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] sofia_glue.c:1618 sofia/external/19542352653 sending invite version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit
e5d72229-ce5d-4c7d-984f-7a3641541932 Local SDP:
e5d72229-ce5d-4c7d-984f-7a3641541932 v=0
e5d72229-ce5d-4c7d-984f-7a3641541932 o=FreeSWITCH 1675088047 1675088048 IN IP4 192.168.65.20
e5d72229-ce5d-4c7d-984f-7a3641541932 s=FreeSWITCH
e5d72229-ce5d-4c7d-984f-7a3641541932 c=IN IP4 192.168.65.20
e5d72229-ce5d-4c7d-984f-7a3641541932 t=0 0
e5d72229-ce5d-4c7d-984f-7a3641541932 m=audio 24788 RTP/AVP 0 9 101
e5d72229-ce5d-4c7d-984f-7a3641541932 a=rtpmap:0 PCMU/8000
e5d72229-ce5d-4c7d-984f-7a3641541932 a=rtpmap:9 G722/8000
e5d72229-ce5d-4c7d-984f-7a3641541932 a=rtpmap:101 telephone-event/8000
e5d72229-ce5d-4c7d-984f-7a3641541932 a=fmtp:101 0-16
e5d72229-ce5d-4c7d-984f-7a3641541932 a=ptime:20
e5d72229-ce5d-4c7d-984f-7a3641541932 a=sendrecv
e5d72229-ce5d-4c7d-984f-7a3641541932
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_ROUTING (Cur 3 Tot 107)
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/2107@192.168.65.94) State ROUTING
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] mod_sofia.c:154 sofia/internal/2107@192.168.65.94 SOFIA ROUTING
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/2107@192.168.65.94) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/2107@192.168.65.94) State ROUTING going to sleep
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 107)
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:40 sofia/external/19542352653 Standard INIT
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:48 (sofia/external/19542352653) State Change CS_INIT -> CS_ROUTING
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:628 (sofia/external/19542352653) State INIT going to sleep
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/2107@192.168.65.94) State CONSUME_MEDIA
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:663 (sofia/internal/2107@192.168.65.94) State CONSUME_MEDIA going to sleep
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.223660 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [calling][0]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_ROUTING (Cur 3 Tot 107)
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] sofia.c:7326 Channel sofia/external/19542352653 entering state [calling][0]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:644 (sofia/external/19542352653) State ROUTING
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] mod_sofia.c:154 sofia/external/19542352653 SOFIA ROUTING
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_ivr_originate.c:67 (sofia/external/19542352653) State Change CS_ROUTING -> CS_CONSUME_MEDIA
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:644 (sofia/external/19542352653) State ROUTING going to sleep
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 107)
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:663 (sofia/external/19542352653) State CONSUME_MEDIA
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.223660 [DEBUG] switch_core_state_machine.c:663 (sofia/external/19542352653) State CONSUME_MEDIA going to sleep
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:8977 sofia/external/100@hpbx043.telecomsvc.com Set 2833 dtmf send payload to 101
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:8984 sofia/external/100@hpbx043.telecomsvc.com Set 2833 dtmf receive payload to 101
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:9007 sofia/external/100@hpbx043.telecomsvc.com Set rtp dtmf delay to 40
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/100@hpbx043.telecomsvc.com!
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_channel.c:3565 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change RINGING -> EARLY
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/external/100@hpbx043.telecomsvc.com.
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.223660 [DEBUG] mod_sofia.c:2593 Ring SDP:
062ca2cd-d581-43d5-baf0-102d69b63cd7 v=0
062ca2cd-d581-43d5-baf0-102d69b63cd7 o=FreeSWITCH 1675095691 1675095692 IN IP4 192.168.65.20
062ca2cd-d581-43d5-baf0-102d69b63cd7 s=FreeSWITCH
062ca2cd-d581-43d5-baf0-102d69b63cd7 c=IN IP4 192.168.65.20
062ca2cd-d581-43d5-baf0-102d69b63cd7 t=0 0
062ca2cd-d581-43d5-baf0-102d69b63cd7 m=audio 17144 RTP/AVP 9 101
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=rtpmap:9 G722/8000
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=rtpmap:101 telephone-event/8000
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=fmtp:101 0-16
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=ptime:20
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=sendrecv
062ca2cd-d581-43d5-baf0-102d69b63cd7
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.243658 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [early][183]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:15.303659 [DEBUG] sofia.c:7326 Channel sofia/external/19542352653 entering state [calling][0]
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.303659 [DEBUG] sofia.c:7326 Channel sofia/internal/2107@192.168.65.94 entering state [proceeding][180]
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.303659 [NOTICE] sofia.c:7437 Ring-Ready sofia/internal/2107@192.168.65.94!
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:15.303659 [DEBUG] switch_channel.c:3437 (sofia/internal/2107@192.168.65.94) Callstate Change DOWN -> RINGING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:15.483661 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] sofia.c:7326 Channel sofia/external/19542352653 entering state [proceeding][183]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] sofia.c:7336 Remote SDP:
e5d72229-ce5d-4c7d-984f-7a3641541932 v=0
e5d72229-ce5d-4c7d-984f-7a3641541932 o=CCSBC 1675081024 1675081025 IN IP4 199.87.144.67
e5d72229-ce5d-4c7d-984f-7a3641541932 s=CCSBC
e5d72229-ce5d-4c7d-984f-7a3641541932 c=IN IP4 199.87.144.67
e5d72229-ce5d-4c7d-984f-7a3641541932 t=0 0
e5d72229-ce5d-4c7d-984f-7a3641541932 m=audio 53774 RTP/AVP 0 101
e5d72229-ce5d-4c7d-984f-7a3641541932 a=rtpmap:0 PCMU/8000
e5d72229-ce5d-4c7d-984f-7a3641541932 a=rtpmap:101 telephone-event/8000
e5d72229-ce5d-4c7d-984f-7a3641541932 a=fmtp:101 0-15
e5d72229-ce5d-4c7d-984f-7a3641541932 a=ptime:20
e5d72229-ce5d-4c7d-984f-7a3641541932 a=silenceSupp:off - - - -
e5d72229-ce5d-4c7d-984f-7a3641541932 a=setup:actpass
e5d72229-ce5d-4c7d-984f-7a3641541932
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [NOTICE] sofia.c:7339 Pre-Answer sofia/external/19542352653!
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_channel.c:3565 (sofia/external/19542352653) Callstate Change DOWN -> EARLY
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:3839 Set Codec sofia/external/19542352653 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_codec.c:111 sofia/external/19542352653 Original read codec set to PCMU:0
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:5911 sofia/external/19542352653 Set 2833 dtmf send payload to 101 recv payload to 101
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/external/19542352653] 192.168.65.20 port 24788 -> 199.87.144.67 port 53774 codec: 0 ms: 20
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:8977 sofia/external/19542352653 Set 2833 dtmf send payload to 101
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:8984 sofia/external/19542352653 Set 2833 dtmf receive payload to 101
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:16.823661 [DEBUG] switch_core_media.c:9007 sofia/external/19542352653 Set rtp dtmf delay to 40
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:17.323657 [DEBUG] sofia.c:7326 Channel sofia/external/19542352653 entering state [proceeding][183]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:17.323657 [DEBUG] sofia.c:7333 Duplicate SDP
e5d72229-ce5d-4c7d-984f-7a3641541932 v=0
e5d72229-ce5d-4c7d-984f-7a3641541932 o=CCSBC 1675081024 1675081025 IN IP4 199.87.144.67
e5d72229-ce5d-4c7d-984f-7a3641541932 s=CCSBC
e5d72229-ce5d-4c7d-984f-7a3641541932 c=IN IP4 199.87.144.67
e5d72229-ce5d-4c7d-984f-7a3641541932 t=0 0
e5d72229-ce5d-4c7d-984f-7a3641541932 m=audio 53774 RTP/AVP 0 101
e5d72229-ce5d-4c7d-984f-7a3641541932 a=rtpmap:0 PCMU/8000
e5d72229-ce5d-4c7d-984f-7a3641541932 a=rtpmap:101 telephone-event/8000
e5d72229-ce5d-4c7d-984f-7a3641541932 a=fmtp:101 0-15
e5d72229-ce5d-4c7d-984f-7a3641541932 a=ptime:20
e5d72229-ce5d-4c7d-984f-7a3641541932 a=silenceSupp:off - - - -
e5d72229-ce5d-4c7d-984f-7a3641541932 a=setup:actpass
e5d72229-ce5d-4c7d-984f-7a3641541932
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:17.323657 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:17.323657 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:17.323657 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:17.323657 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:17.323657 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:17.323657 [DEBUG] switch_core_media.c:5911 sofia/external/19542352653 Set 2833 dtmf send payload to 101 recv payload to 101
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:17.323657 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/external/19542352653.
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.003656 [DEBUG] sofia.c:7326 Channel sofia/external/19542352653 entering state [completing][200]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.003656 [DEBUG] sofia.c:7333 Duplicate SDP
e5d72229-ce5d-4c7d-984f-7a3641541932 v=0
e5d72229-ce5d-4c7d-984f-7a3641541932 o=CCSBC 1675081024 1675081025 IN IP4 199.87.144.67
e5d72229-ce5d-4c7d-984f-7a3641541932 s=CCSBC
e5d72229-ce5d-4c7d-984f-7a3641541932 c=IN IP4 199.87.144.67
e5d72229-ce5d-4c7d-984f-7a3641541932 t=0 0
e5d72229-ce5d-4c7d-984f-7a3641541932 m=audio 53774 RTP/AVP 0 101
e5d72229-ce5d-4c7d-984f-7a3641541932 a=rtpmap:0 PCMU/8000
e5d72229-ce5d-4c7d-984f-7a3641541932 a=rtpmap:101 telephone-event/8000
e5d72229-ce5d-4c7d-984f-7a3641541932 a=fmtp:101 0-15
e5d72229-ce5d-4c7d-984f-7a3641541932 a=ptime:20
e5d72229-ce5d-4c7d-984f-7a3641541932 a=silenceSupp:off - - - -
e5d72229-ce5d-4c7d-984f-7a3641541932 a=setup:actpass
e5d72229-ce5d-4c7d-984f-7a3641541932
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.003656 [DEBUG] sofia.c:7326 Channel sofia/external/19542352653 entering state [ready][200]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.003656 [NOTICE] sofia.c:8445 Channel [sofia/external/19542352653] has been answered
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.003656 [DEBUG] switch_channel.c:3865 (sofia/external/19542352653) Callstate Change EARLY -> ACTIVE
2023-01-30 16:07:18.003656 [DEBUG] switch_ivr_originate.c:3852 Originate Resulted in Success: [sofia/external/19542352653]
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [NOTICE] switch_ivr_originate.c:3759 Hangup sofia/internal/2107@192.168.65.94 [CS_CONSUME_MEDIA] [LOSE_RACE]
2023-01-30 16:07:18.023657 [DEBUG] switch_ivr_originate.c:3984 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_HANGUP (Cur 3 Tot 107)
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/2107@192.168.65.94) Callstate Change RINGING -> HANGUP
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/2107@192.168.65.94) State HANGUP
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] mod_sofia.c:453 Channel sofia/internal/2107@192.168.65.94 hanging up, cause: LOSE_RACE
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] mod_sofia.c:521 Sending CANCEL to sofia/internal/2107@192.168.65.94
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:60 sofia/internal/2107@192.168.65.94 Standard HANGUP, cause: LOSE_RACE
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/2107@192.168.65.94) State HANGUP going to sleep
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/2107@192.168.65.94) State Change CS_HANGUP -> CS_REPORTING
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/2107@192.168.65.94) Running State Change CS_REPORTING (Cur 3 Tot 107)
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/2107@192.168.65.94) State REPORTING
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:174 sofia/internal/2107@192.168.65.94 Standard REPORTING, cause: LOSE_RACE
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/2107@192.168.65.94) State REPORTING going to sleep
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/2107@192.168.65.94) State Change CS_REPORTING -> CS_DESTROY
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_session.c:1726 Session 106 (sofia/internal/2107@192.168.65.94) Locked, Waiting on external entities
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [NOTICE] switch_core_session.c:1744 Session 106 (sofia/internal/2107@192.168.65.94) Ended
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/2107@192.168.65.94 [CS_DESTROY]
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/2107@192.168.65.94) Running State Change CS_DESTROY (Cur 2 Tot 107)
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/2107@192.168.65.94) State DESTROY
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] mod_sofia.c:364 sofia/internal/2107@192.168.65.94 SOFIA DESTROY
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:181 sofia/internal/2107@192.168.65.94 Standard DESTROY
2026466d-1dfe-4183-8e19-25e4c3fc8898 2023-01-30 16:07:18.023657 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/2107@192.168.65.94) State DESTROY going to sleep
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:18.043657 [DEBUG] switch_core_media.c:8645 Audio params are unchanged for sofia/external/100@hpbx043.telecomsvc.com.
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:18.043657 [DEBUG] mod_sofia.c:898 Local SDP sofia/external/100@hpbx043.telecomsvc.com:
062ca2cd-d581-43d5-baf0-102d69b63cd7 v=0
062ca2cd-d581-43d5-baf0-102d69b63cd7 o=FreeSWITCH 1675095691 1675095693 IN IP4 192.168.65.20
062ca2cd-d581-43d5-baf0-102d69b63cd7 s=FreeSWITCH
062ca2cd-d581-43d5-baf0-102d69b63cd7 c=IN IP4 192.168.65.20
062ca2cd-d581-43d5-baf0-102d69b63cd7 t=0 0
062ca2cd-d581-43d5-baf0-102d69b63cd7 m=audio 17144 RTP/AVP 9 101
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=rtpmap:9 G722/8000
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=rtpmap:101 telephone-event/8000
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=fmtp:101 0-16
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=ptime:20
062ca2cd-d581-43d5-baf0-102d69b63cd7 a=sendrecv
062ca2cd-d581-43d5-baf0-102d69b63cd7
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:18.043657 [NOTICE] switch_ivr_bridge.c:1670 Channel [sofia/external/100@hpbx043.telecomsvc.com] has been answered
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:18.043657 [DEBUG] switch_channel.c:3865 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change EARLY -> ACTIVE
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:18.043657 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [completed][200]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.043657 [DEBUG] switch_ivr_bridge.c:1793 (sofia/external/19542352653) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.043657 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 107)
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.043657 [DEBUG] switch_core_state_machine.c:654 (sofia/external/19542352653) State EXCHANGE_MEDIA
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.043657 [DEBUG] mod_sofia.c:656 SOFIA EXCHANGE_MEDIA
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.063657 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:18.063657 [NOTICE] switch_core_media.c:15845 Activating write resampler
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:18.083657 [DEBUG] sofia.c:7326 Channel sofia/external/100@hpbx043.telecomsvc.com entering state [ready][200]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:18.103656 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:18.103656 [NOTICE] switch_core_media.c:15845 Activating write resampler
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [NOTICE] sofia.c:1089 Hangup sofia/external/19542352653 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/external/19542352653]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:654 (sofia/external/19542352653) State EXCHANGE_MEDIA going to sleep
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_HANGUP (Cur 2 Tot 107)
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:848 (sofia/external/19542352653) Callstate Change ACTIVE -> HANGUP
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:850 (sofia/external/19542352653) State HANGUP
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] mod_sofia.c:453 Channel sofia/external/19542352653 hanging up, cause: NORMAL_CLEARING
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:60 sofia/external/19542352653 Standard HANGUP, cause: NORMAL_CLEARING
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:850 (sofia/external/19542352653) State HANGUP going to sleep
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:620 (sofia/external/19542352653) State Change CS_HANGUP -> CS_REPORTING
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:585 (sofia/external/19542352653) Running State Change CS_REPORTING (Cur 2 Tot 107)
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:936 (sofia/external/19542352653) State REPORTING
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:174 sofia/external/19542352653 Standard REPORTING, cause: NORMAL_CLEARING
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:936 (sofia/external/19542352653) State REPORTING going to sleep
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:611 (sofia/external/19542352653) State Change CS_REPORTING -> CS_DESTROY
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_session.c:1726 Session 107 (sofia/external/19542352653) Locked, Waiting on external entities
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_ivr_bridge.c:820 sofia/external/19542352653 ending bridge by request from write function
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/external/100@hpbx043.telecomsvc.com]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [NOTICE] switch_ivr_bridge.c:1944 Hangup sofia/external/100@hpbx043.telecomsvc.com [CS_EXECUTE] [NORMAL_CLEARING]
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [NOTICE] switch_core_session.c:1744 Session 107 (sofia/external/19542352653) Ended
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/19542352653 [CS_DESTROY]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_session.c:2905 sofia/external/100@hpbx043.telecomsvc.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:651 (sofia/external/100@hpbx043.telecomsvc.com) State EXECUTE going to sleep
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_HANGUP (Cur 1 Tot 107)
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:739 (sofia/external/19542352653) Running State Change CS_DESTROY (Cur 1 Tot 107)
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:749 (sofia/external/19542352653) State DESTROY
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] mod_sofia.c:364 sofia/external/19542352653 SOFIA DESTROY
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:848 (sofia/external/100@hpbx043.telecomsvc.com) Callstate Change ACTIVE -> HANGUP
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:181 sofia/external/19542352653 Standard DESTROY
e5d72229-ce5d-4c7d-984f-7a3641541932 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:749 (sofia/external/19542352653) State DESTROY going to sleep
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:850 (sofia/external/100@hpbx043.telecomsvc.com) State HANGUP
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] mod_sofia.c:447 sofia/external/100@hpbx043.telecomsvc.com Overriding SIP cause 480 with 200 from the other leg
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] mod_sofia.c:453 Channel sofia/external/100@hpbx043.telecomsvc.com hanging up, cause: NORMAL_CLEARING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] mod_sofia.c:507 Sending BYE to sofia/external/100@hpbx043.telecomsvc.com
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:60 sofia/external/100@hpbx043.telecomsvc.com Standard HANGUP, cause: NORMAL_CLEARING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:850 (sofia/external/100@hpbx043.telecomsvc.com) State HANGUP going to sleep
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:620 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_HANGUP -> CS_REPORTING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_REPORTING (Cur 1 Tot 107)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:936 (sofia/external/100@hpbx043.telecomsvc.com) State REPORTING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:174 sofia/external/100@hpbx043.telecomsvc.com Standard REPORTING, cause: NORMAL_CLEARING
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:936 (sofia/external/100@hpbx043.telecomsvc.com) State REPORTING going to sleep
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:611 (sofia/external/100@hpbx043.telecomsvc.com) State Change CS_REPORTING -> CS_DESTROY
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_session.c:1726 Session 105 (sofia/external/100@hpbx043.telecomsvc.com) Locked, Waiting on external entities
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [NOTICE] switch_core_session.c:1744 Session 105 (sofia/external/100@hpbx043.telecomsvc.com) Ended
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/100@hpbx043.telecomsvc.com [CS_DESTROY]
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:739 (sofia/external/100@hpbx043.telecomsvc.com) Running State Change CS_DESTROY (Cur 0 Tot 107)
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:749 (sofia/external/100@hpbx043.telecomsvc.com) State DESTROY
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] mod_sofia.c:364 sofia/external/100@hpbx043.telecomsvc.com SOFIA DESTROY
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:181 sofia/external/100@hpbx043.telecomsvc.com Standard DESTROY
062ca2cd-d581-43d5-baf0-102d69b63cd7 2023-01-30 16:07:26.303661 [DEBUG] switch_core_state_machine.c:749 (sofia/external/100@hpbx043.telecomsvc.com) State DESTROY going to sleep