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" ;tag=U35jUNH2QU38H To: Call-ID: 9ae5109e-4167-1235-c28a-000c293e4716 freeswitch@internal> CSeq: 100786889 INVITE Contact: 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" ;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" ;tag=U35jUNH2QU38H To: 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" ;tag=U35jUNH2QU38H To: ;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: 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" ;tag=U35jUNH2QU38H To: ;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: 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" ;tag=U35jUNH2QU38H To: ;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: Accept: application/sdp Content-Type: application/sdp Contact: 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" ;tag=U35jUNH2QU38H To: ;tag=4203370473 Call-ID: 9ae5109e-4167-1235-c28a-000c293e4716 CSeq: 100786889 ACK Contact: 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: ;tag=4203370473 To: "55101" ;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: ;tag=4203370473 To: "55101" ;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