[Freeswitch-users] Issues with stripping Nortel extra SIP data

Joel White joelewhite at gmail.com
Thu Feb 27 23:23:48 MSK 2014 

I did add a line to the public incoming xml that uses the Say command to
repeat back what $1 variable is set to.  I figured it might help me in
debugging



+OK log level debug [7]
2014-02-27 15:13:05.086534 [NOTICE] switch_channel.c:1050 New Channel
sofia/external/23673 [910ede7a-9feb-11e3-9a55-09241ec9370d]
2014-02-27 15:13:05.086534 [DEBUG] switch_core_session.c:1016 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.086534 [DEBUG] switch_core_session.c:1016 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:415
(sofia/external/23673) Running State Change CS_NEW
2014-02-27 15:13:05.086534 [DEBUG] sofia.c:7868 sofia/external/23673
receiving invite from 10.111.11.10:5060 version: 1.2.22 git aabf813
2014-02-24 01:22:36Z 64bit
2014-02-27 15:13:05.086534 [DEBUG] sofia.c:5811 Channel
sofia/external/23673 entering state [received][100]
2014-02-27 15:13:05.086534 [DEBUG] sofia.c:5824 Remote SDP:
v=0
o=- 269323 1 IN IP4 10.111.11.10
s=-
c=IN IP4 10.111.11.17
t=0 0
m=audio 5218 RTP/AVP 0 8 18 101 111
c=IN IP4 10.111.11.17
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:111 X-nt-inforeq/8000
a=ptime:20

2014-02-27 15:13:05.086534 [DEBUG] sofia.c:6071 (sofia/external/23673)
State Change CS_NEW -> CS_INIT
2014-02-27 15:13:05.086534 [DEBUG] switch_core_session.c:1351 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:434
(sofia/external/23673) State NEW
2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:415
(sofia/external/23673) Running State Change CS_INIT
2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:455
(sofia/external/23673) State INIT
2014-02-27 15:13:05.086534 [DEBUG] mod_sofia.c:87 sofia/external/23673
SOFIA INIT
2014-02-27 15:13:05.086534 [DEBUG] mod_sofia.c:127 (sofia/external/23673)
State Change CS_INIT -> CS_ROUTING
2014-02-27 15:13:05.086534 [DEBUG] switch_core_session.c:1351 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:455
(sofia/external/23673) State INIT going to sleep
2014-02-27 15:13:05.086534 [DEBUG] switch_core_state_machine.c:415
(sofia/external/23673) Running State Change CS_ROUTING
2014-02-27 15:13:05.086534 [DEBUG] switch_channel.c:2163
(sofia/external/23673) Callstate Change DOWN -> RINGING
2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:471
(sofia/external/23673) State ROUTING
2014-02-27 15:13:05.106494 [DEBUG] mod_sofia.c:150 sofia/external/23673
SOFIA ROUTING
2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:117
sofia/external/23673 Standard ROUTING
2014-02-27 15:13:05.106494 [INFO] mod_dialplan_xml.c:558 Processing
23673;phone-context=location.systemname
<23673;phone-context=location.systemname>->28365;phone-context=location.systemname
in context public
Dialplan: sofia/external/23673 parsing [public->unloop] continue=false
Dialplan: sofia/external/23673 Regex (PASS) [unloop] ${unroll_loops}(true)
=~ /^true$/ break=on-false
Dialplan: sofia/external/23673 Regex (FAIL) [unloop] ${sip_looped_call}()
=~ /^true$/ break=on-false
Dialplan: sofia/external/23673 parsing [public->outside_call] continue=true
Dialplan: sofia/external/23673 Absolute Condition [outside_call]
Dialplan: sofia/external/23673 Action set(outside_call=true)
Dialplan: sofia/external/23673 Action export(RFC2822_DATE=${strftime(%a, %d
%b %Y %T %z)})
Dialplan: sofia/external/23673 parsing [public->call_debug] continue=true
Dialplan: sofia/external/23673 Regex (FAIL) [call_debug]
${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/23673 parsing [public->public_extensions]
continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [public_extensions]
destination_number(28365;phone-context=location.systemname) =~
/^([456][0-9][0-9][0-9]/d?)$/ break=on-false
Dialplan: sofia/external/23673 parsing [public->public_did_mgw00_inbound]
continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [public_did_mgw00_inbound]
destination_number(28365;phone-context=location.systemname) =~ /^(\d{5})$/
break=on-false
Dialplan: sofia/external/23673 parsing [public->public_did_nortel_inbound]
continue=false
Dialplan: sofia/external/23673 Regex (PASS) [public_did_nortel_inbound]
destination_number(28365;phone-context=location.systemname) =~
/^(\d{5});(.*)$/ break=on-false
Dialplan: sofia/external/23673 Action answer()
Dialplan: sofia/external/23673 Action say(en number iterated 28365)
Dialplan: sofia/external/23673 Action sleep(1000)
Dialplan: sofia/external/23673 Action set(domain_name=10.20.30.123)
Dialplan: sofia/external/23673 Action transfer(28365 XML default)
2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:167
(sofia/external/23673) State Change CS_ROUTING -> CS_EXECUTE
2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1351 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:471
(sofia/external/23673) State ROUTING going to sleep
2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:415
(sofia/external/23673) Running State Change CS_EXECUTE
2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:478
(sofia/external/23673) State EXECUTE
2014-02-27 15:13:05.106494 [DEBUG] mod_sofia.c:243 sofia/external/23673
SOFIA EXECUTE
2014-02-27 15:13:05.106494 [DEBUG] switch_core_state_machine.c:209
sofia/external/23673 Standard EXECUTE
EXECUTE sofia/external/23673 set(outside_call=true)
2014-02-27 15:13:05.106494 [DEBUG] mod_dptools.c:1402 sofia/external/23673
SET [outside_call]=[true]
EXECUTE sofia/external/23673 export(RFC2822_DATE=Thu, 27 Feb 2014 15:13:05
-0500)
2014-02-27 15:13:05.106494 [DEBUG] switch_channel.c:1242 EXPORT
(export_vars) [RFC2822_DATE]=[Thu, 27 Feb 2014 15:13:05 -0500]
EXECUTE sofia/external/23673 answer()
2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:5282 Audio Codec Compare
[PCMU:0:8000:20:64000]/[G722:9:8000:20:64000]
2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:5282 Audio Codec Compare
[PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:3190 Set Codec
sofia/external/23673 PCMU/8000 20 ms 160 samples 64000 bits
2014-02-27 15:13:05.106494 [DEBUG] switch_core_codec.c:111
sofia/external/23673 Original read codec set to PCMU:0
2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf
send/recv payload to 101
2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:3449 AUDIO RTP
[sofia/external/23673] 10.20.30.123 port 20854 -> 10.111.11.17 port 5218
codec: 0 ms: 20
2014-02-27 15:13:05.106494 [DEBUG] switch_rtp.c:2033 Starting timer [soft]
160 bytes per 20ms
2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf send
payload to 101
2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf receive
payload to 101
2014-02-27 15:13:05.106494 [DEBUG] sofia_glue.c:3749 sofia/external/23673
Set rtp dtmf delay to 40
2014-02-27 15:13:05.106494 [NOTICE] sofia_glue.c:4360 Pre-Answer
sofia/external/23673!
2014-02-27 15:13:05.106494 [DEBUG] switch_channel.c:3367
(sofia/external/23673) Callstate Change RINGING -> EARLY
2014-02-27 15:13:05.106494 [DEBUG] mod_sofia.c:866 Local SDP
sofia/external/23673:
v=0
o=FreeSWITCH 1393511131 1393511132 IN IP4 10.20.30.123
s=FreeSWITCH
c=IN IP4 10.20.30.123
t=0 0
m=audio 20854 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1016 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.106494 [DEBUG] sofia.c:5811 Channel
sofia/external/23673 entering state [completed][200]
2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:871 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.106494 [NOTICE] mod_dptools.c:1225 Channel
[sofia/external/23673] has been answered
2014-02-27 15:13:05.106494 [DEBUG] switch_channel.c:3646
(sofia/external/23673) Callstate Change EARLY -> ACTIVE
EXECUTE sofia/external/23673 say(en number iterated 28365)
2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1016 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1016 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1016 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.106494 [DEBUG] switch_core_session.c:1016 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:05.126485 [DEBUG] sofia.c:5811 Channel
sofia/external/23673 entering state [ready][200]
2014-02-27 15:13:05.126485 [DEBUG] switch_ivr_play_say.c:1314 Codec
Activated L16 at 8000hz 1 channels 20ms
2014-02-27 15:13:05.226537 [DEBUG] switch_rtp.c:3749 Correct ip/port
confirmed.
2014-02-27 15:13:07.666516 [DEBUG] switch_ivr_play_say.c:1717 done playing
file
file_string://digits/2.wav!digits/8.wav!digits/3.wav!digits/6.wav!digits/5.wav
EXECUTE sofia/external/23673 sleep(1000)
EXECUTE sofia/external/23673 set(domain_name=10.20.30.123)
2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402 sofia/external/23673
SET [domain_name]=[10.20.30.123]
EXECUTE sofia/external/23673 transfer(28365 XML default)
2014-02-27 15:13:08.666549 [DEBUG] switch_ivr.c:1832 (sofia/external/23673)
State Change CS_EXECUTE -> CS_ROUTING
2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1351 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:871 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:08.666549 [NOTICE] switch_ivr.c:1839 Transfer
sofia/external/23673 to XML[28365 at default]
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:478
(sofia/external/23673) State EXECUTE going to sleep
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:415
(sofia/external/23673) Running State Change CS_ROUTING
2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:2163
(sofia/external/23673) Callstate Change ACTIVE -> RINGING
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:471
(sofia/external/23673) State ROUTING
2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:150 sofia/external/23673
SOFIA ROUTING
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:117
sofia/external/23673 Standard ROUTING
2014-02-27 15:13:08.666549 [INFO] mod_dialplan_xml.c:558 Processing
23673;phone-context=location.systemname
<23673;phone-context=location.systemname>->28365 in context default
Dialplan: sofia/external/23673 parsing [default->unloop] continue=false
Dialplan: sofia/external/23673 Regex (PASS) [unloop] ${unroll_loops}(true)
=~ /^true$/ break=on-false
Dialplan: sofia/external/23673 Regex (FAIL) [unloop] ${sip_looped_call}()
=~ /^true$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->tod_example] continue=true
Dialplan: sofia/external/23673 Date/Time Match (PASS) [tod_example]
break=on-false
Dialplan: sofia/external/23673 Action set(open=true)
Dialplan: sofia/external/23673 parsing [default->tod_brevard] continue=true
Dialplan: sofia/external/23673 Date/Time Match (PASS) [tod_brevard]
break=on-false
Dialplan: sofia/external/23673 Action set(open=true)
Dialplan: sofia/external/23673 parsing [default->holiday_example]
continue=true
Dialplan: sofia/external/23673 Date/TimeMatch (FAIL) [holiday_example]
break=on-false
Dialplan: sofia/external/23673 parsing [default->global-intercept]
continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [global-intercept]
destination_number(28365) =~ /^886$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->group-intercept]
continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [group-intercept]
destination_number(28365) =~ /^\*8$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->intercept-ext]
continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [intercept-ext]
destination_number(28365) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->redial] continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [redial]
destination_number(28365) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->global] continue=true
Dialplan: sofia/external/23673 Regex (FAIL) [global] ${call_debug}(false)
=~ /^true$/ break=never
Dialplan: sofia/external/23673 Regex (FAIL) [global] ${sip_has_crypto}() =~
/^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never
Dialplan: sofia/external/23673 Regex (FAIL) [global]
${endpoint_disposition}(ANSWER) =~ /^(DELAYED NEGOTIATION)/ break=on-false
Dialplan: sofia/external/23673 parsing [default->eavesdrop] continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [eavesdrop]
destination_number(28365) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->eavesdrop] continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [eavesdrop]
destination_number(28365) =~ /^779$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->call_return] continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [call_return]
destination_number(28365) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->del-group] continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [del-group]
destination_number(28365) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->add-group] continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [add-group]
destination_number(28365) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->call-group-simo]
continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [call-group-simo]
destination_number(28365) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->call-group-order]
continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [call-group-order]
destination_number(28365) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->extension-intercom]
continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [extension-intercom]
destination_number(28365) =~ /^8([456][0-9][0-9][0-9][0-9])$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->Local_Extension_4_digit]
continue=false
Dialplan: sofia/external/23673 Regex (FAIL) [Local_Extension_4_digit]
destination_number(28365) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/23673 parsing [default->Local_Extension_5_digit]
continue=false
Dialplan: sofia/external/23673 Regex (PASS) [Local_Extension_5_digit]
destination_number(28365) =~ /^(5[0-9][0-9][0-9][0-9])$/ break=on-false
Dialplan: sofia/external/23673 Action export(dialed_extension=28365)
Dialplan: sofia/external/23673 Action bind_meta_app(1 b s
execute_extension::dx XML features)
Dialplan: sofia/external/23673 Action bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)

Dialplan: sofia/external/23673 Action bind_meta_app(3 b s
execute_extension::cf XML features)
Dialplan: sofia/external/23673 Action bind_meta_app(4 b s
execute_extension::att_xfer XML features)
Dialplan: sofia/external/23673 Action set(ringback=${us-ring})
Dialplan: sofia/external/23673 Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/external/23673 Action set(call_timeout=30)
Dialplan: sofia/external/23673 Action set(hangup_after_bridge=true)
Dialplan: sofia/external/23673 Action set(continue_on_fail=true)
Dialplan: sofia/external/23673 Action
hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})

Dialplan: sofia/external/23673 Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/external/23673 Action
set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
var callgroup)})
Dialplan: sofia/external/23673 Action
hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
Dialplan: sofia/external/23673 Action
hash(insert/${domain_name}-last_dial_ext/global/${uuid})
Dialplan: sofia/external/23673 Action
hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/external/23673 Action
bridge(user/${dialed_extension}@${domain_name})

Dialplan: sofia/external/23673 Action answer()
Dialplan: sofia/external/23673 Action sleep(1000)
Dialplan: sofia/external/23673 Action bridge(loopback/app=voicemail:default
${domain_name} ${dialed_extension})
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:167
(sofia/external/23673) State Change CS_ROUTING -> CS_EXECUTE
2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1351 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:471
(sofia/external/23673) State ROUTING going to sleep
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:415
(sofia/external/23673) Running State Change CS_EXECUTE
2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:2165
(sofia/external/23673) Callstate Change RINGING -> ACTIVE
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:478
(sofia/external/23673) State EXECUTE
2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:243 sofia/external/23673
SOFIA EXECUTE
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:209
sofia/external/23673 Standard EXECUTE
EXECUTE sofia/external/23673 set(open=true)
2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402 sofia/external/23673
SET [open]=[true]
EXECUTE sofia/external/23673 set(open=true)
2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402 sofia/external/23673
SET [open]=[true]
EXECUTE sofia/external/23673 export(dialed_extension=28365)
2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1242 EXPORT
(export_vars) [dialed_extension]=[28365]
EXECUTE sofia/external/23673 bind_meta_app(1 b s execute_extension::dx XML
features)
2014-02-27 15:13:08.666549 [INFO] switch_ivr_async.c:3701 Bound B-Leg: *1
execute_extension::dx XML features
EXECUTE sofia/external/23673 bind_meta_app(2 b s
record_session::/usr/local/freeswitch/recordings/23673;phone-context=location.systemname.2014-02-27-15-13-08.wav)
2014-02-27 15:13:08.666549 [INFO] switch_ivr_async.c:3701 Bound B-Leg: *2
record_session::/usr/local/freeswitch/recordings/23673;phone-context=location.systemname.2014-02-27-15-13-08.wav
EXECUTE sofia/external/23673 bind_meta_app(3 b s execute_extension::cf XML
features)
2014-02-27 15:13:08.666549 [INFO] switch_ivr_async.c:3701 Bound B-Leg: *3
execute_extension::cf XML features
EXECUTE sofia/external/23673 bind_meta_app(4 b s
execute_extension::att_xfer XML features)
2014-02-27 15:13:08.666549 [INFO] switch_ivr_async.c:3701 Bound B-Leg: *4
execute_extension::att_xfer XML features
EXECUTE sofia/external/23673 set(ringback=%(2000,4000,440,480))
2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402 sofia/external/23673
SET [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/external/23673 set(transfer_ringback=local_stream://moh)
2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402 sofia/external/23673
SET [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/external/23673 set(call_timeout=30)
2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402 sofia/external/23673
SET [call_timeout]=[30]
EXECUTE sofia/external/23673 set(hangup_after_bridge=true)
2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402 sofia/external/23673
SET [hangup_after_bridge]=[true]
EXECUTE sofia/external/23673 set(continue_on_fail=true)
2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402 sofia/external/23673
SET [continue_on_fail]=[true]
EXECUTE sofia/external/23673
hash(insert/10.20.30.123-call_return/28365/23673;phone-context=location.systemname)
EXECUTE sofia/external/23673
hash(insert/10.20.30.123-last_dial_ext/28365/910ede7a-9feb-11e3-9a55-09241ec9370d)
EXECUTE sofia/external/23673 set(called_party_callgroup=techsupport)
2014-02-27 15:13:08.666549 [DEBUG] mod_dptools.c:1402 sofia/external/23673
SET [called_party_callgroup]=[techsupport]
EXECUTE sofia/external/23673
hash(insert/10.20.30.123-last_dial_ext/techsupport/910ede7a-9feb-11e3-9a55-09241ec9370d)
EXECUTE sofia/external/23673
hash(insert/10.20.30.123-last_dial_ext/global/910ede7a-9feb-11e3-9a55-09241ec9370d)
EXECUTE sofia/external/23673
hash(insert/10.20.30.123-last_dial/techsupport/910ede7a-9feb-11e3-9a55-09241ec9370d)
EXECUTE sofia/external/23673 bridge(user/28365 at 10.20.30.123)
2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1763
(sofia/external/23673) Callstate Change ACTIVE -> RING_WAIT
2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1196
sofia/external/23673 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 27 Feb
2014 15:13:05 -0500] to event
2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1196
sofia/external/23673 EXPORTING[export_vars] [dialed_extension]=[28365] to
event
2014-02-27 15:13:08.666549 [DEBUG] switch_ivr_originate.c:2069 Parsing
global variables
2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1196
sofia/external/23673 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 27 Feb
2014 15:13:05 -0500] to event
2014-02-27 15:13:08.666549 [DEBUG] switch_channel.c:1196
sofia/external/23673 EXPORTING[export_vars] [dialed_extension]=[28365] to
event
2014-02-27 15:13:08.666549 [DEBUG] switch_ivr_originate.c:2069 Parsing
global variables
2014-02-27 15:13:08.666549 [DEBUG] switch_event.c:1661 Parsing variable
[sip_invite_domain]=[10.20.30.123]
2014-02-27 15:13:08.666549 [DEBUG] switch_event.c:1661 Parsing variable
[presence_id]=[28365 at 10.20.30.123]
2014-02-27 15:13:08.666549 [NOTICE] switch_channel.c:1050 New Channel
sofia/internal/sip:28365 at 10.20.30.121 [93309eb4-9feb-11e3-9a76-09241ec9370d]
2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:5230 (sofia/internal/
sip:28365 at 10.20.30.121) State Change CS_NEW -> CS_INIT
2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1351 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:5300 [zrtp_passthru] Setting
a-leg inherit_codec=true
2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:5303 [zrtp_passthru] Setting
b-leg absolute_codec_string='PCMU at 8000h@20i at 64000b,PCMA at 8000h@20i at 64000b'
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:28365 at 10.20.30.121) Running State Change CS_INIT
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:455
(sofia/internal/sip:28365 at 10.20.30.121) State INIT
2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:87 sofia/internal/
sip:28365 at 10.20.30.121 SOFIA INIT
2014-02-27 15:13:08.666549 [DEBUG] sofia_glue.c:2744 sofia/internal/
sip:28365 at 10.20.30.121 sending invite version: 1.2.22 git aabf813
2014-02-24 01:22:36Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1393508912 1393508913 IN IP4 10.20.30.123
s=FreeSWITCH
c=IN IP4 10.20.30.123
t=0 0
m=audio 23076 RTP/AVP 0 8 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1016 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:127 (sofia/internal/
sip:28365 at 10.20.30.121) State Change CS_INIT -> CS_ROUTING
2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1351 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:455
(sofia/internal/sip:28365 at 10.20.30.121) State INIT going to sleep
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:28365 at 10.20.30.121) Running State Change CS_ROUTING
2014-02-27 15:13:08.666549 [DEBUG] sofia.c:5811 Channel sofia/internal/
sip:28365 at 10.20.30.121 entering state [calling][0]
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/sip:28365 at 10.20.30.121) State ROUTING
2014-02-27 15:13:08.666549 [DEBUG] mod_sofia.c:150 sofia/internal/
sip:28365 at 10.20.30.121 SOFIA ROUTING
2014-02-27 15:13:08.666549 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/sip:28365 at 10.20.30.121) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2014-02-27 15:13:08.666549 [DEBUG] switch_core_session.c:1351 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
2014-02-27 15:13:08.666549 [DEBUG] switch_core_state_machine.c:471
(sofia/internal/sip:28365 at 10.20.30.121) State ROUTING going to sleep
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:28365 at 10.20.30.121) Running State Change
CS_CONSUME_MEDIA
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:490
(sofia/internal/sip:28365 at 10.20.30.121) State CONSUME_MEDIA
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:490
(sofia/internal/sip:28365 at 10.20.30.121) State CONSUME_MEDIA going to sleep
2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1016 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1016 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1016 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
2014-02-27 15:13:08.686500 [DEBUG] sofia.c:5811 Channel sofia/internal/
sip:28365 at 10.20.30.121 entering state [terminated][415]
2014-02-27 15:13:08.686500 [NOTICE] sofia.c:6655 Hangup sofia/internal/
sip:28365 at 10.20.30.121 [CS_CONSUME_MEDIA] [SERVICE_NOT_IMPLEMENTED]
2014-02-27 15:13:08.686500 [DEBUG] switch_channel.c:3186 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [KILL]
2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1351 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:28365 at 10.20.30.121) Running State Change CS_HANGUP
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:678
(sofia/internal/sip:28365 at 10.20.30.121) Callstate Change DOWN -> HANGUP
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:680
(sofia/internal/sip:28365 at 10.20.30.121) State HANGUP
2014-02-27 15:13:08.686500 [DEBUG] mod_sofia.c:506 Channel sofia/internal/
sip:28365 at 10.20.30.121 hanging up, cause: SERVICE_NOT_IMPLEMENTED
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:48
sofia/internal/sip:28365 at 10.20.30.121 Standard HANGUP, cause:
SERVICE_NOT_IMPLEMENTED
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:680
(sofia/internal/sip:28365 at 10.20.30.121) State HANGUP going to sleep
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:447
(sofia/internal/sip:28365 at 10.20.30.121) State Change CS_HANGUP ->
CS_REPORTING
2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1351 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:415
(sofia/internal/sip:28365 at 10.20.30.121) Running State Change CS_REPORTING
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:764
(sofia/internal/sip:28365 at 10.20.30.121) State REPORTING
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:92
sofia/internal/sip:28365 at 10.20.30.121 Standard REPORTING, cause:
SERVICE_NOT_IMPLEMENTED
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:764
(sofia/internal/sip:28365 at 10.20.30.121) State REPORTING going to sleep
2014-02-27 15:13:08.686500 [DEBUG] switch_core_state_machine.c:441
(sofia/internal/sip:28365 at 10.20.30.121) State Change CS_REPORTING ->
CS_DESTROY
2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1351 Send signal
sofia/internal/sip:28365 at 10.20.30.121 [BREAK]
2014-02-27 15:13:08.686500 [DEBUG] switch_core_session.c:1559 Session 2
(sofia/internal/sip:28365 at 10.20.30.121) Locked, Waiting on external entities
2014-02-27 15:13:08.706527 [DEBUG] switch_ivr_originate.c:3657 Originate
Resulted in Error Cause: 79 [SERVICE_NOT_IMPLEMENTED]
2014-02-27 15:13:08.706527 [DEBUG] switch_channel.c:1967
(sofia/external/23673) Callstate Change RING_WAIT -> ACTIVE
2014-02-27 15:13:08.706527 [NOTICE] switch_ivr_originate.c:2670 Cannot
create outgoing channel of type [user] cause: [SERVICE_NOT_IMPLEMENTED]
2014-02-27 15:13:08.706527 [DEBUG] switch_ivr_originate.c:3657 Originate
Resulted in Error Cause: 79 [SERVICE_NOT_IMPLEMENTED]
2014-02-27 15:13:08.706527 [INFO] mod_dptools.c:3201 Originate Failed.
Cause: SERVICE_NOT_IMPLEMENTED
EXECUTE sofia/external/23673 answer()
EXECUTE sofia/external/23673 sleep(1000)
2014-02-27 15:13:08.706527 [NOTICE] switch_core_session.c:1577 Session 2
(sofia/internal/sip:28365 at 10.20.30.121) Ended
2014-02-27 15:13:08.706527 [NOTICE] switch_core_session.c:1581 Close
Channel sofia/internal/sip:28365 at 10.20.30.121 [CS_DESTROY]
2014-02-27 15:13:08.706527 [DEBUG] switch_core_state_machine.c:566
(sofia/internal/sip:28365 at 10.20.30.121) Callstate Change HANGUP -> DOWN
2014-02-27 15:13:08.706527 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/sip:28365 at 10.20.30.121) Running State Change CS_DESTROY
2014-02-27 15:13:08.706527 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/sip:28365 at 10.20.30.121) State DESTROY
2014-02-27 15:13:08.706527 [DEBUG] mod_sofia.c:399 sofia/internal/
sip:28365 at 10.20.30.121 SOFIA DESTROY
2014-02-27 15:13:08.706527 [DEBUG] switch_core_state_machine.c:99
sofia/internal/sip:28365 at 10.20.30.121 Standard DESTROY
2014-02-27 15:13:08.706527 [DEBUG] switch_core_state_machine.c:579
(sofia/internal/sip:28365 at 10.20.30.121) State DESTROY going to sleep
EXECUTE sofia/external/23673 bridge(loopback/app=voicemail:default
10.20.30.123 28365)
2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:1763
(sofia/external/23673) Callstate Change ACTIVE -> RING_WAIT
2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:1196
sofia/external/23673 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 27 Feb
2014 15:13:05 -0500] to event
2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:1196
sofia/external/23673 EXPORTING[export_vars] [dialed_extension]=[28365] to
event
2014-02-27 15:13:09.706545 [DEBUG] switch_ivr_originate.c:2069 Parsing
global variables
2014-02-27 15:13:09.706545 [NOTICE] switch_channel.c:1050 New Channel
loopback/app=voicemail:default 10.20.30.123 28365-a
[93cd50f6-9feb-11e3-9a7f-09241ec9370d]
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:157
loopback/app=voicemail:default 10.20.30.123 28365-a setup codec PCMU/8000/20
2014-02-27 15:13:09.706545 [NOTICE] switch_channel.c:1048 Rename Channel
loopback/app=voicemail:default 10.20.30.123 28365-a->loopback/voicemail-a
[93cd50f6-9feb-11e3-9a7f-09241ec9370d]
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:1158
(loopback/voicemail-a) State Change CS_NEW -> CS_INIT
2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-a [BREAK]
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588 loopback/voicemail-a
CHANNEL KILL
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_INIT
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:455
(loopback/voicemail-a) State INIT
2014-02-27 15:13:09.706545 [NOTICE] switch_channel.c:1050 New Channel
loopback/voicemail-b [93cd7874-9feb-11e3-9a83-09241ec9370d]
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:157 loopback/voicemail-b
setup codec PCMU/8000/20
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:272
(loopback/voicemail-b) State Change CS_NEW -> CS_INIT
2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-b [BREAK]
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588 loopback/voicemail-b
CHANNEL KILL
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:357
(loopback/voicemail-a) State Change CS_INIT -> CS_ROUTING
2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-a [BREAK]
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588 loopback/voicemail-a
CHANNEL KILL
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:455
(loopback/voicemail-a) State INIT going to sleep
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_ROUTING
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:471
(loopback/voicemail-a) State ROUTING
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:389 loopback/voicemail-a
CHANNEL ROUTING
2014-02-27 15:13:09.706545 [DEBUG] switch_ivr_originate.c:67
(loopback/voicemail-a) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-a [BREAK]
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588 loopback/voicemail-a
CHANNEL KILL
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:471
(loopback/voicemail-a) State ROUTING going to sleep
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_CONSUME_MEDIA
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:490
(loopback/voicemail-a) State CONSUME_MEDIA
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:648 CHANNEL CONSUME_MEDIA
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:490
(loopback/voicemail-a) State CONSUME_MEDIA going to sleep
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-b) Running State Change CS_INIT
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:455
(loopback/voicemail-b) State INIT
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:357
(loopback/voicemail-b) State Change CS_INIT -> CS_ROUTING
2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-b [BREAK]
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588 loopback/voicemail-b
CHANNEL KILL
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:455
(loopback/voicemail-b) State INIT going to sleep
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-b) Running State Change CS_ROUTING
2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:2163
(loopback/voicemail-b) Callstate Change DOWN -> RINGING
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:471
(loopback/voicemail-b) State ROUTING
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:389 loopback/voicemail-b
CHANNEL ROUTING
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:408
(loopback/voicemail-b) State Change CS_ROUTING -> CS_EXECUTE
2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-b [BREAK]
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588 loopback/voicemail-b
CHANNEL KILL
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:471
(loopback/voicemail-b) State ROUTING going to sleep
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-b) Running State Change CS_EXECUTE
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:478
(loopback/voicemail-b) State EXECUTE
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:431 loopback/voicemail-b
CHANNEL EXECUTE
2014-02-27 15:13:09.706545 [DEBUG] switch_core_state_machine.c:209
loopback/voicemail-b Standard EXECUTE
EXECUTE loopback/voicemail-b pre_answer()
2014-02-27 15:13:09.706545 [NOTICE] mod_loopback.c:945 Pre-Answer
loopback/voicemail-a!
2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:3363 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:3367
(loopback/voicemail-a) Callstate Change DOWN -> EARLY
2014-02-27 15:13:09.706545 [DEBUG] switch_core_session.c:871 Send signal
loopback/voicemail-b [BREAK]
2014-02-27 15:13:09.706545 [DEBUG] mod_loopback.c:588 loopback/voicemail-b
CHANNEL KILL
2014-02-27 15:13:09.706545 [NOTICE] mod_dptools.c:1260 Pre-Answer
loopback/voicemail-b!
2014-02-27 15:13:09.706545 [DEBUG] switch_channel.c:3367
(loopback/voicemail-b) Callstate Change RINGING -> EARLY
EXECUTE loopback/voicemail-b voicemail(default 10.20.30.123 28365)
2014-02-27 15:13:09.726502 [DEBUG] switch_ivr_originate.c:3513 Originate
Resulted in Success: [loopback/voicemail-a]
2014-02-27 15:13:09.726502 [DEBUG] switch_channel.c:1967
(sofia/external/23673) Callstate Change RING_WAIT -> ACTIVE
2014-02-27 15:13:09.726502 [DEBUG] switch_core_session.c:871 Send signal
loopback/voicemail-a [BREAK]
2014-02-27 15:13:09.726502 [DEBUG] mod_loopback.c:588 loopback/voicemail-a
CHANNEL KILL
2014-02-27 15:13:09.726502 [DEBUG] switch_core_session.c:871 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:09.726502 [DEBUG] switch_ivr_bridge.c:1429
(loopback/voicemail-a) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2014-02-27 15:13:09.726502 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-a [BREAK]
2014-02-27 15:13:09.726502 [DEBUG] mod_loopback.c:588 loopback/voicemail-a
CHANNEL KILL
2014-02-27 15:13:09.726502 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_EXCHANGE_MEDIA
2014-02-27 15:13:09.726502 [DEBUG] switch_core_state_machine.c:481
(loopback/voicemail-a) State EXCHANGE_MEDIA
2014-02-27 15:13:09.726502 [DEBUG] mod_loopback.c:610 CHANNEL LOOPBACK
2014-02-27 15:13:09.826538 [DEBUG] switch_ivr_play_say.c:70 No language
specified - Using [en]
2014-02-27 15:13:09.826538 [DEBUG] switch_ivr_play_say.c:251 Handle
play-file:[voicemail/vm-person.wav] (en:en)
2014-02-27 15:13:09.826538 [DEBUG] switch_ivr_play_say.c:1314 Codec
Activated L16 at 8000hz 1 channels 20ms
2014-02-27 15:13:11.206539 [DEBUG] switch_ivr_play_say.c:1717 done playing
file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-person.wav
2014-02-27 15:13:11.306570 [DEBUG] switch_ivr_play_say.c:251 Handle
say:[28365] (en:en)
2014-02-27 15:13:11.306570 [DEBUG] switch_ivr_play_say.c:1314 Codec
Activated L16 at 8000hz 1 channels 20ms
2014-02-27 15:13:13.866518 [DEBUG] switch_ivr_play_say.c:1717 done playing
file
file_string://digits/5.wav!digits/7.wav!digits/3.wav!digits/3.wav!digits/1.wav
2014-02-27 15:13:13.966519 [DEBUG] switch_ivr_play_say.c:251 Handle
play-file:[voicemail/vm-not_available.wav] (en:en)
2014-02-27 15:13:13.966519 [DEBUG] switch_ivr_play_say.c:1314 Codec
Activated L16 at 8000hz 1 channels 20ms
2014-02-27 15:13:14.946549 [DEBUG] switch_ivr_play_say.c:1717 done playing
file
/usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-not_available.wav
2014-02-27 15:13:15.046549 [DEBUG] switch_ivr_play_say.c:70 No language
specified - Using [en]
2014-02-27 15:13:15.046549 [DEBUG] switch_ivr_play_say.c:251 Handle
play-file:[voicemail/vm-record_message.wav] (en:en)
2014-02-27 15:13:15.046549 [DEBUG] switch_ivr_play_say.c:1314 Codec
Activated L16 at 8000hz 1 channels 20ms
2014-02-27 15:13:15.646531 [DEBUG] switch_core_session.c:1016 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:15.666534 [NOTICE] sofia.c:737 Hangup sofia/external/23673
[CS_EXECUTE] [NORMAL_CLEARING]
2014-02-27 15:13:15.666534 [DEBUG] switch_channel.c:3186 Send signal
sofia/external/23673 [KILL]
2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:633 BRIDGE THREAD
DONE [sofia/external/23673]
2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:661 Send signal
loopback/voicemail-a [BREAK]
2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588 loopback/voicemail-a
CHANNEL KILL
2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:557
sofia/external/23673 ending bridge by request from write function
2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:633 BRIDGE THREAD
DONE [loopback/voicemail-a]
2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:661 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:15.666534 [NOTICE] switch_ivr_bridge.c:722 Hangup
loopback/voicemail-a [CS_EXCHANGE_MEDIA] [ORIGINATOR_CANCEL]
2014-02-27 15:13:15.666534 [DEBUG] switch_channel.c:3186 Send signal
loopback/voicemail-a [KILL]
2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588 loopback/voicemail-a
CHANNEL KILL
2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-a [BREAK]
2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588 loopback/voicemail-a
CHANNEL KILL
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:481
(loopback/voicemail-a) State EXCHANGE_MEDIA going to sleep
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_HANGUP
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:678
(loopback/voicemail-a) Callstate Change EARLY -> HANGUP
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:680
(loopback/voicemail-a) State HANGUP
2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:535 loopback/voicemail-a
CHANNEL HANGUP
2014-02-27 15:13:15.666534 [NOTICE] mod_loopback.c:551 Hangup
loopback/voicemail-b [CS_EXECUTE] [ORIGINATOR_CANCEL]
2014-02-27 15:13:15.666534 [DEBUG] switch_channel.c:3186 Send signal
loopback/voicemail-b [KILL]
2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588 loopback/voicemail-b
CHANNEL KILL
2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-b [BREAK]
2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588 loopback/voicemail-b
CHANNEL KILL
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:48
loopback/voicemail-a Standard HANGUP, cause: ORIGINATOR_CANCEL
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:680
(loopback/voicemail-a) State HANGUP going to sleep
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:447
(loopback/voicemail-a) State Change CS_HANGUP -> CS_REPORTING
2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-a [BREAK]
2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588 loopback/voicemail-a
CHANNEL KILL
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-a) Running State Change CS_REPORTING
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:764
(loopback/voicemail-a) State REPORTING
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:92
loopback/voicemail-a Standard REPORTING, cause: ORIGINATOR_CANCEL
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:764
(loopback/voicemail-a) State REPORTING going to sleep
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:441
(loopback/voicemail-a) State Change CS_REPORTING -> CS_DESTROY
2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-a [BREAK]
2014-02-27 15:13:15.666534 [DEBUG] mod_loopback.c:588 loopback/voicemail-a
CHANNEL KILL
2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1559 Session 3
(loopback/voicemail-a) Locked, Waiting on external entities
2014-02-27 15:13:15.666534 [DEBUG] switch_ivr_bridge.c:1530
sofia/external/23673 skip receive message [UNBRIDGE] (channel is hungup
already)
2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:2810
sofia/external/23673 skip receive message [APPLICATION_EXEC_COMPLETE]
(channel is hungup already)
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:478
(sofia/external/23673) State EXECUTE going to sleep
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:415
(sofia/external/23673) Running State Change CS_HANGUP
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:678
(sofia/external/23673) Callstate Change ACTIVE -> HANGUP
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:680
(sofia/external/23673) State HANGUP
2014-02-27 15:13:15.666534 [DEBUG] mod_sofia.c:500 sofia/external/23673
Overriding SIP cause 480 with 415 from the other leg
2014-02-27 15:13:15.666534 [DEBUG] mod_sofia.c:506 Channel
sofia/external/23673 hanging up, cause: NORMAL_CLEARING
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:48
sofia/external/23673 Standard HANGUP, cause: NORMAL_CLEARING
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:680
(sofia/external/23673) State HANGUP going to sleep
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:447
(sofia/external/23673) State Change CS_HANGUP -> CS_REPORTING
2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:415
(sofia/external/23673) Running State Change CS_REPORTING
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:764
(sofia/external/23673) State REPORTING
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:92
sofia/external/23673 Standard REPORTING, cause: NORMAL_CLEARING
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:764
(sofia/external/23673) State REPORTING going to sleep
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:441
(sofia/external/23673) State Change CS_REPORTING -> CS_DESTROY
2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1351 Send signal
sofia/external/23673 [BREAK]
2014-02-27 15:13:15.666534 [DEBUG] switch_core_session.c:1559 Session 1
(sofia/external/23673) Locked, Waiting on external entities
2014-02-27 15:13:15.666534 [NOTICE] switch_core_session.c:1577 Session 1
(sofia/external/23673) Ended
2014-02-27 15:13:15.666534 [NOTICE] switch_core_session.c:1581 Close
Channel sofia/external/23673 [CS_DESTROY]
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:566
(sofia/external/23673) Callstate Change HANGUP -> DOWN
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:569
(sofia/external/23673) Running State Change CS_DESTROY
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:579
(sofia/external/23673) State DESTROY
2014-02-27 15:13:15.666534 [DEBUG] mod_sofia.c:399 sofia/external/23673
SOFIA DESTROY
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:99
sofia/external/23673 Standard DESTROY
2014-02-27 15:13:15.666534 [DEBUG] switch_core_state_machine.c:579
(sofia/external/23673) State DESTROY going to sleep
2014-02-27 15:13:15.686490 [DEBUG] switch_ivr_play_say.c:1717 done playing
file
/usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-record_message.wav
2014-02-27 15:13:15.686490 [DEBUG] switch_core_session.c:2810
loopback/voicemail-b skip receive message [APPLICATION_EXEC_COMPLETE]
(channel is hungup already)
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:478
(loopback/voicemail-b) State EXECUTE going to sleep
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-b) Running State Change CS_HANGUP
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:678
(loopback/voicemail-b) Callstate Change EARLY -> HANGUP
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:680
(loopback/voicemail-b) State HANGUP
2014-02-27 15:13:15.686490 [DEBUG] mod_loopback.c:535 loopback/voicemail-b
CHANNEL HANGUP
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:48
loopback/voicemail-b Standard HANGUP, cause: ORIGINATOR_CANCEL
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:680
(loopback/voicemail-b) State HANGUP going to sleep
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:447
(loopback/voicemail-b) State Change CS_HANGUP -> CS_REPORTING
2014-02-27 15:13:15.686490 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-b [BREAK]
2014-02-27 15:13:15.686490 [DEBUG] mod_loopback.c:588 loopback/voicemail-b
CHANNEL KILL
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:415
(loopback/voicemail-b) Running State Change CS_REPORTING
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:764
(loopback/voicemail-b) State REPORTING
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:92
loopback/voicemail-b Standard REPORTING, cause: ORIGINATOR_CANCEL
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:764
(loopback/voicemail-b) State REPORTING going to sleep
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:441
(loopback/voicemail-b) State Change CS_REPORTING -> CS_DESTROY
2014-02-27 15:13:15.686490 [DEBUG] switch_core_session.c:1351 Send signal
loopback/voicemail-b [BREAK]
2014-02-27 15:13:15.686490 [DEBUG] mod_loopback.c:588 loopback/voicemail-b
CHANNEL KILL
2014-02-27 15:13:15.686490 [DEBUG] switch_core_session.c:1559 Session 4
(loopback/voicemail-b) Locked, Waiting on external entities
2014-02-27 15:13:15.686490 [NOTICE] switch_core_session.c:1577 Session 4
(loopback/voicemail-b) Ended
2014-02-27 15:13:15.686490 [NOTICE] switch_core_session.c:1581 Close
Channel loopback/voicemail-b [CS_DESTROY]
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:566
(loopback/voicemail-b) Callstate Change HANGUP -> DOWN
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:569
(loopback/voicemail-b) Running State Change CS_DESTROY
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:579
(loopback/voicemail-b) State DESTROY
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:99
loopback/voicemail-b Standard DESTROY
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:579
(loopback/voicemail-b) State DESTROY going to sleep
2014-02-27 15:13:15.686490 [NOTICE] switch_core_session.c:1577 Session 3
(loopback/voicemail-a) Ended
2014-02-27 15:13:15.686490 [NOTICE] switch_core_session.c:1581 Close
Channel loopback/voicemail-a [CS_DESTROY]
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:566
(loopback/voicemail-a) Callstate Change HANGUP -> DOWN
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:569
(loopback/voicemail-a) Running State Change CS_DESTROY
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:579
(loopback/voicemail-a) State DESTROY
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:99
loopback/voicemail-a Standard DESTROY
2014-02-27 15:13:15.686490 [DEBUG] switch_core_state_machine.c:579
(loopback/voicemail-a) State DESTROY going to sleep
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140227/7abc0539/attachment-0001.html

Join us at ClueCon 2013 Aug 6-8, 2013
More information about the FreeSWITCH-users mailing list