Load times

[adamosborne83]

Skin section

Home Widgets

Current Behavior

Not a bug, just more curious in ways of workings.
The first video below is Kodi running from start to first widget loading in Ah2, total load time is around 35 seconds.
2nd video is AF load to first widget is a good 30 seconds more.
I have exactly the same amount of widgets on both set ups.
I'm just curious, is there a lot more going on in the background in AF to make the additional load time.

Expected Behavior

Just curious

Steps To Reproduce

I know both skins are very very different, but people mention it's faster.
I'm happy to provide logs if required.

I use FireCube version 3 is that makes any difference, I know you don't use android

Happy to contribute more if you'd like me to get you one haha ...

Screenshots and Additional Info

firetv_2023-11-05_10_18_31.mp4

firetv_2023-11-05_10_36_12.mp4

Checklist

• I have made a separate issue for each bug that I am reporting.
• I have searched the issues and this bug has not been reported.
• I am using the most recent skin version.
• I have confirmed that this bug does not occur in the default skin.

[jurialmunkey]

Skins dont affect how fast or slow content loads. This is a complete myth that one skin might be "faster" to load content than another.

There's a ton of different reasons a plugin might take longer to load at a different time, none of which relate to the skin used. For instance, I can see different items in both lists, some of those items might be cached, others might not. A cached item is going to load much faster than one which isnt.

Unless you can replicate exactly the same conditions each time (which is impossible) then these types of comparisons are largely meaningless.

[jurialmunkey]

In both videos I can see that the spotlight loads at practically the same time.

The list you are comparing at the bottom is just about the worse possible list to use for comparison. It has completely different items in it, relies on Trakt account authorisation and a history sync, and requires the TMDb server to generate recommendations based on a randomised movie.. All these things could have wildly different response times depending on the state of each server and how recently each of these bits of data were access. In particular, Trakt authorisation and sync times can vary significantly.

[jurialmunkey]

BTW you can use the discussions for general questions etc. that are not specific bugs or feature requests.
https://github.com/jurialmunkey/skin.arctic.fuse/discussions

I've converted this thread to a discussion since it is question.

[adamosborne83]

Thank you.

[jurialmunkey]

If you're using TMDbHelper there is an option you can enable in TMDbHelper Settings under Expert called:
Debug > Log timer reports for directories

That will then give you a report of timing for each list that opens so you can see exactly where the slow down was. Note it will generate a lot of log spam, so it shouldn't be left on during normal usage -- only use it for debugging.

It generates a report per widget like so:

DIRECTORY TIMER REPORT
list_slug=latest-tv-shows&user_slug=garycrawfordgc&tmdb_id=None&info=trakt_userlist&sort_by=added&sort_how=desc&widget=true&reload=
------------------------------
get_list       :   0.203 sec
get_kodi       :   0.174 sec
add_items      :   5.853 sec
--build        :   4.866 sec
- item_api    :   0.264 sec avg |   4.825 sec max |  39
- item_ftv    :   0.147 sec avg |   0.304 sec max |   5
- item_tmdb   :   4.784 sec avg |   4.784 sec max |   1
--sync         :   None
--make         :   0.528 sec
- item_abc    :   None
- item_xyz    :   0.479 sec avg |   0.520 sec max |  39
------------------------------
Total          :   7.235 sec

item_api:
0.124  0.129  0.139  0.115  0.138  0.134  0.137  0.137  0.162  0.164  0.158  0.177  0.113  0.107  0.185  0.113  0.167  0.140  0.221  0.182  0.163  0.116  0.130  0.098  0.159  0.188  0.146  0.132  0.084  0.097  0.137  0.084  0.116  0.069  0.101  0.060  0.308  0.331  4.825 

item_ftv:
0.052  0.050  0.054  0.273  0.304 

item_tmdb:
4.784 

item_xyz:
0.465  0.453  0.461  0.451  0.452  0.470  0.468  0.457  0.463  0.461  0.471  0.460  0.470  0.471  0.475  0.460  0.459  0.465  0.473  0.475  0.474  0.464  0.469  0.469  0.474  0.483  0.482  0.486  0.489  0.501  0.498  0.508  0.512  0.507  0.512  0.520  0.509  0.519  0.520 

In this example, we can see most of the process did not take long. However, there was one random item which took the TMDb API server a long time to return (4.784 seconds) and that held up the loading.

Most likely what happened here was I triggered their server rate limiter -- this was on startup, so I had a lot of widgets all loading at the same time, so lots of requests all being made at once.

Here's a more detailed explainer of each row:

get_list
Time to get list of item IDs from Trakt (or disk if cached). In the above that didn't take long, likely because it was already cached to disk.

get_kodi
Time to retrieve additional details from Kodi library database.

add_items
Total time to retrieve all additional details from various APIs (or disk if cached) and then construct them and add to the container. We can see this took the bulk of time at 5.83 seconds.

build
The total time it took to do detailed item lookups for each item and construct the metadata. Below it lists a breakdown of this process.

item_api
This is the per item average and max for each item in the build process. This is process is threaded, so each item is done side by side. The logger only logs values over a threshold of 0.05 seconds. We can see there were 39 items over this threshold (last number in row).

On average, each item only took 0.26 seconds. However, we can also see that one item maxed out at 4.784 seconds which accounts for basically all the 4.866 seconds of build time.

item_tmdb / item_ftv
These are additional breakdowns which specifically list online lookups from APIs (i.e. uncached items or details needing refreshing due to cache expiry). At the very bottom of the report we can also see the per item timings.

Here we can see that the TMDb server was holding things up for that one item with a 4.78 second wait.

sync
Time it took to sync my watched and progress data from Trakt. This took no time in this case because it was already cached from another widget loading.

make
Time it takes to configure the items as Kodi ListItems so that they can be added to the widget.

Here's another example that shows sync time:

DIRECTORY TIMER REPORT
list_slug=imdb-top-rated-tv-shows&user_slug=justin&tmdb_id=None&info=trakt_userlist&sort_by=rank&sort_how=asc&widget=true&reload=
------------------------------
get_list       :   0.031 sec
get_kodi       :   None
add_items      :   2.456 sec
--build        :   0.085 sec
- item_api    :   0.050 sec avg |   0.050 sec max |   2
- item_ftv    :   None
--sync         :   1.111 sec
--make         :   0.964 sec
- item_abc    :   None
- item_xyz    :   0.615 sec avg |   0.948 sec max |  14
------------------------------
Total          :   2.506 sec

item_api:
0.050  0.050 

item_xyz:
0.053  0.051  0.053  0.052  0.053  0.934  0.916  0.909  0.917  0.911  0.929  0.937  0.948  0.945 

In this list we can see everything loaded very fast. Likely all already cached since I use this list a lot and it doesnt change much.

However, we can see the sync time taking up a big chunk. That's why the first list didn't have sync time -- because the sync happened during this widget loading instead.

And finally one more example to show a Trakt list which requires a lot of additional data.
This is my Trakt "To Watch" list which combines Watchlist with Up Next, so it uses a lot of sync points.

DIRECTORY TIMER REPORT
info=trakt_towatch&tmdb_type=tv&widget=true&reload=
------------------------------
get_list       :   5.116 sec
get_kodi       :   None
add_items      :   0.585 sec
--build        :   0.462 sec
- item_api    :   0.393 sec avg |   0.449 sec max |  15
- item_ftv    :   0.385 sec avg |   0.412 sec max |   3
--sync         :   None
--make         :   0.091 sec
- item_abc    :   0.050 sec avg |   0.051 sec max |   3
- item_xyz    :   0.052 sec avg |   0.052 sec max |   1
------------------------------
Total          :   5.710 sec

item_api:
0.386  0.378  0.377  0.376  0.380  0.386  0.379  0.379  0.387  0.386  0.407  0.412  0.394  0.422  0.449 

item_ftv:
0.355  0.390  0.412 

item_abc:
0.050  0.050  0.051 

item_xyz:
0.052 

You can see in this list that the items themselves barely took any time. That's because most of them are already cached.

However, the get_list took up the bulk of the time. That's because this list involves multiple Trakt syncs (watchlist, history, calculation of inprogress per item). Since this was first load, this data likely needed to re-sync due to activity changes.

[adamosborne83]

Thank you for your thorough explanation, I will have a look at this later.