search

quarckster / kodi.kino.pub

Kodi add-on for kino.pub
BSD 3-Clause "New" or "Revised" License
87 stars 17 forks source link

Ошибка воспроизведения с InputStream.Adaptive 2.6.16 #192

Closed ivashin closed 3 years ago

ivashin commented 3 years ago

InputStream.Adaptive начиная с версии 2.6.16 выдает ошибку при использовании локальных файлов. Подробности тут: https://github.com/xbmc/inputstream.adaptive/issues/701

Конфигурация: CoreELEC 19.2-Matrix_rc2 (Amlogic S905X) Kodi 19.1.0 kodi.kino.pub 3.0.3 InputStream Adaptive 2.6.16.1 Тип стриминга HLS4

При попытке воспроизведения возникает ошибка при парсинге локального плейлиста:

2021-06-28 09:48:37.159 T:4877     INFO <general>: initializing python engine.
2021-06-28 09:48:38.518 T:4877     INFO <general>: [video.kino.pub]: temporary hls playlist /storage/.kodi/temp/616502c9-beb9-4653-a6f1-42542d77e43d.m3u8 was created
2021-06-28 09:48:38.712 T:4671     INFO <general>: VideoPlayer::OpenFile: plugin://video.kino.pub/play/72466?season_index=1&index=1
2021-06-28 09:48:38.718 T:4880     INFO <general>: Creating InputStream
2021-06-28 09:48:38.780 T:4877     INFO <general>: [video.kino.pub]: playback started
2021-06-28 09:48:38.838 T:4877     INFO <general>: [video.kino.pub]: access token should be refreshed
2021-06-28 09:48:38.844 T:4877     INFO <general>: [video.kino.pub]: refreshing token
2021-06-28 09:48:38.850 T:4877     INFO <general>: [video.kino.pub]: sending payload {'grant_type': 'refresh_token', 'refresh_token': 'i9fnf618a1dpbbsdql1i4jwtg2mcqyzz', 'client_id': 'xbmc', 'client_secret': 'cgg3gtifu46urtfp2zp1nqtba0k2ezxh'} to oauth api
2021-06-28 09:48:38.876 T:4880     INFO <general>: AddOnLog: inputstream.adaptive: SetVideoResolution (1920 x 1080)
2021-06-28 09:48:38.885 T:4880    FATAL <general>: AddOnLog: inputstream.adaptive: Invalid url: / expected ()
2021-06-28 09:48:38.885 T:4880    ERROR <general>: AddOnLog: inputstream.adaptive: Could not open / parse manifest (/storage/.kodi/temp/616502c9-beb9-4653-a6f1-42542d77e43d.m3u8)
2021-06-28 09:48:38.886 T:4880    ERROR <general>: CVideoPlayer::OpenInputStream - error opening [plugin://video.kino.pub/play/72466?season_index=1&index=1]
2021-06-28 09:48:38.887 T:4880     INFO <general>: CVideoPlayer::OnExit()
2021-06-28 09:48:38.888 T:4880     INFO <general>: ADDON: Dll Destroyed - InputStream Adaptive
2021-06-28 09:48:38.896 T:4858     INFO <general>: Deleting settings information for files plugin://video.kino.pub/play/72466?season_index=1&index=1
2021-06-28 09:48:38.913 T:4671     INFO <general>: Loading skin file: DialogConfirm.xml, load type: KEEP_IN_MEMORY
2021-06-28 09:48:38.922 T:4671     INFO <general>: CVideoPlayer::CloseFile()
2021-06-28 09:48:38.959 T:4671     INFO <general>: VideoPlayer: waiting for threads to exit
2021-06-28 09:48:38.959 T:4671     INFO <general>: VideoPlayer: finished waiting
2021-06-28 09:48:38.994 T:4877     INFO <general>: [video.kino.pub]: refresh token - ###; access token - ###; expires in - 86400
2021-06-28 09:48:39.013 T:4877     INFO <general>: [video.kino.pub]: playback stopped
2021-06-28 09:48:39.014 T:4877     INFO <general>: [video.kino.pub]: deleted /storage/.kodi/temp/616502c9-beb9-4653-a6f1-42542d77e43d.m3u8
2021-06-28 09:48:39.681 T:4877     INFO <general>: CPythonInvoker(16, /storage/.kodi/addons/video.kino.pub/addon.py): script successfully run
2021-06-28 09:48:39.957 T:4877     INFO <general>: Python interpreter stopped

Решение проблемы: использование локального прокси-сервера для модификации m3u8 файлов. Пример: https://github.com/Dis90/plugin.video.discoveryplus/pull/51 https://github.com/Dis90/plugin.video.discoveryplus/pull/52

quarckster commented 3 years ago

Да, есть такая ошибка, прокси сервер не нужен, достаточно подправить файлы локально. Я это исправил здесь https://github.com/quarckster/kodi.kino.pub/blob/master/src/resources/lib/utils.py#L12, у вас проблема похоже в том, что файловая система не доступна для записи, поэтому исправленный m3u не сохраняется во временное хранилище. Не хотелось бы ради такой мелочи поднимать целый сервер.

quarckster commented 3 years ago

Хм, это мейнтейнер IA предлагает так делать https://forum.kodi.tv/showthread.php?tid=340055&pid=3038938#pid3038938. Что за жесть.

ivashin commented 3 years ago

Временные файлы вроде бы сохраняются. Вот пример: https://pastebin.com/ntnBYJps

Как написано здесь:

as discussed with @glennguy , local paths aren't really supported and them working until now is more a lucky coincidence / hack. this PR gets them working again - but as per the log warning - support for them will be removed in 20 Add-ons relying on them should use a small HTTP API / Proxy to do any required modifications to the manifest.

И в результате этот PR так и не вмержили.

Вот еще один пример реализации прокси: https://github.com/CastagnaIT/plugin.video.netflix/blob/master/resources/lib/services/http_server.py

quarckster commented 3 years ago

Да, спасибо, тоже уже прочитал. Что ж придётся городить этот прокси.

quarckster commented 3 years ago

@ivashin не могли бы протестировать версию плагина из #193 video.kino.pub-3.0.4-beta-1.zip

ivashin commented 3 years ago

@quarckster в первый раз все запускается, как положено. Есть небольшие непонятки с разрешением, но это наверное надо смотреть настройки inputstream.adaptive и моей железки, и к делу не относится.

Нормальный лог ``` 2021-07-10 09:53:22.963 T:4836 INFO : initializing python engine. 2021-07-10 09:53:23.998 T:4689 INFO : VideoPlayer::OpenFile: plugin://video.kino.pub/play/72466?season_index=1&index=2 2021-07-10 09:53:24.007 T:4840 INFO : Creating InputStream 2021-07-10 09:53:24.126 T:4840 INFO : AddOnLog: inputstream.adaptive: SetVideoResolution (1920 x 1080) 2021-07-10 09:53:24.430 T:4840 INFO : AddOnLog: inputstream.adaptive: Successfully parsed manifest file. #Periods: 1, #Streams in first period: 38, Type: live, Download speed: 3365775.9985 Bytes/s 2021-07-10 09:53:24.439 T:4840 INFO : Creating Demuxer 2021-07-10 09:53:24.444 T:4840 INFO : Opening stream: 1001 source: 256 2021-07-10 09:53:25.683 T:4840 INFO : CVideoPlayerVideo::OpenStream - Creating codec: 27 2021-07-10 09:53:25.688 T:4840 INFO : DVDVideoCodecAmlogic: Opened Amlogic Codec 2021-07-10 09:53:25.688 T:4840 INFO : Creating video thread 2021-07-10 09:53:25.688 T:4846 INFO : running thread: video_thread 2021-07-10 09:53:25.689 T:4840 INFO : Opening stream: 1003 source: 256 2021-07-10 09:53:26.701 T:4840 INFO : Finding audio codec for: 86018 2021-07-10 09:53:26.710 T:4840 INFO : CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac 2021-07-10 09:53:26.710 T:4840 INFO : Creating audio thread 2021-07-10 09:53:26.710 T:4850 INFO : running thread: CVideoPlayerAudio::Process() 2021-07-10 09:53:26.711 T:4840 INFO : Opening stream: 0 source: 1031 2021-07-10 09:53:27.446 T:4846 INFO : DVDVideoCodecAmlogic::AddData Open decoder: fps:25000/1000 2021-07-10 09:53:27.451 T:4850 INFO : Creating audio stream (codec id: 86018, channels: 6, sample rate: 48000, no pass-through) 2021-07-10 09:53:27.457 T:4698 INFO : CActiveAESink::OpenSink - initialize sink 2021-07-10 09:53:27.459 T:4698 INFO : CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=AMLMESONAUDIO,DEV=0" 2021-07-10 09:53:27.466 T:4698 INFO : CAESinkALSA::Initialize - Opened device "hdmi:CARD=AMLMESONAUDIO,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x02" 2021-07-10 09:53:27.466 T:4698 INFO : CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats 2021-07-10 09:53:27.467 T:4698 INFO : CAESinkALSA::InitializeHW - Using data format AE_FMT_S16NE 2021-07-10 09:53:27.560 T:4689 INFO : Constructing CRendererAML 2021-07-10 09:53:27.571 T:4689 INFO : Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY 2021-07-10 09:53:27.582 T:4689 INFO : [WHITELIST] Searching the whitelist for: width: 1920, height: 864, fps: 50.000, 3D: false 2021-07-10 09:53:27.584 T:4689 INFO : Display resolution ADJUST : 1920x1080 @ 50.00 - Full Screen (32) (weight: -985461724020736.000) 2021-07-10 09:53:27.584 T:4689 INFO : VideoPlayer: OnLostDisplay received 2021-07-10 09:53:27.585 T:4689 ERROR : GetString: error reading /sys/class/amhdmitx/amhdmitx0/custom_mode 2021-07-10 09:53:27.808 T:4689 INFO : VideoPlayer: OnResetDisplay received 2021-07-10 09:53:27.808 T:4689 INFO : GLES: Maximum texture width: 4096 2021-07-10 09:53:27.859 T:4689 INFO : Constructing CRendererAML 2021-07-10 09:53:27.862 T:4689 INFO : [WHITELIST] Searching the whitelist for: width: 1920, height: 864, fps: 50.000, 3D: false 2021-07-10 09:53:27.864 T:4689 INFO : Display resolution ADJUST : 1920x1080 @ 50.00 - Full Screen (32) (weight: 0.000) 2021-07-10 09:53:28.008 T:4689 INFO : Constructing CRendererAML 2021-07-10 09:53:28.029 T:4689 INFO : [WHITELIST] Searching the whitelist for: width: 1920, height: 864, fps: 25.000, 3D: false 2021-07-10 09:53:28.030 T:4689 INFO : Display resolution ADJUST : 1920x1080 @ 50.00 - Full Screen (32) (weight: -985461724020736.000) ```

Но при попытке запустить видео еще раз, падает с ошибкой Address already in use, судя по всему при запуске прокси-сервера

Лог с ошибкой ``` 2021-07-10 09:56:20.813 T:4881 INFO : initializing python engine. 2021-07-10 09:56:21.866 T:4881 ERROR : EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<-- - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS! Error Type: Error Contents: [Errno 98] Address already in use Traceback (most recent call last): File "/storage/.kodi/addons/video.kino.pub/addon.py", line 6, in plugin.run() File "/storage/.kodi/addons/video.kino.pub/resources/lib/plugin.py", line 75, in run self.routing.dispatch(self.path) File "/storage/.kodi/addons/video.kino.pub/resources/lib/routing.py", line 62, in dispatch view_func(**kwargs) File "/storage/.kodi/addons/video.kino.pub/resources/lib/main.py", line 285, in play proxy.start() File "/storage/.kodi/addons/video.kino.pub/resources/lib/proxy.py", line 97, in start ProxyServer((HOST, PORT), RequestHandler).start_in_thread() File "/usr/lib/python3.8/socketserver.py", line 452, in __init__ File "/usr/lib/python3.8/http/server.py", line 138, in server_bind File "/usr/lib/python3.8/socketserver.py", line 466, in server_bind OSError: [Errno 98] Address already in use -->End of Python script error report<-- 2021-07-10 09:56:22.216 T:4881 INFO : Python interpreter stopped 2021-07-10 09:56:22.236 T:4689 ERROR : Playlist Player: skipping unplayable item: 0, path [plugin://video.kino.pub/play/72466?season_index=1&index=3] ```
quarckster commented 3 years ago

@ivashin попробуйте следующую итерацию video.kino.pub-3.0.4-beta-2.zip

ivashin commented 3 years ago

Теперь как-то через раз. То ничего не проигрывает с ошибками типа CCurlFile::FillBuffer - Failed: Failure when receiving data from the peer(56)

Лог ``` 2021-07-12 23:09:50.729 T:4835 INFO : initializing python engine. 2021-07-12 23:09:52.024 T:4693 INFO : VideoPlayer::OpenFile: plugin://video.kino.pub/play/8773?season_index=30&index=19 2021-07-12 23:09:52.036 T:4839 INFO : Creating InputStream 2021-07-12 23:09:52.157 T:4839 INFO : AddOnLog: inputstream.adaptive: SetVideoResolution (1920 x 1080) 2021-07-12 23:09:52.169 T:4839 ERROR : CCurlFile::FillBuffer - Failed: Failure when receiving data from the peer(56) 2021-07-12 23:09:52.170 T:4835 INFO : [video.kino.pub]: playback started 2021-07-12 23:09:52.170 T:4839 ERROR : CCurlFile::Open failed with code 0 for http://127.0.0.1:48201/?m3u8_url=aHR0cHM6Ly9zZWxlY3RlbGNkbi5uZXQvaGxzNC9hV1E5TVRnNE9UQTRPell6TkRjNU5qWTJPRHN4TVRnM056QXdORHN4TmpJMk1USXdOVFV6Sm1nOVVFbFRUa2gzYjJGWmIzcHRjWEY1YWsxSU1tMU9aeVpsUFRFMk1qWXlNRFk1TlRNLzYyMzYzOC5tM3U4P2xvYz1ubA%3D%3D: 2021-07-12 23:09:52.170 T:4839 ERROR : AddOnLog: inputstream.adaptive: Download failed: http://127.0.0.1:48201?m3u8_url=aHR0cHM6Ly9zZWxlY3RlbGNkbi5uZXQvaGxzNC9hV1E5TVRnNE9UQTRPell6TkRjNU5qWTJPRHN4TVRnM056QXdORHN4TmpJMk1USXdOVFV6Sm1nOVVFbFRUa2gzYjJGWmIzcHRjWEY1YWsxSU1tMU9aeVpsUFRFMk1qWXlNRFk1TlRNLzYyMzYzOC5tM3U4P2xvYz1ubA%3D%3D 2021-07-12 23:09:52.170 T:4839 ERROR : AddOnLog: inputstream.adaptive: Could not open / parse manifest (http://127.0.0.1:48201?m3u8_url=aHR0cHM6Ly9zZWxlY3RlbGNkbi5uZXQvaGxzNC9hV1E5TVRnNE9UQTRPell6TkRjNU5qWTJPRHN4TVRnM056QXdORHN4TmpJMk1USXdOVFV6Sm1nOVVFbFRUa2gzYjJGWmIzcHRjWEY1YWsxSU1tMU9aeVpsUFRFMk1qWXlNRFk1TlRNLzYyMzYzOC5tM3U4P2xvYz1ubA%3D%3D) 2021-07-12 23:09:52.171 T:4839 ERROR : CVideoPlayer::OpenInputStream - error opening [plugin://video.kino.pub/play/8773?season_index=30&index=19] 2021-07-12 23:09:52.171 T:4839 INFO : CVideoPlayer::OnExit() 2021-07-12 23:09:52.172 T:4839 INFO : ADDON: Dll Destroyed - InputStream Adaptive 2021-07-12 23:09:52.194 T:4693 INFO : Loading skin file: DialogConfirm.xml, load type: KEEP_IN_MEMORY 2021-07-12 23:09:52.203 T:4693 INFO : CVideoPlayer::CloseFile() 2021-07-12 23:09:52.206 T:4693 INFO : VideoPlayer: waiting for threads to exit 2021-07-12 23:09:52.206 T:4693 INFO : VideoPlayer: finished waiting 2021-07-12 23:09:52.288 T:4835 INFO : [video.kino.pub]: playback stopped 2021-07-12 23:09:53.021 T:4835 INFO : CPythonInvoker(6, /storage/.kodi/addons/video.kino.pub/addon.py): script successfully run 2021-07-12 23:09:53.310 T:4835 INFO : Python interpreter stopped ```

То один раз падает с той же ошибкой, а потом работает без проблем:

Лог - сначала ошибка, потом успешное воспроизведение ``` 2021-07-12 23:35:30.404 T:4794 INFO : initializing python engine. 2021-07-12 23:35:31.428 T:4669 INFO : VideoPlayer::OpenFile: plugin://video.kino.pub/play/72466?season_index=1&index=3 2021-07-12 23:35:31.438 T:4798 INFO : Creating InputStream 2021-07-12 23:35:31.557 T:4798 INFO : AddOnLog: inputstream.adaptive: SetVideoResolution (1920 x 1080) 2021-07-12 23:35:31.569 T:4794 INFO : [video.kino.pub]: playback started 2021-07-12 23:35:31.569 T:4798 ERROR : CCurlFile::FillBuffer - Failed: Failure when receiving data from the peer(56) 2021-07-12 23:35:31.569 T:4798 ERROR : CCurlFile::Open failed with code 0 for http://127.0.0.1:48201/?m3u8_url=aHR0cHM6Ly95YW5kZXgtY2RuLm5ldC9obHM0L2FXUTlNVGc0T1RBNE96WXpORGM1TmpZMk9Ec3hNVGczTnpBd05Ec3hOakkyTVRJeU1USTFKbWc5ZERWUlQwMXFaMmxmTW5KbFFTMHhTMmh4VWt4eFVTWmxQVEUyTWpZeU1EZzFNalUvODA5NDEwLm0zdTg_bG9jPW5s: 2021-07-12 23:35:31.569 T:4798 ERROR : AddOnLog: inputstream.adaptive: Download failed: http://127.0.0.1:48201?m3u8_url=aHR0cHM6Ly95YW5kZXgtY2RuLm5ldC9obHM0L2FXUTlNVGc0T1RBNE96WXpORGM1TmpZMk9Ec3hNVGczTnpBd05Ec3hOakkyTVRJeU1USTFKbWc5ZERWUlQwMXFaMmxmTW5KbFFTMHhTMmh4VWt4eFVTWmxQVEUyTWpZeU1EZzFNalUvODA5NDEwLm0zdTg_bG9jPW5s 2021-07-12 23:35:31.569 T:4798 ERROR : AddOnLog: inputstream.adaptive: Could not open / parse manifest (http://127.0.0.1:48201?m3u8_url=aHR0cHM6Ly95YW5kZXgtY2RuLm5ldC9obHM0L2FXUTlNVGc0T1RBNE96WXpORGM1TmpZMk9Ec3hNVGczTnpBd05Ec3hOakkyTVRJeU1USTFKbWc5ZERWUlQwMXFaMmxmTW5KbFFTMHhTMmh4VWt4eFVTWmxQVEUyTWpZeU1EZzFNalUvODA5NDEwLm0zdTg_bG9jPW5s) 2021-07-12 23:35:31.570 T:4798 ERROR : CVideoPlayer::OpenInputStream - error opening [plugin://video.kino.pub/play/72466?season_index=1&index=3] 2021-07-12 23:35:31.570 T:4798 INFO : CVideoPlayer::OnExit() 2021-07-12 23:35:31.571 T:4798 INFO : ADDON: Dll Destroyed - InputStream Adaptive 2021-07-12 23:35:31.596 T:4669 INFO : Loading skin file: DialogConfirm.xml, load type: KEEP_IN_MEMORY 2021-07-12 23:35:31.604 T:4669 INFO : CVideoPlayer::CloseFile() 2021-07-12 23:35:31.641 T:4669 INFO : VideoPlayer: waiting for threads to exit 2021-07-12 23:35:31.641 T:4669 INFO : VideoPlayer: finished waiting 2021-07-12 23:35:32.528 T:4794 INFO : [video.kino.pub]: playback stopped 2021-07-12 23:35:33.414 T:4794 INFO : CPythonInvoker(7, /storage/.kodi/addons/video.kino.pub/addon.py): script successfully run 2021-07-12 23:35:33.684 T:4794 INFO : Python interpreter stopped 2021-07-12 23:35:53.859 T:4677 INFO : CActiveAESink::OpenSink - initialize sink 2021-07-12 23:35:53.859 T:4677 INFO : CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=AMLMESONAUDIO,DEV=0" 2021-07-12 23:35:53.865 T:4677 INFO : CAESinkALSA::Initialize - Opened device "hdmi:CARD=AMLMESONAUDIO,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00" 2021-07-12 23:35:53.866 T:4677 INFO : CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats 2021-07-12 23:35:53.866 T:4677 INFO : CAESinkALSA::InitializeHW - Using data format AE_FMT_S16NE 2021-07-12 23:35:54.324 T:4821 INFO : initializing python engine. 2021-07-12 23:35:55.130 T:4821 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/items/72466 2021-07-12 23:35:55.511 T:4821 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=72466 2021-07-12 23:35:56.028 T:4669 INFO : VideoPlayer::OpenFile: plugin://video.kino.pub/play/72466?season_index=1&index=4 2021-07-12 23:35:56.034 T:4825 INFO : Creating InputStream 2021-07-12 23:35:56.036 T:4825 INFO : AddOnLog: inputstream.adaptive: SetVideoResolution (1920 x 1080) 2021-07-12 23:35:56.328 T:4821 INFO : [video.kino.pub]: playback started 2021-07-12 23:35:56.330 T:4825 INFO : AddOnLog: inputstream.adaptive: Successfully parsed manifest file. #Periods: 1, #Streams in first period: 38, Type: live, Download speed: 5914603.0335 Bytes/s 2021-07-12 23:35:56.340 T:4825 INFO : Creating Demuxer 2021-07-12 23:35:56.345 T:4825 INFO : Opening stream: 1001 source: 256 2021-07-12 23:35:57.804 T:4825 INFO : CVideoPlayerVideo::OpenStream - Creating codec: 27 2021-07-12 23:35:57.809 T:4825 INFO : DVDVideoCodecAmlogic: Opened Amlogic Codec 2021-07-12 23:35:57.809 T:4825 INFO : Creating video thread 2021-07-12 23:35:57.810 T:4831 INFO : running thread: video_thread 2021-07-12 23:35:57.810 T:4825 INFO : Opening stream: 1003 source: 256 2021-07-12 23:35:58.448 T:4825 INFO : Finding audio codec for: 86018 2021-07-12 23:35:58.458 T:4825 INFO : CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac 2021-07-12 23:35:58.459 T:4825 INFO : Creating audio thread 2021-07-12 23:35:58.460 T:4833 INFO : running thread: CVideoPlayerAudio::Process() 2021-07-12 23:35:58.460 T:4825 INFO : Opening stream: 0 source: 1030 2021-07-12 23:35:59.022 T:4831 INFO : DVDVideoCodecAmlogic::AddData Open decoder: fps:25000/1000 2021-07-12 23:35:59.028 T:4833 INFO : Creating audio stream (codec id: 86018, channels: 6, sample rate: 48000, no pass-through) 2021-07-12 23:35:59.031 T:4677 INFO : CActiveAESink::OpenSink - initialize sink 2021-07-12 23:35:59.032 T:4677 INFO : CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=AMLMESONAUDIO,DEV=0" 2021-07-12 23:35:59.042 T:4677 INFO : CAESinkALSA::Initialize - Opened device "hdmi:CARD=AMLMESONAUDIO,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x02" 2021-07-12 23:35:59.045 T:4677 INFO : CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats 2021-07-12 23:35:59.045 T:4677 INFO : CAESinkALSA::InitializeHW - Using data format AE_FMT_S16NE 2021-07-12 23:35:59.109 T:4669 INFO : Constructing CRendererAML 2021-07-12 23:35:59.121 T:4669 INFO : Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY 2021-07-12 23:35:59.131 T:4669 INFO : [WHITELIST] Searching the whitelist for: width: 1920, height: 864, fps: 25.000, 3D: false 2021-07-12 23:35:59.133 T:4669 INFO : Display resolution ADJUST : 1920x1080 @ 25.00 - Full Screen (33) (weight: -24664696946688.000) 2021-07-12 23:35:59.133 T:4669 INFO : VideoPlayer: OnLostDisplay received 2021-07-12 23:35:59.134 T:4669 ERROR : GetString: error reading /sys/class/amhdmitx/amhdmitx0/custom_mode 2021-07-12 23:35:59.334 T:4669 INFO : VideoPlayer: OnResetDisplay received 2021-07-12 23:35:59.334 T:4669 INFO : GLES: Maximum texture width: 4096 2021-07-12 23:36:04.974 T:4669 INFO : CVideoPlayer::CloseFile() 2021-07-12 23:36:04.976 T:4669 INFO : VideoPlayer: waiting for threads to exit 2021-07-12 23:36:04.977 T:4825 INFO : CVideoPlayer::OnExit() 2021-07-12 23:36:04.977 T:4825 INFO : Closing stream player 1 2021-07-12 23:36:04.978 T:4825 INFO : Waiting for audio thread to exit 2021-07-12 23:36:04.980 T:4833 INFO : thread end: CVideoPlayerAudio::OnExit() 2021-07-12 23:36:04.980 T:4825 INFO : Closing audio device 2021-07-12 23:36:04.990 T:4825 INFO : Deleting audio codec 2021-07-12 23:36:04.991 T:4677 INFO : CActiveAESink::OpenSink - initialize sink 2021-07-12 23:36:04.991 T:4825 INFO : Closing stream player 2 2021-07-12 23:36:04.992 T:4825 INFO : waiting for video thread to exit 2021-07-12 23:36:05.004 T:4831 INFO : thread end: video_thread 2021-07-12 23:36:05.007 T:4825 INFO : deleting video codec 2021-07-12 23:36:05.011 T:4825 INFO : Closing stream player 3 2021-07-12 23:36:05.017 T:4825 INFO : ADDON: Dll Destroyed - InputStream Adaptive 2021-07-12 23:36:05.018 T:4669 INFO : VideoPlayer: finished waiting 2021-07-12 23:36:05.018 T:4669 INFO : CVideoPlayer::CloseFile() 2021-07-12 23:36:05.018 T:4669 INFO : VideoPlayer: waiting for threads to exit 2021-07-12 23:36:05.018 T:4669 INFO : VideoPlayer: finished waiting 2021-07-12 23:36:05.079 T:4669 ERROR : GetString: error reading /sys/class/amhdmitx/amhdmitx0/custom_mode 2021-07-12 23:36:05.184 T:4677 INFO : CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=AMLMESONAUDIO,DEV=0" 2021-07-12 23:36:05.189 T:4677 INFO : CAESinkALSA::Initialize - Opened device "hdmi:CARD=AMLMESONAUDIO,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00" 2021-07-12 23:36:05.190 T:4677 INFO : CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats 2021-07-12 23:36:05.190 T:4677 INFO : CAESinkALSA::InitializeHW - Using data format AE_FMT_S16NE 2021-07-12 23:36:05.275 T:4669 INFO : GLES: Maximum texture width: 4096 2021-07-12 23:36:05.312 T:4669 ERROR : Control 55 in window 10025 has been asked to focus, but it can't 2021-07-12 23:36:05.724 T:4846 INFO : initializing python engine. 2021-07-12 23:36:05.825 T:4821 INFO : [video.kino.pub]: playback stopped 2021-07-12 23:36:06.004 T:4821 INFO : CPythonInvoker(8, /storage/.kodi/addons/video.kino.pub/addon.py): script successfully run 2021-07-12 23:36:06.320 T:4821 INFO : Python interpreter stopped ```

Закономерность пока установить не смог. К сожалению мало времени сейчас на тестирвоание.

ivashin commented 3 years ago

Такое ощущение, что прокси медленно стартует, и в первый раз не возвращает что следует. Ситуацию, когда ничего не воспроизводится, пока повторить не могу.

quarckster commented 3 years ago

video.kino.pub-3.0.4-beta-3.zip Попробовал сделать кое-какие изменения. На моём Kodi 19.1 работает нормально.

ivashin commented 3 years ago

У меня все равно при первом запуске падает с ошибкой CCurlFile::FillBuffer - Failed: Failure when receiving data from the peer(56), а потом начинает работать нормально, но судя по логам на каждый запуск видео бросает исключение dictionary changed size during iteration

Лог с момента запуска плагина. Два запуска одного и того же видео. ``` 2021-07-17 22:16:35.074 T:4750 INFO : initializing python engine. 2021-07-17 22:16:36.179 T:4750 INFO : CPythonInvoker(1, /storage/.kodi/addons/video.kino.pub/addon.py): script successfully run 2021-07-17 22:16:36.435 T:4750 INFO : Python interpreter stopped 2021-07-17 22:16:38.338 T:4756 INFO : initializing python engine. 2021-07-17 22:16:39.217 T:4756 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/bookmarks 2021-07-17 22:16:39.901 T:4756 INFO : CPythonInvoker(2, /storage/.kodi/addons/video.kino.pub/addon.py): script successfully run 2021-07-17 22:16:40.191 T:4756 INFO : Python interpreter stopped 2021-07-17 22:16:41.667 T:4760 INFO : initializing python engine. 2021-07-17 22:16:42.497 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/bookmarks/155308 2021-07-17 22:16:43.157 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=68770 2021-07-17 22:16:43.467 T:4760 ERROR : NEWADDON Unknown Video Info Key "time" 2021-07-17 22:16:43.585 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=89 2021-07-17 22:16:43.884 T:4760 ERROR : NEWADDON Unknown Video Info Key "time" 2021-07-17 22:16:43.986 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=11 2021-07-17 22:16:44.353 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=410 2021-07-17 22:16:44.618 T:4760 ERROR : NEWADDON Unknown Video Info Key "time" 2021-07-17 22:16:44.786 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=273 2021-07-17 22:16:45.085 T:4760 ERROR : NEWADDON Unknown Video Info Key "time" 2021-07-17 22:16:45.310 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=2107 2021-07-17 22:16:45.586 T:4760 ERROR : NEWADDON Unknown Video Info Key "time" 2021-07-17 22:16:45.671 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=2466 2021-07-17 22:16:45.970 T:4760 ERROR : NEWADDON Unknown Video Info Key "time" 2021-07-17 22:16:46.054 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=59143 2021-07-17 22:16:46.370 T:4760 ERROR : NEWADDON Unknown Video Info Key "time" 2021-07-17 22:16:46.644 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=61186 2021-07-17 22:16:46.920 T:4760 ERROR : NEWADDON Unknown Video Info Key "time" 2021-07-17 22:16:47.211 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=55468 2021-07-17 22:16:47.572 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=35257 2021-07-17 22:16:47.855 T:4760 ERROR : NEWADDON Unknown Video Info Key "time" 2021-07-17 22:16:48.078 T:4760 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/watching?id=57967 2021-07-17 22:16:48.372 T:4760 ERROR : NEWADDON Unknown Video Info Key "time" 2021-07-17 22:16:48.673 T:4760 INFO : CPythonInvoker(3, /storage/.kodi/addons/video.kino.pub/addon.py): script successfully run 2021-07-17 22:16:48.981 T:4760 INFO : Python interpreter stopped 2021-07-17 22:16:52.801 T:4771 INFO : initializing python engine. 2021-07-17 22:16:53.661 T:4771 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/items/68770 2021-07-17 22:16:54.167 T:4668 INFO : VideoPlayer::OpenFile: plugin://video.kino.pub/play/68770 2021-07-17 22:16:54.176 T:4775 INFO : Creating InputStream 2021-07-17 22:16:54.304 T:4775 INFO : AddOnLog: inputstream.adaptive: SetVideoResolution (1920 x 1080) 2021-07-17 22:16:54.315 T:4775 ERROR : CCurlFile::FillBuffer - Failed: Failure when receiving data from the peer(56) 2021-07-17 22:16:54.315 T:4775 ERROR : CCurlFile::Open failed with code 0 for http://127.0.0.1:48201/?m3u8_url=aHR0cHM6Ly9hbXpuY2RuLm5ldC9obHM0L2FXUTlNVGc0T1RBNE96WXpORGM1TmpZMk9Ec3hNVGczTnpBd05Ec3hOakkyTlRRNU5ERTBKbWc5Tm5rMlVGYzVlRUZIU2tSb00wZzRkelE1U1VsMVVTWmxQVEUyTWpZMk16VTRNVFEvNzgzNTgwLm0zdTg_bG9jPW5s: 2021-07-17 22:16:54.315 T:4775 ERROR : AddOnLog: inputstream.adaptive: Download failed: http://127.0.0.1:48201?m3u8_url=aHR0cHM6Ly9hbXpuY2RuLm5ldC9obHM0L2FXUTlNVGc0T1RBNE96WXpORGM1TmpZMk9Ec3hNVGczTnpBd05Ec3hOakkyTlRRNU5ERTBKbWc5Tm5rMlVGYzVlRUZIU2tSb00wZzRkelE1U1VsMVVTWmxQVEUyTWpZMk16VTRNVFEvNzgzNTgwLm0zdTg_bG9jPW5s 2021-07-17 22:16:54.315 T:4775 ERROR : AddOnLog: inputstream.adaptive: Could not open / parse manifest (http://127.0.0.1:48201?m3u8_url=aHR0cHM6Ly9hbXpuY2RuLm5ldC9obHM0L2FXUTlNVGc0T1RBNE96WXpORGM1TmpZMk9Ec3hNVGczTnpBd05Ec3hOakkyTlRRNU5ERTBKbWc5Tm5rMlVGYzVlRUZIU2tSb00wZzRkelE1U1VsMVVTWmxQVEUyTWpZMk16VTRNVFEvNzgzNTgwLm0zdTg_bG9jPW5s) 2021-07-17 22:16:54.318 T:4775 ERROR : CVideoPlayer::OpenInputStream - error opening [plugin://video.kino.pub/play/68770] 2021-07-17 22:16:54.318 T:4775 INFO : CVideoPlayer::OnExit() 2021-07-17 22:16:54.319 T:4775 INFO : ADDON: Dll Destroyed - InputStream Adaptive 2021-07-17 22:16:54.344 T:4771 ERROR : EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<-- - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS! Error Type: Error Contents: dictionary changed size during iteration Traceback (most recent call last): File "/storage/.kodi/addons/video.kino.pub/resources/lib/player.py", line 61, in onPlayBackStarted proxy.stop() File "/storage/.kodi/addons/video.kino.pub/resources/lib/proxy.py", line 104, in stop ProxyServer.stop_all_threads() File "/storage/.kodi/addons/video.kino.pub/resources/lib/proxy.py", line 89, in stop_all_threads for server, thread in cls.threads.items(): RuntimeError: dictionary changed size during iteration -->End of Python script error report<-- 2021-07-17 22:16:54.352 T:4668 INFO : Loading skin file: DialogConfirm.xml, load type: KEEP_IN_MEMORY 2021-07-17 22:16:54.360 T:4668 INFO : CVideoPlayer::CloseFile() 2021-07-17 22:16:54.447 T:4668 INFO : VideoPlayer: waiting for threads to exit 2021-07-17 22:16:54.447 T:4668 INFO : VideoPlayer: finished waiting 2021-07-17 22:16:54.552 T:4771 INFO : [video.kino.pub]: playback stopped 2021-07-17 22:16:55.138 T:4771 INFO : CPythonInvoker(4, /storage/.kodi/addons/video.kino.pub/addon.py): script successfully run 2021-07-17 22:16:55.409 T:4771 INFO : Python interpreter stopped 2021-07-17 22:16:57.689 T:4779 INFO : initializing python engine. 2021-07-17 22:16:58.552 T:4779 INFO : [video.kino.pub]: sending GET request to https://api.service-kp.com/v1/items/68770 2021-07-17 22:16:59.087 T:4668 INFO : VideoPlayer::OpenFile: plugin://video.kino.pub/play/68770 2021-07-17 22:16:59.113 T:4784 INFO : Creating InputStream 2021-07-17 22:16:59.115 T:4784 INFO : AddOnLog: inputstream.adaptive: SetVideoResolution (1920 x 1080) 2021-07-17 22:16:59.465 T:4784 INFO : AddOnLog: inputstream.adaptive: Successfully parsed manifest file. #Periods: 1, #Streams in first period: 35, Type: live, Download speed: 2966018.6665 Bytes/s 2021-07-17 22:16:59.477 T:4784 INFO : Creating Demuxer 2021-07-17 22:16:59.482 T:4784 INFO : Opening stream: 1001 source: 256 2021-07-17 22:16:59.484 T:4779 ERROR : EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<-- - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS! Error Type: Error Contents: dictionary changed size during iteration Traceback (most recent call last): File "/storage/.kodi/addons/video.kino.pub/resources/lib/player.py", line 61, in onPlayBackStarted proxy.stop() File "/storage/.kodi/addons/video.kino.pub/resources/lib/proxy.py", line 104, in stop ProxyServer.stop_all_threads() File "/storage/.kodi/addons/video.kino.pub/resources/lib/proxy.py", line 89, in stop_all_threads for server, thread in cls.threads.items(): RuntimeError: dictionary changed size during iteration -->End of Python script error report<-- 2021-07-17 22:17:01.625 T:4784 INFO : CVideoPlayerVideo::OpenStream - Creating codec: 173 2021-07-17 22:17:01.625 T:4784 INFO : CBitstreamConverter::Open bitstream to annexb init 2021-07-17 22:17:01.629 T:4784 INFO : DVDVideoCodecAmlogic: Opened Amlogic Codec 2021-07-17 22:17:01.629 T:4784 INFO : Creating video thread 2021-07-17 22:17:01.630 T:4805 INFO : running thread: video_thread 2021-07-17 22:17:01.630 T:4784 INFO : Opening stream: 1003 source: 256 2021-07-17 22:17:02.880 T:4784 INFO : Finding audio codec for: 86018 2021-07-17 22:17:02.889 T:4784 INFO : CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac 2021-07-17 22:17:02.889 T:4784 INFO : Creating audio thread 2021-07-17 22:17:02.890 T:4809 INFO : running thread: CVideoPlayerAudio::Process() 2021-07-17 22:17:02.890 T:4784 INFO : Opening stream: 0 source: 1028 2021-07-17 22:17:04.030 T:4805 INFO : DVDVideoCodecAmlogic::AddData Open decoder: fps:23976/1000 2021-07-17 22:17:04.034 T:4809 INFO : Creating audio stream (codec id: 86018, channels: 6, sample rate: 48000, no pass-through) 2021-07-17 22:17:04.036 T:4677 INFO : CActiveAESink::OpenSink - initialize sink 2021-07-17 22:17:04.038 T:4677 INFO : CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=AMLMESONAUDIO,DEV=0" 2021-07-17 22:17:04.046 T:4677 INFO : CAESinkALSA::Initialize - Opened device "hdmi:CARD=AMLMESONAUDIO,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x02" 2021-07-17 22:17:04.047 T:4677 INFO : CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats 2021-07-17 22:17:04.047 T:4677 INFO : CAESinkALSA::InitializeHW - Using data format AE_FMT_S16NE 2021-07-17 22:17:04.103 T:4668 INFO : Constructing CRendererAML 2021-07-17 22:17:04.148 T:4668 INFO : Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY 2021-07-17 22:17:04.158 T:4668 INFO : [WHITELIST] Searching the whitelist for: width: 3840, height: 1600, fps: 23.976, 3D: false 2021-07-17 22:17:04.159 T:4668 INFO : Display resolution ADJUST : 3840x2160 @ 23.98 - Full Screen (40) (weight: -1041822969233408.000) 2021-07-17 22:17:04.163 T:4668 INFO : VideoPlayer: OnLostDisplay received 2021-07-17 22:17:04.163 T:4668 ERROR : GetString: error reading /sys/class/amhdmitx/amhdmitx0/custom_mode 2021-07-17 22:17:04.544 T:4668 INFO : VideoPlayer: OnResetDisplay received 2021-07-17 22:17:04.545 T:4668 INFO : GLES: Maximum texture width: 4096 2021-07-17 22:17:48.082 T:4668 INFO : CVideoPlayer::CloseFile() 2021-07-17 22:17:48.083 T:4784 INFO : CVideoPlayer::OnExit() 2021-07-17 22:17:48.083 T:4784 INFO : Closing stream player 1 2021-07-17 22:17:48.085 T:4668 INFO : VideoPlayer: waiting for threads to exit 2021-07-17 22:17:48.085 T:4784 INFO : Waiting for audio thread to exit 2021-07-17 22:17:48.093 T:4809 INFO : thread end: CVideoPlayerAudio::OnExit() 2021-07-17 22:17:48.094 T:4784 INFO : Closing audio device 2021-07-17 22:17:48.104 T:4677 INFO : CActiveAESink::OpenSink - initialize sink 2021-07-17 22:17:48.104 T:4784 INFO : Deleting audio codec 2021-07-17 22:17:48.105 T:4784 INFO : Closing stream player 2 2021-07-17 22:17:48.130 T:4784 INFO : waiting for video thread to exit 2021-07-17 22:17:48.130 T:4805 ERROR : Got MSGQ_ABORT or MSGO_IS_ERROR return true 2021-07-17 22:17:48.130 T:4805 INFO : thread end: video_thread 2021-07-17 22:17:48.132 T:4784 INFO : deleting video codec 2021-07-17 22:17:48.139 T:4784 INFO : Closing stream player 3 2021-07-17 22:17:48.152 T:4784 INFO : ADDON: Dll Destroyed - InputStream Adaptive 2021-07-17 22:17:48.153 T:4668 INFO : VideoPlayer: finished waiting 2021-07-17 22:17:48.153 T:4668 INFO : CVideoPlayer::CloseFile() 2021-07-17 22:17:48.153 T:4668 INFO : VideoPlayer: waiting for threads to exit 2021-07-17 22:17:48.153 T:4668 INFO : VideoPlayer: finished waiting 2021-07-17 22:17:48.217 T:4668 ERROR : GetString: error reading /sys/class/amhdmitx/amhdmitx0/custom_mode 2021-07-17 22:17:48.297 T:4677 INFO : CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=AMLMESONAUDIO,DEV=0" 2021-07-17 22:17:48.302 T:4677 INFO : CAESinkALSA::Initialize - Opened device "hdmi:CARD=AMLMESONAUDIO,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00" 2021-07-17 22:17:48.303 T:4677 INFO : CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats 2021-07-17 22:17:48.303 T:4677 INFO : CAESinkALSA::InitializeHW - Using data format AE_FMT_S16NE 2021-07-17 22:17:48.415 T:4668 INFO : GLES: Maximum texture width: 4096 2021-07-17 22:17:48.422 T:4668 ERROR : Control 50 in window 10025 has been asked to focus, but it can't 2021-07-17 22:17:48.923 T:4779 INFO : [video.kino.pub]: playback stopped 2021-07-17 22:17:49.105 T:4779 INFO : CPythonInvoker(5, /storage/.kodi/addons/video.kino.pub/addon.py): script successfully run 2021-07-17 22:17:49.416 T:4779 INFO : Python interpreter stopped ```
ivashin commented 3 years ago

Видимо поскольку у меня не полноценный компьютер, а относительно маломощный медиаплеер, сервер не успевает стартовать в другом потоке до запуска видео. Мне кажется, что прокси имеет смысл запускать при старте плагина и держать запущенным в памяти как сервис. По крайней мере плагины Netflix и Discovery+ делают именно так.

quarckster commented 3 years ago

video.kino.pub-3.0.4-beta-4.zip Я вообще убрал прокси и фикс для m3u8 плейлистов. Похоже на версии inputstream adaptive 2.6.20 всё работает как раньше.

ivashin commented 3 years ago

@quarckster это был бы идеальный вариант) к сожалению пока не могу протестировать - в моем репозитории пока только 2.6.18.1, но вроде скоро обещают обновить.

quarckster commented 3 years ago

@ivashin возможно на вашей версии тоже уже работает.

ivashin commented 3 years ago

Действительно все работает. Можно закрывать