#17304 closed Bugs (Fixed)

Performance issue with Krypton xbmcgui.ListItem methods

Reported by: Basje Owned by: jfcarroll
Priority: 4 - Normal
Component: Python Code and/or Scripts Version: 17.0 "Krypton" Final
Severity: Normal Keywords: xbmcgui add-on python
Cc: Blocked By:
Blocking: Platform: All

Description

My Kodi add-on (Retrospect, http://www.rieter.net/content/) lists online free videos from a number of sites. Lists tend to get quite large (500+ items). This was no problem with Kodi Jarvis, but with the Krypton release the performance dramatically dropped from 5s to 30s to load lists.

Here is some data from a cProfile run on Krypton on my OSMC Raspberry Pi 2:

   ncalls  tottime  cumtime
   1168    3.951    3.951  {method 'setArt' of 'xbmcgui.ListItem' objects}
    584    0.655    0.655  {method 'setContentLookup' of 'xbmcgui.ListItem' objects}
    584    0.227    0.227  {method 'setIconImage' of 'xbmcgui.ListItem' objects}
    584    2.142    2.142  {method 'setInfo' of 'xbmcgui.ListItem' objects}
    584    3.620    3.620  {method 'setLabel' of 'xbmcgui.ListItem' objects}
    584    0.006    0.006  {method 'setLabel2' of 'xbmcgui.ListItem' objects}
    584   14.035   14.035  {method 'addContextMenuItems' of 'xbmcgui.ListItem' objects}

as you can see, creating the ListItems and setting some values takes a total of 24.636 seconds.

Now here is the same trace running Jarvis on that same OSMC Raspberry Pi 2:

 ncalls  tottime  cumtime
   1168    0.049    0.049  {method 'setArt' of 'xbmcgui.ListItem' objects}
    584    0.009    0.009  {method 'setContentLookup' of 'xbmcgui.ListItem' objects}
    584    0.005    0.005  {method 'setIconImage' of 'xbmcgui.ListItem' objects}
    584    0.049    0.049  {method 'setInfo' of 'xbmcgui.ListItem' objects}
    584    0.028    0.028  {method 'setLabel' of 'xbmcgui.ListItem' objects}
    584    0.006    0.006  {method 'setLabel2' of 'xbmcgui.ListItem' objects}
    584    0.210    0.210  {method 'addContextMenuItems' of 'xbmcgui.ListItem' objects}

The same creating of ListItems only takes 0.356 seconds, about 70x faster.

So this is weird. I had multiple reports of this.

I also checked my PC, but and see similar behaviour, however, due to larger amount of CPU power the difference is not as noticeable:

Jarvis on my PC:

  ncalls  tottime  cumtime
    1168    0.003    0.003  {method 'setArt' of 'xbmcgui.ListItem' objects}
     584    0.000    0.000  {method 'setContentLookup' of 'xbmcgui.ListItem' objects}
     584    0.000    0.000  {method 'setIconImage' of 'xbmcgui.ListItem' objects}
     584    0.005    0.005  {method 'setInfo' of 'xbmcgui.ListItem' objects}
     584    0.001    0.001  {method 'setLabel' of 'xbmcgui.ListItem' objects}
     584    0.000    0.000  {method 'setLabel2' of 'xbmcgui.ListItem' objects}
     584    0.024    0.024  {method 'addContextMenuItems' of 'xbmcgui.ListItem' objects}

Which makes a total of 0.033 seconds. And now Krypton on my PC:

   ncalls  tottime  cumtime
     1168    0.018    0.018  {method 'setArt' of 'xbmcgui.ListItem' objects}
      584    0.000    0.000  {method 'setContentLookup' of 'xbmcgui.ListItem' objects}
      584    0.001    0.001  {method 'setIconImage' of 'xbmcgui.ListItem' objects}
      584    0.032    0.032  {method 'setInfo' of 'xbmcgui.ListItem' objects}
      584    0.072    0.072  {method 'setLabel' of 'xbmcgui.ListItem' objects}
      584    0.000    0.000  {method 'setLabel2' of 'xbmcgui.ListItem' objects}
      584    0.169    0.169  {method 'addContextMenuItems' of 'xbmcgui.ListItem' objects}

Which makes a total of 0.292 seconds, which is (even though not noticeable for a user) quite a big difference on such a high end system.

Change History (36)

comment:1 Changed at 2017-02-05T18:25:43Z by Basje

I checked some more of the add-ons I had. The ViaSat add-on (Video Plugin from Kodi repo) has the same issue. Within that add-on go to: Film -> Alla Filmer -> List all in alphabetic order

comment:2 Changed at 2017-02-05T19:44:54Z by asplundj

I am also experiencing that the retrospect addon and the viaplay addon is MUCH slower running kodi 17 on rpi2 than it was on kodi 16.1

comment:4 Changed at 2017-02-06T18:29:48Z by popcornmix

@Basje are you able to rebuild kodi?

The belief is that https://github.com/xbmc/xbmc/pull/9748 caused the reduced performance.

I wonder if you could experiment with sleepTime here: https://github.com/xbmc/xbmc/blob/master/xbmc/Application.cpp#L2748

E.g. start with: unsigned int sleepTime = 10;

and check if performance goes up.

comment:5 Changed at 2017-02-06T20:11:47Z by Basje

I could a while ago, let me update my git repo and try.

comment:6 Changed at 2017-02-06T23:14:35Z by Basje

After setting stuff up I managed to get a build and indeed this seems to be the issue. Played around with values from 2 - 50 in this line:

unsigned int sleepTime = std::max(static_cast<unsigned int>(2), std::min(m_ProcessedExternalCalls >> 2, static_cast<unsigned int>(10)));

And with 10 msec there are just too many loops. I upped to towards 20 which already reduced the time on my PC by a factor 5. Changing it higher than 25 did not seem to make a big difference any more.

comment:7 Changed at 2017-02-06T23:29:09Z by Basje

I checked some more. If I put it on 100, I do get a more 'constant' fast response. With 25-50 it fluctuated.

comment:8 Changed at 2017-02-06T23:31:33Z by popcornmix

sleepTime is in milliseconds, and this is in the main render loop. The sleep opens a window where python get get in. As the render loop may be running at 60fps then setting sleepTime above 16ms will mean that rendering can longer occur at 60fps (you will probably find the GUI animations are a bit more stuttery).

Realistically a certain amount of work also needs to be done to render the GUI so going above 10ms may not be acceptable.

Note, at the moment we are just trying to find a compromise that may be acceptable for Krypton and restores some of the lost performance. The issue is acknowledged and there will be better solutions in the future, but these will be too invasive for Krypton.

Adding a log message just after that line would be useful (without changing sleepTime). Log the value of sleepTime and m_ProcessedExternalCalls and run your addon. Lets see what sleepTime is actually getting on Krypton and we'll think of a way to increase it.

comment:9 Changed at 2017-02-06T23:32:59Z by Basje

I added this log in my test version:

CLog::Log(LOGNOTICE, "Sleeping for external calls for %i ms (external: %i >> 2 = %i)", sleepTime, m_ProcessedExternalCalls, m_ProcessedExternalCalls >> 2);

comment:10 Changed at 2017-02-06T23:34:15Z by popcornmix

Yes that looks fine.

comment:11 Changed at 2017-02-06T23:38:45Z by Basje

I put it on 16ms, but then the result is still twice as slow on my PC with 6 core CPU. I guess on rPi's it will even be slower. Would putting it on 32ms be a good value? That would mean 30fps only during Python script execution? That would bring to down to only half as slow?

But to be honest, I would prefer performance during python script execution over FPS. The users is usually waiting for a result any way?

comment:12 Changed at 2017-02-06T23:40:17Z by Basje

Log looks like this with 32ms:

00:37:24.934 T:17396   DEBUG: CPythonInvoker(4, F:\Kodi\Kodi DEV\portable_data\addons\net.rieter.xot\default.py): instantiating addon using automatically obtained id of "net.rieter.xot" dependent on version 2.14.0 of the xbmc.python api
00:37:25.411 T:5504   DEBUG: ------ Window Init (DialogBusy.xml) ------
00:37:25.412 T:5504  NOTICE: Sleeping for external calls for 2 ms (external: 0 >> 2 = 0)
00:37:25.422 T:17396    INFO: Retrospect :: Additional logging can be found in 'F:\Kodi\Kodi DEV\portable_data\userdata\addon_data\net.rieter.xot\retrospect.log'
00:37:25.509 T:5504  NOTICE: Sleeping for external calls for 2 ms (external: 0 >> 2 = 0)
00:37:25.742 T:17396  NOTICE: Previous line repeats 1 times.
00:37:25.759 T:5504  NOTICE: Sleeping for external calls for 10 ms (external: 43 >> 2 = 10)
00:37:25.775 T:5504  NOTICE: Sleeping for external calls for 32 ms (external: 259 >> 2 = 64)
00:37:25.810 T:5504  NOTICE: Sleeping for external calls for 32 ms (external: 943 >> 2 = 235)
00:37:25.845 T:5504  NOTICE: Sleeping for external calls for 32 ms (external: 1647 >> 2 = 411)
00:37:25.879 T:5504  NOTICE: Sleeping for external calls for 32 ms (external: 2347 >> 2 = 586)
00:37:25.914 T:5504  NOTICE: Sleeping for external calls for 32 ms (external: 3050 >> 2 = 762)
00:37:25.948 T:5504  NOTICE: Sleeping for external calls for 32 ms (external: 3740 >> 2 = 935)
00:37:25.983 T:5504  NOTICE: Sleeping for external calls for 32 ms (external: 4441 >> 2 = 1110)
00:37:26.018 T:5504  NOTICE: Sleeping for external calls for 32 ms (external: 5136 >> 2 = 1284)
00:37:26.052 T:5504  NOTICE: Sleeping for external calls for 32 ms (external: 5838 >> 2 = 1459)
00:37:26.087 T:5504  NOTICE: Sleeping for external calls for 32 ms (external: 6541 >> 2 = 1635)
00:37:26.190 T:17396    INFO: CPythonInvoker(4, F:\Kodi\Kodi DEV\portable_data\addons\net.rieter.xot\default.py): script successfully run
00:37:26.194 T:17396    INFO: Python script stopped


comment:13 Changed at 2017-02-07T12:12:04Z by popcornmix

I'd prefer to see the log with the default code for sleepTime. See how big the sleeps are and how long it takes for them to increase.

comment:14 Changed at 2017-02-07T14:17:56Z by Basje

Right, NP. Here it is with 10ms:

15:08:29.903 T:4348  NOTICE: Sleeping for external calls for 2 ms (external: 0 >> 2 = 0)
15:08:29.919 T:5744    INFO: Retrospect :: Additional logging can be found in 'F:\Kodi\Kodi DEV\portable_data\userdata\addon_data\net.rieter.xot\retrospect.log'
15:08:30.013 T:4348  NOTICE: Sleeping for external calls for 2 ms (external: 0 >> 2 = 0)
15:08:30.447 T:4348  NOTICE: Previous line repeats 1 times.
15:08:30.447 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 55 >> 2 = 13)
15:08:30.464 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 192 >> 2 = 48)
15:08:30.481 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 295 >> 2 = 73)
15:08:30.497 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 559 >> 2 = 139)
15:08:30.514 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 823 >> 2 = 205)
15:08:30.530 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 1063 >> 2 = 265)
15:08:30.547 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 1307 >> 2 = 326)
15:08:30.563 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 1543 >> 2 = 385)
15:08:30.580 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 1802 >> 2 = 450)
15:08:30.597 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 2035 >> 2 = 508)
15:08:30.613 T:4348  NOTICE: Sleeping for external calls for 10 ms (external: 2275 >> 2 = 568)
15:08:30.675 T:5744    INFO: CPythonInvoker(4, F:\Kodi\Kodi DEV\portable_data\addons\net.rieter.xot\default.py): script successfully run

And here with 32ms:

15:10:32.320 T:9648  NOTICE: Sleeping for external calls for 2 ms (external: 0 >> 2 = 0)
15:10:33.271 T:9648   DEBUG: CWinEventsWin32::WndProcWindow is active
15:10:33.703 T:9648  NOTICE: Sleeping for external calls for 2 ms (external: 0 >> 2 = 0)
15:10:33.720 T:9648  NOTICE: Sleeping for external calls for 13 ms (external: 55 >> 2 = 13)
15:10:33.737 T:9648  NOTICE: Sleeping for external calls for 32 ms (external: 391 >> 2 = 97)
15:10:33.772 T:9648  NOTICE: Sleeping for external calls for 32 ms (external: 1189 >> 2 = 297)
15:10:33.807 T:9648  NOTICE: Sleeping for external calls for 2 ms (external: 0 >> 2 = 0)
15:10:33.812 T:9648  NOTICE: Sleeping for external calls for 16 ms (external: 64 >> 2 = 16)
15:10:33.886 T:17308    INFO: CPythonInvoker(3, F:\Kodi\Kodi DEV\portable_data\addons\net.rieter.xot\default.py): script successfully run

I would really like to test it with OSMC on my rPi as it is the slowest there (30 seconds vs 5 seconds before), but I need a OSMC build for that, which I can't do. Trying to get in contact with that dev at the moment.

comment:15 Changed at 2017-02-07T14:22:02Z by popcornmix

Building osmc should be straightforward, albeit slow (they build natively rather than cross-compiling) https://osmc.tv/wiki/development/getting-involved-with-osmc-development/ https://osmc.tv/wiki/development/how-the-osmc-build-system-works/

comment:16 Changed at 2017-02-07T14:37:07Z by Basje

Sadly, I don't run any Linux systems. But I will see how I can manage this.

comment:17 Changed at 2017-02-07T14:52:46Z by popcornmix

Can you describe exactly how you are running your tests? If you explain exactly which add-on to install and how to configure it and where the slow update is, I could try to capture logging from a Pi.

comment:18 Changed at 2017-02-07T17:05:33Z by Basje

That is easy! Use the latest Retrospect add-on which you can install via my repo(http://www.rieter.net/content/xot/troubleshooting/install/). After installation run the add-on one time and check that all channels appear (should be a rather long list).

Then edit de default.py file and go to the bottom. Change this part:

# ANY OF THESE SETTINGS SHOULD ONLY BE ENABLED FOR DEBUGGING PURPOSES
# from debug import remotedebugger
# debugger = remotedebugger.RemoteDebugger()

# import profile as cProfile
# import cProfile
# from debug import profilelinebyline as cProfile

# Path for PC
# statsPath = os.path.abspath(os.path.join(currentPath, "F:\\Kodi\\Kodi DEV\\portable_data\\addons\\DEV\\retrospect.pc.krypton.pstat"))
# statsPath = os.path.abspath(os.path.join(currentPath, "F:\\Kodi\\Kodi DEV\\portable_data\\addons\\DEV\\retrospect.pc.jarvis.pstat"))
# Path for ATV
# statsPath = os.path.abspath("/private/var/mobile/retrospect.atv.pstat")
# Path for rPi
# statsPath = os.path.abspath("/home/pi/.kodi/addons/net.rieter.xot/retrospect.rpi.pstat")

# Profiled run
# cProfile.run("RunPlugin()", statsPath)
# Normal run
RunPlugin()

into

# ANY OF THESE SETTINGS SHOULD ONLY BE ENABLED FOR DEBUGGING PURPOSES
# from debug import remotedebugger
# debugger = remotedebugger.RemoteDebugger()

# import profile as cProfile
import cProfile
# from debug import profilelinebyline as cProfile

# Path for PC
# statsPath = os.path.abspath(os.path.join(currentPath, "F:\\Kodi\\Kodi DEV\\portable_data\\addons\\DEV\\retrospect.pc.krypton.pstat"))
# statsPath = os.path.abspath(os.path.join(currentPath, "F:\\Kodi\\Kodi DEV\\portable_data\\addons\\DEV\\retrospect.pc.jarvis.pstat"))
# Path for ATV
# statsPath = os.path.abspath("/private/var/mobile/retrospect.atv.pstat")
# Path for rPi
statsPath = os.path.abspath("/home/pi/.kodi/addons/net.rieter.xot/retrospect.rpi.pstat")

# Profiled run
cProfile.run("RunPlugin()", statsPath)
# Normal run
# RunPlugin()

make sure the statsPath is set correctly. Then run go back to the add-on and navigate to the "SVT Play" folder. It has 500+ items. After opening it you get a pstat file that you can analyse using pstats or attach it here and I can run my script to print stuff

comment:19 Changed at 2017-02-07T18:36:26Z by Basje

Also compiling OSMC at the moment. Had a spare SD card.

comment:20 Changed at 2017-02-07T19:45:34Z by popcornmix

Do you mean National/SVT Play? I'm only seeing 39 entries ("Titles with 0-9", "Titles with A", ...)

comment:21 Changed at 2017-02-07T19:48:14Z by Basje

Yes, that is correct. But I forget to mention that you should disable the grouping of folders via the add-on settings.

Last edited at 2017-02-07T19:48:41Z by Basje (previous) (diff)

comment:22 Changed at 2017-02-07T22:30:32Z by popcornmix

Okay on Pi3 with 50Hz display (this will make a difference)

With unchanged code it takes 36.104s 40.575s 35.507s http://pastebin.com/fqmbAA5w

With sleepTime forced to 10ms it takes 32.800s 33.875s 32.288s http://pastebin.com/T2bXrpfH

With sleepTime forced to 20ms it takes 16.644s 16.961s 15.098s http://pastebin.com/PChqtKkQ

With sleepTime forced to 40ms it takes 8.223s 8.365s 8.325s http://pastebin.com/yRrT234v

With sleepTime forced to 80ms it takes 5.576s 6.041s 5.386s http://pastebin.com/7mzuBJxM

With sleepTime forced to 160ms it takes 5.467s 5.716s 4.558s http://pastebin.com/8vL8ALe4

With sleepTime alowed to vary with a max of 80ms it takes 6.438s 5.906s 6.645s http://pastebin.com/Hcd6jhQ7

Looking at the log for the first case you find it drops back to 2ms a number of times which means it is somewhat slower than a fixed 10ms.

I added this commit to avoid that occurring: https://github.com/popcornmix/xbmc/commit/e743ca3382c479d58f0e2890148e0297880febfc

By 80ms you are getting to diminishing returns. A longer delay is about 8 times faster than the default.

comment:23 Changed at 2017-02-08T10:11:20Z by asplundj

Does this commit mean that the time will be reduced from 37 s to 33 s? or will it be reduced to 6 seconds?

comment:25 Changed at 2017-02-08T11:58:36Z by Basje

I like the second solution with the

unsigned int max_sleep = m_pPlayer->IsPlayingVideo() && !m_pPlayer->IsPausedPlayback() ? 10 : 80;

But it does depend on why this changes was done in the first place? If it was to solve playback issues, then yes, this is nice.

comment:26 Changed at 2017-02-08T13:40:25Z by Basje

I checked my OSMC builds on and changing it to 32ms reduces loading to about 6-7 seconds. Which is much better:

10:10:49.619 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1051 >> 2 = 262)
10:10:49.759 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1231 >> 2 = 307)
10:10:49.906 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1411 >> 2 = 352)
10:10:50.054 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1584 >> 2 = 396)
10:10:50.202 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1747 >> 2 = 436)
10:10:50.342 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1927 >> 2 = 481)
10:10:50.481 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 2107 >> 2 = 526)
10:10:50.744 T:1958945712  NOTICE: Sleeping for external calls for 2 ms (external: 0 >> 2 = 0)
10:10:50.854 T:1958945712  NOTICE: Sleeping for external calls for 3 ms (external: 12 >> 2 = 3)
10:10:50.965 T:1958945712  NOTICE: Sleeping for external calls for 7 ms (external: 31 >> 2 = 7)
10:10:51.079 T:1958945712  NOTICE: Sleeping for external calls for 17 ms (external: 68 >> 2 = 17)
10:10:51.205 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 163 >> 2 = 40)
10:10:51.352 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 343 >> 2 = 85)
10:10:51.492 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 523 >> 2 = 130)
10:10:51.632 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 703 >> 2 = 175)
10:10:51.772 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 888 >> 2 = 222)
10:10:51.920 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1071 >> 2 = 267)
10:10:52.060 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1243 >> 2 = 310)
10:10:52.200 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1428 >> 2 = 357)
10:10:52.340 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1603 >> 2 = 400)
10:10:52.488 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1788 >> 2 = 447)
10:10:52.627 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 1958 >> 2 = 489)
10:10:52.774 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 2137 >> 2 = 534)
10:10:52.921 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 2316 >> 2 = 579)
10:10:53.069 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 2492 >> 2 = 623)
10:10:53.209 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 2676 >> 2 = 669)
10:10:53.348 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 2851 >> 2 = 712)
10:10:53.489 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 3036 >> 2 = 759)
10:10:53.636 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 3216 >> 2 = 804)
10:10:53.775 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 3402 >> 2 = 850)
10:10:53.915 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 3587 >> 2 = 896)
10:10:54.055 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 3774 >> 2 = 943)
10:10:54.206 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 3906 >> 2 = 976)
10:10:54.349 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 4038 >> 2 = 1009)
10:10:54.492 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 4163 >> 2 = 1040)
10:10:54.635 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 4278 >> 2 = 1069)
10:10:54.784 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 4410 >> 2 = 1102)
10:10:54.932 T:1958945712  NOTICE: Sleeping for external calls for 32 ms (external: 4534 >> 2 = 1133)

Compiling the https://github.com/popcornmix/xbmc/commit/356e1a0144cf236675d3a3f7bace2d3add2ffef0 patch now to see how that ends up.

comment:27 Changed at 2017-02-08T22:04:50Z by Basje

I applied the https://github.com/popcornmix/xbmc/commit/356e1a0144cf236675d3a3f7bace2d3add2ffef0 on my OSMC on rPi2 and the results are very good:

23:01:44.651 T:1958515632  NOTICE: Sleeping for external calls for 2 ms (external: 0 >> 2 = 0)
23:01:44.764 T:1958515632  NOTICE: Sleeping for external calls for 3 ms (external: 12 >> 2 = 3)
23:01:44.878 T:1958515632  NOTICE: Sleeping for external calls for 7 ms (external: 31 >> 2 = 7)
23:01:44.995 T:1958515632  NOTICE: Sleeping for external calls for 18 ms (external: 72 >> 2 = 18)
23:01:45.123 T:1958515632  NOTICE: Sleeping for external calls for 43 ms (external: 175 >> 2 = 43)
23:01:45.276 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 427 >> 2 = 106)
23:01:45.467 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 907 >> 2 = 226)
23:01:45.658 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 1387 >> 2 = 346)
23:01:45.849 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 1831 >> 2 = 457)
23:01:46.040 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 2292 >> 2 = 573)
23:01:46.231 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 2772 >> 2 = 693)
23:01:46.423 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 3247 >> 2 = 811)
23:01:46.613 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 3696 >> 2 = 924)
23:01:46.804 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 4171 >> 2 = 1042)
23:01:46.995 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 4651 >> 2 = 1162)
23:01:47.187 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 5136 >> 2 = 1284)
23:01:47.379 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 5618 >> 2 = 1404)
23:01:47.570 T:1958515632  NOTICE: Sleeping for external calls for 80 ms (external: 6078 >> 2 = 1519)

Would this patch be a possible solution?

comment:28 Changed at 2017-02-10T13:38:22Z by popcornmix

Let me submit a PR, so what the consensus is.

comment:29 Changed at 2017-02-10T15:09:17Z by jaqb

Does this patch have impact on the code I posted in ticket:17293 ?

Edit: I have tested your patch with my sample code and it seems it doesn't have a positive impact when compared to Krypton final.

Last edited at 2017-02-10T16:45:37Z by jaqb (previous) (diff)

comment:30 Changed at 2017-02-10T18:26:12Z by Basje

I compared that exact same patch on my rPi went back to the normal performance. Same on PC. But only if no video is playing.

comment:31 Changed at 2017-02-10T19:05:29Z by jaqb

I was talking about my sample code, you can also test it on your rPi and see what I mean.

http://paste2.org/FJIgk4kf

Last edited at 2017-02-10T19:06:19Z by jaqb (previous) (diff)

comment:32 Changed at 2017-02-10T19:07:35Z by popcornmix

@Basje My patch deliberately only applied when video is not playing otherwise you are sure to get stuttery video. Is fast updates when playing is playing a critical use case?

comment:33 Changed at 2017-02-10T19:48:24Z by Basje

@popcornmix I know, and I am completely fine with that! During playback duration is of no importance. So I vote for your fix. Do you have a PR?

comment:35 Changed at 2017-02-14T19:55:50Z by Basje

Thanks all for the help and efforts in resolving this issue.

comment:36 Changed at 2017-02-14T20:18:00Z by Martijn

  • Milestone changed from Pending / Future to 17.1 "Krypton"
  • Resolution set to Fixed
  • Status changed from new to closed
Note: See TracTickets for help on using tickets.