[REGRESSION] Kodi v18.8 (EDL) muting de-syncs audio 8/12/20

[lilgandhi1199]

Expected Behavior

Here is a clear and concise description of what was expected to happen:

Back in Kodi Version 17.0 it will mute starting at the indicated time and unmute at the end time (as it is marked precisely in the EDL file).

Here is a comparison video of the last stable build 17.1-RC1 (GIT:2017-02-22-964306f)
https://drive.google.com/file/d/1G6YFIc4Owpdt2y3hj7W3mZQrA7NZyDhc/view?usp=sharing

Actual Behavior

The problem is that instead of giving us silence at the start of the mute time it plays the next available sound (which would be the sound, possibly in the buffer, that comes immediately after the marked end mute time)
So, it will play a seemingly random length of audio from the future which won't line up with the lips at all. And it will then silence the audio until it reaches the end of the stolen audio buffer. <<< Instead of unmuting at the marked end time.

Here is a simple video demonstration. Watch their lips
https://drive.google.com/file/d/1Njj79fA5fpLJuu7obMJ5F1LM68D1qBJz/view?usp=sharing

Possible Fix

Remove the patch that came in and messed with the EDL code in V17.1
#11714
^^^ here

To Reproduce

Steps to reproduce the behavior:

1. Download
   https://drive.google.com/open?id=1YBoUXXO3CcjUNgl-eg_Otsu_vwjhwtxm
   !!!Ignore log file which was on Windows 7 originally with Kodi v18.5
   18.8 log on windows 10 is below >>>

WATCH Jimmy Stewart's LIPS.
You will see him grunting repeatedly then on his last grunt you will suddenly see him talking from the future audio.

2...Watch it with and without the edl file in the same folder to get a feel for the dialogue. Note audio should be set to Stereo PCM through DirectSound possibly

3. Play my clip or try it on lots of other videos too that you're more familiar with and watch their lips to see when the audio is getting played ahead of time.
   ...Sometimes it won't play sound from the future (but I think honestly those times it was just silent in the movie where it stole the sound from)
   I notice that 90% of every video does this. And it happens on 4 of my computers Windows 7 Windows 8 and Windows 10 included. I have further tested on 2 more machines with ubuntu 16.04 through 20.04
   It happens on full 1080p blurays and 480p dvds and everything in between from my experience. Audio formats don't matter either.

Debuglog

The debuglog can be found here:

kodi.log
^^^Kodi V18.8 on windows 10
!!!The log in the original download is for 18.5 which can be ignored

As requested
Kodi Nightly Log 8/13/20
https://pastebin.com/CzNeTfML

Additional context or screenshots (if appropriate)

Here is some additional context or explanation that might help:

The other person who initially brought up the most recent EDL (commercials don't skip because of comments) bug over on the forums mentioned this lingering issue (once the comments bug was fixed)
His name is "Astrocyte74" and you can see what he said here
https://forum.kodi.tv/showthread.php?tid=349685
"There is still the annoying audio sync issue for a few seconds before and after every '1' (mute) where as with kodi 17.0 (and earlier builds) the mute worked perfectly. Should I report this somewhere?"
I have also found that v16.1 did not have this issue

EDIT:
Here is another description of his issue which sounds like mine too
"With 18.4, .edl files worked. Though, since v17 .edl files have caused a temporary audio sync issue but it always re-adjusts / catches up. Here is a log for 18.4 running the same movie / edl file:"
^^^But there's his log too...actually that has the previous bug in it which seems to have been fixed.
I'll ask him for a new log only showing this bug which remains which we both seem to have.

Your Environment

Used Operating system:

• Android

• iOS

• Linux

• OSX

• Raspberry-Pi

• Windows

• Windows UWP

• Operating system version/name:

• Kodi version: 18.8

note: Once the issue is made we require you to update it with new information or Kodi versions should that be required.
Team Kodi will consider your problem report however, we will not make any promises the problem will be solved.

[DaVukovic]

Hm, unfortunately I can't reproduce your issue on Linux with my own video files and your EDL file. The muting steps in at that exact time, then everything is muted until the end-time hast reached. Then I hear the normal audio of the video until the next start-time has reached and it's again muted until the end-time.

Will download your file and see if that behaves differently

Edit: Tried with your video file and everything works as expected. So I still can't reproduce

[lilgandhi1199]

I have another gentlemen over on the forums who is likely experiencing the same issue and so I messaged him to come tell us more aswell.
He's also on Windows. Might not be an issue on linux,

Here is another description of his issue which sounds like mine too
"With 18.4, .edl files worked. Though, since v17 .edl files have caused a temporary audio sync issue but it always re-adjusts / catches up. Here is a log for 18.4 running the same movie / edl file:"
^^^But there's his log too...actually that has the previous bug in it which seems to have been fixed.
I'll ask him for a new log only showing this bug which remains which we both seem to have.

However everyone just make sure to watch their lips. Also like I said depending on the source material the audio that it steals from after the expected mute time might be silent or uninteresting so you might not notice it either.

However, Thank you for testing yourself sir DaVukovic.

[lilgandhi1199]

Let me get the log from my Windows 10 PC as well.
I'll be back later with that

EDIT:
kodi.log

[lilgandhi1199]

@fuzzard
@the-black-eagle

Before V19 comes out I know one of you fixed a recent EDL file bug and wonder if you can tackle this one too?

I'm ready to get more logs and do more testing for you when you're ready!

[lilgandhi1199]

@FernetMenta Hey I heard from the-black-eagle that you might be the one to fix this if you can figure it out due to it being an audio bug.
He also said Fritsch is retired but would also know.

Maybe I'll install the nightly version and see if you guys ended up fixing it already maybe with your last review of the EDL code!
Where would I find that though?

[lilgandhi1199]

Alright. Forget about nightlies.
I got the log from Version 17.0 when everything worked perfectly
kodi-17.0-pre_bug.log
and then after the bug popped up the log from 17.1
kodi-17.1-post_bug.log

I noticed in the changelog someone was in the EDL code.

Added support for navigation controls between EDL (commercial skipping) during PVR recodings playback

And it referenced this github pull
#10064

[lilgandhi1199]

@DaVukovic
I think I figured it out! ^^^
Can you provide the nightlies exe install file from 17.0 before 17.1 came out (specifically the day before that request was merged into the project and the day after it was implemented?)

Then if I can prove it is infact his code by testing it this way we could just disable his code in the current version of Kodi and watch the flag fly in the breeze of victory!

[lilgandhi1199]

Here is my analysis of the logs... if it means anything I have no clue. Just grasping for straws of where to look
https://pastebin.com/raw/mDUzYXKN

[lilgandhi1199]

Please! Someone reverse that badly implemented feature addition before windows 10 becomes mandatory and kodi moves onto another version with my chance to have proper muting AND v18 completely gone.

[phunkyfish]

@lilgandhi1199 can you remove your log paste from this issue and use a paste site or a gist instead?

Also it would help if you can reproduce this on Matrix and provide logs for it there. There will have been a lot of code change from kodi 17 to the current master version.

[lilgandhi1199]

Yes let me get right on that!
Oh and the original log file was the current version of kodi by the way I'm 90% sure. I'm going to install 18.8 and get that one as well right now though still. Do I need to make a new issue? I don't see this thread listed in the issues anymore...is that because it's gone from 18.5>18.8??

@DaVukovic The same thing is happening on Ubuntu 20.04 newest Kodi...Ubuntu 16.04...Ubuntu 18.04

I just don't think he knew what he was supposed to be looking for. I was more specific in the master post of the biggest red flag (which is the 2nd mute) to be clear

I also emailed @FernetMenta and he couldn't tell me what his original patch to the code inbetween Kodi V17.0 and 17.1 was really at all. Not willing to reverse fix it either I presume.

So...I have tried to compile kodi on my ubuntu machine to fix this myself in the past weeks and could not get it going after following the step by step guide. Any interest in this case is really greatly apreciated!!

Thank you as well to @techymomof6 adding his experience

@phunkyfish

I tried it on the Matrix last night, same results as described by the-black-eagle.

".edl file doesn't correctly skip or mute."

The audio is out of sync until it catches up to video after mute

I find if I have multiple skips together like for inappropriate scenes for kids, it will sometimes skip whole chunks. For example if I have 3 skips in a row doing the same time in a movie it may skip from the beginning of the first time stamp to the end of the 3rd stamp, instead of playing /skipping the stamp in between. Also it has a buffering time while it skips with visible % wheel while it catches up. The skip/mute only works perfectly in 16.1 from what I've tested.

Hope this makes sense, I don't have programming experience.

[phunkyfish]

@djp952 do you have much experience with EDL files and Video Player by any chance? I know you had some some stuff with audio in demuxer so just asking.

[techymomof6]

@lilgandhi1199 Per your request:

Test .edl Kodi v17.0:
The mute feature works as it should
The skip feature completely freezes the movie, unable to move on

Test .edl Kodi v17.1:
17.1 reads the .edl file the same as the 18 versions. The mute skips to the next audio, instead of muting through it, causing the audio to be off-sync a moment and the skip works sporadically, with buffering and sometimes skipping sections too close together.

[djp952]

@djp952 do you have much experience with EDL files and Video Player by any chance? I know you had some some stuff with audio in demuxer so just asking.

Sadly no, I'm sorry @phunkyfish. My PVR supports EDL and I know my users have been happy with it since it's return in recent Leia versions. That's all MPEG-TS stuff, though, which might have different concerns. They also seem to only use it for skipping commercials.

For what it's worth, in a quick look at some of the log files here I see a semi-correlation with something I've been wanting to report, but I'm not smart enough to offer any via suggestions about them. In the event it may be a clue that helps (which I doubt), I know of problems with audio sync in a couple cases (again, I've not reported these formally): Realtime MPEG-TS A/V streams where the audio bitrate is higher than the video bitrate, and Realtime audio only PCM streams where the PTS falls behind realtime. In both cases, VideoPlayer tries to resync the audio, but it can't since it's impossible to do so for something truly realtime. It's not possible to read into the future. In the low video bitrate case it will manifest as a regular buffer/mute/play/buffer/mute/play, in the PTS falling behind case it just can't resolve the problem and you have to give up.

Again, I doubt one thing has anything to do with the other, but I do believe there are some possible issues with audio sync logic lurking somewhere, and the parts of code being blamed are pretty much the same ones I've been looking at to see if I could offer any reasonable solutions to my problems. I honestly don't think they would apply to streams where Kodi can find the PTS it's looking for.

If this starts leading back to anything I may have touched, please let me know, I'd bend over backwards to try and make it right!

Wow, long comment that added little value :) I gotta be me, right?

edit: Maybe something with the MUTE function that isn't tracking the PTS for the dumped audio? When it tries to fire back up the PTS is so far off from the video that bad things happen? I do see pretty large sync errors in the posted log. 20 seconds, 30 seconds, etc. VideoPlayer is above my paygrade.

[phunkyfish]

edit: Maybe something with the MUTE function that isn't tracking the PTS for the dumped audio? When it tries to fire back up the PTS is so far off from the video that bad things happen? I do see pretty large sync errors in the posted log. 20 seconds, 30 seconds, etc. VideoPlayer is above my paygrade.

Ya, me too!

[phunkyfish]

In my head muting seems to be a simple concept but I'm assuming it's just not passing the audio to the audio device if the current frame is muted.

@FernetMenta, could use your guidance on how this should be done before trying to tackle it.

[djp952]

FWIW, I went ahead and hooked up some EDL via my PVR addon, and there is definitely something wonky with MUTE. For me and a recorded MPEG-TS file with EDL, introduction of MUTE actually causes video playback to stop and momentarily buffer repeatedly, similar (but not exactly the same) to what I see with the realtime streams where the audio bitrate exceeds that of the video bitrate.

I do not think I can be of significant help to fix this, but I can definitely corroborate the report that something is, as I so eloquently put it above, 'wonky'. I have some free time tonight, I'll build a Leia Debug build and see if I can perhaps assist with narrowing it down a bit.

edit: IMO this is definitely related to tracking of PTS/DTS on the audio stream when it's "muted", but my attempt at a quick and dirty fix fell flat on it's face.

[phunkyfish]

Thanks for any assistance you can provide @djp952 😉

[FernetMenta]

In my head muting seems to be a simple concept but I'm assuming it's just not passing the audio to the audio device if the current frame is muted.

@FernetMenta, could use your guidance on how this should be done before trying to tackle it.

do you have a debug log created with master branch? (on vacation with phone and tablet only)

[lilgandhi1199]

@FernetMenta Is the master branch technically 19.0 beta or whatever?
Or are you referring to 18.8? Because I've always uploaded the current branch under debuglog.

[fritsch]

Master branch is the future v19. You can find the nightly builds here: http://mirrors.kodi.tv/nightlies/windows/win64/master/

Please use pastebin.com for your logfile.

[lilgandhi1199]

Alright no problem. I forgot about pastebin. Be right back.

[lilgandhi1199]

Kodi Nightly Log 8/13/20
https://pastebin.com/CzNeTfML

[djp952]

Hi @phunkyfish, I got as far as determining that the action of dropping the audio packet without processing it is the 'root cause', per-se. By not processing the packet the DTS/PTS information and ffmpeg voodoo (that I can't debug) never take place, which ultimately leads to VideoPlayer thinking the audio stream stalled. Things start to fall apart here (Leia codebase):

xbmc/xbmc/cores/VideoPlayer/VideoPlayerAudio.cpp

Lines 390 to 396 in 0e37911

	if (bPacketDrop ||
	(!m_processInfo.IsTempoAllowed(static_cast<float>(m_speed)/DVD_PLAYSPEED_NORMAL) &&
	m_syncState == IDVDStreamPlayer::SYNC_INSYNC))
	{
	pMsg->Release();
	continue;
	}

Krypton appears to handle a dropped audio packet in what has now become CVideoPlayerAudio::ProcessDecoderOutput(), one possibility might be to pass the drop flag to that function and handle it the same way as opposed to just dropping it by ignoring it. I haven't tried anything like that yet, it only occurred to me while diffing Krypton and Leia.

Anything I tried so far was, as expected, a colossal failure other than not dropping the packet in the first place which worked fine (but audio won't be muted).

I do hope this helps in some way.

[phunkyfish]

Thanks @djp952. Your findings make sense and if it’s the manner in which the audio packets are being dropped is the issue hopefully that will us a bit closer to the answer.

[FernetMenta]

You are wrong. VPA and AE doesn't require audio packets to be processed. That's why I dropped rhis old crap. Nevertheless , VPA should not signal stalled after having dropped packets.

[lilgandhi1199]

@enen92 I tested the one you linked me directly as well as this one I saw on the master
KodiSetup-20211116-3f0508c0-master-x64

These are all default settings Windows 10 fresh install and cleared profile folder. (No audio passthrough)

Both failed in the same respect that they always fail. The audio jumps forward to play during the beginning of the mute time stealing from the end time mute. Pushing it out further then it was supposed to end and jumbling dialogue. It should be obvious as I have made a video demonstration of it with the same test clip and EDL file I linked in my original thread.

https://drive.google.com/file/d/1Njj79fA5fpLJuu7obMJ5F1LM68D1qBJz/view?usp=sharing

It does this with all video files I have ever tested. There is nothing special about mine but it is very good at demonstrating the problem.

[lilgandhi1199]

Here is a video of the last stable version
https://drive.google.com/file/d/1G6YFIc4Owpdt2y3hj7W3mZQrA7NZyDhc/view?usp=sharing

17.1-RC1 (GIT:2017-02-22-964306f)

[lilgandhi1199]

@enen92 im sorry I just didn't edit my last post to indicate you don't need to reopen.it. I was leaving it there for posterity.
I think it's fixed atleast in the link you gave me.
thanks again