Kodi 16.1 MFC OUTPUT All buffers are queued and busy

Moderators: mdrjr, odroid

Kodi 16.1 MFC OUTPUT All buffers are queued and busy

Unread postby bpbiszkopt » Wed Sep 20, 2017 4:51 pm

Hello,

since two months i noticed that more and more videos have broken frames...firstly i throw it for downloading and missing packets...
but than i check kodi logs...and i have errors from mfc encoder and missing frame

Code: Select all
CDVDVideoCodecMFC::Decode - MFC OUTPUT All buffers are queued and busy, no space for new frame to decode. Very broken situation. Current encoded frame will be lost
CDVDVideoCodecMFC::Decode - Dropping frame with index 17.....


I was searching for similar topics but most of them are from 2014 and older....and there is now solution, or its kernel problem.

Some kodi logs:
Code: Select all
.08:32:34 T:3036712960  NOTICE: special://profile/ is mapped to: special://masterprofile/
08:32:34 T:3036712960  NOTICE: -----------------------------------------------------------------------
08:32:34 T:3036712960  NOTICE: Starting Kodi (16.1 Git:2016-07-19-84927f3). Platform: Linux ARM (Thumb) 32-bit
08:32:34 T:3036712960  NOTICE: Using Release Kodi x32 build
08:32:34 T:3036712960  NOTICE: Kodi compiled Nov 20 2016 by GCC 4.8.4 for Linux ARM (Thumb) 32-bit version 3.13.11 (199947)
08:32:34 T:3036712960  NOTICE: Running on Ubuntu 14.04.5 LTS, kernel: Linux ARM 32-bit version 3.8.13.30
08:32:34 T:3036712960  NOTICE: FFmpeg statically linked, version: 2.8.6-kodi-2.8.6-Jarvis-16.0
08:32:34 T:3036712960  NOTICE: Host CPU: ARMv7 Processor rev 0 (v7l), 4 cores available
08:32:34 T:3036712960  NOTICE: ARM Features: Neon enabled
08:32:34 T:3036712960  NOTICE: special://xbmc/ is mapped to: /usr/local/share/kodi
08:32:34 T:3036712960  NOTICE: special://xbmcbin/ is mapped to: /usr/local/lib/kodi
08:32:34 T:3036712960  NOTICE: special://masterprofile/ is mapped to: /home/odroid/.kodi/userdata
08:32:34 T:3036712960  NOTICE: special://home/ is mapped to: /home/odroid/.kodi
08:32:34 T:3036712960  NOTICE: special://temp/ is mapped to: /home/odroid/.kodi/temp
08:32:34 T:3036712960  NOTICE: The executable running is: /usr/local/lib/kodi/kodi.bin
08:32:34 T:3036712960  NOTICE: Local hostname: odroid
08:32:34 T:3036712960  NOTICE: Log File is located: /home/odroid/.kodi/temp/kodi.log
08:32:34 T:3036712960  NOTICE: -----------------------------------------------------------------------
08:32:34 T:3036712960  NOTICE: load settings...
08:32:34 T:3036712960 WARNING: CSettingInt: unknown options filler "audiocdactions" of "audiocds.autoaction"
08:32:34 T:3036712960  NOTICE: Found 1 Lists of Devices
08:32:34 T:3036712960  NOTICE: Enumerated ALSA devices:
08:32:34 T:3036712960  NOTICE:     Device 1
08:32:34 T:3036712960  NOTICE:         m_deviceName      : default
08:32:34 T:3036712960  NOTICE:         m_displayName     : Playback/recording through the PulseAudio sound server
08:32:34 T:3036712960  NOTICE:         m_displayNameExtra:
08:32:34 T:3036712960  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM
08:32:34 T:3036712960  NOTICE:         m_channels        : FL,FR,BL,BR,FC,LFE,SL,SR,UNKNOWN1,UNKNOWN2,UNKNOWN3,UNKNOWN4,UNKNOWN5,UNKNOWN6,UNKNOWN7,UNKNOWN8
08:32:34 T:3036712960  NOTICE:         m_sampleRates     : 5512,8000,11025,16000,22050,32000,44100,48000,64000,88200,96000,176400,192000
08:32:34 T:3036712960  NOTICE:         m_dataFormats     : AE_FMT_FLOAT,AE_FMT_S32NE,AE_FMT_S16NE,AE_FMT_S16LE,AE_FMT_S16BE,AE_FMT_U8
08:32:34 T:3036712960  NOTICE:     Device 2
08:32:34 T:3036712960  NOTICE:         m_deviceName      : pulse
08:32:34 T:3036712960  NOTICE:         m_displayName     : PulseAudio Sound Server
08:32:34 T:3036712960  NOTICE:         m_displayNameExtra:
08:32:34 T:3036712960  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM
08:32:34 T:3036712960  NOTICE:         m_channels        : FL,FR,BL,BR,FC,LFE,SL,SR,UNKNOWN1,UNKNOWN2,UNKNOWN3,UNKNOWN4,UNKNOWN5,UNKNOWN6,UNKNOWN7,UNKNOWN8
08:32:34 T:3036712960  NOTICE:         m_sampleRates     : 5512,8000,11025,16000,22050,32000,44100,48000,64000,88200,96000,176400,192000
08:32:34 T:3036712960  NOTICE:         m_dataFormats     : AE_FMT_FLOAT,AE_FMT_S32NE,AE_FMT_S16NE,AE_FMT_S16LE,AE_FMT_S16BE,AE_FMT_U8
08:32:34 T:3036712960  NOTICE: No settings file to load (special://xbmc/system/advancedsettings.xml)
08:32:34 T:3036712960  NOTICE: No settings file to load (special://masterprofile/advancedsettings.xml)
08:32:34 T:3036712960  NOTICE: Default DVD Player: dvdplayer
08:32:34 T:3036712960  NOTICE: Default Video Player: dvdplayer
08:32:34 T:3036712960  NOTICE: Default Audio Player: paplayer
08:32:34 T:3036712960  NOTICE: Disabled debug logging due to GUI setting. Level 0.
08:32:34 T:3036712960  NOTICE: Log level changed to "LOG_LEVEL_NORMAL"
08:32:34 T:3036712960  NOTICE: CMediaSourceSettings: loading media sources from special://masterprofile/sources.xml
08:32:34 T:3036712960  NOTICE: Loading player core factory settings from special://xbmc/system/playercorefactory.xml.
08:32:34 T:3036712960  NOTICE: Loaded playercorefactory configuration
08:32:34 T:3036712960  NOTICE: Loading player core factory settings from special://masterprofile/playercorefactory.xml.
08:32:34 T:3036712960  NOTICE: special://masterprofile/playercorefactory.xml does not exist. Skipping.
08:32:56 T:2650272752  NOTICE: Creating InputStream
08:32:56 T:2650272752  NOTICE: Creating Demuxer
08:32:58 T:2650272752  NOTICE: Opening stream: 0 source: 256
08:32:58 T:2650272752  NOTICE: Creating video codec with codec id: 13
08:32:58 T:2650272752  NOTICE: CDVDVideoCodecMFC::Open - MFC Setup succesfull (720x304, linesize 720, format 0x32314d4e), start streaming
08:32:58 T:2650272752  NOTICE: Creating video thread
08:33:03 T:2801791984  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:25
08:33:13 T:2801791984  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
08:33:36 T:3036712960  NOTICE: DVDPlayer: Opening:
08:33:36 T:3036712960 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
08:33:36 T:2650272752  NOTICE: Creating InputStream
08:33:36 T:2650272752  NOTICE: Creating Demuxer
08:33:36 T:2650272752  NOTICE: Opening stream: 0 source: 256
08:33:36 T:2650272752  NOTICE: Creating video codec with codec id: 28
08:33:36 T:2650272752  NOTICE: CDVDVideoCodecMFC::Open - MFC Setup succesfull (720x304, linesize 720, format 0x32314d4e), start streaming
08:33:36 T:2650272752  NOTICE: Creating video thread
08:33:36 T:2650272752  NOTICE: Opening stream: 1 source: 256
08:33:36 T:2650272752  NOTICE: Finding audio codec for: 86019
08:33:36 T:2879464432  NOTICE: running thread: video_thread
08:33:36 T:2650272752  NOTICE: Creating audio thread
08:33:36 T:2810180592  NOTICE: running thread: CDVDPlayerAudio::Process()
08:33:36 T:2810180592  NOTICE: Creating audio stream (codec id: 86019, channels: 6, sample rate: 48000, no pass-through)
08:33:36 T:2810180592  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 32
08:33:36 T:2879464432  NOTICE:  fps: 23.976024, pwidth: 720, pheight: 304, dwidth: 720, dheight: 304
08:33:36 T:2879464432  NOTICE: Display resolution DESKTOP : 1024x768 (16)
08:33:36 T:3036712960  NOTICE: Using GL_TEXTURE_2D
08:33:36 T:2810180592  NOTICE: CDVDPlayerAudio::OutputPacket duplicate 3 packets of duration 32
08:33:36 T:3036712960  NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
08:33:36 T:3036712960  NOTICE: GL: NPOT texture support detected
08:33:37 T:2810180592  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 32
08:33:38 T:2879464432  NOTICE: Previous line repeats 3 times.
08:33:38 T:2879464432   ERROR: CDVDVideoCodecMFC::Decode - MFC OUTPUT All buffers are queued and busy, no space for new frame to decode. Very broken situation. Current encoded frame will be lost
08:33:38 T:2879464432   ERROR: Previous line repeats 1 times.



Kernel:
Code: Select all
 uname -a
Linux odroid 3.8.13.30 #1 SMP PREEMPT Fri Sep 4 23:45:57 BRT 2015 armv7l armv7l armv7l GNU/Linux


Media info from movie with buffers problem:
Code: Select all
avprobe version 9.20-6:9.20-0ubuntu0.14.04.1, Copyright (c) 2007-2014 the Libav developers
  built on Dec  7 2016 21:28:33 with gcc 4.8 (Ubuntu/Linaro 4.8.4-2ubuntu1~14.04.3)
Input #0, matroska,webm,
  Duration: 02:05:41.53, start: 0.000000, bitrate: N/A
    Stream #0.0: Video: h264 (High), yuv420p, 720x304 [PAR 1:1 DAR 45:19], 23.98 fps, 23.98 tbr, 1k tbn, 47.95 tbc (default)
    Metadata:
      BPS             : 1499623
      BPS-eng         : 1499623
      DURATION        : 02:05:41.534000000
      DURATION-eng    : 02:05:41.534000000
      NUMBER_OF_FRAMES: 180816
      NUMBER_OF_FRAMES-eng: 180816
      NUMBER_OF_BYTES : 1413682397
      NUMBER_OF_BYTES-eng: 1413682397
      _STATISTICS_WRITING_APP: mkvmerge v8.5.2 ('Crosses') 32bit
      _STATISTICS_WRITING_APP-eng: mkvmerge v8.5.2 ('Crosses') 32bit
      _STATISTICS_WRITING_DATE_UTC: 2016-08-24 08:20:35
      _STATISTICS_WRITING_DATE_UTC-eng: 2016-08-24 08:20:35
      _STATISTICS_TAGS: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
    Stream #0.1: Audio: ac3, 48000 Hz, 5.1, fltp, 448 kb/s (default)
    Metadata:
      BPS             : 448000
      BPS-eng         : 448000
      DURATION        : 02:05:41.536000000
      DURATION-eng    : 02:05:41.536000000
      NUMBER_OF_FRAMES: 235673
      NUMBER_OF_FRAMES-eng: 235673
      NUMBER_OF_BYTES : 422326016
      NUMBER_OF_BYTES-eng: 422326016
      _STATISTICS_WRITING_APP: mkvmerge v8.5.2 ('Crosses') 32bit
      _STATISTICS_WRITING_APP-eng: mkvmerge v8.5.2 ('Crosses') 32bit
      _STATISTICS_WRITING_DATE_UTC: 2016-08-24 08:20:35
      _STATISTICS_WRITING_DATE_UTC-eng: 2016-08-24 08:20:35
      _STATISTICS_TAGS: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
# avprobe output


dmesg for mfc
Code: Select all
[    0.000000] sclk_mfc: source is mout_mfc0 (0), rate is 50000000
[    2.478696] sclk_mfc rate is: 200
[    2.478854] s5p-mfc s5p-mfc: decoder registered as /dev/video8
[    2.478958] s5p-mfc s5p-mfc: encoder registered as /dev/video9
[    2.906093] pd-mfc: Power-off latency exceeded, new value 237458 ns
[    4.507468] pd-mfc: Power-on latency exceeded, new value 1332875 ns
[    4.507981] s5p-mfc s5p-mfc: start latency exceeded, new value 791 ns
[    4.508002] s5p-mfc s5p-mfc: state restore latency exceeded, new value 3708 ns
[    4.578146] s5p-mfc s5p-mfc: stop latency exceeded, new value 1583 ns
[    4.578160] s5p-mfc s5p-mfc: state save latency exceeded, new value 2583 ns
[    4.578414] pd-mfc: Power-off latency exceeded, new value 246958 ns
[    4.631860] s5p-mfc s5p-mfc: state save latency exceeded, new value 2708 ns
[    4.632443] pd-mfc: Power-off latency exceeded, new value 571250 ns


s5p files:
Code: Select all
ls -ll /lib/firmware/s5p-mfc
total 1716
-rw-r--r-- 1 root root 352652 Dec  1  2016 s5p-mfc.fw
-rw-r--r-- 1 root root 306312 Dec  1  2016 s5p-mfc-v6.fw
-rw-r--r-- 1 root root 343756 Dec  1  2016 s5p-mfc-v6-v2.fw
-rw-r--r-- 1 root root 382724 Dec  1  2016 s5p-mfc-v7.fw
-rw-r--r-- 1 root root 360576 Dec  1  2016 s5p-mfc-v8.fw


Is there any solution for this problem, how to fix it?
I was trying debian but problem still occurs.
Thanks for any ideas.
bpbiszkopt
 
Posts: 24
Joined: Fri Jan 22, 2016 5:19 pm
languages_spoken: english
ODROIDs: u3

Re: Kodi 16.1 MFC OUTPUT All buffers are queued and busy

Unread postby OverSun » Wed Sep 20, 2017 6:29 pm

Those videos are encoded by people who think they know what they are doing better than anyone around them.
I bet you are watching anime or some ripped TV shows.
Thing is that these videos are encoded with enormous amount of B- or P-frames, frames that hold only difference to adjacent pictures. To decode them the codec need to hold previous pictures in buffer - to know the base of the picture differences should be applied to.
At the beginning of the video number of buffers needed for that are asked from the hardware providing video header, and the hardware returns how much buffers it would like to have to decode properly this exact video clip. Then 1.5 times of that number is allocated, just to make sure it is enough.
Most of the time it is enough, there are something like 4 - 10 buffers are used, and 10 is for really heavy videos. But sometimes there is a clip that requires enormous amount of buffers, more than 16, and that number doesn't fit into device buffer, it's just wrong way to do it. There is no reason to encode videos like this the same way there is no reason to shoot yourself in the leg only because you can. But some people do that.
User avatar
OverSun
 
Posts: 1266
Joined: Mon Apr 29, 2013 5:12 pm
languages_spoken: english

Re: Kodi 16.1 MFC OUTPUT All buffers are queued and busy

Unread postby bpbiszkopt » Wed Sep 20, 2017 8:16 pm

OverSun thank you really much for answering, and telling where the problem is.
And you wrongly bet...its neither anime or tv rip, they are normal movies, dvdrip or bdrip,.
Is there any possibility to make workaround? If i open them in another player eg.smplayer it plays normally but i cant resize picture.

Two more examples:
Code: Select all
avprobe version 9.20-6:9.20-0ubuntu0.14.04.1, Copyright (c) 2007-2014 the Libav developers
  built on Dec  7 2016 21:28:33 with gcc 4.8 (Ubuntu/Linaro 4.8.4-2ubuntu1~14.04.3)
Input #0, matroska,webm,
  Duration: 01:52:12.30, start: 0.000000, bitrate: N/A
    Stream #0.0: Video: h264 (High), yuv420p, 1280x534 [PAR 1:1 DAR 640:267], 23.98 fps, 23.98 tbr, 1k tbn, 47.95 tbc (default)
    Metadata:
      BPS             : 2499743
      BPS-eng         : 2499743
      DURATION        : 01:52:12.309000000
      DURATION-eng    : 01:52:12.309000000
      NUMBER_OF_FRAMES: 161414
      NUMBER_OF_FRAMES-eng: 161414
      NUMBER_OF_BYTES : 2103630592
      NUMBER_OF_BYTES-eng: 2103630592
      _STATISTICS_WRITING_APP: mkvmerge v8.5.2 ('Crosses') 32bit
      _STATISTICS_WRITING_APP-eng: mkvmerge v8.5.2 ('Crosses') 32bit
      _STATISTICS_WRITING_DATE_UTC: 2016-09-06 01:37:13
      _STATISTICS_WRITING_DATE_UTC-eng: 2016-09-06 01:37:13
      _STATISTICS_TAGS: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
    Stream #0.1: Audio: ac3, 48000 Hz, 5.1, fltp, 384 kb/s (default)
    Metadata:
      BPS             : 384000
      BPS-eng         : 384000
      DURATION        : 01:52:07.712000000
      DURATION-eng    : 01:52:07.712000000
      NUMBER_OF_FRAMES: 210241
      NUMBER_OF_FRAMES-eng: 210241
      NUMBER_OF_BYTES : 322930176
      NUMBER_OF_BYTES-eng: 322930176
      _STATISTICS_WRITING_APP: mkvmerge v8.5.2 ('Crosses') 32bit
      _STATISTICS_WRITING_APP-eng: mkvmerge v8.5.2 ('Crosses') 32bit
      _STATISTICS_WRITING_DATE_UTC: 2016-09-06 01:37:13
      _STATISTICS_WRITING_DATE_UTC-eng: 2016-09-06 01:37:13
      _STATISTICS_TAGS: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
# avprobe output


Code: Select all
avprobe version 9.20-6:9.20-0ubuntu0.14.04.1, Copyright (c) 2007-2014 the Libav developers
  built on Dec  7 2016 21:28:33 with gcc 4.8 (Ubuntu/Linaro 4.8.4-2ubuntu1~14.04.3)
Input #0, matroska,webm,
  Duration: 02:06:13.50, start: 0.000000, bitrate: N/A
    Stream #0.0(eng): Video: h264 (High), yuv420p, 1280x534, PAR 1:1 DAR 640:267, 23.98 fps, 23.98 tbr, 1k tbn, 47.95 tbc (default) (forced)
    Stream #0.1: Audio: ac3, 48000 Hz, 5.1, fltp, 448 kb/s (default)
# avprobe output
bpbiszkopt
 
Posts: 24
Joined: Fri Jan 22, 2016 5:19 pm
languages_spoken: english
ODROIDs: u3

Re: Kodi 16.1 MFC OUTPUT All buffers are queued and busy

Unread postby OverSun » Wed Sep 20, 2017 9:56 pm

if your movies are played normally in smplayer, which should be software accell, just disable hardware acceleration in Kodi and it should be fine for you then.
User avatar
OverSun
 
Posts: 1266
Joined: Mon Apr 29, 2013 5:12 pm
languages_spoken: english


Return to Ubuntu

Who is online

Users browsing this forum: No registered users and 1 guest