search

jellyfin / jellyfin-mpv-shim

MPV Cast Client for Jellyfin
Other
1.59k stars 93 forks source link

Certain video files are not playing, while most other do #272

Closed Pysta closed 2 years ago

Pysta commented 2 years ago

Describe the bug After upgrading both jellyfin to 10.8.0 on rpi 3 - raspbian and jellyfin-mpv-shim to 2.1.0 on mac os 12.3.1, certain video files are not playing through, only thing I noticed in common with videos not playing is that they are 1080p H264 SDR, even h265 plays fine. I did manage to find h264 videos playing just fine, but I haven't found any non h.264 that stopped working.

Tried same files on EndeavourOS and they worked fine, so only Mac OS seems to be affected. Also using "Copy stream url" in jellyfin and opening it in MPV worked fine on Mac.

Example of video that did not play:

Video Title: 1080p H264 SDR Codec: H264 AVC: Yes Profile: High Level: 40 Resolution: 1918x802 Aspect ratio: 2.40:1 Interlaced: No Framerate: 23.976025 Bitrate: 11738 kbps Bit depth: 8 bit Video range: SDR Color space: bt709 Color transfer: bt709 Color primaries: bt709 Pixel format: yuv420p Ref frames: 1 NAL: 4

And video that did:

Video Title: 720p H264 SDR Codec: H264 Codec tag: avc1 AVC: No Profile: Main Level: 40 Resolution: 1280x720 Aspect ratio: 16:9 Interlaced: No Framerate: 25 Bitrate: 2011 kbps Bit depth: 8 bit Video range: SDR Color space: bt709 Color transfer: bt709 Color primaries: bt709 Pixel format: yuv420p Ref frames: 1 NAL: 0

Worth noting before upgrading both jellyfin and mpv shim those files worked fine.

To Reproduce Steps to reproduce the behavior:

  1. update jellyfin to 10.80.0 and jellyfin-mpv-shim to 2.1.0
  2. add H.264 video
  3. click on play
  4. error in console and no video playing

Desktop (please complete the following information):

Error Messages 2022-06-15 16:26:34,873 [ DEBUG] event_handler: Handled Event Play: {'ItemIds': ['*CENSORED*', '*CENSORED*'], 'PlayCommand': 'PlayNow', 'ControllingUserId': '*CENSORED*', 'ServerId': '*CENSORED*'} 2022-06-15 16:26:34,973 [ DEBUG] urllib3.connectionpool: http://*CENSORED*:8096 "GET /Users/*CENSORED*/Items/*CENSORED* HTTP/1.1" 200 None 2022-06-15 16:26:34,980 [ DEBUG] urllib3.connectionpool: Starting new HTTPS connection (1): checkip.amazonaws.com:443 2022-06-15 16:26:35,189 [ DEBUG] urllib3.connectionpool: https://checkip.amazonaws.com:443 "GET / HTTP/1.1" 200 16 2022-06-15 16:26:35,190 [ DEBUG] charset_normalizer: override steps (5) and chunk_size (512) as content does not fit (16 byte(s) given) parameters. 2022-06-15 16:26:35,190 [ WARNING] charset_normalizer: Trying to detect encoding from a tiny portion of (16) byte(s). 2022-06-15 16:26:35,190 [ INFO] charset_normalizer: ascii passed initial chaos probing. Mean measured chaos is 0.000000 % 2022-06-15 16:26:35,190 [ DEBUG] charset_normalizer: ascii should target any language(s) of ['Latin Based'] 2022-06-15 16:26:35,191 [ INFO] charset_normalizer: ascii is most likely the one. Stopping the process. 2022-06-15 16:26:35,191 [ DEBUG] event_handler: EventHandler::playMedia <jellyfin_mpv_shim.media.Media object at 0x101d50490> 2022-06-15 16:26:35,191 [ DEBUG] media: Bandwidth: local=False, bitrate=None, force=False 2022-06-15 16:26:35,283 [ DEBUG] urllib3.connectionpool: http://*CENSORED*:8096 "POST /Items/*CENSORED*/PlaybackInfo HTTP/1.1" 200 None 2022-06-15 16:26:35,285 [ ERROR] player: PlayerManager::play no URL found

iwalton3 commented 2 years ago

Please enable the config option log_decisions (see this article for help). It looks like the Jellyfin Server is sending back an empty media decision with no URLs to actually play.

relates to https://github.com/jellyfin/jellyfin-mpv-shim/issues/251

Pysta commented 2 years ago

Hopefully I didn't go overboard with censorship in the log:

2022-06-21 09:03:42,011 [ INFO] player: Using external mpv playback backend. 2022-06-21 09:03:42,012 [ DEBUG] mpv-jsonipc: Staring MPV from mpv. 2022-06-21 09:03:42,012 [ DEBUG] mpv-jsonipc: Using IPC socket /tmp/CENSORED for MPV. 2022-06-21 09:03:43,635 [ DEBUG] mpv-jsonipc: Found MPV socket. 2022-06-21 09:03:43,654 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.client: JellyfinClient initializing... 2022-06-21 09:03:43,654 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.configuration: Configuration initializing... 2022-06-21 09:03:43,654 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.configuration: Begin http constructor. 2022-06-21 09:03:43,654 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.ws_client: WSClient initializing... 2022-06-21 09:03:43,654 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.connection_manager: ConnectionManager initializing... 2022-06-21 09:03:43,654 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.credentials: Credentials initializing... 2022-06-21 09:03:43,655 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.configuration: Begin app constructor. 2022-06-21 09:03:43,656 [ INFO] JELLYFIN.jellyfin_apiclient_python.connection_manager: Begin connect 2022-06-21 09:03:43,656 [ INFO] JELLYFIN.jellyfin_apiclient_python.connection_manager: Begin getAvailableServers 2022-06-21 09:03:43,656 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.credentials: credentialsupdated 2022-06-21 09:03:43,656 [ INFO] JELLYFIN.jellyfin_apiclient_python.connection_manager: connect has 1 servers 2022-06-21 09:03:43,656 [ INFO] JELLYFIN.jellyfin_apiclient_python.connection_manager: begin connectToServer 2022-06-21 09:03:43,656 [ INFO] JELLYFIN.jellyfin_apiclient_python.api: Sending get request to system/info/public 2022-06-21 09:03:43,656 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.api: 5 2022-06-21 09:03:43,656 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.api: {'Accept': 'application/json', 'Content-type': 'application/x-www-form-urlencoded; charset=UTF-8', 'X-Application': 'Jellyfin MPV Shim/2.1.0', 'Accept-Charset': 'UTF-8,', 'Accept-encoding': 'gzip', 'User-Agent': 'Jellyfin-MPV-Shim/2.1.0', 'x-emby-authorization': 'MediaBrowser Client=Jellyfin MPV Shim, Device=CENSORED, DeviceId=CENSORED, Version=2.1.0'} 2022-06-21 09:03:43,665 [ DEBUG] urllib3.connectionpool: Starting new HTTP connection (1): CENSORED:8096 2022-06-21 09:03:44,017 [ DEBUG] urllib3.connectionpool: http://CENSORED:8096 "GET /system/info/public HTTP/1.1" 200 None 2022-06-21 09:03:44,022 [ INFO] JELLYFIN.jellyfin_apiclient_python.connection_manager: calling onSuccessfulConnection with server CENSORED 2022-06-21 09:03:44,022 [ INFO] JELLYFIN.jellyfin_apiclient_python.api: Sending get request to system/info 2022-06-21 09:03:44,022 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.api: 5 2022-06-21 09:03:44,023 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.api: {'Accept': 'application/json', 'Content-type': 'application/x-www-form-urlencoded; charset=UTF-8', 'X-Application': 'Jellyfin MPV Shim/2.1.0', 'Accept-Charset': 'UTF-8,', 'Accept-encoding': 'gzip', 'User-Agent': 'Jellyfin-MPV-Shim/2.1.0', 'x-emby-authorization': 'MediaBrowser Client=Jellyfin MPV Shim, Device=CENSORED, DeviceId=CENSORED, Version=2.1.0', 'X-MediaBrowser-Token': 'REDACTED'} 2022-06-21 09:03:44,024 [ DEBUG] urllib3.connectionpool: Starting new HTTP connection (1): CENSORED:8096 2022-06-21 09:03:45,894 [ DEBUG] urllib3.connectionpool: http://*CENSORED*:8096 "GET /system/info HTTP/1.1" 200 None 2022-06-21 09:03:45,967 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.credentials: credentialsupdated 2022-06-21 09:03:45,967 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.connection_manager: resolving connect with result: {'Servers': "[{'address': 'http://*CENSORED*:8096', 'Name': 'CENSORED', 'Id': 'CENSORED', 'DateLastAccessed': '2022-06-21T09:03:45Z', 'UserId': 'CENSORED', 'AccessToken': 'REDACTED', 'Users': [{'Id': 'CENSORED', 'IsSignedInOffline': True}], 'uuid': 'CENSORED', 'username': 'CENSORED', 'connected': True}]", 'State': 3} 2022-06-21 09:03:45,967 [ INFO] JELLYFIN.jellyfin_apiclient_python.client: User is authenticated. 2022-06-21 09:03:45,968 [ DEBUG] urllib3.util.retry: Converted retries value: 3 -> 'Retry(total=3, connect=None, read=None, redirect=None, status=None)' 2022-06-21 09:03:45,968 [ DEBUG] urllib3.util.retry: Converted retries value: 3 -> 'Retry(total=3, connect=None, read=None, redirect=None, status=None)' 2022-06-21 09:03:45,968 [ INFO] JELLYFIN.jellyfin_apiclient_python.ws_client: Websocket url: ws://CENSORED:8096/socket?api_key=REDACTEDREDACTED&device_id=CENSORED 2022-06-21 09:03:45,970 [ DEBUG] urllib3.connectionpool: Starting new HTTP connection (1): CENSORED:8096 2022-06-21 09:03:46,739 [ INFO] JELLYFIN.jellyfin_apiclient_python.ws_client: --->[ websocket ] 2022-06-21 09:03:46,739 [ DEBUG] event_handler: Unhandled Event WebSocketConnect: None 2022-06-21 09:03:47,562 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.ws_client: ForceKeepAlive received from server. 2022-06-21 09:03:47,643 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.ws_client: KeepAlive received from server. 2022-06-21 09:03:49,565 [ DEBUG] urllib3.connectionpool: http://*CENSORED*:8096 "POST /Sessions/Capabilities/Full HTTP/1.1" 204 0 2022-06-21 09:04:17,592 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.ws_client: KeepAlive received from server. 2022-06-21 09:04:47,645 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.ws_client: KeepAlive received from server. 2022-06-21 09:05:17,619 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.ws_client: KeepAlive received from server. 2022-06-21 09:05:36,990 [ DEBUG] event_handler: Handled Event GeneralCommand: {'Name': 'DisplayContent', 'ControllingUserId': 'CENSORED', 'Arguments': {'ItemId': 'CENSORED', 'ItemType': 'CollectionFolder'}, 'ServerId': 'CENSORED'} 2022-06-21 09:05:47,624 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.ws_client: KeepAlive received from server. 2022-06-21 09:05:53,208 [ DEBUG] event_handler: Handled Event GeneralCommand: {'Name': 'DisplayContent', 'ControllingUserId': 'CENSORED', 'Arguments': {'ItemId': '060c676305c7f704ba53c388c4584494', 'ItemType': 'Series'}, 'ServerId': 'CENSORED'} 2022-06-21 09:05:56,427 [ DEBUG] event_handler: Handled Event GeneralCommand: {'Name': 'DisplayContent', 'ControllingUserId': 'CENSORED', 'Arguments': {'ItemId': 'CENSORED', 'ItemType': 'Season'}, 'ServerId': 'CENSORED'} 2022-06-21 09:05:57,078 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001001', 'ItemId': 'CENSORED'}, {'UnplayedItemCount': 1, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001', 'ItemId': 'CENSORED'}], 'ServerId': 'CENSORED'} 2022-06-21 09:05:58,975 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001002', 'ItemId': '488bd0e2623f75f96ee35bc1341b4717'}, {'UnplayedItemCount': 2, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001', 'ItemId': 'CENSORED'}], 'ServerId': 'CENSORED'} 2022-06-21 09:06:00,713 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001001', 'ItemId': 'CENSORED'}, {'UnplayedItemCount': 2, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001', 'ItemId': 'CENSORED'}, {'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': 'CENSORED', 'ItemId': '437ae50f2640db433e41df8a82a809aa'}], 'ServerId': 'CENSORED'} 2022-06-21 09:06:02,329 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001002', 'ItemId': '488bd0e2623f75f96ee35bc1341b4717'}, {'UnplayedItemCount': 2, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001', 'ItemId': 'CENSORED'}, {'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001004', 'ItemId': '8ba577d3c9bbb9e65297de1900389896'}], 'ServerId': 'CENSORED'} 2022-06-21 09:06:03,157 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': 'CENSORED', 'ItemId': '437ae50f2640db433e41df8a82a809aa'}, {'UnplayedItemCount': 2, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001', 'ItemId': 'CENSORED'}, {'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001005', 'ItemId': 'de6a87ef06a0d9712f6e92bf02983ffc'}], 'ServerId': 'CENSORED'} 2022-06-21 09:06:04,819 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001004', 'ItemId': '8ba577d3c9bbb9e65297de1900389896'}, {'UnplayedItemCount': 1, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001', 'ItemId': 'CENSORED'}], 'ServerId': 'CENSORED'} 2022-06-21 09:06:06,430 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001005', 'ItemId': 'de6a87ef06a0d9712f6e92bf02983ffc'}, {'UnplayedItemCount': 1, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001', 'ItemId': 'CENSORED'}, {'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001006', 'ItemId': '9f4e242309131aadaa6180c4ee128a67'}], 'ServerId': 'CENSORED'} 2022-06-21 09:06:08,281 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001007', 'ItemId': 'CENSORED'}, {'UnplayedItemCount': 1, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001', 'ItemId': 'CENSORED'}, {'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001006', 'ItemId': '9f4e242309131aadaa6180c4ee128a67'}], 'ServerId': 'CENSORED'} 2022-06-21 09:06:09,772 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001008', 'ItemId': 'a71cb1654921be5763ad9a7125bacf71'}, {'UnplayedItemCount': 1, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'Key': '371980001', 'ItemId': 'CENSORED'}, {'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001007', 'ItemId': 'CENSORED'}], 'ServerId': 'CENSORED'} 2022-06-21 09:06:10,774 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001009', 'ItemId': 'cc8b500e7431eab893d203a1fb4140c1'}, {'UnplayedItemCount': 0, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': True, 'Key': '371980001', 'ItemId': 'CENSORED'}, {'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001008', 'ItemId': 'a71cb1654921be5763ad9a7125bacf71'}], 'ServerId': 'CENSORED'} 2022-06-21 09:06:11,324 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': 'CENSORED', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2022-06-21T07:05:55.746Z', 'Played': True, 'Key': '371980001009', 'ItemId': 'cc8b500e7431eab893d203a1fb4140c1'}, {'UnplayedItemCount': 0, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': True, 'Key': '371980001', 'ItemId': 'CENSORED'}], 'ServerId': 'CENSORED'} 2022-06-21 09:06:14,231 [ DEBUG] event_handler: Handled Event GeneralCommand: {'Name': 'DisplayContent', 'ControllingUserId': 'CENSORED', 'Arguments': {'ItemId': 'CENSORED', 'ItemType': 'CollectionFolder'}, 'ServerId': 'CENSORED'} 2022-06-21 09:06:16,245 [ DEBUG] event_handler: Handled Event Play: {'ItemIds': ['CENSORED', '488bd0e2623f75f96ee35bc1341b4717', '437ae50f2640db433e41df8a82a809aa', '8ba577d3c9bbb9e65297de1900389896', 'de6a87ef06a0d9712f6e92bf02983ffc', '9f4e242309131aadaa6180c4ee128a67', 'CENSORED', 'a71cb1654921be5763ad9a7125bacf71', 'cc8b500e7431eab893d203a1fb4140c1'], 'PlayCommand': 'PlayNow', 'ControllingUserId': 'CENSORED', 'ServerId': 'CENSORED'} 2022-06-21 09:06:16,306 [ DEBUG] urllib3.util.retry: Incremented Retry for (url='/Users/CENSORED/Items/CENSORED'): 'Retry(total=2, connect=None, read=None, redirect=None, status=None)' 2022-06-21 09:06:16,307 [ WARNING] urllib3.connectionpool: Retrying ('Retry(total=2, connect=None, read=None, redirect=None, status=None)') after connection broken by '"('Connection aborted.', ConnectionResetError(54, 'Connection reset by peer'))"': /Users/CENSORED/Items/CENSORED 2022-06-21 09:06:16,307 [ DEBUG] urllib3.connectionpool: Starting new HTTP connection (2): CENSORED:8096 2022-06-21 09:06:16,899 [ DEBUG] urllib3.connectionpool: http://*CENSORED*:8096 "GET /Users/CENSORED/Items/CENSORED HTTP/1.1" 200 None 2022-06-21 09:06:17,140 [ DEBUG] urllib3.connectionpool: Starting new HTTPS connection (1): checkip.amazonaws.com:443 2022-06-21 09:06:17,341 [ DEBUG] urllib3.connectionpool: https://checkip.amazonaws.com:443 "GET / HTTP/1.1" 200 16 2022-06-21 09:06:17,343 [ DEBUG] charset_normalizer: override steps (5) and chunk_size (512) as content does not fit (16 byte(s) given) parameters. 2022-06-21 09:06:17,343 [ WARNING] charset_normalizer: Trying to detect encoding from a tiny portion of (16) byte(s). 2022-06-21 09:06:17,347 [ INFO] charset_normalizer: ascii passed initial chaos probing. Mean measured chaos is 0.000000 % 2022-06-21 09:06:17,348 [ DEBUG] charset_normalizer: ascii should target any language(s) of ['Latin Based'] 2022-06-21 09:06:17,348 [ INFO] charset_normalizer: ascii is most likely the one. Stopping the process. 2022-06-21 09:06:17,348 [ DEBUG] event_handler: EventHandler::playMedia <jellyfin_mpv_shim.media.Media object at 0x1112890d0> 2022-06-21 09:06:17,348 [ DEBUG] media: Bandwidth: local=False, bitrate=None, force=False 2022-06-21 09:06:18,474 [ DEBUG] urllib3.connectionpool: http://*CENSORED*:8096 "POST /Items/CENSORED/PlaybackInfo HTTP/1.1" 200 None 2022-06-21 09:06:18,479 [ DEBUG] media: Media Decision: {'Protocol': 'File', 'Id': 'CENSORED', 'Path': 'CENSORED', 'Type': 'Default', 'Container': 'mkv', 'Size': 5006715904, 'Name': 'CENSORED', 'IsRemote': False, 'ETag': 'a1aa3dbb907823d73a53800253d1257d', 'RunTimeTicks': 34347520000, 'ReadAtNativeFramerate': False, 'IgnoreDts': False, 'IgnoreIndex': False, 'GenPtsInput': False, 'SupportsTranscoding': False, 'SupportsDirectStream': False, 'SupportsDirectPlay': False, 'IsInfiniteStream': False, 'RequiresOpening': False, 'RequiresClosing': False, 'RequiresLooping': False, 'SupportsProbing': True, 'VideoType': 'VideoFile', 'MediaStreams': [{'Codec': 'h264', 'ColorSpace': 'bt709', 'ColorTransfer': 'bt709', 'ColorPrimaries': 'bt709', 'TimeBase': '1/1000', 'VideoRange': 'SDR', 'DisplayTitle': '1080p H264 SDR', 'NalLengthSize': '4', 'IsInterlaced': False, 'IsAVC': True, 'BitRate': 11661315, 'BitDepth': 8, 'RefFrames': 1, 'IsDefault': True, 'IsForced': False, 'Height': 802, 'Width': 1918, 'AverageFrameRate': 23.976025, 'RealFrameRate': 23.976025, 'Profile': 'High', 'Type': 'Video', 'AspectRatio': '2.40:1', 'Index': 0, 'IsExternal': False, 'IsTextSubtitleStream': False, 'SupportsExternalStream': False, 'PixelFormat': 'yuv420p', 'Level': 40}, {'Codec': 'eac3', 'Language': 'rus', 'TimeBase': '1/1000', 'DisplayTitle': 'Russian - Dolby Digital+ - 5.1 - Default', 'IsInterlaced': False, 'ChannelLayout': '5.1', 'BitRate': 768000, 'Channels': 6, 'SampleRate': 48000, 'IsDefault': True, 'IsForced': False, 'Type': 'Audio', 'Index': 1, 'IsExternal': False, 'IsTextSubtitleStream': False, 'SupportsExternalStream': False, 'Level': 0}, {'Codec': 'eac3', 'Language': 'eng', 'TimeBase': '1/1000', 'DisplayTitle': 'English - Dolby Digital+ - 5.1', 'IsInterlaced': False, 'ChannelLayout': '5.1', 'BitRate': 768000, 'Channels': 6, 'SampleRate': 48000, 'IsDefault': False, 'IsForced': False, 'Type': 'Audio', 'Index': 2, 'IsExternal': False, 'IsTextSubtitleStream': False, 'SupportsExternalStream': False, 'Level': 0}, {'Codec': 'subrip', 'Language': 'rus', 'TimeBase': '1/1000', 'Title': 'Forced', 'LocalizedUndefined': 'Nedefinované', 'LocalizedDefault': 'Predvolené', 'LocalizedForced': 'Vynútené', 'LocalizedExternal': 'Externé', 'DisplayTitle': 'Forced - Russian - Predvolené - SUBRIP', 'IsInterlaced': False, 'IsDefault': True, 'IsForced': False, 'Type': 'Subtitle', 'Index': 3, 'IsExternal': False, 'DeliveryMethod': 'External', 'DeliveryUrl': '/Videos/CENSORED/Subtitles/3/0/Stream.srt?api_key=REDACTEDREDACTED', 'IsExternalUrl': False, 'IsTextSubtitleStream': True, 'SupportsExternalStream': True, 'Level': 0}, {'Codec': 'subrip', 'Language': 'rus', 'TimeBase': '1/1000', 'LocalizedUndefined': 'Nedefinované', 'LocalizedDefault': 'Predvolené', 'LocalizedForced': 'Vynútené', 'LocalizedExternal': 'Externé', 'DisplayTitle': 'Russian - SUBRIP', 'IsInterlaced': False, 'IsDefault': False, 'IsForced': False, 'Type': 'Subtitle', 'Index': 4, 'IsExternal': False, 'DeliveryMethod': 'External', 'DeliveryUrl': '/Videos/CENSORED/Subtitles/4/0/Stream.srt?api_key=REDACTEDREDACTED', 'IsExternalUrl': False, 'IsTextSubtitleStream': True, 'SupportsExternalStream': True, 'Level': 0}, {'Codec': 'subrip', 'Language': 'rus', 'TimeBase': '1/1000', 'Title': 'SDH', 'LocalizedUndefined': 'Nedefinované', 'LocalizedDefault': 'Predvolené', 'LocalizedForced': 'Vynútené', 'LocalizedExternal': 'Externé', 'DisplayTitle': 'SDH - Russian - SUBRIP', 'IsInterlaced': False, 'IsDefault': False, 'IsForced': False, 'Type': 'Subtitle', 'Index': 5, 'IsExternal': False, 'DeliveryMethod': 'External', 'DeliveryUrl': '/Videos/CENSORED/Subtitles/5/0/Stream.srt?api_key=REDACTEDREDACTED', 'IsExternalUrl': False, 'IsTextSubtitleStream': True, 'SupportsExternalStream': True, 'Level': 0}, {'Codec': 'subrip', 'Language': 'eng', 'TimeBase': '1/1000', 'LocalizedUndefined': 'Nedefinované', 'LocalizedDefault': 'Predvolené', 'LocalizedForced': 'Vynútené', 'LocalizedExternal': 'Externé', 'DisplayTitle': 'English - SUBRIP', 'IsInterlaced': False, 'IsDefault': False, 'IsForced': False, 'Type': 'Subtitle', 'Index': 6, 'IsExternal': False, 'DeliveryMethod': 'External', 'DeliveryUrl': '/Videos/CENSORED/Subtitles/6/0/Stream.srt?api_key=REDACTEDREDACTED', 'IsExternalUrl': False, 'IsTextSubtitleStream': True, 'SupportsExternalStream': True, 'Level': 0}, {'Codec': 'subrip', 'Language': 'eng', 'TimeBase': '1/1000', 'Title': 'SDH', 'LocalizedUndefined': 'Nedefinované', 'LocalizedDefault': 'Predvolené', 'LocalizedForced': 'Vynútené', 'LocalizedExternal': 'Externé', 'DisplayTitle': 'SDH - English - SUBRIP', 'IsInterlaced': False, 'IsDefault': False, 'IsForced': False, 'Type': 'Subtitle', 'Index': 7, 'IsExternal': False, 'DeliveryMethod': 'External', 'DeliveryUrl': '/Videos/CENSORED/Subtitles/7/0/Stream.srt?api_key=REDACTEDREDACTED', 'IsExternalUrl': False, 'IsTextSubtitleStream': True, 'SupportsExternalStream': True, 'Level': 0}, {'Codec': 'subrip', 'Language': 'heb', 'TimeBase': '1/1000', 'LocalizedUndefined': 'Nedefinované', 'LocalizedDefault': 'Predvolené', 'LocalizedForced': 'Vynútené', 'LocalizedExternal': 'Externé', 'DisplayTitle': 'Hebrew - SUBRIP', 'IsInterlaced': False, 'IsDefault': False, 'IsForced': False, 'Type': 'Subtitle', 'Index': 8, 'IsExternal': False, 'DeliveryMethod': 'External', 'DeliveryUrl': '/Videos/CENSORED/Subtitles/8/0/Stream.srt?api_key=REDACTEDREDACTED', 'IsExternalUrl': False, 'IsTextSubtitleStream': True, 'SupportsExternalStream': True, 'Level': 0}, {'Codec': 'subrip', 'Language': 'ukr', 'TimeBase': '1/1000', 'LocalizedUndefined': 'Nedefinované', 'LocalizedDefault': 'Predvolené', 'LocalizedForced': 'Vynútené', 'LocalizedExternal': 'Externé', 'DisplayTitle': 'Ukrainian - SUBRIP', 'IsInterlaced': False, 'IsDefault': False, 'IsForced': False, 'Type': 'Subtitle', 'Index': 9, 'IsExternal': False, 'DeliveryMethod': 'External', 'DeliveryUrl': '/Videos/CENSORED/Subtitles/9/0/Stream.srt?api_key=REDACTEDREDACTED', 'IsExternalUrl': False, 'IsTextSubtitleStream': True, 'SupportsExternalStream': True, 'Level': 0}], 'MediaAttachments': [], 'Formats': [], 'Bitrate': 13197315, 'RequiredHttpHeaders': {}, 'DefaultAudioStreamIndex': 1, 'DefaultSubtitleStreamIndex': 3} 2022-06-21 09:06:18,480 [ ERROR] player: PlayerManager::play no URL found 2022-06-21 09:06:18,480 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.ws_client: KeepAlive received from server. 2022-06-21 09:06:31,558 [ INFO] root: Stopping services... 2022-06-21 09:06:31,559 [ ERROR] mpv-jsonipc: Socket connection died. Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/python_mpv_jsonipc.py", line 168, in run current_data = self.socket.recv(1024) OSError: [Errno 9] Bad file descriptor

iwalton3 commented 2 years ago

The error message is correct…

'SupportsTranscoding': False, 'SupportsDirectStream': False, 'SupportsDirectPlay': False,

The Jellyfin server is claiming your file does not support playback in any way.

Do you have any kind of bandwidth limit or have transcoding disabled? Posting a server log might help.

Pysta commented 2 years ago

I do have transcoding disabled, mainly because raspberry is probably too slow for that. Other than that, no other limit as far as I know, definitely no change from me while upgrading to newer jellyfin/jellyfin-mpv-shim.

server log when starting the server:

[2022-06-21 06:52:01.200 +01:00] [INF] Loaded plugin: "Fanart" "10.0.0.0" [2022-06-21 06:52:01.213 +01:00] [INF] Loaded plugin: "Kitsu" "4.0.0.0" [2022-06-21 06:52:01.217 +01:00] [INF] Loaded plugin: "Open Subtitles" "18.0.0.0" [2022-06-21 06:52:01.220 +01:00] [INF] Loaded plugin: "Skin Manager" "2.0.1" [2022-06-21 06:52:01.223 +01:00] [INF] Loaded plugin: "TheTVDB" "8.0.0.0" [2022-06-21 06:52:01.226 +01:00] [INF] Loaded plugin: "TMDb" "10.8.0.0" [2022-06-21 06:52:01.228 +01:00] [INF] Loaded plugin: "Studio Images" "10.8.0.0" [2022-06-21 06:52:01.230 +01:00] [INF] Loaded plugin: "OMDb" "10.8.0.0" [2022-06-21 06:52:01.232 +01:00] [INF] Loaded plugin: "MusicBrainz" "10.8.0.0" [2022-06-21 06:52:01.234 +01:00] [INF] Loaded plugin: "AudioDB" "10.8.0.0" [2022-06-21 06:52:02.361 +01:00] [INF] Kestrel listening on "All Addresses" [2022-06-21 06:52:05.311 +01:00] [INF] Running startup tasks [2022-06-21 06:52:05.533 +01:00] [INF] Daily trigger for "Extrahovať obrázky kapitol" set to fire at 2022-06-22 02:00:00.000 +01:00, which is 19:07:54.4678986 from now. [2022-06-21 06:52:06.769 +01:00] [INF] Found ffmpeg version "5.0.1" [2022-06-21 06:52:07.055 +01:00] [INF] Available "decoders": ["libdav1d", "av1", "h264", "hevc", "mpeg2video", "mpeg4", "msmpeg4", "vp8", "libvpx", "vp9", "libvpx-vp9", "aac", "ac3", "flac", "mp3"] [2022-06-21 06:52:07.124 +01:00] [INF] Available "encoders": ["libx264", "h264_v4l2m2m", "libx265", "mpeg4", "msmpeg4", "libvpx", "libvpx-vp9", "aac", "libfdk_aac", "ac3", "flac", "libmp3lame", "libopus", "libvorbis", "srt"] [2022-06-21 06:52:07.200 +01:00] [INF] Available filters: ["hwupload_vaapi", "zscale", "alphasrc"] [2022-06-21 06:52:07.262 +01:00] [WRN] Filter: "scale_cuda" with option "Output format (default \"same\")" is not available [2022-06-21 06:52:07.326 +01:00] [WRN] Filter: "tonemap_cuda" with option "GPU accelerated HDR to SDR tonemapping" is not available [2022-06-21 06:52:07.382 +01:00] [WRN] Filter: "tonemap_opencl" with option "bt2390" is not available [2022-06-21 06:52:07.437 +01:00] [WRN] Filter: "overlay_opencl" with option "Action to take when encountering EOF from secondary input" is not available [2022-06-21 06:52:07.504 +01:00] [WRN] Filter: "overlay_vaapi" with option "Action to take when encountering EOF from secondary input" is not available [2022-06-21 06:52:07.583 +01:00] [INF] Available hwaccel types: ["drm"] [2022-06-21 06:52:07.655 +01:00] [INF] FFmpeg: "/usr/lib/jellyfin-ffmpeg/ffmpeg" [2022-06-21 06:52:07.708 +01:00] [INF] ServerId: "CENSORED" [2022-06-21 06:52:08.411 +01:00] [INF] Executed all pre-startup entry points in 0:00:00.6551208 [2022-06-21 06:52:08.411 +01:00] [INF] Core startup complete [2022-06-21 06:52:08.572 +01:00] [INF] "StartupTrigger" fired for task: "Aktualizovať zásuvné moduly" [2022-06-21 06:52:08.578 +01:00] [INF] Queuing task "PluginUpdateTask" [2022-06-21 06:52:08.595 +01:00] [INF] Executing "Aktualizovať zásuvné moduly" [2022-06-21 06:52:10.208 +01:00] [INF] Executed all post-startup entry points in 0:00:01.7957588 [2022-06-21 06:52:10.208 +01:00] [INF] Startup complete 0:01:12.5219665 [2022-06-21 06:52:10.382 +01:00] [INF] Watching directory "CENSORED" [2022-06-21 06:52:10.382 +01:00] [INF] Watching directory "CENSORED" [2022-06-21 06:52:11.172 +01:00] [INF] Watching directory "CENSORED" [2022-06-21 06:52:11.856 +01:00] [INF] Watching directory "CENSORED" [2022-06-21 06:52:11.980 +01:00] [INF] Watching directory "CENSORED" [2022-06-21 06:52:12.768 +01:00] [INF] "Aktualizovať zásuvné moduly" Completed after 0 minute(s) and 4 seconds [2022-06-21 06:52:12.806 +01:00] [INF] ExecuteQueuedTasks

Part of the server log when I was trying to play that file:

[2022-06-21 08:06:11.648 +01:00] [WRN] Slow HTTP Response from "http://CENSORED/Shows/NextUp?Limit=24&Fields=PrimaryImageAspectRatio%2CDateCreated%2CBasicSyncInfo%2CPath%2CMediaSourceCount&UserId=CENSORED&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CBanner%2CThumb&EnableTotalRecordCount=false&DisableFirstEpisode=false&NextUpDateCutoff=2021-06-21T07%3A06%3A10.873Z&EnableRewatching=false" to "CENSORED" in 0:00:00.6471351 with Status Code 200 [2022-06-21 08:06:16.975 +01:00] [WRN] Slow HTTP Response from "http://CENSORED:8096/Users/CENSORED/Items/CENSORED" to "CENSORED" in 0:00:00.5447542 with Status Code 200 [2022-06-21 08:06:18.252 +01:00] [INF] User policy for "CENSORED". EnablePlaybackRemuxing: False EnableVideoPlaybackTranscoding: False EnableAudioPlaybackTranscoding: False [2022-06-21 08:06:18.416 +01:00] [INF] StreamBuilder.BuildVideoItem( Profile="Jellyfin MPV Shim", Path="CENSORED.mkv", AudioStreamIndex=null, SubtitleStreamIndex=null ) => ( PlayMethod=Transcode, TranscodeReason=ContainerBitrateExceedsLimit ) "media:/videos/CENSORED/stream?MediaSourceId=CENSORED&AudioStreamIndex=1&SubtitleStreamIndex=3&api_key=&SubtitleMethod=Encode&RequireAvc=false&Tag=a1aa3dbb907823d73a53800253d1257d&TranscodeReasons=ContainerBitrateExceedsLimit" [2022-06-21 08:06:18.550 +01:00] [WRN] Slow HTTP Response from "http://CENSORED:8096/Items/CENSORED/PlaybackInfo" to "CENSORED" in 0:00:01.1013232 with Status Code 200

iwalton3 commented 2 years ago

ContainerBitrateExceedsLimit

The log said earlier that your server appeared as non-local so it is applying the remote streaming bitrate limit. Which then since you have both transcoding and remuxing disabled it can't play the media at all.

In your client configuration, set the remote transcode quality to something higher or disable it completely. This option is under video settings. Of course, if that exceeds your internet upload speed and the server really is not local as the IP address detection suggests, you may have issues.

You may be able to squeeze a little more out of the upload bandwidth by enabling remuxing which the Raspberry PI should be able to handle.

Pysta commented 2 years ago

that worked, thank you, for anyone else wondering, just open any other video, hit "C" in MPV -> video preferences -> remote transcode quality -> No transcode 2Gbps