firsttris / plugin.video.sendtokodi

:tv: plays various stream sites on kodi using youtube-dl
MIT License
126 stars 28 forks source link

Improve performance of parsing playlists #15

Closed anohren closed 2 years ago

anohren commented 5 years ago

I need help to hypothesise on whether the following issue is really within the SendToKodi Kodi plugin, or if it's external. I don't have that much insight into the Kodi plugin mechanics.

Here's the debug log of what happens when I send a Youtube playlist URL to Kodi. The results are basically a nonresponsive Kodi displaying a spinner for over a minute, and after that it just restarts the first video in the playlist repeatedly for about 5-10 minutes while rendering at 9 FPS (audio works fine). After all that the performance is restored, and the video is actually allowed to continue playing.

(This is the URL I tested with: https://www.youtube.com/watch?v=BXXgbGwEnYw&list=PLc7fktTRMBox4cnUiShLPKg_-em5MJNP1&index=16&t=0s )

What caught my eye in the log was the following:

1. It takes forever before playback starts

Look at the timestamps for this line:

2019-10-04 23:32:29.408 T:1714189024 DEBUG: [download] Downloading video 1 of 36

...and compare it to the time of this line:

2019-10-04 23:33:59.418 T:1714189024 DEBUG: [download] Downloading video 36 of 36

For 90 seconds there's nothing on screen except for a spinner, and Kodi is unresponsive. The question is, why is it spending minutes downloading the page of every single video in the playlist instead of starting playback of the first item immediately? Something's wrong...

2. It generates huge amounts of JSON

Does it have any connection to the described issues? It seems to happen for only a few seconds so maybe not:

Timestamp of first line: 2019-10-04 23:34:02.499 T:1714189024 DEBUG: plugin.video.sendtokodi:

Timestamp of last line: 2019-10-04 23:34:06.781 T:1714189024 DEBUG: plugin.video.sendtokodi:

This might be completely irrelevant ā€” I did enable JSON API logging beforehand, so perhaps this log output is because of that and is completely normal.

3. A lot of downloading and processing of webpages

In the third "section" of the log, after all the JSON, there seems to be lots of downloading and processing of webpages going on again:

Here, minutes after sending the URL to Kodi, the playlist is being downloaded again (?):

2019-10-04 23:34:22.176 T:1116975840   DEBUG: [youtube:playlist] Downloading playlist PLc7fktTRMBox4cnUiShLPKg_-em5MJNP1 - add --no-playlist to just download video BXXgbGwEnYw
2019-10-04 23:34:22.177 T:1116975840   DEBUG: .
2019-10-04 23:34:22.177 T:1116975840   DEBUG: [youtube:playlist] PLc7fktTRMBox4cnUiShLPKg_-em5MJNP1: Downloading webpage

It then downloads webpages pretty much every second:

2019-10-04 23:34:24.984 T:1116975840   DEBUG: [youtube] 44iu0NPnvjY: Downloading webpage
[...]
2019-10-04 23:34:25.666 T:1116975840   DEBUG: [youtube] 44iu0NPnvjY: Downloading video info webpage
[...]
2019-10-04 23:34:26.599 T:1116975840   DEBUG: [youtube] g3-MSlk1AY8: Downloading webpage
[...]
2019-10-04 23:34:27.276 T:1116975840   DEBUG: [youtube] g3-MSlk1AY8: Downloading video info webpage
[...]
2019-10-04 23:34:28.148 T:1116975840   DEBUG: [youtube] PYOsevW3KdA: Downloading webpage

Maybe that's what causing the performance hit. Any hunch as to why all this work is happening, and at this frequency?

firsttris commented 5 years ago

What kind of device are you using for Kodi?

Because i know parsing a playlist with 36 items could take a while...

anohren commented 5 years ago

It's a Raspberry Pi 3, running OSMC.

Yeah, it seemingly parses every single page in the playlist before starting the first item. If that wasn't bad enough you don't even end up with a working playlist in the end; the Kodi playlist ends up malformed to the point that interacting with it instantly discards it. It has no titles for its entries and the duration of almost every entry is the same.

I tried playing another entry in the playlist using the GUI but then Kodi just started listing my local library there instead, and then Kodi acted as though there was nothing enqueued anymore.

I think it's reasonable to expect to be able to send playlists with well over 1000 entries. Luckily I haven't tried that yet!

firsttris commented 5 years ago

will test and report back

anohren commented 4 years ago

Did you learn anything? Does it do a lot of unnecessary work for you too?

firsttris commented 4 years ago

acutally i forgot to test, will find time soon

anohren commented 4 years ago

I just sent a URL of what I thought was a youtube video, had Kodi spin forever, forgot about it, and then had videos start playing about 30 minutes later šŸ™‚ It turned out to have gone through the channel's entire video list.

firsttris commented 4 years ago

Hey @anohren

sorry that i had not found time to check on your issue.

if you send very big playlists or channels - it can take (depending on your machine) very long time to parse all the streams.

e.g. the example link you posted (form Chris Titus Tech) has about 43 streams in its playlist. which could take very long (depending on your machine).

regards Tristan

anohren commented 4 years ago

Hi. No worries. Iā€™m just keeping the issue alive. Iā€™m well aware that it takes a long time ā€” that is the whole issue after all šŸ˜‰

anohren commented 4 years ago

@firsttris I profiled the addon when sending a Youtube playlist URL with 29 entries. This small playlist took 55 seconds (!) to parse:

Thu May 28 15:32:09 2020    profiling_stats

         2946276 function calls (2793454 primitive calls) in 55.010 seconds

   Ordered by: cumulative time
   List reduced from 750 to 10 due to restriction <10>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     30/1    0.021    0.001   52.064   52.064 /home/osmc/.kodi/addons/plugin.video.sendtokodi/youtube_dl/YoutubeDL.py:771(extract_info)
     59/1    0.011    0.000   40.451   40.451 /home/osmc/.kodi/addons/plugin.video.sendtokodi/youtube_dl/YoutubeDL.py:841(process_ie_result)
       30    0.080    0.003   37.448    1.248 /home/osmc/.kodi/addons/plugin.video.sendtokodi/youtube_dl/extractor/common.py:524(extract)
       29    2.021    0.070   36.689    1.265 /home/osmc/.kodi/addons/plugin.video.sendtokodi/youtube_dl/extractor/youtube.py:1683(_real_extract)
       31    0.003    0.000   22.368    0.722 /home/osmc/.kodi/addons/plugin.video.sendtokodi/youtube_dl/extractor/youtube.py:267(_download_webpage_handle)
       31    0.003    0.000   22.365    0.721 /home/osmc/.kodi/addons/plugin.video.sendtokodi/youtube_dl/extractor/common.py:650(_download_webpage_handle)
       31    0.003    0.000   22.015    0.710 /home/osmc/.kodi/addons/plugin.video.sendtokodi/youtube_dl/extractor/common.py:595(_request_webpage)
       31    0.001    0.000   21.929    0.707 /home/osmc/.kodi/addons/plugin.video.sendtokodi/youtube_dl/YoutubeDL.py:2234(urlopen)
       31    0.008    0.000   21.903    0.707 /usr/lib/python2.7/urllib2.py:411(open)
     2262    0.030    0.000   18.471    0.008 /usr/lib/python2.7/ssl.py:759(recv)

It's basically spending 52 out of the 55 seconds in a single call to YoutubeDL.py:771(extract_info) (and 30 recursive calls, accounting for the 29 entries plus, I'm guessing, the playlist itself).

firsttris commented 4 years ago

hey @anohren

if your running on a raspberrypi 3 your processing power is limited, i think the bottleleck is the cpu.

maybe you have a more powerfull computer where you can repeat your test?

anohren commented 4 years ago

Yes, it is limited, but hardly to this extent. Parsing a list of 30 items should be done by any Rpi in a second or so, even if it's on a webpage. Not a minute. That just means we're doing loads and loads of unneccesary work.

What we need is a new strategy. I looked at it a bit (and asked youtube-dl directly, who said the performance was "reasonable"), and intuitively I would say that the solution should be this:

ydl_opts = {
    'extract_flat': 'in_playlist'
}

That skips any attempt to "resolve" every single item in the list for almost no benefit and at a gigantic cost. The problem then becomes: how do we get called back whenever Kodi tries to play a queued item that contains (if possible) only a Youtube URL? That should be our goal. That way every item can be resolved lazily.

This way we could support playlists of 1000 entries, easily.

Do you know of a way to define a URL scheme that makes Kodi call the addon upon playing an item? Or another way of doing it?

anohren commented 4 years ago

@firsttris I did the following test, which should allegedly have worked, but instead results in crashing Kodi entirely:

     pl = xbmc.PlayList(1)
    pl.clear()
    xbmc.PlayList(1).add("plugin://plugin.video.sendtokodi/?KBkWoK66fus")
    xbmc.Player().play(pl)

Feels like standing on top of a house of cards šŸ™‚

anohren commented 4 years ago

Well, I've been told you shouldn't use xbmc.Player from a plugin addon, but only from a script addon. Still seems possible to enqueue the items but they can't be played back, neither by the plugin nor manually.

I don't know what a conversion from a "plugin" to a "script" would entail.