[Freeswitch-users] Originate Failed. Cause: NONE

Paul Muaddib paul.muaddib83 at gmail.com
Tue Aug 21 12:58:58 UTC 2018 

Sorry, I could not make a SIP Trace. The error happens only rarely.
I removed G722 from the allowed codecs and added <param
name="NDLB-allow-bad-iananame" value="true"/>

So far I havent had this problem again.

Best regards,
Paul

Am Mo., 30. Juli 2018 um 21:30 Uhr schrieb David Villasmil <
david.villasmil.work at gmail.com>:

> 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
>
> _________________________________________________________________________
> 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/20180821/dabf31eb/attachment-0001.html>

More information about the FreeSWITCH-users mailing list