315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [NOTICE] switch_channel.c:1104 New Channel sofia/192.168.10.200/262086050@187.239.216.12:5060 [315a736f-b5a2-4190-8f87-2541d13a5ea4] 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_core_state_machine.c:584 (sofia/192.168.10.200/262086050@187.239.216.12:5060) Running State Change CS_NEW 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] sofia.c:9639 sofia/192.168.10.200/262086050@187.239.216.12:5060 receiving invite from 187.239.216.12:5060 version: 1.7.0 git d34b501 2016-09-20 22:18:10Z 64bit nua.c:610 nua_set_hparams() nua: nua_r_set_params with invalid handle (nil) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] sofia.c:6965 Channel sofia/192.168.10.200/262086050@187.239.216.12:5060 entering state [received][100] 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] sofia.c:6975 Remote SDP: v=0 o=- 907486760 907486761 IN IP4 187.239.216.12 s=VoipSIP c=IN IP4 187.239.216.12 t=0 0 m=audio 7446 RTP/AVP 8 0 97 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:97 telephone-event/8000 a=fmtp:97 0-15 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] sofia.c:7344 (sofia/192.168.10.200/262086050@187.239.216.12:5060) State Change CS_NEW -> CS_INIT 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_core_state_machine.c:603 (sofia/192.168.10.200/262086050@187.239.216.12:5060) State NEW 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_core_state_machine.c:584 (sofia/192.168.10.200/262086050@187.239.216.12:5060) Running State Change CS_INIT 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_core_state_machine.c:627 (sofia/192.168.10.200/262086050@187.239.216.12:5060) State INIT 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] mod_sofia.c:90 sofia/192.168.10.200/262086050@187.239.216.12:5060 SOFIA INIT 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_core_state_machine.c:40 sofia/192.168.10.200/262086050@187.239.216.12:5060 Standard INIT 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_core_state_machine.c:48 (sofia/192.168.10.200/262086050@187.239.216.12:5060) State Change CS_INIT -> CS_ROUTING 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_core_state_machine.c:627 (sofia/192.168.10.200/262086050@187.239.216.12:5060) State INIT going to sleep 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_core_state_machine.c:584 (sofia/192.168.10.200/262086050@187.239.216.12:5060) Running State Change CS_ROUTING 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_channel.c:2249 (sofia/192.168.10.200/262086050@187.239.216.12:5060) Callstate Change DOWN -> RINGING 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_core_state_machine.c:643 (sofia/192.168.10.200/262086050@187.239.216.12:5060) State ROUTING 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] mod_sofia.c:143 sofia/192.168.10.200/262086050@187.239.216.12:5060 SOFIA ROUTING 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [DEBUG] switch_core_state_machine.c:236 sofia/192.168.10.200/262086050@187.239.216.12:5060 Standard ROUTING 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.018819 [INFO] mod_dialplan_xml.c:637 Processing 262086050 <262086050>->962810476 in context default [...] 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [INFO] switch_ivr_originate.c:1215 Sending early media 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:4299 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:4354 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:4299 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:4215 Set telephone-event payload to 97@8000 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:3019 Set Codec sofia/192.168.10.200/262086050@187.239.216.12:5060 PCMA/8000 20 ms 160 samples 64000 bits 1 channels 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_codec.c:111 sofia/192.168.10.200/262086050@187.239.216.12:5060 Original read codec set to PCMA:8 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:4560 Set telephone-event payload to 97@8000 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:4619 sofia/192.168.10.200/262086050@187.239.216.12:5060 Set 2833 dtmf send payload to 101 recv payload to 101 [...] 2016-09-29 16:33:02.238820 [DEBUG] switch_core_port_allocator.c:183 UDP port robustness check for port 10442 pass 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:6479 AUDIO RTP [sofia/192.168.10.200/262086050@187.239.216.12:5060] 192.168.10.200 port 10442 -> 187.239.216.12 port 7446 codec: 8 ms: 20 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_rtp.c:3838 Starting timer [soft] 160 bytes per 20ms 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:6778 sofia/192.168.10.200/262086050@187.239.216.12:5060 Set 2833 dtmf send payload to 101 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:6785 sofia/192.168.10.200/262086050@187.239.216.12:5060 Set 2833 dtmf receive payload to 101 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] switch_core_media.c:6808 sofia/192.168.10.200/262086050@187.239.216.12:5060 Set rtp dtmf delay to 40 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [NOTICE] sofia_media.c:92 Pre-Answer sofia/192.168.10.200/262086050@187.239.216.12:5060! 315a736f-b5a2-4190-8f87-2541d13a5ea4 EXECUTE sofia/192.168.10.200/262086050@187.239.216.12:5060 lua(execute_on_ring.lua) 2016-09-29 16:33:02.238820 [DEBUG] switch_cpp.cpp:1360 /opt/commsmundi/scripts/fs/execute_on_ring.lua:12 starting 315a736f-b5a2-4190-8f87-2541d13a5ea4 EXECUTE sofia/192.168.10.200/262086050@187.239.216.12:5060 set(_execute_on_ring_done=true) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.238820 [DEBUG] mod_dptools.c:1519 SET sofia/192.168.10.200/262086050@187.239.216.12:5060 [_execute_on_ring_done]=[true] 315a736f-b5a2-4190-8f87-2541d13a5ea4 EXECUTE sofia/192.168.10.200/262086050@187.239.216.12:5060 lua(execute_on_ring_line.lua) 2016-09-29 16:33:02.258821 [DEBUG] switch_cpp.cpp:1360 /opt/commsmundi/scripts/fs/execute_on_ring_line.lua:13 starting (SUPER_RABINO_ENTRADA, => inbound) 315a736f-b5a2-4190-8f87-2541d13a5ea4 EXECUTE sofia/192.168.10.200/262086050@187.239.216.12:5060 hash(insert/last_inbound_uuid/line:SUPER_RABINO_ENTRADA/315a736f-b5a2-4190-8f87-2541d13a5ea4) 315a736f-b5a2-4190-8f87-2541d13a5ea4 EXECUTE sofia/192.168.10.200/262086050@187.239.216.12:5060 hash(insert/last_uuid/line:SUPER_RABINO_ENTRADA/315a736f-b5a2-4190-8f87-2541d13a5ea4) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.258821 [DEBUG] switch_cpp.cpp:1107 sofia/192.168.10.200/262086050@187.239.216.12:5060 destroy/unlink session from object 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.258821 [DEBUG] switch_cpp.cpp:1107 sofia/192.168.10.200/262086050@187.239.216.12:5060 destroy/unlink session from object 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.258821 [DEBUG] switch_channel.c:3480 (sofia/192.168.10.200/262086050@187.239.216.12:5060) Callstate Change RINGING -> EARLY 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.258821 [DEBUG] mod_sofia.c:2307 Ring SDP: v=0 o=FreeSWITCH 1475149140 1475149141 IN IP4 84.124.119.225 s=FreeSWITCH c=IN IP4 84.124.119.225 t=0 0 m=audio 10442 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.258821 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@8000hz 1 channel 20ms 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.258821 [DEBUG] switch_core_codec.c:221 sofia/192.168.10.200/262086050@187.239.216.12:5060 Push codec L16:100 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.258821 [DEBUG] switch_ivr_originate.c:1342 Play Ringback Tone [%(1500,3000,425.0)] 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.278821 [DEBUG] sofia.c:6965 Channel sofia/192.168.10.200/262086050@187.239.216.12:5060 entering state [early][183] 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.478822 [DEBUG] switch_rtp.c:6738 Correct audio ip/port confirmed. [...] 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.738819 [DEBUG] switch_core_codec.c:246 sofia/192.168.10.200/262086050@187.239.216.12:5060 Restore previous codec PCMA:8. 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.738819 [DEBUG] mod_sofia.c:822 Local SDP sofia/192.168.10.200/262086050@187.239.216.12:5060: v=0 o=FreeSWITCH 1475149140 1475149142 IN IP4 84.124.119.225 s=FreeSWITCH c=IN IP4 84.124.119.225 t=0 0 m=audio 10442 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.738819 [NOTICE] switch_ivr_originate.c:3628 Channel [sofia/192.168.10.200/262086050@187.239.216.12:5060] has been answered 315a736f-b5a2-4190-8f87-2541d13a5ea4 EXECUTE sofia/192.168.10.200/262086050@187.239.216.12:5060 lua(execute_on_answer.lua) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:02.738819 [DEBUG] sofia.c:6965 Channel sofia/192.168.10.200/262086050@187.239.216.12:5060 entering state [completed][200] [...] 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.758819 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.758819 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.778832 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.778832 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.798820 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.798820 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.818820 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.818820 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.838820 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.838820 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.858819 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.858819 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.878820 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.878820 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.898829 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.898829 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.918820 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.918820 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.938820 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.938820 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.958831 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:07.958831 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:08.298818 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:08.298818 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:08.318819 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:08.318819 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring... 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:08.338819 [DEBUG] switch_core_media.c:2542 alternate payload received (received 97, expecting 8) 315a736f-b5a2-4190-8f87-2541d13a5ea4 2016-09-29 16:33:08.338819 [WARNING] switch_core_media.c:2565 Could not change to payload type 97, ignoring...