August 2018 - FreeSWITCH-users - FreeSWITCH Mailing Lists

Originate Failed. Cause: NONE
by Paul Muaddib 21 Aug '18

21 Aug '18

Hi, I finally managed to setup Telekom DeutschlandLAN Voip sip trunk. Most of it is working now, but some calls get droped without clear reason. After one ring freeswitch drops the call: Originate Failed. Cause: NONE. That happens only if the caller uses a mobile phone. Some mobile phones work, others dont. This was not happening before when I used a ISDN / SIP Gateway. Here is the log file: 2018-07-23 16:32:57.539715 [NOTICE] switch_channel.c:1104 New Channel sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de [1a4d0118-09cc-46e7-906e-c2bfd1cecba1] 2018-07-23 16:32:57.539715 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+(a)sip-trunk.telekom.de) Running State Change CS_NEW (Cur 1 Tot 229) 2018-07-23 16:32:57.539715 [DEBUG] sofia.c:9873 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de receiving invite from 217.0.15.67:5060 version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 32bit 2018-07-23 16:32:57.539715 [DEBUG] sofia.c:7084 Channel sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de entering state [received][100] 2018-07-23 16:32:57.539715 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=- 1532356377 1532356377 IN IP4 217.0.15.67 s=on transit c=IN IP4 217.0.132.101 t=0 0 a=sendrecv m=audio 22482 RTP/AVP 9 8 100 a=rtpmap:9 G722/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:100 telephone-event/8000 a=fmtp:100 0-15 a=maxptime:40 a=ptime:20 2018-07-23 16:32:57.559717 [DEBUG] sofia.c:7486 (sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de) State Change CS_NEW -> CS_INIT 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:603 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State NEW 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Running State Change CS_INIT (Cur 1 Tot 229) 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State INIT 2018-07-23 16:32:57.559717 [DEBUG] mod_sofia.c:90 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de SOFIA INIT 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:40 sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Standard INIT 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State Change CS_INIT -> CS_ROUTING 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State INIT going to sleep 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Running State Change CS_ROUTING (Cur 1 Tot 229) 2018-07-23 16:32:57.559717 [DEBUG] switch_channel.c:2249 (sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de) Callstate Change DOWN -> RINGING 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State ROUTING 2018-07-23 16:32:57.559717 [DEBUG] mod_sofia.c:143 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de SOFIA ROUTING 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:236 sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Standard ROUTING 2018-07-23 16:32:57.559717 [INFO] mod_dialplan_xml.c:637 Processing +49171XXXXXXX <+49171XXXXXXX>->551130118089 in context public Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [public->unloop] continue=false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [public->outside_call] continue=true Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Absolute Condition [outside_call] Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(outside_call=true) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [public->call_debug] continue=true Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [public->telekom-voip-inbound-main] continue=false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (PASS) [telekom-voip-inbound-main] ${sip_h_P-Called-Party-ID}(< sip:+49XXXXXXXXX@sip-trunk.telekom.de;user=phone>) =~ /(XXXXXXXXX)/ break=on-false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(domain_name=10.0.200.2) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(effective_caller_id_number=${caller_id_number}) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(effective_caller_id_name=${caller_id_number}) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(ringback=%(1000,4000,425)) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action transfer(operator XML default) 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:286 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State Change CS_ROUTING -> CS_EXECUTE 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State ROUTING going to sleep 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Running State Change CS_EXECUTE (Cur 1 Tot 229) 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State EXECUTE 2018-07-23 16:32:57.559717 [DEBUG] mod_sofia.c:198 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de SOFIA EXECUTE 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:328 sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Standard EXECUTE EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(outside_call=true) 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [outside_call]=[true] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de export(RFC2822_DATE=Mon, 23 Jul 2018 16:32:57 +0200) 2018-07-23 16:32:57.559717 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Mon, 23 Jul 2018 16:32:57 +0200] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(domain_name=10.0.200.2) 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [domain_name]=[10.0.200.2] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(effective_caller_id_number=+49171XXXXXXX) 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [effective_caller_id_number]=[+49171XXXXXXX] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(effective_caller_id_name=+49171XXXXXXX) 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [effective_caller_id_name]=[+49171XXXXXXX] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(ringback=%(1000,4000,425)) 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [ringback]=[%(1000,4000,425)] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de transfer(operator XML default) 2018-07-23 16:32:57.559717 [DEBUG] switch_ivr.c:2165 (sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de) State Change CS_EXECUTE -> CS_ROUTING 2018-07-23 16:32:57.559717 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de to XML[operator@default] 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State EXECUTE going to sleep 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Running State Change CS_ROUTING (Cur 1 Tot 229) 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State ROUTING 2018-07-23 16:32:57.559717 [DEBUG] mod_sofia.c:143 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de SOFIA ROUTING 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:236 sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Standard ROUTING 2018-07-23 16:32:57.559717 [INFO] mod_dialplan_xml.c:637 Processing +49171XXXXXXX <+49171XXXXXXX>->operator in context default Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [default->unloop] continue=false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [default->blacklist_check1] continue=false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (FAIL) [blacklist_check1] ${regex(${caller_id_number}|(XXXXXXXXX))}(false) =~ /^true$/ break=on-false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [default->Time of day] continue=true Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Date/Time Match (PASS) [Time of day] break=never Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(office_status=closed) INLINE EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(office_status=closed) 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [office_status]=[closed] Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Date/TimeMatch (FAIL) [Time of day] break=never Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [default->global] continue=true Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Absolute Condition [global] Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action export(nolocal:api_on_answer=uuid_setvar ${uuid} transfer false) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(ringback=%(1000,4000,425)) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [default->global-pickup] continue=false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (FAIL) [global-pickup] destination_number(operator) =~ /^#$/ break=on-false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [default->local-pickup] continue=false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (FAIL) [local-pickup] destination_number(operator) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [default->group_dial_werkstatt] continue=false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (FAIL) [group_dial_werkstatt] destination_number(operator) =~ /^16$/ break=on-false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de parsing [default->Operator] continue=false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (PASS) [Operator] destination_number(operator) =~ /^(operator)$|^(90)$/ break=on-false Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action export(dialed_extension=operator) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(dialed_user=operator@${domain_name}) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(call_timeout=90) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(hangup_after_bridge=true) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action set(continue_on_fail=true) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action bind_digit_action(get_digits,~^([1-9][0-9])$,exec:lua,get_digits.lua,peer,self) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action digit_action_set_realm(get_digits) Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action ring_ready() |--- Dialplan: Processing recursive conditions level:1 [Operator_recur_1] require-nested=FALSE |--- Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (FAIL) [Operator_recur_1] ${office_status}(closed) =~ /^(open)$/ break=on-true |--- Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Regex (PASS) [Operator_recur_1] ${office_status}(closed) =~ /^(closed)$/ break=on-true |--- Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action bridge(group/buero :_: group/werkstatt,pickup/global) |--- Dialplan: sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Action hangup(NO_ANSWER) 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:286 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State Change CS_ROUTING -> CS_EXECUTE 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State ROUTING going to sleep 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Running State Change CS_EXECUTE (Cur 1 Tot 229) 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State EXECUTE 2018-07-23 16:32:57.559717 [DEBUG] mod_sofia.c:198 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de SOFIA EXECUTE 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:328 sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Standard EXECUTE EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de export(nolocal:api_on_answer=uuid_setvar 1a4d0118-09cc-46e7-906e-c2bfd1cecba1 transfer false) 2018-07-23 16:32:57.559717 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [api_on_answer]=[uuid_setvar 1a4d0118-09cc-46e7-906e-c2bfd1cecba1 transfer false] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(ringback=%(1000,4000,425)) 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [ringback]=[%(1000,4000,425)] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de export(dialed_extension=operator) 2018-07-23 16:32:57.559717 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[operator] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(dialed_user= operator(a)10.0.200.2) 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [dialed_user]=[operator(a)10.0.200.2] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(call_timeout=90) 2018-07-23 16:32:57.579719 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [call_timeout]=[90] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(hangup_after_bridge=true) 2018-07-23 16:32:57.579719 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [hangup_after_bridge]=[true] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de set(continue_on_fail=true) 2018-07-23 16:32:57.579719 [DEBUG] mod_dptools.c:1548 SET sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [continue_on_fail]=[true] EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de bind_digit_action(get_digits,~^([1-9][0-9])$,exec:lua,get_digits.lua,peer,self) 2018-07-23 16:32:57.579719 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'get_digits' 2018-07-23 16:32:57.579719 [DEBUG] switch_ivr_async.c:320 Digit parser DPTOOLS: binding ^([1-9][0-9])$/get_digits/0 callback: 0xb58163e0 data: 0x8f414d0 EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de digit_action_set_realm(get_digits) EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de ring_ready() 2018-07-23 16:32:57.579719 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de! 2018-07-23 16:32:57.579719 [DEBUG] sofia.c:7084 Channel sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de entering state [early][180] 2018-07-23 16:32:57.579719 [NOTICE] mod_dptools.c:1028 Ring Ready sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de! EXECUTE sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de bridge(group/buero :_: group/werkstatt,pickup/global) 2018-07-23 16:32:57.579719 [DEBUG] switch_channel.c:1250 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 23 Jul 2018 16:32:57 +0200] to event 2018-07-23 16:32:57.579719 [DEBUG] switch_channel.c:1250 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de EXPORTING[export_vars] [api_on_answer]=[uuid_setvar 1a4d0118-09cc-46e7-906e-c2bfd1cecba1 transfer false] to event 2018-07-23 16:32:57.579719 [DEBUG] switch_channel.c:1250 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de EXPORTING[export_vars] [dialed_extension]=[operator] to event 2018-07-23 16:32:57.579719 [DEBUG] switch_ivr_originate.c:1548 Parsing ultra-global variables 2018-07-23 16:32:57.579719 [INFO] switch_ivr_originate.c:1614 Sending early media 2018-07-23 16:32:57.579719 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 100@8000 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de G722/8000 20 ms 160 samples 64000 bits 1 channels 2018-07-23 16:32:57.579719 [DEBUG] switch_core_codec.c:111 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de Original read codec set to G722:9 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 100@8000 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4767 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de Set 2833 dtmf send payload to 100 recv payload to 100 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de] 10.0.200.2 port 7082 -> 217.0.132.101 port 22482 codec: 9 ms: 20 2018-07-23 16:32:57.579719 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-07-23 16:32:57.579719 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms 2018-07-23 16:32:57.579719 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-07-23 16:32:57.579719 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables 2018-07-23 16:32:57.579719 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/10@10.0.200.10:5060 [6306dfab-d366-4060-8b39-8e8349f72417] 2018-07-23 16:32:57.579719 [DEBUG] mod_sofia.c:4819 (sofia/internal/ 10@10.0.200.10:5060) State Change CS_NEW -> CS_INIT 2018-07-23 16:32:57.579719 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables 2018-07-23 16:32:57.579719 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-07-23 16:32:57.579719 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/11@10.0.200.11:5060 [ed0352eb-0d61-41f0-87c0-5837c5de4ef8] 2018-07-23 16:32:57.579719 [WARNING] switch_ivr_originate.c:2647 Only calling the first element in the list in this mode. 2018-07-23 16:32:57.579719 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables 2018-07-23 16:32:57.579719 [DEBUG] mod_sofia.c:4819 (sofia/internal/ 11@10.0.200.11:5060) State Change CS_NEW -> CS_INIT 2018-07-23 16:32:57.579719 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/15@10.0.200.15:5060 [9c8a2e89-cab4-40f6-b760-4a9e3ea6ef05] 2018-07-23 16:32:57.579719 [DEBUG] mod_sofia.c:4819 (sofia/internal/ 15@10.0.200.15:5060) State Change CS_NEW -> CS_INIT 2018-07-23 16:32:57.579719 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/10@10.0.200.10:5060) Running State Change CS_INIT (Cur 4 Tot 232) 2018-07-23 16:32:57.579719 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/10@10.0.200.10:5060) State INIT 2018-07-23 16:32:57.579719 [DEBUG] mod_sofia.c:90 sofia/internal/ 10@10.0.200.10:5060 SOFIA INIT 2018-07-23 16:32:57.579719 [DEBUG] sofia_glue.c:1295 sofia/internal/ 10@10.0.200.10:5060 sending invite version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 32bit Local SDP: v=0 o=FreeSWITCH 1532349289 1532349290 IN IP4 10.0.200.2 s=FreeSWITCH c=IN IP4 10.0.200.2 t=0 0 m=audio 7088 RTP/AVP 8 0 9 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:9 G722/8000 a=ptime:20 a=sendrecv 2018-07-23 16:32:57.579719 [DEBUG] switch_core_state_machine.c:40 sofia/internal/10@10.0.200.10:5060 Standard INIT 2018-07-23 16:32:57.579719 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/10@10.0.200.10:5060) State Change CS_INIT -> CS_ROUTING 2018-07-23 16:32:57.579719 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/10@10.0.200.10:5060) State INIT going to sleep 2018-07-23 16:32:57.579719 [DEBUG] mod_dptools.c:3872 () State Change CS_NEW -> CS_ROUTING 2018-07-23 16:32:57.579719 [NOTICE] switch_channel.c:1104 New Channel pickup/global [66ab149c-54a4-4d17-8428-26e1872e6f9d] 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/11@10.0.200.11:5060) Running State Change CS_INIT (Cur 5 Tot 233) 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/11@10.0.200.11:5060) State INIT 2018-07-23 16:32:57.599721 [DEBUG] mod_sofia.c:90 sofia/internal/ 11@10.0.200.11:5060 SOFIA INIT 2018-07-23 16:32:57.599721 [DEBUG] sofia_glue.c:1295 sofia/internal/ 11@10.0.200.11:5060 sending invite version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 32bit Local SDP: v=0 o=FreeSWITCH 1532349305 1532349306 IN IP4 10.0.200.2 s=FreeSWITCH c=IN IP4 10.0.200.2 t=0 0 m=audio 7072 RTP/AVP 8 0 9 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:9 G722/8000 a=ptime:20 a=sendrecv 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:40 sofia/internal/11@10.0.200.11:5060 Standard INIT 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/11@10.0.200.11:5060) State Change CS_INIT -> CS_ROUTING 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/11@10.0.200.11:5060) State INIT going to sleep 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/11@10.0.200.11:5060) Running State Change CS_ROUTING (Cur 5 Tot 233) 2018-07-23 16:32:57.599721 [DEBUG] sofia.c:7084 Channel sofia/internal/ 11@10.0.200.11:5060 entering state [calling][0] 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/11@10.0.200.11:5060) State ROUTING 2018-07-23 16:32:57.599721 [DEBUG] mod_sofia.c:143 sofia/internal/ 11@10.0.200.11:5060 SOFIA ROUTING 2018-07-23 16:32:57.599721 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/11@10.0.200.11:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/11@10.0.200.11:5060) State ROUTING going to sleep 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/15@10.0.200.15:5060) Running State Change CS_INIT (Cur 5 Tot 233) 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/15@10.0.200.15:5060) State INIT 2018-07-23 16:32:57.599721 [DEBUG] mod_sofia.c:90 sofia/internal/ 15@10.0.200.15:5060 SOFIA INIT 2018-07-23 16:32:57.599721 [DEBUG] sofia_glue.c:1295 sofia/internal/ 15@10.0.200.15:5060 sending invite version: 1.6.20 git 43a9feb 2018-05-07 18:56:11Z 32bit Local SDP: v=0 o=FreeSWITCH 1532349297 1532349298 IN IP4 10.0.200.2 s=FreeSWITCH c=IN IP4 10.0.200.2 t=0 0 m=audio 7080 RTP/AVP 8 0 9 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:9 G722/8000 a=ptime:20 a=sendrecv 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/11@10.0.200.11:5060) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 233) 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:40 sofia/internal/15@10.0.200.15:5060 Standard INIT 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/15@10.0.200.15:5060) State Change CS_INIT -> CS_ROUTING 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/15@10.0.200.15:5060) State INIT going to sleep 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/11@10.0.200.11:5060) State CONSUME_MEDIA 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/11@10.0.200.11:5060) State CONSUME_MEDIA going to sleep 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:584 (pickup/global) Running State Change CS_ROUTING (Cur 5 Tot 233) 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/15@10.0.200.15:5060) Running State Change CS_ROUTING (Cur 5 Tot 233) 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:643 (pickup/global) State ROUTING 2018-07-23 16:32:57.599721 [DEBUG] switch_ivr_originate.c:67 (pickup/global) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:643 (pickup/global) State ROUTING going to sleep 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:584 (pickup/global) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 233) 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:662 (pickup/global) State CONSUME_MEDIA 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:662 (pickup/global) State CONSUME_MEDIA going to sleep 2018-07-23 16:32:57.599721 [DEBUG] sofia.c:7084 Channel sofia/internal/ 15@10.0.200.15:5060 entering state [calling][0] 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/15@10.0.200.15:5060) State ROUTING 2018-07-23 16:32:57.599721 [DEBUG] mod_sofia.c:143 sofia/internal/ 15@10.0.200.15:5060 SOFIA ROUTING 2018-07-23 16:32:57.599721 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/15@10.0.200.15:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/15@10.0.200.15:5060) State ROUTING going to sleep 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/15@10.0.200.15:5060) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 233) 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/15@10.0.200.15:5060) State CONSUME_MEDIA 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/15@10.0.200.15:5060) State CONSUME_MEDIA going to sleep 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/10@10.0.200.10:5060) Running State Change CS_ROUTING (Cur 5 Tot 233) 2018-07-23 16:32:57.599721 [DEBUG] sofia.c:7084 Channel sofia/internal/ 10@10.0.200.10:5060 entering state [calling][0] 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/10@10.0.200.10:5060) State ROUTING 2018-07-23 16:32:57.599721 [DEBUG] mod_sofia.c:143 sofia/internal/ 10@10.0.200.10:5060 SOFIA ROUTING 2018-07-23 16:32:57.599721 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/10@10.0.200.10:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/10@10.0.200.10:5060) State ROUTING going to sleep 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/10@10.0.200.10:5060) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 233) 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/10@10.0.200.10:5060) State CONSUME_MEDIA 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/10@10.0.200.10:5060) State CONSUME_MEDIA going to sleep 2018-07-23 16:32:57.599721 [DEBUG] switch_core_media.c:7180 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de Set 2833 dtmf send payload to 100 2018-07-23 16:32:57.599721 [DEBUG] switch_core_media.c:7187 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de Set 2833 dtmf receive payload to 100 2018-07-23 16:32:57.599721 [DEBUG] switch_core_media.c:7210 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de Set rtp dtmf delay to 40 2018-07-23 16:32:57.599721 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de! 2018-07-23 16:32:57.599721 [DEBUG] switch_channel.c:3474 (sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de) Callstate Change RINGING -> EARLY 2018-07-23 16:32:57.619722 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de. 2018-07-23 16:32:57.619722 [DEBUG] mod_sofia.c:2364 Ring SDP: v=0 o=FreeSWITCH 1532349295 1532349296 IN IP4 10.0.200.2 s=FreeSWITCH c=IN IP4 10.0.200.2 t=0 0 m=audio 7082 RTP/AVP 9 100 a=rtpmap:9 G722/8000 a=rtpmap:100 telephone-event/8000 a=fmtp:100 0-16 a=ptime:20 a=sendrecv 2018-07-23 16:32:57.619722 [DEBUG] sofia.c:7084 Channel sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de entering state [early][183] 2018-07-23 16:32:57.639724 [DEBUG] sofia.c:7084 Channel sofia/internal/ 15@10.0.200.15:5060 entering state [proceeding][180] 2018-07-23 16:32:57.639724 [NOTICE] sofia.c:7192 Ring-Ready sofia/internal/ 15@10.0.200.15:5060! 2018-07-23 16:32:57.639724 [DEBUG] switch_channel.c:3346 (sofia/internal/ 15@10.0.200.15:5060) Callstate Change DOWN -> RINGING 2018-07-23 16:32:57.639724 [DEBUG] sofia.c:7084 Channel sofia/internal/ 10@10.0.200.10:5060 entering state [proceeding][180] 2018-07-23 16:32:57.639724 [NOTICE] sofia.c:7192 Ring-Ready sofia/internal/ 10@10.0.200.10:5060! 2018-07-23 16:32:57.639724 [DEBUG] switch_channel.c:3346 (sofia/internal/ 10@10.0.200.10:5060) Callstate Change DOWN -> RINGING 2018-07-23 16:32:57.679728 [DEBUG] sofia.c:7084 Channel sofia/internal/ 11@10.0.200.11:5060 entering state [proceeding][180] 2018-07-23 16:32:57.679728 [NOTICE] sofia.c:7192 Ring-Ready sofia/internal/ 11@10.0.200.11:5060! 2018-07-23 16:32:57.679728 [DEBUG] switch_channel.c:3346 (sofia/internal/ 11@10.0.200.11:5060) Callstate Change DOWN -> RINGING 2018-07-23 16:32:58.879835 [DEBUG] sofia.c:7084 Channel sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de entering state [terminated][487] 2018-07-23 16:32:58.879835 [NOTICE] sofia.c:8273 Hangup sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de [CS_EXECUTE] [ORIGINATOR_CANCEL] 2018-07-23 16:32:58.899837 [NOTICE] switch_ivr_originate.c:3612 Hangup sofia/internal/15@10.0.200.15:5060 [CS_CONSUME_MEDIA] [LOSE_RACE] 2018-07-23 16:32:58.899837 [NOTICE] switch_ivr_originate.c:3612 Hangup pickup/global [CS_CONSUME_MEDIA] [LOSE_RACE] 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/15@10.0.200.15:5060) Running State Change CS_HANGUP (Cur 5 Tot 233) 2018-07-23 16:32:58.899837 [DEBUG] switch_ivr_originate.c:3837 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:584 (pickup/global) Running State Change CS_HANGUP (Cur 5 Tot 233) 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/15@10.0.200.15:5060) Callstate Change RINGING -> HANGUP 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:850 (pickup/global) Callstate Change DOWN -> HANGUP 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:852 (pickup/global) State HANGUP 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/15@10.0.200.15:5060) State HANGUP 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:60 pickup/global Standard HANGUP, cause: LOSE_RACE 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:852 (pickup/global) State HANGUP going to sleep 2018-07-23 16:32:58.899837 [DEBUG] mod_sofia.c:438 Channel sofia/internal/ 15@10.0.200.15:5060 hanging up, cause: LOSE_RACE 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:619 (pickup/global) State Change CS_HANGUP -> CS_REPORTING 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:584 (pickup/global) Running State Change CS_REPORTING (Cur 5 Tot 233) 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:938 (pickup/global) State REPORTING 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:938 (pickup/global) State REPORTING going to sleep 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:610 (pickup/global) State Change CS_REPORTING -> CS_DESTROY 2018-07-23 16:32:58.899837 [DEBUG] switch_core_session.c:1665 Session 233 (pickup/global) Locked, Waiting on external entities 2018-07-23 16:32:58.899837 [NOTICE] switch_core_session.c:1683 Session 233 (pickup/global) Ended 2018-07-23 16:32:58.899837 [NOTICE] switch_core_session.c:1687 Close Channel pickup/global [CS_DESTROY] 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:741 (pickup/global) Running State Change CS_DESTROY (Cur 4 Tot 233) 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:751 (pickup/global) State DESTROY 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:181 pickup/global Standard DESTROY 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:751 (pickup/global) State DESTROY going to sleep 2018-07-23 16:32:58.899837 [NOTICE] switch_ivr_originate.c:3612 Hangup sofia/internal/10@10.0.200.10:5060 [CS_CONSUME_MEDIA] [LOSE_RACE] 2018-07-23 16:32:58.899837 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/15@10.0.200.15:5060 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:60 sofia/internal/15@10.0.200.15:5060 Standard HANGUP, cause: LOSE_RACE 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/15@10.0.200.15:5060) State HANGUP going to sleep 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/15@10.0.200.15:5060) State Change CS_HANGUP -> CS_REPORTING 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/15@10.0.200.15:5060) Running State Change CS_REPORTING (Cur 4 Tot 233) 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/15@10.0.200.15:5060) State REPORTING 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:174 sofia/internal/15@10.0.200.15:5060 Standard REPORTING, cause: LOSE_RACE 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/15@10.0.200.15:5060) State REPORTING going to sleep 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/15@10.0.200.15:5060) State Change CS_REPORTING -> CS_DESTROY 2018-07-23 16:32:58.899837 [DEBUG] switch_core_session.c:1665 Session 232 (sofia/internal/15@10.0.200.15:5060) Locked, Waiting on external entities 2018-07-23 16:32:58.899837 [NOTICE] switch_core_session.c:1683 Session 232 (sofia/internal/15@10.0.200.15:5060) Ended 2018-07-23 16:32:58.899837 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/15@10.0.200.15:5060 [CS_DESTROY] 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/15@10.0.200.15:5060) Running State Change CS_DESTROY (Cur 3 Tot 233) 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/15@10.0.200.15:5060) State DESTROY 2018-07-23 16:32:58.899837 [DEBUG] mod_sofia.c:343 sofia/internal/ 15@10.0.200.15:5060 SOFIA DESTROY 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:181 sofia/internal/15@10.0.200.15:5060 Standard DESTROY 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/15@10.0.200.15:5060) State DESTROY going to sleep 2018-07-23 16:32:58.899837 [NOTICE] switch_ivr_originate.c:3612 Hangup sofia/internal/11@10.0.200.11:5060 [CS_CONSUME_MEDIA] [LOSE_RACE] 2018-07-23 16:32:58.899837 [DEBUG] switch_ivr_originate.c:3837 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] 2018-07-23 16:32:58.899837 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [group] cause: [LOSE_RACE] 2018-07-23 16:32:58.899837 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 502 [LOSE_RACE] 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/10@10.0.200.10:5060) Running State Change CS_HANGUP (Cur 3 Tot 233) 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/10@10.0.200.10:5060) Callstate Change RINGING -> HANGUP 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/10@10.0.200.10:5060) State HANGUP 2018-07-23 16:32:58.899837 [DEBUG] mod_sofia.c:438 Channel sofia/internal/ 10@10.0.200.10:5060 hanging up, cause: LOSE_RACE 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/11@10.0.200.11:5060) Running State Change CS_HANGUP (Cur 3 Tot 233) 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/11@10.0.200.11:5060) Callstate Change RINGING -> HANGUP 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/11@10.0.200.11:5060) State HANGUP 2018-07-23 16:32:58.899837 [DEBUG] mod_sofia.c:438 Channel sofia/internal/ 11@10.0.200.11:5060 hanging up, cause: LOSE_RACE 2018-07-23 16:32:58.899837 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NONE 2018-07-23 16:32:58.899837 [DEBUG] switch_core_session.c:2815 sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State EXECUTE going to sleep 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Running State Change CS_HANGUP (Cur 3 Tot 233) 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:850 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Callstate Change EARLY -> HANGUP 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:852 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State HANGUP 2018-07-23 16:32:58.919839 [DEBUG] mod_sofia.c:438 Channel sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de hanging up, cause: ORIGINATOR_CANCEL 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:60 sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Standard HANGUP, cause: ORIGINATOR_CANCEL 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:852 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State HANGUP going to sleep 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:619 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State Change CS_HANGUP -> CS_REPORTING 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Running State Change CS_REPORTING (Cur 3 Tot 233) 2018-07-23 16:32:58.919839 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/10@10.0.200.10:5060 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:938 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State REPORTING 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:60 sofia/internal/10@10.0.200.10:5060 Standard HANGUP, cause: LOSE_RACE 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/10@10.0.200.10:5060) State HANGUP going to sleep 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/10@10.0.200.10:5060) State Change CS_HANGUP -> CS_REPORTING 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:174 sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Standard REPORTING, cause: ORIGINATOR_CANCEL 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:938 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State REPORTING going to sleep 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/10@10.0.200.10:5060) Running State Change CS_REPORTING (Cur 3 Tot 233) 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:610 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State Change CS_REPORTING -> CS_DESTROY 2018-07-23 16:32:58.919839 [DEBUG] switch_core_session.c:1665 Session 229 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Locked, Waiting on external entities 2018-07-23 16:32:58.919839 [NOTICE] switch_core_session.c:1683 Session 229 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Ended 2018-07-23 16:32:58.919839 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de [CS_DESTROY] 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:741 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) Running State Change CS_DESTROY (Cur 2 Tot 233) 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:751 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State DESTROY 2018-07-23 16:32:58.919839 [DEBUG] mod_sofia.c:343 sofia/external/+ 49171XXXXXXX(a)sip-trunk.telekom.de SOFIA DESTROY 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:181 sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de Standard DESTROY 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:751 (sofia/external/+49171XXXXXXX(a)sip-trunk.telekom.de) State DESTROY going to sleep 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/10@10.0.200.10:5060) State REPORTING 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:174 sofia/internal/10@10.0.200.10:5060 Standard REPORTING, cause: LOSE_RACE 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/10@10.0.200.10:5060) State REPORTING going to sleep 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/10@10.0.200.10:5060) State Change CS_REPORTING -> CS_DESTROY 2018-07-23 16:32:58.919839 [DEBUG] switch_core_session.c:1665 Session 230 (sofia/internal/10@10.0.200.10:5060) Locked, Waiting on external entities 2018-07-23 16:32:58.919839 [NOTICE] switch_core_session.c:1683 Session 230 (sofia/internal/10@10.0.200.10:5060) Ended 2018-07-23 16:32:58.919839 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/10@10.0.200.10:5060 [CS_DESTROY] 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/10@10.0.200.10:5060) Running State Change CS_DESTROY (Cur 1 Tot 233) 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/10@10.0.200.10:5060) State DESTROY 2018-07-23 16:32:58.919839 [DEBUG] mod_sofia.c:343 sofia/internal/ 10@10.0.200.10:5060 SOFIA DESTROY 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:181 sofia/internal/10@10.0.200.10:5060 Standard DESTROY 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/10@10.0.200.10:5060) State DESTROY going to sleep 2018-07-23 16:32:58.919839 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/11@10.0.200.11:5060 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:60 sofia/internal/11@10.0.200.11:5060 Standard HANGUP, cause: LOSE_RACE 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/11@10.0.200.11:5060) State HANGUP going to sleep 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/11@10.0.200.11:5060) State Change CS_HANGUP -> CS_REPORTING 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/11@10.0.200.11:5060) Running State Change CS_REPORTING (Cur 1 Tot 233) 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/11@10.0.200.11:5060) State REPORTING 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:174 sofia/internal/11@10.0.200.11:5060 Standard REPORTING, cause: LOSE_RACE 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/11@10.0.200.11:5060) State REPORTING going to sleep 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/11@10.0.200.11:5060) State Change CS_REPORTING -> CS_DESTROY 2018-07-23 16:32:58.919839 [DEBUG] switch_core_session.c:1665 Session 231 (sofia/internal/11@10.0.200.11:5060) Locked, Waiting on external entities 2018-07-23 16:32:58.919839 [NOTICE] switch_core_session.c:1683 Session 231 (sofia/internal/11@10.0.200.11:5060) Ended 2018-07-23 16:32:58.919839 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/11@10.0.200.11:5060 [CS_DESTROY] 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/11@10.0.200.11:5060) Running State Change CS_DESTROY (Cur 0 Tot 233) 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/11@10.0.200.11:5060) State DESTROY 2018-07-23 16:32:58.919839 [DEBUG] mod_sofia.c:343 sofia/internal/ 11@10.0.200.11:5060 SOFIA DESTROY 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:181 sofia/internal/11@10.0.200.11:5060 Standard DESTROY 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/11@10.0.200.11:5060) State DESTROY going to sleep

2 2

how to bridge call to call center module
by Do Nguyen Ha 20 Aug '18

20 Aug '18

Hi i am testing a lua script to bridge calls my dialplan call center setup <extension name="callcenter"> <condition field="destination_number" expression="^(6789)$"> <action application="callcenter" data="support@default"/> </condition> </extension> my call center module setup <configuration name="callcenter.conf" description="CallCenter"> <settings>   </settings> <queues> <queue name="support@default"> <param name="strategy" value="longest-idle-agent"/> ..... <param name="abandoned-resume-allowed" value="false"/> </queue> </queues> <agents> <agent name="1000@default" type="callback" contact="[leg_timeout=10]user/1000@default" status="Available" max-no-answer="3" wrap-up-time="10" reject-delay-time="10" busy-delay-time="60" /> </agents> <tiers> <tier agent="1000@default" queue="support@default" level="1" position="1"/> </tiers> </configuration> 1. init a call to first person (legA=freeswitch.Session( "sofia/gateway/fs1/9903")) 2. when a first call ready 3. i made another call to callcenter module(legB=freeswitch.Session("sofia/ 192.168.56.101/support@default")) how to make successfully call in step 3 using lua script thank you

1 0

call park detect which ext was parked and which was hungup
by Bipin Patel 19 Aug '18

19 Aug '18

hi, i have a diaplan such that when an ext places a call, a hash value for his ext set to oncall so if any1 else calls same ext, using conditions i check hash value and play ivr that user is busy so wait or dial later and if there is no oncall value then bridge directly. same oncall value is set for destination ext and when the caller disconnects i clear the hash value for both caller and callee using api_hangup_hook and this all seems to work fine. the problem arises when A calls B and oncall value is set for both but then either of them transfer to a park ext and themselves get hung up then the usual routine clears hash value for both rather than only the dropped ext, is there any other way to achieve this using xml dialplan only, probably someway to check using conditions which ext was parked and which was hangup? -- Regards, Bipin

1 0

Strange RXFAX Delay - Hangup Hook
by Tim Bowyer 17 Aug '18

17 Aug '18

Hi All, Have been pulling my hair out trying to work out why we're getting a strange delay upon completion of a t38 fax using rxfax. Upon finishing the receiving of a fax, and sending BYE to the originator, freeswitch seems to keep the channel open for exactly 30 seconds then tries to issue another hangup. Have tried all sorts of things in dialplan, including moving the answer to before the hangup hook - I prefer the answer to be post hangup hook to aid in hunting to different servers in case of API call failures. What's also weird, 30 seconds after rxfax completes there are debug entries for time stamps in the CLI from calls in the past?!@ If I do a show channels at idle - there are 0 total freeswitch@7f9729cbe5af> show channels 0 total. ---------------------------- Dialplan as follows ---------------------------- <?xml version="1.0" encoding="UTF-8" standalone="no"?> <document type="freeswitch/xml"> <section name="dialplan" description="Incoming Fax"> <context name="public"> <extension name="Fax{{ destination_number }}"> <condition field="destination_number" expression="^({{ destination_number }})$"> <action application="set" data="api_hangup_hook=system /data/python/process_fax.py {{ uuid }} /tmp/{{ uuid }}.tif {{ formats }} --caller {{ caller }} --fax_result_code \\\${fax_result_$........................cut<file:///$%7bfax_result_$........................cut> <action application="answer" /> <action application="playback" data="silence_stream://2000"/> {% if subscription.verbose_logging %} <action application="set" data="fax_verbose=true"/> {% endif %} <action application="set" data="fax_enable_t38_request=true"/> <action application="set" data="fax_enable_t38=true"/> <action application="set" data="fax_ident={{ subscription.rendered_fax_ident }}"/> <action application="set" data="fax_header={{ subscription.rendered_fax_header }}"/> <action application="rxfax" data="/tmp/{{ uuid }}.tif"/> <action application="hangup"/> </condition> </extension> </context> </section> </document> ---------------------------- Debug logs ---------------------------- 2018-08-13 05:41:39.127583 [DEBUG] mod_spandsp_fax.c:496 ============================================================================== 2018-08-13 05:41:39.127583 [DEBUG] mod_spandsp_fax.c:502 Fax successfully received. 2018-08-13 05:41:39.127583 [DEBUG] mod_spandsp_fax.c:526 ============================================================================== 2018-08-13 05:41:39.127583 [DEBUG] mod_spandsp_fax.c:276 FLOW T.38T FAX exchange complete 2018-08-13 05:41:39.127583 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 Call completed 2018-08-13 05:41:39.127583 [DEBUG] mod_spandsp_fax.c:276 FLOW T.30 HDLC signal status is Carrier down (-1) in state CALL_FINISHED 2018-08-13 05:41:39.127583 [DEBUG] switch_core_codec.c:248 sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> Restore previous codec PCMA:8. EXECUTE sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> hangup() 2018-08-13 05:41:39.127583 [NOTICE] mod_dptools.c:1286 Hangup sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_EXECUTE] [NORMAL_CLEARING] 2018-08-13 05:41:39.127583 [DEBUG] switch_core_session.c:2815 sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-08-13 05:41:39.127583 [DEBUG] switch_core_state_machine.c:650 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) State EXECUTE going to sleep 2018-08-13 05:41:39.127583 [DEBUG] switch_core_state_machine.c:584 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Running State Change CS_HANGUP (Cur 1 Tot 68) 2018-08-13 05:41:39.127583 [DEBUG] switch_core_state_machine.c:850 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Callstate Change ACTIVE -> HANGUP 2018-08-13 05:41:39.127583 [DEBUG] switch_core_state_machine.c:852 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) State HANGUP 2018-08-13 05:41:39.127583 [DEBUG] mod_sofia.c:438 Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> hanging up, cause: NORMAL_CLEARING >> here's the BYE 2018-08-13 05:41:39.127583 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> 2018-08-13 05:41:39.127583 [DEBUG] switch_core_state_machine.c:60 sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> Standard HANGUP, cause: NORMAL_CLEARING 2018-08-13 05:41:39.127583 [DEBUG] switch_core_state_machine.c:852 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) State HANGUP going to sleep >> 30 second delay??? 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:783 Hangup Command with Session system(/data/python/process_fax.py 4407e217-a0bb-4e04-a185-b2e42c6e36ff /tmp/4407e217-a0bb-4e04-a185-b2e42c6e36ff.tif --pdf --pdf --caller 61XXXXXXXXX --fax_result_code 0 --fax_result_text 'OK' --fax_remote_station_id '' --fax_document_total_pages 2 --fax_document_transferred_pages 2 --fax_image_resolution '8040x3850' --fax_image_size 37216 --fax_success 1 --fax_v17_disabled 0 --t38_gateway_format '' --t38_peer '' --fax_transfer_rate 14400 --t38_trace_read ''): Fax host is api:8000 Fax host scheme is http {'fax_document_total_pages': '2', 't38_gateway_format': '', 't38_trace_read': '', 't38_peer': '', 'fax_image_resolution': '8040x3850', 'fax_result_text': 'OK', 'fax_v17_disabled': '0', 'caller': '61XXXXXXXXX', 'fax_remote_station_id': '', 'fax_result_code': '0', 'fax_document_transferred_pages': '2', 'fax_image_size': '37216', 'fax_transfer_rate': '14400'} Updating fax status: http://api:8000/fax/update OK Attempting to convert Updating fax status: http://api:8000/fax/update OK Uploading fax files: http://api:8000/fax/upload {'tiff': <open file '/tmp/4407e217-a0bb-4e04-a185-b2e42c6e36ff.tif', mode 'rb' at 0x7fb570877e40>, 'pdf': <open file '/tmp/3f8e90cc-5b01-4d82-8674-18227449b9c0.pdf', mode 'rb' at 0x7fb570877ed0>} 3.32.124.126 [CS_EXECUTE] [NORMAL_CLEARING] > > Notices for calls which completed in the past?? 2018-08-08 10:33:54.207573 [NOTICE] switch_core_session.c:1683 Session 65 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Ended 2018-08-08 10:33:54.207573 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_DESTROY] 2018-08-08 10:39:01.707631 [NOTICE] switch_channel.c:1104 New Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [9a93cb39-1f2b-4ce2-bfc3-5feee3c9fa01] 2018-08-08 10:39:01.707631 [INFO] mod_dialplan_xml.c:637 Processing 61XXXXXXXXX <61XXXXXXXXX>->61XXXXXXXXX in context public 2018-08-08 10:39:01.787568 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>! 2018-08-08 10:39:01.787568 [NOTICE] mod_dptools.c:1312 Channel [sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx] has been answered 2018-08-08 10:39:48.487606 [NOTICE] mod_dptools.c:1286 Hangup sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_EXECUTE] [NORMAL_CLEARING] 2018-08-08 10:40:19.608111 [NOTICE] switch_core_session.c:1683 Session 66 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Ended 2018-08-08 10:40:19.608111 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_DESTROY] 2018-08-09 09:51:59.127574 [NOTICE] switch_channel.c:1104 New Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [33f5c499-20e6-4a29-a6f6-daa90b6d35dc] 2018-08-09 09:51:59.127574 [INFO] mod_dialplan_xml.c:637 Processing 61XXXXXXXXX <61XXXXXXXXX>->61XXXXXXXXX in context public 2018-08-09 09:51:59.207595 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>! 2018-08-09 09:51:59.207595 [NOTICE] mod_dptools.c:1312 Channel [sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx] has been answered 2018-08-09 09:52:46.007578 [NOTICE] mod_dptools.c:1286 Hangup sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_EXECUTE] [NORMAL_CLEARING] 2018-08-09 09:53:17.807983 [NOTICE] switch_core_session.c:1683 Session 67 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Ended 2018-08-09 09:53:17.807983 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_DESTROY] 2018-08-13 05:40:52.187572 [NOTICE] switch_channel.c:1104 New Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [4407e217-a0bb-4e04-a185-b2e42c6e36ff] 2018-08-13 05:40:52.187572 [INFO] mod_dialplan_xml.c:637 Processing 61XXXXXXXXX <61XXXXXXXXX>->61XXXXXXXXX in context public 2018-08-13 05:40:52.307599 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>! 2018-08-13 05:40:52.307599 [NOTICE] mod_dptools.c:1312 Channel [sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx] has been answered 2018-08-13 05:41:39.127583 [NOTICE] mod_dptools.c:1286 Hangup sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_EXECUTE] [NORMAL_CLEARING] 3.32.124.126 [CS_EXECUTE] [NORMAL_CLEARING] 2018-08-08 10:33:54.207573 [NOTICE] switch_core_session.c:1683 Session 65 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Ended 2018-08-08 10:33:54.207573 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_DESTROY] 2018-08-08 10:39:01.707631 [NOTICE] switch_channel.c:1104 New Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [9a93cb39-1f2b-4ce2-bfc3-5feee3c9fa01] 2018-08-08 10:39:01.707631 [INFO] mod_dialplan_xml.c:637 Processing 61XXXXXXXXX <61XXXXXXXXX>->61XXXXXXXXX in context public 2018-08-08 10:39:01.787568 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>! 2018-08-08 10:39:01.787568 [NOTICE] mod_dptools.c:1312 Channel [sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx] has been answered 2018-08-08 10:39:48.487606 [NOTICE] mod_dptools.c:1286 Hangup sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_EXECUTE] [NORMAL_CLEARING] 2018-08-08 10:40:19.608111 [NOTICE] switch_core_session.c:1683 Session 66 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Ended 2018-08-08 10:40:19.608111 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_DESTROY] 2018-08-09 09:51:59.127574 [NOTICE] switch_channel.c:1104 New Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [33f5c499-20e6-4a29-a6f6-daa90b6d35dc] 2018-08-09 09:51:59.127574 [INFO] mod_dialplan_xml.c:637 Processing 61XXXXXXXXX <61XXXXXXXXX>->61XXXXXXXXX in context public 2018-08-09 09:51:59.207595 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>! 2018-08-09 09:51:59.207595 [NOTICE] mod_dptools.c:1312 Channel [sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx] has been answered 2018-08-09 09:52:46.007578 [NOTICE] mod_dptools.c:1286 Hangup sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_EXECUTE] [NORMAL_CLEARING] 2018-08-09 09:53:17.807983 [NOTICE] switch_core_session.c:1683 Session 67 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Ended 2018-08-09 09:53:17.807983 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_DESTROY] 2018-08-13 05:40:52.187572 [NOTICE] switch_channel.c:1104 New Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [4407e217-a0bb-4e04-a185-b2e42c6e36ff] 2018-08-13 05:40:52.187572 [INFO] mod_dialplan_xml.c:637 Processing 61XXXXXXXXX <61XXXXXXXXX>->61XXXXXXXXX in context public 2018-08-13 05:40:52.307599 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>! 2018-08-13 05:40:52.307599 [NOTICE] mod_dptools.c:1312 Channel [sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx] has been answered 2018-08-13 05:41:39.127583 [NOTICE] mod_dptools.c:1286 Hangup sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_EXECUTE] [NORMAL_CLEARING] 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:619 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) State Change CS_HANGUP -> CS_REPORTING 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:584 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Running State Change CS_REPORTING (Cur 1 Tot 68) 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:938 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) State REPORTING 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:174 sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> Standard REPORTING, cause: NORMAL_CLEARING 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:938 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) State REPORTING going to sleep 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:610 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) State Change CS_REPORTING -> CS_DESTROY 2018-08-13 05:42:10.847595 [DEBUG] switch_core_session.c:1665 Session 68 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Locked, Waiting on external entities 2018-08-13 05:42:10.847595 [NOTICE] switch_core_session.c:1683 Session 68 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Ended 2018-08-13 05:42:10.847595 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> [CS_DESTROY] 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:741 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) Running State Change CS_DESTROY (Cur 0 Tot 68) 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:751 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) State DESTROY 2018-08-13 05:42:10.847595 [DEBUG] mod_sofia.c:343 sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> SOFIA DESTROY 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:181 sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx> Standard DESTROY 2018-08-13 05:42:10.847595 [DEBUG] switch_core_state_machine.c:751 (sofia/external/61XXXXXXXXX(a)2xx.xx.xxx.xxx<mailto:sofia/external/61XXXXXXXXX@2xx.xx.xxx.xxx>) State DESTROY going to sleep Cheers, Tim

2 1

Outbound stats are not populated
by Richard Screene 16 Aug '18

16 Aug '18

Hello, Could someone tell me if the outbound stats in the channel variables are functional? Eg. If I do uuid_set_media_stats and then uuid_dump I then see the outbound stats, eg: ``` variable_rtp_audio_out_raw_bytes: 6323167 variable_rtp_audio_out_media_bytes: 6323167 variable_rtp_audio_out_packet_count: 14829 variable_rtp_audio_out_media_packet_count: 14829 variable_rtp_audio_out_skip_packet_count: 0 variable_rtp_audio_out_dtmf_packet_count: 0 variable_rtp_audio_out_cng_packet_count: 0 ``` But, repeating these command whilst using tc to dump occasional packets I do not see variable_rtp_audio_out_skip_packet_count change - it stays at 0. Looking at the code I cannot see that this value is ever populated. Is there something I'm missing or were the outbound stats not completed? Many thanks, Richard

1 0

Call handling via Esl
by Francesco Facco de Lagarda 15 Aug '18

15 Aug '18

In need to achieve the following with Esl commands (port 8021 is php): Starting with a two leg call (A and B) of which I know uuid of leg A 1. Put both on hold (with music or announcement) 2. Originate a call and bridge to leg B 3. At some point pass new call to leg A 4. Hangup leg B Francesco Facco de Lagarda

1 0

Originating calls via ESL
by Francesco Facco de Lagarda 15 Aug '18

15 Aug '18

I'm trying to send cmds to 8021 port Esl via php api sofia status api show registrations And lots of other WOrk FINE! But I tried api originate user/1001 &park() and it says: USAGE: <call url> <exten>|&<application_name>(<app_args>) [<dialplan>] [<context>] [<cid_name>] [<cid_num>] [<timeout_sec>] what AM i doing wrong? Francesco Facco de Lagarda

3 3

FreeSWITCH version 1.8.1 now in production in the UK - Great work by the FreeSWITCH team!
by Andrew Keil 14 Aug '18

14 Aug '18

To FreeSWITCH Users, I just wanted to share my thanks and appreciation to the FreeSWITCH team for releasing FreeSWITCH version 1.8.1 (especially to Andrey Volk for his work on the Windows build). My client in London is now running in production this version (built using Visual Studio 2017 (version: 15.7.6) - SDK 10.0.17134.0). FYI: The only change done separately to the standard build is to roll in support for the latest Lua version 5.3.5 and the latest curl version 7.61.0. I ran a 1000 concurrent call flood test also with 100% success with FreeSWITCH running on Windows Server 2016 (with all the latest updates) and the main IVR service language used being Lua. Kind Regards, Andrew Keil Visytel Pty Ltd www.visytel.com<http://www.visytel.com>

3 6

Re: [Freeswitch-users] Originating calls via ESL
by Tihomir Culjaga 14 Aug '18

14 Aug '18

** D E V ** tculjaga@bladeranger /usr/local/nexios/classes/com/nex/server/core # telnet localhost 8021 Trying ::1... telnet: connect to address ::1: Connection refused Trying 127.0.0.1... Connected to localhost. Escape character is '^]'. Content-Type: auth/request auth ClueCon Content-Type: command/reply Reply-Text: +OK accepted events plain all Content-Type: command/reply Reply-Text: +OK event listener enabled plain api originate user/1001 &park() Content-Type: api/response Content-Length: 25 -ERR USER_NOT_REGISTERED Content-Length: 65 Content-Type: text/event-plain as u can see it works without any problem. just try doing it manually ... telnet localhost 8021 after that you login, subscribe events and hit your api command. bear in mind you will most likely need to use bgapi instead of api. Tihomir. On 14 August 2018 at 18:18, Davide Colombo via FreeSWITCH-users < freeswitch-users(a)lists.freeswitch.org> wrote: > _________________________________________________________________________ > Professional FreeSWITCH Services > sales(a)freeswitch.com > https://freeswitch.com > > Official FreeSWITCH Sites > https://freeswitch.com/oss > https://freeswitch.org/confluence > https://cluecon.com > > FreeSWITCH-users mailing list > FreeSWITCH-users(a)lists.freeswitch.org > http://lists.freeswitch.org/mailman/listinfo/freeswitch-users > UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users > https://freeswitch.com > > > ---------- Forwarded message ---------- > From: Davide Colombo <dcolombo(a)voismart.it> > To: freeswitch-users <freeswitch-users(a)lists.freeswitch.org> > Cc: > Bcc: > Date: Tue, 14 Aug 2018 01:25:18 +0200 (CEST) > Subject: Re: [Freeswitch-users] Originating calls via ESL > According to originate command docs (https://freeswitch.org/ > confluence/display/FREESWITCH/mod_commands#mod_commands-originate), > call_url is an endpoint like sofia. > You could try something like this: > > originate sofia/your_internal_profile/1001%your_domain &park() > > ----- Messaggio originale ----- > Da: "Francesco Facco de Lagarda" <francesco(a)delagarda.com> > A: "freeswitch-users" <freeswitch-users(a)lists.freeswitch.org> > Inviato: Venerdì, 10 agosto 2018 9:07:21 > Oggetto: [Freeswitch-users] Originating calls via ESL > > I'm trying to send cmds to 8021 port Esl via php > > api sofia status > api show registrations > And lots of other > WOrk FINE! > > But I tried > api originate user/1001 &park() > > and it says: > USAGE: <call url> <exten>|&<application_name>(<app_args>) [<dialplan>] > [<context>] [<cid_name>] [<cid_num>] [<timeout_sec>] > > what AM i doing wrong? > Francesco Facco de Lagarda > > > > _________________________________________________________________________ > Professional FreeSWITCH Services > sales(a)freeswitch.com > https://freeswitch.com > > Official FreeSWITCH Sites > https://freeswitch.com/oss > https://freeswitch.org/confluence > https://cluecon.com > > FreeSWITCH-users mailing list > FreeSWITCH-users(a)lists.freeswitch.org > http://lists.freeswitch.org/mailman/listinfo/freeswitch-users > UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users > https://freeswitch.com > > >

1 0

hangup processing in latest FS versions
by Mi Ke 14 Aug '18

14 Aug '18

1 0