firsttris / plugin.video.sendtokodi

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

WinError 123 on all YouTube videos #94

Closed sgoffman closed 1 year ago

sgoffman commented 1 year ago

Description of the bug

Any attempt to send a YouTube video via "Play On Kodi" (through Kore) results in "SendToKodi error: See log for more details". The exception from the log: Error Contents: [WinError 123] The filename, directory name, or volume label syntax is incorrect: 'C:\Kodi\plugin:\plugin.video.sendtokodi\yt_dlp_plugins'

Manually creating the "yt_dlp_plugins" folder it's looking for doesn't resolve the issue.

Steps to reproduce

  1. On Android, open a YouTube video.
  2. Tap "Share"
  3. Select "Kore Play on Kodi"

Version and plattform:

Kodi log

``` 2023-06-28 11:36:41.667 T:17756 INFO : JSONRPC Server: New connection added 2023-06-28 11:36:41.735 T:25364 INFO : initializing python engine. 2023-06-28 11:36:42.228 T:25364 ERROR : EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<-- - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS! Error Type: Error Contents: [WinError 123] The filename, directory name, or volume label syntax is incorrect: 'C:\\Kodi\\plugin:\\plugin.video.sendtokodi\\yt_dlp_plugins' Traceback (most recent call last): File "C:\Kodi\portable_data\addons\plugin.video.sendtokodi\service.py", line 246, in from lib.yt_dlp import YoutubeDL File "C:\Kodi\portable_data\addons\plugin.video.sendtokodi\lib\yt_dlp\__init__.py", line 20, in from .downloader.external import get_external_downloader File "C:\Kodi\portable_data\addons\plugin.video.sendtokodi\lib\yt_dlp\downloader\__init__.py", line 26, in from .external import FFmpegFD, get_external_downloader File "C:\Kodi\portable_data\addons\plugin.video.sendtokodi\lib\yt_dlp\downloader\external.py", line 12, in from ..postprocessor.ffmpeg import EXT_TO_OUT_FORMATS, FFmpegPostProcessor File "C:\Kodi\portable_data\addons\plugin.video.sendtokodi\lib\yt_dlp\postprocessor\__init__.py", line 38, in _PLUGIN_CLASSES = load_plugins('postprocessor', 'PP') File "C:\Kodi\portable_data\addons\plugin.video.sendtokodi\lib\yt_dlp\plugins.py", line 138, in load_plugins for finder, module_name, _ in iter_modules(name): File "C:\Kodi\portable_data\addons\plugin.video.sendtokodi\lib\yt_dlp\plugins.py", line 122, in iter_modules pkg = importlib.import_module(fullname) File "C:\Kodi\system\python\Lib\importlib\__init__.py", line 127, in import_module return _bootstrap._gcd_import(name[level:], package, level) File "", line 1014, in _gcd_import File "", line 991, in _find_and_load File "", line 971, in _find_and_load_unlocked File "", line 914, in _find_spec File "C:\Kodi\portable_data\addons\plugin.video.sendtokodi\lib\yt_dlp\plugins.py", line 99, in find_spec search_locations = list(map(str, self.search_locations(fullname))) File "C:\Kodi\portable_data\addons\plugin.video.sendtokodi\lib\yt_dlp\plugins.py", line 89, in search_locations if candidate.is_dir(): File "C:\Kodi\system\python\Lib\pathlib.py", line 1403, in is_dir return S_ISDIR(self.stat().st_mode) File "C:\Kodi\system\python\Lib\pathlib.py", line 1194, in stat return self._accessor.stat(self) OSError: [WinError 123] The filename, directory name, or volume label syntax is incorrect: 'C:\\Kodi\\plugin:\\plugin.video.sendtokodi\\yt_dlp_plugins' -->End of Python script error report<-- 2023-06-28 11:36:42.238 T:22644 INFO : CActiveAESink::OpenSink - initialize sink 2023-06-28 11:36:42.248 T:25364 INFO : Python interpreter stopped ``` **Additional context** Switching to youtube-dl resolver seems to work ("seems to" because it did hang on the "Working..." dialog on my first test with it).
nullket commented 1 year ago

I have no idea what that exactly means. And I would not know why there is a ":" in C:\\Kodi\\plugin:\... and why the path is not C:\Kodi\portable_data\addons\plugin.video.sendtokodi\

So I assume this is a yt_dlp issue. Lets track is down a bit:

sgoffman commented 1 year ago

1) This is my first installation of sendtokodi, so can't compare to previous versions, sorry. 2) I'm using https://www.youtube.com/watch?v=bWLGTB0coec as my test video. 3) I just tested with yt-dlp 2023.06.22 standalone on the same device, and it worked. 4) Haven't tried any other websites; I'll experiment with some later (or if you have a known-working link you would like me to test with, let me know).

nullket commented 1 year ago

Here is a random link that works (using even input stream adapative) https://www.arte.tv/de/videos/047935-000-A/denkmaeler-der-ewigkeit/ Basically most websites with media should work (yt-dlp states all supported sites on their github repo).

Maybe the issue is that you run kodi in portable mode? Could you try to "normally" install kodi, add the plugin and try again? I do not have a Windows machine so I can not try to reproduce your issue.

I do not know with fit you are with python but you could try to debug the issue yourself (e.g. starting a python interpreter in ther folder of the plugin and try to run from lib.yt_dlp import YoutubeDL)

anohren commented 1 year ago

And I would not know why there is a ":" in C:\\Kodi\\plugin:\...

To me it looks like yt-dlp fails to load because Python is being handed a malformed file path. That file path looks as though some helpful routine has turned the URL plugin://plugin.video.sendtokodi into the nonsensical plugin:\\plugin.video.sendtokodi in an effort to placate Windows (which of course becomes plugin:\plugin.video.sendtokodi after passing through some routine that resolves the escaping \\). Surely that hasn't been done by yt-dlp.

Has this been done by Kodi or Python? My guess would be Kodi. In either case, Kodi clearly has the responsibility to convert "plugin://" URLs into something that makes sense, before passing it along to Python.

You would think that both Kodi and Python, as cross-platform software, has as their goal to abstract away differences in things like path component separators, so this is my guess.

sgoffman commented 1 year ago

I tried running a local install with the same result (error due to 'C:\Kodi\plugin:\plugin.video.sendtokodi\yt_dlp_plugins').

What result should I expect from 'lib.yt_dlp import YoutubeDL'? I ran that in the Py interpreter, but there was no output (nor error).

It does appear to be a Windows-specific problem: I tested on a Pi running OSMC and the same install/setup of Kodi 19.1, and the plugin worked fine with yt-dlp.

I agree with anohren that it seems like Kodi is mangling the path in an attempt to "fix" it for Windows... except that I can't see why that would only happen when using yt-dlp and NOT youtube-dl.

nullket commented 1 year ago

I totally agree that this is mostly a kodi/integrated python issue.

... except that I can't see why that would only happen when using yt-dlp and NOT youtube-dl.

Maybe this happens due to the usage of importlib (which is not used directly in youtube-dl). But on the other hand based on the documentation importlib.load_module() seems to be very similar to the regular import statement (I have no experience with importlib) and all this does is to load the modules. The dangling of the path might happen much earlier.

In case you want to debug a bit you could try to print candidate_locations and sys.path right before the line pkg = importlib.import_module(fullname). Note that printing wont be displayed so you either need to try to log this to kodi (import xbmc and then log) or write the content to a file or similar.

What result should I expect from 'lib.yt_dlp import YoutubeDL'? I ran that in the Py interpreter, but there was no output (nor error).

I would expect to simply output nothing. This confirms somewhat that kodi or its integrated python interpreter is at fault.

anohren commented 1 year ago

Here are the conversion functions: https://github.com/xbmc/xbmc/blob/b3ad281818609488336c73d295e5d08c460d0908/xbmc/platform/win32/WIN32Util.cpp#L431

Here's the python execution function: https://github.com/xbmc/xbmc/blob/b3ad281818609488336c73d295e5d08c460d0908/xbmc/interfaces/python/PythonInvoker.cpp#L139

A Kodi Debug log would probably print the paths used, but I'm not sure. Got a bit tired of reading the Kodi source since there are no explanations of what's what (I'm supposed to already know the responsibilities of XBPython, without being told? ...)

nullket commented 1 year ago

@sgoffman could you test kodi 20? Especially 20.2 mentioned something about fixing the import path

A fix was backported that mainly affected Linux platforms: the path used when searching for modules was appending Kodi script paths at the end of the list

from https://kodi.tv/article/kodi-20-2-nexus-release/

anohren commented 1 year ago

Sounds like they just intended to insert it further to the front of the list though, judging by the rest of the sentence:

...and therefore could potentially find system Python scripts/modules instead of Kodi-specific scripts/modules

sgoffman commented 1 year ago

So I've tested with Kodi 20.2, and good news/bad news:

Good news: No more plugin path error, yay!

Bad news: Most videos fail to play with yt-dlp config (but still work fine with youtube-dl config). They are passed and parsed correctly by the plugin, Kodi report that the video is playing, but it doesn't actually play.

The only potential cause I see in the log is the single line "AddOnLog: inputstream.adaptive: Unsupported codec in stream ID: " (doesn't actually id the codec or the stream at fault).

I tested an older video (one I uploaded 5 years ago: 'https://www.youtube.com/watch?v=xJPTuitaYE4') and it played fine. All others I tested failed to play.

I used standalone yt-dlp to download the .webm for my working test case and a failing test case, and they both report using the VP90 codec.

Again, this still is not a show-stopper bug since simply switching to youtube-dl fixes it.

Log for yt-dlp playback:

2023-07-03 10:21:19.776 T:28964    info <general>: JSONRPC Server: Disconnection detected
2023-07-03 10:21:45.263 T:2180     info <general>: ES: Client  from ::ffff:192.168.1.102 timed out
2023-07-03 10:21:50.465 T:28964    info <general>: JSONRPC Server: New connection added
2023-07-03 10:21:52.750 T:33376    info <general>: CActiveAESink::OpenSink - initialize sink
2023-07-03 10:21:52.753 T:23444    info <general>: plugin.video.sendtokodi: found original manifest: https://manifest.googlevideo.com/api/manifest/hls_variant/expire/1688426511/ei/rwOjZM_pINvjkgb_y4WwAg/ip/72.219.179.243/id/bdc1b703b891ecd2/source/youtube/requiressl/yes/playback_host/rr4---sn-a5msenek.googlevideo.com/mh/wJ/mm/31%2C29/mn/sn-a5msenek%2Csn-a5meknsd/ms/au%2Crdu/mv/m/mvi/4/pl/18/tx/24379858/txs/24379852%2C24379853%2C24379854%2C24379855%2C24379856%2C24379857%2C24379858/hfr/1/demuxed/1/tts_caps/1/maudio/1/gcr/us/initcwndbps/1602500/vprv/1/go/1/mt/1688404413/fvip/1/nvgoi/1/short_key/1/ncsapi/1/keepalive/yes/fexp/24007246/beids/24350018/dover/13/itag/0/playlist_type/DVR/sparams/expire%2Cei%2Cip%2Cid%2Csource%2Crequiressl%2Ctx%2Ctxs%2Chfr%2Cdemuxed%2Ctts_caps%2Cmaudio%2Cgcr%2Cvprv%2Cgo%2Citag%2Cplaylist_type/sig/AOq0QJ8wRAIgOoy3T-SbnEJLfAj3TLiMAftfMVxRbXwJpapovXxnfmECIG-Hnc9ki0uAvJopfsYIly2QtJzR3ruWmcYAUKKTPsEf/lsparams/playback_host%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Cinitcwndbps/lsig/AG3C_xAwRQIhAOn9CxtfRdX0SbBiUlgRUvgcTleUmK5ba3Gs07bg2uXzAiAjBgz4y7TwqMHyt_3rUnZuo0TgYbvqpenzJvqRUMLQCw%3D%3D/file/index.m3u8
2023-07-03 10:21:52.808 T:23444    info <general>: plugin.video.sendtokodi: creating list item for url https://manifest.googlevideo.com/api/manifest/hls_variant/expire/1688426511/ei/rwOjZM_pINvjkgb_y4WwAg/ip/72.219.179.243/id/bdc1b703b891ecd2/source/youtube/requiressl/yes/playback_host/rr4---sn-a5msenek.googlevideo.com/mh/wJ/mm/31%2C29/mn/sn-a5msenek%2Csn-a5meknsd/ms/au%2Crdu/mv/m/mvi/4/pl/18/tx/24379858/txs/24379852%2C24379853%2C24379854%2C24379855%2C24379856%2C24379857%2C24379858/hfr/1/demuxed/1/tts_caps/1/maudio/1/gcr/us/initcwndbps/1602500/vprv/1/go/1/mt/1688404413/fvip/1/nvgoi/1/short_key/1/ncsapi/1/keepalive/yes/fexp/24007246/beids/24350018/dover/13/itag/0/playlist_type/DVR/sparams/expire%2Cei%2Cip%2Cid%2Csource%2Crequiressl%2Ctx%2Ctxs%2Chfr%2Cdemuxed%2Ctts_caps%2Cmaudio%2Cgcr%2Cvprv%2Cgo%2Citag%2Cplaylist_type/sig/AOq0QJ8wRAIgOoy3T-SbnEJLfAj3TLiMAftfMVxRbXwJpapovXxnfmECIG-Hnc9ki0uAvJopfsYIly2QtJzR3ruWmcYAUKKTPsEf/lsparams/playback_host%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Cinitcwndbps/lsig/AG3C_xAwRQIhAOn9CxtfRdX0SbBiUlgRUvgcTleUmK5ba3Gs07bg2uXzAiAjBgz4y7TwqMHyt_3rUnZuo0TgYbvqpenzJvqRUMLQCw%3D%3D/file/index.m3u8
2023-07-03 10:21:52.818 T:23444 warning <general>: Setting most video properties through ListItem.setInfo() is deprecated and might be removed in future Kodi versions. Please use the respective setter in InfoTagVideo.
2023-07-03 10:21:53.054 T:22672    info <general>: VideoPlayer::OpenFile: plugin://plugin.video.sendtokodi/?https://youtu.be/vcG3A7iR7NI
2023-07-03 10:21:53.121 T:22900    info <general>: Creating InputStream
2023-07-03 10:21:53.123 T:22900    info <general>: AddOnLog: inputstream.adaptive: [Repr. chooser] Resolution set: 1920x1200, max allowed: 1920x1200, Adjust refresh rate: 0
2023-07-03 10:21:53.345 T:22900    info <general>: AddOnLog: inputstream.adaptive: Successfully parsed manifest file (Periods: 1, Streams in first period: 3, Type: live)
2023-07-03 10:21:53.345 T:22900 warning <general>: AddOnLog: inputstream.adaptive: Unsupported codec  in stream ID: 
2023-07-03 10:21:53.346 T:22900    info <general>: Creating Demuxer
2023-07-03 10:21:53.346 T:22900    info <general>: Opening stream: 1002 source: 256
2023-07-03 10:21:53.787 T:22900    info <general>: Finding audio codec for: 86018
2023-07-03 10:21:53.787 T:22900    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2023-07-03 10:21:53.787 T:22900    info <general>: CVideoPlayerAudio::OpenStream: Allowing max Out-Of-Sync Value of 10 ms
2023-07-03 10:21:53.787 T:22900    info <general>: Creating audio thread
2023-07-03 10:21:53.788 T:7580     info <general>: running thread: CVideoPlayerAudio::Process()
2023-07-03 10:21:53.788 T:22900    info <general>: Opening stream: 0 source: 1024
2023-07-03 10:21:53.893 T:22900   error <general>: CVideoPlayerSubtitle::OpenStream - Unable to create subtitle parser
2023-07-03 10:21:53.893 T:22900    info <general>: Opening stream: 0 source: 1025
2023-07-03 10:21:53.964 T:22900   error <general>: CVideoPlayerSubtitle::OpenStream - Unable to create subtitle parser
2023-07-03 10:21:53.965 T:22900    info <general>: Opening stream: 0 source: 1026
2023-07-03 10:21:54.011 T:22900   error <general>: CVideoPlayerSubtitle::OpenStream - Unable to create subtitle parser
2023-07-03 10:21:54.011 T:22900    info <general>: Opening stream: 0 source: 1027
2023-07-03 10:21:54.074 T:22900   error <general>: CVideoPlayerSubtitle::OpenStream - Unable to create subtitle parser
2023-07-03 10:21:54.074 T:22900    info <general>: Opening stream: 0 source: 1028
2023-07-03 10:21:54.119 T:22900   error <general>: CVideoPlayerSubtitle::OpenStream - Unable to create subtitle parser
2023-07-03 10:21:54.119 T:22900    info <general>: Opening stream: 0 source: 1029
2023-07-03 10:21:54.162 T:22900    info <general>: CDVDSubtitlesLibass: Using libass version 1502000
2023-07-03 10:21:54.163 T:22900    info <general>: CDVDSubtitlesLibass: Creating ASS library structure
2023-07-03 10:21:54.163 T:22900    info <general>: CDVDSubtitlesLibass: Initializing ASS Renderer
2023-07-03 10:21:54.164 T:22900    info <general>: CDVDSubtitlesLibass: Initializing ASS library font settings
2023-07-03 10:21:54.333 T:22900    info <general>: CDVDSubtitlesLibass: Creating new ASS track
2023-07-03 10:21:54.334 T:22900    info <general>: CVideoPlayer::Process - eof reading from demuxer
2023-07-03 10:21:54.334 T:22900    info <general>: CVideoPlayer::OnExit()
2023-07-03 10:21:54.334 T:22900    info <general>: VideoPlayer: eof, waiting for queues to empty
2023-07-03 10:21:54.334 T:22900    info <general>: Closing stream player 1
2023-07-03 10:21:54.334 T:22900    info <general>: Waiting for audio thread to exit
2023-07-03 10:21:54.344 T:7580     info <general>: thread end: CVideoPlayerAudio::OnExit()
2023-07-03 10:21:54.345 T:22900    info <general>: Closing audio device
2023-07-03 10:21:54.345 T:22900    info <general>: Deleting audio codec
2023-07-03 10:21:54.345 T:22900    info <general>: Closing stream player 3
2023-07-03 10:21:54.346 T:22900    info <general>: ADDON: Dll Destroyed - InputStream Adaptive
2023-07-03 10:21:54.351 T:22672    info <general>: CVideoPlayer::CloseFile()
2023-07-03 10:21:54.352 T:22672    info <general>: VideoPlayer: waiting for threads to exit
2023-07-03 10:21:54.352 T:22672    info <general>: VideoPlayer: finished waiting
2023-07-03 10:21:54.352 T:22672    info <general>: CVideoPlayer::CloseFile()
2023-07-03 10:21:54.352 T:22672    info <general>: VideoPlayer: waiting for threads to exit
2023-07-03 10:21:54.352 T:22672    info <general>: VideoPlayer: finished waiting
nullket commented 1 year ago

So it was in fact a bug in kodi 19 which is nice and we can then close this issue (feel free to still use the thread for discussion).

For the Unsupported codec in stream ID: you are just very unlucky concerning the time you started to use this plugin. We have an issue tracking that but it not the fault of this plugin (or yt_dlp). The issue comes from the input stream adaptive plugin and to my understanding should already be fixed but a newer version has not been released (and releases seem to be quite rare).

As a workaround disable adaptive streaming in the settings. This should make all youtube videos work in 720p (more is only with adaptive streaming possible) but might break other websites.