[BUG] Not scrobbling when letting episode run until the end

Alistair1231 commented 1 year ago

Describe the bug When watching an episode using MPV and Syncplay it doesn't mark episodes as complete if the episode runs to 100% and automatically skips to the next episode. It only works if manually skipped.

Desktop (please complete the following information):

OS and Version: Windows 11
Python Version: 3.7.9
Player and Version: mpv 0.34.0, syncplay 1.6.9

To Reproduce

Steps to reproduce the behavior:

Open syncplay and have it use mpv with the proper ipc-server argument
- Syncplay does some manipulation of the arguments I think, so I have to use --input-ipc-server=\\.\mpvsocket in syncplay as "additional player argmuents", while I use ipc_path: \\.\pipe\mpvsocket in config.yaml from trakt-scrobbler
Add multiple files to the playlist
open a file (you may skip to 95% or something) and let it play to the end, the next episode will start playing but it will not show up in trakt history, even though it was showing as playing on the trakt homepage while it was playing.

Log file

Log from an example of where it DOES NOT work (automatic advance to next episode)

``` 2022-08-04 10:58:26,764 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 10:38:36,396 - DEBUG - mpv - monitor - {'state': 2, 'progress': 12.32, 'media_info': {'type': 'episode', 'title': 'Solar Opposites', 'season': 3, 'episode': 4}, 'updated_at': 1659602316.3965714} 2022-08-04 10:38:36,396 - DEBUG - scrobbler - scrobbler - Scrobbling start at 12.32% for Solar Opposites 2022-08-04 10:38:36,614 - INFO - scrobbler - scrobbler - Scrobble resume successful for Solar Opposites S03E04 at 12.32% 2022-08-04 10:58:26,764 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 10:58:26,764 - DEBUG - mpv - monitor - {'state': 1, 'progress': 100.0, 'media_info': {'type': 'episode', 'title': 'Solar Opposites', 'season': 3, 'episode': 4}, 'updated_at': 1659603506.7643456} 2022-08-04 10:58:26,764 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 100.00% for Solar Opposites 2022-08-04 10:58:26,973 - INFO - scrobbler - scrobbler - Scrobble pause successful for Solar Opposites S03E04 at 100.00% 2022-08-04 10:58:27,422 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 10:58:27,422 - DEBUG - mpv - monitor - {'state': 1, 'progress': 0.0, 'media_info': {'type': 'episode', 'title': 'Solar Opposites', 'season': 3, 'episode': 4}, 'updated_at': 1659603507.4227629} 2022-08-04 10:58:27,422 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 0.00% for Solar Opposites 2022-08-04 10:58:27,572 - INFO - scrobbler - scrobbler - Scrobble pause successful for Solar Opposites S03E04 at 0.00% 2022-08-04 10:58:27,902 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 10:58:27,902 - DEBUG - mpv - monitor - {'state': 0, 'progress': 0.0, 'media_info': {'type': 'episode', 'title': 'Solar Opposites', 'season': 3, 'episode': 4}, 'updated_at': 1659603507.902092} 2022-08-04 10:58:27,902 - DEBUG - scrobbler - scrobbler - Scrobbling stop at 0.00% for Solar Opposites 2022-08-04 10:58:28,039 - INFO - scrobbler - scrobbler - Scrobble pause successful for Solar Opposites S03E04 at 0.00% 2022-08-04 10:58:28,718 - DEBUG - mpv - file_info - Raw filepath 'https://user:pass@web.site/_Plex/TV/Solar Opposites/S03/Solar.Opposites.S03E05.1080p.WEB.H264-CAKES.mkv' 2022-08-04 10:58:28,718 - DEBUG - mpv - file_info - Converted to url 'https://user:pass@web.site/_Plex/TV/Solar Opposites/S03/Solar.Opposites.S03E05.1080p.WEB.H264-CAKES.mkv' 2022-08-04 10:58:28,718 - DEBUG - mpv - file_info - Guessit url '/_Plex/TV/Solar Opposites/S03/Solar.Opposites.S03E05.1080p.WEB.H264-CAKES.mkv' 2022-08-04 10:58:28,718 - DEBUG - mpv - file_info - Matched whitelist entry 'https://user:pass@web.site/_Plex' 2022-08-04 10:58:28,731 - DEBUG - mpv - file_info - Guess: MatchesDict([('title', 'Solar Opposites'), ('season', 3), ('episode', 5), ('screen_size', '1080p'), ('source', 'Web'), ('video_codec', 'H.264'), ('release_group', 'CAKES'), ('container', 'mkv'), ('mimetype', 'video/x-matroska'), ('type', 'episode')]) 2022-08-04 10:58:28,731 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 10:58:28,731 - DEBUG - mpv - monitor - {'state': 1, 'progress': 0.0, 'media_info': {'type': 'episode', 'title': 'Solar Opposites', 'season': 3, 'episode': 5}, 'updated_at': 1659603508.7313597} 2022-08-04 10:58:28,731 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 0.00% for Solar Opposites 2022-08-04 10:58:28,865 - INFO - scrobbler - scrobbler - Scrobble pause successful for Solar Opposites S03E05 at 0.00% 2022-08-04 10:58:31,978 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 10:58:31,978 - DEBUG - mpv - monitor - {'state': 2, 'progress': 0.0, 'media_info': {'type': 'episode', 'title': 'Solar Opposites', 'season': 3, 'episode': 5}, 'updated_at': 1659603511.9788485} 2022-08-04 10:58:31,978 - DEBUG - scrobbler - scrobbler - Scrobbling start at 0.00% for Solar Opposites 2022-08-04 10:58:32,163 - INFO - scrobbler - scrobbler - Scrobble resume successful for Solar Opposites S03E05 at 0.00% ```

Log from an example of where it DOES work (manual advance to next episode)

``` 2022-08-04 11:14:59,824 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 0.00% for Amphibia 2022-08-04 11:15:01,806 - INFO - scrobbler - scrobbler - Scrobble pause successful for Amphibia S01E01 at 0.00% 2022-08-04 11:15:04,017 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 11:15:04,017 - DEBUG - mpv - monitor - {'state': 1, 'progress': 95.71, 'media_info': {'type': 'episode', 'title': 'Amphibia', 'season': 1, 'episode': 1, 'year': 2019}, 'updated_at': 1659604504.017309} 2022-08-04 11:15:04,017 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 95.71% for Amphibia 2022-08-04 11:15:04,409 - INFO - scrobbler - scrobbler - Scrobble pause successful for Amphibia S01E01 at 95.71% 2022-08-04 11:15:04,749 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 11:15:04,750 - DEBUG - mpv - monitor - {'state': 2, 'progress': 95.71, 'media_info': {'type': 'episode', 'title': 'Amphibia', 'season': 1, 'episode': 1, 'year': 2019}, 'updated_at': 1659604504.7494798} 2022-08-04 11:15:04,750 - DEBUG - scrobbler - scrobbler - Scrobbling start at 95.71% for Amphibia 2022-08-04 11:15:05,835 - INFO - scrobbler - scrobbler - Scrobble resume successful for Amphibia S01E01 at 95.71% 2022-08-04 11:15:06,809 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 11:15:06,809 - DEBUG - mpv - monitor - {'state': 1, 'progress': 96.0, 'media_info': {'type': 'episode', 'title': 'Amphibia', 'season': 1, 'episode': 1, 'year': 2019}, 'updated_at': 1659604506.8096132} 2022-08-04 11:15:06,809 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 96.00% for Amphibia 2022-08-04 11:15:07,260 - INFO - scrobbler - scrobbler - Scrobble pause successful for Amphibia S01E01 at 96.00% 2022-08-04 11:15:08,743 - ERROR - mpv - mpv - Error with command ['get_property', 'time-pos']. Response: {'request_id': 1358, 'error': 'property unavailable'} 2022-08-04 11:15:09,922 - DEBUG - mpv - file_info - Raw filepath 'https://user:pass@web.site/_Plex/TV/Amphibia/Amphibia (2019) S01 (1080p AMZN Webrip x265 10bit EAC3 2.0 - Goki)[TAoE]/Amphibia (2019) S01E02 Best Fronds (1080p AMZN Webrip x265 10bit EAC3 2.0 - Goki)[TAoE].mkv' 2022-08-04 11:15:09,922 - DEBUG - mpv - file_info - Converted to url 'https://user:pass@web.site/_Plex/TV/Amphibia/Amphibia (2019) S01 (1080p AMZN Webrip x265 10bit EAC3 2.0 - Goki)[TAoE]/Amphibia (2019) S01E02 Best Fronds (1080p AMZN Webrip x265 10bit EAC3 2.0 - Goki)[TAoE].mkv' 2022-08-04 11:15:09,923 - DEBUG - mpv - file_info - Guessit url '/_Plex/TV/Amphibia/Amphibia (2019) S01 (1080p AMZN Webrip x265 10bit EAC3 2.0 - Goki)[TAoE]/Amphibia (2019) S01E02 Best Fronds (1080p AMZN Webrip x265 10bit EAC3 2.0 - Goki)[TAoE].mkv' 2022-08-04 11:15:09,923 - DEBUG - mpv - file_info - Matched whitelist entry 'https://user:pass@web.site/_Plex' 2022-08-04 11:15:09,949 - DEBUG - mpv - file_info - Guess: MatchesDict([('title', 'Amphibia'), ('year', 2019), ('season', 1), ('screen_size', '1080p'), ('streaming_service', 'Amazon Prime'), ('source', 'Web'), ('other', 'Rip'), ('video_codec', 'H.265'), ('color_depth', '10-bit'), ('audio_codec', 'Dolby Digital Plus'), ('audio_channels', '2.0'), ('release_group', 'Goki)[TAoE]'), ('episode', 2), ('episode_title', 'Best Fronds'), ('container', 'mkv'), ('mimetype', 'video/x-matroska'), ('type', 'episode')]) 2022-08-04 11:15:09,949 - DEBUG - mpv - monitor - action=stop_previous 2022-08-04 11:15:09,949 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 11:15:09,949 - DEBUG - scrobbler - scrobbler - Scrobbling stop at 96.00% for Amphibia 2022-08-04 11:15:09,949 - DEBUG - mpv - monitor - {'state': 1, 'progress': 0.0, 'media_info': {'type': 'episode', 'title': 'Amphibia', 'season': 1, 'episode': 2, 'year': 2019}, 'updated_at': 1659604509.9496522} 2022-08-04 11:15:10,539 - INFO - scrobbler - scrobbler - Scrobble stop successful for Amphibia S01E01 at 96.00% 2022-08-04 11:15:10,542 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 0.00% for Amphibia 2022-08-04 11:15:10,967 - INFO - scrobbler - scrobbler - Scrobble pause successful for Amphibia S01E02 at 0.00% 2022-08-04 11:15:18,623 - DEBUG - mpv - monitor - action=scrobble 2022-08-04 11:15:18,623 - DEBUG - mpv - monitor - {'state': 0, 'progress': 0.0, 'media_info': {'type': 'episode', 'title': 'Amphibia', 'season': 1, 'episode': 2, 'year': 2019}, 'updated_at': 1659604518.623619} 2022-08-04 11:15:18,623 - DEBUG - scrobbler - scrobbler - Scrobbling stop at 0.00% for Amphibia 2022-08-04 11:15:18,625 - DEBUG - mpv - mpv - Pipe closed. 2022-08-04 11:15:19,051 - INFO - scrobbler - scrobbler - Scrobble pause successful for Amphibia S01E02 at 0.00% ```

iamkroot commented 1 year ago

I have a plain MPV setup, and this case works just fine (scrobbles stop at 100%). I'll try to set up syncplay to see if it is doing something weird.

soredake commented 4 months ago

I'm getting this more and more often, can trakt-scrobbler gain option to scrobble after playing media to certain percentage, like 85%?

iamkroot commented 4 months ago

@soredake what media player are you using?

soredake commented 4 months ago

@iamkroot mpv.net

iamkroot commented 4 months ago

Maybe some issue with Windows? Would be difficult for me to reproduce.

soredake commented 4 months ago

Maybe some issue with Windows?

I don't think so, this happens only when playing with syncplay.

soredake commented 3 months ago

This happened again, I've noticed that before changing the playlist item to next syncplay sets time to 00:00:00, that must be the reason why trakt-scrobbler is not sent finished state to trakt.

Pinging the syncplay expert @Et0h

Et0h commented 3 months ago

This happened again, I've noticed that before changing the playlist item to next syncplay set time to 00:00:00, that must be the reason why trakt-scrobbler is not sent finished state to trakt.

Pinging the syncplay expert @Et0h

That's a useful insight.

The way Syncplay changes files at the end of the shared Syncplay playlist is a bit hacky as it was a feature added in later and designed to work using general commands supported by a variety of media players and with both the user and other users being able to trigger it, sometimes simultaneously.

My recollection is that for legacy reasons the protocol treats setting playback position and changing playlist item as two separate events and I think the current code is the way it is to minimise the chance of the playlist being advanced twice due to advancement being double triggered (and to prevent playback position not being reset, but some still report problems with that when they manually change files).

I can try to rework it when I have time but it will probably need a bit of testing to ensure it doesn't create new problems elsewhere (i.e. as it needs to maintain backwards and cross player compatibility).

iamkroot commented 3 months ago

Maybe as a workaround here, we can add logic that a pause at 100% is sent as a stop event. I would really prefer to not do this since it just adds more corner cases that might break in the future. Not sure how it will interact with all the other features (fast_pause and preview).

But I'm assuming pause at 100% is very uncommon. We can revisit it if the change causes more problems.

iamkroot commented 3 months ago

I've made the changes here. Give it a shot

Stop the scrobbler with trakts stop
Run pipx install --force --pip-args='--force-reinstall' git+https://github.com/iamkroot/trakt-scrobbler.git@syncplay-stop-fix
Start scrobbler with trakts start

soredake commented 3 months ago

@iamkroot unfortunately, nothing changed for me, log:

2024-04-04 13:33:27,574 - INFO - scrobbler - scrobbler - Scrobble start successful for P. E. Teacher S01E14 at 79.66%
2024-04-04 13:38:02,474 - DEBUG - syncplay@mpv - monitor - action=scrobble
2024-04-04 13:38:02,475 - DEBUG - syncplay@mpv - monitor - {'state': 1, 'progress': 0.0, 'media_info': {'type': 'episode', 'title': 'Ôèçðóê', 'season': 1, 'episode': 14}, 'updated_at': 1712227082.474096}
2024-04-04 13:38:02,475 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 0.00% for Ôèçðóê
2024-04-04 13:38:02,654 - INFO - scrobbler - scrobbler - Scrobble pause successful for P. E. Teacher S01E14 at 0.00%
2024-04-04 13:38:07,941 - DEBUG - syncplay@mpv - file_info - Raw filepath 'C:/Users/user/shared-unruhe\\non-anime\\The.Walking.Dead.S10.Season.10.COMPLETE.1080p.WEBRip.x264-maximersk [mrsktv]\\The.Walking.Dead.S10E15.1080p.WEBRip.x264-KSRM.mkv'
2024-04-04 13:38:07,941 - DEBUG - syncplay@mpv - file_info - Matched whitelist entry WindowsPath('C:/Users/user/shared-unruhe/non-anime')
2024-04-04 13:38:07,984 - DEBUG - syncplay@mpv - file_info - Guess: MatchesDict({'episode_title': 'anime', 'title': 'The Walking Dead', 'season': 10, 'screen_size': '1080p', 'source': 'Web', 'other': 'Rip', 'video_codec': 'H.264', 'episode': 15, 'release_group': 'KSRM', 'container': 'mkv', 'mimetype': 'video/x-matroska', 'type': 'episode'})
2024-04-04 13:38:07,985 - DEBUG - syncplay@mpv - monitor - action=stop_previous
2024-04-04 13:38:07,985 - DEBUG - syncplay@mpv - monitor - action=scrobble
2024-04-04 13:38:07,985 - DEBUG - scrobbler - scrobbler - Scrobbling stop at 0.00% for Ôèçðóê
2024-04-04 13:38:07,986 - DEBUG - syncplay@mpv - monitor - {'state': 1, 'progress': 0.0, 'media_info': {'type': 'episode', 'title': 'The Walking Dead', 'season': 10, 'episode': 15}, 'updated_at': 1712227087.9859424}
2024-04-04 13:38:08,162 - INFO - scrobbler - scrobbler - Scrobble pause successful for P. E. Teacher S01E14 at 0.00%
2024-04-04 13:38:08,176 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 0.00% for The Walking Dead
2024-04-04 13:38:09,480 - INFO - scrobbler - scrobbler - Scrobble pause successful for The Walking Dead S10E15 at 0.00%
2024-04-04 13:38:18,840 - DEBUG - syncplay@mpv - monitor - action=scrobble
2024-04-04 13:38:18,840 - DEBUG - syncplay@mpv - monitor - {'state': 2, 'progress': 0.16, 'media_info': {'type': 'episode', 'title': 'The Walking Dead', 'season': 10, 'episode': 15}, 'updated_at': 1712227098.8409228}
2024-04-04 13:38:18,841 - DEBUG - scrobbler - scrobbler - Scrobbling start at 0.16% for The Walking Dead

iamkroot commented 3 months ago

That's a bit weird. I've pushed another fix for it, could you give it a try @soredake ? Same installation instructions as before. Would like to see the logs in case it doesn't work.

soredake commented 3 months ago

@iamkroot even after this commit, I still got this:

2024-04-07 13:31:19,833 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 0.00% for Ôèçðóê
2024-04-07 13:31:20,396 - INFO - scrobbler - scrobbler - Scrobble pause successful for P. E. Teacher S01E17 at 0.00%
2024-04-07 13:52:28,680 - DEBUG - syncplay@mpv - monitor - action=scrobble
2024-04-07 13:52:28,680 - DEBUG - syncplay@mpv - monitor - {'state': 2, 'progress': 0.16, 'media_info': {'type': 'episode', 'title': 'Ôèçðóê', 'season': 1, 'episode': 17}, 'updated_at': 1712487148.6801653}
2024-04-07 13:52:28,681 - DEBUG - scrobbler - scrobbler - Scrobbling start at 0.16% for Ôèçðóê
2024-04-07 13:52:29,475 - INFO - scrobbler - scrobbler - Scrobble resume successful for P. E. Teacher S01E17 at 0.16%
2024-04-07 14:11:47,299 - DEBUG - syncplay@mpv - monitor - action=scrobble
2024-04-07 14:11:47,300 - DEBUG - syncplay@mpv - monitor - {'state': 1, 'progress': 0.0, 'media_info': {'type': 'episode', 'title': 'Ôèçðóê', 'season': 1, 'episode': 17}, 'updated_at': 1712488307.2991385}
2024-04-07 14:11:47,300 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 0.00% for Ôèçðóê
2024-04-07 14:11:47,993 - INFO - scrobbler - scrobbler - Scrobble pause successful for P. E. Teacher S01E17 at 0.00%
2024-04-07 14:11:51,261 - DEBUG - syncplay@mpv - monitor - action=stop_previous
2024-04-07 14:11:51,261 - DEBUG - syncplay@mpv - monitor - action=scrobble
2024-04-07 14:11:51,261 - DEBUG - scrobbler - scrobbler - Scrobbling stop at 0.00% for Ôèçðóê
2024-04-07 14:11:51,261 - DEBUG - syncplay@mpv - monitor - {'state': 1, 'progress': 0.0, 'media_info': {'type': 'episode', 'title': 'Skull Island', 'season': 1, 'episode': 1}, 'updated_at': 1712488311.2618978}
2024-04-07 14:11:51,441 - INFO - scrobbler - scrobbler - Scrobble pause successful for P. E. Teacher S01E17 at 0.00%
2024-04-07 14:11:51,453 - DEBUG - scrobbler - scrobbler - Scrobbling pause at 0.00% for Skull Island
2024-04-07 14:11:52,781 - INFO - scrobbler - scrobbler - Scrobble pause successful for Skull Island S01E01 at 0.00%
2024-04-07 14:12:02,129 - DEBUG - syncplay@mpv - monitor - action=scrobble
2024-04-07 14:12:02,129 - DEBUG - syncplay@mpv - monitor - {'state': 2, 'progress': 0.21, 'media_info': {'type': 'episode', 'title': 'Skull Island', 'season': 1, 'episode': 1}, 'updated_at': 1712488322.129851}
2024-04-07 14:12:02,129 - DEBUG - scrobbler - scrobbler - Scrobbling start at 0.21% for Skull Island
2024-04-07 14:12:02,372 - INFO - scrobbler - scrobbler - Scrobble resume successful for Skull Island S01E01 at 0.21%

state['progress'] == 100

This time, syncplay jumped to 00:00:00 at ~99.77%, so 100% might not work all the time.

iamkroot commented 3 months ago

Wait, we don't even see the 99.97% event in our monitor. It directly goes from 0.16% back to 0% from our viewpoint. That's a big problem. We need to somehow keep polling the player for updates (I believe we already do that) and detect such big jumps. Gonna be harder than I thought, since we need to differentiate between syncplay initiated jumps and a user manually jumping to 0%.

iamkroot / trakt-scrobbler

[BUG] Not scrobbling when letting episode run until the end #202