GNOME Bugzilla – Bug 771723
opusdec: too short buffers trigger error instead of PLC
Last modified: 2016-12-05 09:12:04 UTC
I am using opusenc/opusdec to send audio over RTP (via rtpbin) over network that tends to periodically drop packets. I've noticed that receiver from time to time raises error on the bus, from opusdec saying that "buffer is too small". Instead it should drop the buffer and let PLC do it's job but should not stop playback and raise an error.
Can you share the particular settings for opusenc/opusdec etc that might have an influence on packet size ?
Created attachment 335940 [details] [review] possible fix Alternatively, does this work (RTP with dropped packets works for me with and without the patch).
I generally speaking use opusenc with dtx=true inband-fec=true rest of settings is default. Opusdec with use-inband-fec=true plc=true apply-gain=false. rtpjitterbuffer (or rather rtpbin that builds one) has do-lost=true do-retransmission=true drop-on-latency=true. I have been changing rtpjitterbuffer latency and opusenc bitrate (in range 64-128kbit/s) and it seems that this does not affect the issue - such error still happens from time to time. I have been using simple pipelines such as (some source) ! ... ! opusenc ! rtpopuspay ! udpsink and udpsrc ! rtpjitterbuffer ! rtpopusdepay ! opusdec ! ... ! (some sink) and rtpbin with retransmission enabled and it happens from time to time in both cases. It is really hard to reproduce as it hapens rarely and I am unable to log full GST_DEBUG=... in this environment (it's production machine).
By the way, I was testing something different, and I got the following log: 0:00:33.733337000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:33.733879000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:33.756563000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:33.756632000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:33.757103000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:33.860996000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:33.861064000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:33.861540000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:33.872584000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:33.872644000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:33.873165000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:33.895807000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:33.895856000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:33.896260000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:33.918871000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:33.918925000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:33.919305000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:33.942252000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:33.942314000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:33.942806000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:33.953652000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:33.953702000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:33.954129000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:33.976910000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:33.976957000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:33.977272000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.000164000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.000211000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.000497000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.023519000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.023583000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.024066000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.034989000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.035057000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.035554000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.058346000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.058405000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.058919000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.116410000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.116462000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.116892000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples [2016-09-20 17:32:42.715] Warning: lost 4 packets 0:00:34.139606000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.139665000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.140204000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.162856000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.162940000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.163456000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.174294000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.174357000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.174814000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.197518000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.197569000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.197946000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.220820000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.220883000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.221373000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.232494000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.232556000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.233040000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.255619000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.255674000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.256059000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.278929000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.278973000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.279247000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.302297000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.302361000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.302929000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.313715000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.313781000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.314187000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.336959000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.337015000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.337424000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.360290000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.360359000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.360861000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.383512000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.383580000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.384046000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.394993000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.395041000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.395389000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.418305000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.418356000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.418783000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.441419000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.441461000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.441733000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.453026000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.453093000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.453699000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.476258000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.476315000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.476698000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.499563000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.499627000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.500108000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.522743000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.522798000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.523216000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.534271000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.534339000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.534875000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.557489000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.557537000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.557918000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.615488000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.615543000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.615923000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.673540000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.673595000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.674027000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples [2016-09-20 17:32:43.266] Sender 1930162613 timeout 0:00:34.743303000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.743376000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.743858000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.754824000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.754869000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.755293000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.778001000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.778054000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.778417000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.801312000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.801371000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.801883000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.812957000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.813021000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.813511000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.836014000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 0 0:00:34.836076000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.836452000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.859423000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.859484000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.859517000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:498:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> missing buffer, doing PLC duration 0:00:00.020117273 plus leftover 5124095:34:33.708972107 0:00:34.859566000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:531:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> calculated PLC frame length: 0:00:00.020000000 num frame samples: 960 new leftover: 5124095:34:33.709089380 0:00:34.860108000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.882623000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.882681000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.883199000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.894117000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 0 0:00:34.894165000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.894529000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:34.917359000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:34.917410000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:34.917436000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:498:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> missing buffer, doing PLC duration 0:00:00.020829305 plus leftover 5124095:34:33.709089380 0:00:34.917474000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:531:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> calculated PLC frame length: 0:00:00.020000000 num frame samples: 960 new leftover: 0:00:00.000367069 0:00:34.917756000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:35.022117000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.022179000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.022536000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:35.080035000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.080099000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.080575000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:35.103160000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.103224000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.103796000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples [2016-09-20 17:32:43.716] Warning: lost 4 packets 0:00:35.172883000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.172958000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.173467000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples [2016-09-20 17:32:43.770] Sender 3026407810 timeout 0:00:35.196000000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.196050000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.196343000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:35.219095000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.219137000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.219405000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:35.242342000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.242388000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.242658000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:35.253955000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.253997000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.254261000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:35.277169000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.277212000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.277482000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:35.335220000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.335267000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.335552000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:35.358420000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 0 0:00:35.358461000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.358757000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:576:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> decoded 960 samples 0:00:35.381802000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:456:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Received buffer of size 327 0:00:35.381875000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:482:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> Using buffer of size 327 0:00:35.381909000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:498:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> missing buffer, doing PLC duration 0:00:00.018488400 plus leftover 0:00:00.000367069 0:00:35.381956000 96148 0x7fac930135e0 DEBUG opusdec gstopusdec.c:531:GstFlowReturn opus_dec_chain_parse_data(GstOpusDec *, GstBuffer *):<decoder> calculated PLC frame length: 0:00:00.020000000 num frame samples: 960 new leftover: 5124095:34:33.708407085 Leftover duration in the last entry looks suspicious.
Created attachment 336220 [details] pcap file showing the buffer too small error To reproduce the bug please run the following pipeline with the attached pcap file. Tested with 1.8.2 on Ubuntu 16.04 gst-launch-1.0 -v rtpbin do-lost=1 name=rtpbin filesrc location=bug-771723.pcap ! pcapparse dst-port=5000 ! identity sync=1 ! "application/x-rtp, payload=111, clock-rate=48000, media=audio, encoding-name=OPUS" ! rtpbin.recv_rtp_sink_0 rtpbin. ! rtpopusdepay ! opusdec plc=1 use-inband-fec=1 ! audioconvert ! audioresample ! audiorate ! voaacenc ! aacparse ! mp4mux ! filesink location=test.mp4
Created attachment 336255 [details] [review] fix "buffer too small" error Thanks for the repro. This patch fixes that test case.
The new patch fixes the error for me. Thank you.
I'm getting no audio in another pcap file. Probably when fec kicks in. Tested with the patch when both plc and fec are enabled. I'm going to disable use-inband-fec in my app for now.
Created attachment 336304 [details] Stream cut when using use-inband-fec Not sure if this should be a separate bug. When I run the pipeline with fec disabled I'm getting 8 seconds audio. You can hear sound at the beginning and at the end with silence in between. This is the expected result. gst-launch-1.0 -v rtpbin do-lost=1 name=rtpbin filesrc location=bug-771723-b.pcap ! pcapparse dst-port=5000 ! identity sync=1 ! "application/x-rtp, payload=111, clock-rate=48000, media=audio, encoding-name=OPUS" ! rtpbin.recv_rtp_sink_0 rtpbin. ! rtpopusdepay ! opusdec plc=1 use-inband-fec=0 ! audioconvert ! audioresample ! audiorate ! voaacenc ! aacparse ! mp4mux ! filesink location=test-no-fec.mp4 When I run the pipeline with use-inband-fec=1 the audio file ends after 3 seconds. gst-launch-1.0 -v rtpbin do-lost=1 name=rtpbin filesrc location=bug-771723-b.pcap ! pcapparse dst-port=5000 ! identity sync=1 ! "application/x-rtp, payload=111, clock-rate=48000, media=audio, encoding-name=OPUS" ! rtpbin.recv_rtp_sink_0 rtpbin. ! rtpopusdepay ! opusdec plc=1 use-inband-fec=1 ! audioconvert ! audioresample ! audiorate ! voaacenc ! aacparse ! mp4mux ! filesink location=test-fec.mp4
Created attachment 337060 [details] [review] interpret zero duration as unknown This fixes that second problem, which turned out to be unrelated.
Tested the new patch with the pcap and now I'm getting 8 seconds with use-inband-fec=1 as expected. Thanks
Why didn't you push these fixes? Is there anything still missing, any known problems? How risky are they, what is the worst thing they could cause? AFAIU these code paths only happen when packets are actually lost?
I was waiting for an review/OK :) No known problems, and it happens only on loss, yes. I think worst case is too much allocated for the buffer, but that's not very large (100k for 8 channel at 48 kHz it seems).
Can you confirm whether that comment means ok to push now, even though frozen ? :)
Now it's 4 days later, after freeze then for 1.10.1.
commit b0866b9cc1441cbdd95c599f88d2574b3dfd5b7d Author: Vincent Penquerc'h <vincent.penquerch@collabora.co.uk> Date: Thu Oct 6 11:44:11 2016 +0100 opusdec: interpret zero duration as unknown This fixes missing audio when we get buffers with zero duration, denoting unknown duration. When several such buffers are received in a row, they're all at the same timestamp, with zero duration. https://bugzilla.gnome.org/show_bug.cgi?id=771723 commit a6ced9cbc8be263ad882a57ab22eafd33b9bcb79 Author: Vincent Penquerc'h <vincent.penquerch@collabora.co.uk> Date: Mon Sep 26 10:50:52 2016 +0100 opusdec: fix "buffer too small" error Always supply a buffer with max size to the decoder, as we can't really decide how many samples will be in the lost packet based on the timestamps we get. https://bugzilla.gnome.org/show_bug.cgi?id=771723
This breaks the unit test "opus.test_opus_decode_plc_timestamps_with_fec": 'dur * 2' (20000000) is not equal to 'GST_BUFFER_DURATION (buf)' (120000000)
The idea of the lost(gap) event is to be able to conceal a lost packet in a stream so that it is not noticeable for the listener that a packet was indeed lost. If you have a stream of packets like this: seq: 1 2 3 4 dur: 10ms 10ms 10ms 10ms ts: 0ms 10ms 20ms 30ms But instead you get this: seq: 1 ? 3 4 dur: 10ms ? 10ms 10ms ts: 0ms ? 20ms 30ms The gap event will provide you with a timestamp and a duration that you can use to fill in this gap, in our case the timestamp and duration of that gap-event would match perfectly like this: seq: 1 GAP 3 4 dur: 10ms 10ms 10ms 10ms ts: 0ms 10ms 20ms 30ms Now the "opusdec: fix "buffer too small" error" will always overwrite the calculated samples based on the gap-duration, and replace it with 120ms, like so: seq: 1 GAP 3 4 dur: 10ms 120ms 10ms 10ms ts: 0ms 10ms 130ms 140ms And that will end up both producing a lot of silence in the middle of the stream, as well as skewing the timestamps for the following packets, breaking synchronization. Probably not a good idea?
This max size is meant to be the buffer passed to the Opus decoding API, to ensure we always supply enough. It should then be set to whatever Opus returned.
But why have it create output for bigger than the gap (of which we known the duration!)?
I just didn't realize it was doing so at the time :)
So what's the fix? :)
I don't know yet, I just started looking at this when I commented :)
opusdec gets lost buffers with 17ms duration. However, all the non-lost buffers it gets are 20ms. Something is getting 17ms duration on the empty buffers. The element before opusdec is opusrtpdepay, and logging in there shows duration is unset. So I think the culprit is somewhere in audiodecoder or audiobasedecoder. When getting these 17ms buffers, sometimes the "aligned" missing duration (aligned to the minimum 2.5ms that Opus supports) will end up lower than the FEC data, and Opus errors out.
The last time I looked at libopus I remember it is hidden deep in the guts of libopus and there is no way to even know if the packet contains FEC or not. I'm curious how do you know FEC is the problem and how do you get the amount of FEC data the packet contains?
You'd probably have to copy code from libopus for this. In the case here (pcap attached to this bug), the opusdec code ends up in: n = opus_multistream_decode (dec->state, data, size, out_data, samples, 1); This returns -2 (buffer too small). If there was no FEC data in there, it would probably not moan about this.
It all comes from the jitterbuffer receiving pts that are somewhat jittery, with differences a bit above 20ms (the Opus buffers are 20ms). At some point there is a gap of 34ms (one missing buffer, and the pts difference is 34). The jitterbuffer decides to cut this time in two, and sends a gap of 17ms, though the missing packet was 20ms. This is what is causing a buffer of 17ms to be sent to libopus. I don't yet know why the pts is jittery.
Looks like https://bugzilla.gnome.org/show_bug.cgi?id=772646 fixed this.
So is there a bug in opusdec now with this patch, or does it only show a new bug caused by rtpjitterbuffer? Or are there two bugs, both?
(In reply to Vincent Penquerc'h from comment #28) > Looks like https://bugzilla.gnome.org/show_bug.cgi?id=772646 fixed this. Still fails the same for me: elements/opus.c:470:F:general:test_opus_decode_plc_timestamps_with_fec:0: 'dur * 2' (20000000) is not equal to 'GST_BUFFER_DURATION (buf)' (120000000)
And of course it doesn't. I'd just stashed my debug changes which undid the fauly fix, and forgot to unstash after sync. Sigh.
I think there are two bugs: 1 - pts not straight 20ms (I guess this comes from the sending pipeline, but the test case is from a pcap file, so no logs about how these are generated, would need to set up a pipeline for this). 2 - opusdec does not cope well with that. For the second one, I'm thinking that since we don't know how much samples is in the FEC data, we could have a loop to increase the buffer size when decoding fails. Up to the 120 ms theoretical max.
I am just forced to move out from GStreamer in one of the projects because it silently increases buffer somewhere (don't know, where, despite debugging for quite a while). Please do not add another incentive.
(In reply to Vincent Penquerc'h from comment #32) > I think there are two bugs: > > 1 - pts not straight 20ms (I guess this comes from the sending pipeline, but > the test case is from a pcap file, so no logs about how these are generated, > would need to set up a pipeline for this). Check the difference in receive times between packets and the difference between RTP timestamps. And write that down to get an idea what happens here. Maybe rtpjitterbuffer behaves correct, maybe not. > 2 - opusdec does not cope well with that. > > For the second one, I'm thinking that since we don't know how much samples > is in the FEC data, we could have a loop to increase the buffer size when > decoding fails. Up to the 120 ms theoretical max. That sounds not great at all, and like a API or design problem in Opus. But what can we do (please file a bug against Opus), so let's do that I guess? However, why does Opus generate 120ms of data here if there is not that much FEC (or generally not that much data missing)? Can't we prevent Opus from generating too much output based on the gap duration information we have (and if it's by clipping the opusdec output afterwards)?
(In reply to Marcin Lewandowski from comment #33) > I am just forced to move out from GStreamer in one of the projects because > it silently increases buffer somewhere (don't know, where, despite debugging > for quite a while). Please do not add another incentive. Not constructive, better help with finding a solution to this bug and it's also not clear how this comment even relates to this bug.
This is not Opus generating 120 ms AFAICT. This is Opus having 20 ms' worth of FEC data in the next packet, but timestamps getting the jitterbuffer to think the gap is 17 ms. So opusdec makes a ~17 ms packet (quantized to 2.5 ms after added with any previous leftover), and gives that to libopus, which errors out. The fact that something somewhere ends up with a 120ms bump is something else, as the 120 size was supposed to just be a local "give max size to make sure it fits".
Created attachment 339129 [details] [review] fix tests by retrying with larger buffer if needed That fixes the test, and still works with the pcap test case.
Created attachment 339130 [details] [review] fix tests by retrying with larger buffer if needed Minus a leftover debug trace
And actually it was Opus generating 120 ms after all. I had to set samples to the return value, and it was actually returning 120 with the max size.
commit 9121131f3121466910eee5a735b2dab18cb8a7a5 Author: Vincent Penquerc'h <vincent.penquerch@collabora.co.uk> Date: Fri Nov 4 16:41:05 2016 +0000 opusdec: fix 120 ms buffers being wrongly emitted Using the max 120 ms buffer size to ensure we have enough space for decoded data meant that Opus could actually return 120 ms' worth of data. https://bugzilla.gnome.org/show_bug.cgi?id=771723