Fix queuing of next episode using playlist #204

thebertster · 2020-07-29T01:39:53Z

Fixes issues with queuing of next episode via playlist:

We should not reset state if an episode ends, triggering the onPlayBackEnded event, when we have the next episode queued.
We should queue the next episode when the "Up Next" dialog is presented, but dequeue the next episode if the user cancels playback of the next episode.
We should not queue the next episode when the "Still Watching?" dialog is presented until and unless the user indicates they are indeed still watching.

thebertster · 2020-07-29T10:56:03Z

@thebertster Disable that check. Some of the default checks have weird expectations from developers IMO.

Done and agreed on some of the default pylint checks.

thebertster · 2020-07-29T11:07:06Z

With regards to #203 I think there are quite a few additional things needed to handle user playlists properly. I don't use playlists myself so haven't tested that.

ltguillaume · 2020-07-29T13:30:52Z

With regards to #203 I think there are quite a few additional things needed to handle user playlists properly. I don't use playlists myself so haven't tested that.

Using Kodi's videos setting "Play next video automatically" prepopulates the (user) playlist before playback, so in the case I'm describing, it should be straightforward (then again, nothing ever is in software development 😉).

MoojMidge · 2020-07-30T14:36:06Z

Fixes issues with queuing of next episode via playlist:

We should not reset state if an episode ends, triggering the onPlayBackEnded event, when we have the next episode queued.

This should happen the other way round. The event is triggered independently of this addon, but while the state should not be reset in this event handler, the queue does need to be reset in the onPlayBackEnded event.

We should queue the next episode when the "Up Next" dialog is presented, but dequeue the next episode if the user cancels playback of the next episode.

Good pickup.

We should not queue the next episode when the "Still Watching?" dialog is presented until and unless the user indicates they are indeed still watching.

Did this cause any problems? Need to be careful to not delay the queuing too much otherwise the original problem from #139 can re-occur.

MoojMidge · 2020-07-30T14:49:32Z

resources/lib/playbackmanager.py

-        if not playlist_item:
-            self.state.queued = self.api.queue_next_item(episode)
-


This was added here to try and ensure there was enough time for the next item to actually be enqueued and not get caught up with the closing of the previous item.

An alternate method that resolves the incorrect dequeueing can be seen here: MoojMidge/service.upnext@d5c46a2

MoojMidge · 2020-07-30T16:10:11Z

resources/lib/player.py

+        if not self.state.queued:
+            # Reset if playback ended without the next episode being queued
+            self.reset_queue()
+            self.api.reset_addon_data()
+            self.state = State()  # Reset state


The queue needs to be reset here, but the state should not be.

See MoojMidge/service.upnext@d5c46a2 for an alternative method.

Fixes issues with queuing of next episode via playlist:

We should not reset state if an episode ends, triggering the onPlayBackEnded event, when we have the next episode queued.

This should happen the other way round. The event is triggered independently of this addon, but while the state should not be reset in this event handler, the queue does need to be reset in the onPlayBackEnded event.

Yes, that makes sense. The problem was with resetting state at that point as it prevents Still Watching? from ever being invoked.

We should queue the next episode when the "Up Next" dialog is presented, but dequeue the next episode if the user cancels playback of the next episode.

Good pickup.

We should not queue the next episode when the "Still Watching?" dialog is presented until and unless the user indicates they are indeed still watching.

Did this cause any problems? Need to be careful to not delay the queuing too much otherwise the original problem from #139 can re-occur.

It's an affirmative action by the user to say they are still watching. While it's true that if the user presses the button at the very last moment before playback ends then the problem from #139 could happen, it's not a major issue from a user experience perspective.

But the alternative would be to enqueue the next episode by default and then dequeue it if the Still Watching dialog times out without the user pressing the button - but the concern there is that a similar race condition could happen where the RPC to dequeue could be processed after the next episode has already started to be played back. Again, from a user experience perspective, this would be a worse scenario than the above.

Fixes issues with queuing of next episode via playlist:

We should not reset state if an episode ends, triggering the onPlayBackEnded event, when we have the next episode queued.

This should happen the other way round. The event is triggered independently of this addon, but while the state should not be reset in this event handler, the queue does need to be reset in the onPlayBackEnded event.

Yes, that makes sense. The problem was with resetting state at that point as it prevents Still Watching? from ever being invoked.

I never used the Still Watching? feature, but upon checking my settings I saw it was actually set to 3, so in theory I should have seen the Still Watching? popup. I guess the state reset meant that this never worked on some systems.

We should queue the next episode when the "Up Next" dialog is presented, but dequeue the next episode if the user cancels playback of the next episode.

Good pickup.

We should not queue the next episode when the "Still Watching?" dialog is presented until and unless the user indicates they are indeed still watching.

Did this cause any problems? Need to be careful to not delay the queuing too much otherwise the original problem from #139 can re-occur.

It's an affirmative action by the user to say they are still watching. While it's true that if the user presses the button at the very last moment before playback ends then the problem from #139 could happen, it's not a major issue from a user experience perspective.

But the alternative would be to enqueue the next episode by default and then dequeue it if the Still Watching dialog times out without the user pressing the button - but the concern there is that a similar race condition could happen where the RPC to dequeue could be processed after the next episode has already started to be played back. Again, from a user experience perspective, this would be a worse scenario than the above.

I'm not sure either scenario is better or worse, one results in failure to playback, the other in unwanted playback. Personally I think it is a bigger issue that the addon doesn't perform its main intended function, but the Still Watching? function should not be broken to achieve this.

There is also a third scenario - where the autoPlayMode has been changed from the default. This could also result in unwanted playback.

I think the only way to resolve this for all scenarios is to use an onAVStarted event handler that would stop unwanted playback.

Actually onAVStarted may not be required.

Can you see if https://github.com/MoojMidge/service.upnext/tree/98f6d65781f18755ab47f3bd6b24bfbbc7470340 works for you?

Should also cover the fourth scenario where unwanted playback could occur - when hitting the close button on the Still Watching? popup.

This is not working right. After the nth episode when the "Still Watching?" popup is displayed, I click "Continue watching" and the next episode plays immediately as expected, however UpNext does not trigger for that next episode at all.

I have seen that happen before but haven't been able to reliably replicate. I believe it is related to the onPlayBackStarted event handler activating (when going to next playlist item) but before there is actually any stream to play.

Should be able to be fixed, but to help narrow down the problem can you clarify:

What type of content is being played? Local? Streaming via internet? From local or remote media server?

Is there any delay before playback starts once the previous file completes?

Observed behaviour is that clicking "Continue Watching" results in the the next episode playing, but after that UpNext fails to activate at all. Does this happen consistently whenever "Continue Watching" is clicked?

What happens when "Watch Now" is clicked from a regular UpNext notification, rather than waiting for playback to finish?

What type of content is being played? Local? Streaming via internet? From local or remote media server?

From a Synology NAS via SMB over gigabit Ethernet and using a shared MariaDb database rather than the local database. Kodi itself is LibreELEC running on a fanless PC. Same issue also seen on a different Kodi running on a Raspberry Pi 3.

Is there any delay before playback starts once the previous file completes?

No, there is no perceptable delay.

Observed behaviour is that clicking "Continue Watching" results in the the next episode playing, but after that UpNext fails to activate at all. Does this happen consistently whenever "Continue Watching" is clicked?

Yes that's correct - it happens consistently with your build (tested a dozen or so times to be sure it wasn't an intermittent thing).

What happens when "Watch Now" is clicked from a regular UpNext notification, rather than waiting for playback to finish?

Just tested this and playback of next episode starts immediately as expected, but again UpNext doesn't trigger for that next episode. Again tried a few times and this is consistent.

I should note that with my original commits on this PR, which I've been using for a week or so now, everything is working fine for all my use cases 100% consistently but as you mention there is also autoPlayNextEpisode and playlists to consider (neither of which I use, so haven't tested behaviour).

I was also thinking about your comment that we should still be calling reset_queue() (but not reset state) in the onPlayBackEnded handler even when self.state.queued==True. I did code that up, and didn't encounter any change in behaviour, but was wondering if it could trigger yet another race condition in some corner case (potentially clearing the playlist before Kodi has queued up the next item?). I agree we should call reset_queue() at some point to clear the playlist but I'm thinking that will happen anyway...

Whatever happens subsequently (next episode is successfully played from the playlist, user presses STOP, some error occurs etc.), one of onPlayBackStarted, onPlayBackStopped or onPlayBackError should get triggered, all of which call reset_queue() anyway...

My setup is DAS via USB3 to Odroid N2 running CoreElec, so faster storage and client somewhere in the middle

It's interesting to get some datapoints to figure out why all these issues are occurring, the original issue from #139 was only an intermittent thing for me, but can still occur depending on how late I click the Still Watching? button with this original PR.

Just tested this and playback of next episode starts immediately as expected, but again UpNext doesn't trigger for that next episode. Again tried a few times and this is consistent.

I can only replicate this if the 5s delay onPlayBackStarted is reduced, but in doing so have noticed that there are some odd occasions where xbmc.Player().isPlaying() returns True, but xbmc.Player().getTotalTime() returns zero. Waiting for a bit longer results in getTotalTime() returning the correct duration. Perhaps caching has something to do with this? Have you changed the buffermode value to 1 or 4 by any chance? https://kodi.wiki/view/HOW-TO:Modify_the_video_cache#Cache_settings

Can you check if https://github.com/MoojMidge/service.upnext/tree/eacf14278b437720dbe84f77fabab5252ae9a3bf is any better?

I was also thinking about your comment that we should still be calling reset_queue() (but not reset state) in the onPlayBackEnded handler even when self.state.queued==True. I did code that up, and didn't encounter any change in behaviour, but was wondering if it could trigger yet another race condition in some corner case (potentially clearing the playlist before Kodi has queued up the next item?). I agree we should call reset_queue() at some point to clear the playlist but I'm thinking that will happen anyway...

This possible scenario should be covered, just didn't realise that the state reset was being done incorrectly as I never used the Still Watching? functionality. I'm guessing this was the reason for the issue reported in #135.

I can't trigger this possible scenario normally, but I did test something similar (was trying to see whether removing a playlist item would be enough to prevent the unwanted playback you were experiencing), and removing the playlist item doesn't seem to effect playback. If there was some scenario where the next item had not been queued yet, then the first playlist item gets removed (which does nothing), then the next item may or may not be queued, but reset_queue() should then get called on the next resulting onPlayBackStarted/onAVStarted.

Whatever happens subsequently (next episode is successfully played from the playlist, user presses STOP, some error occurs etc.), one of onPlayBackStarted, onPlayBackStopped or onPlayBackError should get triggered, all of which call reset_queue() anyway...

The idea behind reset_queue() was to only remove the playlist entry that was just added. If it is only called onPlayBackStopped or onPlayBackError then the playlist will continue to grow. reset_queue() during onPlayBackStarted should cover most normal scenarios, but not also the stop/error events. It would therefore need to be changed to keep track of every item added or clear the entire playlist to cover both scenarios.

have noticed that there are some odd occasions where xbmc.Player().isPlaying() returns True, but xbmc.Player().getTotalTime() returns zero. Waiting for a bit longer results in getTotalTime() returning the correct duration

Hmmm this also happens intermittently even after the onAVStarted event fires. It is also possible that this is what is preventing UpNext working with Emby/EmbyCon in some situations.

Another go at fixing the problem: https://github.com/MoojMidge/service.upnext/tree/b8edb738ff0d6fcd897d41de1d19aedb3361aab5

MoojMidge · 2020-08-24T04:45:33Z

Have continued plugging away at fixing this issue and ended up sticking fingers in everything...

https://github.com/MoojMidge/service.upnext/tree/97808a3baea278015a5309f6d5aa95da06e9b245

Not sure the best way to manage this (separate PR?) as the changes are widespread and interconnected, but would appreciate some testing to check if all identified playback issues have been resolved.

Changes include:

Adds the ability for UpNext to be used as a module to greatly simplify addon integration ¹
Fix issue where Kodi identifies it has started playing a video stream but stream details have not yet loaded
Fixes issue with seeking to end of file resulting in Kodi playing past the end of the file
Fixes for handling of scenario where addons provide incorrect notification time/offset
Fixes multiple timing issues and race conditions resulting from UpNext losing state information when previous streams stop too early/late, new streams start too early/late, video player threads are closed early/late. This should fix Not advancing to next episode #117, never get Still Watching dialog #135, Timing issues preventing Up Next working reliably #139, Not playing next item #170, and Doesn't auto-play next episode #199. Testing required to confirm. ²
Addresses unresolved issues from Fix various runtime exceptions #142
Fixes issues where changing addon settings can result in UpNext losing state information
Updated Api methods
Increased amount of logging
Allows less restrictive playlist operation. In general if it is in a playlist and playlist handling is enabled, then Up Next will try to handle it. This should address issue identified Use with "Play next video automatically" #203, however the functionality described in comment-665702929 may no longer work (if it ever did?)
Searches for next episode in next season in Kodi library
Includes implementation of PR Automatically take action after X seconds (into credits) #200
Includes implementation of PR Mark (local) episode as watched when playing next #77

[1]: Basic addon integration can be as simple as the following.
In addon.xml:

    <requires>
        ...
        <import addon="service.upnext" optional="true"/>
    </requires>

In code for playing stream:

    xbmcplugin.setResolvedUrl(handle, True, listItem)
    
    try:
        import upnext
    except Exception as e:
        xbmc.log(msg='Up Next addon not installed: %s' % e, level=xbmc.LOGWARNING))
        return
    
    upnext_info = dict(
        current_episode=listItem,
        play_url=url
    )
    
    upnext.send_signal(xbmcaddon.Addon().getAddonInfo('id'), upnext_info)

[2]: I believe this should also resolve a number of other previously reported issues, including #134, #196, #197, but further testing is required.

dagwieers · 2020-08-24T11:00:11Z

@MoojMidge Fantastic!

A PR would definitely be the easiest to review and discuss, however I think the best way forward is to create PR in small stand-alone chunks. For instance, a lot of the bug-fixes will work without any new functionality or restructuring.

I am not saying you need to create PRs for the smallest possible chunk, just a PR for everything that is understandable by itself. (So a bunch of one-line fixes scattered over the code can definitely go together since it makes it possible to review those changes in isolation inside the one PR)

This will also make the process easier to merge the obvious patches asap, and discuss and iterate over the harder/complexer changes in e.g. design.

MoojMidge · 2020-08-24T15:16:08Z

For instance, a lot of the bug-fixes will work without any new functionality or restructuring.

Maybe. I'll have to have a look at how to split it all up, but the major bug fixes were squashed by moving functionality into UpNextPlayer, from PlayItem, UpNextMonitor, and PlaybackManager, in order to prevent the issues from occurring.

My mistake was also updating State, Api, and utils at the same time, as this was needed to properly keep track of state. Should have done this beforehand.

however I think the best way forward is to create PR in small stand-alone chunks.

Let me figure out how to use git and I will try and split all this up into manageable PRs

dagwieers · 2020-08-24T23:52:23Z

If it is hard to impossible to get simple fixes out, make one PR and we will see :-)

dagwieers · 2020-08-24T23:53:39Z

PR #77 and PR #200 are definitely not ready to be included though.

dagwieers · 2020-08-24T23:59:37Z

BTW If you make a PR, please create a named branch first, otherwise we might have issues later. git checkout -b big-rewrite

MoojMidge · 2020-08-25T09:39:48Z

I can split up some of the less convoluted changes, but there is going to be one big one.

I could try to split it up further but the resulting PRs will likely produce a non-functioning addon when merged, until all related PRs are reviewed/tested/changed/merged. If you could create a test branch I can create the PRs against the test branch to avoid messing up master. Once everything is ok the test branch could be merged back into master.

PR #77 and PR #200 are definitely not ready to be included though.

With the refactor, implementing #200 was fairly simple, and therefore also easy to remove, but the issues identified in the original PR should no longer be a problem.

The biggest issue I found was that the notification time variables behaved in different ways to each other, and also compared to what their names would suggest (notification_time was a popup duration or offset from end of file, notification_offset was actually a time stamp, and autoPlayCustomTime/autoPlaySeasonTime variables were also popup duration times or offsets from the end of the file).

This was an issue because the effect of #200 is to reduce the effective total file play time by cutting out the credits, which means that variables that were offset from the end of the file ended up being incorrect. Became simple to handle the change in effective run time by making all cue points relative to the start of the file, but needed to rename a bunch of private variables/methods for things to make sense while maintaining compatibility with existing use of the public variables.

#77 is a different case and is something that is now necessary to resolve other bugs. One of the big problem I found was that Kodi does some manner of fast seeking and only seeks to keyframes. When seeking to the end of a file, it doesnt actually seek to the end, but the closest keyframe instead

When this happens programmatically Kodi sometimes (often?) gets confused and thinks that the file has ended and either stops the video too early (creating issues with the Player callbacks) or the video player keeps going (as it should) but then keeps playing past the end of the file (which it shouldn't) and nothing stops it (because Kodi thinks the file had already ended). This was the issue originally reported in #117.

The only way to fix this is to directly play the next file rather than seeking. However directly playing the next file creates other problems - watched state may not be incremented and a resume point may be created depending on popup duration and Kodi settings. Therefore #77 would need to be implemented to avoid unintended issues with watch and resume points.

dagwieers · 2020-08-28T16:23:49Z

@MoojMidge I have been test-driving you branch the past few days and AFAICT everything has been working fine. I had no specific issues before, but I don't have any now either. 👍

dagwieers · 2020-08-28T16:32:06Z

@im85288 @thebertster @MoojMidge How we want to proceed with this? If we don't make a plan I fear we will end up (weeks from now) with a stale contribution, or a situation where contributors are unhappy because of wrong expectations or spend effort turned useless. I have been on the receiving end of this, so I can identify ;-)

thebertster · 2020-08-28T16:35:05Z

I was going to test @MoojMidge's build over the weekend. Looks to be a much more comprehensive approach, so hopefully addresses all these corner cases. Been really manic with work of late so haven't had time. Will let you know the results.

MoojMidge · 2020-08-29T00:55:53Z

@thebertster, @dagwieers There are a few additional bugs that I have seen:

Kodi can start a new file without onPlayBackEnded triggering (fixed in master and test-instances branches)
Popup can get stuck open if new file starts early but then terminates before tracking function can process it (fixed in test-instances)
Mistake where I wasn't updating popup progress bar correctly and was using current episode duration rather than next episode duration for end time display on popup (fixed in test-instances)

If you wouldn't mind testing, could you use test-instances? Aside from the changes above, this branch is a step towards allowing for arbitrary class instantiation for the purposes of unit testing.

@dagwieers

How we want to proceed with this?

I have tested splitting up the changes and it can be done, but I was hoping a new test branch (copy of current master) could be created here. This way I can create the PRs against this test branch and if anything needs to change, or doesn't work until later PRs are merged, then master will remain unaffected. Let me know what is preferable, either way I can create the PRs (to master or to a new test branch).

thebertster · 2020-08-29T14:15:08Z

@MoojMidge test-instances branch is giving an exception when the popup is displayed (same on my RPi and Intel systems):

2020-08-29 15:12:41.669 T:1616180096   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <type 'exceptions.TypeError'>
                                            Error Contents: function takes at least 2 arguments (0 given)
                                            Traceback (most recent call last):
                                              File "/storage/.kodi/addons/service.upnext/resources/lib/service_entry.py", line 10, in <module>
                                                UpNextMonitor().run()
                                              File "/storage/.kodi/addons/service.upnext/resources/lib/monitor.py", line 95, in run
                                                state=self.state
                                              File "/storage/.kodi/addons/service.upnext/resources/lib/playbackmanager.py", line 39, in launch_up_next
                                                play_next, keep_playing = self.launch_popup(episode, playlist_item)
                                              File "/storage/.kodi/addons/service.upnext/resources/lib/playbackmanager.py", line 76, in launch_popup
                                                dialog = UpNextPopup(xmlFilename=filename, item=episode)
                                            TypeError: function takes at least 2 arguments (0 given)

MoojMidge · 2020-08-29T14:57:01Z

@thebertster Sorry, forgot to push local changes. Should be up to date now if you wouldn't mind downloading again.

im85288 · 2020-08-31T18:22:38Z

Sorry guys for some reason the notifications were going into my spam folder so wasn’t aware of this PR. @MoojMidge fantastic stuff, really appreciate your input. @dagwieers I always like to encourage contributions so merge when your happy with how things are.

thebertster · 2020-08-31T18:23:50Z

Been using @MoojMidge 's test-instances branch all weekend and not had any issues.

notoco · 2020-08-31T19:10:02Z

I tested on coreelec, on files from the library, as well as on Netflix and on the Netflix + library connection. Works without errors.

dagwieers · 2020-08-31T22:33:21Z

@im85288 @thebertster @notoco @MoojMidge Let us make that PR, and formally review the PR together. I would like to take this opportunity to document as much as possible the logic that is not self-evident so we can improve the readability of this code (which IMO was always a bit lacking before).

As soon as this is merged, I would like to call out to all our stakeholders (and all reporters of open issues) to test the master branch for a few weeks before we can plan to release this.

dagwieers · 2020-08-31T22:34:10Z

Let me close this PR to kick off the new plan ;-)

Thanks everyone for participating!

dagwieers · 2020-08-31T22:37:32Z

@MoojMidge Please don't forget to make a branch before creating your PR. If you need help on Git, let me know.

MoojMidge · 2020-09-01T03:21:21Z

@dagwieers I have started off with some minor PRs.

There will be three major PRs to follow:
PR for test-merge - brings things up to date with my master
PR for test-instances - master + additional bug fixes + combine popups into one class
PR for test-monitor - master + additional bug fixes + combine popups into one class + monitor performs all monitoring + allow for multiple instances for testing

But I will probably just create a single PR for test-monitor to save reviewing things that have already been changed.

Can discuss further when the minor PRs are reviewed.

thebertster added 2 commits July 29, 2020 02:33

Fix queuing of next episode using playlist

48f6c7b

Refactor slightly to pass linting

8788969

This comment has been minimized.

Sign in to view

dagwieers added the bug Something isn't working label Jul 29, 2020

dagwieers added this to the v1.2.0 milestone Jul 29, 2020

dagwieers mentioned this pull request Jul 29, 2020

Use with "Play next video automatically" #203

Closed

Exclude too-many-branches linting check

ff2c5d2

MoojMidge reviewed Jul 30, 2020

View reviewed changes

dagwieers closed this Aug 31, 2020

MoojMidge mentioned this pull request Oct 13, 2020

Prepare for v1.1.3 release #217

Merged

dagwieers removed this from the v1.2.0 milestone Oct 18, 2020

MoojMidge mentioned this pull request Dec 13, 2020

Fix to prevent unwanted playback when using playlist queueing method #237

Merged

		if not playlist_item:
		self.state.queued = self.api.queue_next_item(episode)

Fix queuing of next episode using playlist #204

Fix queuing of next episode using playlist #204

Conversation

thebertster commented Jul 29, 2020

This comment has been minimized.

thebertster commented Jul 29, 2020

thebertster commented Jul 29, 2020

ltguillaume commented Jul 29, 2020 • edited Loading

MoojMidge commented Jul 30, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

MoojMidge Aug 4, 2020 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

MoojMidge commented Aug 24, 2020

dagwieers commented Aug 24, 2020

MoojMidge commented Aug 24, 2020

dagwieers commented Aug 24, 2020

dagwieers commented Aug 24, 2020

dagwieers commented Aug 24, 2020

MoojMidge commented Aug 25, 2020

dagwieers commented Aug 28, 2020 • edited Loading

dagwieers commented Aug 28, 2020

thebertster commented Aug 28, 2020

MoojMidge commented Aug 29, 2020

thebertster commented Aug 29, 2020

MoojMidge commented Aug 29, 2020

im85288 commented Aug 31, 2020

thebertster commented Aug 31, 2020

notoco commented Aug 31, 2020

dagwieers commented Aug 31, 2020

dagwieers commented Aug 31, 2020

dagwieers commented Aug 31, 2020

MoojMidge commented Sep 1, 2020

ltguillaume commented Jul 29, 2020 •

edited

Loading

MoojMidge Aug 4, 2020 •

edited

Loading

dagwieers commented Aug 28, 2020 •

edited

Loading