can't hear audio when dialing 9198 (Tetris audio test)
Hi, I installed FreeSwitch 1.2.23 on an Amazon EC2 instance (running Amazon Linux). I opened port 5060 for UDP to the server. I then registered as user 1005 using SipDroid on my phone via WiFi. At first when I dialed 9198, I could hear the Tetris music. I could also hear the music on hold audio (when I dialed 9664). However, the echo test failed. Therefore I tried changing the config for the server according to this: http://wiki.freeswitch.org/wiki/Amazon_EC2 However, after doing that not only did the echo test not work, but neither did the Tetris or music on hold tests. So I returned the config back to what it was originally. Unfortunately I still can't hear the Tetris or music on hold audio. I have tried using both LinPhone and XLite softphones as alternatives, but I can't hear the audio on those either. Signalling appears to work. I can dial an extension on a registered softphone and have another registered softphone ring, but there is no audio. I would appreciate any help or insight anyone has on what the problem might be. Also, I have tried using G722, PCMA, PCMU and GSM audio codecs, but none have worked. All the softphones I have tried are able to register without any noticeable problems. Thanks. Jeff Stark Below is part of the log for a typical session where I can't hear the Tetris audio. (I have masked the IP addresses with descriptive labels): 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Regex (PASS) [tone_stream] destination_number(9198) =~ /^9198$/ break=on-false 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action playback({loops=10}tone_stream://path=${base_dir}/conf/tetris.ttml) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1005@<FreeSwitch server Public IP>) State Change CS_ROUTING -> CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1005@<FreeSwitch server Public IP>) State ROUTING going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:243 sofia/internal/1005@<FreeSwitch server Public IP> SOFIA EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1005@<FreeSwitch server Public IP> Standard EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-spymap/1005/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/1005/9198) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/global/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> export(RFC2822_DATE=Fri, 02 May 2014 23:28:51 +0000) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:1242 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 02 May 2014 23:28:51 +0000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5282 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3190 Set Codec sofia/internal/1005@<FreeSwitch server Public IP> G722/8000 20 ms 160 samples 64000 bits 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_codec.c:111 sofia/internal/1005@<FreeSwitch server Public IP> Original read codec set to G722:9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf send/recv payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3449 AUDIO RTP [sofia/internal/1005@<FreeSwitch server Public IP>] <FreeSwitch server Private IP> port 23728 -> <Softphone Public IP> port 50062 codec: 9 ms: 20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_rtp.c:2040 Starting timer [soft] 160 bytes per 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf send payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf receive payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3749 sofia/internal/1005@<FreeSwitch server Public IP> Set rtp dtmf delay to 40 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1005@<FreeSwitch server Public IP>! 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3368 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1005@<FreeSwitch server Public IP>: 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 v=0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 o=FreeSWITCH 1399049603 1399049604 IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 s=FreeSWITCH 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 t=0 0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 m=audio 23728 RTP/AVP 9 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:9 G722/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=fmtp:101 0-16 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=ptime:20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=sendrecv 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [completed][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] mod_dptools.c:1225 Channel [sofia/internal/1005@<FreeSwitch server Public IP>] has been answered 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3647 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change EARLY -> ACTIVE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> playback({loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml) 2014-05-02 23:28:51.111375 [DEBUG] switch_event.c:1661 Parsing variable [loops]=[10] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@16000hz 1 channels 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [ready][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.331345 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [NOTICE] sofia.c:737 Hangup sofia/internal/1005@<FreeSwitch server Public IP> [CS_EXECUTE] [NORMAL_CLEARING] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_channel.c:3187 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [KILL] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_ivr_play_say.c:1717 done playing file {loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:2810 sofia/internal/1005@<FreeSwitch server Public IP> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change ACTIVE -> HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:680 (sofia/internal/1005@<FreeSwitch server Public IP>) State HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1005@<FreeSwitch server Public IP> hanging up, cause: NORMAL_CLEARING 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1005@<FreeSwitch server Public IP> Standard HANGUP, cause: NORMAL_CLEARING
do you have udp ports open for rtp? On May 4, 2014, at 9:03 PM, Jeff Stark <jstark888@gmail.com> wrote:
Hi,
I installed FreeSwitch 1.2.23 on an Amazon EC2 instance (running Amazon Linux). I opened port 5060 for UDP to the server. I then registered as user 1005 using SipDroid on my phone via WiFi. At first when I dialed 9198, I could hear the Tetris music. I could also hear the music on hold audio (when I dialed 9664). However, the echo test failed. Therefore I tried changing the config for the server according to this: http://wiki.freeswitch.org/wiki/Amazon_EC2 However, after doing that not only did the echo test not work, but neither did the Tetris or music on hold tests. So I returned the config back to what it was originally. Unfortunately I still can't hear the Tetris or music on hold audio. I have tried using both LinPhone and XLite softphones as alternatives, but I can't hear the audio on those either. Signalling appears to work. I can dial an extension on a registered softphone and have another registered softphone ring, but there is no audio. I would appreciate any help or insight anyone has on what the problem might be. Also, I have tried using G722, PCMA, PCMU and GSM audio codecs, but none have worked. All the softphones I have tried are able to register without any noticeable problems.
Thanks.
Jeff Stark
Below is part of the log for a typical session where I can't hear the Tetris audio. (I have masked the IP addresses with descriptive labels):
84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Regex (PASS) [tone_stream] destination_number(9198) =~ /^9198$/ break=on-false 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action playback({loops=10}tone_stream://path=${base_dir}/conf/tetris.ttml) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1005@<FreeSwitch server Public IP>) State Change CS_ROUTING -> CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1005@<FreeSwitch server Public IP>) State ROUTING going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:243 sofia/internal/1005@<FreeSwitch server Public IP> SOFIA EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1005@<FreeSwitch server Public IP> Standard EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-spymap/1005/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/1005/9198) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/global/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> export(RFC2822_DATE=Fri, 02 May 2014 23:28:51 +0000) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:1242 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 02 May 2014 23:28:51 +0000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5282 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3190 Set Codec sofia/internal/1005@<FreeSwitch server Public IP> G722/8000 20 ms 160 samples 64000 bits 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_codec.c:111 sofia/internal/1005@<FreeSwitch server Public IP> Original read codec set to G722:9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf send/recv payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3449 AUDIO RTP [sofia/internal/1005@<FreeSwitch server Public IP>] <FreeSwitch server Private IP> port 23728 -> <Softphone Public IP> port 50062 codec: 9 ms: 20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_rtp.c:2040 Starting timer [soft] 160 bytes per 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf send payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf receive payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3749 sofia/internal/1005@<FreeSwitch server Public IP> Set rtp dtmf delay to 40 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1005@<FreeSwitch server Public IP>! 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3368 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1005@<FreeSwitch server Public IP>: 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 v=0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 o=FreeSWITCH 1399049603 1399049604 IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 s=FreeSWITCH 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 t=0 0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 m=audio 23728 RTP/AVP 9 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:9 G722/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=fmtp:101 0-16 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=ptime:20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=sendrecv 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [completed][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] mod_dptools.c:1225 Channel [sofia/internal/1005@<FreeSwitch server Public IP>] has been answered 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3647 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change EARLY -> ACTIVE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> playback({loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml) 2014-05-02 23:28:51.111375 [DEBUG] switch_event.c:1661 Parsing variable [loops]=[10] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@16000hz 1 channels 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [ready][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.331345 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [NOTICE] sofia.c:737 Hangup sofia/internal/1005@<FreeSwitch server Public IP> [CS_EXECUTE] [NORMAL_CLEARING] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_channel.c:3187 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [KILL] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_ivr_play_say.c:1717 done playing file {loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:2810 sofia/internal/1005@<FreeSwitch server Public IP> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change ACTIVE -> HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:680 (sofia/internal/1005@<FreeSwitch server Public IP>) State HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1005@<FreeSwitch server Public IP> hanging up, cause: NORMAL_CLEARING 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1005@<FreeSwitch server Public IP> Standard HANGUP, cause: NORMAL_CLEARING
Also check the IP in the logged "remote SDP" message (which is before what you're posted). Verify that it's an IP actually reachable from the server. A common problem is having a client that's behind NAT sending the LAN IP which isn't reachable over the internet, rather than it's external IP. On 5 May 2014 14:55, Michael Jerris <mike@jerris.com> wrote:
do you have udp ports open for rtp?
On May 4, 2014, at 9:03 PM, Jeff Stark <jstark888@gmail.com> wrote:
Hi,
I installed FreeSwitch 1.2.23 on an Amazon EC2 instance (running Amazon Linux). I opened port 5060 for UDP to the server. I then registered as user 1005 using SipDroid on my phone via WiFi. At first when I dialed 9198, I could hear the Tetris music. I could also hear the music on hold audio (when I dialed 9664). However, the echo test failed. Therefore I tried changing the config for the server according to this: http://wiki.freeswitch.org/wiki/Amazon_EC2 However, after doing that not only did the echo test not work, but neither did the Tetris or music on hold tests. So I returned the config back to what it was originally. Unfortunately I still can't hear the Tetris or music on hold audio. I have tried using both LinPhone and XLite softphones as alternatives, but I can't hear the audio on those either. Signalling appears to work. I can dial an extension on a registered softphone and have another registered softphone ring, but there is no audio. I would appreciate any help or insight anyone has on what the problem might be. Also, I have tried using G722, PCMA, PCMU and GSM audio codecs, but none have worked. All the softphones I have tried are able to register without any noticeable problems.
Thanks.
Jeff Stark
Below is part of the log for a typical session where I can't hear the Tetris audio. (I have masked the IP addresses with descriptive labels):
84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Regex (PASS) [tone_stream] destination_number(9198) =~ /^9198$/ break=on-false 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action playback({loops=10}tone_stream://path=${base_dir}/conf/tetris.ttml) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1005@<FreeSwitch server Public IP>) State Change CS_ROUTING -> CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1005@<FreeSwitch server Public IP>) State ROUTING going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:243 sofia/internal/1005@<FreeSwitch server Public IP> SOFIA EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1005@<FreeSwitch server Public IP> Standard EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-spymap/1005/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/1005/9198) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/global/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> export(RFC2822_DATE=Fri, 02 May 2014 23:28:51 +0000) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:1242 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 02 May 2014 23:28:51 +0000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5282 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3190 Set Codec sofia/internal/1005@<FreeSwitch server Public IP> G722/8000 20 ms 160 samples 64000 bits 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_codec.c:111 sofia/internal/1005@<FreeSwitch server Public IP> Original read codec set to G722:9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf send/recv payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3449 AUDIO RTP [sofia/internal/1005@<FreeSwitch server Public IP>] <FreeSwitch server Private IP> port 23728 -> <Softphone Public IP> port 50062 codec: 9 ms: 20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_rtp.c:2040 Starting timer [soft] 160 bytes per 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf send payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf receive payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3749 sofia/internal/1005@<FreeSwitch server Public IP> Set rtp dtmf delay to 40 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1005@<FreeSwitch server Public IP>! 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3368 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1005@<FreeSwitch server Public IP>: 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 v=0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 o=FreeSWITCH 1399049603 1399049604 IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 s=FreeSWITCH 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 t=0 0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 m=audio 23728 RTP/AVP 9 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:9 G722/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=fmtp:101 0-16 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=ptime:20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=sendrecv 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [completed][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] mod_dptools.c:1225 Channel [sofia/internal/1005@<FreeSwitch server Public IP>] has been answered 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3647 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change EARLY -> ACTIVE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> playback({loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml) 2014-05-02 23:28:51.111375 [DEBUG] switch_event.c:1661 Parsing variable [loops]=[10] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@16000hz 1 channels 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [ready][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.331345 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [NOTICE] sofia.c:737 Hangup sofia/internal/1005@<FreeSwitch server Public IP> [CS_EXECUTE] [NORMAL_CLEARING] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_channel.c:3187 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [KILL] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_ivr_play_say.c:1717 done playing file {loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:2810 sofia/internal/1005@<FreeSwitch server Public IP> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change ACTIVE -> HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:680 (sofia/internal/1005@<FreeSwitch server Public IP>) State HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1005@<FreeSwitch server Public IP> hanging up, cause: NORMAL_CLEARING 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1005@<FreeSwitch server Public IP> Standard HANGUP, cause: NORMAL_CLEARING
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
You'll find these two variables in your internal and external profiles, try setting them to either STUN (as per the examples in the comments) or hard code the IP address: <param name="ext-rtp-ip" value="$${external_rtp_ip}"/> <param name="ext-sip-ip" value="$${external_sip_ip}"/> This along with opening the correct ports is the best solution I've found for double NAT scenarios, but that's installing on bare metal. YMMV. On 2014-05-06 00:02, Steven Ayre wrote:
Also check the IP in the logged "remote SDP" message (which is before what you're posted). Verify that it's an IP actually reachable from the server. A common problem is having a client that's behind NAT sending the LAN IP which isn't reachable over the internet, rather than it's external IP.
On 5 May 2014 14:55, Michael Jerris <mike@jerris.com> wrote:
do you have udp ports open for rtp?
On May 4, 2014, at 9:03 PM, Jeff Stark <jstark888@gmail.com> wrote:
Hi,
I installed FreeSwitch 1.2.23 on an Amazon EC2 instance (running Amazon Linux). I opened port 5060 for UDP to the server. I then registered as user 1005 using SipDroid on my phone via WiFi. At first when I dialed 9198, I could hear the Tetris music. I could also hear the music on hold audio (when I dialed 9664). However, the echo test failed. Therefore I tried changing the config for the server according to this: http://wiki.freeswitch.org/wiki/Amazon_EC2 [1] However, after doing that not only did the echo test not work, but neither did the Tetris or music on hold tests. So I returned the config back to what it was originally. Unfortunately I still can't hear the Tetris or music on hold audio. I have tried using both LinPhone and XLite softphones as alternatives, but I can't hear the audio on those either. Signalling appears to work. I can dial an extension on a registered softphone and have another registered softphone ring, but there is no audio. I would appreciate any help or insight anyone has on what the problem might be. Also, I have tried using G722, PCMA, PCMU and GSM audio codecs, but none have worked. All the softphones I have tried are able to register without any noticeable problems.
Thanks.
Jeff Stark
Below is part of the log for a typical session where I can't hear the Tetris audio. (I have masked the IP addresses with descriptive labels):
84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Regex (PASS) [tone_stream] destination_number(9198) =~ /^9198$/ break=on-false 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action playback({loops=10}tone_stream://path=${base_dir}/conf/tetris.ttml) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1005@<FreeSwitch server Public IP>) State Change CS_ROUTING -> CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1005@<FreeSwitch server Public IP>) State ROUTING going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:243 sofia/internal/1005@<FreeSwitch server Public IP> SOFIA EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1005@<FreeSwitch server Public IP> Standard EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-spymap/1005/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/1005/9198) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/global/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> export(RFC2822_DATE=Fri, 02 May 2014 23:28:51 +0000) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:1242 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 02 May 2014 23:28:51 +0000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5282 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3190 Set Codec sofia/internal/1005@<FreeSwitch server Public IP> G722/8000 20 ms 160 samples 64000 bits 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_codec.c:111 sofia/internal/1005@<FreeSwitch server Public IP> Original read codec set to G722:9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf send/recv payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3449 AUDIO RTP [sofia/internal/1005@<FreeSwitch server Public IP>] <FreeSwitch server Private IP> port 23728 -> <Softphone Public IP> port 50062 codec: 9 ms: 20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_rtp.c:2040 Starting timer [soft] 160 bytes per 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf send payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf receive payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3749 sofia/internal/1005@<FreeSwitch server Public IP> Set rtp dtmf delay to 40 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1005@<FreeSwitch server Public IP>! 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3368 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1005@<FreeSwitch server Public IP>: 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 v=0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 o=FreeSWITCH 1399049603 1399049604 IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 s=FreeSWITCH 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 t=0 0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 m=audio 23728 RTP/AVP 9 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:9 G722/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=fmtp:101 0-16 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=ptime:20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=sendrecv 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [completed][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] mod_dptools.c:1225 Channel [sofia/internal/1005@<FreeSwitch server Public IP>] has been answered 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3647 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change EARLY -> ACTIVE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> playback({loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml) 2014-05-02 23:28:51.111375 [DEBUG] switch_event.c:1661 Parsing variable [loops]=[10] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@16000hz 1 channels 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [ready][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.331345 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [NOTICE] sofia.c:737 Hangup sofia/internal/1005@<FreeSwitch server Public IP> [CS_EXECUTE] [NORMAL_CLEARING] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_channel.c:3187 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [KILL] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_ivr_play_say.c:1717 done playing file {loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:2810 sofia/internal/1005@<FreeSwitch server Public IP> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change ACTIVE -> HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:680 (sofia/internal/1005@<FreeSwitch server Public IP>) State HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1005@<FreeSwitch server Public IP> hanging up, cause: NORMAL_CLEARING 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1005@<FreeSwitch server Public IP> Standard HANGUP, cause: NORMAL_CLEARING
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2]
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3]
Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6]
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4]
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2] FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3] Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6] FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4] Links: ------ [1] http://wiki.freeswitch.org/wiki/Amazon_EC2 [2] http://www.freeswitchsolutions.com [3] http://www.cudatel.com [4] http://www.freeswitch.org [5] http://wiki.freeswitch.org [6] http://www.cluecon.com [7] http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [8] http://lists.freeswitch.org/mailman/options/freeswitch-users
Thanks to all who commented. Both opening up the UDP RTP ports and setting the internal profile ext-rtp-ip and ext-sip-ip values to the FreeSwitch server public IP solved the problem. Now both the Tetris and Echo tests work. However, I still have a question. When I compared the logs before and after I made the change I saw this difference which I account as the reason for the original problem: Log before the changes: 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1007@<FreeSwitch server Public IP>! 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [DEBUG] switch_channel.c:3368 (sofia/internal/1007@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1007@<FreeSwitch server Public IP>: 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 v=0 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 o=FreeSWITCH 1399305799 1399305800 IN IP4 <FreeSwitch server Private IP> 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 s=FreeSWITCH 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 t=0 0 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 m=audio 28254 RTP/AVP 9 101 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=rtpmap:9 G722/8000 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=fmtp:101 0-16 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=ptime:20 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=sendrecv 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 Log after the changes: bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1007@<FreeSwitch server Public IP>! bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [DEBUG] switch_channel.c:3368 (sofia/internal/1007@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1007@<FreeSwitch server Public IP>: bc2c05ce-d4b1-11e3-bd7d-6970e278349a v=0 bc2c05ce-d4b1-11e3-bd7d-6970e278349a o=FreeSWITCH 1399309520 1399309521 IN IP4 <FreeSwitch server Public IP> bc2c05ce-d4b1-11e3-bd7d-6970e278349a s=FreeSWITCH bc2c05ce-d4b1-11e3-bd7d-6970e278349a c=IN IP4 <FreeSwitch server Public IP> bc2c05ce-d4b1-11e3-bd7d-6970e278349a t=0 0 bc2c05ce-d4b1-11e3-bd7d-6970e278349a m=audio 25038 RTP/AVP 9 101 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=rtpmap:9 G722/8000 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=rtpmap:101 telephone-event/8000 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=fmtp:101 0-16 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=ptime:20 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=sendrecv bc2c05ce-d4b1-11e3-bd7d-6970e278349a So the main difference is that the Local SDP has the server's private IP before I made the changes and then after it has the server's public IP. However, I don't quite understand what is going on here. Is this some additional negotiation between the server and client to establish the audio channel? Thanks. Jeff Stark On Sun, May 4, 2014 at 11:27 PM, Francis <sms@icefire.qza.net.au> wrote:
You'll find these two variables in your internal and external profiles, try setting them to either STUN (as per the examples in the comments) or hard code the IP address:
<param name="ext-rtp-ip" value="$${external_rtp_ip}"/> <param name="ext-sip-ip" value="$${external_sip_ip}"/>
This along with opening the correct ports is the best solution I've found for double NAT scenarios, but that's installing on bare metal. YMMV.
On 2014-05-06 00:02, Steven Ayre wrote:
Also check the IP in the logged "remote SDP" message (which is before what you're posted). Verify that it's an IP actually reachable from the server. A common problem is having a client that's behind NAT sending the LAN IP which isn't reachable over the internet, rather than it's external IP.
On 5 May 2014 14:55, Michael Jerris <mike@jerris.com> wrote:
do you have udp ports open for rtp?
On May 4, 2014, at 9:03 PM, Jeff Stark <jstark888@gmail.com> wrote:
Hi,
I installed FreeSwitch 1.2.23 on an Amazon EC2 instance (running Amazon Linux). I opened port 5060 for UDP to the server. I then registered as user 1005 using SipDroid on my phone via WiFi. At first when I dialed 9198, I could hear the Tetris music. I could also hear the music on hold audio (when I dialed 9664). However, the echo test failed. Therefore I tried changing the config for the server according to this: http://wiki.freeswitch.org/wiki/Amazon_EC2 However, after doing that not only did the echo test not work, but neither did the Tetris or music on hold tests. So I returned the config back to what it was originally. Unfortunately I still can't hear the Tetris or music on hold audio. I have tried using both LinPhone and XLite softphones as alternatives, but I can't hear the audio on those either. Signalling appears to work. I can dial an extension on a registered softphone and have another registered softphone ring, but there is no audio. I would appreciate any help or insight anyone has on what the problem might be. Also, I have tried using G722, PCMA, PCMU and GSM audio codecs, but none have worked. All the softphones I have tried are able to register without any noticeable problems.
Thanks.
Jeff Stark
Below is part of the log for a typical session where I can't hear the Tetris audio. (I have masked the IP addresses with descriptive labels):
84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Regex (PASS) [tone_stream] destination_number(9198) =~ /^9198$/ break=on-false 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action playback({loops=10}tone_stream://path=${base_dir}/conf/tetris.ttml) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1005@<FreeSwitch server Public IP>) State Change CS_ROUTING -> CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1005@<FreeSwitch server Public IP>) State ROUTING going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:243 sofia/internal/1005@<FreeSwitch server Public IP> SOFIA EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1005@<FreeSwitch server Public IP> Standard EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-spymap/1005/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/1005/9198) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/global/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> export(RFC2822_DATE=Fri, 02 May 2014 23:28:51 +0000) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:1242 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 02 May 2014 23:28:51 +0000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5282 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3190 Set Codec sofia/internal/1005@<FreeSwitch server Public IP> G722/8000 20 ms 160 samples 64000 bits 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_codec.c:111 sofia/internal/1005@<FreeSwitch server Public IP> Original read codec set to G722:9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf send/recv payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3449 AUDIO RTP [sofia/internal/1005@<FreeSwitch server Public IP>] <FreeSwitch server Private IP> port 23728 -> <Softphone Public IP> port 50062 codec: 9 ms: 20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_rtp.c:2040 Starting timer [soft] 160 bytes per 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf send payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf receive payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3749 sofia/internal/1005@<FreeSwitch server Public IP> Set rtp dtmf delay to 40 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1005@<FreeSwitch server Public IP>! 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3368 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1005@<FreeSwitch server Public IP>: 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 v=0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 o=FreeSWITCH 1399049603 1399049604 IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 s=FreeSWITCH 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 t=0 0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 m=audio 23728 RTP/AVP 9 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:9 G722/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=fmtp:101 0-16 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=ptime:20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=sendrecv 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [completed][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] mod_dptools.c:1225 Channel [sofia/internal/1005@<FreeSwitch server Public IP>] has been answered 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3647 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change EARLY -> ACTIVE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> playback({loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml) 2014-05-02 23:28:51.111375 [DEBUG] switch_event.c:1661 Parsing variable [loops]=[10] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@16000hz 1 channels 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [ready][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.331345 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [NOTICE] sofia.c:737 Hangup sofia/internal/1005@<FreeSwitch server Public IP> [CS_EXECUTE] [NORMAL_CLEARING] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_channel.c:3187 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [KILL] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_ivr_play_say.c:1717 done playing file {loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:2810 sofia/internal/1005@<FreeSwitch server Public IP> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change ACTIVE -> HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:680 (sofia/internal/1005@<FreeSwitch server Public IP>) State HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1005@<FreeSwitch server Public IP> hanging up, cause: NORMAL_CLEARING 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1005@<FreeSwitch server Public IP> Standard HANGUP, cause: NORMAL_CLEARING
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services:consulting@freeswitch.orghttp://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Serverhttp://www.cudatel.com
Official FreeSWITCH Siteshttp://www.freeswitch.orghttp://wiki.freeswitch.orghttp://www.cluecon.com
FreeSWITCH-users mailing listFreeSWITCH-users@lists.freeswitch.orghttp://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-usershttp://www.frees...
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
What you're seeing is normal for the settings you had. In the first instance, FS doesn't even know if it has a public IP or not, so it's trying to discover the public IP automatically, then decide if the endpoint should get one or the other. That's the smoke and mirrors of NAT detection at work. If at any step of the process- eg, the public IP can't be reliably determined, or the endpoint's public/private/NAT status can't be reliably determined, you see some rather strange behaviour as FS does its best to fix a bad situation. In this case, the endpoint contacts FS at the public IP, then FS, not knowing the public IP, tells the endpoint to send packets to its private IP. The endpoint dutifully obeys, and everything goes pear shaped after that. In the second instance, FS has the public IP already, which helps it better decide how to identify and respond to endpoints. By manually setting the public IP, you're basically telling FS: "Always use this as the public IP, no matter what". which cuts out some of the guesswork on FS part. The NAT logic, simplified, is something like this: Is the endpoint on the same subnet as me? Yes: Give it the local IP for SDP No: Do I know the public IP? Yes: Give the public IP for SDP No: Can I guess the public IP somehow? Yes: Give it the guessed IP and HOPE THAT IT'S THE RIGHT ONE No: Umm... ok, the endpoint must have found me somehow, maybe it's routed to me from another subnet? I'll give it the private IP and let it figure out this mess. Francis On 2014-05-06 10:24, Jeff Stark wrote:
Thanks to all who commented. Both opening up the UDP RTP ports and setting the internal profile ext-rtp-ip and ext-sip-ip values to the FreeSwitch server public IP solved the problem. Now both the Tetris and Echo tests work.
However, I still have a question. When I compared the logs before and after I made the change I saw this difference which I account as the reason for the original problem:
Log before the changes:
8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1007@<FreeSwitch server Public IP>! 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [DEBUG] switch_channel.c:3368 (sofia/internal/1007@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1007@<FreeSwitch server Public IP>: 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 v=0 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 o=FreeSWITCH 1399305799 1399305800 IN IP4 <FreeSwitch server Private IP> 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 s=FreeSWITCH 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 t=0 0 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 m=audio 28254 RTP/AVP 9 101 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=rtpmap:9 G722/8000 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=fmtp:101 0-16 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=ptime:20 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=sendrecv 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9
Log after the changes:
bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1007@<FreeSwitch server Public IP>! bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [DEBUG] switch_channel.c:3368 (sofia/internal/1007@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1007@<FreeSwitch server Public IP>: bc2c05ce-d4b1-11e3-bd7d-6970e278349a v=0 bc2c05ce-d4b1-11e3-bd7d-6970e278349a o=FreeSWITCH 1399309520 1399309521 IN IP4 <FreeSwitch server Public IP> bc2c05ce-d4b1-11e3-bd7d-6970e278349a s=FreeSWITCH bc2c05ce-d4b1-11e3-bd7d-6970e278349a c=IN IP4 <FreeSwitch server Public IP> bc2c05ce-d4b1-11e3-bd7d-6970e278349a t=0 0 bc2c05ce-d4b1-11e3-bd7d-6970e278349a m=audio 25038 RTP/AVP 9 101 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=rtpmap:9 G722/8000 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=rtpmap:101 telephone-event/8000 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=fmtp:101 0-16 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=ptime:20 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=sendrecv bc2c05ce-d4b1-11e3-bd7d-6970e278349a
So the main difference is that the Local SDP has the server's private IP before I made the changes and then after it has the server's public IP. However, I don't quite understand what is going on here. Is this some additional negotiation between the server and client to establish the audio channel?
Thanks.
Jeff Stark
On Sun, May 4, 2014 at 11:27 PM, Francis <sms@icefire.qza.net.au> wrote:
You'll find these two variables in your internal and external profiles, try setting them to either STUN (as per the examples in the comments) or hard code the IP address:
<param name="ext-rtp-ip" value="$${external_rtp_ip}"/> <param name="ext-sip-ip" value="$${external_sip_ip}"/>
This along with opening the correct ports is the best solution I've found for double NAT scenarios, but that's installing on bare metal. YMMV.
On 2014-05-06 00:02, Steven Ayre wrote: Also check the IP in the logged "remote SDP" message (which is before what you're posted). Verify that it's an IP actually reachable from the server. A common problem is having a client that's behind NAT sending the LAN IP which isn't reachable over the internet, rather than it's external IP.
On 5 May 2014 14:55, Michael Jerris <mike@jerris.com> wrote:
do you have udp ports open for rtp?
On May 4, 2014, at 9:03 PM, Jeff Stark <jstark888@gmail.com> wrote:
Hi,
I installed FreeSwitch 1.2.23 on an Amazon EC2 instance (running Amazon Linux). I opened port 5060 for UDP to the server. I then registered as user 1005 using SipDroid on my phone via WiFi. At first when I dialed 9198, I could hear the Tetris music. I could also hear the music on hold audio (when I dialed 9664). However, the echo test failed. Therefore I tried changing the config for the server according to this: http://wiki.freeswitch.org/wiki/Amazon_EC2 [1] However, after doing that not only did the echo test not work, but neither did the Tetris or music on hold tests. So I returned the config back to what it was originally. Unfortunately I still can't hear the Tetris or music on hold audio. I have tried using both LinPhone and XLite softphones as alternatives, but I can't hear the audio on those either. Signalling appears to work. I can dial an extension on a registered softphone and have another registered softphone ring, but there is no audio. I would appreciate any help or insight anyone has on what the problem might be. Also, I have tried using G722, PCMA, PCMU and GSM audio codecs, but none have worked. All the softphones I have tried are able to register without any noticeable problems.
Thanks.
Jeff Stark
Below is part of the log for a typical session where I can't hear the Tetris audio. (I have masked the IP addresses with descriptive labels):
84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Regex (PASS) [tone_stream] destination_number(9198) =~ /^9198$/ break=on-false 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action playback({loops=10}tone_stream://path=${base_dir}/conf/tetris.ttml) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1005@<FreeSwitch server Public IP>) State Change CS_ROUTING -> CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1005@<FreeSwitch server Public IP>) State ROUTING going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:243 sofia/internal/1005@<FreeSwitch server Public IP> SOFIA EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1005@<FreeSwitch server Public IP> Standard EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-spymap/1005/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/1005/9198) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/global/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> export(RFC2822_DATE=Fri, 02 May 2014 23:28:51 +0000) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:1242 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 02 May 2014 23:28:51 +0000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5282 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3190 Set Codec sofia/internal/1005@<FreeSwitch server Public IP> G722/8000 20 ms 160 samples 64000 bits 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_codec.c:111 sofia/internal/1005@<FreeSwitch server Public IP> Original read codec set to G722:9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf send/recv payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3449 AUDIO RTP [sofia/internal/1005@<FreeSwitch server Public IP>] <FreeSwitch server Private IP> port 23728 -> <Softphone Public IP> port 50062 codec: 9 ms: 20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_rtp.c:2040 Starting timer [soft] 160 bytes per 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf send payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf receive payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3749 sofia/internal/1005@<FreeSwitch server Public IP> Set rtp dtmf delay to 40 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1005@<FreeSwitch server Public IP>! 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3368 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1005@<FreeSwitch server Public IP>: 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 v=0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 o=FreeSWITCH 1399049603 1399049604 IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 s=FreeSWITCH 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 t=0 0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 m=audio 23728 RTP/AVP 9 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:9 G722/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=fmtp:101 0-16 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=ptime:20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=sendrecv 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [completed][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] mod_dptools.c:1225 Channel [sofia/internal/1005@<FreeSwitch server Public IP>] has been answered 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3647 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change EARLY -> ACTIVE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> playback({loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml) 2014-05-02 23:28:51.111375 [DEBUG] switch_event.c:1661 Parsing variable [loops]=[10] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@16000hz 1 channels 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [ready][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.331345 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [NOTICE] sofia.c:737 Hangup sofia/internal/1005@<FreeSwitch server Public IP> [CS_EXECUTE] [NORMAL_CLEARING] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_channel.c:3187 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [KILL] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_ivr_play_say.c:1717 done playing file {loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:2810 sofia/internal/1005@<FreeSwitch server Public IP> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change ACTIVE -> HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:680 (sofia/internal/1005@<FreeSwitch server Public IP>) State HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1005@<FreeSwitch server Public IP> hanging up, cause: NORMAL_CLEARING 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1005@<FreeSwitch server Public IP> Standard HANGUP, cause: NORMAL_CLEARING
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2]
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3]
Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6]
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4]
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2] FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3] Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6] FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4] _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2] FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3] Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6] FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4] _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2] FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3] Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6] FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4] Links: ------ [1] http://wiki.freeswitch.org/wiki/Amazon_EC2 [2] http://www.freeswitchsolutions.com [3] http://www.cudatel.com [4] http://www.freeswitch.org [5] http://wiki.freeswitch.org [6] http://www.cluecon.com [7] http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [8] http://lists.freeswitch.org/mailman/options/freeswitch-users
Great explanation Francis. Thanks. What is strange is that when I first started the server (with auto-nat settings) it worked. It only stopped working when I stopped the server and then restarted it. In any case it works now with ext-rtp-ip and ext-sip-ip explicitly set with the server's public IP. Thanks again. Jeff On Mon, May 5, 2014 at 6:00 PM, Francis <sms@icefire.qza.net.au> wrote:
What you're seeing is normal for the settings you had.
In the first instance, FS doesn't even know if it has a public IP or not, so it's trying to discover the public IP automatically, then decide if the endpoint should get one or the other. That's the smoke and mirrors of NAT detection at work. If at any step of the process- eg, the public IP can't be reliably determined, or the endpoint's public/private/NAT status can't be reliably determined, you see some rather strange behaviour as FS does its best to fix a bad situation. In this case, the endpoint contacts FS at the public IP, then FS, not knowing the public IP, tells the endpoint to send packets to its private IP. The endpoint dutifully obeys, and everything goes pear shaped after that.
In the second instance, FS has the public IP already, which helps it better decide how to identify and respond to endpoints. By manually setting the public IP, you're basically telling FS: "Always use this as the public IP, no matter what". which cuts out some of the guesswork on FS part.
The NAT logic, simplified, is something like this:
Is the endpoint on the same subnet as me?
Yes: Give it the local IP for SDP
No: Do I know the public IP?
Yes: Give the public IP for SDP
No: Can I guess the public IP somehow?
Yes: Give it the guessed IP and HOPE THAT IT'S THE RIGHT ONE
No: Umm... ok, the endpoint must have found me somehow, maybe it's routed to me from another subnet? I'll give it the private IP and let it figure out this mess.
Francis
On 2014-05-06 10:24, Jeff Stark wrote:
Thanks to all who commented. Both opening up the UDP RTP ports and setting the internal profile ext-rtp-ip and ext-sip-ip values to the FreeSwitch server public IP solved the problem. Now both the Tetris and Echo tests work.
However, I still have a question. When I compared the logs before and after I made the change I saw this difference which I account as the reason for the original problem:
Log before the changes:
8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1007@<FreeSwitch server Public IP>! 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [DEBUG] switch_channel.c:3368 (sofia/internal/1007@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1007@<FreeSwitch server Public IP>: 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 v=0 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 o=FreeSWITCH 1399305799 1399305800 IN IP4 <FreeSwitch server Private IP> 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 s=FreeSWITCH 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 t=0 0 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 m=audio 28254 RTP/AVP 9 101 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=rtpmap:9 G722/8000 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=fmtp:101 0-16 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=ptime:20 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=sendrecv 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9
Log after the changes:
bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1007@<FreeSwitch server Public IP>! bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [DEBUG] switch_channel.c:3368 (sofia/internal/1007@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1007@<FreeSwitch server Public IP>: bc2c05ce-d4b1-11e3-bd7d-6970e278349a v=0 bc2c05ce-d4b1-11e3-bd7d-6970e278349a o=FreeSWITCH 1399309520 1399309521 IN IP4 <FreeSwitch server Public IP> bc2c05ce-d4b1-11e3-bd7d-6970e278349a s=FreeSWITCH bc2c05ce-d4b1-11e3-bd7d-6970e278349a c=IN IP4 <FreeSwitch server Public IP> bc2c05ce-d4b1-11e3-bd7d-6970e278349a t=0 0 bc2c05ce-d4b1-11e3-bd7d-6970e278349a m=audio 25038 RTP/AVP 9 101 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=rtpmap:9 G722/8000 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=rtpmap:101 telephone-event/8000 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=fmtp:101 0-16 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=ptime:20 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=sendrecv bc2c05ce-d4b1-11e3-bd7d-6970e278349a
So the main difference is that the Local SDP has the server's private IP before I made the changes and then after it has the server's public IP. However, I don't quite understand what is going on here. Is this some additional negotiation between the server and client to establish the audio channel?
Thanks.
Jeff Stark
On Sun, May 4, 2014 at 11:27 PM, Francis <sms@icefire.qza.net.au> wrote:
You'll find these two variables in your internal and external profiles, try setting them to either STUN (as per the examples in the comments) or hard code the IP address:
<param name="ext-rtp-ip" value="$${external_rtp_ip}"/> <param name="ext-sip-ip" value="$${external_sip_ip}"/>
This along with opening the correct ports is the best solution I've found for double NAT scenarios, but that's installing on bare metal. YMMV.
On 2014-05-06 00:02, Steven Ayre wrote:
Also check the IP in the logged "remote SDP" message (which is before what you're posted). Verify that it's an IP actually reachable from the server. A common problem is having a client that's behind NAT sending the LAN IP which isn't reachable over the internet, rather than it's external IP.
On 5 May 2014 14:55, Michael Jerris <mike@jerris.com> wrote:
do you have udp ports open for rtp?
On May 4, 2014, at 9:03 PM, Jeff Stark <jstark888@gmail.com> wrote:
Hi,
I installed FreeSwitch 1.2.23 on an Amazon EC2 instance (running Amazon Linux). I opened port 5060 for UDP to the server. I then registered as user 1005 using SipDroid on my phone via WiFi. At first when I dialed 9198, I could hear the Tetris music. I could also hear the music on hold audio (when I dialed 9664). However, the echo test failed. Therefore I tried changing the config for the server according to this: http://wiki.freeswitch.org/wiki/Amazon_EC2 However, after doing that not only did the echo test not work, but neither did the Tetris or music on hold tests. So I returned the config back to what it was originally. Unfortunately I still can't hear the Tetris or music on hold audio. I have tried using both LinPhone and XLite softphones as alternatives, but I can't hear the audio on those either. Signalling appears to work. I can dial an extension on a registered softphone and have another registered softphone ring, but there is no audio. I would appreciate any help or insight anyone has on what the problem might be. Also, I have tried using G722, PCMA, PCMU and GSM audio codecs, but none have worked. All the softphones I have tried are able to register without any noticeable problems.
Thanks.
Jeff Stark
Below is part of the log for a typical session where I can't hear the Tetris audio. (I have masked the IP addresses with descriptive labels):
84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Regex (PASS) [tone_stream] destination_number(9198) =~ /^9198$/ break=on-false 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action playback({loops=10}tone_stream://path=${base_dir}/conf/tetris.ttml) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1005@<FreeSwitch server Public IP>) State Change CS_ROUTING -> CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1005@<FreeSwitch server Public IP>) State ROUTING going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:243 sofia/internal/1005@<FreeSwitch server Public IP> SOFIA EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1005@<FreeSwitch server Public IP> Standard EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-spymap/1005/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/1005/9198) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/global/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> export(RFC2822_DATE=Fri, 02 May 2014 23:28:51 +0000) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:1242 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 02 May 2014 23:28:51 +0000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5282 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3190 Set Codec sofia/internal/1005@<FreeSwitch server Public IP> G722/8000 20 ms 160 samples 64000 bits 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_codec.c:111 sofia/internal/1005@<FreeSwitch server Public IP> Original read codec set to G722:9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf send/recv payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3449 AUDIO RTP [sofia/internal/1005@<FreeSwitch server Public IP>] <FreeSwitch server Private IP> port 23728 -> <Softphone Public IP> port 50062 codec: 9 ms: 20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_rtp.c:2040 Starting timer [soft] 160 bytes per 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf send payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf receive payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3749 sofia/internal/1005@<FreeSwitch server Public IP> Set rtp dtmf delay to 40 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1005@<FreeSwitch server Public IP>! 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3368 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1005@<FreeSwitch server Public IP>: 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 v=0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 o=FreeSWITCH 1399049603 1399049604 IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 s=FreeSWITCH 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 t=0 0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 m=audio 23728 RTP/AVP 9 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:9 G722/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=fmtp:101 0-16 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=ptime:20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=sendrecv 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [completed][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] mod_dptools.c:1225 Channel [sofia/internal/1005@<FreeSwitch server Public IP>] has been answered 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3647 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change EARLY -> ACTIVE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> playback({loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml) 2014-05-02 23:28:51.111375 [DEBUG] switch_event.c:1661 Parsing variable [loops]=[10] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@16000hz 1 channels 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [ready][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.331345 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [NOTICE] sofia.c:737 Hangup sofia/internal/1005@<FreeSwitch server Public IP> [CS_EXECUTE] [NORMAL_CLEARING] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_channel.c:3187 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [KILL] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_ivr_play_say.c:1717 done playing file {loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:2810 sofia/internal/1005@<FreeSwitch server Public IP> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change ACTIVE -> HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:680 (sofia/internal/1005@<FreeSwitch server Public IP>) State HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1005@<FreeSwitch server Public IP> hanging up, cause: NORMAL_CLEARING 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1005@<FreeSwitch server Public IP> Standard HANGUP, cause: NORMAL_CLEARING
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services:consulting@freeswitch.orghttp://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Serverhttp://www.cudatel.com
Official FreeSWITCH Siteshttp://www.freeswitch.orghttp://wiki.freeswitch.orghttp://www.cluecon.com
FreeSWITCH-users mailing listFreeSWITCH-users@lists.freeswitch.orghttp://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-usershttp://www.frees...
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services:consulting@freeswitch.orghttp://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Serverhttp://www.cudatel.com
Official FreeSWITCH Siteshttp://www.freeswitch.orghttp://wiki.freeswitch.orghttp://www.cluecon.com
FreeSWITCH-users mailing listFreeSWITCH-users@lists.freeswitch.orghttp://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-usershttp://www.frees...
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
I won't tell you how many hours I spent getting my head around NAT ;) On 2014-05-08 04:44, Jeff Stark wrote:
Great explanation Francis. Thanks.
What is strange is that when I first started the server (with auto-nat settings) it worked. It only stopped working when I stopped the server and then restarted it. In any case it works now with ext-rtp-ip and ext-sip-ip explicitly set with the server's public IP.
Thanks again.
Jeff
On Mon, May 5, 2014 at 6:00 PM, Francis <sms@icefire.qza.net.au> wrote:
What you're seeing is normal for the settings you had.
In the first instance, FS doesn't even know if it has a public IP or not, so it's trying to discover the public IP automatically, then decide if the endpoint should get one or the other. That's the smoke and mirrors of NAT detection at work. If at any step of the process- eg, the public IP can't be reliably determined, or the endpoint's public/private/NAT status can't be reliably determined, you see some rather strange behaviour as FS does its best to fix a bad situation. In this case, the endpoint contacts FS at the public IP, then FS, not knowing the public IP, tells the endpoint to send packets to its private IP. The endpoint dutifully obeys, and everything goes pear shaped after that.
In the second instance, FS has the public IP already, which helps it better decide how to identify and respond to endpoints. By manually setting the public IP, you're basically telling FS: "Always use this as the public IP, no matter what". which cuts out some of the guesswork on FS part.
The NAT logic, simplified, is something like this:
Is the endpoint on the same subnet as me?
Yes: Give it the local IP for SDP
No: Do I know the public IP?
Yes: Give the public IP for SDP
No: Can I guess the public IP somehow?
Yes: Give it the guessed IP and HOPE THAT IT'S THE RIGHT ONE
No: Umm... ok, the endpoint must have found me somehow, maybe it's routed to me from another subnet? I'll give it the private IP and let it figure out this mess.
Francis
On 2014-05-06 10:24, Jeff Stark wrote: Thanks to all who commented. Both opening up the UDP RTP ports and setting the internal profile ext-rtp-ip and ext-sip-ip values to the FreeSwitch server public IP solved the problem. Now both the Tetris and Echo tests work.
However, I still have a question. When I compared the logs before and after I made the change I saw this difference which I account as the reason for the original problem:
Log before the changes:
8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1007@<FreeSwitch server Public IP>! 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [DEBUG] switch_channel.c:3368 (sofia/internal/1007@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 2014-05-05 23:54:13.331397 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1007@<FreeSwitch server Public IP>: 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 v=0 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 o=FreeSWITCH 1399305799 1399305800 IN IP4 <FreeSwitch server Private IP> 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 s=FreeSWITCH 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 t=0 0 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 m=audio 28254 RTP/AVP 9 101 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=rtpmap:9 G722/8000 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=fmtp:101 0-16 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=ptime:20 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9 a=sendrecv 8f1896d4-d4b0-11e3-98a8-7f053ccdf4d9
Log after the changes:
bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1007@<FreeSwitch server Public IP>! bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [DEBUG] switch_channel.c:3368 (sofia/internal/1007@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY bc2c05ce-d4b1-11e3-bd7d-6970e278349a 2014-05-06 00:02:38.431536 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1007@<FreeSwitch server Public IP>: bc2c05ce-d4b1-11e3-bd7d-6970e278349a v=0 bc2c05ce-d4b1-11e3-bd7d-6970e278349a o=FreeSWITCH 1399309520 1399309521 IN IP4 <FreeSwitch server Public IP> bc2c05ce-d4b1-11e3-bd7d-6970e278349a s=FreeSWITCH bc2c05ce-d4b1-11e3-bd7d-6970e278349a c=IN IP4 <FreeSwitch server Public IP> bc2c05ce-d4b1-11e3-bd7d-6970e278349a t=0 0 bc2c05ce-d4b1-11e3-bd7d-6970e278349a m=audio 25038 RTP/AVP 9 101 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=rtpmap:9 G722/8000 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=rtpmap:101 telephone-event/8000 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=fmtp:101 0-16 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=ptime:20 bc2c05ce-d4b1-11e3-bd7d-6970e278349a a=sendrecv bc2c05ce-d4b1-11e3-bd7d-6970e278349a
So the main difference is that the Local SDP has the server's private IP before I made the changes and then after it has the server's public IP. However, I don't quite understand what is going on here. Is this some additional negotiation between the server and client to establish the audio channel?
Thanks.
Jeff Stark
On Sun, May 4, 2014 at 11:27 PM, Francis <sms@icefire.qza.net.au> wrote:
You'll find these two variables in your internal and external profiles, try setting them to either STUN (as per the examples in the comments) or hard code the IP address:
<param name="ext-rtp-ip" value="$${external_rtp_ip}"/> <param name="ext-sip-ip" value="$${external_sip_ip}"/>
This along with opening the correct ports is the best solution I've found for double NAT scenarios, but that's installing on bare metal. YMMV.
On 2014-05-06 00:02, Steven Ayre wrote: Also check the IP in the logged "remote SDP" message (which is before what you're posted). Verify that it's an IP actually reachable from the server. A common problem is having a client that's behind NAT sending the LAN IP which isn't reachable over the internet, rather than it's external IP.
On 5 May 2014 14:55, Michael Jerris <mike@jerris.com> wrote:
do you have udp ports open for rtp?
On May 4, 2014, at 9:03 PM, Jeff Stark <jstark888@gmail.com> wrote:
Hi,
I installed FreeSwitch 1.2.23 on an Amazon EC2 instance (running Amazon Linux). I opened port 5060 for UDP to the server. I then registered as user 1005 using SipDroid on my phone via WiFi. At first when I dialed 9198, I could hear the Tetris music. I could also hear the music on hold audio (when I dialed 9664). However, the echo test failed. Therefore I tried changing the config for the server according to this: http://wiki.freeswitch.org/wiki/Amazon_EC2 [1] However, after doing that not only did the echo test not work, but neither did the Tetris or music on hold tests. So I returned the config back to what it was originally. Unfortunately I still can't hear the Tetris or music on hold audio. I have tried using both LinPhone and XLite softphones as alternatives, but I can't hear the audio on those either. Signalling appears to work. I can dial an extension on a registered softphone and have another registered softphone ring, but there is no audio. I would appreciate any help or insight anyone has on what the problem might be. Also, I have tried using G722, PCMA, PCMU and GSM audio codecs, but none have worked. All the softphones I have tried are able to register without any noticeable problems.
Thanks.
Jeff Stark
Below is part of the log for a typical session where I can't hear the Tetris audio. (I have masked the IP addresses with descriptive labels):
84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Regex (PASS) [tone_stream] destination_number(9198) =~ /^9198$/ break=on-false 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action playback({loops=10}tone_stream://path=${base_dir}/conf/tetris.ttml) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1005@<FreeSwitch server Public IP>) State Change CS_ROUTING -> CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1005@<FreeSwitch server Public IP>) State ROUTING going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:243 sofia/internal/1005@<FreeSwitch server Public IP> SOFIA EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1005@<FreeSwitch server Public IP> Standard EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-spymap/1005/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/1005/9198) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/global/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> export(RFC2822_DATE=Fri, 02 May 2014 23:28:51 +0000) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:1242 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 02 May 2014 23:28:51 +0000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5282 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3190 Set Codec sofia/internal/1005@<FreeSwitch server Public IP> G722/8000 20 ms 160 samples 64000 bits 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_codec.c:111 sofia/internal/1005@<FreeSwitch server Public IP> Original read codec set to G722:9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf send/recv payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3449 AUDIO RTP [sofia/internal/1005@<FreeSwitch server Public IP>] <FreeSwitch server Private IP> port 23728 -> <Softphone Public IP> port 50062 codec: 9 ms: 20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_rtp.c:2040 Starting timer [soft] 160 bytes per 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf send payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf receive payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3749 sofia/internal/1005@<FreeSwitch server Public IP> Set rtp dtmf delay to 40 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1005@<FreeSwitch server Public IP>! 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3368 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1005@<FreeSwitch server Public IP>: 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 v=0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 o=FreeSWITCH 1399049603 1399049604 IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 s=FreeSWITCH 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 t=0 0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 m=audio 23728 RTP/AVP 9 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:9 G722/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=fmtp:101 0-16 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=ptime:20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=sendrecv 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [completed][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] mod_dptools.c:1225 Channel [sofia/internal/1005@<FreeSwitch server Public IP>] has been answered 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3647 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change EARLY -> ACTIVE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> playback({loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml) 2014-05-02 23:28:51.111375 [DEBUG] switch_event.c:1661 Parsing variable [loops]=[10] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@16000hz 1 channels 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [ready][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.331345 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [NOTICE] sofia.c:737 Hangup sofia/internal/1005@<FreeSwitch server Public IP> [CS_EXECUTE] [NORMAL_CLEARING] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_channel.c:3187 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [KILL] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_ivr_play_say.c:1717 done playing file {loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:2810 sofia/internal/1005@<FreeSwitch server Public IP> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change ACTIVE -> HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:680 (sofia/internal/1005@<FreeSwitch server Public IP>) State HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1005@<FreeSwitch server Public IP> hanging up, cause: NORMAL_CLEARING 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1005@<FreeSwitch server Public IP> Standard HANGUP, cause: NORMAL_CLEARING
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2]
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3]
Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6]
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4]
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2] FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3] Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6] FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4] _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2] FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3] Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6] FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4] _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2] FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3] Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6] FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4] _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2] FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3] Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6] FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4] _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com [2] FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com [3] Official FreeSWITCH Sites http://www.freeswitch.org [4] http://wiki.freeswitch.org [5] http://www.cluecon.com [6] FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [7] UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users [8] http://www.freeswitch.org [4] Links: ------ [1] http://wiki.freeswitch.org/wiki/Amazon_EC2 [2] http://www.freeswitchsolutions.com [3] http://www.cudatel.com [4] http://www.freeswitch.org [5] http://wiki.freeswitch.org [6] http://www.cluecon.com [7] http://lists.freeswitch.org/mailman/listinfo/freeswitch-users [8] http://lists.freeswitch.org/mailman/options/freeswitch-users
There is more than 5060 that needs to be opened, see https://wiki.freeswitch.org/wiki/Firewall Thanks, Moishe Grunstein Tornado Computer Systems, Inc. 212.400.7650 888.IPPBX.US Service Request Email: support@nysolutions.com<mailto:support@nysolutions.com> Polycom Certified VAR Microsoft Small Business Specialist, Cisco SMB Select Certified [cid:image001.jpg@01C72F94.9EE45D60]<http://www.nysolutions.com/> Computer Networking * Managed Services * IP Video Surveillance * Network Assessments * Web Solutions * Voice over IP * Disaster Recovery * Network Security * Site Surveys * CMS From: freeswitch-users-bounces@lists.freeswitch.org [mailto:freeswitch-users-bounces@lists.freeswitch.org] On Behalf Of Steven Ayre Sent: Monday, May 05, 2014 10:03 AM To: FreeSWITCH Users Help Subject: Re: [Freeswitch-users] can't hear audio when dialing 9198 (Tetris audio test) Also check the IP in the logged "remote SDP" message (which is before what you're posted). Verify that it's an IP actually reachable from the server. A common problem is having a client that's behind NAT sending the LAN IP which isn't reachable over the internet, rather than it's external IP. On 5 May 2014 14:55, Michael Jerris <mike@jerris.com<mailto:mike@jerris.com>> wrote: do you have udp ports open for rtp? On May 4, 2014, at 9:03 PM, Jeff Stark <jstark888@gmail.com<mailto:jstark888@gmail.com>> wrote: Hi, I installed FreeSwitch 1.2.23 on an Amazon EC2 instance (running Amazon Linux). I opened port 5060 for UDP to the server. I then registered as user 1005 using SipDroid on my phone via WiFi. At first when I dialed 9198, I could hear the Tetris music. I could also hear the music on hold audio (when I dialed 9664). However, the echo test failed. Therefore I tried changing the config for the server according to this: http://wiki.freeswitch.org/wiki/Amazon_EC2 However, after doing that not only did the echo test not work, but neither did the Tetris or music on hold tests. So I returned the config back to what it was originally. Unfortunately I still can't hear the Tetris or music on hold audio. I have tried using both LinPhone and XLite softphones as alternatives, but I can't hear the audio on those either. Signalling appears to work. I can dial an extension on a registered softphone and have another registered softphone ring, but there is no audio. I would appreciate any help or insight anyone has on what the problem might be. Also, I have tried using G722, PCMA, PCMU and GSM audio codecs, but none have worked. All the softphones I have tried are able to register without any noticeable problems. Thanks. Jeff Stark Below is part of the log for a typical session where I can't hear the Tetris audio. (I have masked the IP addresses with descriptive labels): 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Regex (PASS) [tone_stream] destination_number(9198) =~ /^9198$/ break=on-false 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 Dialplan: sofia/internal/1005@<FreeSwitch server Public IP> Action playback({loops=10}tone_stream://path=${base_dir}/conf/tetris.ttml) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1005@<FreeSwitch server Public IP>) State Change CS_ROUTING -> CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1005@<FreeSwitch server Public IP>) State ROUTING going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:243 sofia/internal/1005@<FreeSwitch server Public IP> SOFIA EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1005@<FreeSwitch server Public IP> Standard EXECUTE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-spymap/1005/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/1005/9198) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> hash(insert/<FreeSwitch server Private IP>-last_dial/global/84a7c5c8-d251-11e3-9565-7f053ccdf4d9) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> export(RFC2822_DATE=Fri, 02 May 2014 23:28:51 +0000) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:1242 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 02 May 2014 23:28:51 +0000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> answer() 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5282 Audio Codec Compare [G722:9:8000:20:64000]/[G722:9:8000:20:64000] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3190 Set Codec sofia/internal/1005@<FreeSwitch server Public IP> G722/8000 20 ms 160 samples 64000 bits 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_codec.c:111 sofia/internal/1005@<FreeSwitch server Public IP> Original read codec set to G722:9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:5451 Set 2833 dtmf send/recv payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3449 AUDIO RTP [sofia/internal/1005@<FreeSwitch server Public IP>] <FreeSwitch server Private IP> port 23728 -> <Softphone Public IP> port 50062 codec: 9 ms: 20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_rtp.c:2040 Starting timer [soft] 160 bytes per 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3716 Set 2833 dtmf send payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3722 Set 2833 dtmf receive payload to 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia_glue.c:3749 sofia/internal/1005@<FreeSwitch server Public IP> Set rtp dtmf delay to 40 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] sofia_glue.c:4360 Pre-Answer sofia/internal/1005@<FreeSwitch server Public IP>! 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3368 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change RINGING -> EARLY 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] mod_sofia.c:866 Local SDP sofia/internal/1005@<FreeSwitch server Public IP>: 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 v=0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 o=FreeSWITCH 1399049603 1399049604 IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 s=FreeSWITCH 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 c=IN IP4 <FreeSwitch server Private IP> 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 t=0 0 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 m=audio 23728 RTP/AVP 9 101 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:9 G722/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=rtpmap:101 telephone-event/8000 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=fmtp:101 0-16 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=ptime:20 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 a=sendrecv 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [completed][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [NOTICE] mod_dptools.c:1225 Channel [sofia/internal/1005@<FreeSwitch server Public IP>] has been answered 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_channel.c:3647 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change EARLY -> ACTIVE 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 EXECUTE sofia/internal/1005@<FreeSwitch server Public IP> playback({loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml) 2014-05-02 23:28:51.111375 [DEBUG] switch_event.c:1661 Parsing variable [loops]=[10] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.111375 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@16000hz 1 channels 20ms 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:28:51.331419 [DEBUG] sofia.c:5815 Channel sofia/internal/1005@<FreeSwitch server Public IP> entering state [ready][200] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.331345 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [NOTICE] sofia.c:737 Hangup sofia/internal/1005@<FreeSwitch server Public IP> [CS_EXECUTE] [NORMAL_CLEARING] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_channel.c:3187 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [KILL] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1005@<FreeSwitch server Public IP> [BREAK] 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_ivr_play_say.c:1717 done playing file {loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_session.c:2810 sofia/internal/1005@<FreeSwitch server Public IP> skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1005@<FreeSwitch server Public IP>) State EXECUTE going to sleep 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1005@<FreeSwitch server Public IP>) Running State Change CS_HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:678 (sofia/internal/1005@<FreeSwitch server Public IP>) Callstate Change ACTIVE -> HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:680 (sofia/internal/1005@<FreeSwitch server Public IP>) State HANGUP 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1005@<FreeSwitch server Public IP> hanging up, cause: NORMAL_CLEARING 84a7c5c8-d251-11e3-9565-7f053ccdf4d9 2014-05-02 23:29:31.351377 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1005@<FreeSwitch server Public IP> Standard HANGUP, cause: NORMAL_CLEARING _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org<mailto:consulting@freeswitch.org> http://www.freeswitchsolutions.com FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org<mailto:FreeSWITCH-users@lists.freeswitch.org> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
participants (5)
-
Francis
-
Jeff Stark
-
Michael Jerris
-
Moishe Grunstein
-
Steven Ayre