Video playback stutter when connected to control4 system (connection via “allow remote control from applications on other systems”)

Hi All

First off I wanted to express my deep appreciation for all the hard work that goes into this project, which is just awesome. I also want to apologise in advance if I have overlooked something stupid, I’ve spent at least 50 solid hours reading and troubleshooting on my own before posting…

I have access to several boxes including A95X-B7N, Mini M8S Pro, T95Kpro and BM8 Pro (half use s905x the other half s912). I use a Control4 system connected using this IP driver for control: http://www.chowmainsoft.com/kodi-xbmc-full-driver-for-control4

On any of the above boxes, running any version of coreelec (currently 9.03) I get a relatively regular video stutter when the Control4 connection is active, that is to say the frame freezes for a split second and then catches up, audio doesn’t seem to be affected.

This occurs regardless of the source material or location of the media (network via nfs, usb or local storage). If I terminate the connection of the control4 system, playback is perfect.

Nearly all of my content are 1080p or 2160p mkv films at 23.98Hz – playback issue applies to both resolutions encoded in either h264 or h265.

The log located at https://paste.ubuntu.com/p/gDVfjvmzG9/ includes playback with the issue (90 seconds without event removed due to upload constraint) – stutter occurred and I pressed stop on the video shortly afterwards.

I’m not sure whether this is an issue that relates to coreelec or Kodi, and whichever it is I’m unsure whether it will ultimately be the driver which requires fixing. However, I’m hoping someone smarter than me can have a look at the attached log and offer some insights on the cause of the problem and how it might be solved?

Thanks in advance for any and all input!

It looks like issue in your plugin blocking rendering. Rendering is running high priority thread and have to appear regulary for every frame (for 23.976 fps every 41 ms). To see this issue in debug log you have to enable audio/video timing specific debugging in logging settings.

Hi, I enabled audio/video timing specific debugging along with json (method of Control4 control) - this yielded a huge log. I have copied and pasted a 4 second section where the stutter occurred (video stopped immediately after to help isolate location in log): https://paste.ubuntu.com/p/tgwdBbG26F/

I have also tried to create a full log and upload via coreelec plugin, however, after I playback a video it always says failed to paste.

Does the new log offer any further insight? Thanks for your help!

I reduced your log to two threads to see issue. PollFrame is used for syncing rendering to frame rate frequency. It have to appears every 41.666 msec (1/23.976). The thread T:3601814320 JSONRPC is blocking rendering for 172 msec.

2019-08-27 09:58:15.979 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:35.421ms
2019-08-27 09:58:15.985 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.432 renderPts: 533.597 nextFramePts: 533.575 -> diff: 0.022 render: 1 forceNext: 0
2019-08-27 09:58:15.986 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1042, drop:0
2019-08-27 09:58:16.021 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:34.344ms
2019-08-27 09:58:16.028 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.476 renderPts: 533.640 nextFramePts: 533.616 -> diff: 0.024 render: 1 forceNext: 0
2019-08-27 09:58:16.029 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1043, drop:0
2019-08-27 09:58:16.050 T:3601814320 DEBUG: JSONRPC: Incoming request: {"id":"1","method":"XBMC.GetInfoLabels","jsonrpc":"2.0","params": {"label s":["System.CpuUsage","System.CPUTemperature","System.ScreenResolution","System.CpuFrequency","System.Memory(used.percent)","System.Uptime","System.TotalSpace","System.CurrentWindow"]}}
2019-08-27 09:58:16.062 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:32.648ms
2019-08-27 09:58:16.234 T:3601814320 DEBUG: JSONRPC: Incoming request: {"id":"1","jsonrpc":"2.0","method":"JSONRPC.Ping"}
2019-08-27 09:58:16.236 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.683 renderPts: 533.848 nextFramePts: 533.658 -> diff: 0.19 render: 1 forceNext: 0
2019-08-27 09:58:16.236 T:4091505472 DEBUG: CRenderManager::PrepareNextRender Frame Skip:3 iter.pts:533.700 lf:3 latency:0.125 Clock:53 3.683
2019-08-27 09:58:16.236 T:4091505472 DEBUG: CRenderManager::PrepareNextRender Frame Skip:4 iter.pts:533.742 lf:2 latency:0.125 Clock:53 3.683
2019-08-27 09:58:16.236 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1044, drop:1
2019-08-27 09:58:16.236 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1045, drop:1
2019-08-27 09:58:16.238 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1046, drop:0
2019-08-27 09:58:16.238 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:0.020ms
2019-08-27 09:58:16.243 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.691 renderPts: 533.855 nextFramePts: 533.783 -> diff: 0.072 render: 1 forceNext: 0
2019-08-27 09:58:16.244 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1047, drop:0
2019-08-27 09:58:16.271 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:26.611ms
2019-08-27 09:58:16.276 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.724 renderPts: 533.888 nextFramePts: 533.825 -> diff: 0.063 render: 1 forceNext: 0
2019-08-27 09:58:16.278 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1048, drop:0
2019-08-27 09:58:16.313 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:34.955ms
2019-08-27 09:58:16.318 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.765 renderPts: 533.930 nextFramePts: 533.867 -> diff: 0.063 render: 1 forceNext: 0
2019-08-27 09:58:16.319 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1049, drop:0
2019-08-27 09:58:16.354 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:34.671ms
2019-08-27 09:58:16.359 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.807 renderPts: 533.971 nextFramePts: 533.908 -> diff: 0.063 render: 1 forceNext: 0
2019-08-27 09:58:16.360 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1050, drop:0
2019-08-27 09:58:16.396 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:35.579ms
2019-08-27 09:58:16.401 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.848 renderPts: 534.013 nextFramePts: 533.950 -> diff: 0.063 render: 1 forceNext: 0
2019-08-27 09:58:16.403 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1051, drop:0
2019-08-27 09:58:16.438 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:34.502ms
2019-08-27 09:58:16.443 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.890 renderPts: 534.055 nextFramePts: 533.992 -> diff: 0.063 render: 1 forceNext: 0
2019-08-27 09:58:16.443 T:4091505472 DEBUG: CRenderManager::PrepareNextRender Frame Skip:5 iter.pts:534.034 lf:0 latency:0.125 Clock:53 3.89
2019-08-27 09:58:16.443 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1052, drop:1
2019-08-27 09:58:16.444 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1053, drop:0
2019-08-27 09:58:16.479 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:34.992ms
2019-08-27 09:58:16.485 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.932 renderPts: 534.097 nextFramePts: 534.075 -> diff: 0.022 render: 1 forceNext: 0
2019-08-27 09:58:16.486 T:4091505472 DEBUG: CAMLCodec::ReleaseFrame idx:1054, drop:0
2019-08-27 09:58:16.521 T:4091505472 DEBUG: CAMLCodec::PollFrame elapsed:34.744ms
2019-08-27 09:58:16.528 T:4091505472 DEBUG: PrepareNextRender: frameOnScreen: 533.976 renderPts: 534.140 nextFramePts: 534.117 -> diff: 0.023 render: 1 forceNext: 0

Thanks very much for this analysis, I will feed this back to the developer… is there some way to lower the priority of the JSON thread and avoiding this issue? (apologies if this make no sense, I have a very limited understanding of what’s happening here).

I don’t think it helps. This have to be issue in plugin blocking some resources for rendering.

This isn’t a plugin… i.e. there is no plugin installed that relates to this functionality, it is simply commands sent from another linux device on the network (control4) using kodi option “allow remote control from applications on other systems” settings > services.

This is the kodi related issue. Amlogic HW decoding has no issue.

Hi, I have tried and failed to reproduce this issue using AFTV and kodi 18.3 arm - it seems specific to amlogic hardware…

This issue can be reproduced by connecting via telnet on 9090 and sending the following JSON query:

{“id”:“1”,“method”:“XBMC.GetInfoLabels”,“jsonrpc”:“2.0”,“params”:{“labels”:[“System.CpuUsage”,“System.CPUTemperature”,“System.ScreenResolution”,“System.CpuFrequency”,“System.Memory(used.percent)”,“System.Uptime”,“System.TotalSpace”,“System.CurrentWindow”]}}

(The control4 system utilises this method to display this information in its own GUI) - this seems to be the only JSONRPC command that causes the video stutter. It only causes a stutter occassionally, not each time the command is issued, if someone can explain why that would be very helpful…

Today have tested the latest version of liberelec on x86 hardware which does not suffer from this issue, i then tested the latest version of libreelec for odriod C2 and the same issue is present. It is therefore definitely something specific to coreelec / libreelec on Amlogic hardware… any thoughts?

It doesn’t mean anything, because the ARM based systems use a different way to render the GUI.

I’m sorry but I’m really confused, the issue I am describing is a video playback stutter - the reference I made to GUI was in relation to the Control4 system GUI which is interacting / controlling Kodi as described here:

However, even without the Control4 system, if you establish a telnet connection to coreelec and send

{“id”:“1”,“method”:“XBMC.GetInfoLabels”,“jsonrpc”:“2.0”,“params”:{“labels”:[“System.CpuUsage”,“System.CPUTemperature”,“System.ScreenResolution”,“System.CpuFrequency”,“System.Memory(used.percent)”,“System.Uptime”,“System.TotalSpace”,“System.CurrentWindow”]}}

a few times eventually you get the same playback stutter. Control4 system is simply using JSONRPC on 9090 to “talk” to kodi and it is JSONRPC implementation that is causing the problem… This is only happens on coreelec s905x or s912 and libreelec odriod C2.

The issue is not present on libreelec x86 OR KODI 8.3 ARM running on AFTV3 with S905Z. Am I making sense?

Jamiec- Did you ever find a solution to this problem?

I had been playing MKV’s from my UNRAID server for the last year with no issues.

I had the Chowmain Kodi lite driver installed last week on my C4 system to control 3-Vero 4k+ Boxes.

All weekend my mkv streams were juttering/stuttering roughly every 4-5 mins.

I spent all weekend troubleshooting and finally turn off the IP control from Control4 And I was able to stream my mkv’s with no jitter/stuttering.

Cheers manutdsoc20

I am having same problem with my Vero 4k+ boxes. Both with Kodi 18 and 19. Anyone figure out solution?