search

matthuisman / slyguy.addons

Github mirror of SlyGuy add-ons
https://www.matthuisman.nz/2020/02/slyguy-kodi-repository.html
282 stars 77 forks source link

[Nebula] Jet Lag audio sync #470

Closed tepreece closed 1 year ago

tepreece commented 1 year ago

I'm experiencing some issues with audio sync when watching "Jet Lag: The Game".

Expected behaviour:

Actual behaviour:

Episode 2 of the Japan season (the latest episode as of the time of submission of this issue) is a good example. It begins with an extended motion-graphics sequence, and the sound effects that play in time with the graphics on desktop play several seconds ahead on Kodi.

Adjusting the audio offset in Kodi makes no difference: the audio plays several seconds ahead of the video, regardless of how the audio offset is set.

So far it appears to only be Jet Lag that is affected. None of the other creators that I watch have the same issue, including the other channels by the same creator (Wendover Productions, Half as Interesting).

The same video plays with the correct audio offset in a web browser, and the YouTube version of Jet Lag plays with the correct audio offset in Kodi.

Previous seasons were not affected by this issue when I watched them at the time of release, but I also tested some previous episodes today and found the same issue.

I'm running version 0.2.3 of the addon, on a fully up-to-date OSMC on a Vero 4K+.

Here is a log extract from playing the most recent episode: 

2023-06-07 16:40:26.171 T:3153  warning <general>: Setting most video properties through ListItem.setInfo() is deprecated and might be removed in future Kodi versions. Please use the respective setter in InfoTagVideo.
2023-06-07 16:40:26.222 T:2952     info <general>: VideoPlayer::OpenFile: plugin://slyguy.nebula/?_=play&_play=1&slug=jetlag-ep-2-we-played-a-96hour-game-of-capture-the-flag-across-japan
2023-06-07 16:40:26.230 T:3300     info <general>: Creating InputStream
2023-06-07 16:40:26.394 T:3300     info <general>: AddOnLog: inputstream.adaptive: [Repr. chooser] Resolution set: 1920x1080, max allowed: 1920x1080, Adjust refresh rate: 0
2023-06-07 16:40:26.584 T:3300     info <general>: AddOnLog: inputstream.adaptive: Successfully parsed manifest file (Periods: 1, Streams in first period: 3, Type: live)
2023-06-07 16:40:26.584 T:3300     info <general>: Creating Demuxer
2023-06-07 16:40:26.587 T:3300     info <general>: Opening stream: 1001 source: 256
2023-06-07 16:40:26.687 T:3300     info <general>: Creating video codec with codec id: 27
2023-06-07 16:40:26.688 T:3300     info <general>: CDVDVideoCodecAmlogic: using Amlogic decoder H.264/MVC
2023-06-07 16:40:26.722 T:3300     info <general>: secureOSMC setup successful
2023-06-07 16:40:26.723 T:3300     info <general>: auth_get_key_id: TEEC_InvokeCommand failed with code 0xffff0006 origin 0x4
2023-06-07 16:40:26.723 T:3300  warning <general>: OSMCSecureOS::getKeyId: unable to get key id
2023-06-07 16:40:26.723 T:3300  warning <general>: OSMCSecureOS: key-id = <unknown>
2023-06-07 16:40:26.726 T:3300     info <general>: DVDVideoCodecAmlogic: Opened Amlogic Codec
2023-06-07 16:40:26.726 T:3300     info <general>: Creating video thread
2023-06-07 16:40:26.727 T:3300     info <general>: Opening stream: 1002 source: 256
2023-06-07 16:40:26.729 T:3306     info <general>: running thread: video_thread
2023-06-07 16:40:26.835 T:3300     info <general>: Finding audio codec for: 86018
2023-06-07 16:40:26.842 T:3300     info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2023-06-07 16:40:26.842 T:3300     info <general>: OpenStream: Allowing max Out-Of-Sync Value of 10 ms
2023-06-07 16:40:26.842 T:3300     info <general>: Creating audio thread
2023-06-07 16:40:26.842 T:3300     info <general>: Opening stream: 1003 source: 256
2023-06-07 16:40:26.845 T:3310     info <general>: running thread: CVideoPlayerAudio::Process()
2023-06-07 16:40:26.882 T:3300     info <general>: CDVDSubtitlesLibass: Using libass version 1500000
2023-06-07 16:40:26.882 T:3300     info <general>: CDVDSubtitlesLibass: Creating ASS library structure
2023-06-07 16:40:26.882 T:3300     info <general>: CDVDSubtitlesLibass: Initializing ASS Renderer
2023-06-07 16:40:26.884 T:3300     info <general>: CDVDSubtitlesLibass: Initializing ASS library font settings
2023-06-07 16:40:26.962 T:3300     info <general>: CDVDSubtitlesLibass: Creating new ASS track
2023-06-07 16:40:27.326 T:3306     info <general>: CBitstreamConverter::Open bitstream to annexb init
2023-06-07 16:40:27.346 T:3310     info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2023-06-07 16:40:27.347 T:3310     info <general>: Creating audio stream (codec id: 86018, channels: 2, sample rate: 48000, no pass-through)
2023-06-07 16:40:27.357 T:3047     info <general>: CActiveAESink::OpenSink - initialize sink
2023-06-07 16:40:27.357 T:3047     info <general>: CAESinkALSA::Initialize - Requested layout FL, FR
2023-06-07 16:40:27.358 T:3047     info <general>: CAESinkALSA::Initialize - set digital codec 0
2023-06-07 16:40:27.358 T:3047     info <general>: CAESinkALSA::Initialize - Attempting to open device "default"
2023-06-07 16:40:27.367 T:3047     info <general>: CAESinkALSA::Initialize - Opened device "default"
2023-06-07 16:40:27.367 T:3047     info <general>: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
2023-06-07 16:40:27.367 T:3047     info <general>: CAESinkALSA::InitializeHW - Using data format AE_FMT_S24NE4
2023-06-07 16:40:27.369 T:3047     info <general>: CAESinkALSA::Initialize - speaker layout 0
2023-06-07 16:40:27.388 T:3047    error <general>: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
2023-06-07 16:40:27.887 T:2952     info <general>: Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY
2023-06-07 16:40:27.897 T:2952     info <general>: Constructing CRendererAML
2023-06-07 16:40:29.142 T:2952     info <general>: CVideoPlayer::CloseFile()
2023-06-07 16:40:29.142 T:2952     info <general>: VideoPlayer: waiting for threads to exit
2023-06-07 16:40:29.143 T:3300     info <general>: CVideoPlayer::OnExit()
2023-06-07 16:40:29.143 T:3300     info <general>: Closing stream player 1
2023-06-07 16:40:29.145 T:3300     info <general>: Waiting for audio thread to exit
2023-06-07 16:40:29.150 T:3310     info <general>: thread end: CVideoPlayerAudio::OnExit()
2023-06-07 16:40:29.151 T:3300     info <general>: Closing audio device
2023-06-07 16:40:29.171 T:3047     info <general>: CActiveAESink::OpenSink - initialize sink
2023-06-07 16:40:29.171 T:3300     info <general>: Deleting audio codec
2023-06-07 16:40:29.172 T:3300     info <general>: Closing stream player 2
2023-06-07 16:40:29.173 T:3300     info <general>: waiting for video thread to exit
2023-06-07 16:40:29.185 T:3306     info <general>: thread end: video_thread
2023-06-07 16:40:29.187 T:3300     info <general>: deleting video codec
2023-06-07 16:40:29.192 T:3300     info <general>: Closing stream player 3
2023-06-07 16:40:29.207 T:3069     info <general>: Deleting settings information for files plugin://slyguy.nebula/?_=play&_play=1&slug=jetlag-ep-2-we-played-a-96hour-game-of-capture-the-flag-across-japan
2023-06-07 16:40:29.214 T:3300     info <general>: ADDON: Dll Destroyed - InputStream Adaptive
2023-06-07 16:40:29.216 T:2952     info <general>: VideoPlayer: finished waiting
2023-06-07 16:40:29.216 T:2952     info <general>: CVideoPlayer::CloseFile()
2023-06-07 16:40:29.216 T:2952     info <general>: VideoPlayer: waiting for threads to exit
2023-06-07 16:40:29.216 T:2952     info <general>: VideoPlayer: finished waiting
2023-06-07 16:40:29.273 T:2952    error <general>: Control 55 in window 10025 has been asked to focus, but it can't
2023-06-07 16:40:29.369 T:3047     info <general>: CAESinkALSA::Initialize - Requested layout FL, FR
2023-06-07 16:40:29.369 T:3047     info <general>: CAESinkALSA::Initialize - set digital codec 0
2023-06-07 16:40:29.370 T:3047     info <general>: CAESinkALSA::Initialize - Attempting to open device "default"
2023-06-07 16:40:29.376 T:3047     info <general>: CAESinkALSA::Initialize - Opened device "default"
2023-06-07 16:40:29.377 T:3047     info <general>: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
2023-06-07 16:40:29.377 T:3047     info <general>: CAESinkALSA::InitializeHW - Using data format AE_FMT_S24NE4
2023-06-07 16:40:29.386 T:3047     info <general>: CAESinkALSA::Initialize - speaker layout 0
2023-06-07 16:40:30.047 T:3153  warning <general>: Setting most video properties through ListItem.setInfo() is deprecated and might be removed in future Kodi versions. Please use the respective setter in InfoTagVideo.

I noticed that there was a new version of the Nebula addon since the previous series ended. I downgraded to 0.2.2 to test whether that had the same problem - but that version will no longer play any videos, and shows the following error when I attempt to play one:

error <general>: slyguy.nebula - 'NoneType' object has no attribute 'startswith'
Traceback (most recent call last):
    File "/home/osmc/.kodi/addons/script.module.slyguy/resources/modules/slyguy/signals.py", line 41, in throwable
        yield
    File "/home/osmc/.kodi/addons/script.module.slyguy/resources/modules/slyguy/router.py", line 121, in dispatch
        function(**params)
    File "/home/osmc/.kodi/addons/script.module.slyguy/resources/modules/slyguy/plugin.py", line 62, in decorated_function
        item = f(*args, **kwargs)
    File "/home/osmc/.kodi/addons/script.module.slyguy/resources/modules/slyguy/plugin.py", line 53, in decorated_function
        return f(*args, **kwargs)
    File "/home/osmc/.kodi/addons/slyguy.nebula/resources/lib/plugin.py", line 402, in play
        data = api.play(slug)
    File "/home/osmc/.kodi/addons/slyguy.nebula/resources/lib/api.py", line 220, in play
        def play_podcast(self, channel, episode):
    File "/home/osmc/.kodi/addons/slyguy.dependencies/resources/modules/requests/sessions.py", line 564, in head
        return self.request('HEAD', url, **kwargs)
    File "/home/osmc/.kodi/addons/script.module.slyguy/resources/modules/slyguy/session.py", line 358, in request
        if not url.startswith('http'):
AttributeError: 'NoneType' object has no attribute 'startswith'
matthuisman commented 1 year ago

Playback is generally out of the hands of addons. I doubt this will be an issue I can resolve.

Could be an inputstream. Adaptive issue or Kodi issue or osmc issue. You'd be best to advise the versions for each of those (or provide full debug log)

And thanks for the heads-up on the new season, it's my fav show

matthuisman commented 1 year ago

also see this issue: https://github.com/MichaIng/DietPi/issues/4998

matthuisman commented 1 year ago

i just tried on Kodi 20 windows and have no such audio sync issues Also on Kodi 20 android was fine i think best to open an issue on osmc forums :)

matthuisman commented 1 year ago

actually, i found a small bug in the code. All streams were getting treated as live streams so the "Use Inputstream for HLS for VOD Stream" was not doing anything.

It was actually using the "Use Inputstream for HLS for Live Stream" value.

v0.2.4 fixes that so now it uses the "Use Inputstream for HLS for VOD Stream" correctly.

This is default to OFF - so by default - Nebula will now use FFMPEG for VOD and IA for live.

@tepreece please try with now. Try with this enabled and with this disabled and see if either fix your issue. If still issue either way - then OSMC forums probably best place to ask

UPDATE AGain: found that FFMPEG in nebula has issues seeking. So I have now forced the use of Inputstream adaptive with v0.2.5 looks like you were using IA and having issues. So you could try turn off IA in v0.2.4 and see if that helps. 0.2.5 doesnt even have the IA setting anymore

tepreece commented 1 year ago

I tried 0.2.4 with IA on and off, and 0.2.5, and both had the same issue.

You mentioned trying it on Windows, which reminded me that I had meant to try it on my Ubuntu desktop as well - and it works fine there too.

So it does sound like it's an issue specific to OSMC - I'll follow up with them and see if they have any ideas.

Thanks for your help!

matthuisman commented 1 year ago

im going to close this for now. hopefully osmc can fix for you