watch doesn't add to history anymore

[player8472]

The problem

When watching something on plex, it scobbles progress fine - but at the end it doesn't mark it as completed in Trakt-History

Error trace

No response

Expected behavior

Watched Episodes/Movies should be marked as watched in Trakt-History.

Steps to reproduce the behavior

Watch something on connected PLEX-instance

Inspect of problematic items

No response

Workarounds

Using Sync, but that only works if Item hasn't been watched before.

Install method

docker-compose

Version

0.18.15

Python Version

3.10.0 (according to docker inspect)

Operating System and Version

Fedora 35 (Containers Host)

[glensc]

anymore? what is the last version this worked then? what's the output of watch command? have you tried enabling debugging and see debug log of when play has stopped what appears to log?

[player8472]

It just stopped working - not even sure if there was an update.

I used version 0.8.14 before when the issue appeared (at least I think that was when it appeared - I don't check regularly and only noticed recently, but it did definitely work about 3 weeks ago). Updated to latest (0.18.15) to see if it might be fixed already
I can't really find any possibly configuration related errors in the debug-log.

I created one that only has the timeframe I basically skipped through an Item.
It scobbles progress fine and then it just sends a stop command.

The Play doesn't appear in Trakt history

plextraktsync.bak.log

[glensc]

@player8472 revoke your trakt token. you have shared it publicly with debug log (Authorization': 'Bearer xxx')

[player8472]

@player8472 revoke your trakt token. you have shared it publicly with debug log (Authorization': 'Bearer xxx')

hmpf, overlooked that one - thx
Why are they in the log in the first place?

[glensc]

as you described scrobble stop is sent:

2022-01-30 06:47:20,567 INFO[PlexTraktSync.WatchStateUpdater]:<Episode:49384:The-Americans-(2013)-s03e01>: 99.823599% W
atched: True, LastViewed: 2022-01-29 18:50:42
2022-01-30 06:47:20,760 DEBUG[urllib3.connectionpool]:https://api-v2launch.trakt.tv:443 "POST /scrobble/stop HTTP/1.1" 201 None

after that trakt.tv site should mark item as played. perhaps the trakt.tv sit was slow and it needed to update cache>

there's also tons of json errors

2022-01-30 06:47:20,565 DEBUG[requests_cache.cache_keys]:Invalid JSON body:

but unclear, were those retried and then recovered? i've already submitted PR to trakt library to improve logging there:

• [python-pytrakt] Feature: Throw BadResponseException on JSON decode errors moogar0880/PyTrakt#181

[player8472]

after that trakt.tv site should mark item as played. perhaps the trakt.tv sit was slow and it needed to update cache>

I can assure you it is not just slowness.
I have entire seasons (rewatch) missing from my history.

It would be helpful to have the actual historyID the scobble sends back in the log, so I can check it.

[glensc]

what is historyID? link? or perhaps send yourself PR with adding logger.debug? and describe how you would check it?

[glensc]

@player8472 revoke your trakt token. you have shared it publicly with debug log (Authorization': 'Bearer xxx')

hmpf, overlooked that one - thx Why are they in the log in the first place?

that's logs from different project:

DEBUG[trakt.core]:headers:

you could git blame there, maybe there's reasonable commit message explaining :D but I guess it's just debugging what headers are sent. I would drop it from there. or redact.

EDIT: submitted a PR moogar0880/PyTrakt#195

[player8472]

what is historyID? link? or perhaps send yourself PR with adding logger.debug? and describe how you would check it?

https://trakt.docs.apiary.io/#reference/scrobble/stop

According to the API the scobble-stop should return the 64Bit historyID it saved the scobble as in the trakt-db.

I am not too sure how to check it, I'd research that if I had it (I really didn't use the API directly that much, so far ... )

[florianehmke]

I'm experiencing the same issue. I only installed 10 days ago and watch never worked whereas sync works just fine.

[player8472]

I'm experiencing the same issue. I only installed 10 days ago and watch never worked whereas sync works just fine.

Maybe instead of sending scobble->stop, sending scobble-pause (so it doesn't double add when trakt gets their sh** together at some point) + sync->add to history?
https://trakt.docs.apiary.io/#reference/sync/add-to-history

Could be a workaround and should be more stable

The call for add to history could also be used for #506 (although this bug wouldn't be half as bad if #506 was already implemented :) )
Although I do understand that for past watches, there would be more work involved than just adding everything (the bug that plagued the plex-plugin for years - adding everything to the history every sync proves that).

Here however, a simple call with watched_at set to the present system-time should suffice.

[glensc]

History Id is added to debug log if you take changes of this branch and apply changes to trakt library (linked in the pr):

• Fix: pass progress from plex when calling scrobble api #761

[glensc]

Encountering this myself too now.

So far no errors. looks like trakt.tv side something changed?

DEBUG    {'type': 'playing', 'size': 1, 'PlaySessionStateNotification': [{'sessionKey': '86',
         'clientIdentifier': 'x', 'guid': '', 'ratingKey': '13204', 'url': '',
         'key': '/library/metadata/13204', 'viewOffset': 3041000, 'playQueueItemID': 38389,
         'playQueueID': 1598, 'state': 'playing', 'transcodeSession': 'x'}]}
INFO     on_play: <Episode:13204:s02e06>: 99.972714% Watched: False, LastViewed:  
         2022-02-02 22:54:13
DEBUG    {'type': 'playing', 'size': 1, 'PlaySessionStateNotification': [{'sessionKey': '86', 
         'clientIdentifier': 'x', 'guid': '', 'ratingKey': '13204', 'url': '',    
         'key': '/library/metadata/13204', 'viewOffset': 3041000, 'playQueueItemID': 38389,   
         'playQueueID': 1598, 'state': 'stopped', 'transcodeSession': 'x'}]}   
INFO     on_play: <Episode:13204:s02e06>: 99.972714% Watched: False, LastViewed:    
         2022-02-02 22:54:13                                                           
DEBUG    Sleeping for 0.576 seconds

I don't read anything new from docs:

• https://trakt.docs.apiary.io/#reference/scrobble/stop

[glensc]

managed to capture response (details on how: #758 (comment)):

INFO     on_play: <Episode:13205:s02e07>: 99.989809% Watched: False, LastViewed: None
DEBUG    post: https://api-v2launch.trakt.tv/scrobble/stop
DEBUG    RESPONSE [post] (https://api-v2launch.trakt.tv/scrobble/stop): <Response [201]>
DEBUG    Scrobbled: {'id': 0, 'action': 'pause', 'progress': 0.0, 'sharing': {'facebook': False,
         'twitter': False, 'tumblr': False}, 'episode': {'season': 2, 'number': 7, 'title': 'x', 'ids': {'trakt': x, 'tvdb': x, 'imdb': 'x', 'tmdb':
         x, 'tvrage': None}}, 'show': {'title': 'x', 'year': 2015, 'ids': {'trakt':
         x, 'slug': 'x', 'tvdb': x, 'imdb': 'x', 'tmdb': x, 'tvrage':
         x}}}

so, somewhy action=pause and progress=0.0 in response. that's not expected.

[glensc]

got message where it worked, with this branch applied:

• https://github.com/Taxel/PlexTraktSync/pull/761/commits

INFO     on_play: <Episode:13207:s02e09>: 99.967202% Watched: False, LastViewed: None
DEBUG    stop(<TVEpisode>: S2E9 None): 99.9672017720029
DEBUG    post: https://api-v2launch.trakt.tv/scrobble/stop
DEBUG    https://api-v2launch.trakt.tv:443 "POST /scrobble/stop HTTP/1.1" 201 None
DEBUG    RESPONSE [post] (https://api-v2launch.trakt.tv/scrobble/stop): <Response [201]>
DEBUG    Scrobbled: {'id': 8138889017, 'action': 'scrobble', 'progress': 99.9672017720029, 'sharing':
         {'facebook': False, 'twitter': False, 'tumblr': False}, 'episode': {'season': 2, 'number': 9,
         'title': 'x', 'ids': {'trakt': x, 'tvdb': x, 'imdb': 'x',
         'tmdb': x, 'tvrage': None}}, 'show': {'title': 'x', 'year': 2015, 'ids':
         {'trakt': x, 'slug': 'x', 'tvdb': x, 'imdb': 'x', 'tmdb': x,
         'tvrage': x}}}