Playback Stalling on Web Client

[BrettB]

I use LibreELEC running on an RPi 3 as my primary NextPVR user interface/client. I have the recording devices mapped as SMB drives from my NextPVR server to the RPi and use advancedsettings.xml with path substitution redirect the player to access the .ts files directly from the SMB drives rather than via NextPVR's HTTP streaming (in order to get .edl skipping support).

Recently I've been having problems with several recordings where the playback will stall for various lengths of time. Sometimes Kodi will display a Buffering message. Other times it just stalls for a while before beginning playing again. Often this happens during/after a commercial skip or a manual skip forward during playback. So far, I haven't been able to track down the cause. I don't think that it is network/hardware related. It seems more like it is related to the contents of the .ts file because some files will exhibit this problem multiple times during playback and other files will play just fine.

I just updated to the latest LibreELEC Beta (v. 1.95.2) and am still having the problem. When the problem happens, the kodi.log file is showing some/all of these errors:

Code:

WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
ERROR: CDVDAudio::AddPacketsRenderer - timeout adding data to renderer
ERROR: Previous line repeats 73 times.
NOTICE: CVideoPlayerAudio::Process - stream stalled

And when this situation just happened while playing a file, I turned on debugging (at 14:43:42 in the attached kodi.log), continued waiting and watching through a couple of skips, and then zipped the attached logs.

I'm wondering if anyone else is seeing similar problems or has ideas about where I look next to try to fix the issue(s).

Also, I also noticed an HTTP 404 error in the logs when I pressed the Info key, but I don't think that is at all related. Maybe something else to look at fixing, though:

Code:

14:44:25.189 T:1940603808   DEBUG: ActiveAE::SyncStream pll:0.00000 (act:1.00000 lim:0.00000) rr:0.99845 threshold:0.020 error:-0.654687
14:44:25.495 T:1462760352   DEBUG: http://192.168.143.10:8866/control?media=2250.28710938&client=sdl-KNEWA0xb827eb9ccb26L&sid=6e35acd72852448cb283554ff3437d84
14:44:25.604 T:1962185840   DEBUG: LIRC: Update - NEW at 7453540:166 0 KEY_INFO devinput (KEY_INFO)
14:44:25.605 T:1962185840   DEBUG: OnKey: launch_media_center (0xc3) pressed, action is Info
14:44:25.606 T:1484546976   DEBUG: http://192.168.143.10:8866/control?time=1486241065&key=131138&client=sdl-KNEWA0xb827eb9ccb26L&sid=6e35acd72852448cb283554ff3437d84
14:44:25.884 T:1962185840   DEBUG: CMMALRenderer::RenderUpdate - vsync 446955 (+7)
14:44:25.971 T:1962185840   DEBUG: LIRC: Update - NEW at 7453907:166 0 KEY_INFO_UP devinput (KEY_INFO_UP)
14:44:26.234 T:1940603808   DEBUG: ActiveAE::SyncStream pll:0.00000 (act:1.00000 lim:0.00000) rr:0.99884 threshold:0.020 error:0.139469
14:44:26.517 T:1462760352   DEBUG: http://192.168.143.10:8866/control?media=2251.3190918&client=sdl-KNEWA0xb827eb9ccb26L&sid=6e35acd72852448cb283554ff3437d84
14:44:26.596 T:1462760352   DEBUG: {u'url': u'', u'screen': u'Recordings'}
14:44:26.806 T:1962185840   DEBUG: CMMALRenderer::RenderUpdate - vsync 447011 (+7)
14:44:27.283 T:1940603808   DEBUG: ActiveAE::SyncStream pll:0.00000 (act:1.00000 lim:0.00000) rr:0.99855 threshold:0.020 error:-0.442777
14:44:27.598 T:1462760352   DEBUG: http://192.168.143.10:8866/control?media=2252.39599609&client=sdl-KNEWA0xb827eb9ccb26L&sid=6e35acd72852448cb283554ff3437d84
14:44:27.679 T:1462760352   DEBUG: {u'url': u'', u'screen': u'Recordings'}
14:44:27.884 T:1962185840   DEBUG: CMMALRenderer::RenderUpdate - vsync 447074 (+8)
14:44:28.204 T:1962185840   DEBUG: LIRC: Update - NEW at 7456140:166 0 KEY_INFO devinput (KEY_INFO)
14:44:28.204 T:1962185840   DEBUG: OnKey: launch_media_center (0xc3) pressed, action is Info
14:44:28.205 T:1484546976   DEBUG: http://192.168.143.10:8866/control?time=1486241068&key=131138&client=sdl-KNEWA0xb827eb9ccb26L&sid=6e35acd72852448cb283554ff3437d84
14:44:28.226 T:1484546976   DEBUG: 404
14:44:28.226 T:1484546976   DEBUG: HTTP Error 404: Not Found
14:44:28.332 T:1940603808   DEBUG: ActiveAE::SyncStream pll:0.00000 (act:1.00000 lim:0.00000) rr:0.99904 threshold:0.020 error:0.537892
14:44:28.589 T:1962185840   DEBUG: LIRC: Update - NEW at 7456524:166 0 KEY_INFO_UP devinput (KEY_INFO_UP)
14:44:28.685 T:1462760352   DEBUG: http://192.168.143.10:8866/control?media=2253.48608398&client=sdl-KNEWA0xb827eb9ccb26L&sid=6e35acd72852448cb283554ff3437d84

[BrettB]

To rule out the LibreELEC/RPi SMB client, I tried switching to NFS. Still the same problems.

[BrettB]

Another discovery: During automatic commercial skipping, if I display the timeline on the screen while playback is "stalled", it shows the current position proceeding through commercial section in real-time (while the audio and video are black). And then when it gets to the end of the commercial section, there is a brief "stutter" and then playback continues normally.

[mvallevand]

Does it play from Windows PC? I do suspect a file problem perhaps ts4np will fix it.

Martin

[BrettB]

Does it play from Windows PC? I do suspect a file problem perhaps ts4np will fix it.

Actually, it seems to be a LibreELEC (or more likely) Kodi problem. I had posted about it in the LibreELEC forum here https://forum.libreelec.tv/thread-4546.html and pavlov70 reported seeing the same behavior with an Intel NUC playing recordings from a MythTV backend.

I downgraded back to LibreELEC 7.95.1 and it is doing the auto skip OK again. I think that there may be something file related as I was occassionally getting this sort of behavior with a few files with pre-7.95.2 versions. But when I went to 7.95.2, it was consistently happening with every file that I played. Weird. And annoying!

[mvallevand]

Actually, it seems to be a LibreELEC (or more likely) Kodi problem

Yes it seems to be a Kodi problem, in later Krypton versions and I see it on other platform outside LE. https://github.com/xbmc/xbmc/pull/11646 The fix is out for Leia but nothing about a Krypon backport yet.

Martin

[BrettB]

Yes it seems to be a Kodi problem, in later Krypton versions and I see it on other platform outside LW. https://github.com/xbmc/xbmc/pull/11646 The fix is out for Leia but nothing about a Krypon backport yet.

Thanks for finding this Martin. I've been watching for any acknowledgement of a problem, etc. as well as trying to figure out what might have changed in the code between the Kodi is 7.95.1 and 7.95.2. But I hadn't gotten very far. :-( For now, I've downgraded to 7.95.1 where it's working OK. Hopefully they will backport to Krypton. This bug is pretty much a show-stopper (literally) for me!

[mvallevand]

I compiled and build 17.1 RC today and comskip is working with the backport patches.

Martin

[BrettB]

I compiled and build 17.1 RC today and comskip is working with the backport patches.

Great. Hopefully it won't take too long for it to make it into the LibreElec distribution.