plexinc/plex-for-kodi

Playback error when transcoding

gregorij89 opened this issue · 1 comments

Description:

Hi, I am seeing an error, when the session needs to be transcoded. I can see in the server dashboard, that the playback is transcoded (I am seeing the progress). The client shows the fanart with the waiting icon, but after app. 30 seconds, it returns back to the movie selection page. As I wrote, during these 30 seconds, on the PMS the progress is showed like the video is played.

I don´t have any issues with transcoding on any other client I am using (Plex Media Player /Windows/, iOS app, Android app, Web Client). Even with the same movie and the same settings. I´ve also noticed, that if transcoding should happen from the low bitrate source (eg. 720p, 4.5 Mbps) then it works. But anything even close to FullHD crash. PMS has definitely enough power to do the transcoding - it´s a docker image on amd64 Linux machine with two Xeon CPUs.

A part from the Kodi log:

2020-06-13 09:47:38.564 T:3685069696 WARNING: CreateLoader - unsupported protocol(script) in script://script.plex/-poster.jpg 2020-06-13 09:47:38.564 T:3685069696 WARNING: CreateLoader - unsupported protocol(script) in script://script.plex/-poster.png 2020-06-13 09:47:38.564 T:3685069696 WARNING: CreateLoader - unsupported protocol(script) in script://script.plex/-banner.jpg 2020-06-13 09:47:38.565 T:3685069696 WARNING: CreateLoader - unsupported protocol(script) in script://script.plex/-banner.png 2020-06-13 09:48:05.135 T:3751310208 ERROR: CCurlFile::Stat - Failed: HTTP response code said error(22) for https://XXX-XXX-XXX-XXX.bd1c1a4afbec4b489ab7c5ae9c1456da.plex.direct:32400/photo/:/transcode?url=http%3A%2F%2Fimage.tmdb.org%2Ft%2Fp%2Foriginal%2F9zI0Ed8aGxLPdTQeV0He9Rl0eSX.jpg&width=268&height=268&X-Plex-Token=TOKEN 2020-06-13 09:48:11.236 T:4089859504 NOTICE: VideoPlayer::OpenFile: https://XXX-XXX-XXX-XXX.bd1c1a4afbec4b489ab7c5ae9c1456da.plex.direct:32400/video/:/transcode/universal/start.mkv?X-Plex-Token=TOKEN&protocol=http&copyts=1&X-Plex-Client-Profile-Name=Chrome&subtitles=burn&path=%2Flibrary%2Fmetadata%2F14051&offset=0&session=b7366776-8026-4025-bfeb-f2ffa94814da&directStream=0&directPlay=0&videoQuality=75&videoResolution=1920x1080&maxVideoBitrate=10000&mediaIndex=0&partIndex=0&X-Plex-Client-Profile-Extra=append-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Dac3%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Dac3%29%2Bappend-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Deac3%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Deac3%29%2Bappend-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Ddca%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Ddca%29%2Badd-limitation%28scope%3DvideoAudioCodec%26scopeName%3Ddca%26type%3DupperBound%26name%3Daudio.channels%26value%3D8%26isRequired%3Dfalse%29%2Bappend-transcode-target-codec%28type%3DvideoProfile%26context%3Dstreaming%26videoCodec%3Dvp9%29&X-Plex-Client-Identifier=b7366776-8026-4025-bfeb-f2ffa94814da&X-Plex-Client-Profile-Name=Chrome 2020-06-13 09:48:16.703 T:3254850432 NOTICE: Creating InputStream 2020-06-13 09:48:36.963 T:3254850432 ERROR: CCurlFile::FillBuffer - Failed: Timeout was reached(28) 2020-06-13 09:48:57.383 T:3254850432 ERROR: Previous line repeats 1 times. 2020-06-13 09:48:57.384 T:3254850432 NOTICE: Creating Demuxer 2020-06-13 09:48:57.419 T:3254850432 ERROR: Open - error probing input format, https://XXX-XXX-XXX-186.bd1c1a4afbec4b489ab7c5ae9c1456da.plex.direct:32400/video/:/transcode/universal/start.mkv?X-Plex-Token=TOKEN&protocol=http&copyts=1&X-Plex-Client-Profile-Name=Chrome&subtitles=burn&path=%2Flibrary%2Fmetadata%2F14051&offset=0&session=b7366776-8026-4025-bfeb-f2ffa94814da&directStream=0&directPlay=0&videoQuality=75&videoResolution=1920x1080&maxVideoBitrate=10000&mediaIndex=0&partIndex=0&X-Plex-Client-Profile-Extra=append-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Dac3%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Dac3%29%2Bappend-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Deac3%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Deac3%29%2Bappend-transcode-target-audio-codec%28type%3DvideoProfile%26context%3Dstreaming%26audioCodec%3Ddca%29%2Badd-direct-play-profile%28type%3DvideoProfile%26container%3Dmatroska%26videoCodec%3D%2A%26audioCodec%3Ddca%29%2Badd-limitation%28scope%3DvideoAudioCodec%26scopeName%3Ddca%26type%3DupperBound%26name%3Daudio.channels%26value%3D8%26isRequired%3Dfalse%29%2Bappend-transcode-target-codec%28type%3DvideoProfile%26context%3Dstreaming%26videoCodec%3Dvp9%29&X-Plex-Client-Identifier=b7366776-8026-4025-bfeb-f2ffa94814da&X-Plex-Client-Profile-Name=Chrome 2020-06-13 09:48:57.419 T:3254850432 ERROR: OpenDemuxStream - Error creating demuxer 2020-06-13 09:48:57.420 T:3254850432 NOTICE: CVideoPlayer::OnExit() 2020-06-13 09:48:57.482 T:4089859504 NOTICE: CVideoPlayer::CloseFile() 2020-06-13 09:48:57.484 T:4089859504 NOTICE: VideoPlayer: waiting for threads to exit 2020-06-13 09:48:57.484 T:4089859504 NOTICE: VideoPlayer: finished waiting 2020-06-13 09:48:57.543 T:3263243136 ERROR: EXCEPTION: XBMC is not playing any media file 2020-06-13 09:48:58.087 T:3263243136 ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<-- - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS! Error Type: <type 'exceptions.AttributeError'> Error Contents: 'NoneType' object has no attribute 'doClose' Traceback (most recent call last): File "/storage/.kodi/addons/script.plex/lib/player.py", line 932, in onPlayBackStopped self.handler.onPlayBackStopped() File "/storage/.kodi/addons/script.plex/lib/player.py", line 336, in onPlayBackStopped self.hideOSD(delete=True) File "/storage/.kodi/addons/script.plex/lib/player.py", line 259, in hideOSD d.doClose() AttributeError: 'NoneType' object has no attribute 'doClose' -->End of Python script error report<-- 2020-06-13 09:48:58.635 T:3228271488 ERROR: Exception in thread PLAYER:MONITOR: Traceback (most recent call last): File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner File "/usr/lib/python2.7/threading.py", line 754, in run File "/storage/.kodi/addons/script.plex/lib/player.py", line 1018, in _monitor self._preplayMonitor() File "/storage/.kodi/addons/script.plex/lib/player.py", line 1032, in _preplayMonitor self.onPlayBackFailed() File "/storage/.kodi/addons/script.plex/lib/player.py", line 955, in onPlayBackFailed util.showNotification(util.T(32448, 'Playback Failed!')) File "/storage/.kodi/addons/script.plex/lib/util.py", line 179, in showNotification xbmc.executebuiltin('Notification({0},{1},{2},{3})'.format(header, message, time_ms, icon_path)) UnicodeEncodeError: 'ascii' codec can't encode character u'\u0159' in position 1: ordinal not in range(128)

Details:

  • Add-on version: 0.2.0
  • Kodi version: 18.3
  • OS Platform: CoreELEC
  • Hardware: Amlogic S905D

Not sure if this is related but im getting a crash when i try to play some movies.
Any help would be appreciated.
This is the bottom of the crash log

2020-10-22 00:23:17.091 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such device) 2020-10-22 00:23:19.324 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such file or directory) 2020-10-22 00:23:21.541 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such device) 2020-10-22 00:23:25.414 T:2119168208 ERROR: Previous line repeats 1 times. 2020-10-22 00:23:25.414 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:26.023 T:2951737552 WARNING: Previous line repeats 8 times. 2020-10-22 00:23:26.023 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such file or directory) 2020-10-22 00:23:26.025 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:28.322 T:2951737552 WARNING: Previous line repeats 44 times. 2020-10-22 00:23:28.323 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such device) 2020-10-22 00:23:28.334 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:29.812 T:1774063824 WARNING: Previous line repeats 28 times. 2020-10-22 00:23:29.812 T:1774063824 ERROR: Exception in thread sectionchanged: Traceback (most recent call last): File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner self.run() File "/usr/lib/python2.7/threading.py", line 754, in run self.__target(*self.__args, **self.__kwargs) File "/home/pi/.kodi/addons/script.plex/lib/windows/home.py", line 705, in _sectio nChanged self._sectionReallyChanged() File "/home/pi/.kodi/addons/script.plex/lib/windows/home.py", line 712, in _sectio nReallyChanged self.showHubs(section) File "/home/pi/.kodi/addons/script.plex/lib/windows/home.py", line 794, in showHub s self._showHubs(section=section, update=update) File "/home/pi/.kodi/addons/script.plex/lib/windows/home.py", line 839, in _showHu bs identifier = hub.getCleanHubIdentifier() TypeError: __call__() takes exactly 2 arguments (1 given) 2020-10-22 00:23:29.819 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:30.661 T:2951737552 WARNING: Previous line repeats 16 times. 2020-10-22 00:23:30.661 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such device) 2020-10-22 00:23:30.689 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:32.903 T:2951737552 WARNING: Previous line repeats 43 times. 2020-10-22 00:23:32.903 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such file or directory) 2020-10-22 00:23:32.944 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:33.598 T:2110775504 WARNING: Previous line repeats 12 times. 2020-10-22 00:23:33.598 T:2110775504 NOTICE: CVideoPlayerAudio::Process - stream stalled 2020-10-22 00:23:34.201 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:35.093 T:2951737552 WARNING: Previous line repeats 13 times. 2020-10-22 00:23:35.093 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such file or directory) 2020-10-22 00:23:35.118 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:37.391 T:2951737552 WARNING: Previous line repeats 44 times. 2020-10-22 00:23:37.391 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such device) 2020-10-22 00:23:37.421 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:39.603 T:2951737552 WARNING: Previous line repeats 42 times. 2020-10-22 00:23:39.603 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such file or directory) 2020-10-22 00:23:39.622 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:41.883 T:2951737552 WARNING: Previous line repeats 44 times. 2020-10-22 00:23:41.883 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such file or directory) 2020-10-22 00:23:41.927 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:42.162 T:2110775504 WARNING: Previous line repeats 4 times. 2020-10-22 00:23:42.162 T:2110775504 NOTICE: CVideoPlayerAudio::Process - stream stalled 2020-10-22 00:23:42.746 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:44.073 T:2951737552 WARNING: Previous line repeats 21 times. 2020-10-22 00:23:44.073 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such file or directory) 2020-10-22 00:23:44.124 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:46.321 T:2951737552 WARNING: Previous line repeats 42 times. 2020-10-22 00:23:46.321 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such device) 2020-10-22 00:23:46.325 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:48.571 T:2951737552 WARNING: Previous line repeats 43 times. 2020-10-22 00:23:48.571 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such device) 2020-10-22 00:23:48.580 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:50.821 T:2951737552 WARNING: Previous line repeats 43 times. 2020-10-22 00:23:50.821 T:2951737552 ERROR: open_restricted - failed to open /dev/input/event4 (No such device) 2020-10-22 00:23:50.832 T:2119168208 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 2020-10-22 00:23:50.938 T:2110775504 WARNING: Previous line repeats 2 times. 2020-10-22 00:23:50.938 T:2110775504 NOTICE: CVideoPlayerAudio::Process - stream stalled 2020-10-22 00:23:51.132 T:2972462176 NOTICE: CVideoPlayer::CloseFile() 2020-10-22 00:23:51.139 T:2081411280 NOTICE: CVideoPlayer::OnExit() 2020-10-22 00:23:51.139 T:2081411280 NOTICE: Closing stream player 1 2020-10-22 00:23:51.139 T:2081411280 NOTICE: Waiting for audio thread to exit 2020-10-22 00:23:51.145 T:2110775504 NOTICE: thread end: CVideoPlayerAudio::OnExit() 2020-10-22 00:23:51.145 T:2081411280 NOTICE: Closing audio device 2020-10-22 00:23:51.158 T:2972462176 NOTICE: VideoPlayer: waiting for threads to exit 2020-10-22 00:23:51.195 T:2081411280 NOTICE: Deleting audio codec 2020-10-22 00:23:51.195 T:2081411280 NOTICE: Closing stream player 2 2020-10-22 00:23:51.195 T:2081411280 NOTICE: waiting for video thread to exit 2020-10-22 00:23:51.233 T:2119168208 NOTICE: thread end: video_thread 2020-10-22 00:23:51.234 T:2081411280 NOTICE: deleting video codec 2020-10-22 00:23:51.244 T:2972462176 NOTICE: VideoPlayer: finished waiting 2020-10-22 00:23:51.244 T:2972462176 NOTICE: CVideoPlayer::CloseFile() 2020-10-22 00:23:51.244 T:2972462176 NOTICE: VideoPlayer: waiting for threads to exit 2020-10-22 00:23:51.244 T:2972462176 NOTICE: VideoPlayer: finished waiting 2020-10-22 00:23:51.454 T:1908445392 ERROR: EXCEPTION: XBMC is not playing any media file 2020-10-22 00:23:51.463 T:1908445392 ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the f ollowing error<-- - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS! Error Type: <type 'exceptions.ZeroDivisionError'> Error Contents: float division by zero Traceback (most recent call last): File "/home/pi/.kodi/addons/script.plex/lib/player.py", line 932, in onPlayBackSto pped self.handler.onPlayBackStopped() File "/home/pi/.kodi/addons/script.plex/lib/player.py", line 332, in onPlayBackSto pped if self.trueTime * 1000 / float(self.duration) >= 0.90 and self.next(on_end=True ): ZeroDivisionError: float division by zero -->End of Python script error report<-- 2020-10-22 00:23:51.777 T:2972462176 NOTICE: VideoPlayer::OpenFile: https://192-168-50-190.c026f5d8867041eda5ab89794e8ccb10.ple x.direct:32400/library/parts/131226/1583528528/file.mkv?X-Plex-Token=n6K5AHsyAVUbZ5bNJGi_&X-Plex-Client-Identifier=9299a7b0-3ed9 -469a-a5a3-5b11dd947fe3&X-Plex-Client-Profile-Name=Chrome 2020-10-22 00:23:51.793 T:1948238032 NOTICE: Creating InputStream 2020-10-22 00:23:51.849 T:1948238032 NOTICE: Creating Demuxer 2020-10-22 00:23:51.902 T:1948238032 NOTICE: Opening stream: 0 source: 256 2020-10-22 00:23:51.902 T:1948238032 NOTICE: Creating video codec with codec id: 173 2020-10-22 00:23:51.902 T:1948238032 ERROR: CMMALVideo::Open : Video codec unknown: ad 2020-10-22 00:23:51.902 T:1948238032 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: hevc 2020-10-22 00:23:51.905 T:1948238032 NOTICE: Creating video thread 2020-10-22 00:23:51.935 T:1757376720 NOTICE: running thread: video_thread 2020-10-22 00:23:52.056 T:1948238032 NOTICE: Opening stream: 1 source: 256 2020-10-22 00:23:52.056 T:1948238032 NOTICE: Finding audio codec for: 86018 2020-10-22 00:23:52.062 T:1948238032 NOTICE: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac 2020-10-22 00:23:52.062 T:1948238032 NOTICE: Creating audio thread 2020-10-22 00:23:52.063 T:1924112592 NOTICE: running thread: CVideoPlayerAudio::Process() 2020-10-22 00:23:52.065 T:1757376720 NOTICE: CDecoder::Open - fmt:187