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

[Alistair1231]

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]

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]

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

[iamkroot]

@soredake what media player are you using?

[soredake]

@iamkroot mpv.net

[iamkroot]

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

[soredake]

Maybe some issue with Windows?

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

[soredake]

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]

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]

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.