Playback fails with sponsor section at video start

[kuehnelth]

When I play a video with a sponsor section at 00:00 I see the popup that the section was blocked. But playback just stops instead of skipping the section. Trying to play the video again plays the video fine but none of the sponsor sections are blocked.

[siku2]

Would you mind sharing the video in question? Also, you wouldn't happen to be able to share the logs for this too, would you?

[kuehnelth]

https://www.youtube.com/watch?v=-_qpzFlpgpo is a video that shows this bug for me. The log shows the following exceptions from the script:

2020-09-14 16:05:07.735 T:139691046467328   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <type 'exceptions.RuntimeError'>
                                            Error Contents: checkpoint listener running and not being stopped
                                            Traceback (most recent call last):
                                              File "/storage/.kodi/addons/script.service.sponsorblock/resources/lib/player_listener.py", line 115, in onPlayBackStarted
                                                self.start()
                                              File "/storage/.kodi/addons/script.service.sponsorblock/resources/lib/utils/checkpoint_listener.py", line 176, in start
                                                raise RuntimeError("checkpoint listener running and not being stopped")
                                            RuntimeError: checkpoint listener running and not being stopped
                                            -->End of Python script error report<--

2020-09-14 16:06:11.881 T:139790951364352   ERROR: EXCEPTION: XBMC is not playing any media file
2020-09-14 16:06:11.882 T:139790951364352   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <type 'exceptions.RuntimeError'>
                                            Error Contents: XBMC is not playing any media file
                                            Traceback (most recent call last):
                                              File "/storage/.kodi/addons/script.service.sponsorblock/resources/lib/gui/sponsor_skipped.py", line 70, in onClick
                                                self._on_unskip()
                                              File "/storage/.kodi/addons/script.service.sponsorblock/resources/lib/player_listener.py", line 132, in unskip
                                                self.seekTime(seg.start)
                                            RuntimeError: XBMC is not playing any media file
                                            -->End of Python script error report<--
2020-09-14 16:06:11.883 T:139790951364352   ERROR: EXCEPTION: XBMC is not playing any media file
2020-09-14 16:06:11.883 T:139790951364352   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <type 'exceptions.RuntimeError'>
                                            Error Contents: XBMC is not playing any media file
                                            Traceback (most recent call last):
                                              File "/storage/.kodi/addons/script.service.sponsorblock/resources/lib/gui/sponsor_skipped.py", line 84, in onAction
                                                self.onClick(self.getFocusId())
                                              File "/storage/.kodi/addons/script.service.sponsorblock/resources/lib/gui/sponsor_skipped.py", line 70, in onClick
                                                self._on_unskip()
                                              File "/storage/.kodi/addons/script.service.sponsorblock/resources/lib/player_listener.py", line 132, in unskip
                                                self.seekTime(seg.start)
                                            RuntimeError: XBMC is not playing any media file
                                            -->End of Python script error report<--

[siku2]

Thanks a lot! It sure looks like a quirk on Kodi's end. I'll look into it, should be relatively easy to fix.

[siku2]

Oh and just to clarify, the segment isn't just not being skipped, the playback stops entirely? The logs seem to indicate that the "unskip" button was pressed but in your description you said "Trying to play the video again [...]". Do you mean you're pressing "unskip" to play the video again or are you restarting it from scratch?

[kuehnelth]

Here is what I did with a bit more detail:

• I try to start the video from the watch later list.
• The loading circle is visible shortly, then I'm back on the watch later list. Playback never really starts. The sponsorblock popup shown up.
• I clicked "unskip" hoping it will close the popup, then I pressed back on my remote to close it.
• I try to play the video again, now playback works but nothing is skipped.

When I don't press unskip, only the first exception shows up.

[kuehnelth]

Hi,

I updated to sponsorblock 0.2.1, it still doesn't work. There is no more exception in the log but the message [script.service.sponsorblock] player_listener: segment ends after end of video, skipping to next video I modified the message so it also shows self.getTotalTime(). The result is 0.0.

[siku2]

Okay, looks like there are multiple issues at play here and I only solved one of them. Looks like this is (yet another) issue with Kodi itself but it should be relatively easy to work around it. Thanks for pointing this out!

[siku2]

For the record, I never encountered this error during testing. What version of Kodi are you using?

[kuehnelth]

I'm using Libreelec 9.2.4, Kodi 18.8.0, Youtube Plugin 6.8.5. I also tried it on Windows with the same kodi version. Here is a full log https://gist.github.com/kuehnelth/51dff366184731cb6aa8d8cd195f20b0

For some reason it behaves differently on windows and libreelec. On libreelec I see the error every time I try to play the video. On windows it only happens if I play it directly after some other youtube video. Skipping works if it's the first video I try to play after opening kodi or do nothing for a minute before hitting play.

[bclindner]

+1 on this issue (Kodi 18.8, Sponsorblock version 0.2.1, YouTube addon 6.8.5). Some other sample links that are still failing:

https://www.youtube.com/watch?v=cC8KT07m5aY https://www.youtube.com/watch?v=WKsJC1nuqVo https://www.youtube.com/watch?v=n1O3uHPCOLA

Gonna start looking into the issue myself, but no promises - my experience with Kodi addons is limited.

[bclindner]

So this is interesting - I time.sleep(1)'d just before the skip logic @kuehnelth mentioned here on a hunch and it started working (albeit skipping a second late, of course). There's no docs I could find on xbmc.Player needing time to initialize... Provided we have no way to await that, I'm thinking maybe nudging the start times of segments starting at zero forward a little bit could work, or maybe adding another qualifier to that if statement ignoring that logic and attempting the skip if the time is set to 0.0 (but that might cause issues on super short videos).

[siku2]

@bclindner Yeah that's in line with what I expected. Kodi's player is absolutely dreadful. Errors like this are everywhere - you can't even trust Player.getTime() to be accurate: https://github.com/siku2/script.service.sponsorblock/blob/19c406f7c2c896f3ef17b6b4533e548b7527832c/resources/lib/utils/checkpoint_listener.py#L73-L83

My plan is to just check if getTotalTime() returns zero and if it does, we just ignore it and assume that the video is long enough. If you'd like to contribute, this is where the issue occurs: https://github.com/siku2/script.service.sponsorblock/blob/19c406f7c2c896f3ef17b6b4533e548b7527832c/resources/lib/player_listener.py#L150-L155

[bclindner]

On it.

[kuehnelth]

I'm thinking maybe nudging the start times of segments starting at zero forward a little bit could work

Yes that works. I added if start < 0.5: start = 0.5before this line

[bclindner]

Okay, interestingly enough that didn't do it, it just throws up the skip pop-up without seeking, maybe even seeking needs time to warm up... I'm gonna try @kuehnelth's solution

[siku2]

Ah, should've seen that coming. Kodi's broken all the way down :frowning_face:

[bclindner]

Yeah, that works on my end as well. Not perfect but neither is this whole situation... @kuehnelth, the implementation's technically yours, you want to PR it or should I just submit what I have?

[kuehnelth]

Sure, just submit it if you want to.

[siku2]

Just released version 0.2.2 with this patch. Let's hope that fixes the issue for good. Thanks a lot for helping out to both of you!