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