AviSynth+ thread Vol.2

[jpsdr]

@qyot27
As i'm not a masochist, i didn't choose the masochist path, and used the SDK provided. So i need the DLL.


------------------------------

Otherwise, i tried to build soundtouch with LLVM, but it fails.
LLVM is integrated to Visual Studio. I use Visual Studio 2019 Update 9.26 because it's the last one (at leat with 2019, no idea about 2022) on which you can just install "clang option" without installing the compiler, and install manualy (and so update the version) the compiler using the "LLVM-xx.x.x-win64.exe" (or "LLVM-xx.x.x-win32.exe") provided on the LLVM github.
So i create the VS project with CMake, and in the project property, switch the compiler from "Visual Studio" to "clang-LLVM".
It has always worked, but not for soundtouch. Build works fine with MSVC compiler.

[gispos]

Originally Posted by pinterf

It is reproduced but I don't even know in which module does it hang.

Start AvsPMod
Open script

ColorBars(width=640, height=480, pixel_type="YUV420P8") #first loading works, reloading fails
KillAudio()
LoadPlugin("c:\RIFE\RIFE.DLL")
sourcefps=framerate(last)
RIFEsc=true
aimodel="4.17"
gpunumber=0 # ID for the GPU to use.
RIFEwrap(last, framenum=2*Round(framerate(last)), frameden=1, model=aimodel, sc=RIFEsc, gpuid=gpunumber)

Toggle Preview
Reload Script (ctrl-f5)

Stalls forever. And this is not related to the actual new Avisynth, factory 3.7.3 is doing the same. It can be at any place, on the resource free-allocation, either in Vulkan API or RIFE, or of course it can be Avisynth as well, but we'd have to know what happens on "Reload" under preview. Does RIFE get closed and reinitialized, etc.

Originally Posted by gispos

It hangs when releasing the clip.
Test:
Not F5 but in the context menu tab, 'Release video memory'
It then hangs forever.

Test 2:
Restart AvsPmod do not open the script yet, under Options select 'AvsPmod & Avisynth test'
Then I no longer have any problems, which indicates that it could be due to the Avisynth C interface.

I will take a closer look at it though.

ColorBars(width=640, height=480, pixel_type="YUV420P8") #first loading works, reloading fails
KillAudio()
LoadPlugin("D:\Tools\AviSynth\plugins64\RIFE\RIFE.dll")

sourcefps=framerate(last)
RIFEsc=true
aimodel=46
gpunumber=0 # ID for the GPU to use.
RIFEwrap(last, framenum=2*Round(framerate(last)), frameden=1, model=aimodel, sc=RIFEsc, gpuid=gpunumber)

Test 3, what I noticed:
If the 'Test Option' is turned off again, there are still no problems. Not even with F5.

It is as if something was activated in Avisynth or AvsPmod (but I think less in AvsPmod) that there are no more problems as long as Avisynth is not completely shut down by restarting AvsPmod.

This happens if the test option in AvsPmod is not used and the clip is released.

* release all frames, OK
print('frames released')
time.sleep(1)

* release all clips, OK
print('clips released')
time.sleep(1)

* release the ScriptEnvironment, Failed
self.env = None # it hangs here, but when it is commented out it runs to the end of the procedure and hangs then for ever.
print('env released')
time.sleep(1)

print('release finished')
time.sleep(1)
# at this point all has been released and AvsPmod should do nothing, but the procedure doesn't return, so avisynth doesn't return.


Next test using AviSource for the same script:
AviSource("C:\Users\GPo\Desktop\preview_test.avs")

If I open the same script just once, not directly but with AviSource, there are no more problems with other tabs (scripts) that are loaded directly.
Nothing has changed in AvsPmod, it works just as before and releasing the env works also, theoretically it can only be the Avisynth C interface that has changed something after using it once with AviSource.

[pinterf]

Originally Posted by gispos

* release the ScriptEnvironment, Failed
self.env = None # it hangs here, but when it is commented out it runs to the end of the procedure and hangs then for ever.

Well, this is easier (for us) than we thought.

avs_delete_script_environment is called.
It deletes all functions.
Deletes all manually and autoloaded plugins.

And when it calls FreeLibrary("RIFE.DLL") it never returns.

[pinterf]

Originally Posted by jpsdr

@qyot27
As i'm not a masochist, i didn't choose the masochist path, and used the SDK provided. So i need the DLL.

Originally Posted by jpsdr

Otherwise, i tried to build soundtouch with LLVM, but it fails.
LLVM is integrated to Visual Studio. I use Visual Studio 2019 Update 9.26 because it's the last one (at leat with 2019, no idea about 2022) on which you can just install "clang option" without installing the compiler

In Visual Studio 2022 feature installer GUI, this is just two options:

[X] C++ Clang Compiler for Windows (18.1.8)
[X] MSBuild Support for LLVM (clang-cl) toolset

But Asd-g for example is using the latest one, which must be installed and integrated into VS 2022 separately, there was a discussion on github about it.

[wonkey_monkey]

Originally Posted by qyot27

Does it happen with the C-plugin?
https://forum.doom9.org/showthread.php?t=175173

It does. It's all very odd. It's seem like it's something to do with jumping from the start of the source to near the end - if I change the jump to nearer the middle it doesn't happen, and if I skip (in VirtualDub2) to the end of the output (which is just two short segments of the video spliced together with my own filter) before playing from the start, it doesn't happen. Plus I can't seem to get coherent reports from my debugging plugin.

Obviously my splicing filter should be the first suspect, but the crash only seems to happen at the point where GetAudio is being called on the source.

Anyway it's all far too complicated to expect anyone to be able to figure it out at this stage, but I just wanted to check about the audio buffer pointer changing, and whether that might be something audio caching in Avisynth+ is doing. But actually that only seems to happen when there's a GetChannels call changing the number of channels, and the crash happens either way.

[pinterf]

Originally Posted by wonkey_monkey

Anyway it's all far too complicated to expect anyone to be able to figure it out at this stage, but I just wanted to check about the audio buffer pointer changing, and whether that might be something audio caching in Avisynth+ is doing. But actually that only seems to happen when there's a GetChannels call changing the number of channels, and the crash happens either way.

Regarding whether it's cache-related or not: Avisynth 3.7.2 did not have audio cache. Version 3.7.3 reintroduced it, essentially using the audio cache code from Avisynth 2.6.

Give 3.7.2 a try.

[gispos]

Originally Posted by pinterf

Well, this is easier (for us) than we thought.

avs_delete_script_environment is called.
It deletes all functions.
Deletes all manually and autoloaded plugins.

And when it calls FreeLibrary("RIFE.DLL") it never returns.

Even if I don't kill the env, avisynth hangs !

#self.env = None # it is commented out !!

print('release finished')
# at this point all has been released and AvsPmod should do nothing, but the procedure doesn't return, so avisynth doesn't return.

Please note that:
Next test using AviSource for the same script:
AviSource("C:\Users\GPo\Desktop\preview_test.avs")

If I open the same script just once, not directly but with AviSource, there are no more problems with other tabs (scripts) that are loaded directly.
Nothing has changed in AvsPmod, it works just as before and releasing the env works also, theoretically it can only be the Avisynth C interface that has changed something after using it once with AviSource.

Video in Archive 7z: https://drive.google.com/file/d/1KgZ...ew?usp=sharing

And here Test 2: https://forum.doom9.org/showthread.p...91#post2014491

[wonkey_monkey]

Originally Posted by pinterf

Regarding whether it's cache-related or not: Avisynth 3.7.2 did not have audio cache. Version 3.7.3 reintroduced it, essentially using the audio cache code from Avisynth 2.6.

Give 3.7.2 a try.

Just got a little further ahead and have establised that it's definitely cache.cpp throwing bad_alloc at line 554.

For some reason, frame_range is negative (-1994645504), presumably an overflow.

I'll keep digging.

[pinterf]

Originally Posted by wonkey_monkey

Just got a little further ahead and have establised that it's definitely cache.cpp throwing bad_alloc at line 554.

For some reason, frame_range is negative (-1994645504), presumably an overflow.

I'll keep digging.

And is probably set and overflow here in Line 351:

    int new_size = (int)(_pimpl->vi.BytesFromAudioSamples(count) + 8191) & -8192;

[wonkey_monkey]

Originally Posted by pinterf

And is probably set and overflow here in Line 351:

    int new_size = (int)(_pimpl->vi.BytesFromAudioSamples(count) + 8191) & -8192;

Nope, line 380:

      int new_size = (int)(_pimpl->vi.BytesFromAudioSamples(std::max(count, _pimpl->AudioCacheStart + (int64_t)_pimpl->CacheCount - start)) + 8192) & -8192; // Yes +1 to +8192 bytes

GetAudio is being called with start = 240000 and count = 24000.

Edit: _pimpl->MaxSampleCount = 96084352

[pinterf]

Originally Posted by wonkey_monkey

Nope, line 380:

      int new_size = (int)(_pimpl->vi.BytesFromAudioSamples(std::max(count, _pimpl->AudioCacheStart + (int64_t)_pimpl->CacheCount - start)) + 8192) & -8192; // Yes +1 to +8192 bytes

GetAudio is being called with start = 240000 and count = 24000.

Edit: _pimpl->MaxSampleCount = 96084352

Good catch, I searched only for explicite CACHE_AUDIO_AUTO_START_ON text.
Fix? Something like this:

      int64_t new_size = (_pimpl->vi.BytesFromAudioSamples(std::max(count, _pimpl->AudioCacheStart + _pimpl->CacheCount - start)) + 8192) & -8192; // Yes +1 to +8192 bytes
      new_size = std::min((int64_t)8192 * 1024, new_size);
      _RPT2(0, "CA:%x: Autoupsizing buffer to %d bytes!\n", this, (int)new_size);
      SetCacheHints(_pimpl->AudioPolicy, (int)new_size); // updates maxsamplecount!!

[wonkey_monkey]

Yay, bug squished! Thanks pinterf.

Is it of any concern that the logic should come close to allocating such a large cache (if not for the std::min)? Is it just because I jumped 40 minutes ahead in the same clip?

[pinterf]

Originally Posted by wonkey_monkey

Yay, bug squished! Thanks pinterf.

Is it of any concern that the logic should come close to allocating such a large cache (if not for the std::min)? Is it just because I jumped 40 minutes ahead in the same clip?

I think the 8 MB size I see in the code is just a logical limit. And yes, simply jumping 40 minutes triggered the overflow.

[pinterf]

Originally Posted by gispos

Even if I don't kill the env, avisynth hangs !

#self.env = None # it is commented out !!

print('release finished')
# at this point all has been released and AvsPmod should do nothing, but the procedure doesn't return, so avisynth doesn't return.

Please note that:
Next test using AviSource for the same script:
AviSource("C:\Users\GPo\Desktop\preview_test.avs")

If I open the same script just once, not directly but with AviSource, there are no more problems with other tabs (scripts) that are loaded directly.
Nothing has changed in AvsPmod, it works just as before and releasing the env works also, theoretically it can only be the Avisynth C interface that has changed something after using it once with AviSource.

Video in Archive 7z: https://drive.google.com/file/d/1KgZ...ew?usp=sharing

And here Test 2: https://forum.doom9.org/showthread.p...91#post2014491

Thanks for the video. I see. I couldn't find those points in the source, are they private? Another question: which line's "env = None" did you comment out?
Edit1: I found the place, I think, putting there printfs I got similar debug window like you had.

Edit2:

New finding.

The reference count of the main clip (script containing RIFE) never reaches zero. As a result, the clip is not destroyed, and the RIFE plugin's "free_filter" is not called.

Clip objects are reference-counted, and their destructor is invoked only when the counter reaches zero. The function avs_take_clip (as_clip) increases the count by one. Copying with avs_copy_value also increases it by one. Conversely, avs_release_clip decreases the count by one, and avs_release_value on a 'clip' type AVS_Value also decreases it.

Each copy_value must have a corresponding release_value pair. Similarly, each take_clip must have a corresponding release_clip pair.

I see that this is handled correctly throughout the code, invoke is ok, copy and release_on_del flags usages, but still, somehow somewhere it misses a clip release.

Since the free_filter callback event is not triggered, RIFE does not clean up and destroy its GPU instance objects. This is likely why simply unloading the DLL causes internal issues.

[VoodooFX]

@pinterf Will the new version require the wrapper to be updated for MeGUI?

[Kurt.noise]

Originally Posted by VoodooFX

@pinterf Will the new version require the wrapper to be updated for MeGUI?

I tested rev 4178, and the last bundle provided in my releases was ok.

[Emulgator]

Congrats, pinterf and gispos, and many thanks for the effort !
Now further regression testing... Win10P64, i9-11900K+128GB, dGPU RTX3080+16GB, iGPU Intel UHD750
Yes, AvsPmod64 2.7.9.2 can handle AviSynth64+ r4066 and r4178 nicely, releasing works, no stalls on my few attempts.

Still AviSynth64+ r4178 crashes if I call RIFE instances within Scriptclip while r4066 performs nicely.
To exclude any sidesuckers I rewrote my interpolation .avsis to get rid of RIFEwrap.
I am calling RIFE directly now: Much better, huge speed gain !

With which Avs+ version the regression came in ? It seems to be the r41xy versions.

AviSynth64+ r4066: 1 RIFE instance within Scriptclip: Playable in AvsPmod64/Encoders64. Topaz 2.6.4 loads script, sees and processes all frames. Ok.
AviSynth64+ r4073: 1 RIFE instance within Scriptclip: Playable in AvsPmod64. Topaz 2.6.4 immediately sees no frame, range 0..-1. Unusable for Topaz.
AviSynth64+ r4096 Clang: 1 RIFE instance within Scriptclip: Playable in AvsPmod64. Topaz 2.6.4 immediately sees no frame, range 0..-1. Unusable for Topaz.
AviSynth64+ r4096 LLVM: 1 RIFE instance within Scriptclip: Playable in AvsPmod64. Topaz 2.6.4 immediately sees no frame, range 0..-1. Unusable for Topaz.

AviSynth64+ r4173: 1 RIFE instance within Scriptclip: F5-loading in AvsPmod64 2.7.9.2: 1st frame 0 gets loaded.
When I press Play: I hear the first audio blip for that frame 0, then frame 0 is shown stuck for 5..6 seconds, no audio.
After these 5 seconds I hear the same audio blip of frame 0 a second time, then AvsPmod64 aborts.
Topaz 2.6.4 crashes immediately on script loading.

AviSynth64+ r4177: 1 RIFE instance within Scriptclip: F5-loading in AvsPmod64 2.7.9.2: 1st frame 0 gets loaded.
When I press Play: I hear the first audio blip for that frame 0, then frame 0 is shown stuck for 5..6 seconds, no audio.
After these 5 seconds I hear the same audio blip of frame 0 a second time, then AvsPmod64 aborts.
Topaz 2.6.4 crashes immediately on script loading.

AviSynth64+ r4178: 1 RIFE instance within Scriptclip: F5-loading in AvsPmod64 2.7.9.2: 1st frame 0 gets loaded.
When I press Play: I hear the first audio blip for that frame 0, then frame 0 is shown stuck for 5..6 seconds, no audio.
After these 5 seconds I hear the same audio blip of frame 0 a second time, then AvsPmod64 aborts.
Topaz 2.6.4 crashes immediately on script loading.

P.S. I have to repeat those tests.
I found a repeatable race condition which leads to stalled processing, under same hovering CPU/GPU load, even with r4066.
After around ~83% progress rendering slows down sharply until the very same frame seems to be served forever,
sometimes advancing, then stalling, downstream forcing a reloading, but AviSynth+ delivers no more frames
and downstream is waiting forever.

AviSynth64+ r4066 serving a restoration script for frameskipped 29.97->25fps footage.
The sequence is: Skippy 25p -> periodically/manually insert dup-before-skip, obtaining duppy-skippy 29,97p ->
Interpolate over each dup -> obtain smooth moving 29.97p -> Interpolate 2x fps -> 59.94p
The script concatenates various trimmed segments of SelectEvery(5,0,0,1,2,3,4).Assumefps("ntsc_video"),
then calling an Interpolation .avsi which contains ScriptClip loops containing RIFE procedures which are auto-triggered by consecutive dups.
If the SelectEvery() section is commented out (because the source contains no frameskips), all is well, no stalling.
Happens the same on 2 identical machines, System SSDs not exact mirrors, but similar environment.

P.P.S. It just hits me that the rendering getting stuck around 83% progress (5/6) matches the frame ratio (5in/6out) !
Non-matching framecount/current_frame calculation/reporting along SelectEvery/ScriptClip/RIFE?

PPPS. Took SelectEvery() out of the chain.
Played that reduced script in AvsPmod: No problem, plays until the end 100%.
Fed that reduced script to Topaz: 83% stuck.
SelectEvery back in, played the full script in AvsPmod: No problem, plays until the end 100%.
Fed the full script to Topaz: 83% stuck.
It might have to do with how frames are reported to Topaz, I guess; the no frames (0,-1) could point into such direction as well.

Ok, back to intermediates then for such corner cases.

PPPPS: The 83% stuck was Topaz fault choking on audio stream shorter than video.
As I exported a test clip from AvsPmod and threw it into Vegas it beame obvious:
My 25->29 procedures within AviSynth+ led to audio being only 83% of video length.
Workaround: KillAudio() at the start, AudioDub() at the end after all trickery is done.

[pinterf]

Originally Posted by Emulgator

AviSynth64+ r4066: 1 RIFE instance within Scriptclip: Playable in AvsPmod64/Encoders64. Topaz 2.6.4 loads script, sees and processes all frames. Ok.
AviSynth64+ r4073: 1 RIFE instance within Scriptclip: Playable in AvsPmod64. Topaz 2.6.4 immediately sees no frame, range 0..-1. Unusable for Topaz.
[...]
If the SelectEvery() section is commented out (because the source contains no frameskips), all is well, no stalling.
Happens the same on 2 identical machines, System SSDs not exact mirrors, but similar environment.

PPPS. Took SelectEvery() out of the chain.
Played that reduced script in AvsPmod: No problem, plays until the end 100%.

Fantastic job on the bug report!
These helped a lot.
There indeed was a commit related to Interleave (which is called by SelectEvery). I'm gonna look at it.

EDIT: Please try with this test build.
EDIT 2: Found the cause of the crash. Test build removed and currently under construction.
EDIT3: The access violation occurred when AviSynth was inside a ScriptClip with a C plugin and getPropInt (or any other runtime getter).
Please try this build (find the 4182-uncommitted version):
https://github.com/pinterf/AviSynthP...ag/v3.7.3.4178

One less bug. Let's see how it is working for you. I had successful reloads and parallel scripts open in the new AvsPMod. Thanks.

[Jamaika]

YUV420P8 doesn't work for me.

if (!vi.IsPlanar() || !vi.IsPlanarRGB() || !vi.IsPlanarRGBA())
            throw_error("clip must be planar");

[StainlessS]

Jamaika, is that YOUR code, or Avs+ code ?

If yours (where post is Off Topic in this thread), then how about

if (!(vi.IsPlanar() || vi.IsPlanarRGB() || vi.IsPlanarRGBA()))
            throw_error("clip must be planar");