External MPV skips episodes without playback

aaakoako commented 1 year ago

Describe the bug

When using a third-party MPV player, when i click on a new episode or the next episode on the emby web, it will keep skipping until an episode is loaded correctly, and it will mark the skipped episodes as watched. I use a third-party MPV called MPV-LAZY, which has the latest version on github. I suspect that some timeout detection triggered this behavior, but I tried to modify the parameters such as ‘sync_max_delay_skip’ in conf.json, and it had no effect.

Expected behavior I hope to fix this bug.

Screenshots None

Desktop (please complete the following information):

OS: Windows
Version 2.5.0

Error Messages (I replaced the correct domain name in the log with xxx.) 2023-02-27 13:42:35,184 [ WARNING] utils: checkip.amazonaws.com is unavailable. Assuming potential WAN ip is remote. File "urllib3\connection.py", line 174, in _new_conn

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "urllib3\connectionpool.py", line 703, in urlopen File "urllib3\connectionpool.py", line 386, in _make_request File "urllib3\connectionpool.py", line 1042, in _validate_conn File "urllib3\connection.py", line 358, in connect File "urllib3\connection.py", line 186, in _new_conn urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x000001D16DBE5F40>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "requests\adapters.py", line 489, in send File "urllib3\connectionpool.py", line 787, in urlopen File "urllib3\util\retry.py", line 592, in increment urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16DBE5F40>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "jellyfin_mpv_shim\utils.py", line 77, in is_local_domain File "requests\api.py", line 73, in get File "requests\api.py", line 59, in request File "requests\sessions.py", line 587, in request File "requests\sessions.py", line 701, in send File "requests\adapters.py", line 565, in send requests.exceptions.ConnectionError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16DBE5F40>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed')) 2023-02-27 13:42:35,186 [ DEBUG] event_handler: EventHandler::playMedia <jellyfin_mpv_shim.media.Media object at 0x000001D16DBBCCD0> 2023-02-27 13:42:35,186 [ DEBUG] media: Bandwidth: local=False, bitrate=None, force=False 2023-02-27 13:42:35,424 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Items/987937/PlaybackInfo HTTP/1.1" 200 None 2023-02-27 13:42:35,424 [ DEBUG] media: Using direct url. 2023-02-27 13:42:35,425 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 13:42:35,426 [ INFO] mpv: cplayer: Resuming playback. This behavior can be disabled with --no-resume-playback. 2023-02-27 13:42:36,881 [ DEBUG] websocket: Sending ping 2023-02-27 13:42:37,726 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x1596 24.000fps) 2023-02-27 13:42:37,726 [ INFO] mpv: cplayer: (+) Audio --aid=1 () (aac 2ch 48000Hz) 2023-02-27 13:42:37,726 [ INFO] mpv: display-tags: File tags: 2023-02-27 13:42:37,726 [ INFO] mpv: display-tags: Date: 2022-12-09T10:33:09.2303085+08:00 2023-02-27 13:42:38,079 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 13:42:38,079 [ INFO] mpv: auto_profiles: Applying auto profile: deband_bitrate 2023-02-27 13:42:38,080 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 13:42:38,080 [ DEBUG] player: PlayerManager::play selecting subtitle stream (none) 2023-02-27 13:42:39,430 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 13:42:39,430 [ INFO] update_check: Checking for updates... 2023-02-27 13:42:39,430 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 13:42:39,431 [ DEBUG] urllib3.connectionpool: Starting new HTTPS connection (1): github.com:443 2023-02-27 13:42:39,432 [ INFO] trickplay: No chapters available 2023-02-27 13:42:39,490 [ INFO] mpv: cplayer: AO: [wasapi] 192000Hz stereo 2ch float 2023-02-27 13:42:39,849 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 13:42:39,849 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 13:42:39,955 [ DEBUG] urllib3.connectionpool: https://github.com:443 "GET /jellyfin/jellyfin-mpv-shim/releases/latest HTTP/1.1" 302 0 2023-02-27 13:42:40,716 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 13:42:40,716 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 13:42:41,036 [ INFO] mpv: cplayer: VO: [gpu] 1732x720 yuv420p 2023-02-27 13:42:41,164 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 13:42:41,165 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 24, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T05:42:36.0000000Z', 'Played': True, 'ItemId': '987937'}], 'ServerId': '000000000'} 2023-02-27 13:42:42,478 [ DEBUG] websocket: Sending ping 2023-02-27 13:42:43,333 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 13:42:45,446 [ DEBUG] event_handler: Handled Event Playstate: {'Id': '0f7e9140410672be90430730ea0ea45f', 'Command': 'NextTrack', 'ControllingUserId': '000000000', 'ServerId': '000000000'} 2023-02-27 13:42:45,689 [ DEBUG] urllib3.connectionpool: https://xxx:443 "GET /Users/000000000/Items/987938 HTTP/1.1" 200 2099 2023-02-27 13:42:45,695 [ DEBUG] urllib3.connectionpool: Starting new HTTPS connection (1): checkip.amazonaws.com:443 2023-02-27 13:42:45,695 [ WARNING] utils: checkip.amazonaws.com is unavailable. Assuming potential WAN ip is remote. Traceback (most recent call last): File "urllib3\connection.py", line 174, in _new_conn File "urllib3\util\connection.py", line 72, in create_connection File "socket.py", line 954, in getaddrinfo socket.gaierror: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "urllib3\connectionpool.py", line 703, in urlopen File "urllib3\connectionpool.py", line 386, in _make_request File "urllib3\connectionpool.py", line 1042, in _validate_conn File "urllib3\connection.py", line 358, in connect File "urllib3\connection.py", line 186, in _new_conn urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x000001D16DBEC9D0>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "requests\adapters.py", line 489, in send File "urllib3\connectionpool.py", line 787, in urlopen File "urllib3\util\retry.py", line 592, in increment urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16DBEC9D0>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "jellyfin_mpv_shim\utils.py", line 77, in is_local_domain File "requests\api.py", line 73, in get File "requests\api.py", line 59, in request File "requests\sessions.py", line 587, in request File "requests\sessions.py", line 701, in send File "requests\adapters.py", line 565, in send requests.exceptions.ConnectionError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16DBEC9D0>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed')) 2023-02-27 13:42:45,929 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing/Stopped HTTP/1.1" 204 0 2023-02-27 13:42:45,929 [ DEBUG] media: Bandwidth: local=False, bitrate=None, force=False 2023-02-27 13:42:46,164 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Items/987938/PlaybackInfo HTTP/1.1" 200 None 2023-02-27 13:42:46,164 [ DEBUG] media: Using direct url. 2023-02-27 13:42:46,165 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 13:42:46,166 [ INFO] mpv: cplayer: Saving state. 2023-02-27 13:42:46,451 [ INFO] mpv: cplayer: 2023-02-27 13:42:46,451 [ INFO] mpv: auto_profiles: Restoring profile: deband_bitrate 2023-02-27 13:42:46,452 [ INFO] mpv: cplayer: Resuming playback. This behavior can be disabled with --no-resume-playback. 2023-02-27 13:42:46,893 [ DEBUG] websocket: Sending ping 2023-02-27 13:42:48,719 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x1596 24.000fps) 2023-02-27 13:42:48,719 [ INFO] mpv: cplayer: (+) Audio --aid=1 () (aac 2ch 48000Hz) 2023-02-27 13:42:48,720 [ INFO] mpv: display-tags: File tags: 2023-02-27 13:42:48,720 [ INFO] mpv: display-tags: Date: 2022-12-09T10:33:42.8757517+08:00 2023-02-27 13:42:48,787 [ INFO] mpv: auto_profiles: Applying auto profile: deband_bitrate 2023-02-27 13:42:48,787 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 13:42:48,787 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 13:42:48,788 [ DEBUG] player: PlayerManager::play selecting subtitle stream (none) 2023-02-27 13:42:49,960 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 13:42:49,960 [ INFO] update_check: Update check performed in last day. Skipping. 2023-02-27 13:42:49,960 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 13:42:49,960 [ INFO] trickplay: No chapters available 2023-02-27 13:42:49,960 [ DEBUG] player: PlayerManager::finished_callback starting next episode 2023-02-27 13:42:49,961 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 24, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T05:42:36.0000000Z', 'Played': True, 'ItemId': '987937'}, {'UnplayedItemCount': 5, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'ItemId': '987936'}], 'ServerId': '000000000'} 2023-02-27 13:42:50,219 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 13:42:50,219 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 13:42:50,259 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 13:42:50,259 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 13:42:52,479 [ DEBUG] websocket: Sending ping 2023-02-27 13:42:54,141 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 12, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T05:42:46.0000000Z', 'Played': True, 'ItemId': '987938'}], 'ServerId': '000000000'} 2023-02-27 13:42:54,225 [ DEBUG] urllib3.connectionpool: https://xxx:443 "GET /Users/000000000/Items/987939 HTTP/1.1" 200 1683 2023-02-27 13:42:54,227 [ DEBUG] urllib3.connectionpool: Starting new HTTPS connection (1): checkip.amazonaws.com:443 2023-02-27 13:42:54,227 [ WARNING] utils: checkip.amazonaws.com is unavailable. Assuming potential WAN ip is remote. Traceback (most recent call last): File "urllib3\connection.py", line 174, in _new_conn File "urllib3\util\connection.py", line 72, in create_connection File "socket.py", line 954, in getaddrinfo socket.gaierror: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "urllib3\connectionpool.py", line 703, in urlopen File "urllib3\connectionpool.py", line 386, in _make_request File "urllib3\connectionpool.py", line 1042, in _validate_conn File "urllib3\connection.py", line 358, in connect File "urllib3\connection.py", line 186, in _new_conn urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x000001D16DC15DC0>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "requests\adapters.py", line 489, in send File "urllib3\connectionpool.py", line 787, in urlopen File "urllib3\util\retry.py", line 592, in increment urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16DC15DC0>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "jellyfin_mpv_shim\utils.py", line 77, in is_local_domain File "requests\api.py", line 73, in get File "requests\api.py", line 59, in request File "requests\sessions.py", line 587, in request File "requests\sessions.py", line 701, in send File "requests\adapters.py", line 565, in send requests.exceptions.ConnectionError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16DC15DC0>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed')) 2023-02-27 13:42:54,466 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing/Stopped HTTP/1.1" 204 0 2023-02-27 13:42:54,466 [ DEBUG] media: Bandwidth: local=False, bitrate=None, force=False 2023-02-27 13:42:54,708 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Items/987939/PlaybackInfo HTTP/1.1" 200 None 2023-02-27 13:42:54,711 [ DEBUG] media: Using direct url. 2023-02-27 13:42:54,711 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 13:42:54,713 [ INFO] mpv: cplayer: Saving state. 2023-02-27 13:42:54,968 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 12, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T05:42:46.0000000Z', 'Played': True, 'ItemId': '987938'}, {'UnplayedItemCount': 5, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'ItemId': '987936'}], 'ServerId': '000000000'} 2023-02-27 13:42:55,030 [ INFO] mpv: cplayer: 2023-02-27 13:42:55,031 [ INFO] mpv: auto_profiles: Restoring profile: deband_bitrate 2023-02-27 13:42:55,031 [ INFO] mpv: cplayer: Resuming playback. This behavior can be disabled with --no-resume-playback. 2023-02-27 13:42:56,900 [ DEBUG] websocket: Sending ping 2023-02-27 13:42:57,431 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x1596 24.000fps) 2023-02-27 13:42:57,431 [ INFO] mpv: cplayer: (+) Audio --aid=1 () (aac 2ch 48000Hz) 2023-02-27 13:42:57,431 [ INFO] mpv: display-tags: File tags: 2023-02-27 13:42:57,431 [ INFO] mpv: display-tags: Date: 2022-12-16T13:06:56.2223374+08:00 2023-02-27 13:42:57,498 [ INFO] mpv: auto_profiles: Applying auto profile: deband_bitrate 2023-02-27 13:42:57,499 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 13:42:57,499 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 13:42:57,499 [ DEBUG] player: PlayerManager::play selecting subtitle stream (none) 2023-02-27 13:42:57,738 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 13:42:57,738 [ INFO] update_check: Update check performed in last day. Skipping. 2023-02-27 13:42:57,738 [ DEBUG] player: PlayerManager::finished_callback starting next episode 2023-02-27 13:42:57,738 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 13:42:57,738 [ INFO] trickplay: No chapters available 2023-02-27 13:42:58,123 [ DEBUG] urllib3.connectionpool: https://xxx:443 "GET /Users/000000000/Items/987941 HTTP/1.1" 200 2212 2023-02-27 13:42:58,128 [ DEBUG] urllib3.connectionpool: Starting new HTTPS connection (1): checkip.amazonaws.com:443 2023-02-27 13:42:58,128 [ WARNING] utils: checkip.amazonaws.com is unavailable. Assuming potential WAN ip is remote. Traceback (most recent call last): File "urllib3\connection.py", line 174, in _new_conn File "urllib3\util\connection.py", line 72, in create_connection File "socket.py", line 954, in getaddrinfo socket.gaierror: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "urllib3\connectionpool.py", line 703, in urlopen File "urllib3\connectionpool.py", line 386, in _make_request File "urllib3\connectionpool.py", line 1042, in _validate_conn File "urllib3\connection.py", line 358, in connect File "urllib3\connection.py", line 186, in _new_conn urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x000001D16DBBC700>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "requests\adapters.py", line 489, in send File "urllib3\connectionpool.py", line 787, in urlopen File "urllib3\util\retry.py", line 592, in increment urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16DBBC700>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "jellyfin_mpv_shim\utils.py", line 77, in is_local_domain File "requests\api.py", line 73, in get File "requests\api.py", line 59, in request File "requests\sessions.py", line 587, in request File "requests\sessions.py", line 701, in send File "requests\adapters.py", line 565, in send requests.exceptions.ConnectionError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16DBBC700>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed')) 2023-02-27 13:42:58,363 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing/Stopped HTTP/1.1" 204 0 2023-02-27 13:42:58,364 [ DEBUG] media: Bandwidth: local=False, bitrate=None, force=False 2023-02-27 13:42:58,461 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 13:42:58,461 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 13:42:58,500 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 13:42:58,500 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 13:42:58,596 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Items/987941/PlaybackInfo HTTP/1.1" 200 None 2023-02-27 13:42:58,606 [ DEBUG] media: Using direct url. 2023-02-27 13:42:58,917 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 11, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T05:42:54.0000000Z', 'Played': True, 'ItemId': '987939'}, {'UnplayedItemCount': 5, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'ItemId': '987936'}], 'ServerId': '000000000'} 2023-02-27 13:42:59,270 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 13:42:59,372 [ INFO] mpv: cplayer: Saving state. 2023-02-27 13:42:59,664 [ INFO] mpv: cplayer: 2023-02-27 13:42:59,664 [ INFO] mpv: auto_profiles: Restoring profile: deband_bitrate 2023-02-27 13:42:59,665 [ INFO] mpv: cplayer: Resuming playback. This behavior can be disabled with --no-resume-playback. 2023-02-27 13:43:01,429 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x1596 24.000fps) 2023-02-27 13:43:01,429 [ INFO] mpv: cplayer: (+) Audio --aid=1 () (aac 2ch 48000Hz) 2023-02-27 13:43:01,491 [ INFO] mpv: auto_profiles: Applying auto profile: deband_bitrate 2023-02-27 13:43:01,492 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 13:43:01,492 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 13:43:01,492 [ DEBUG] player: PlayerManager::play selecting subtitle stream (none) 2023-02-27 13:43:01,742 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 13:43:01,743 [ INFO] update_check: Update check performed in last day. Skipping. 2023-02-27 13:43:01,743 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 13:43:01,743 [ DEBUG] player: PlayerManager::finished_callback starting next episode 2023-02-27 13:43:01,743 [ INFO] trickplay: No chapters available 2023-02-27 13:43:01,979 [ DEBUG] urllib3.connectionpool: https://xxx:443 "GET /Users/000000000/Items/987942 HTTP/1.1" 200 2212 2023-02-27 13:43:01,982 [ DEBUG] urllib3.connectionpool: Starting new HTTPS connection (1): checkip.amazonaws.com:443 2023-02-27 13:43:01,982 [ WARNING] utils: checkip.amazonaws.com is unavailable. Assuming potential WAN ip is remote. Traceback (most recent call last): File "urllib3\connection.py", line 174, in _new_conn File "urllib3\util\connection.py", line 72, in create_connection File "socket.py", line 954, in getaddrinfo socket.gaierror: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "urllib3\connectionpool.py", line 703, in urlopen File "urllib3\connectionpool.py", line 386, in _make_request File "urllib3\connectionpool.py", line 1042, in _validate_conn File "urllib3\connection.py", line 358, in connect File "urllib3\connection.py", line 186, in _new_conn urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x000001D16E52DB80>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "requests\adapters.py", line 489, in send File "urllib3\connectionpool.py", line 787, in urlopen File "urllib3\util\retry.py", line 592, in increment urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16E52DB80>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "jellyfin_mpv_shim\utils.py", line 77, in is_local_domain File "requests\api.py", line 73, in get File "requests\api.py", line 59, in request File "requests\sessions.py", line 587, in request File "requests\sessions.py", line 701, in send File "requests\adapters.py", line 565, in send requests.exceptions.ConnectionError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16E52DB80>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed')) 2023-02-27 13:43:02,228 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing/Stopped HTTP/1.1" 204 0 2023-02-27 13:43:02,228 [ DEBUG] media: Bandwidth: local=False, bitrate=None, force=False 2023-02-27 13:43:02,399 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 13:43:02,400 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 13:43:02,439 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 13:43:02,439 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 13:43:02,474 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Items/987942/PlaybackInfo HTTP/1.1" 200 None 2023-02-27 13:43:02,492 [ DEBUG] media: Using direct url. 2023-02-27 13:43:02,492 [ DEBUG] websocket: Sending ping 2023-02-27 13:43:02,725 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 10, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T05:42:58.0000000Z', 'Played': True, 'ItemId': '987941'}, {'UnplayedItemCount': 5, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'ItemId': '987936'}], 'ServerId': '000000000'} 2023-02-27 13:43:03,212 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 13:43:03,316 [ INFO] mpv: cplayer: Saving state. 2023-02-27 13:43:03,604 [ INFO] mpv: cplayer: 2023-02-27 13:43:03,605 [ INFO] mpv: auto_profiles: Restoring profile: deband_bitrate 2023-02-27 13:43:05,755 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x1596 24.000fps) 2023-02-27 13:43:05,755 [ INFO] mpv: cplayer: (+) Audio --aid=1 () (aac 2ch 48000Hz) 2023-02-27 13:43:05,755 [ INFO] mpv: display-tags: File tags: 2023-02-27 13:43:05,755 [ INFO] mpv: display-tags: Date: 2022-12-30T09:51:27.2004954+08:00 2023-02-27 13:43:05,820 [ INFO] mpv: auto_profiles: Applying auto profile: deband_bitrate 2023-02-27 13:43:05,821 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 13:43:05,822 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 13:43:05,822 [ DEBUG] player: PlayerManager::play selecting subtitle stream (none) 2023-02-27 13:43:06,063 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 13:43:06,063 [ INFO] update_check: Update check performed in last day. Skipping. 2023-02-27 13:43:06,063 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 13:43:06,063 [ DEBUG] player: PlayerManager::finished_callback starting next episode 2023-02-27 13:43:06,063 [ INFO] trickplay: No chapters available 2023-02-27 13:43:06,276 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 13:43:06,276 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 13:43:06,291 [ DEBUG] urllib3.connectionpool: https://xxx:443 "GET /Users/000000000/Items/987940 HTTP/1.1" 200 2081 2023-02-27 13:43:06,302 [ DEBUG] urllib3.connectionpool: Starting new HTTPS connection (1): checkip.amazonaws.com:443 2023-02-27 13:43:06,302 [ WARNING] utils: checkip.amazonaws.com is unavailable. Assuming potential WAN ip is remote. Traceback (most recent call last): File "urllib3\connection.py", line 174, in _new_conn File "urllib3\util\connection.py", line 72, in create_connection File "socket.py", line 954, in getaddrinfo socket.gaierror: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "urllib3\connectionpool.py", line 703, in urlopen File "urllib3\connectionpool.py", line 386, in _make_request File "urllib3\connectionpool.py", line 1042, in _validate_conn File "urllib3\connection.py", line 358, in connect File "urllib3\connection.py", line 186, in _new_conn urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x000001D16DBE5940>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "requests\adapters.py", line 489, in send File "urllib3\connectionpool.py", line 787, in urlopen File "urllib3\util\retry.py", line 592, in increment urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16DBE5940>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "jellyfin_mpv_shim\utils.py", line 77, in is_local_domain File "requests\api.py", line 73, in get File "requests\api.py", line 59, in request File "requests\sessions.py", line 587, in request File "requests\sessions.py", line 701, in send File "requests\adapters.py", line 565, in send requests.exceptions.ConnectionError: HTTPSConnectionPool(host='checkip.amazonaws.com', port=443): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x000001D16DBE5940>: Failed to establish a new connection: [Errno 11004] getaddrinfo failed')) 2023-02-27 13:43:06,565 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 5, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T05:43:02.0000000Z', 'Played': True, 'ItemId': '987942'}], 'ServerId': '000000000'} 2023-02-27 13:43:06,902 [ DEBUG] websocket: Sending ping 2023-02-27 13:43:07,094 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 13:43:07,094 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 13:43:07,554 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Sessions/Playing/Stopped HTTP/1.1" 204 0 2023-02-27 13:43:07,555 [ DEBUG] media: Bandwidth: local=False, bitrate=None, force=False 2023-02-27 13:43:07,793 [ DEBUG] urllib3.connectionpool: https://xxx:443 "POST /Items/987940/PlaybackInfo HTTP/1.1" 200 None 2023-02-27 13:43:07,793 [ DEBUG] media: Using direct url. 2023-02-27 13:43:08,055 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 5, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T05:43:02.0000000Z', 'Played': True, 'ItemId': '987942'}, {'UnplayedItemCount': 5, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'ItemId': '987936'}], 'ServerId': '000000000'} 2023-02-27 13:43:12,499 [ DEBUG] websocket: Sending ping 2023-02-27 13:43:16,903 [ DEBUG] websocket: Sending ping 2023-02-27 13:43:22,513 [ DEBUG] websocket: Sending ping 2023-02-27 13:43:26,907 [ DEBUG] websocket: Sending ping 2023-02-27 13:43:32,516 [ DEBUG] websocket: Sending ping 2023-02-27 13:43:36,907 [ DEBUG] websocket: Sending ping 2023-02-27 13:43:37,808 [ ERROR] mpv-jsonipc: EventHandler caught exception from (<function PlayerManager.init..handle_stop at 0x000001D16DB40040>, ()). Traceback (most recent call last): File "python_mpv_jsonipc.py", line 89, in send File "multiprocessing\connection.py", line 188, in send_bytes File "multiprocessing\connection.py", line 141, in _check_closed OSError: handle is closed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "python_mpv_jsonipc.py", line 382, in run File "jellyfin_mpv_shim\player.py", line 246, in handle_stop File "jellyfin_mpv_shim\utils.py", line 54, in _synchronizer File "jellyfin_mpv_shim\player.py", line 608, in stop File "python_mpv_jsonipc.py", line 643, in getattr File "python_mpv_jsonipc.py", line 639, in command File "python_mpv_jsonipc.py", line 335, in command File "python_mpv_jsonipc.py", line 92, in send BrokenPipeError: handle is closed 2023-02-27 13:43:42,517 [ DEBUG] websocket: Sending ping 2023-02-27 13:43:46,918 [ DEBUG] websocket: Sending ping 2023-02-27 13:43:52,524 [ DEBUG] websocket: Sending ping

and here is the setting i have: { "allow_transcode_to_h265": false, "always_transcode": false, "audio_output": "hdmi", "auto_play": true, "check_updates": true, "client_uuid": "xxxxxxxxxxxxx", "connect_retry_mins": 0, "direct_paths": false, "discord_presence": false, "display_mirroring": false, "enable_gui": true, "enable_osc": false, "force_audio_codec": null, "force_set_played": false, "force_video_codec": null, "fullscreen": false, "health_check_interval": 300, "idle_cmd": null, "idle_cmd_delay": 60, "idle_ended_cmd": null, "idle_when_paused": false, "ignore_ssl_cert": false, "kb_debug": "~", "kb_fullscreen": "f", "kb_kill_shader": "k", "kb_menu": "c", "kb_menu_down": "down", "kb_menu_esc": "esc", "kb_menu_left": "left", "kb_menu_ok": "enter", "kb_menu_right": "right", "kb_menu_up": "up", "kb_next": ">", "kb_pause": "space", "kb_prev": "<", "kb_stop": "q", "kb_unwatched": "u", "kb_watched": "w", "lang": null, "lang_filter": "und,eng,jpn,mis,mul,zxx", "lang_filter_audio": false, "lang_filter_sub": false, "local_kbps": 2147483, "log_decisions": false, "media_ended_cmd": null, "media_key_seek": false, "media_keys": true, "menu_mouse": true, "mpv_ext": true, "mpv_ext_ipc": null, "mpv_ext_no_ovr": true, "mpv_ext_path": "E:\mpv\mpv-lazy\mpv.exe", "mpv_ext_start": true, "mpv_log_level": "info", "notify_updates": true, "play_cmd": null, "playback_timeout": 30, "player_name": "aaahuang", "pre_media_cmd": null, "prefer_transcode_to_h265": false, "raise_mpv": true, "remote_direct_paths": false, "remote_kbps": 10000, "sanitize_output": true, "screenshot_dir": "C:\Users\xxx\Desktop", "screenshot_menu": true, "seek_down": -60, "seek_h_exact": false, "seek_left": -5, "seek_right": 5, "seek_up": 60, "seek_v_exact": false, "shader_pack_custom": true, "shader_pack_enable": true, "shader_pack_profile": null, "shader_pack_remember": true, "shader_pack_subtype": "lq", "skip_intro_always": false, "skip_intro_prompt": false, "stop_cmd": null, "stop_idle": false, "subtitle_color": "#FFFFFFFF", "subtitle_position": "bottom", "subtitle_size": 100, "svp_enable": false, "svp_socket": null, "svp_url": "http://127.0.0.1:9901/", "sync_attempts": 5, "sync_max_delay_skip": 300, "sync_max_delay_speed": 50, "sync_method_thresh": 2000, "sync_osd_message": true, "sync_revert_seek": true, "sync_speed_attempts": 3, "sync_speed_time": 1000, "thumbnail_enable": true, "thumbnail_jellyscrub": false, "thumbnail_osc_builtin": true, "thumbnail_preferred_size": 320, "transcode_dolby_vision": true, "transcode_hdr": false, "transcode_hi10p": false, "transcode_warning": true, "use_web_seek": false, "write_logs": true }

iwalton3 commented 1 year ago

Are you trying to use this application with Emby? If so Emby is not supported. Please try to reproduce this issue with Jellyfin.

aaakoako commented 1 year ago

您好！我已收到您的邮件！

aaakoako commented 1 year ago

Are you trying to use this application with Emby? If so Emby is not supported. Please try to reproduce this issue with Jellyfin.

But emby works fine when playing a single episode, except when clicking to a new episode or switching to the next one.

iwalton3 commented 1 year ago

Sorry, but I don't feel like reverse engineering another proprietary media server application. (I already did it once for Plex!) If someone wants to properly support Emby they are free to fork the application.

If the same issue happens in Jellyfin feel free to re-open as I have some hope of troubleshooting and fixing the issue.

maaldheefee commented 1 year ago

I used to get this issue with Jellyfin and external mpv. Haven't had recently so didn't bother opening an issue.

iwalton3 commented 1 year ago

I made a change to disable "resume playback" which looks like it is being triggered in the log. That will conflict with Jellyfin progress save/restore and could be causing the episode skipping.

Try the latest CI build here once it finishes if you are on Windows: https://github.com/jellyfin/jellyfin-mpv-shim/actions/runs/4279793299

You can also directly install the application from the GitHub repository to test with the changes via pip if you are not on Windows. A similar result can be had from adding resume-playback=no to mpv.conf.

aaakoako commented 1 year ago

Thank you for reopening this issue and trying to solve my problem! I downloaded the latest build according to the way you provided, and set ‘resume-playback=no’ in the third-party mpv.conf, but I’m sorry to say that the problem has not been solved. My external mpv still skips episodes without playback, and if a skip occurs, the keyboard keys bound to mpv will also fail, and it cannot be closed directly except by killing the process. Below I will post the current log. From the log, it seems that the error has been resolved: 2023-02-27 20:03:46,461 [ INFO] player: Using external mpv playback backend. 2023-02-27 20:03:46,466 [ DEBUG] mpv-jsonipc: Staring MPV from E:\mpv\mpv-lazy\mpv.exe. 2023-02-27 20:03:46,466 [ DEBUG] mpv-jsonipc: Using IPC socket \.\pipe\mpv211898036718699 for MPV. 2023-02-27 20:03:46,615 [ DEBUG] mpv-jsonipc: Found MPV socket. 2023-02-27 20:03:46,625 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.client: JellyfinClient initializing... 2023-02-27 20:03:46,625 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.configuration: Configuration initializing... 2023-02-27 20:03:46,626 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.configuration: Begin http constructor. 2023-02-27 20:03:46,626 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.ws_client: WSClient initializing... 2023-02-27 20:03:46,626 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.connection_manager: ConnectionManager initializing... 2023-02-27 20:03:46,626 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.credentials: Credentials initializing... 2023-02-27 20:03:46,626 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.configuration: Begin app constructor. 2023-02-27 20:03:46,626 [ INFO] JELLYFIN.jellyfin_apiclient_python.connection_manager: Begin connect 2023-02-27 20:03:46,626 [ INFO] JELLYFIN.jellyfin_apiclient_python.connection_manager: Begin getAvailableServers 2023-02-27 20:03:46,627 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.credentials: credentialsupdated 2023-02-27 20:03:46,627 [ INFO] JELLYFIN.jellyfin_apiclient_python.connection_manager: connect has 1 servers 2023-02-27 20:03:46,627 [ INFO] JELLYFIN.jellyfin_apiclient_python.connection_manager: begin connect_to_server 2023-02-27 20:03:46,627 [ INFO] JELLYFIN.jellyfin_apiclient_python.api: Sending get request to system/info/public 2023-02-27 20:03:46,627 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.api: 5 2023-02-27 20:03:46,627 [ 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.5.0', 'Accept-Charset': 'UTF-8,', 'Accept-encoding': 'gzip', 'User-Agent': 'Jellyfin-MPV-Shim/2.5.0', 'x-emby-authorization': 'MediaBrowser Client=Jellyfin MPV Shim, Device=0000000, DeviceId=0000000, Version=2.5.0'} 2023-02-27 20:03:46,628 [ DEBUG] urllib3.connectionpool: Starting new HTTP connection (1): 192.168.1.246:8097 2023-02-27 20:03:46,634 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "GET /system/info/public HTTP/1.1" 200 134 2023-02-27 20:03:46,635 [ INFO] JELLYFIN.jellyfin_apiclient_python.connection_manager: calling onSuccessfulConnection with server DESKTOP-88888 2023-02-27 20:03:46,635 [ INFO] JELLYFIN.jellyfin_apiclient_python.api: Sending get request to system/info 2023-02-27 20:03:46,635 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.api: 5 2023-02-27 20:03:46,635 [ 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.5.0', 'Accept-Charset': 'UTF-8,', 'Accept-encoding': 'gzip', 'User-Agent': 'Jellyfin-MPV-Shim/2.5.0', 'x-emby-authorization': 'MediaBrowser Client=Jellyfin MPV Shim, Device=0000000, DeviceId=0000000, Version=2.5.0', 'X-MediaBrowser-Token': 'REDACTED'} 2023-02-27 20:03:46,636 [ DEBUG] urllib3.connectionpool: Starting new HTTP connection (1): 192.168.1.246:8097 2023-02-27 20:03:46,665 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "GET /system/info HTTP/1.1" 200 536 2023-02-27 20:03:46,667 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.credentials: credentialsupdated 2023-02-27 20:03:46,667 [ DEBUG] JELLYFIN.jellyfin_apiclient_python.connection_manager: resolving connect with result: {'Servers': "[{'address': 'http://192.168.1.246:8097', 'Name': 'DESKTOP-88888', 'Id': '000000000000', 'DateLastAccessed': '2023-02-27T20:03:46Z', 'UserId': '000000000000', 'AccessToken': 'REDACTED', 'Users': [{'Id': '000000000000', 'IsSignedInOffline': True}], 'uuid': '0000000', 'username': '0000000', 'connected': True}]", 'State': 3} 2023-02-27 20:03:46,667 [ INFO] JELLYFIN.jellyfin_apiclient_python.client: User is authenticated. 2023-02-27 20:03:46,667 [ DEBUG] urllib3.util.retry: Converted retries value: 3 -> 'Retry(total=3, connect=None, read=None, redirect=None, status=None)' 2023-02-27 20:03:46,667 [ DEBUG] urllib3.util.retry: Converted retries value: 3 -> 'Retry(total=3, connect=None, read=None, redirect=None, status=None)' 2023-02-27 20:03:46,667 [ INFO] JELLYFIN.jellyfin_apiclient_python.ws_client: Websocket url: ws://192.168.1.246:8097/socket?api_key=REDACTEDREDACTED&device_id=0000000 2023-02-27 20:03:46,669 [ DEBUG] urllib3.connectionpool: Starting new HTTP connection (1): 192.168.1.246:8097 2023-02-27 20:03:46,673 [ INFO] websocket: Websocket connected 2023-02-27 20:03:46,673 [ INFO] JELLYFIN.jellyfin_apiclient_python.ws_client: --->[ websocket ] 2023-02-27 20:03:46,673 [ DEBUG] event_handler: Unhandled Event WebSocketConnect: None 2023-02-27 20:03:46,674 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Capabilities/Full HTTP/1.1" 204 0 2023-02-27 20:03:46,677 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "GET /Sessions?ControllableByUserId=000000000000 HTTP/1.1" 200 1188 2023-02-27 20:04:01,149 [ DEBUG] event_handler: Handled Event GeneralCommand: {'Id': 'b98546382a79254129bc7b453d197181', 'Name': 'DisplayContent', 'ControllingUserId': '000000000000', 'Arguments': {'ItemName': '0000000', 'ItemId': '14050', 'ItemType': 'Series'}, 'ServerId': '000000000000'} 2023-02-27 20:04:03,135 [ DEBUG] event_handler: Handled Event Play: {'Id': 'b98546382a79254129bc7b453d197181', 'ItemIds': [14059, 14056, 14057, 14060, 14062, 14061, 14063, 14058, 14055, 14053, 14182, 14054], 'PlayCommand': 'PlayNow', 'ControllingUserId': '000000000000', 'StartIndex': 0, 'ServerId': '000000000000'} 2023-02-27 20:04:03,143 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "GET /Users/000000000000/Items/14059 HTTP/1.1" 200 2998 2023-02-27 20:04:03,144 [ DEBUG] event_handler: EventHandler::playMedia <jellyfin_mpv_shim.media.Media object at 0x000002078DF85F40> 2023-02-27 20:04:03,144 [ DEBUG] media: Bandwidth: local=True, bitrate=None, force=False 2023-02-27 20:04:03,159 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Items/14059/PlaybackInfo HTTP/1.1" 200 2587 2023-02-27 20:04:03,159 [ DEBUG] media: Using direct url. 2023-02-27 20:04:03,160 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 20:04:03,289 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:03,289 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:03,289 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:03,289 [ INFO] mpv: display-tags: File tags: 2023-02-27 20:04:03,289 [ INFO] mpv: display-tags: Description: Packed by Bilibili XCoder v2.0.2 2023-02-27 20:04:03,698 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 20:04:03,698 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 20:04:03,834 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 20:04:03,834 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 20:04:04,474 [ INFO] mpv: auto_profiles: Applying auto profile: deband_bitrate 2023-02-27 20:04:04,474 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 20:04:04,844 [ INFO] mpv: cplayer: AO: [wasapi] 192000Hz stereo 2ch float 2023-02-27 20:04:04,844 [ INFO] mpv: cplayer: VO: [gpu] 1280x720 yuv420p 2023-02-27 20:04:04,844 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 20:04:04,845 [ DEBUG] player: PlayerManager::play selecting subtitle stream index=2 2023-02-27 20:04:04,845 [ INFO] mpv: cplayer: Track switched: 2023-02-27 20:04:04,845 [ DEBUG] player: PlayerManager::play selecting external subtitle id=2 2023-02-27 20:04:04,845 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:04,845 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:04,845 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:04,888 [ INFO] mpv: cplayer: Track added: 2023-02-27 20:04:04,888 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:04,889 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:04,889 [ INFO] mpv: cplayer: Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:04,889 [ INFO] mpv: cplayer: (+) Subs --sid=2 'Stream.srt?api_key=REDACTEDREDACTED' (subrip) (external) 2023-02-27 20:04:04,916 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 20:04:04,918 [ INFO] update_check: Checking for updates... 2023-02-27 20:04:04,918 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 20:04:04,918 [ INFO] trickplay: No chapters available 2023-02-27 20:04:04,920 [ DEBUG] urllib3.connectionpool: Starting new HTTPS connection (1): github.com:443 2023-02-27 20:04:05,511 [ DEBUG] urllib3.connectionpool: https://github.com:443 "GET /jellyfin/jellyfin-mpv-shim/releases/latest HTTP/1.1" 302 0 2023-02-27 20:04:05,516 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 20:04:05,517 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 8, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T12:04:05.0000000Z', 'Played': True, 'ItemId': '14059'}], 'ServerId': '000000000000'} 2023-02-27 20:04:06,682 [ DEBUG] websocket: Sending ping 2023-02-27 20:04:09,594 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 20:04:09,595 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 20:04:09,819 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 20:04:09,824 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 20:04:11,167 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 20:04:11,600 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 20:04:16,613 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 20:04:16,686 [ DEBUG] websocket: Sending ping 2023-02-27 20:04:21,624 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 20:04:26,639 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 20:04:26,696 [ DEBUG] websocket: Sending ping 2023-02-27 20:04:28,239 [ DEBUG] event_handler: Handled Event Play: {'Id': 'b98546382a79254129bc7b453d197181', 'ItemIds': [14059, 14056, 14057, 14060, 14062, 14061, 14063, 14058, 14055, 14053, 14182, 14054], 'PlayCommand': 'PlayNow', 'ControllingUserId': '000000000000', 'StartIndex': 1, 'ServerId': '000000000000'} 2023-02-27 20:04:28,253 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "GET /Users/000000000000/Items/14056 HTTP/1.1" 200 2818 2023-02-27 20:04:28,253 [ DEBUG] event_handler: EventHandler::playMedia <jellyfin_mpv_shim.media.Media object at 0x000002078DFA5D00> 2023-02-27 20:04:28,254 [ DEBUG] media: Bandwidth: local=True, bitrate=None, force=False 2023-02-27 20:04:28,271 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Items/14056/PlaybackInfo HTTP/1.1" 200 2587 2023-02-27 20:04:28,271 [ DEBUG] media: Using direct url. 2023-02-27 20:04:28,271 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 20:04:28,272 [ INFO] mpv: cplayer: Saving state. 2023-02-27 20:04:28,628 [ INFO] mpv: cplayer: 2023-02-27 20:04:28,628 [ INFO] mpv: auto_profiles: Restoring profile: deband_bitrate 2023-02-27 20:04:28,745 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:28,745 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:28,745 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:28,745 [ INFO] mpv: display-tags: File tags: 2023-02-27 20:04:28,745 [ INFO] mpv: display-tags: Description: Packed by Bilibili XCoder v2.0.2 2023-02-27 20:04:28,874 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 20:04:28,874 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 20:04:28,917 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 20:04:28,917 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 20:04:29,697 [ INFO] mpv: auto_profiles: Applying auto profile: deband_bitrate 2023-02-27 20:04:29,698 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 20:04:30,008 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 20:04:30,110 [ INFO] mpv: cplayer: Track switched: 2023-02-27 20:04:30,110 [ DEBUG] player: PlayerManager::play selecting subtitle stream index=2 2023-02-27 20:04:30,110 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:30,110 [ DEBUG] player: PlayerManager::play selecting external subtitle id=2 2023-02-27 20:04:30,110 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:30,110 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:30,152 [ INFO] mpv: cplayer: Track added: 2023-02-27 20:04:30,152 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:30,152 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:30,152 [ INFO] mpv: cplayer: Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:30,152 [ INFO] mpv: cplayer: (+) Subs --sid=2 'Stream.srt?api_key=REDACTEDREDACTED' (subrip) (external) 2023-02-27 20:04:30,161 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 20:04:30,162 [ INFO] update_check: Update check performed in last day. Skipping. 2023-02-27 20:04:30,162 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 20:04:30,162 [ DEBUG] player: PlayerManager::finished_callback starting next episode 2023-02-27 20:04:30,162 [ INFO] trickplay: No chapters available 2023-02-27 20:04:30,166 [ DEBUG] urllib3.connectionpool: Starting new HTTP connection (2): 192.168.1.246:8097 2023-02-27 20:04:30,168 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "GET /Users/000000000000/Items/14057 HTTP/1.1" 200 2880 2023-02-27 20:04:30,191 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Progress HTTP/1.1" 204 0 2023-02-27 20:04:30,195 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Stopped HTTP/1.1" 204 0 2023-02-27 20:04:30,195 [ DEBUG] media: Bandwidth: local=True, bitrate=None, force=False 2023-02-27 20:04:30,201 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Items/14057/PlaybackInfo HTTP/1.1" 200 2587 2023-02-27 20:04:30,201 [ DEBUG] media: Using direct url. 2023-02-27 20:04:30,201 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 20:04:30,202 [ INFO] mpv: cplayer: Saving state. 2023-02-27 20:04:30,440 [ INFO] mpv: cplayer: 2023-02-27 20:04:30,440 [ INFO] mpv: auto_profiles: Restoring profile: deband_bitrate 2023-02-27 20:04:30,487 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:30,488 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:30,488 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:30,488 [ INFO] mpv: display-tags: File tags: 2023-02-27 20:04:30,488 [ INFO] mpv: display-tags: Description: Packed by Bilibili XCoder v2.0.2 2023-02-27 20:04:30,551 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 20:04:30,705 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 4, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T12:04:30.0000000Z', 'Played': True, 'ItemId': '14056'}, {'UnplayedItemCount': 7, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'ItemId': '14052'}], 'ServerId': '000000000000'} 2023-02-27 20:04:31,381 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 20:04:31,381 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 20:04:31,381 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 20:04:31,381 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 20:04:31,483 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 20:04:31,599 [ DEBUG] player: PlayerManager::play selecting subtitle stream index=2 2023-02-27 20:04:31,599 [ DEBUG] player: PlayerManager::play selecting external subtitle id=2 2023-02-27 20:04:31,599 [ INFO] mpv: cplayer: Track switched: 2023-02-27 20:04:31,599 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:31,599 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:31,599 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:31,637 [ INFO] mpv: cplayer: Track added: 2023-02-27 20:04:31,637 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:31,637 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:31,638 [ INFO] mpv: cplayer: Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:31,638 [ INFO] mpv: cplayer: (+) Subs --sid=2 'Stream.srt?api_key=REDACTEDREDACTED' (subrip) (external) 2023-02-27 20:04:31,646 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 20:04:31,647 [ INFO] update_check: Update check performed in last day. Skipping. 2023-02-27 20:04:31,647 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 20:04:31,647 [ DEBUG] player: PlayerManager::finished_callback starting next episode 2023-02-27 20:04:31,647 [ INFO] trickplay: No chapters available 2023-02-27 20:04:31,651 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "GET /Users/000000000000/Items/14060 HTTP/1.1" 200 2924 2023-02-27 20:04:31,656 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Stopped HTTP/1.1" 204 0 2023-02-27 20:04:31,656 [ DEBUG] media: Bandwidth: local=True, bitrate=None, force=False 2023-02-27 20:04:31,661 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Items/14060/PlaybackInfo HTTP/1.1" 200 2587 2023-02-27 20:04:31,661 [ DEBUG] media: Using direct url. 2023-02-27 20:04:31,661 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 20:04:31,663 [ INFO] mpv: cplayer: Saving state. 2023-02-27 20:04:31,888 [ INFO] mpv: cplayer: 2023-02-27 20:04:31,968 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:31,969 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:31,969 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:31,969 [ INFO] mpv: display-tags: File tags: 2023-02-27 20:04:31,969 [ INFO] mpv: display-tags: Description: Packed by Bilibili XCoder v2.0.2 2023-02-27 20:04:32,082 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 20:04:32,082 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 20:04:32,123 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 20:04:32,123 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 20:04:32,168 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 4, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T12:04:32.0000000Z', 'Played': True, 'ItemId': '14057'}, {'UnplayedItemCount': 7, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'ItemId': '14052'}], 'ServerId': '000000000000'} 2023-02-27 20:04:32,744 [ INFO] mpv: auto_profiles: Applying auto profile: deband_bitrate 2023-02-27 20:04:32,744 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 20:04:33,085 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 20:04:33,086 [ DEBUG] player: PlayerManager::play selecting subtitle stream index=2 2023-02-27 20:04:33,086 [ DEBUG] player: PlayerManager::play selecting external subtitle id=2 2023-02-27 20:04:33,086 [ INFO] mpv: cplayer: Track switched: 2023-02-27 20:04:33,086 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:33,086 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:33,086 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:33,119 [ INFO] mpv: cplayer: Track added: 2023-02-27 20:04:33,120 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:33,120 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:33,120 [ INFO] mpv: cplayer: Subs --sid=1 --slang=chi '�� ' (subrip) 2023-02-27 20:04:33,120 [ INFO] mpv: cplayer: (+) Subs --sid=2 'Stream.srt?api_key=REDACTEDREDACTED' (subrip) (external) 2023-02-27 20:04:33,127 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 20:04:33,127 [ INFO] update_check: Update check performed in last day. Skipping. 2023-02-27 20:04:33,127 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 20:04:33,127 [ DEBUG] player: PlayerManager::finished_callback starting next episode 2023-02-27 20:04:33,127 [ INFO] trickplay: No chapters available 2023-02-27 20:04:33,132 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "GET /Users/000000000000/Items/14062 HTTP/1.1" 200 2978 2023-02-27 20:04:33,136 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Stopped HTTP/1.1" 204 0 2023-02-27 20:04:33,137 [ DEBUG] media: Bandwidth: local=True, bitrate=None, force=False 2023-02-27 20:04:33,142 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Items/14062/PlaybackInfo HTTP/1.1" 200 2596 2023-02-27 20:04:33,143 [ DEBUG] media: Using direct url. 2023-02-27 20:04:33,143 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 20:04:33,144 [ INFO] mpv: cplayer: Saving state. 2023-02-27 20:04:33,384 [ INFO] mpv: cplayer: 2023-02-27 20:04:33,384 [ INFO] mpv: auto_profiles: Restoring profile: deband_bitrate 2023-02-27 20:04:33,452 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:33,452 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:33,452 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi () '��ģ��壩' (subrip) 2023-02-27 20:04:33,452 [ INFO] mpv: display-tags: File tags: 2023-02-27 20:04:33,452 [ INFO] mpv: display-tags: Description: Packed by Bilibili XCoder v2.0.2 2023-02-27 20:04:33,591 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 20:04:33,592 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 20:04:33,629 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 20:04:33,629 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 20:04:33,649 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 4, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T12:04:33.0000000Z', 'Played': True, 'ItemId': '14060'}, {'UnplayedItemCount': 7, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'ItemId': '14052'}], 'ServerId': '000000000000'} 2023-02-27 20:04:34,276 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 20:04:34,544 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 20:04:34,545 [ INFO] mpv: cplayer: Track switched: 2023-02-27 20:04:34,545 [ DEBUG] player: PlayerManager::play selecting subtitle stream index=2 2023-02-27 20:04:34,545 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:34,545 [ DEBUG] player: PlayerManager::play selecting external subtitle id=2 2023-02-27 20:04:34,545 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:34,546 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi () '��ģ��壩' (subrip) 2023-02-27 20:04:34,577 [ INFO] mpv: cplayer: Track added: 2023-02-27 20:04:34,577 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:34,577 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:34,577 [ INFO] mpv: cplayer: Subs --sid=1 --slang=chi () '��ģ��壩' (subrip) 2023-02-27 20:04:34,578 [ INFO] mpv: cplayer: (+) Subs --sid=2 'Stream.srt?api_key=REDACTEDREDACTED' (subrip) (external) 2023-02-27 20:04:34,583 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 20:04:34,583 [ INFO] update_check: Update check performed in last day. Skipping. 2023-02-27 20:04:34,583 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 20:04:34,583 [ DEBUG] player: PlayerManager::finished_callback starting next episode 2023-02-27 20:04:34,583 [ INFO] trickplay: No chapters available 2023-02-27 20:04:34,590 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "GET /Users/000000000000/Items/14061 HTTP/1.1" 200 2717 2023-02-27 20:04:34,594 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Stopped HTTP/1.1" 204 0 2023-02-27 20:04:34,594 [ DEBUG] media: Bandwidth: local=True, bitrate=None, force=False 2023-02-27 20:04:34,600 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Items/14061/PlaybackInfo HTTP/1.1" 200 2600 2023-02-27 20:04:34,600 [ DEBUG] media: Using direct url. 2023-02-27 20:04:34,600 [ INFO] mpv: thumbfast: Clearing trickplay. 2023-02-27 20:04:34,602 [ INFO] mpv: cplayer: Saving state. 2023-02-27 20:04:34,816 [ INFO] mpv: cplayer: 2023-02-27 20:04:34,868 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:34,868 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn () (aac 2ch 48000Hz) 2023-02-27 20:04:34,868 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi '��ģ��壩| ��' (subrip) 2023-02-27 20:04:34,868 [ INFO] mpv: display-tags: File tags: 2023-02-27 20:04:34,868 [ INFO] mpv: display-tags: Description: Packed by Bilibili XCoder v2.0.2 2023-02-27 20:04:35,020 [ INFO] mpv: vd: Using hardware decoding (dxva2-copy). 2023-02-27 20:04:35,021 [ INFO] mpv: autoconvert: Converting nv12 -> yuv420p 2023-02-27 20:04:35,059 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported. 2023-02-27 20:04:35,059 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration. 2023-02-27 20:04:35,098 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 2, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T12:04:35.0000000Z', 'Played': True, 'ItemId': '14062'}, {'UnplayedItemCount': 7, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'ItemId': '14052'}], 'ServerId': '000000000000'} 2023-02-27 20:04:35,816 [ DEBUG] player: Finished waiting for media duration. 2023-02-27 20:04:36,027 [ DEBUG] player: PlayerManager::play selecting audio stream index=1 2023-02-27 20:04:36,027 [ DEBUG] player: PlayerManager::play selecting subtitle stream index=2 2023-02-27 20:04:36,027 [ DEBUG] player: PlayerManager::play selecting external subtitle id=2 2023-02-27 20:04:36,028 [ INFO] mpv: cplayer: Track switched: 2023-02-27 20:04:36,028 [ INFO] mpv: cplayer: (+) Video --vid=1 () (hevc 3840x2160 23.976fps) 2023-02-27 20:04:36,028 [ INFO] mpv: cplayer: (+) Audio --aid=1 --alang=jpn (*) (aac 2ch 48000Hz) 2023-02-27 20:04:36,028 [ INFO] mpv: cplayer: (+) Subs --sid=1 --slang=chi '��ģ��壩| ��' (subrip) 2023-02-27 20:04:36,696 [ DEBUG] websocket: Sending ping 2023-02-27 20:04:46,709 [ DEBUG] websocket: Sending ping 2023-02-27 20:04:56,720 [ DEBUG] websocket: Sending ping 2023-02-27 20:05:06,726 [ DEBUG] websocket: Sending ping 2023-02-27 20:05:09,369 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing HTTP/1.1" 204 0 2023-02-27 20:05:09,369 [ INFO] update_check: Update check performed in last day. Skipping. 2023-02-27 20:05:09,369 [ DEBUG] player: PlayerManager::finished_callback starting next episode 2023-02-27 20:05:09,369 [ INFO] trickplay: Collecting trickplay images... 2023-02-27 20:05:09,369 [ INFO] trickplay: No chapters available 2023-02-27 20:05:09,377 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "GET /Users/000000000000/Items/14063 HTTP/1.1" 200 3114 2023-02-27 20:05:09,381 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Sessions/Playing/Stopped HTTP/1.1" 204 0 2023-02-27 20:05:09,382 [ DEBUG] media: Bandwidth: local=True, bitrate=None, force=False 2023-02-27 20:05:09,388 [ DEBUG] urllib3.connectionpool: http://192.168.1.246:8097 "POST /Items/14063/PlaybackInfo HTTP/1.1" 200 2607 2023-02-27 20:05:09,388 [ DEBUG] media: Using direct url. 2023-02-27 20:05:09,898 [ DEBUG] event_handler: Unhandled Event UserDataChanged: {'UserId': '000000000000', 'UserDataList': [{'PlaybackPositionTicks': 0, 'PlayCount': 1, 'IsFavorite': False, 'LastPlayedDate': '2023-02-27T12:05:10.0000000Z', 'Played': True, 'ItemId': '14061'}, {'UnplayedItemCount': 6, 'PlaybackPositionTicks': 0, 'PlayCount': 0, 'IsFavorite': False, 'Played': False, 'ItemId': '14052'}], 'ServerId': '000000000000'} 2023-02-27 20:05:16,729 [ DEBUG] websocket: Sending ping

iwalton3 commented 1 year ago

The only thing suspicious I see left in that log is:

2023-02-27 20:04:28,917 [ WARNING] mpv: vapoursynth: Frame requested during init! This is unsupported.
2023-02-27 20:04:28,917 [ WARNING] mpv: vapoursynth: Returning black dummy frame with 0 duration.

Maybe try disabling any vapoursynth filters and see if it fixes it?

aaakoako commented 1 year ago

Thank you for your message. I followed your clues and disabled all the vapoursynth filters, then tried to switch to the next episode. The phenomenon this time was that the player skipped 7 episodes in a row at a very fast speed. Thank you again! This may be a difficult bug to troubleshoot, but fortunately, if this player is called up for the first time, all functions are available. However, when I need to play the next episode, I need to close the current player and call it up again, instead of playing the next episode directly in sync mode.

aaakoako commented 1 year ago

By the way, I encountered another pop-up error when trying to close the program: Traceback (most recent call last): File "python_mpv_jsonipc.py", line 89, in send File "multiprocessing\connection.py", line 188, in send_bytes File "multiprocessing\connection.py", line 141, in _check_closed OSError: handle is closed

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "run.py", line 23, in File "jellyfin_mpv_shim\mpv_shim.py", line 101, in main File "jellyfin_mpv_shim\player.py", line 1025, in terminate File "jellyfin_mpv_shim\utils.py", line 54, in _synchronizer File "jellyfin_mpv_shim\player.py", line 612, in stop File "python_mpv_jsonipc.py", line 643, in getattr File "python_mpv_jsonipc.py", line 639, in command File "python_mpv_jsonipc.py", line 335, in command File "python_mpv_jsonipc.py", line 92, in send BrokenPipeError: handle is closed

qwerty12 commented 1 year ago

2023-02-27 13:42:38,079 [ INFO] mpv: auto_profiles: Applying auto profile: deband_bitrate

I have no idea what MPV-LAZY changes, so this might not work for you, but see if adding load-auto-profiles=no to your mpv.conf fixes this for you like it did me. You'll lose the functionality of your auto profiles, of course. I have no idea what in auto_profiles.lua is incompatible with the shim, but even the most benign auto profile in my mpv.conf causes unstoppable skipping once I try to play the next file. I just ended up reimplementing some of my more simpler profiles in a script.

iwalton3 commented 1 year ago

It looks like that auto profile script does some sketchy catching stuff. Maybe it is causing these events to be received multiple times? https://github.com/jellyfin/jellyfin-mpv-shim/blob/master/jellyfin_mpv_shim/player.py#L369

iwalton3 commented 1 year ago

The _finished_lock should prevent those from firing multiple times, but...

aaakoako commented 1 year ago

2023-02-27 13:42:38,079 [ INFO] mpv: auto_profiles: Applying auto profile: deband_bitrate

I have no idea what MPV-LAZY changes, so this might not work for you, but see if adding to your mpv.conf fixes this for you like it did me. You'll lose the functionality of your auto profiles, of course. I have no idea what in auto_profiles.lua is incompatible with the shim, but even the most benign auto profile in my mpv.conf causes unstoppable skipping once I try to play the next file. I just ended up reimplementing some of my more simpler profiles in a script.load-auto-profiles=no

This is great! Thanks for the method you provided, I managed to stop unstoppable skipping, although I don't really know what the downside of this is, but it does work, maybe I can adopt this until a better version is updated.

iwalton3 commented 1 year ago

Strangely enough I just tried the auto-profile:

[protocol.https]
speed=2

which does not cause uncontrolled skipping for me.

qwerty12 commented 1 year ago

I think it's because those sort of profiles are handled by mpv internally:

https://github.com/mpv-player/mpv/blob/dcc9bc5deab932be8b4a743326f48b25ba2cbe84/player/configfiles.c#L157

Any profile with a profile-cond parameter, however, is managed by the auto-profiles.lua script. Something like this, while not checking for, or setting, anything that would seemingly interfere with the shim's operation does cause problems:

[something]
profile-cond=pid == 420
priority = high

iwalton3 commented 1 year ago

This will be fixed in the next release.

jellyfin / jellyfin-mpv-shim

External MPV skips episodes without playback #323