Hi All, I am trying to transcode between OPUS and G711. I encountered a strange problem which I couldn’t find any clue about the cause. After the channel has been answered with opus, I hear a strange sound (highly distorted version of my voice) for 10 seconds and it starts to operate properly with the message "[DEBUG] switch_core_media_bug.c:1198 Removing BUG from…” . I can reproduce same problem with echo application. Here is my logs and opus.conf.xml files. Did anybody experienced this issue? Thanks. /Volkan My FreeSWITH Version: FreeSWITCH Version 1.6.16+git~20170407T164913Z~3da6bd0108~64bit (git 3da6bd0 2017-04-07 16:49:13Z 64bit) Opus.xml config: <configuration name="opus.conf"> <settings> <param name="use-vbr" value="1"/> <param name="use-dtx" value="1"/> <param name="complexity" value="10"/> <param name="maxaveragebitrate" value="14400"/> <param name="maxplaybackrate" value="8000"/> <param name="packet-loss-percent" value="15"/> <param name="keep-fec-enabled" value="1"/> <param name="use-jb-lookahead" value="0"/> <param name="advertise-useinbandfec" value="1"/> <param name="asymmetric-sample-rates" value="1"/> </settings> </configuration> Freeswitch Log: 2017-09-25 22:01:06.277462 [NOTICE] switch_channel.c:1104 New Channel sofia/internalopus/2223@sip.example.com [1048c869-8d71-41fd-b0b7-f8fbd01a0d93] 2017-09-25 22:01:06.277462 [DEBUG] switch_core_state_machine.c:584 (sofia/internalopus/2223@sip.example.com) Running State Change CS_NEW (Cur 2 Tot 3196652) 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:9828 sofia/internalopus/2223@sip.example.com receiving invite from 192.168.100.2:5060 version: 1.6.16 git 3da6bd0 2017-04-07 16:49:13Z 64bit 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com entering state [received][100] 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:7058 Remote SDP: v=0 o=- 8070049943 45777 IN IP4 192.168.100.2 s=dvjtiwu c=IN IP4 192.168.100.2 t=0 0 m=audio 10036 RTP/AVP 103 8 0 9 101 a=rtpmap:103 opus/48000/2 a=fmtp:103 maxplaybackrate=8000;maxaveragebitrate=15500;useinbandfec=1;usedtx=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=nortpproxy:yes . . . . . 2017-09-25 22:01:06.337394 [INFO] mod_dialplan_xml.c:637 Processing 2223 <2223>->*71 in context default Dialplan: sofia/internalopus/2223@sip.example.com parsing [default->echo] continue=false Dialplan: sofia/internalopus/2223@sip.example.com Regex (PASS) [echo] destination_number(*71) =~ /^\*71$/ break=on-false Dialplan: sofia/internalopus/2223@sip.example.com Action answer() Dialplan: sofia/internalopus/2223@sip.example.com Action echo() 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:286 (sofia/internalopus/2223@sip.example.com) State Change CS_ROUTING -> CS_EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:643 (sofia/internalopus/2223@sip.example.com) State ROUTING going to sleep 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:584 (sofia/internalopus/2223@sip.example.com) Running State Change CS_EXECUTE (Cur 2 Tot 3196652) 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:650 (sofia/internalopus/2223@sip.example.com) State EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] mod_sofia.c:198 sofia/internalopus/2223@sip.example.com SOFIA EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:328 sofia/internalopus/2223@sip.example.com Standard EXECUTE EXECUTE sofia/internalopus/2223@sip.example.com answer() 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:3049 Set Codec sofia/internalopus/2223@sip.example.com opus/8000 20 ms 960 samples 0 bits 1 channels 2017-09-25 22:01:06.357410 [DEBUG] switch_core_codec.c:111 sofia/internalopus/2223@sip.example.com Original read codec set to opus:116 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4747 sofia/internalopus/2223@sip.example.com Set 2833 dtmf send payload to 101 recv payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/internalopus/2223@sip.example.com] 192.168.100.12 port 23594 -> 192.168.100.2 port 10036 codec: 103 ms: 20 2017-09-25 22:01:06.357410 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 960 bytes per 20ms 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7109 sofia/internalopus/2223@sip.example.com Set 2833 dtmf send payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7116 sofia/internalopus/2223@sip.example.com Set 2833 dtmf receive payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7139 sofia/internalopus/2223@sip.example.com Set rtp dtmf delay to 40 2017-09-25 22:01:06.357410 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internalopus/2223@sip.example.com! 2017-09-25 22:01:06.357410 [DEBUG] switch_channel.c:3473 (sofia/internalopus/2223@sip.example.com) Callstate Change RINGING -> EARLY 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:6786 Audio params are unchanged for sofia/internalopus/2223@sip.example.com. 2017-09-25 22:01:06.357410 [DEBUG] mod_sofia.c:850 Local SDP sofia/internalopus/2223@sip.example.com: v=0 o=FreeSWITCH 1506342472 1506342473 IN IP4 192.168.100.12 s=FreeSWITCH c=IN IP4 192.168.100.12 t=0 0 m=audio 23594 RTP/AVP 103 101 a=rtpmap:103 opus/48000/2 a=fmtp:103 useinbandfec=1; usedtx=1; maxaveragebitrate=14400; maxplaybackrate=8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2017-09-25 22:01:06.357410 [NOTICE] mod_dptools.c:1312 Channel [sofia/internalopus/2223@sip.example.com] has been answered 2017-09-25 22:01:06.357410 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com entering state [completed][200] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media_bug.c:828 Attaching BUG to sofia/internalopus/2223@sip.example.com 2017-09-25 22:01:06.357410 [DEBUG] switch_channel.c:3772 (sofia/internalopus/2223@sip.example.com) Callstate Change EARLY -> ACTIVE EXECUTE sofia/internalopus/2223@sip.example.com echo() 2017-09-25 22:01:06.737463 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com entering state [ready][200] 2017-09-25 22:01:06.837459 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed. 2017-09-25 22:01:06.837459 [DEBUG] switch_core_io.c:448 Setting BUG Codec opus:116 2017-09-25 22:01:06.837459 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.837459 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.837459 [DEBUG] switch_core_io.c:780 Engaging Read Buffer at 320 bytes vs 15 [...CREEPY VOICE STARTS HERE AND ENDS WITH THE BELOW MESSAGE...] 2017-09-25 22:01:16.017463 [DEBUG] switch_core_media_bug.c:1198 Removing BUG from sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>
This is due to an incomplete implementation of the asymmetric sample rate feature. It should work fine without that setting. On Mon, Sep 25, 2017 at 2:22 PM Volkan Oransoy <voransoy@gmail.com> wrote:
Hi All,
I am trying to transcode between OPUS and G711. I encountered a strange problem which I couldn’t find any clue about the cause. After the channel has been answered with opus, I hear a strange sound (highly distorted version of my voice) for 10 seconds and it starts to operate properly with the message "[DEBUG] switch_core_media_bug.c:1198 Removing BUG from…” . I can reproduce same problem with echo application. Here is my logs and opus.conf.xml files. Did anybody experienced this issue?
Thanks.
/Volkan
My FreeSWITH Version: FreeSWITCH Version 1.6.16+git~20170407T164913Z~3da6bd0108~64bit (git 3da6bd0 2017-04-07 16:49:13Z 64bit)
Opus.xml config: <configuration name="opus.conf"> <settings> <param name="use-vbr" value="1"/> <param name="use-dtx" value="1"/> <param name="complexity" value="10"/> <param name="maxaveragebitrate" value="14400"/> <param name="maxplaybackrate" value="8000"/> <param name="packet-loss-percent" value="15"/> <param name="keep-fec-enabled" value="1"/> <param name="use-jb-lookahead" value="0"/> <param name="advertise-useinbandfec" value="1"/> <param name="asymmetric-sample-rates" value="1"/> </settings> </configuration>
Freeswitch Log: 2017-09-25 22:01:06.277462 [NOTICE] switch_channel.c:1104 New Channel sofia/internalopus/2223@sip.example.com [1048c869-8d71-41fd-b0b7-f8fbd01a0d93] 2017-09-25 22:01:06.277462 [DEBUG] switch_core_state_machine.c:584 ( sofia/internalopus/2223@sip.example.com) Running State Change CS_NEW (Cur 2 Tot 3196652) 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:9828 sofia/internalopus/2223@sip.example.com receiving invite from 192.168.100.2:5060 version: 1.6.16 git 3da6bd0 2017-04-07 16:49:13Z 64bit 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com entering state [received][100] 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:7058 Remote SDP: v=0 o=- 8070049943 45777 IN IP4 192.168.100.2 s=dvjtiwu c=IN IP4 192.168.100.2 t=0 0 m=audio 10036 RTP/AVP 103 8 0 9 101 a=rtpmap:103 opus/48000/2 a=fmtp:103 maxplaybackrate=8000;maxaveragebitrate=15500;useinbandfec=1;usedtx=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=nortpproxy:yes . . . . . 2017-09-25 22:01:06.337394 [INFO] mod_dialplan_xml.c:637 Processing 2223 <2223>->*71 in context default Dialplan: sofia/internalopus/2223@sip.example.com parsing [default->echo] continue=false Dialplan: sofia/internalopus/2223@sip.example.com Regex (PASS) [echo] destination_number(*71) =~ /^\*71$/ break=on-false Dialplan: sofia/internalopus/2223@sip.example.com Action answer() Dialplan: sofia/internalopus/2223@sip.example.com Action echo() 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:286 ( sofia/internalopus/2223@sip.example.com) State Change CS_ROUTING -> CS_EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:643 ( sofia/internalopus/2223@sip.example.com) State ROUTING going to sleep 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:584 ( sofia/internalopus/2223@sip.example.com) Running State Change CS_EXECUTE (Cur 2 Tot 3196652) 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:650 ( sofia/internalopus/2223@sip.example.com) State EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] mod_sofia.c:198 sofia/internalopus/2223@sip.example.com SOFIA EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:328 sofia/internalopus/2223@sip.example.com Standard EXECUTE EXECUTE sofia/internalopus/2223@sip.example.com answer() 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:3049 Set Codec sofia/internalopus/2223@sip.example.com opus/8000 20 ms 960 samples 0 bits 1 channels 2017-09-25 22:01:06.357410 [DEBUG] switch_core_codec.c:111 sofia/internalopus/2223@sip.example.com Original read codec set to opus:116 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4747 sofia/internalopus/2223@sip.example.com Set 2833 dtmf send payload to 101 recv payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:6803 AUDIO RTP [ sofia/internalopus/2223@sip.example.com] 192.168.100.12 port 23594 -> 192.168.100.2 port 10036 codec: 103 ms: 20 2017-09-25 22:01:06.357410 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 960 bytes per 20ms 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7109 sofia/internalopus/2223@sip.example.com Set 2833 dtmf send payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7116 sofia/internalopus/2223@sip.example.com Set 2833 dtmf receive payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7139 sofia/internalopus/2223@sip.example.com Set rtp dtmf delay to 40 2017-09-25 22:01:06.357410 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internalopus/2223@sip.example.com! 2017-09-25 22:01:06.357410 [DEBUG] switch_channel.c:3473 ( sofia/internalopus/2223@sip.example.com) Callstate Change RINGING -> EARLY 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:6786 Audio params are unchanged for sofia/internalopus/2223@sip.example.com.
2017-09-25 22:01:06.357410 [DEBUG] mod_sofia.c:850 Local SDP sofia/internalopus/2223@sip.example.com: v=0 o=FreeSWITCH 1506342472 1506342473 IN IP4 192.168.100.12 s=FreeSWITCH c=IN IP4 192.168.100.12 t=0 0 m=audio 23594 RTP/AVP 103 101 a=rtpmap:103 opus/48000/2 a=fmtp:103 useinbandfec=1; usedtx=1; maxaveragebitrate=14400; maxplaybackrate=8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv
2017-09-25 22:01:06.357410 [NOTICE] mod_dptools.c:1312 Channel [ sofia/internalopus/2223@sip.example.com] has been answered 2017-09-25 22:01:06.357410 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com entering state [completed][200] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media_bug.c:828 Attaching BUG to sofia/internalopus/2223@sip.example.com 2017-09-25 22:01:06.357410 [DEBUG] switch_channel.c:3772 ( sofia/internalopus/2223@sip.example.com) Callstate Change EARLY -> ACTIVE EXECUTE sofia/internalopus/2223@sip.example.com echo() 2017-09-25 22:01:06.737463 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com entering state [ready][200] 2017-09-25 22:01:06.837459 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed. 2017-09-25 22:01:06.837459 [DEBUG] switch_core_io.c:448 Setting BUG Codec opus:116 2017-09-25 22:01:06.837459 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.837459 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.837459 [DEBUG] switch_core_io.c:780 Engaging Read Buffer at 320 bytes vs 15 [...CREEPY VOICE STARTS HERE AND ENDS WITH THE BELOW MESSAGE...] 2017-09-25 22:01:16.017463 [DEBUG] switch_core_media_bug.c:1198 Removing BUG from sofia/internalopus/2223@sip.example.com
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.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
Michael, Thank you for your reply. I have removed that directive and it is still the same. In fact I started with the example config at https://freeswitch.org/confluence/display/FREESWITCH/FreeSWITCH+And+The+Opus... <https://freeswitch.org/confluence/display/FREESWITCH/FreeSWITCH+And+The+Opus+Audio+Codec> and I tried different directives like asymmetric sample rate which may effect this issue. Right now my current config is the same as the reference document, but the issue persists. <configuration name="opus.conf"> <settings> <param name="use-vbr" value="1"/> <param name="use-dtx" value="0"/> <param name="complexity" value="10"/> <param name="maxaveragebitrate" value="14400"/> <param name="maxplaybackrate" value="8000"/> <param name="packet-loss-percent" value="15"/> <param name="keep-fec-enabled" value="1"/> <param name="use-jb-lookahead" value="1"/> <param name="advertise-useinbandfec" value="1"/> </settings> </configuration> /Volkan
On 25 Sep 2017, at 22:35, Michael Jerris <mike@jerris.com> wrote:
This is due to an incomplete implementation of the asymmetric sample rate feature. It should work fine without that setting.
On Mon, Sep 25, 2017 at 2:22 PM Volkan Oransoy <voransoy@gmail.com <mailto:voransoy@gmail.com>> wrote: Hi All,
I am trying to transcode between OPUS and G711. I encountered a strange problem which I couldn’t find any clue about the cause. After the channel has been answered with opus, I hear a strange sound (highly distorted version of my voice) for 10 seconds and it starts to operate properly with the message "[DEBUG] switch_core_media_bug.c:1198 Removing BUG from…” . I can reproduce same problem with echo application. Here is my logs and opus.conf.xml files. Did anybody experienced this issue?
Thanks.
/Volkan
My FreeSWITH Version: FreeSWITCH Version 1.6.16+git~20170407T164913Z~3da6bd0108~64bit (git 3da6bd0 2017-04-07 16:49:13Z 64bit)
Opus.xml config: <configuration name="opus.conf"> <settings> <param name="use-vbr" value="1"/> <param name="use-dtx" value="1"/> <param name="complexity" value="10"/> <param name="maxaveragebitrate" value="14400"/> <param name="maxplaybackrate" value="8000"/> <param name="packet-loss-percent" value="15"/> <param name="keep-fec-enabled" value="1"/> <param name="use-jb-lookahead" value="0"/> <param name="advertise-useinbandfec" value="1"/> <param name="asymmetric-sample-rates" value="1"/> </settings> </configuration>
Freeswitch Log: 2017-09-25 22:01:06.277462 [NOTICE] switch_channel.c:1104 New Channel sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> [1048c869-8d71-41fd-b0b7-f8fbd01a0d93] 2017-09-25 22:01:06.277462 [DEBUG] switch_core_state_machine.c:584 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) Running State Change CS_NEW (Cur 2 Tot 3196652) 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:9828 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> receiving invite from 192.168.100.2:5060 <http://192.168.100.2:5060/> version: 1.6.16 git 3da6bd0 2017-04-07 16:49:13Z 64bit 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> entering state [received][100] 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:7058 Remote SDP: v=0 o=- 8070049943 45777 IN IP4 192.168.100.2 s=dvjtiwu c=IN IP4 192.168.100.2 t=0 0 m=audio 10036 RTP/AVP 103 8 0 9 101 a=rtpmap:103 opus/48000/2 a=fmtp:103 maxplaybackrate=8000;maxaveragebitrate=15500;useinbandfec=1;usedtx=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=nortpproxy:yes . . . . . 2017-09-25 22:01:06.337394 [INFO] mod_dialplan_xml.c:637 Processing 2223 <2223>->*71 in context default Dialplan: sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> parsing [default->echo] continue=false Dialplan: sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Regex (PASS) [echo] destination_number(*71) =~ /^\*71$/ break=on-false Dialplan: sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Action answer() Dialplan: sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Action echo() 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:286 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) State Change CS_ROUTING -> CS_EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:643 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) State ROUTING going to sleep 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:584 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) Running State Change CS_EXECUTE (Cur 2 Tot 3196652) 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:650 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) State EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] mod_sofia.c:198 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> SOFIA EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:328 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Standard EXECUTE EXECUTE sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> answer() 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:3049 Set Codec sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> opus/8000 20 ms 960 samples 0 bits 1 channels 2017-09-25 22:01:06.357410 [DEBUG] switch_core_codec.c:111 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Original read codec set to opus:116 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4747 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Set 2833 dtmf send payload to 101 recv payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>] 192.168.100.12 port 23594 -> 192.168.100.2 port 10036 codec: 103 ms: 20 2017-09-25 22:01:06.357410 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 960 bytes per 20ms 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7109 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Set 2833 dtmf send payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7116 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Set 2833 dtmf receive payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7139 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Set rtp dtmf delay to 40 2017-09-25 22:01:06.357410 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>! 2017-09-25 22:01:06.357410 [DEBUG] switch_channel.c:3473 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) Callstate Change RINGING -> EARLY 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:6786 Audio params are unchanged for sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>.
2017-09-25 22:01:06.357410 [DEBUG] mod_sofia.c:850 Local SDP sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>: v=0 o=FreeSWITCH 1506342472 1506342473 IN IP4 192.168.100.12 s=FreeSWITCH c=IN IP4 192.168.100.12 t=0 0 m=audio 23594 RTP/AVP 103 101 a=rtpmap:103 opus/48000/2 a=fmtp:103 useinbandfec=1; usedtx=1; maxaveragebitrate=14400; maxplaybackrate=8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv
2017-09-25 22:01:06.357410 [NOTICE] mod_dptools.c:1312 Channel [sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>] has been answered 2017-09-25 22:01:06.357410 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> entering state [completed][200] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media_bug.c:828 Attaching BUG to sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> 2017-09-25 22:01:06.357410 [DEBUG] switch_channel.c:3772 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) Callstate Change EARLY -> ACTIVE EXECUTE sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> echo() 2017-09-25 22:01:06.737463 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> entering state [ready][200] 2017-09-25 22:01:06.837459 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed. 2017-09-25 22:01:06.837459 [DEBUG] switch_core_io.c:448 Setting BUG Codec opus:116 2017-09-25 22:01:06.837459 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.837459 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.837459 [DEBUG] switch_core_io.c:780 Engaging Read Buffer at 320 bytes vs 15 [...CREEPY VOICE STARTS HERE AND ENDS WITH THE BELOW MESSAGE...] 2017-09-25 22:01:16.017463 [DEBUG] switch_core_media_bug.c:1198 Removing BUG from sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org <mailto:consulting@freeswitch.org> http://www.freeswitchsolutions.com <http://www.freeswitchsolutions.com/>
Official FreeSWITCH Sites http://www.freeswitch.org <http://www.freeswitch.org/> http://confluence.freeswitch.org <http://confluence.freeswitch.org/> http://www.cluecon.com <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 <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users <http://lists.freeswitch.org/mailman/options/freeswitch-users> http://www.freeswitch.org <http://www.freeswitch.org/>_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.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
Hi, I have solved the issue. It is caused by the variable I set before execute_on_answer=spandsp_start_fax_detect transfer '*11 XML default’ 10 Somehow the bug placed by this directive effects the decoder when the codec is opus. When 10 seconds expire, it turns back to normal. Thanks, /Volkan
On 25 Sep 2017, at 22:46, Volkan Oransoy <voransoy@gmail.com> wrote:
Michael,
Thank you for your reply. I have removed that directive and it is still the same.
In fact I started with the example config at https://freeswitch.org/confluence/display/FREESWITCH/FreeSWITCH+And+The+Opus... <https://freeswitch.org/confluence/display/FREESWITCH/FreeSWITCH+And+The+Opus+Audio+Codec> and I tried different directives like asymmetric sample rate which may effect this issue. Right now my current config is the same as the reference document, but the issue persists.
<configuration name="opus.conf"> <settings> <param name="use-vbr" value="1"/> <param name="use-dtx" value="0"/> <param name="complexity" value="10"/> <param name="maxaveragebitrate" value="14400"/> <param name="maxplaybackrate" value="8000"/> <param name="packet-loss-percent" value="15"/> <param name="keep-fec-enabled" value="1"/> <param name="use-jb-lookahead" value="1"/> <param name="advertise-useinbandfec" value="1"/> </settings> </configuration>
/Volkan
On 25 Sep 2017, at 22:35, Michael Jerris <mike@jerris.com <mailto:mike@jerris.com>> wrote:
This is due to an incomplete implementation of the asymmetric sample rate feature. It should work fine without that setting.
On Mon, Sep 25, 2017 at 2:22 PM Volkan Oransoy <voransoy@gmail.com <mailto:voransoy@gmail.com>> wrote: Hi All,
I am trying to transcode between OPUS and G711. I encountered a strange problem which I couldn’t find any clue about the cause. After the channel has been answered with opus, I hear a strange sound (highly distorted version of my voice) for 10 seconds and it starts to operate properly with the message "[DEBUG] switch_core_media_bug.c:1198 Removing BUG from…” . I can reproduce same problem with echo application. Here is my logs and opus.conf.xml files. Did anybody experienced this issue?
Thanks.
/Volkan
My FreeSWITH Version: FreeSWITCH Version 1.6.16+git~20170407T164913Z~3da6bd0108~64bit (git 3da6bd0 2017-04-07 16:49:13Z 64bit)
Opus.xml config: <configuration name="opus.conf"> <settings> <param name="use-vbr" value="1"/> <param name="use-dtx" value="1"/> <param name="complexity" value="10"/> <param name="maxaveragebitrate" value="14400"/> <param name="maxplaybackrate" value="8000"/> <param name="packet-loss-percent" value="15"/> <param name="keep-fec-enabled" value="1"/> <param name="use-jb-lookahead" value="0"/> <param name="advertise-useinbandfec" value="1"/> <param name="asymmetric-sample-rates" value="1"/> </settings> </configuration>
Freeswitch Log: 2017-09-25 22:01:06.277462 [NOTICE] switch_channel.c:1104 New Channel sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> [1048c869-8d71-41fd-b0b7-f8fbd01a0d93] 2017-09-25 22:01:06.277462 [DEBUG] switch_core_state_machine.c:584 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) Running State Change CS_NEW (Cur 2 Tot 3196652) 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:9828 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> receiving invite from 192.168.100.2:5060 <http://192.168.100.2:5060/> version: 1.6.16 git 3da6bd0 2017-04-07 16:49:13Z 64bit 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> entering state [received][100] 2017-09-25 22:01:06.277462 [DEBUG] sofia.c:7058 Remote SDP: v=0 o=- 8070049943 45777 IN IP4 192.168.100.2 s=dvjtiwu c=IN IP4 192.168.100.2 t=0 0 m=audio 10036 RTP/AVP 103 8 0 9 101 a=rtpmap:103 opus/48000/2 a=fmtp:103 maxplaybackrate=8000;maxaveragebitrate=15500;useinbandfec=1;usedtx=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=nortpproxy:yes . . . . . 2017-09-25 22:01:06.337394 [INFO] mod_dialplan_xml.c:637 Processing 2223 <2223>->*71 in context default Dialplan: sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> parsing [default->echo] continue=false Dialplan: sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Regex (PASS) [echo] destination_number(*71) =~ /^\*71$/ break=on-false Dialplan: sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Action answer() Dialplan: sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Action echo() 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:286 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) State Change CS_ROUTING -> CS_EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:643 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) State ROUTING going to sleep 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:584 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) Running State Change CS_EXECUTE (Cur 2 Tot 3196652) 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:650 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) State EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] mod_sofia.c:198 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> SOFIA EXECUTE 2017-09-25 22:01:06.357410 [DEBUG] switch_core_state_machine.c:328 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Standard EXECUTE EXECUTE sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> answer() 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [opus:103:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.357410 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:3049 Set Codec sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> opus/8000 20 ms 960 samples 0 bits 1 channels 2017-09-25 22:01:06.357410 [DEBUG] switch_core_codec.c:111 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Original read codec set to opus:116 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:4747 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Set 2833 dtmf send payload to 101 recv payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>] 192.168.100.12 port 23594 -> 192.168.100.2 port 10036 codec: 103 ms: 20 2017-09-25 22:01:06.357410 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 960 bytes per 20ms 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7109 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Set 2833 dtmf send payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7116 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Set 2833 dtmf receive payload to 101 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:7139 sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> Set rtp dtmf delay to 40 2017-09-25 22:01:06.357410 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>! 2017-09-25 22:01:06.357410 [DEBUG] switch_channel.c:3473 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) Callstate Change RINGING -> EARLY 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media.c:6786 Audio params are unchanged for sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>.
2017-09-25 22:01:06.357410 [DEBUG] mod_sofia.c:850 Local SDP sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>: v=0 o=FreeSWITCH 1506342472 1506342473 IN IP4 192.168.100.12 s=FreeSWITCH c=IN IP4 192.168.100.12 t=0 0 m=audio 23594 RTP/AVP 103 101 a=rtpmap:103 opus/48000/2 a=fmtp:103 useinbandfec=1; usedtx=1; maxaveragebitrate=14400; maxplaybackrate=8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv
2017-09-25 22:01:06.357410 [NOTICE] mod_dptools.c:1312 Channel [sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>] has been answered 2017-09-25 22:01:06.357410 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> entering state [completed][200] 2017-09-25 22:01:06.357410 [DEBUG] switch_core_media_bug.c:828 Attaching BUG to sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> 2017-09-25 22:01:06.357410 [DEBUG] switch_channel.c:3772 (sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>) Callstate Change EARLY -> ACTIVE EXECUTE sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> echo() 2017-09-25 22:01:06.737463 [DEBUG] sofia.c:7048 Channel sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com> entering state [ready][200] 2017-09-25 22:01:06.837459 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed. 2017-09-25 22:01:06.837459 [DEBUG] switch_core_io.c:448 Setting BUG Codec opus:116 2017-09-25 22:01:06.837459 [DEBUG] mod_opus.c:596 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [14400bps] 2017-09-25 22:01:06.837459 [DEBUG] mod_opus.c:613 Opus encoder: set audio bandwidth to [NARROWBAND] based on maxplaybackrate value found in SDP or local config [8000Hz] 2017-09-25 22:01:06.837459 [DEBUG] switch_core_io.c:780 Engaging Read Buffer at 320 bytes vs 15 [...CREEPY VOICE STARTS HERE AND ENDS WITH THE BELOW MESSAGE...] 2017-09-25 22:01:16.017463 [DEBUG] switch_core_media_bug.c:1198 Removing BUG from sofia/internalopus/2223@sip.example.com <mailto:sofia/internalopus/2223@sip.example.com>
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org <mailto:consulting@freeswitch.org> http://www.freeswitchsolutions.com <http://www.freeswitchsolutions.com/>
Official FreeSWITCH Sites http://www.freeswitch.org <http://www.freeswitch.org/> http://confluence.freeswitch.org <http://confluence.freeswitch.org/> http://www.cluecon.com <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 <http://lists.freeswitch.org/mailman/listinfo/freeswitch-users> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users <http://lists.freeswitch.org/mailman/options/freeswitch-users> http://www.freeswitch.org <http://www.freeswitch.org/>_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org <mailto:consulting@freeswitch.org> http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.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
participants (2)
-
Michael Jerris
-
Volkan Oransoy