[Freeswitch-users] Opus Codec Error

David Shemesh david at kaymera.com
Thu Nov 20 11:23:16 MSK 2014 

Hope someone can help with this:
I am experiencing a strange issue using Opus.
The call is from a registered client to a landline through a sip Trunk. 
Freeswitch is transcoding From Opus to PCMU and after about ~1min the 
call drops with "switch_core_io.c:1282 Codec OPUS (STANDARD) decoder 
error!" and the call gets disconnected.
It looks like this happens only when i enabling the jitterbuffer.
I was able to reproduce this using various Clients (Csipsimple, Jitsi) & 
Sip trunks. it seems like its has something to do with freeswitch's 
implementation of OPUS.

FreeSWITCH Version 1.5.15b+git~20141112T004420Z~dd629c1516~64bit

Dialplan:

<extension name="out" >
    <condition field="destination_number" expression="^9(\d+)$" >
        <action application="set" 
data="rtp_jitter_buffer_during_bridge=true" />
        <action application="set" data="rtp_jitter_buffer_plc=true" />
        <action application="set" data="jitterbuffer_msec=60:200:20" />
        <action application="set" data="call_direction=outbound" />
        <action application="set" data="hangup_after_bridge=true" />
        <action application="set" 
data="effective_caller_id_name=${outbound_caller_id_name}" />
        <action application="set" 
data="effective_caller_id_number=${outbound_caller_id_number}" />
        <action application="set" data="inherit_codec=true" />
        <action application="set" data="continue_on_fail=true" />
        <action application="bridge" data="sofia/gateway/out01/$1" />
        <action application="bridge" data="sofia/gateway/ou02/$1" />
    </condition>
</extension>

Freeswitch Log:

2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3389 Audio Codec 
Compare [PCMU:0:8000:10:64000]/[opus:116:48000:20:0]
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3389 Audio Codec 
Compare [PCMU:0:8000:10:64000]/[PCMU:0:8000:20:64000]
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3424 Audio Codec 
Compare [PCMU:0:8000:20:64000] is saved as a near-match
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3389 Audio Codec 
Compare [PCMU:0:8000:10:64000]/[GSM:3:8000:20:13200]
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3389 Audio Codec 
Compare [PCMU:0:8000:10:64000]/[PCMA:8:8000:20:64000]
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3389 Audio Codec 
Compare [PCMU:0:8000:10:64000]/[G722:9:8000:20:64000]
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3389 Audio Codec 
Compare [PCMU:0:8000:10:64000]/[AMR:96:8000:20:12200]
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3389 Audio Codec 
Compare [PCMU:0:8000:10:64000]/[iLBC:97:8000:30:13330]
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3389 Audio Codec 
Compare [PCMU:0:8000:10:64000]/[SPEEX:99:8000:20:24600]
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3389 Audio Codec 
Compare [PCMU:0:8000:10:64000]/[SPEEX:99:16000:20:42200]
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3389 Audio Codec 
Compare [PCMU:0:8000:10:64000]/[SPEEX:99:32000:20:44000]
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3315 Set 
telephone-event payload to 101
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3494 Substituting 
codec PCMU at 10i@8000h
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:2343 Set Codec 
sofia/external/123456789 PCMU/8000 10 ms 80 samples 64000 bits
2014-11-18 10:51:25.876680 [DEBUG] switch_core_codec.c:111 
sofia/external/123456789 Original read codec set to PCMU:0
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:3623 Set 2833 
dtmf send payload to 101
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:4847 AUDIO RTP 
[sofia/external/123456789] 10.0.50.160 port 23644 -> 212.179.176.54 port 
60036 codec: 0 ms: 10
2014-11-18 10:51:25.876680 [DEBUG] switch_rtp.c:3334 Starting timer 
[soft] 80 bytes per 10ms
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:5194 Set 2833 
dtmf send payload to 101
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:5200 Set 2833 
dtmf receive payload to 101
2014-11-18 10:51:25.876680 [DEBUG] switch_core_media.c:5228 Set comfort 
noise payload to 13
2014-11-18 10:51:25.876680 [NOTICE] sofia_media.c:92 Pre-Answer 
sofia/external/123456789!
2014-11-18 10:51:25.876680 [DEBUG] switch_channel.c:3389 Send signal 
sofia/internal/1000 at 192.168.10.150 [BREAK]
2014-11-18 10:51:25.876680 [DEBUG] switch_channel.c:3393 
(sofia/external/123456789) Callstate Change RINGING -> EARLY
2014-11-18 10:51:25.896682 [DEBUG] switch_core_codec.c:246 
sofia/internal/1000 at 192.168.10.150 Restore previous codec opus:116.
2014-11-18 10:51:25.896682 [DEBUG] switch_ivr_originate.c:3551 Originate 
Resulted in Success: [sofia/external/123456789]
2014-11-18 10:51:25.896682 [DEBUG] switch_core_session.c:907 Send signal 
sofia/external/123456789 [BREAK]
2014-11-18 10:51:25.896682 [DEBUG] switch_core_session.c:907 Send signal 
sofia/internal/1000 at 192.168.10.150 [BREAK]
2014-11-18 10:51:25.896682 [DEBUG] switch_ivr_bridge.c:1460 
(sofia/external/123456789) State Change CS_CONSUME_MEDIA -> 
CS_EXCHANGE_MEDIA
2014-11-18 10:51:25.896682 [DEBUG] switch_core_session.c:1387 Send 
signal sofia/external/123456789 [BREAK]
2014-11-18 10:51:25.896682 [DEBUG] switch_core_state_machine.c:467 
(sofia/external/123456789) Running State Change CS_EXCHANGE_MEDIA
2014-11-18 10:51:25.896682 [DEBUG] switch_core_state_machine.c:533 
(sofia/external/123456789) State EXCHANGE_MEDIA
2014-11-18 10:51:25.896682 [DEBUG] mod_sofia.c:592 SOFIA EXCHANGE_MEDIA
2014-11-18 10:51:26.056685 [DEBUG] switch_rtp.c:5555 Correct ip/port 
confirmed.
2014-11-18 10:51:26.056685 [NOTICE] switch_core_io.c:1230 Activating 
write resampler
2014-11-18 10:51:26.056685 [DEBUG] switch_core_io.c:1458 Engaging Write 
Buffer at 160 bytes to accommodate 320->160
2014-11-18 10:51:26.136684 [ERR] switch_core_io.c:1282 Codec OPUS 
(STANDARD) decoder error!
2014-11-18 10:51:26.136684 [DEBUG] switch_ivr_bridge.c:578 
sofia/external/123456789 ending bridge by request from write function
2014-11-18 10:51:26.136684 [DEBUG] switch_ivr_bridge.c:659 BRIDGE THREAD 
DONE [sofia/internal/1000 at 192.168.10.150]
2014-11-18 10:51:26.136684 [DEBUG] switch_ivr_bridge.c:689 Send signal 
sofia/external/123456789 [BREAK]
2014-11-18 10:51:26.136684 [DEBUG] switch_ivr_bridge.c:659 BRIDGE THREAD 
DONE [sofia/external/123456789]
2014-11-18 10:51:26.136684 [DEBUG] switch_ivr_bridge.c:689 Send signal 
sofia/internal/1000 at 192.168.10.150 [BREAK]
2014-11-18 10:51:26.136684 [NOTICE] switch_ivr_bridge.c:751 Hangup 
sofia/external/123456789 [CS_EXCHANGE_MEDIA] [ORIGINATOR_CANCEL]
2014-11-18 10:51:26.136684 [DEBUG] switch_channel.c:3215 Send signal 
sofia/external/123456789 [KILL]
2014-11-18 10:51:26.136684 [DEBUG] switch_core_session.c:1387 Send 
signal sofia/external/123456789 [BREAK]
2014-11-18 10:51:26.136684 [DEBUG] switch_core_state_machine.c:533 
(sofia/external/123456789) State EXCHANGE_MEDIA going to sleep
2014-11-18 10:51:26.136684 [DEBUG] switch_core_state_machine.c:467 
(sofia/external/123456789) Running State Change CS_HANGUP
2014-11-18 10:51:26.136684 [DEBUG] switch_core_state_machine.c:730 
(sofia/external/123456789) Callstate Change EARLY -> HANGUP
2014-11-18 10:51:26.136684 [DEBUG] switch_core_state_machine.c:732 
(sofia/external/123456789) State HANGUP
2014-11-18 10:51:26.136684 [DEBUG] mod_sofia.c:413 Channel 
sofia/external/123456789 hanging up, cause: ORIGINATOR_CANCEL

Anyone have any idea whats going on ?

Thanks
David

Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users mailing list