[Freeswitch-users] Originate Failed. Cause: NONE
David Villasmil
david.villasmil.work at gmail.com
Thu Jul 26 03:19:52 UTC 2018
Could you send an actual trace?
sofia profile [your-profile] siptrace on
On Tue, Jul 24, 2018, 10:35 Paul Muaddib <paul.muaddib83 at gmail.com> wrote:
> 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 at 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/+ at 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 at 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 at 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 at 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 at sip-trunk.telekom.de) State NEW
> 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:584
> (sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de) State INIT
> 2018-07-23 16:32:57.559717 [DEBUG] mod_sofia.c:90 sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de SOFIA INIT
> 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:40
> sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Standard INIT
> 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:48
> (sofia/external/+49171XXXXXXX at 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 at 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 at 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 at 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 at sip-trunk.telekom.de) State ROUTING
> 2018-07-23 16:32:57.559717 [DEBUG] mod_sofia.c:143 sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de SOFIA ROUTING
> 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:236
> sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de parsing
> [public->unloop] continue=false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (PASS)
> [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (FAIL)
> [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de parsing
> [public->outside_call] continue=true
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Absolute
> Condition [outside_call]
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(outside_call=true)
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de parsing
> [public->call_debug] continue=true
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (FAIL)
> [call_debug] ${call_debug}(false) =~ /^true$/ break=never
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de parsing
> [public->telekom-voip-inbound-main] continue=false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (PASS)
> [telekom-voip-inbound-main] ${sip_h_P-Called-Party-ID}(<
> sip:+49XXXXXXXXX at sip-trunk.telekom.de;user=phone>) =~ /(XXXXXXXXX)/
> break=on-false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(domain_name=10.0.200.2)
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(effective_caller_id_number=${caller_id_number})
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(effective_caller_id_name=${caller_id_number})
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(ringback=%(1000,4000,425))
> Dialplan: sofia/external/+49171XXXXXXX at 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 at 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 at 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 at 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 at sip-trunk.telekom.de) State EXECUTE
> 2018-07-23 16:32:57.559717 [DEBUG] mod_sofia.c:198 sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de SOFIA EXECUTE
> 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:328
> sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Standard EXECUTE
> EXECUTE sofia/external/+49171XXXXXXX at sip-trunk.telekom.de
> set(outside_call=true)
> 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de [outside_call]=[true]
> EXECUTE sofia/external/+49171XXXXXXX at 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 at 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 at sip-trunk.telekom.de [domain_name]=[10.0.200.2]
> EXECUTE sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de
> [effective_caller_id_number]=[+49171XXXXXXX]
> EXECUTE sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de
> [effective_caller_id_name]=[+49171XXXXXXX]
> EXECUTE sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de [ringback]=[%(1000,4000,425)]
> EXECUTE sofia/external/+49171XXXXXXX at sip-trunk.telekom.de
> transfer(operator XML default)
> 2018-07-23 16:32:57.559717 [DEBUG] switch_ivr.c:2165 (sofia/external/+
> 49171XXXXXXX at 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 at sip-trunk.telekom.de to XML[operator at default]
> 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:650
> (sofia/external/+49171XXXXXXX at 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 at 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 at sip-trunk.telekom.de) State ROUTING
> 2018-07-23 16:32:57.559717 [DEBUG] mod_sofia.c:143 sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de SOFIA ROUTING
> 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:236
> sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de parsing
> [default->unloop] continue=false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (PASS)
> [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (FAIL)
> [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de parsing
> [default->blacklist_check1] continue=false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (FAIL)
> [blacklist_check1] ${regex(${caller_id_number}|(XXXXXXXXX))}(false) =~
> /^true$/ break=on-false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de parsing
> [default->Time of day] continue=true
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Date/Time
> Match (PASS) [Time of day] break=never
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(office_status=closed) INLINE
> EXECUTE sofia/external/+49171XXXXXXX at sip-trunk.telekom.de
> set(office_status=closed)
> 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de [office_status]=[closed]
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de
> Date/TimeMatch (FAIL) [Time of day] break=never
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de parsing
> [default->global] continue=true
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Absolute
> Condition [global]
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> export(nolocal:api_on_answer=uuid_setvar ${uuid} transfer false)
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(ringback=%(1000,4000,425))
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de parsing
> [default->global-pickup] continue=false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (FAIL)
> [global-pickup] destination_number(operator) =~ /^#$/ break=on-false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de parsing
> [default->local-pickup] continue=false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (FAIL)
> [local-pickup] destination_number(operator) =~ /^\*\*(\d+)$/ break=on-false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de parsing
> [default->group_dial_werkstatt] continue=false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (FAIL)
> [group_dial_werkstatt] destination_number(operator) =~ /^16$/ break=on-false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de parsing
> [default->Operator] continue=false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex (PASS)
> [Operator] destination_number(operator) =~ /^(operator)$|^(90)$/
> break=on-false
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> export(dialed_extension=operator)
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(dialed_user=operator@${domain_name})
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(call_timeout=90)
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(hangup_after_bridge=true)
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> set(continue_on_fail=true)
> Dialplan: sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de Action
> digit_action_set_realm(get_digits)
> Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> ring_ready()
> |--- Dialplan: Processing recursive conditions level:1 [Operator_recur_1]
> require-nested=FALSE
> |--- Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex
> (FAIL) [Operator_recur_1] ${office_status}(closed) =~ /^(open)$/
> break=on-true
> |--- Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Regex
> (PASS) [Operator_recur_1] ${office_status}(closed) =~ /^(closed)$/
> break=on-true
> |--- Dialplan: sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Action
> bridge(group/buero :_: group/werkstatt,pickup/global)
> |--- Dialplan: sofia/external/+49171XXXXXXX at 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 at 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 at 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 at 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 at sip-trunk.telekom.de) State EXECUTE
> 2018-07-23 16:32:57.559717 [DEBUG] mod_sofia.c:198 sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de SOFIA EXECUTE
> 2018-07-23 16:32:57.559717 [DEBUG] switch_core_state_machine.c:328
> sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Standard EXECUTE
> EXECUTE sofia/external/+49171XXXXXXX at 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 at 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 at sip-trunk.telekom.de [ringback]=[%(1000,4000,425)]
> EXECUTE sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de set(dialed_user=
> operator at 10.0.200.2)
> 2018-07-23 16:32:57.559717 [DEBUG] mod_dptools.c:1548 SET sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de [dialed_user]=[operator at 10.0.200.2]
> EXECUTE sofia/external/+49171XXXXXXX at sip-trunk.telekom.de
> set(call_timeout=90)
> 2018-07-23 16:32:57.579719 [DEBUG] mod_dptools.c:1548 SET sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de [call_timeout]=[90]
> EXECUTE sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de [hangup_after_bridge]=[true]
> EXECUTE sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de [continue_on_fail]=[true]
> EXECUTE sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de
> digit_action_set_realm(get_digits)
> EXECUTE sofia/external/+49171XXXXXXX at sip-trunk.telekom.de ring_ready()
> 2018-07-23 16:32:57.579719 [NOTICE] mod_sofia.c:2273 Ring-Ready
> sofia/external/+49171XXXXXXX at sip-trunk.telekom.de!
> 2018-07-23 16:32:57.579719 [DEBUG] sofia.c:7084 Channel sofia/external/+
> 49171XXXXXXX at 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 at sip-trunk.telekom.de!
> EXECUTE sofia/external/+49171XXXXXXX at 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 at 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 at 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 at 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 at 8000
> 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:3061 Set Codec
> sofia/external/+49171XXXXXXX at 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 at 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 at 8000
> 2018-07-23 16:32:57.579719 [DEBUG] switch_core_media.c:4767
> sofia/external/+49171XXXXXXX at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 10.0.200.10:5060) State INIT
> 2018-07-23 16:32:57.579719 [DEBUG] mod_sofia.c:90 sofia/internal/
> 10 at 10.0.200.10:5060 SOFIA INIT
> 2018-07-23 16:32:57.579719 [DEBUG] sofia_glue.c:1295 sofia/internal/
> 10 at 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 at 10.0.200.10:5060 Standard INIT
> 2018-07-23 16:32:57.579719 [DEBUG] switch_core_state_machine.c:48
> (sofia/internal/10 at 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 at 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 at 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 at 10.0.200.11:5060) State INIT
> 2018-07-23 16:32:57.599721 [DEBUG] mod_sofia.c:90 sofia/internal/
> 11 at 10.0.200.11:5060 SOFIA INIT
> 2018-07-23 16:32:57.599721 [DEBUG] sofia_glue.c:1295 sofia/internal/
> 11 at 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 at 10.0.200.11:5060 Standard INIT
> 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:48
> (sofia/internal/11 at 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 at 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 at 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 at 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 at 10.0.200.11:5060) State ROUTING
> 2018-07-23 16:32:57.599721 [DEBUG] mod_sofia.c:143 sofia/internal/
> 11 at 10.0.200.11:5060 SOFIA ROUTING
> 2018-07-23 16:32:57.599721 [DEBUG] switch_ivr_originate.c:67
> (sofia/internal/11 at 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 at 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 at 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 at 10.0.200.15:5060) State INIT
> 2018-07-23 16:32:57.599721 [DEBUG] mod_sofia.c:90 sofia/internal/
> 15 at 10.0.200.15:5060 SOFIA INIT
> 2018-07-23 16:32:57.599721 [DEBUG] sofia_glue.c:1295 sofia/internal/
> 15 at 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 at 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 at 10.0.200.15:5060 Standard INIT
> 2018-07-23 16:32:57.599721 [DEBUG] switch_core_state_machine.c:48
> (sofia/internal/15 at 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 at 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 at 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 at 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 at 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 at 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 at 10.0.200.15:5060) State ROUTING
> 2018-07-23 16:32:57.599721 [DEBUG] mod_sofia.c:143 sofia/internal/
> 15 at 10.0.200.15:5060 SOFIA ROUTING
> 2018-07-23 16:32:57.599721 [DEBUG] switch_ivr_originate.c:67
> (sofia/internal/15 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 10.0.200.10:5060) State ROUTING
> 2018-07-23 16:32:57.599721 [DEBUG] mod_sofia.c:143 sofia/internal/
> 10 at 10.0.200.10:5060 SOFIA ROUTING
> 2018-07-23 16:32:57.599721 [DEBUG] switch_ivr_originate.c:67
> (sofia/internal/10 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at sip-trunk.telekom.de!
> 2018-07-23 16:32:57.599721 [DEBUG] switch_channel.c:3474 (sofia/external/+
> 49171XXXXXXX at 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 at 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 at sip-trunk.telekom.de entering state [early][183]
> 2018-07-23 16:32:57.639724 [DEBUG] sofia.c:7084 Channel sofia/internal/
> 15 at 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 at 10.0.200.15:5060!
> 2018-07-23 16:32:57.639724 [DEBUG] switch_channel.c:3346 (sofia/internal/
> 15 at 10.0.200.15:5060) Callstate Change DOWN -> RINGING
> 2018-07-23 16:32:57.639724 [DEBUG] sofia.c:7084 Channel sofia/internal/
> 10 at 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 at 10.0.200.10:5060!
> 2018-07-23 16:32:57.639724 [DEBUG] switch_channel.c:3346 (sofia/internal/
> 10 at 10.0.200.10:5060) Callstate Change DOWN -> RINGING
> 2018-07-23 16:32:57.679728 [DEBUG] sofia.c:7084 Channel sofia/internal/
> 11 at 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 at 10.0.200.11:5060!
> 2018-07-23 16:32:57.679728 [DEBUG] switch_channel.c:3346 (sofia/internal/
> 11 at 10.0.200.11:5060) Callstate Change DOWN -> RINGING
> 2018-07-23 16:32:58.879835 [DEBUG] sofia.c:7084 Channel sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de entering state [terminated][487]
> 2018-07-23 16:32:58.879835 [NOTICE] sofia.c:8273 Hangup sofia/external/+
> 49171XXXXXXX at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 10.0.200.15:5060
> 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:60
> sofia/internal/15 at 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 at 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 at 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 at 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 at 10.0.200.15:5060) State REPORTING
> 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:174
> sofia/internal/15 at 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 at 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 at 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 at 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 at 10.0.200.15:5060) Ended
> 2018-07-23 16:32:58.899837 [NOTICE] switch_core_session.c:1687 Close
> Channel sofia/internal/15 at 10.0.200.15:5060 [CS_DESTROY]
> 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:741
> (sofia/internal/15 at 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 at 10.0.200.15:5060) State DESTROY
> 2018-07-23 16:32:58.899837 [DEBUG] mod_sofia.c:343 sofia/internal/
> 15 at 10.0.200.15:5060 SOFIA DESTROY
> 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:181
> sofia/internal/15 at 10.0.200.15:5060 Standard DESTROY
> 2018-07-23 16:32:58.899837 [DEBUG] switch_core_state_machine.c:751
> (sofia/internal/15 at 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 at 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 at 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 at 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 at 10.0.200.10:5060) State HANGUP
> 2018-07-23 16:32:58.899837 [DEBUG] mod_sofia.c:438 Channel sofia/internal/
> 10 at 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 at 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 at 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 at 10.0.200.11:5060) State HANGUP
> 2018-07-23 16:32:58.899837 [DEBUG] mod_sofia.c:438 Channel sofia/internal/
> 11 at 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 at 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 at 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 at 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 at 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 at sip-trunk.telekom.de) State HANGUP
> 2018-07-23 16:32:58.919839 [DEBUG] mod_sofia.c:438 Channel sofia/external/+
> 49171XXXXXXX at 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 at 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 at 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 at 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 at 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 at 10.0.200.10:5060
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:938
> (sofia/external/+49171XXXXXXX at sip-trunk.telekom.de) State REPORTING
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:60
> sofia/internal/10 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at sip-trunk.telekom.de) Ended
> 2018-07-23 16:32:58.919839 [NOTICE] switch_core_session.c:1687 Close
> Channel sofia/external/+49171XXXXXXX at sip-trunk.telekom.de [CS_DESTROY]
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:741
> (sofia/external/+49171XXXXXXX at 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 at sip-trunk.telekom.de) State DESTROY
> 2018-07-23 16:32:58.919839 [DEBUG] mod_sofia.c:343 sofia/external/+
> 49171XXXXXXX at sip-trunk.telekom.de SOFIA DESTROY
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:181
> sofia/external/+49171XXXXXXX at sip-trunk.telekom.de Standard DESTROY
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:751
> (sofia/external/+49171XXXXXXX at 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 at 10.0.200.10:5060) State REPORTING
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:174
> sofia/internal/10 at 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 at 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 at 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 at 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 at 10.0.200.10:5060) Ended
> 2018-07-23 16:32:58.919839 [NOTICE] switch_core_session.c:1687 Close
> Channel sofia/internal/10 at 10.0.200.10:5060 [CS_DESTROY]
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:741
> (sofia/internal/10 at 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 at 10.0.200.10:5060) State DESTROY
> 2018-07-23 16:32:58.919839 [DEBUG] mod_sofia.c:343 sofia/internal/
> 10 at 10.0.200.10:5060 SOFIA DESTROY
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:181
> sofia/internal/10 at 10.0.200.10:5060 Standard DESTROY
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:751
> (sofia/internal/10 at 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 at 10.0.200.11:5060
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:60
> sofia/internal/11 at 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 at 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 at 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 at 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 at 10.0.200.11:5060) State REPORTING
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:174
> sofia/internal/11 at 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 at 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 at 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 at 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 at 10.0.200.11:5060) Ended
> 2018-07-23 16:32:58.919839 [NOTICE] switch_core_session.c:1687 Close
> Channel sofia/internal/11 at 10.0.200.11:5060 [CS_DESTROY]
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:741
> (sofia/internal/11 at 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 at 10.0.200.11:5060) State DESTROY
> 2018-07-23 16:32:58.919839 [DEBUG] mod_sofia.c:343 sofia/internal/
> 11 at 10.0.200.11:5060 SOFIA DESTROY
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:181
> sofia/internal/11 at 10.0.200.11:5060 Standard DESTROY
> 2018-07-23 16:32:58.919839 [DEBUG] switch_core_state_machine.c:751
> (sofia/internal/11 at 10.0.200.11:5060) State DESTROY going to sleep
>
> _________________________________________________________________________
> Professional FreeSWITCH Services
> sales at 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 at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> https://freeswitch.com
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20180725/f4c3b2ba/attachment-0001.html>
More information about the FreeSWITCH-users
mailing list