freeswitch@internal>
freeswitch@internal>
freeswitch@internal> originate {origination_caller_id_name=55101,origination_caller_id_number=55101,igonre_early_media=true}sofia/external/sip:+2348124523790@10.200.161.132 5000
+OK c3869b92-c6c4-11e6-add0-0dd5d13e0dc6
2016-12-20 15:58:27.755418 [DEBUG] switch_ivr_originate.c:2100 Parsing global variables
2016-12-20 15:58:27.755418 [DEBUG] switch_event.c:1698 Parsing variable [origination_caller_id_name]=[55101]
2016-12-20 15:58:27.755418 [DEBUG] switch_event.c:1698 Parsing variable [origination_caller_id_number]=[55101]
2016-12-20 15:58:27.755418 [DEBUG] switch_event.c:1698 Parsing variable [igonre_early_media]=[true]
2016-12-20 15:58:27.755418 [NOTICE] switch_channel.c:1055 New Channel sofia/external/%2B2348124523790@10.200.161.132 [c3869b92-c6c4-11e6-add0-0dd5d13e0dc6]
2016-12-20 15:58:27.755418 [DEBUG] mod_sofia.c:4701 (sofia/external/%2B2348124523790@10.200.161.132) State Change CS_NEW -> CS_INIT
2016-12-20 15:58:27.755418 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:472 (sofia/external/%2B2348124523790@10.200.161.132) Running State Change CS_INIT
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:512 (sofia/external/%2B2348124523790@10.200.161.132) State INIT
2016-12-20 15:58:27.755418 [DEBUG] mod_sofia.c:87 sofia/external/%2B2348124523790@10.200.161.132 SOFIA INIT
2016-12-20 15:58:27.755418 [DEBUG] sofia_glue.c:1232 sofia/external/%2B2348124523790@10.200.161.132 sending invite version: 1.4.18 64bit
Local SDP:
v=0
o=FreeSWITCH 1482220153 1482220154 IN IP4 10.227.49.19
s=FreeSWITCH
c=IN IP4 10.227.49.19
t=0 0
m=audio 25754 RTP/AVP 0 8 3 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:40 sofia/external/%2B2348124523790@10.200.161.132 Standard INIT
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:48 (sofia/external/%2B2348124523790@10.200.161.132) State Change CS_INIT -> CS_ROUTING
2016-12-20 15:58:27.755418 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:512 (sofia/external/%2B2348124523790@10.200.161.132) State INIT going to sleep
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:472 (sofia/external/%2B2348124523790@10.200.161.132) Running State Change CS_ROUTING
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:528 (sofia/external/%2B2348124523790@10.200.161.132) State ROUTING
2016-12-20 15:58:27.755418 [DEBUG] mod_sofia.c:123 sofia/external/%2B2348124523790@10.200.161.132 SOFIA ROUTING
2016-12-20 15:58:27.755418 [DEBUG] switch_ivr_originate.c:67 (sofia/external/%2B2348124523790@10.200.161.132) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2016-12-20 15:58:27.755418 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:528 (sofia/external/%2B2348124523790@10.200.161.132) State ROUTING going to sleep
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:472 (sofia/external/%2B2348124523790@10.200.161.132) Running State Change CS_CONSUME_MEDIA
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:547 (sofia/external/%2B2348124523790@10.200.161.132) State CONSUME_MEDIA
2016-12-20 15:58:27.755418 [DEBUG] switch_core_state_machine.c:547 (sofia/external/%2B2348124523790@10.200.161.132) State CONSUME_MEDIA going to sleep
send 1050 bytes to udp/[10.200.161.132]:5060 at 15:58:27.766321:
------------------------------------------------------------------------
INVITE sip:+2348124523790@10.200.161.132 SIP/2.0
Via: SIP/2.0/UDP 10.227.47.13:5080;rport;branch=z9hG4bKXj2Nv4D43SS2e
Max-Forwards: 70
From: "55101" <sip:55101@10.227.47.13>;tag=U35jUNH2QU38H
To: <sip:+2348124523790@10.200.161.132>
Call-ID: 9ae5109e-4167-1235-c28a-000c293e4716
freeswitch@internal> CSeq: 100786889 INVITE
Contact: <sip:mod_sofia@10.227.47.13:5080>
User-Agent: FreeSWITCH-mod_sofia/1.4.18~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 270
X-FS-Support: update_display,send_info
Remote-Party-ID: "55101" <sip:55101@10.227.47.13>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1482220153 1482220154 IN IP4 10.227.49.19
s=FreeSWITCH
c=IN IP4 10.227.49.19
t=0 0
m=audio 25754 RTP/AVP 0 8 3 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2016-12-20 15:58:27.755418 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:27.755418 [DEBUG] sofia.c:6623 Channel sofia/external/%2B2348124523790@10.200.161.132 entering state [calling][0]
recv 307 bytes from udp/[10.200.161.132]:5060 at 15:58:27.791236:
------------------------------------------------------------------------
SIP/2.0 100 Trying
From: "55101" <sip:55101@10.227.47.13>;tag=U35jUNH2QU38H
To: <sip:+2348124523790@10.200.161.132>
Via: SIP/2.0/UDP 10.227.47.13:5080;rport;branch=z9hG4bKXj2Nv4D43SS2e;received=10.227.47.13
Call-ID: 9ae5109e-4167-1235-c28a-000c293e4716
CSeq: 100786889 INVITE
Content-Length: 0
------------------------------------------------------------------------
recv 706 bytes from udp/[10.200.161.132]:5060 at 15:58:30.353518:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
From: "55101" <sip:55101@10.227.47.13>;tag=U35jUNH2QU38H
To: <sip:+2348124523790@10.200.161.132>;tag=4203370473
Via: SIP/2.0/UDP 10.227.47.13:5080;rport;branch=z9hG4bKXj2Nv4D43SS2e;received=10.227.47.13
Call-ID: 9ae5109e-4167-1235-c28a-000c293e4716
CSeq: 100786889 INVITE
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,PRACK,UPDATE
Content-Type: application/sdp
Contact: <sip:10.200.161.132:5060;transport=UDP>
Content-Length: 242
v=0
o=- 1398662 1398662 IN IP4 TSS.LGTSS.LGTSS01.NG
s=-
c=IN IP4 10.200.12.27
t=0 0
a=sendrecv
m=audio 13100 RTP/AVP 8 101
c=IN IP4 10.200.12.27
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=maxptime:40
------------------------------------------------------------------------
2016-12-20 15:58:30.335408 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:30.335408 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:30.335408 [DEBUG] sofia.c:6623 Channel sofia/external/%2B2348124523790@10.200.161.132 entering state [proceeding][183]
2016-12-20 15:58:30.335408 [DEBUG] sofia.c:6633 Remote SDP:
v=0
o=- 1398662 1398662 IN IP4 TSS.LGTSS.LGTSS01.NG
s=-
c=IN IP4 10.200.12.27
t=0 0
a=sendrecv
m=audio 13100 RTP/AVP 8 101
c=IN IP4 10.200.12.27
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=maxptime:40
2016-12-20 15:58:30.335408 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:40:64000:1]/[PCMU:0:8000:20:64000:1]
2016-12-20 15:58:30.335408 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:40:64000:1]/[PCMA:8:8000:20:64000:1]
2016-12-20 15:58:30.335408 [DEBUG] switch_core_media.c:3687 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2016-12-20 15:58:30.335408 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:40:64000:1]/[GSM:3:8000:20:13200:1]
2016-12-20 15:58:30.335408 [DEBUG] switch_core_media.c:3548 Set telephone-event payload to 101
2016-12-20 15:58:30.335408 [DEBUG] switch_core_media.c:2473 Set Codec sofia/external/%2B2348124523790@10.200.161.132 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2016-12-20 15:58:30.335408 [DEBUG] switch_core_codec.c:111 sofia/external/%2B2348124523790@10.200.161.132 Original read codec set to PCMA:8
2016-12-20 15:58:30.335408 [DEBUG] switch_core_media.c:3886 Set 2833 dtmf send payload to 101
2016-12-20 15:58:30.335408 [DEBUG] switch_core_media.c:5147 AUDIO RTP [sofia/external/%2B2348124523790@10.200.161.132] 10.227.49.19 port 25754 -> 10.200.12.27 port 13100 codec: 8 ms: 20
2016-12-20 15:58:30.335408 [DEBUG] switch_rtp.c:3562 Starting timer [soft] 160 bytes per 20ms
2016-12-20 15:58:30.355402 [DEBUG] switch_core_media.c:5445 Set 2833 dtmf send payload to 101
2016-12-20 15:58:30.355402 [DEBUG] switch_core_media.c:5451 Set 2833 dtmf receive payload to 101
2016-12-20 15:58:30.355402 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/%2B2348124523790@10.200.161.132!
2016-12-20 15:58:30.355402 [DEBUG] switch_channel.c:3399 (sofia/external/%2B2348124523790@10.200.161.132) Callstate Change DOWN -> EARLY
2016-12-20 15:58:30.355402 [DEBUG] switch_ivr_originate.c:3577 Originate Resulted in Success: [sofia/external/%2B2348124523790@10.200.161.132]
2016-12-20 15:58:30.355402 [DEBUG] switch_ivr.c:1854 (sofia/external/%2B2348124523790@10.200.161.132) State Change CS_CONSUME_MEDIA -> CS_ROUTING
2016-12-20 15:58:30.355402 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:30.355402 [DEBUG] switch_core_session.c:912 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:30.355402 [NOTICE] switch_ivr.c:1861 Transfer sofia/external/%2B2348124523790@10.200.161.132 to XML[5000@default]
2016-12-20 15:58:30.355402 [DEBUG] switch_core_state_machine.c:472 (sofia/external/%2B2348124523790@10.200.161.132) Running State Change CS_ROUTING
2016-12-20 15:58:30.355402 [DEBUG] switch_core_state_machine.c:528 (sofia/external/%2B2348124523790@10.200.161.132) State ROUTING
2016-12-20 15:58:30.355402 [DEBUG] mod_sofia.c:123 sofia/external/%2B2348124523790@10.200.161.132 SOFIA ROUTING
2016-12-20 15:58:30.355402 [DEBUG] switch_core_state_machine.c:166 sofia/external/%2B2348124523790@10.200.161.132 Standard ROUTING
2016-12-20 15:58:30.355402 [INFO] mod_dialplan_xml.c:635 Processing 55101 <55101>->5000 in context default
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->unloop] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->tod_example] continue=true
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Date/Time Match (PASS) [tod_example] break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Action set(open=true)
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->holiday_example] continue=true
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Date/TimeMatch (FAIL) [holiday_example] break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->global-intercept] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [global-intercept] destination_number(5000) =~ /^886$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->group-intercept] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [group-intercept] destination_number(5000) =~ /^\*8$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->intercept-ext] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [intercept-ext] destination_number(5000) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->redial] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [redial] destination_number(5000) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->global] continue=true
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [global] ${default_password}(65432) =~ /^1234$/ break=never
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [global] ${endpoint_disposition}(EARLY MEDIA) =~ /^(DELAYED NEGOTIATION)/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->snom-demo-2] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [snom-demo-2] destination_number(5000) =~ /^9001$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->snom-demo-1] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [snom-demo-1] destination_number(5000) =~ /^9000$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->eavesdrop] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [eavesdrop] destination_number(5000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->eavesdrop] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [eavesdrop] destination_number(5000) =~ /^779$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->call_return] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [call_return] destination_number(5000) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->del-group] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [del-group] destination_number(5000) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->add-group] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [add-group] destination_number(5000) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->call-group-simo] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [call-group-simo] destination_number(5000) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->call-group-order] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [call-group-order] destination_number(5000) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->extension-intercom] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [extension-intercom] destination_number(5000) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->Local_Extension] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [Local_Extension] destination_number(5000) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->Local_Extension_Skinny] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [Local_Extension_Skinny] destination_number(5000) =~ /^(11[01][0-9])$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->group_dial_sales] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [group_dial_sales] destination_number(5000) =~ /^2000$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->group_dial_support] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [group_dial_support] destination_number(5000) =~ /^2001$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->group_dial_billing] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [group_dial_billing] destination_number(5000) =~ /^2002$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->operator] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [operator] destination_number(5000) =~ /^(operator|0)$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->vmain] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [vmain] destination_number(5000) =~ /^vmain$|^4000$|^\*98$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->sip_uri] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [sip_uri] destination_number(5000) =~ /^sip:(.*)$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->nb_conferences] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [nb_conferences] destination_number(5000) =~ /^(30\d{2})$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->wb_conferences] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [wb_conferences] destination_number(5000) =~ /^(31\d{2})$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->uwb_conferences] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [uwb_conferences] destination_number(5000) =~ /^(32\d{2})$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->cdquality_conferences] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [cdquality_conferences] destination_number(5000) =~ /^(33\d{2})$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->freeswitch_public_conf_via_sip] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(5000) =~ /^9(888|8888|1616|3232)$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->mad_boss_intercom] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [mad_boss_intercom] destination_number(5000) =~ /^0911$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->mad_boss_intercom] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [mad_boss_intercom] destination_number(5000) =~ /^0912$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->mad_boss] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (FAIL) [mad_boss] destination_number(5000) =~ /^0913$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 parsing [default->ivr_demo] continue=false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Regex (PASS) [ivr_demo] destination_number(5000) =~ /^5000$/ break=on-false
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Action answer()
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Action sleep(2000)
Dialplan: sofia/external/%2B2348124523790@10.200.161.132 Action ivr(demo_ivr)
2016-12-20 15:58:30.355402 [INFO] switch_channel.c:3062 sofia/external/%2B2348124523790@10.200.161.132 Flipping CID from "55101" <55101> to "Outbound Call" <+2348124523790>
2016-12-20 15:58:30.355402 [DEBUG] switch_core_state_machine.c:216 (sofia/external/%2B2348124523790@10.200.161.132) State Change CS_ROUTING -> CS_EXECUTE
2016-12-20 15:58:30.355402 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:30.355402 [DEBUG] switch_core_state_machine.c:528 (sofia/external/%2B2348124523790@10.200.161.132) State ROUTING going to sleep
2016-12-20 15:58:30.355402 [DEBUG] switch_core_state_machine.c:472 (sofia/external/%2B2348124523790@10.200.161.132) Running State Change CS_EXECUTE
2016-12-20 15:58:30.355402 [DEBUG] switch_core_state_machine.c:535 (sofia/external/%2B2348124523790@10.200.161.132) State EXECUTE
2016-12-20 15:58:30.355402 [DEBUG] mod_sofia.c:178 sofia/external/%2B2348124523790@10.200.161.132 SOFIA EXECUTE
2016-12-20 15:58:30.355402 [DEBUG] switch_core_state_machine.c:258 sofia/external/%2B2348124523790@10.200.161.132 Standard EXECUTE
EXECUTE sofia/external/%2B2348124523790@10.200.161.132 set(open=true)
2016-12-20 15:58:30.355402 [DEBUG] mod_dptools.c:1445 sofia/external/%2B2348124523790@10.200.161.132 SET [open]=[true]
EXECUTE sofia/external/%2B2348124523790@10.200.161.132 answer()
EXECUTE sofia/external/%2B2348124523790@10.200.161.132 sleep(2000)
recv 373 bytes from udp/[10.200.161.132]:5060 at 15:58:31.448784:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
From: "55101" <sip:55101@10.227.47.13>;tag=U35jUNH2QU38H
To: <sip:+2348124523790@10.200.161.132>;tag=4203370473
Via: SIP/2.0/UDP 10.227.47.13:5080;rport;branch=z9hG4bKXj2Nv4D43SS2e;received=10.227.47.13
Call-ID: 9ae5109e-4167-1235-c28a-000c293e4716
CSeq: 100786889 INVITE
Contact: <sip:10.200.161.132:5060;transport=UDP>
Content-Length: 0
------------------------------------------------------------------------
2016-12-20 15:58:31.435334 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:31.435334 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:31.455399 [DEBUG] sofia.c:6623 Channel sofia/external/%2B2348124523790@10.200.161.132 entering state [proceeding][180]
2016-12-20 15:58:31.455399 [NOTICE] sofia.c:6725 Ring-Ready sofia/external/%2B2348124523790@10.200.161.132!
2016-12-20 15:58:31.455399 [DEBUG] switch_channel.c:3277 (sofia/external/%2B2348124523790@10.200.161.132) Callstate Change EARLY -> RINGING
2016-12-20 15:58:31.455399 [DEBUG] switch_rtp.c:5870 Correct ip/port confirmed.
EXECUTE sofia/external/%2B2348124523790@10.200.161.132 ivr(demo_ivr)
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-exit'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-sub'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-exec-app'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-play-sound'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-back'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-top'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:858 building menu 'demo_ivr'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-exec-app' to '1'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-exec-app' to '2'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-exec-app' to '3'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-exec-app' to '4'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-exec-app' to '5'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:858 building menu 'demo_ivr_submenu'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-top' to '*'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-sub' to '6'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-exec-app' to '/^(10[01][0-9])$/'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-top' to '9'
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_menu.c:469 Executing IVR menu demo_ivr
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-welcome_to_freeswitch.wav] (en:en)
2016-12-20 15:58:32.395356 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:34.995350 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-welcome_to_freeswitch.wav
2016-12-20 15:58:35.115350 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-this_ivr_will_let_you_test_features.wav] (en:en)
2016-12-20 15:58:35.135386 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:39.095349 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-this_ivr_will_let_you_test_features.wav
2016-12-20 15:58:39.235397 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-you_may_exit_by_hanging_up.wav] (en:en)
2016-12-20 15:58:39.255383 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:41.835349 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-you_may_exit_by_hanging_up.wav
2016-12-20 15:58:41.955347 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-enter_ext_pound.wav] (en:en)
2016-12-20 15:58:41.975350 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
recv 778 bytes from udp/[10.200.161.132]:5060 at 15:58:42.764695:
------------------------------------------------------------------------
SIP/2.0 200 OK
From: "55101" <sip:55101@10.227.47.13>;tag=U35jUNH2QU38H
To: <sip:+2348124523790@10.200.161.132>;tag=4203370473
Via: SIP/2.0/UDP 10.227.47.13:5080;rport;branch=z9hG4bKXj2Nv4D43SS2e;received=10.227.47.13
Call-ID: 9ae5109e-4167-1235-c28a-000c293e4716
CSeq: 100786889 INVITE
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,PRACK,UPDATE
P-Asserted-Identity: <sip:8124523790@LGTSS01SIP;user=phone>
Accept: application/sdp
Content-Type: application/sdp
Contact: <sip:10.200.161.132:5060;transport=UDP>
Content-Length: 242
v=0
o=- 1398662 1398662 IN IP4 TSS.LGTSS.LGTSS01.NG
s=-
c=IN IP4 10.200.12.27
t=0 0
a=sendrecv
m=audio 13100 RTP/AVP 8 101
c=IN IP4 10.200.12.27
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=maxptime:40
------------------------------------------------------------------------
2016-12-20 15:58:42.755348 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:42.755348 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:42.775350 [INFO] sofia.c:1192 sofia/external/%2B2348124523790@10.200.161.132 Update Caller ID to "Outbound Call" <8124523790>
2016-12-20 15:58:42.775350 [DEBUG] sofia.c:6623 Channel sofia/external/%2B2348124523790@10.200.161.132 entering state [completing][200]
2016-12-20 15:58:42.775350 [DEBUG] sofia.c:6630 Duplicate SDP
v=0
o=- 1398662 1398662 IN IP4 TSS.LGTSS.LGTSS01.NG
s=-
c=IN IP4 10.200.12.27
t=0 0
a=sendrecv
m=audio 13100 RTP/AVP 8 101
c=IN IP4 10.200.12.27
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=maxptime:40
send 386 bytes to udp/[10.200.161.132]:5060 at 15:58:42.776529:
------------------------------------------------------------------------
ACK sip:10.200.161.132:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 10.227.47.13:5080;rport;branch=z9hG4bKyUUeyZy702FNa
Max-Forwards: 70
From: "55101" <sip:55101@10.227.47.13>;tag=U35jUNH2QU38H
To: <sip:+2348124523790@10.200.161.132>;tag=4203370473
Call-ID: 9ae5109e-4167-1235-c28a-000c293e4716
CSeq: 100786889 ACK
Contact: <sip:mod_sofia@10.227.47.13:5080>
Content-Length: 0
------------------------------------------------------------------------
2016-12-20 15:58:42.775350 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:42.775350 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 15:58:42.775350 [DEBUG] sofia.c:6623 Channel sofia/external/%2B2348124523790@10.200.161.132 entering state [ready][200]
2016-12-20 15:58:42.795392 [NOTICE] sofia.c:7425 Channel [sofia/external/%2B2348124523790@10.200.161.132] has been answered
2016-12-20 15:58:42.795392 [DEBUG] switch_channel.c:3689 (sofia/external/%2B2348124523790@10.200.161.132) Callstate Change RINGING -> ACTIVE
2016-12-20 15:58:44.635349 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-enter_ext_pound.wav
2016-12-20 15:58:44.775337 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[silence_stream://1500] (en:en)
2016-12-20 15:58:44.795387 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:46.275345 [DEBUG] switch_ivr_play_say.c:1747 done playing file silence_stream://1500
2016-12-20 15:58:46.415348 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_call_the_freeswitch_conference.wav] (en:en)
2016-12-20 15:58:46.435383 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:48.055349 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_call_the_freeswitch_conference.wav
2016-12-20 15:58:48.195351 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:58:48.195351 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:48.615351 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:58:48.735343 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:58:48.755393 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:49.135351 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:58:49.295348 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/1.wav] (en:en)
2016-12-20 15:58:49.295348 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:49.735349 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/1.wav
2016-12-20 15:58:49.855349 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_do_a_freeswitch_echo_test.wav] (en:en)
2016-12-20 15:58:49.855349 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:51.655349 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_do_a_freeswitch_echo_test.wav
2016-12-20 15:58:51.795350 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:58:51.795350 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:52.215330 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:58:52.315339 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:58:52.315339 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:52.715325 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:58:52.815329 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/2.wav] (en:en)
2016-12-20 15:58:52.815329 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:53.195335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/2.wav
2016-12-20 15:58:53.335404 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_listen_to_moh.wav] (en:en)
2016-12-20 15:58:53.355334 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:54.915401 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_listen_to_moh.wav
2016-12-20 15:58:55.075334 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:58:55.075334 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:55.495334 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:58:55.595336 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:58:55.615336 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:55.995401 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:58:56.115403 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/3.wav] (en:en)
2016-12-20 15:58:56.135421 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:58:56.195324 [DEBUG] switch_rtp.c:6092 RTP RECV DTMF 6:560
2016-12-20 15:58:56.215334 [DEBUG] switch_channel.c:488 RECV DTMF 6:560
2016-12-20 15:58:56.215334 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/3.wav
2016-12-20 15:58:56.315335 [DEBUG] switch_ivr_menu.c:363 waiting for 3/4 digits t/o 2000
2016-12-20 15:58:58.355336 [DEBUG] switch_ivr_menu.c:410 digits '6'
2016-12-20 15:58:58.355336 [DEBUG] switch_ivr_menu.c:561 IVR action on menu 'demo_ivr' matched '6' param 'demo_ivr_submenu'
2016-12-20 15:58:58.355336 [DEBUG] switch_ivr_menu.c:565 switch_ivr_menu_execute todo=[1]
2016-12-20 15:58:58.355336 [DEBUG] switch_ivr_menu.c:469 Executing IVR menu demo_ivr_submenu
2016-12-20 15:58:58.355336 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2016-12-20 15:58:58.355336 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-welcome_to_freeswitch.wav] (en:en)
2016-12-20 15:58:58.355336 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:00.955390 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-welcome_to_freeswitch.wav
2016-12-20 15:59:01.095400 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-sample_submenu.wav] (en:en)
2016-12-20 15:59:01.115397 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:07.355401 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-sample_submenu.wav
2016-12-20 15:59:07.515335 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_return_to_previous_menu.wav] (en:en)
2016-12-20 15:59:07.515335 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:09.075408 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_return_to_previous_menu.wav
2016-12-20 15:59:09.215402 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:59:09.235408 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:09.635396 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:59:09.775397 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:59:09.795406 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:10.175411 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:59:10.315396 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/star.wav] (en:en)
2016-12-20 15:59:10.335411 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:10.815396 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/star.wav
2016-12-20 15:59:10.955397 [DEBUG] switch_ivr_menu.c:363 waiting for 1/1 digits t/o 7500
2016-12-20 15:59:14.315400 [DEBUG] switch_rtp.c:6092 RTP RECV DTMF *:560
2016-12-20 15:59:14.335401 [DEBUG] switch_channel.c:488 RECV DTMF *:560
2016-12-20 15:59:14.335401 [DEBUG] switch_ivr_menu.c:410 digits '*'
2016-12-20 15:59:14.335401 [DEBUG] switch_ivr_menu.c:561 IVR action on menu 'demo_ivr_submenu' matched '*' param ''
2016-12-20 15:59:14.335401 [DEBUG] switch_ivr_menu.c:565 switch_ivr_menu_execute todo=[5]
2016-12-20 15:59:14.335401 [DEBUG] switch_ivr_menu.c:543 action regex [6] [/^(10[01][0-9])$/] [0]
2016-12-20 15:59:14.335401 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2016-12-20 15:59:14.335401 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-welcome_to_freeswitch.wav] (en:en)
2016-12-20 15:59:14.335401 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:16.935402 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-welcome_to_freeswitch.wav
2016-12-20 15:59:17.075402 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-this_ivr_will_let_you_test_features.wav] (en:en)
2016-12-20 15:59:17.095438 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:21.055399 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-this_ivr_will_let_you_test_features.wav
2016-12-20 15:59:21.175403 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-you_may_exit_by_hanging_up.wav] (en:en)
2016-12-20 15:59:21.195441 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:23.775401 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-you_may_exit_by_hanging_up.wav
2016-12-20 15:59:23.895402 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-enter_ext_pound.wav] (en:en)
2016-12-20 15:59:23.915443 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:26.595333 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-enter_ext_pound.wav
2016-12-20 15:59:26.695401 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[silence_stream://1500] (en:en)
2016-12-20 15:59:26.715439 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:28.195399 [DEBUG] switch_ivr_play_say.c:1747 done playing file silence_stream://1500
2016-12-20 15:59:28.335336 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_call_the_freeswitch_conference.wav] (en:en)
2016-12-20 15:59:28.335336 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:29.955408 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_call_the_freeswitch_conference.wav
2016-12-20 15:59:30.095401 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:59:30.115440 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:30.515400 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:59:30.655405 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:59:30.675440 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:31.055416 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:59:31.195335 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/1.wav] (en:en)
2016-12-20 15:59:31.195335 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:31.635402 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/1.wav
2016-12-20 15:59:31.755424 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_do_a_freeswitch_echo_test.wav] (en:en)
2016-12-20 15:59:31.775441 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:33.575401 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_do_a_freeswitch_echo_test.wav
2016-12-20 15:59:33.695401 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:59:33.715439 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:34.115399 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:59:34.235400 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:59:34.255439 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:34.635398 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:59:34.755400 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/2.wav] (en:en)
2016-12-20 15:59:34.775438 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:35.155400 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/2.wav
2016-12-20 15:59:35.295399 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_listen_to_moh.wav] (en:en)
2016-12-20 15:59:35.315444 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:36.875400 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_listen_to_moh.wav
2016-12-20 15:59:37.015405 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:59:37.035444 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:37.435400 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:59:37.555405 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:59:37.575435 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:37.955406 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:59:38.095399 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/3.wav] (en:en)
2016-12-20 15:59:38.115456 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:38.495403 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/3.wav
2016-12-20 15:59:38.615401 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-register_for_cluecon.wav] (en:en)
2016-12-20 15:59:38.635440 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:41.055332 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-register_for_cluecon.wav
2016-12-20 15:59:41.155401 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/4.wav] (en:en)
2016-12-20 15:59:41.175389 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:41.595337 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/4.wav
2016-12-20 15:59:41.735336 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_hear_screaming_monkeys.wav] (en:en)
2016-12-20 15:59:41.735336 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:43.215390 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_hear_screaming_monkeys.wav
2016-12-20 15:59:43.335414 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:59:43.355392 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:43.755364 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:59:43.895333 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:59:43.915393 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:44.295367 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:59:44.435389 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/5.wav] (en:en)
2016-12-20 15:59:44.455336 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:44.975334 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/5.wav
2016-12-20 15:59:45.095398 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_hear_sample_submenu.wav] (en:en)
2016-12-20 15:59:45.115334 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:47.495334 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_hear_sample_submenu.wav
2016-12-20 15:59:47.595336 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:59:47.615435 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:48.035332 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:59:48.135332 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:59:48.155332 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:48.555336 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:59:48.655337 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/6.wav] (en:en)
2016-12-20 15:59:48.655337 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:49.175405 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/6.wav
2016-12-20 15:59:49.335337 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_repeat_these_options.wav] (en:en)
2016-12-20 15:59:49.335337 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:50.535367 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_repeat_these_options.wav
2016-12-20 15:59:50.655410 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:59:50.675402 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:51.075388 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:59:51.195393 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:59:51.215390 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:51.595391 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:59:51.715409 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/9.wav] (en:en)
2016-12-20 15:59:51.735395 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:52.155389 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/9.wav
2016-12-20 15:59:52.295392 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[silence_stream://2000] (en:en)
2016-12-20 15:59:52.315389 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:53.875404 [DEBUG] switch_rtp.c:6092 RTP RECV DTMF 9:560
2016-12-20 15:59:53.875404 [DEBUG] switch_channel.c:488 RECV DTMF 9:560
2016-12-20 15:59:53.895392 [DEBUG] switch_ivr_play_say.c:1747 done playing file silence_stream://2000
2016-12-20 15:59:54.035388 [DEBUG] switch_ivr_menu.c:363 waiting for 3/4 digits t/o 2000
2016-12-20 15:59:56.035412 [DEBUG] switch_ivr_menu.c:410 digits '9'
2016-12-20 15:59:56.055334 [DEBUG] switch_ivr_menu.c:543 action regex [9] [/^(10[01][0-9])$/] [0]
2016-12-20 15:59:56.055334 [DEBUG] switch_ivr_menu.c:561 IVR action on menu 'demo_ivr' matched '9' param ''
2016-12-20 15:59:56.055334 [DEBUG] switch_ivr_menu.c:565 switch_ivr_menu_execute todo=[5]
2016-12-20 15:59:56.055334 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2016-12-20 15:59:56.055334 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[silence_stream://1000] (en:en)
2016-12-20 15:59:56.055334 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:57.035402 [DEBUG] switch_ivr_play_say.c:1747 done playing file silence_stream://1000
2016-12-20 15:59:57.155403 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_call_the_freeswitch_conference.wav] (en:en)
2016-12-20 15:59:57.175353 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:58.815335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_call_the_freeswitch_conference.wav
2016-12-20 15:59:58.935335 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 15:59:58.935335 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:59.335336 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 15:59:59.455335 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 15:59:59.455335 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 15:59:59.835335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 15:59:59.975333 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/1.wav] (en:en)
2016-12-20 15:59:59.995336 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:00.455388 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/1.wav
2016-12-20 16:00:00.575332 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_do_a_freeswitch_echo_test.wav] (en:en)
2016-12-20 16:00:00.595393 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:02.415332 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_do_a_freeswitch_echo_test.wav
2016-12-20 16:00:02.535346 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 16:00:02.535346 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:02.955334 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 16:00:03.075336 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 16:00:03.075336 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:03.475335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 16:00:03.575336 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/2.wav] (en:en)
2016-12-20 16:00:03.575336 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:03.955345 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/2.wav
2016-12-20 16:00:04.075333 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_listen_to_moh.wav] (en:en)
2016-12-20 16:00:04.075333 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:05.655335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_listen_to_moh.wav
2016-12-20 16:00:05.755390 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 16:00:05.775388 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:06.175335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 16:00:06.315405 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 16:00:06.315405 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:06.715336 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 16:00:06.815390 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/3.wav] (en:en)
2016-12-20 16:00:06.835400 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:07.235345 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/3.wav
2016-12-20 16:00:07.355341 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_hear_sample_submenu.wav] (en:en)
2016-12-20 16:00:07.355341 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:09.715390 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_hear_sample_submenu.wav
2016-12-20 16:00:09.855400 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 16:00:09.875390 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:10.275335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 16:00:10.415399 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 16:00:10.435403 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:10.835336 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 16:00:10.935401 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/4.wav] (en:en)
2016-12-20 16:00:10.955335 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:11.395335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/4.wav
2016-12-20 16:00:11.515335 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_hear_screaming_monkeys.wav] (en:en)
2016-12-20 16:00:11.515335 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:12.995336 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_hear_screaming_monkeys.wav
2016-12-20 16:00:13.135402 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 16:00:13.155400 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:13.555336 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 16:00:13.695336 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 16:00:13.695336 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:14.075335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 16:00:14.215399 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/5.wav] (en:en)
2016-12-20 16:00:14.235401 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:14.755335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/5.wav
2016-12-20 16:00:14.855399 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_repeat_these_options.wav] (en:en)
2016-12-20 16:00:14.875402 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:16.095335 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_repeat_these_options.wav
2016-12-20 16:00:16.195401 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 16:00:16.215335 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:16.635336 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 16:00:16.735401 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 16:00:16.755335 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:17.135408 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 16:00:17.255400 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/9.wav] (en:en)
2016-12-20 16:00:17.275403 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:17.695402 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/9.wav
2016-12-20 16:00:17.835336 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[silence_stream://2000] (en:en)
2016-12-20 16:00:17.835336 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:19.815401 [DEBUG] switch_ivr_play_say.c:1747 done playing file silence_stream://2000
2016-12-20 16:00:19.955398 [DEBUG] switch_ivr_menu.c:363 waiting for 4/4 digits t/o 2000
2016-12-20 16:00:21.675402 [DEBUG] switch_rtp.c:6092 RTP RECV DTMF 6:560
2016-12-20 16:00:21.675402 [DEBUG] switch_channel.c:488 RECV DTMF 6:560
2016-12-20 16:00:23.695407 [DEBUG] switch_ivr_menu.c:410 digits '6'
2016-12-20 16:00:23.715410 [DEBUG] switch_ivr_menu.c:561 IVR action on menu 'demo_ivr' matched '6' param 'demo_ivr_submenu'
2016-12-20 16:00:23.715410 [DEBUG] switch_ivr_menu.c:565 switch_ivr_menu_execute todo=[1]
2016-12-20 16:00:23.715410 [DEBUG] switch_ivr_menu.c:469 Executing IVR menu demo_ivr_submenu
2016-12-20 16:00:23.715410 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2016-12-20 16:00:23.715410 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-welcome_to_freeswitch.wav] (en:en)
2016-12-20 16:00:23.715410 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:26.315347 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-welcome_to_freeswitch.wav
2016-12-20 16:00:26.435402 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-sample_submenu.wav] (en:en)
2016-12-20 16:00:26.455347 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:32.695405 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-sample_submenu.wav
2016-12-20 16:00:32.815412 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-to_return_to_previous_menu.wav] (en:en)
2016-12-20 16:00:32.835402 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:34.395346 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-to_return_to_previous_menu.wav
2016-12-20 16:00:34.515400 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-please.wav] (en:en)
2016-12-20 16:00:34.535400 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:34.935347 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-please.wav
2016-12-20 16:00:35.055347 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2016-12-20 16:00:35.075401 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:35.455402 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2016-12-20 16:00:35.575413 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[digits/star.wav] (en:en)
2016-12-20 16:00:35.595409 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms
2016-12-20 16:00:36.075399 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/digits/star.wav
2016-12-20 16:00:36.215399 [DEBUG] switch_ivr_menu.c:363 waiting for 1/1 digits t/o 7500
recv 359 bytes from udp/[10.200.161.132]:5060 at 16:00:39.361417:
------------------------------------------------------------------------
BYE sip:mod_sofia@10.227.47.13:5080 SIP/2.0
From: <sip:+2348124523790@10.200.161.132>;tag=4203370473
To: "55101" <sip:55101@10.227.47.13>;tag=U35jUNH2QU38H
Max-Forwards: 70
Via: SIP/2.0/UDP 10.200.161.132:5060;branch=z9hG4bK00000002864043090940
Call-ID: 9ae5109e-4167-1235-c28a-000c293e4716
CSeq: 1 BYE
Reason: Q.850;cause=16
Content-Length: 0
------------------------------------------------------------------------
2016-12-20 16:00:39.355399 [DEBUG] switch_core_session.c:1061 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 16:00:39.375390 [NOTICE] sofia.c:952 Hangup sofia/external/%2B2348124523790@10.200.161.132 [CS_EXECUTE] [NORMAL_CLEARING]
2016-12-20 16:00:39.375390 [DEBUG] switch_channel.c:3222 Send signal sofia/external/%2B2348124523790@10.200.161.132 [KILL]
2016-12-20 16:00:39.375390 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 16:00:39.375390 [DEBUG] switch_ivr_menu.c:410 digits ''
2016-12-20 16:00:39.375390 [DEBUG] switch_ivr_menu.c:643 IVR menu 'demo_ivr_submenu' no input detected
2016-12-20 16:00:39.375390 [DEBUG] switch_ivr_menu.c:543 action regex [6] [/^(10[01][0-9])$/] [0]
2016-12-20 16:00:39.375390 [DEBUG] switch_ivr_menu.c:655 exit-sound 'voicemail/vm-goodbye.wav'
send 456 bytes to udp/[10.200.161.132]:5060 at 16:00:39.376719:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.200.161.132:5060;branch=z9hG4bK00000002864043090940
From: <sip:+2348124523790@10.200.161.132>;tag=4203370473
To: "55101" <sip:55101@10.227.47.13>;tag=U35jUNH2QU38H
Call-ID: 9ae5109e-4167-1235-c28a-000c293e4716
CSeq: 1 BYE
User-Agent: FreeSWITCH-mod_sofia/1.4.18~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Content-Length: 0
------------------------------------------------------------------------
2016-12-20 16:00:39.375390 [DEBUG] switch_core_session.c:2901 sofia/external/%2B2348124523790@10.200.161.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:535 (sofia/external/%2B2348124523790@10.200.161.132) State EXECUTE going to sleep
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:472 (sofia/external/%2B2348124523790@10.200.161.132) Running State Change CS_HANGUP
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:735 (sofia/external/%2B2348124523790@10.200.161.132) Callstate Change ACTIVE -> HANGUP
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:737 (sofia/external/%2B2348124523790@10.200.161.132) State HANGUP
2016-12-20 16:00:39.375390 [DEBUG] mod_sofia.c:413 Channel sofia/external/%2B2348124523790@10.200.161.132 hanging up, cause: NORMAL_CLEARING
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:60 sofia/external/%2B2348124523790@10.200.161.132 Standard HANGUP, cause: NORMAL_CLEARING
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:737 (sofia/external/%2B2348124523790@10.200.161.132) State HANGUP going to sleep
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:504 (sofia/external/%2B2348124523790@10.200.161.132) State Change CS_HANGUP -> CS_REPORTING
2016-12-20 16:00:39.375390 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:472 (sofia/external/%2B2348124523790@10.200.161.132) Running State Change CS_REPORTING
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:823 (sofia/external/%2B2348124523790@10.200.161.132) State REPORTING
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:104 sofia/external/%2B2348124523790@10.200.161.132 Standard REPORTING, cause: NORMAL_CLEARING
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:823 (sofia/external/%2B2348124523790@10.200.161.132) State REPORTING going to sleep
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:498 (sofia/external/%2B2348124523790@10.200.161.132) State Change CS_REPORTING -> CS_DESTROY
2016-12-20 16:00:39.375390 [DEBUG] switch_core_session.c:1396 Send signal sofia/external/%2B2348124523790@10.200.161.132 [BREAK]
2016-12-20 16:00:39.375390 [DEBUG] switch_core_session.c:1623 Session 6 (sofia/external/%2B2348124523790@10.200.161.132) Locked, Waiting on external entities
2016-12-20 16:00:39.375390 [NOTICE] switch_core_session.c:1641 Session 6 (sofia/external/%2B2348124523790@10.200.161.132) Ended
2016-12-20 16:00:39.375390 [NOTICE] switch_core_session.c:1645 Close Channel sofia/external/%2B2348124523790@10.200.161.132 [CS_DESTROY]
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:626 (sofia/external/%2B2348124523790@10.200.161.132) Running State Change CS_DESTROY
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:636 (sofia/external/%2B2348124523790@10.200.161.132) State DESTROY
2016-12-20 16:00:39.375390 [DEBUG] mod_sofia.c:323 sofia/external/%2B2348124523790@10.200.161.132 SOFIA DESTROY
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:111 sofia/external/%2B2348124523790@10.200.161.132 Standard DESTROY
2016-12-20 16:00:39.375390 [DEBUG] switch_core_state_machine.c:636 (sofia/external/%2B2348124523790@10.200.161.132) State DESTROY going to sleep