[Freeswitch-users] can't hear audio when dialing 9198 (Tetris audio test)

Mon May 5 05:03:52 MSD 2014

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 at 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140504/6a18f879/attachment-0001.html 