im85288 / service.upnext

GNU General Public License v2.0
81 stars 42 forks source link

[BUG] Trakt stopping scrobble after 2 episodes #303

Closed Yedrimas closed 1 year ago

Yedrimas commented 1 year ago

Hello,

I'm not the first, but I think I know what is causing the issue. To sum up the issue, when you have both trakt & upnext working on Kodi, trakt will successfuly scrobble the firsrt episode, the second one, but then on the third it stops working.

Got into the logs, and I found this : debug <general>: [script.trakt] resources.lib.scrobbler: Current playlist item changed! Not updating time! (1 -> 0)

I wondered because I didnt delete an item from the list, so the index should not have changed. Reading a bit more the log file and I found this :

debug <general>: Skin Helper Service --> Kodi_Monitor: sender xbmc - method: Playlist.OnRemove  - data: {"playlistid":1,"position":0}
debug <general>: script.skin.helper.widgets --> Kodi_Monitor: sender xbmc - method: Playlist.OnRemove  - data: {"playlistid":1,"position":0}

And I found the culprit. monitor.py:onNofitication() => api.py:reset_queue() When this chain of events happens (which is a normal chain of events), the playlist is modified while playing, and if the playlist is modified while playing, trakt scrobble stops working.

https://github.com/im85288/service.upnext/blob/dd2609fef2d42a2a182a1d78f5c02aa0943f3327/resources/lib/monitor.py#L129 https://github.com/im85288/service.upnext/blob/dd2609fef2d42a2a182a1d78f5c02aa0943f3327/resources/lib/api.py#L121

Removing this code, the issue vanishes and the playlist stays intact (as an added bonus). I think there should be an option to keep the playlist while a on watch session, quick and easy fix (or just to remove this playlist clean as I dont really know why its there).

MoojMidge commented 1 year ago

And I found the culprit. monitor.py:onNofitication() => api.py:reset_queue()

That is not what actually happens. api.reset_queue is not called directly. It is player.reset_queue that is called, and it only calls api.reset_queue if there is a queue (created by Up Next) to reset. It won't do anything if there is a normal playlist being used. Note as well that this code is only executed if another plugin sends data to Up Next, it doesn't do anything by itself.

Removing this code, the issue vanishes and the playlist stays intact (as an added bonus). I think there should be an option to keep the playlist while a on watch session, quick and easy fix (or just to remove this playlist clean as I dont really know why its there).

Not sure this is the root cause. There is no actual playlist to keep intact, it is only being temporarily created and reset by Up Next. If an actual playlist is being used then Up Next won't reset it.

Also, the exact same code would get executed after the first episode is played, so if Up Next creates a queue, it will also reset the queue after the second episode starts. If the Trakt scrobbler is picking up the queue reset, it would pick this up for second episode being played, not only the third.

It almost sounds like the Up Next queue is being created, but then a playlist is also being created or modified by some other plugin, which is then also sending data to Up Next.

Normally this would not be a problem because the Trakt scrobbler only activates after a user adjustable time delay after a video starts playing, but perhaps you have this set too low, or the data being sent to Up Next from another plugin is being received too late.

Can you provide the debug log showing this occuring?

Yedrimas commented 1 year ago

I found this when making my addon, but I reverted back to local storage to remove any issue that could be on my side. When starting the playback of a local file, without using a playlist, it seems like UpNext will use Playlist.Add, then once playing the next episode, it is removing the previous one, but now the Trakt pluggin is lost as the current playing item has changed position in the playlist. The same issue happens when another addon is calling UpNext.

I've added UpNext => reset_queue to the log to make it easier to see when the function is called. Log ends with the trakt script refusing to perform the scrobble update due to the playlist changing.

upnext.log

Edit: I've tried using the delay in the trakt addon settings, it now stops working after the first UpNext play instead of the second.

Edit2:

Not sure this is the root cause. There is no actual playlist to keep intact, it is only being temporarily created and reset by Up Next.

Issue is, this "temporary playlist" is the reason why trakt addon is lost. When the UpNext episode starts, it is as position index 1 in the playlist, then it moves to 0 as the UpNext addon clears this "temporary playlist". So the playlist is changed without a new file playing, this causes the trakt addon to stop the scrobbling. For it to work properly, UpNext should not be clearing the temporary playlist (or at least, give the user an option to prevent that, so that Trakt Addon works properly). debug <general>: [script.trakt] resources.lib.scrobbler: Current playlist item changed! Not updating time! (1 -> 0)

MoojMidge commented 1 year ago

When starting the playback of a local file, without using a playlist, it seems like UpNext will use Playlist.Add, then once playing the next episode, it is removing the previous one

Yes, Up Next uses the internal Kodi playlist to play the next video, to try and avoid issues where Kodi would not correctly play the next video because it thought the current video was stopping. It also clears the previously played video from the playlist to avoid filling the internal playlist with those previously played videos.

but now the Trakt pluggin is lost as the current playing item has changed position in the playlist.

Yes, that does appear to be happening, because the Trakt onAVStarted callback is executing before the same callback in Up Next.

The same issue happens when another addon is calling UpNext.

Possibly, but it is not likely for this to occur unless the plugin is also creating a playlist, as the notification should happen well after the onAVStarted callbacks, and by that time the Up Next onAVStarted callback would have reset the queue already.

Edit: I've tried using the delay in the trakt addon settings, it now stops working after the first UpNext play instead of the second.

Is the log showing what happens when using the delay? It appears to show the queue being reset two times, and both times the Trakt onAVStarted callback has already executed so the playlist position check fails. Looking at the code, I can't see how this would work with the second episode, but not the third, and the log seems to show that it doesn't work for the second either.

To get an idea of what is happening, the Up Next onAVStarted callback is purposefully delayed by 5 seconds. You can see in the log that the AVStarted event occurs here:

2023-09-28 08:40:20.412 T:17236   debug <general>: CApplicationPlayerCallback::OnAVStarted: CApplication::OnAVStarted

and the queue reset (happening as part of the Up Next player onAVStarted callback, rather than the monitor onNotification callback) occurs 5 seconds after:

2023-09-28 08:40:25.685 T:31612   debug <general>: UpNext => reset_queue

Conversely, the Trakt onAVStarted callback starts 1 second after the AVStarted event:

2023-09-28 08:40:21.513 T:18568   debug <general>: [script.trakt] resources.lib.service: [traktPlayer] onAVStarted() - activePlayers: [{'playerid': 1, 'playertype': 'internal', 'type': 'video'}]

And the subsequent start of the scrobbler, where the playlist position is saved, occurs shortly after:

2023-09-28 08:40:21.727 T:18568   debug <general>: [script.trakt] resources.lib.scrobbler: playbackStarted(data: {'id': 291, 'type': 'episode'})

The scrobble start offset should be a value in minutes, so it seems like the delay is still actually set to 0 minutes (the default). Can you try changing it to 1 (60 seconds) and see what happens?

For it to work properly, UpNext should not be clearing the temporary playlist (or at least, give the user an option to prevent that, so that Trakt Addon works properly).

Perhaps, but there are a number of video plugins that also have issues when the internal Kodi playlist grows unexpectedly. It is also possible for a user to change the playlist if it is not being reset by Up Next (shuffling it, clearing it, moving or deleting items).

The check of playlist position in the Trakt plugin appears to be intended to determine whether the currently playing video has changed, and while there may be a very good reason why it is using playlist position to indicate this, it doesn't seem to be the most robust of checks as opposed to just checking the currently playing video file path.

Yedrimas commented 1 year ago

Possibly, but it is not likely for this to occur unless the plugin is also creating a playlist, as the notification should happen well after the onAVStarted callbacks, and by that time the Up Next onAVStarted callback would have reset the queue already.

I've tried with my addon, using either setResolvedUrl, Playlist.add, Player.play have the same result; the first episode is ok, the second one can work but the third definitely doest work on trakt.

Is the log showing what happens when using the delay?

No, the log is showing what most users will experience; default settings I am not aware of the internal Kodi playlist causing issues when growing unexpectedly. But that explains why UpNext clears the playlist.

Can you try changing it to 1 (60 seconds) and see what happens?

Done, and it, kind of works. The scrobbler now works with UpNext, but Trakt will also wait 60s to show up the "rating" notification, meaning it will appear during the next episode.

This could also be a change on Trakts addon, but since it has not been updated for over 2 years and looking at all the opened (and ignored) issues, I dont think relying on them for an update is possible.

Maybe a threshold would be an acceptable workaround, to give at least the first few episodes (like the first 10 to give a random number, or user configurable) a chance to work on trakt, and then accept that the playlist should be cleared.

MoojMidge commented 1 year ago

I've tried with my addon, using either setResolvedUrl, Playlist.add, Player.play have the same result; the first episode is ok, the second one can work but the third definitely doest work on trakt.

What I meant was that while it is unlikely for a plugin to cause the same behaviour by itself, the timing of the onAVStarted callback means that it will still trigger the problem irrespective of what the other plugin may do.

No, the log is showing what most users will experience; default settings

Hmm, are you sure the second episode was tracked properly in that log? It definitely says that it has detected the first playlist position change:

2023-09-28 08:40:26.108 T:18568   debug <general>: [script.trakt] resources.lib.scrobbler: Current playlist item changed! Not updating time! (1 -> 0)

I am not too familair with what the Trakt plugin does, and while it does appear to track the playlist position in multiple locations, I'm pretty sure that this particular debug message is the one that should be displayed when the scrobbler stops keeping track of the watched time. If it is actually tracking the watched time for the second episode, then there may be something else happening.

I am not aware of the internal Kodi playlist causing issues when growing unexpectedly. But that explains why UpNext clears the playlist.

Manipulating the playlist doesn't cause issues for Kodi itself, but it does cause issues for other video plugins that don't expect the internal playlist to increase in size, very similar to this issue (but the opposite), where the Trakt plugin doesn't expect the internal playlist to reduce in size.

Up Next tries to play nice with other plugins since it is only performing a secondary utility function, but I really think the Trakt plugin should be handling playlist mutations in a more robust manner. If Up Next cannot change the playlist it creates itself without effecting how the Trakt plugin works, is the expectation that a user similarly cannot change their own playlist, or that other video plugins cannot manipulate their own playlists?

Maybe a threshold would be an acceptable workaround, to give at least the first few episodes (like the first 10 to give a random number, or user configurable) a chance to work on trakt, and then accept that the playlist should be cleared.

I think there may be another way to handle this - it may be possible to reset the Up Next queue before the AVStarted event occurs.

Can you try changing the following lines: https://github.com/im85288/service.upnext/blob/dd2609fef2d42a2a182a1d78f5c02aa0943f3327/resources/lib/player.py#L49-L51 to this instead:

        def onAVStarted(self):  # pylint: disable=invalid-name
            """Will be called when Kodi has a video or audiostream"""
            self._check_video()

        def onPlayBackStarted(self):  # pylint: disable=invalid-name
            """Will be called when kodi starts playing a file"""
            self.reset_queue()

If that works with the Trakt plugin and doesn't cause playback issues for you, then I can create a PR to add this workaround as an option in Up Next.

Yedrimas commented 1 year ago

I also think Trakt should not be lost when the playlist changes, as long as the file is correclty identified, it should not be an issue.

Can you try changing the following lines:

If I understood correclty, removing the if completely (and replacing it with its content, both then and else); it works. Both the regular player and my addon are working correctly 😃

Tested with no delay on Trakt scrobbling

MoojMidge commented 1 year ago

@Yedrimas - See #305. It is essentially the same as the modifications you have already made, but it would be good if you could test and confirm everything still works as expected.

Yedrimas commented 1 year ago

That was fast 😄 Brilliant, it works flawlessly ! Thanks

MoojMidge commented 1 year ago

Thanks for testing. I'll try and get a release pushed out, time permitting.