[Freeswitch-users] Originate Failed. Cause: NONE

Paul Muaddib paul.muaddib83 at gmail.com
Mon Jul 23 14:51:18 UTC 2018 

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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20180723/7b46259f/attachment-0001.html>

More information about the FreeSWITCH-users mailing list