[Freeswitch-users] IVR bridge no sound

29 Jun 2015

      Hello all,

Strange error. I have an external number. 
When I make a bridge to an extension that everything works without problems. There are sound. Everything is fine.

<extension name="from-pe3ny">
   <condition field="destination_number" expression="^(222265206)$">
    <condition wday="1-5" hour="9-18">
        <action application="bridge" data="user/1010@sip1.applicloud.com"/>
        <action application="hangup"/>
    </condition>
    <condition hour="18-9">
    </condition>
   </condition>
</extension> 

But when I do the same thing through the IVR, all works connected. But there is absolutely no sound.

<entry action="menu-exec-app" digits="1" param="bridge user/1010@sip1.applicloud.com"/> 

For IVR need some special settings? 

Sending log

5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [NOTICE] switch_channel.c:1089 New Channel sofia/external/775415382@213.168.162.219 [5e02ac87-283a-45ed-8f13-72b60c812aef]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_core_state_machine.c:473 (sofia/external/775415382@213.168.162.219) Running State Change CS_NEW
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] sofia.c:8933 sofia/external/775415382@213.168.162.219 receiving invite from 213.168.162.219:5060 version: 1.7.0 git 21afd1b 2015-06-20 02:48:23Z 64bit
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] sofia.c:9775 sofia/external/775415382@213.168.162.219 setting variable [verbose_sdp]=[true]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] sofia.c:9775 sofia/external/775415382@213.168.162.219 setting variable [absolute_codec_string]=[G722,G729,PCMA,PCMU]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] sofia.c:6701 Channel sofia/external/775415382@213.168.162.219 entering state [received][100]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] sofia.c:6711 Remote SDP:
5e02ac87-283a-45ed-8f13-72b60c812aef v=0
5e02ac87-283a-45ed-8f13-72b60c812aef o=root 307824703 307824703 IN IP4 213.168.162.219
5e02ac87-283a-45ed-8f13-72b60c812aef s=VoIPEX Switch
5e02ac87-283a-45ed-8f13-72b60c812aef c=IN IP4 213.168.162.219
5e02ac87-283a-45ed-8f13-72b60c812aef b=CT:384
5e02ac87-283a-45ed-8f13-72b60c812aef t=0 0
5e02ac87-283a-45ed-8f13-72b60c812aef m=audio 14212 RTP/AVP 8 18 97 9 101
5e02ac87-283a-45ed-8f13-72b60c812aef a=rtpmap:8 PCMA/8000
5e02ac87-283a-45ed-8f13-72b60c812aef a=rtpmap:18 G729/8000
5e02ac87-283a-45ed-8f13-72b60c812aef a=fmtp:18 annexb=no
5e02ac87-283a-45ed-8f13-72b60c812aef a=rtpmap:97 iLBC/8000
5e02ac87-283a-45ed-8f13-72b60c812aef a=fmtp:97 mode=30
5e02ac87-283a-45ed-8f13-72b60c812aef a=rtpmap:9 G722/8000
5e02ac87-283a-45ed-8f13-72b60c812aef a=rtpmap:101 telephone-event/8000
5e02ac87-283a-45ed-8f13-72b60c812aef a=fmtp:101 0-16
5e02ac87-283a-45ed-8f13-72b60c812aef a=ptime:20
5e02ac87-283a-45ed-8f13-72b60c812aef m=video 10336 RTP/AVP 34 99
5e02ac87-283a-45ed-8f13-72b60c812aef a=rtpmap:34 H263/90000
5e02ac87-283a-45ed-8f13-72b60c812aef a=fmtp:34 F=0;I=0;J=0;T=0;K=0;N=0;BPP=0;HRD=0
5e02ac87-283a-45ed-8f13-72b60c812aef a=rtpmap:99 H264/90000
5e02ac87-283a-45ed-8f13-72b60c812aef a=fmtp:99 redundant-pic-cap=0;parameter-add=0;packetization-mode=0;level-asymmetry-allowed=0
5e02ac87-283a-45ed-8f13-72b60c812aef 
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] sofia.c:6963 (sofia/external/775415382@213.168.162.219) State Change CS_NEW -> CS_INIT
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_core_state_machine.c:492 (sofia/external/775415382@213.168.162.219) State NEW
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_core_state_machine.c:473 (sofia/external/775415382@213.168.162.219) Running State Change CS_INIT
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_core_state_machine.c:516 (sofia/external/775415382@213.168.162.219) State INIT
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] mod_sofia.c:88 sofia/external/775415382@213.168.162.219 SOFIA INIT
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_core_state_machine.c:40 sofia/external/775415382@213.168.162.219 Standard INIT
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_core_state_machine.c:48 (sofia/external/775415382@213.168.162.219) State Change CS_INIT -> CS_ROUTING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_core_state_machine.c:516 (sofia/external/775415382@213.168.162.219) State INIT going to sleep
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_core_state_machine.c:473 (sofia/external/775415382@213.168.162.219) Running State Change CS_ROUTING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_channel.c:2239 (sofia/external/775415382@213.168.162.219) Callstate Change DOWN -> RINGING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_core_state_machine.c:532 (sofia/external/775415382@213.168.162.219) State ROUTING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] mod_sofia.c:141 sofia/external/775415382@213.168.162.219 SOFIA ROUTING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [DEBUG] switch_core_state_machine.c:166 sofia/external/775415382@213.168.162.219 Standard ROUTING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.707608 [INFO] mod_dialplan_xml.c:642 Processing 775415382 <775415382>->222265206 in context office
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 parsing [office->unloop] continue=false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 parsing [office->tod_example] continue=true
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Date/Time Match (PASS) [tod_example] break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action set(open=true)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 parsing [office->holiday_example] continue=true
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Date/TimeMatch (FAIL) [holiday_example] break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 parsing [office->from-pe3ny] continue=false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Regex (PASS) [from-pe3ny] destination_number(222265206) =~ /^(222265206)$/ break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef |--- Dialplan: Processing recursive conditions level:1 [from-pe3ny_recur_1] require-nested=TRUE
5e02ac87-283a-45ed-8f13-72b60c812aef |--- Dialplan: sofia/external/775415382@213.168.162.219 Date/Time Match (PASS) [from-pe3ny_recur_1] break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef |--- Dialplan: sofia/external/775415382@213.168.162.219 Action answer()
5e02ac87-283a-45ed-8f13-72b60c812aef |--- Dialplan: sofia/external/775415382@213.168.162.219 Action ivr(demo_ivr)
5e02ac87-283a-45ed-8f13-72b60c812aef |--- Dialplan: sofia/external/775415382@213.168.162.219 Action hangup()
5e02ac87-283a-45ed-8f13-72b60c812aef |--- Dialplan: sofia/external/775415382@213.168.162.219 Date/TimeMatch (FAIL) [from-pe3ny_recur_1] break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_state_machine.c:216 (sofia/external/775415382@213.168.162.219) State Change CS_ROUTING -> CS_EXECUTE
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_state_machine.c:532 (sofia/external/775415382@213.168.162.219) State ROUTING going to sleep
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_state_machine.c:473 (sofia/external/775415382@213.168.162.219) Running State Change CS_EXECUTE
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_state_machine.c:539 (sofia/external/775415382@213.168.162.219) State EXECUTE
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] mod_sofia.c:196 sofia/external/775415382@213.168.162.219 SOFIA EXECUTE
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_state_machine.c:258 sofia/external/775415382@213.168.162.219 Standard EXECUTE
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 set(open=true)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] mod_dptools.c:1469 sofia/external/775415382@213.168.162.219 SET [open]=[true]
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 answer()
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] mod_sofia.c:766 Disabling proxy mode due to call answer with no bridge
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4117 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4117 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [iLBC:97:8000:20:0:1]/[G722:9:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [iLBC:97:8000:20:0:1]/[G729:18:8000:20:8000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4117 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G722:9:8000:20:64000:1]/[G729:18:8000:20:8000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:3978 Set telephone-event payload to 101
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:2848 Set Codec sofia/external/775415382@213.168.162.219 G722/8000 20 ms 160 samples 64000 bits 1 channels
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_codec.c:111 sofia/external/775415382@213.168.162.219 Original read codec set to G722:9
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:4329 Set 2833 dtmf send/recv payload to 101
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:5885 AUDIO RTP [sofia/external/775415382@213.168.162.219] 62.168.61.75 port 20790 -> 213.168.162.219 port 14212 codec: 9 ms: 20
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_rtp.c:3682 Starting timer [soft] 160 bytes per 20ms
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:6184 Set 2833 dtmf send payload to 101
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:6190 Set 2833 dtmf receive payload to 101
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_core_media.c:6212 sofia/external/775415382@213.168.162.219 Set rtp dtmf delay to 40
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/775415382@213.168.162.219!
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_channel.c:3460 (sofia/external/775415382@213.168.162.219) Callstate Change RINGING -> EARLY
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] mod_sofia.c:798 Local SDP sofia/external/775415382@213.168.162.219:
5e02ac87-283a-45ed-8f13-72b60c812aef v=0
5e02ac87-283a-45ed-8f13-72b60c812aef o=FreeSWITCH 1435565395 1435565396 IN IP4 62.168.61.75
5e02ac87-283a-45ed-8f13-72b60c812aef s=FreeSWITCH
5e02ac87-283a-45ed-8f13-72b60c812aef c=IN IP4 62.168.61.75
5e02ac87-283a-45ed-8f13-72b60c812aef t=0 0
5e02ac87-283a-45ed-8f13-72b60c812aef m=audio 20790 RTP/AVP 9 101
5e02ac87-283a-45ed-8f13-72b60c812aef a=rtpmap:9 G722/8000
5e02ac87-283a-45ed-8f13-72b60c812aef a=rtpmap:101 telephone-event/8000
5e02ac87-283a-45ed-8f13-72b60c812aef a=fmtp:101 0-16
5e02ac87-283a-45ed-8f13-72b60c812aef a=ptime:20
5e02ac87-283a-45ed-8f13-72b60c812aef a=sendrecv
5e02ac87-283a-45ed-8f13-72b60c812aef 
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [NOTICE] mod_dptools.c:1292 Channel [sofia/external/775415382@213.168.162.219] has been answered
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] switch_channel.c:3759 (sofia/external/775415382@213.168.162.219) Callstate Change EARLY -> ACTIVE
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.867610 [DEBUG] sofia.c:6701 Channel sofia/external/775415382@213.168.162.219 entering state [completed][200]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.887610 [DEBUG] sofia.c:6701 Channel sofia/external/775415382@213.168.162.219 entering state [ready][200]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:25.907610 [DEBUG] switch_rtp.c:6450 Correct audio ip/port confirmed.
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 ivr(demo_ivr)
2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-exit'
2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-sub'
2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-exec-app'
2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-play-sound'
2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-back'
2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_menu.c:721 switch_ivr_menu_stack_xml_add binding 'menu-top'
2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_menu.c:858 building menu 'demo_ivr'
2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-exec-app' to '1'
2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_menu.c:942 binding menu action 'menu-top' to '9'
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_menu.c:469 Executing IVR menu demo_ivr
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:29.887610 [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:29.907612 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-welcome_to_freeswitch.wav] (en:en)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:29.907612 [DEBUG] switch_ivr_play_say.c:1352 Codec Activated L16@16000hz 1 channels 20ms
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:32.507609 [DEBUG] switch_ivr_play_say.c:1798 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-welcome_to_freeswitch.wav
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:32.607609 [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[ivr/ivr-this_ivr_will_let_you_test_features.wav] (en:en)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:32.607609 [DEBUG] switch_ivr_play_say.c:1352 Codec Activated L16@16000hz 1 channels 20ms
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:32.627609 [DEBUG] switch_rtp.c:6669 RTP RECV DTMF 1:2560
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:32.627609 [DEBUG] switch_channel.c:502 RECV DTMF 1:2560
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:32.627609 [DEBUG] switch_ivr_play_say.c:1798 done playing file /usr/local/freeswitch/sounds/en/us/callie/ivr/ivr-this_ivr_will_let_you_test_features.wav
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:32.747609 [DEBUG] switch_ivr_menu.c:363 waiting for 3/4 digits t/o 2000
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.767609 [DEBUG] switch_ivr_menu.c:410 digits 1
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.767609 [DEBUG] switch_ivr_menu.c:561 IVR action on menu demo_ivr matched 1 param execute_extension CONNECT
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.767609 [DEBUG] switch_ivr_menu.c:565 switch_ivr_menu_execute todo=[2]
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 execute_extension(CONNECT)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.767609 [INFO] mod_dialplan_xml.c:642 Processing 775415382 <775415382>->CONNECT in context office
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 parsing [office->unloop] continue=false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 parsing [office->tod_example] continue=true
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Date/Time Match (PASS) [tod_example] break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action set(open=true)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 parsing [office->holiday_example] continue=true
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Date/TimeMatch (FAIL) [holiday_example] break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 parsing [office->from-pe3ny] continue=false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Regex (FAIL) [from-pe3ny] destination_number(CONNECT) =~ /^(222265206)$/ break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 parsing [office->out-2-city] continue=false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Regex (FAIL) [out-2-city] destination_number(CONNECT) =~ /^(\d{9})$/ break=on-false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 parsing [office->from-pe3ny-connect] continue=false
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Regex (PASS) [from-pe3ny-connect] destination_number(CONNECT) =~ /^CONNECT$/ break=on-true
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action export(nolocal:absolute_codec_string=G722,G729,PCMA,PCMU)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action set(zrtp_secure_media=true)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action set(inherit_codec=true)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action set(ringback=${us-ring})
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action set(transfer_ringback=local_stream://moh)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action set(call_timeout=30)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action set(hangup_after_bridge=true)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action set(continue_on_fail=true)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action bridge({ignore_early_media=true}user/1010@sip1.applicloud.com)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action answer()
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action sleep(1000)
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
5e02ac87-283a-45ed-8f13-72b60c812aef Dialplan: sofia/external/775415382@213.168.162.219 Action hangup()
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [NOTICE] switch_core_session.c:3023 Execute set(open=true)
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 set(open=true)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] mod_dptools.c:1469 sofia/external/775415382@213.168.162.219 SET [open]=[true]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [NOTICE] switch_core_session.c:3023 Execute export(nolocal:absolute_codec_string=G722,G729,PCMA,PCMU)
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 export(nolocal:absolute_codec_string=G722,G729,PCMA,PCMU)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] switch_channel.c:1281 EXPORT (export_vars) (REMOTE ONLY) [absolute_codec_string]=[G722,G729,PCMA,PCMU]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [NOTICE] switch_core_session.c:3023 Execute set(zrtp_secure_media=true)
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 set(zrtp_secure_media=true)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] mod_dptools.c:1469 sofia/external/775415382@213.168.162.219 SET [zrtp_secure_media]=[true]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [NOTICE] switch_core_session.c:3023 Execute set(inherit_codec=true)
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 set(inherit_codec=true)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] mod_dptools.c:1469 sofia/external/775415382@213.168.162.219 SET [inherit_codec]=[true]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [NOTICE] switch_core_session.c:3023 Execute set(ringback=${us-ring})
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 set(ringback=%(2000,4000,440,480))
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] mod_dptools.c:1469 sofia/external/775415382@213.168.162.219 SET [ringback]=[%(2000,4000,440,480)]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [NOTICE] switch_core_session.c:3023 Execute set(transfer_ringback=local_stream://moh)
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 set(transfer_ringback=local_stream://moh)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] mod_dptools.c:1469 sofia/external/775415382@213.168.162.219 SET [transfer_ringback]=[local_stream://moh]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [NOTICE] switch_core_session.c:3023 Execute set(call_timeout=30)
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 set(call_timeout=30)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] mod_dptools.c:1469 sofia/external/775415382@213.168.162.219 SET [call_timeout]=[30]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [NOTICE] switch_core_session.c:3023 Execute set(hangup_after_bridge=true)
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 set(hangup_after_bridge=true)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] mod_dptools.c:1469 sofia/external/775415382@213.168.162.219 SET [hangup_after_bridge]=[true]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [NOTICE] switch_core_session.c:3023 Execute set(continue_on_fail=true)
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 set(continue_on_fail=true)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] mod_dptools.c:1469 sofia/external/775415382@213.168.162.219 SET [continue_on_fail]=[true]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [NOTICE] switch_core_session.c:3023 Execute bridge({ignore_early_media=true}user/1010@sip1.applicloud.com)
5e02ac87-283a-45ed-8f13-72b60c812aef EXECUTE sofia/external/775415382@213.168.162.219 bridge({ignore_early_media=true}user/1010@sip1.applicloud.com)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] switch_channel.c:1808 (sofia/external/775415382@213.168.162.219) Callstate Change ACTIVE -> RING_WAIT
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] switch_channel.c:1235 sofia/external/775415382@213.168.162.219 EXPORTING[export_vars] [absolute_codec_string]=[G722,G729,PCMA,PCMU] to event
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:34.947609 [DEBUG] switch_ivr_originate.c:2104 Parsing global variables
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:35.067610 [DEBUG] switch_channel.c:1235 sofia/external/775415382@213.168.162.219 EXPORTING[export_vars] [absolute_codec_string]=[G722,G729,PCMA,PCMU] to event

5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:35.067610 [DEBUG] switch_ivr_originate.c:2104 Parsing global variables
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [NOTICE] switch_channel.c:1089 New Channel sofia/internal/1010@192.168.0.254:5060 [14401975-55cc-429e-b383-fa3da0122648]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] mod_sofia.c:4734 (sofia/internal/1010@192.168.0.254:5060) State Change CS_NEW -> CS_INIT
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:35.067610 [DEBUG] mod_sofia.c:4804 [zrtp_passthru] Setting a-leg inherit_codec=true
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:35.067610 [DEBUG] mod_sofia.c:4807 [zrtp_passthru] Setting b-leg absolute_codec_string=CORE_PCM_MODULE.PCMA@8000h@20i@64000b,mod_bcg729.G729@8000h@20i@8000b,mod_spandsp.G722@8000h@20i@64000b
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1010@192.168.0.254:5060) Running State Change CS_INIT
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:516 (sofia/internal/1010@192.168.0.254:5060) State INIT
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] mod_sofia.c:88 sofia/internal/1010@192.168.0.254:5060 SOFIA INIT
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] sofia_glue.c:1227 sip:1010@84.242.71.194:5060 Setting proxy route to sofia/internal/1010@192.168.0.254:5060
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] sofia_glue.c:1256 sofia/internal/1010@192.168.0.254:5060 sending invite version: 1.7.0 git 21afd1b 2015-06-20 02:48:23Z 64bit
14401975-55cc-429e-b383-fa3da0122648 Local SDP:
14401975-55cc-429e-b383-fa3da0122648 v=0
14401975-55cc-429e-b383-fa3da0122648 o=FreeSWITCH 1435559015 1435559016 IN IP4 62.168.61.75
14401975-55cc-429e-b383-fa3da0122648 s=FreeSWITCH
14401975-55cc-429e-b383-fa3da0122648 c=IN IP4 62.168.61.75
14401975-55cc-429e-b383-fa3da0122648 t=0 0
14401975-55cc-429e-b383-fa3da0122648 m=audio 27180 RTP/AVP 9 18 8 0 101
14401975-55cc-429e-b383-fa3da0122648 a=rtpmap:9 G722/8000
14401975-55cc-429e-b383-fa3da0122648 a=rtpmap:18 G729/8000
14401975-55cc-429e-b383-fa3da0122648 a=fmtp:18 annexb=no
14401975-55cc-429e-b383-fa3da0122648 a=rtpmap:8 PCMA/8000
14401975-55cc-429e-b383-fa3da0122648 a=rtpmap:0 PCMU/8000
14401975-55cc-429e-b383-fa3da0122648 a=rtpmap:101 telephone-event/8000
14401975-55cc-429e-b383-fa3da0122648 a=fmtp:101 0-16
14401975-55cc-429e-b383-fa3da0122648 a=ptime:20
14401975-55cc-429e-b383-fa3da0122648 a=sendrecv
14401975-55cc-429e-b383-fa3da0122648 
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1010@192.168.0.254:5060 Standard INIT
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1010@192.168.0.254:5060) State Change CS_INIT -> CS_ROUTING
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:516 (sofia/internal/1010@192.168.0.254:5060) State INIT going to sleep
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1010@192.168.0.254:5060) Running State Change CS_ROUTING
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] sofia.c:6701 Channel sofia/internal/1010@192.168.0.254:5060 entering state [calling][0]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/1010@192.168.0.254:5060) State ROUTING
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] mod_sofia.c:141 sofia/internal/1010@192.168.0.254:5060 SOFIA ROUTING
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1010@192.168.0.254:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/1010@192.168.0.254:5060) State ROUTING going to sleep
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1010@192.168.0.254:5060) Running State Change CS_CONSUME_MEDIA
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:551 (sofia/internal/1010@192.168.0.254:5060) State CONSUME_MEDIA
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.067610 [DEBUG] switch_core_state_machine.c:551 (sofia/internal/1010@192.168.0.254:5060) State CONSUME_MEDIA going to sleep
2015-06-29 15:56:35.107610 [INFO] sofia.c:1219 sofia/internal/1010@192.168.0.254:5060 Update Callee ID to "1010" <1010>
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.107610 [DEBUG] sofia.c:6701 Channel sofia/internal/1010@192.168.0.254:5060 entering state [proceeding][180]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.107610 [NOTICE] sofia.c:6803 Ring-Ready sofia/internal/1010@192.168.0.254:5060!
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:35.107610 [DEBUG] switch_channel.c:3332 (sofia/internal/1010@192.168.0.254:5060) Callstate Change DOWN -> RINGING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:35.127611 [DEBUG] switch_ivr_originate.c:1252 Raw Codec Activation Success L16@16000hz 1 channel 20ms
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:35.127611 [DEBUG] switch_core_codec.c:221 sofia/external/775415382@213.168.162.219 Push codec L16:100
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:35.127611 [DEBUG] switch_ivr_originate.c:1284 Play Ringback File [local_stream://moh]
2015-06-29 15:56:35.127611 [DEBUG] mod_local_stream.c:669 Opening Stream [moh/16000] 16000hz
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] sofia.c:6701 Channel sofia/internal/1010@192.168.0.254:5060 entering state [completing][200]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] sofia.c:6711 Remote SDP:
14401975-55cc-429e-b383-fa3da0122648 v=0
14401975-55cc-429e-b383-fa3da0122648 o=- 2509095 2509095 IN IP4 192.168.0.254
14401975-55cc-429e-b383-fa3da0122648 s=-
14401975-55cc-429e-b383-fa3da0122648 c=IN IP4 192.168.0.254
14401975-55cc-429e-b383-fa3da0122648 t=0 0
14401975-55cc-429e-b383-fa3da0122648 m=audio 5001 RTP/AVP 18 100 101
14401975-55cc-429e-b383-fa3da0122648 a=rtpmap:18 G729a/8000
14401975-55cc-429e-b383-fa3da0122648 a=rtpmap:100 NSE/8000
14401975-55cc-429e-b383-fa3da0122648 a=fmtp:100 192-193
14401975-55cc-429e-b383-fa3da0122648 a=rtpmap:101 telephone-event/8000
14401975-55cc-429e-b383-fa3da0122648 a=fmtp:101 0-15
14401975-55cc-429e-b383-fa3da0122648 a=ptime:30
14401975-55cc-429e-b383-fa3da0122648 
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] sofia.c:6701 Channel sofia/internal/1010@192.168.0.254:5060 entering state [ready][200]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G729a:18:8000:30:8000:1]/[G722:9:8000:20:64000:1]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G729a:18:8000:30:8000:1]/[G729:18:8000:20:8000:1]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4098 Audio Codec Compare [G729:18:8000:20:8000:1] is saved as a near-match
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMA:8:8000:20:64000:1]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMU:0:8000:20:64000:1]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [NSE:100:8000:30:0:1]/[G722:9:8000:20:64000:1]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [NSE:100:8000:30:0:1]/[G729:18:8000:20:8000:1]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [NSE:100:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4062 Audio Codec Compare [NSE:100:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:3978 Set telephone-event payload to 101
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4168 Substituting codec G729@30i@8000h@1c
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:2848 Set Codec sofia/internal/1010@192.168.0.254:5060 G729/8000 30 ms 240 samples 8000 bits 1 channels
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_codec.c:111 sofia/internal/1010@192.168.0.254:5060 Original read codec set to G729:18
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:4320 Set 2833 dtmf send payload to 101
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:5885 AUDIO RTP [sofia/internal/1010@192.168.0.254:5060] 62.168.61.75 port 27180 -> 192.168.0.254 port 5001 codec: 18 ms: 30
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_rtp.c:3682 Starting timer [soft] 240 bytes per 30ms
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:1914 Setting Jitterbuffer to 120ms (4 frames) (10 max frames) (0 max drift)
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:6184 Set 2833 dtmf send payload to 101
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:6190 Set 2833 dtmf receive payload to 101
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_core_media.c:6212 sofia/internal/1010@192.168.0.254:5060 Set rtp dtmf delay to 40
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [NOTICE] sofia.c:7562 Channel [sofia/internal/1010@192.168.0.254:5060] has been answered
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.147609 [DEBUG] switch_channel.c:3759 (sofia/internal/1010@192.168.0.254:5060) Callstate Change RINGING -> ACTIVE
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:37.167610 [DEBUG] switch_core_codec.c:246 sofia/external/775415382@213.168.162.219 Restore previous codec G722:9.
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:37.167610 [DEBUG] switch_ivr_originate.c:3584 Originate Resulted in Success: [sofia/internal/1010@192.168.0.254:5060]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:37.167610 [DEBUG] switch_channel.c:2034 (sofia/external/775415382@213.168.162.219) Callstate Change RING_WAIT -> ACTIVE
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:37.167610 [DEBUG] switch_ivr_originate.c:3584 Originate Resulted in Success: [sofia/internal/1010@192.168.0.254:5060]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.167610 [DEBUG] switch_core_media.c:8825 sofia/internal/1010@192.168.0.254:5060 PAUSE Jitterbuffer
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.167610 [DEBUG] switch_ivr_bridge.c:1536 (sofia/internal/1010@192.168.0.254:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.167610 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1010@192.168.0.254:5060) Running State Change CS_EXCHANGE_MEDIA
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.167610 [DEBUG] switch_core_state_machine.c:542 (sofia/internal/1010@192.168.0.254:5060) State EXCHANGE_MEDIA
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.167610 [DEBUG] mod_sofia.c:612 SOFIA EXCHANGE_MEDIA
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.207613 [NOTICE] switch_core_io.c:1191 Activating write resampler
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:37.207613 [DEBUG] switch_core_io.c:1437 Engaging Write Buffer at 480 bytes to accommodate 320->480
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [NOTICE] sofia.c:952 Hangup sofia/internal/1010@192.168.0.254:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_ivr_bridge.c:725 BRIDGE THREAD DONE [sofia/internal/1010@192.168.0.254:5060]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:542 (sofia/internal/1010@192.168.0.254:5060) State EXCHANGE_MEDIA going to sleep
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1010@192.168.0.254:5060) Running State Change CS_HANGUP
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/1010@192.168.0.254:5060) Callstate Change ACTIVE -> HANGUP
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1010@192.168.0.254:5060) State HANGUP
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] mod_sofia.c:431 Channel sofia/internal/1010@192.168.0.254:5060 hanging up, cause: NORMAL_CLEARING
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1010@192.168.0.254:5060 Standard HANGUP, cause: NORMAL_CLEARING
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1010@192.168.0.254:5060) State HANGUP going to sleep
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:508 (sofia/internal/1010@192.168.0.254:5060) State Change CS_HANGUP -> CS_REPORTING
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1010@192.168.0.254:5060) Running State Change CS_REPORTING
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:827 (sofia/internal/1010@192.168.0.254:5060) State REPORTING
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1010@192.168.0.254:5060 Standard REPORTING, cause: NORMAL_CLEARING
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:827 (sofia/internal/1010@192.168.0.254:5060) State REPORTING going to sleep
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:499 (sofia/internal/1010@192.168.0.254:5060) State Change CS_REPORTING -> CS_DESTROY
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_session.c:1639 Session 2 (sofia/internal/1010@192.168.0.254:5060) Locked, Waiting on external entities
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_ivr_bridge.c:646 sofia/internal/1010@192.168.0.254:5060 ending bridge by request from write function
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_ivr_bridge.c:725 BRIDGE THREAD DONE [sofia/external/775415382@213.168.162.219]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [NOTICE] switch_ivr_bridge.c:1679 Hangup sofia/external/775415382@213.168.162.219 [CS_EXECUTE] [NORMAL_CLEARING]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [NOTICE] switch_core_session.c:1657 Session 2 (sofia/internal/1010@192.168.0.254:5060) Ended
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [NOTICE] switch_core_session.c:1661 Close Channel sofia/internal/1010@192.168.0.254:5060 [CS_DESTROY]
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:630 (sofia/internal/1010@192.168.0.254:5060) Running State Change CS_DESTROY
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_session.c:2924 sofia/external/775415382@213.168.162.219 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1010@192.168.0.254:5060) State DESTROY
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] mod_sofia.c:341 sofia/internal/1010@192.168.0.254:5060 SOFIA DESTROY
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1010@192.168.0.254:5060 Standard DESTROY
14401975-55cc-429e-b383-fa3da0122648 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1010@192.168.0.254:5060) State DESTROY going to sleep
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_session.c:2924 sofia/external/775415382@213.168.162.219 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_ivr_menu.c:655 exit-sound voicemail/vm-goodbye.wav
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_session.c:2924 sofia/external/775415382@213.168.162.219 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:539 (sofia/external/775415382@213.168.162.219) State EXECUTE going to sleep
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:473 (sofia/external/775415382@213.168.162.219) Running State Change CS_HANGUP
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:739 (sofia/external/775415382@213.168.162.219) Callstate Change ACTIVE -> HANGUP
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:741 (sofia/external/775415382@213.168.162.219) State HANGUP
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] mod_sofia.c:425 sofia/external/775415382@213.168.162.219 Overriding SIP cause 480 with 200 from the other leg
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] mod_sofia.c:431 Channel sofia/external/775415382@213.168.162.219 hanging up, cause: NORMAL_CLEARING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] mod_sofia.c:483 Sending BYE to sofia/external/775415382@213.168.162.219
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:60 sofia/external/775415382@213.168.162.219 Standard HANGUP, cause: NORMAL_CLEARING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:741 (sofia/external/775415382@213.168.162.219) State HANGUP going to sleep
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:508 (sofia/external/775415382@213.168.162.219) State Change CS_HANGUP -> CS_REPORTING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:473 (sofia/external/775415382@213.168.162.219) Running State Change CS_REPORTING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:827 (sofia/external/775415382@213.168.162.219) State REPORTING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:104 sofia/external/775415382@213.168.162.219 Standard REPORTING, cause: NORMAL_CLEARING
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:827 (sofia/external/775415382@213.168.162.219) State REPORTING going to sleep
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:499 (sofia/external/775415382@213.168.162.219) State Change CS_REPORTING -> CS_DESTROY
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_session.c:1639 Session 1 (sofia/external/775415382@213.168.162.219) Locked, Waiting on external entities
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [NOTICE] switch_core_session.c:1657 Session 1 (sofia/external/775415382@213.168.162.219) Ended
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [NOTICE] switch_core_session.c:1661 Close Channel sofia/external/775415382@213.168.162.219 [CS_DESTROY]
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:630 (sofia/external/775415382@213.168.162.219) Running State Change CS_DESTROY
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:640 (sofia/external/775415382@213.168.162.219) State DESTROY
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] mod_sofia.c:341 sofia/external/775415382@213.168.162.219 SOFIA DESTROY
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:111 sofia/external/775415382@213.168.162.219 Standard DESTROY
5e02ac87-283a-45ed-8f13-72b60c812aef 2015-06-29 15:56:45.047610 [DEBUG] switch_core_state_machine.c:640 (sofia/external/775415382@213.168.162.219) State DESTROY going to sleep

-- 
S pozdravem,
Ing.Denis Jakovlev                           
mob.tel. 775-415-382