Encoding slowdown

[hello_hello]

Is there anything a mere mortal can do to trackdown the cause of a slowdown?

I've been re-encoding a bunch of AVIs I first remuxed as MKV (old TV captures) and every so often I notice one will run at half the usual speed. I'm pretty sure it doesn't slow down. It starts off slow and stays slow. As I'm using slow filtering I'm encoding them two at a time, but I've noticed the same thing happen when only running one encode. If I stop the "slow" encode and start it again, it invariably runs at normal speed. I've only noticed it happen when using QTGMC and LSFMod in the same script. Is there any way to determine if it's a plugin at fault or if it's some odd Avisynth bug? I'm running (sorry) XP and Avisynth 2.6.0.6

I've had odd problems before when combining QTGMC and LSFMod. One batch of files would often encode at half speed if I encoded them from the beginning, but simply putting something like Trim(50,0) at the end of the script would ensure the encoding would run at normal speed. I just don't know if it's possible, or how to find the culprit. Here's today's example:

Same type of source video. The one on the left is running at normal speed, while the one on the right is running at half speed.
http://s3.postimg.org/7p6sqr6rj/2encodes1.jpg (http://postimg.org/image/7p6sqr6rj/)

After aborting the encode on the right and starting it again, it runs at normal speed.
http://s10.postimg.org/dh8lxvw0l/2encodes2.jpg (http://postimg.org/image/dh8lxvw0l/)

After aborting it a second time and adding Trim to the script so it commences from where it left off the first time, it still runs at normal speed.
http://s12.postimg.org/7z6rv29k9/2encodes3.jpg (http://postimg.org/image/7z6rv29k9/)

This is the script:
LoadPlugin("C:\Program Files\MeGUI\tools\ffms\ffms2.dll")
FFVideoSource("E:\video.mkv", cachefile="D:\video.mkv.ffindex", fpsnum=24000, fpsden=1001, threads=1)
QTGMC(InputType=1, Ezdenoise=2)
LSFMod(strength=66)
gradfun3()


The resolution of these files is only 640x480. When this problem occurs while re-encoding HD video, which it does now and then, things get really slow.
Thanks.

[StainlessS]

Hello, Hello Hello.

Sorry dont have a clue about cause of your problem, however

putting something like Trim(50,0) at the end of the script would ensure the encoding would run at normal speed

I pretty much always put a Trim(0,0) in my automated scripts to make sure that any spliced clips dont result in audio sync problems,
all it does is chop off any extra audio that is longer than video, OR, pad (EDIT: with silence) short audio to same length as video.
Might be worth a try seeing if Trim(0,0) at end of your scripts obviates or 'hides' the problem that you are having.
There should be no ill effects.
Good luck.

EDIT: Adding a trim to end of script would insert an extra cache, but no idea why that might prevent the problem.

[johnmeyer]

I don't know of tools or methods to help track down the cause of a slowdown. However, the symptoms you describe can be caused by running out of RAM memory, and the system then switching over to using your disk drive as "virtual memory." This results in a condition known as "thrashing." The next time you do an encode, look at the disk drive light on your computer at the beginning of the encode, when everything is running fast. Then, if you sense a slowdown, look at the disk drive light again and see if it is lit all the time, or is lit a lot more than before. If so, you've got thrashing, and this is most likely your problem. Most AVISynth encodes are not disk bound, and usually the disk light is off more than on.

If you do suspect disk thrashing, a way to sometimes get around memory issues -- although it is not a fix that will always work -- is to use a "SetMemoryMax()" statement at the beginning of the script. The largest number you can use depends on what version of Windows you use. The number is given in kB, so a good number to start with is 768, e.g., SetMemoryMax(768).

[kuchikirukia]

Don't know if it's the same problem, but i had the same symptoms and solution with QTGMC using LSMASH (half-speed encodes solved by trimming off the first few frames.) Something about it would cause LSMASH to keep creating and killing threads.

http://forum.doom9.org/showthread.php?p=1736158#post1736158

Though it will occasionally do it without QTGMC, it seems to be a major trigger.

Set Threads=2 and load up process explorer (with admin access) and see if ffms2 is doing the same thing.
If it is the same bug, your half-speed encodes may have errors.

[hello_hello]

Thanks for the replies guys.

I had a very repeatable QTGMC speed issue at one stage with particular files (but once again, only in combination with LSFMod). I posted about it here, and at VideoHelp (http://forum.videohelp.com/threads/369143-ResizersPack-MasksPack-PlaygroundPack-SmoothContrast-Logo-mod-functions?p=2389299&viewfull=1#post2389299), along with a sample of the video in question. That's when Trim(50,0) stopped the slowdown from happening. In that case, so did using MP_Pipeline. I also discovered if I reverted back to an earlier version of QTGMC the problem went away. Dogway also modified his mod of QTGMC for me (http://forum.videohelp.com/threads/369143-ResizersPack-MasksPack-PlaygroundPack-SmoothContrast-Logo-mod-functions?p=2389468&viewfull=1#post2389468) and that fixed the problem, but I don't think it was ever discovered why.
In that case MP_Pipeline preventing the slowdown seemed to point to a memory issue, but if it was, it makes no sense that something as simple as Trim(50,0) could fix it too, or switching to an older QTGMC version would do likewise.
I'm pretty sure it happened whether I was using ffms or L-Smash for indexing, but I might need to re-test that.

In the above case the problem was 100% repeatable for me, and re-starting the encodes didn't make the problem go away, whereas the files I referred to in the opening post here generally encode at normal speed, only every now and then one doesn't, despite the source files all being the same (640x480, Xvid AVIs). That makes it even harder to track down the cause, because it's so irregular and random.

I don't think it's a memory issue, because it's happened while the PC's been unattended and MeGUI is running through the jobs in the queue two at a time, yet job number 14 (for example) might encode at half speed for no apparent reason, then it's back to full speed for the next job. If it is a memory issue, I've not noticed any disc thrashing as a result. The hard drive light just flashes now and then.
I've not seen any errors in the slow encodes either. I checked one quite thoroughly and it looked fine, even though in that case encoding had slowed to about 1fps.

I'll probably try the sample I linked to again in the next day or so (if anyone else would care to try it, it's attached to the VideoHelp post I linked to along with the scripts I was using) as "hopefully" that'll make the problem 100% repeatable again, and if so I'll try Trim(0,0) to see if that makes a difference. I'd be interested to learn if the sample encodes at normal speed using the same script for someone else (it encoded at a snail's pace using two different PCs here).

Thanks.

[hello_hello]

I think maybe I'll try older versions of QTGMC next time to see if that's the problem. The main reason it's so noticeable for me is I generally run a bunch of encodes with similar scripts one after the other, and often two at a time.

This encode started while I was in bed. Along with a second encode which started around the same time. I was fairly surprised they hadn't completed when I checked. They both ran at the same speed. The pertinent info from MeGUI's log file:

[Information] [20/10/15 9:35:04 AM] Avisynth input script
-[NoImage] LoadPlugin("C:\Program Files\MeGUI\tools\dgindex\DGDecode.dll")
-[NoImage] DGDecode_mpeg2source("D:\078 Genesis Of The Daleks, Part 4.d2v")
-[NoImage] trim(0,712).TFM().ChangeFPS(50,1)\
-[NoImage] ++trim(713,34273).QTGMC(sharpness=0.5)\
-[NoImage] ++trim(34274,0).TFM().ChangeFPS(50,1)
-[NoImage] crop(22, 10, -24, -12)
-[NoImage] Spline36Resize(640,480,0,1,0,0)
-[NoImage] gradfun3()
[Information] [20/10/15 9:35:04 AM] Job command line: "C:\Program Files\MeGUI\tools\x264\x264.exe" --level 4.1 --preset slow --tune film --crf 18.0 --keyint 500 --vbv-bufsize 78125 --vbv-maxrate 62500 --no-fast-pskip --stitchable --colormatrix bt470bg --sar 1:1 --output "D:\078 Genesis Of The Daleks, Part 4.mkv" "D:\078 Genesis Of The Daleks, Part 4.avs"
[Information] [20/10/15 3:55:18 PM] encoded 71102 frames, 3.12 fps, 1606.01 kb/s

Yet the two encodes currently running use this same script, the same encoder settings, with only a slight difference in frame numbers for Trim(), they're both currently 20% complete and both plodding along at 6.9fps. It seems odd that whenever an encode runs slower than it should, it's always around half the speed that it should.

[Information] [20/10/15 5:17:03 PM] Avisynth input script
-[NoImage] LoadPlugin("C:\Program Files\MeGUI\tools\dgindex\DGDecode.dll")
-[NoImage] DGDecode_mpeg2source("D:\078 Genesis Of The Daleks, Part 6.d2v")
-[NoImage] trim(0,733).TFM().ChangeFPS(50,1)\
-[NoImage] ++trim(734,34040).QTGMC(sharpness=0.5)\
-[NoImage] ++trim(34041,0).TFM().ChangeFPS(50,1)
-[NoImage] crop(16, 6, -16, -6)
-[NoImage] Spline36Resize(640,480)
-[NoImage] gradfun3()

[hello_hello]

It's possibly something to do with Trim(). I had two more encodes running simultaneously today and both had two "layers" of Trim() in the script. When I checked, both were running at about one quarter speed rather than the usual half speed. About 1.7fps.

LoadPlugin("C:\Program Files\MeGUI\tools\dgindex\DGDecode.dll")
DGDecode_mpeg2source("D:\video.d2v")
AssumeTFF()
trim(0,733).TFM().ChangeFPS(50,1)\
++trim(734,34040).QTGMC(sharpness=0.5)\
++trim(34041,0).TFM().ChangeFPS(50,1)
crop(16, 6, -16, -6)
Spline36Resize(640,480)
gradfun3()
Trim(0,68079)\
++Trim(68081,68081)\
++Trim(68081,0)

I aborted both encodes, changed the second lot of trims so they resumed encoding where they left off (about 7 minutes from the beginning), restarted both and now they're plodding along at 6.53fps and 6.60fps respectively. It's a mystery.....

[kuchikirukia]

Using your sample with L-SMASH and QTGMC 3.33 I get a lot of MSVCR120 thread destruction/creation causing slowdowns, though it has a period different from what I observed in my encodes (instead of constant Christmas-tree flashing slowing it to half, it does it for a few seconds, then is good for a few seconds.)
Note this is without avstp.dll, which I had disabled for other reasons, though I checked and it does it with.

http://s10.postimg.org/yqpiyc2v9/Untitled.jpg (http://postimg.org/image/yqpiyc2v9/)

Trim(50,0) and it's clear sailing:

http://s24.postimg.org/fu2iqwkkx/Untitled.jpg (http://postimg.org/image/fu2iqwkkx/)

Though your problem was using FFMS2, and I'm not seeing any slowdowns with that. (E: note, I wasn't looking at it from the very start of the clip here. See further down where there is a problem with 3.33 and FFMS2 in the first 150 frames)



E: QTGMC 3.33d, though! Halfway through the encode FFMS2 goes crazy with CPU usage and we slow down significantly.

http://s24.postimg.org/5y1wamvqp/Untitled.jpg (http://postimg.org/image/5y1wamvqp/)
This is with your QTGMC(InputType=1, Preset="medium", EzDenoise=1)

crop(4, 2, -4, -2)
Spline36Resize(1280,720)

LSFMod(strength=75)

We have a few FFMS2 CPU spikes early in the encode, it settles down to ~0.2-0.4% CPU util per thread (where it should be), but around 50% complete it jumps to 2%-6% on each thread and the avs4x264mod thread drops to 4-6% from 12.3%.
Since I have a hyperthreaded quad-core and there was plenty of CPU left, simply having extra CPU util on the FFMS2 threads should not have slowed avs4x264mod down. My guess is it wasn't being fed.
E2: Still does it adding setmemorymax(1200)

E3: Trim(0,0) doesn't help
E4: Trim(1,0) doesn't help

E5: Trim(50,0), and we're good (though we already knew that)
Trim(10,0) is good
Trim(3,0) is good
Trim(2,0) is good
Trim(1,0) (again) bad.
Edit (many moons later): Trim (2,0) was good there, but not always. Just did another round of tests where it took Trim (4,0) for it to settle down.

With Trim(2,0) or greater, FFMS2 is 0.2-0.4% CPU util throughout. With Trim (1,0) or lower, it's high at 1.2% to start, then goes up and down from 0.2 to 5% for a bit before settling at the 0.2-0.4% level, until hitting a spike at 48% of the way through, then pretty much shitting itself at 51%, which it never recovers from.

E6: QTGMC 3.33 without Trim seems to have problems at the start, too. It just doesn't result into it faltering later.
Without trim, the FFMS2 threads are at 1.4% util from the start, dropping down, then spiking to 3% at frame 20, 4% at frame 30, 6% at frame 60. Pretty much settles down after frame 80 except for a spike around 150.
Add Trim(2,0) and it's clean all the way through.

E7: Switching to LSMASH, those frames correspond where it creates and destroys MSVCR120 threads.

E8: And with 3.33d and LSMASH, 55% is where we go full Christmas with thread creation/destruction. Craps out all the way to the end.
FFMS2 has a solid event at 52-53% of 5-6% cpu util that doesn't seem to correspond to anything in LSMASH. From 53% until 55% it's back to 0.2%, and 55% is where it craps out and never recovers.

And for anyone wondering, QTGMC 3.32 also seems to have those initial problems with the first 150 or so frames. Trim(2,0) clears it up.

Even though it takes LSFmod to make 3.33d crap out at 55% here, I have definitely had QTGMC crap out without LSFmod.

Oh: System is Windows 10; Groucho2004's Avisynth 2.6.0.6 ICL10
Same result with regular 2.6.0.6
Same with Avisynth+.
Trim (2,0) seems to fix it with all.
So I'd say QTGMC 3.33d is busted. 3.33 and 3.32 don't seem to destabilize like 3.33d here, but since they also exhibit some problems at the start, it might be possible that a different script will cause them to crap out at some point too.

Ran another test with 3.33d, this time bobbing with:QTGMC()
LSFMod(strength=75)
It craps out at 24%.
So it doesn't seem to be related to anything with a feature of the clip, it's number of frames processed.
Inputtype=1 craps out after around 350 output frames
bobbing craps out after around 350 output frames
Bob with selecteven() and it craps out after around 170 output frames.
And I'm done.

[hello_hello]

Wow.... thanks for all the testing. I only just saw your post and while I've read it, I probably haven't taken it all in properly yet. I'm probably going to have to come back to this later tonight or tomorrow.

After several more half speed encodes today (while encoding scripts two at a time using this PC and also while encoding them one at a time using another PC) I switched back to the QTGMC version dogway modified for me and so far it's been fine. Yesterdays problem encodes used DGDecode for decoding so I'm assuming it's not caused by the decoder as such. Dogway's script download link no longer works, but I've posted here (http://forum.videohelp.com/threads/369143-ResizersPack-MasksPack-PlaygroundPack-SmoothContrast-Logo-mod-functions?p=2415423&viewfull=1#post2415423) asking if he could apply the same mod (http://forum.videohelp.com/threads/369143-ResizersPack-MasksPack-PlaygroundPack-SmoothContrast-Logo-mod-functions?p=2389468&viewfull=1#post2389468) to the latest QTGMC (3.33s) so I could test it (I'm not sure I trust myself to modify QTGMC correctly). If you feel so inclined, could you try again with the attached version of QTGMC. It's 3.33d with "revert to QTGMC_deflate/QTGMC_inflate" applied and I strongly suspect that's got something to do with it. I think 3.33d was the first version to use mt_xxflate.

So far I've been able to confirm that when encoding slows down, CPU usage also drops. When I'm running two normal speed encodes simultaneously using this PC, CPU usage sits on 100%. When two simultaneous encodes are both running at half speed for no apparent reason, CPU usage is more like 60%.

Anyway, thank you very much for your time and testing. Hopefully I might be able to post something more substantial than "QTGMC is sometimes slow" in the QTGMC thread soon so someone can have a look at fixing it. There's two versions of QTGMC included in the following link.

"QTGMC-3.33d (mod) v2.avsi" is version 3.33d with "revert to QTGMC_deflate/QTGMC_inflate" and so far today it's been fine.
"QTGMC 3.33s (mod) v2.avsi" is the version I've been using lately and the one resulting in slowdowns over the last few days. It should be the same as the version labelled 2015 9 10 here (http://forum.doom9.org/showpost.php?p=1732845&postcount=2041). I renamed the avsi files to stop myself becoming too confused over which flavour I was using.

Thanks.

Same zip file, two different links (in case one doesn't work).
http://www.filedropper.com/qtgmc-333d333s
http://www.megafileupload.com/9y7z/QTGMC-3.33d_&_3.33s.zip

I'll return later to read your previous post again.... more thoroughly.

[hello_hello]

kuchikirukia,
I still can't experiment too much yet as I'm wanting to finish the encoding jobs in the queue first, but since switching to the version of QTGMC 3.33d dogway modified for me, neither PC has missed a beat. Both CPUs are running close to 100% and encoding is running at normal speed for these jobs (I know that because they're consistently running at about twice the speed of some identical encodes jobs this afternoon). I'm using QTGMC and LSFMod in these scripts and that still hasn't caused a slowdown with the modified QTGMC.

I tried having a play with Process Explorer, but aside from the fact I've never used it before, I don't seem to be seeing the same info as you. I've not using avs4x264mod so I can only look at x264.exe but i'm not seeing any Avisynth related processes. I don't know if that's normal, or because I don't know what I'm doing, or because I'm using XP (I've put a parts list together for a new PC build and plan on a trip to the local PC shop tomorrow, but it's still XP until next week).

I am curious about one thing though. I thought maybe my not seeing Avisynth related processes might have something to do with avstp.dll. It probably doesn't, but what do I know, so I removed it from the Avisynth plugins folder and started a fresh encode. It still appeared in the threads list. So I thought maybe Avisynth kept it loaded between encodes, if that's even possible, so I rebooted and tried again. It still appeared in the threads list. When I removed QTGMC from the script, it didn't. How can QTGMC appear to be causing a plugin to auto-load when the plugin isn't in the plugins folder? Is it normal? Thanks.

http://s23.postimg.org/yu09wgxzr/avstp.jpg (http://postimg.org/image/yu09wgxzr/)

Edit: Okay I found a partial answer. When I move avstp.dll to the root of my D drive it still manages to get loaded/used. I'm not sure why and it's not what I expected. I tried the root of the C drive and the E drive and it's not loaded from there, but the root of the D drive and it is. I assume that's not inexplicable, but I don't know what the explanation is.

Cheers.

[kuchikirukia]

You have another copy of avstp.dll in some auto-load directory.

Ok, while testing yours just found out that just:
QTGMC(inputtype=1) [and thus preset="slower]
...makes them all crap out from beginning to end. (including 3.32) LSFMod not needed. Trim doesn't fix it. This is a super-duper crap-out not seen before.
Add preset=medium to it and we're good with 3.32. (haven't tested the others)

I'm also now noticing some hiccups with just using QTGMC() using 3.32. Past 25% we definitely have a lot of 2-5% CPU util on FFMS2, and it does slow down a bit, but just not half. Goes from 2.83fps (and rising) to 2.45. This is with just assumetff() and qtgmc() -- nothing else.
Rising indeed: with Trim(50,0) it tops out at 3.1 fps.

This problem doesn't seem to affect it at the preset=slow level. 5.83fps with or without trim. (though a heavier script might)

I'll run a couple tests with your scripts in the next post. Just gonna leave this with 3.32 since it's more important.

[kuchikirukia]

Your 3.33s mod v2 breaks at 350 frames with QTGMC(preset="slow")
3.33d mod v2 doesn't.
At preset= slower, 3.33d mod v2 does the same thing as 3.32 though. It slows down around 250 frames in.
Trim (50,0) fixes it.

[real.finder]

hello_hello change nothing but the below

http://i.imgur.com/NqxLJh5.png

anyway I made it

http://forum.doom9.org/showpost.php?p=1732845&postcount=2041

2016 one

[kuchikirukia]

Ok, that 3.33s just posted reverts to the previous (3.32, 3.33,"3.33d mod v2") behavior: with a call of QTGMC() it slows down after ~300 frames. Though not halving. With FFMS2 showing excessive CPU util:

http://s29.postimg.org/71029fjhv/Untitled.jpg (http://postimg.org/image/71029fjhv/)

Without trim: 2.53 fps
With trim(50,0): 3.10 fps

[hello_hello]

You have another copy of avstp.dll in some auto-load directory.


Because I'm using Avisynth 2.6.0.6 there's only one auto-load directory in the registry.
I did a thorough search though, and there's no avstp.dll in a directory that could be an auto-load directory, plus it only loads when I put it at the root of the D drive. If I put it on another drive it doesn't load (unless it's in the avisynth plugins folder).

I even searched the registry for "PluginDir2_5" and only found one instance, pointing to the usual Avisynth/plugins folder. I'll try again later with some other plugins to see if they all autoload when residing at the root of the D drive, or if avstp.dll is the only one. I'm certain it is loading from there, unless I've lost my mind.

All my current jobs finished without any slowdowns, so I'll give the modified 3.33s a spin shortly with the problem sample (thanks real.finder), although I don't expect the result to be any different to yours kuchikirukia.

One thing I'd be keen to learn, is why that sample? What's different about it that it always causes issues with QTGMC?

[hello_hello]

So far the new QTGMC mod is behaving itself with that sample for me. Even when using preset="slow".

Have I mentioned that for this sample at least (and for me), the other fix, aside from Trim(50,0) was to use MP_Pipeline? It fixed the problem for these particular encodes, but I'm fairly sure there's been a few encodes since where it didn't. Why MP_Pipeline changes things in relation to slowdowns, I have no idea.

I'm copying the numbers from MeGUI's log file, and keep in mind this PC's old so it's slow. I've listed the encoding speed for comparing QTGMC versions.

QTGMC 3.33s (new version) - 3.89fps.
QTGMC 3.33s with Preset="slow" - 3.11fps
QTGMC 3.33s with MP_Pipeline - 4.66fps

QTGMC 3.33d (original version) - around 1fps (I didn't bother running the whole encode)
QTGMC 3.33d with Preset="slow" - around 1fps (I didn't bother running the whole encode)
QTGMC 3.33d with MP_Pipeline - 4.69fps

I'd use MP_Pipeline all the time for HD (with QTGMC and LSFMod), but as I'm still using XP and I tend to run two QTGMC encodes simultaneously, I think I run out of RAM when encoding two at a time because eventually encoding speed slows to a crawl. The individual encodes tend to be a little slower without it, but they run at "normal" speed from start to finish.

kuchikirukia,
I assume I'm not able to see as much info about the various processes as you because I'm running XP? I can't tell what ffms2 is doing. I'm pretty sure I tried using L-Smash instead at the time (for these samples) with no change, but are you using the exact script I posted at VideoHelp for testing? I ask, because I'm using an older version of ffmsindex as it tends to behave itself, but now and then ffmsindex does odd things due to the frame rate conversion MeGUI adds to the script. Mostly I think it's a good idea to include it, but now and then it makes fmsindex behave oddly (it tends to drop/repeat frames when the source is AVI). I mention it in case that's your ffms2 issue. I'm using version 2.21, I think. ffmsindex.exe is dated 21st June 2014.

MP_Pipeline("""
LoadPlugin("C:\Program Files\MeGUI\tools\ffms\ffms2.dll")
FFVideoSource("E:\test.mkv", cachefile="D:\test.mkv.ffindex", fpsnum=24, fpsden=1, threads=1)
QTGMC(InputType=1, Preset="medium", EzDenoise=1)
### prefetch: 16, 0
### ###
""")
crop(4, 2, -4, -2)
Spline36Resize(1280,720)
LSFMod(strength=75)
gradfun3()

[Groucho2004]

Because I'm using Avisynth 2.6.0.6 there's only one auto-load directory in the registry.
I did a thorough search though, and there's no avstp.dll in a directory that could be an auto-load directory, plus it only loads when I put it at the root of the D drive. If I put it on another drive it doesn't load (unless it's in the avisynth plugins folder).
Avstp.dll gets automatically loaded if it's in:
- a Avisynth autoload directory
- the directory where the script resides
- a directory to which the "PATH" environment variable points

If, for example, you or some program you installed added "d:\" to the "PATH" variable, it will be loaded.
I suggest you check that and also run the AVS Info Tool, saving the main and plugin info logs and post them here (pastebin).

[kuchikirukia]

You need to use threads=2 for it to split the FFMS2 and LSMASH threads out for you to see in process explorer.

[real.finder]

Have I mentioned that for this sample at least (and for me), the other fix, aside from Trim(50,0) was to use MP_Pipeline? It fixed the problem for these particular encodes

I don't use MeGUI but as I see it use avs4x264mod, maybe it has some issues with this case

using MP_Pipeline will do something like avs4x264mod but between script blocks

[hello_hello]

I don't use MeGUI but as I see it use avs4x264mod, maybe it has some issues with this case

using MP_Pipeline will do something like avs4x264mod but between script blocks

MeGUI only uses avs4x264mod when the 64 bit version of x264 is being used, but in my case I can't because I'm still running 32 bit XP (just for one more week, hopefully).

I checked the command line and there's definitely no avs4x264mod involved.

[Information] [23/10/15 6:21:24 PM] Job command line: "C:\Program Files\MeGUI\tools\x264\x264.exe" --level 4.1 --preset slow --tune film --crf 18.0 --keyint 240 --vbv-bufsize 50000 --vbv-maxrate 50000 --stitchable --colormatrix bt470bg --sar 1:1 --output "D:\test.mkv.mkv" "D:\test.mkv.avs"

[hello_hello]

Avstp.dll gets automatically loaded if it's in:
- a Avisynth autoload directory
- the directory where the script resides
- a directory to which the "PATH" environment variable points

In my case it would have been option number two. At least that clears up one mystery.
Cheers.

[hello_hello]

You need to use threads=2 for it to split the FFMS2 and LSMASH threads out for you to see in process explorer.

I tried but it didn't make any difference. I'm still not seeing that process. Could not using avs4x264mod have anything to do with it? Maybe ffms2 is ignoring the parameter (I'm using an older version) but later (maybe tomorrow) I'll run those encodes again with threads=2 and also with the latest ffms2 to see if anything changes. I pretty much always use threads=1 so I should check to make sure increasing the thread count doesn't have an adverse effect. I'll report back if anything changes.

[hello_hello]

Interesting.... the ffms2 MeGUI just downloaded for me (v2.22) appears in Process Explorer when threads=2. I repeated the previous encodes with threads=2. I don't really know what I should be looking for with Process Explorer anyway, so here's another list of encoding speeds.

QTGMC 3.33s (new version) - 3.93fps.
QTGMC 3.33s with Preset="slow" - 3.33fps
QTGMC 3.33s with MP_Pipeline - 4.82fps

QTGMC 3.33d (original version) - around 1fps (I didn't bother running the whole encode)
QTGMC 3.33d with Preset="slow" - around 1fps (I didn't bother running the whole encode)
QTGMC 3.33d with MP_Pipeline - 5.01fps

Speed for each encode was marginally faster than last time, probably thanks to the additional ffms2 thread, but the new mod version of QTGMC 3.33s still seems fine with my sample while 3.33d still encodes at a snails pace without MP_Pipeline. In other words, changing ffms2 versions didn't make any difference.

Edit: I just realised I was probably in dumb mode earlier and the reason the old ffms2 wasn't appearing in Process Explorer where I thought it should (when threads=2) was because I'd added MP_Pipeline to the script for testing before changing the thread count.

[real.finder]

MeGUI only uses avs4x264mod when the 64 bit version of x264 is being used, but in my case I can't because I'm still running 32 bit XP (just for one more week, hopefully).

I checked the command line and there's definitely no avs4x264mod involved.

[Information] [23/10/15 6:21:24 PM] Job command line: "C:\Program Files\MeGUI\tools\x264\x264.exe" --level 4.1 --preset slow --tune film --crf 18.0 --keyint 240 --vbv-bufsize 50000 --vbv-maxrate 50000 --stitchable --colormatrix bt470bg --sar 1:1 --output "D:\test.mkv.mkv" "D:\test.mkv.avs"

I didn't face your problem before

I still use https://www.dropbox.com/s/xhqggxamegia420/avisynth_20130309.7z because 2013.09.28 was do some crashes for me and didn't try newer one in actual encoding until now

and use MP_Pipeline most of the time

[hello_hello]

Thanks. I'll keep that version too, just in case, but at the moment the 3.33s you reverted for me seems to be behaving itself.

I'm not sure I can recall a time QTGMC caused a crash for me. Not since I gave up on MT Avisynth. Single threaded QTGMC has been rock solid, except for the "running at half speed" problem.
Of the DVD encodes I ran a couple of days ago with 3.33s (not the reverted version) a significant number started encoding at half speed and stayed that way, but they all ran at normal speed after I aborted them and re-started. For some I used Trim() to resume encoding where the previous encode stopped, but for some I simply aborted and restarted as they hadn't been running long. They still ran at normal speed the second time around though. It's odd....

The sample I attached to the post at VideoHelp always runs slow when using 3.33d. Why it's consistently slow when generally that's not the case, I don't know. Thinking about it though, the sample was from a group of files (TV show episodes) I was re-encoding at the time and most of them encoded at half speed unless I used Trim(). In the end I gave up and split every encode into two sections. A script to re-encode the first minute or so, then a second to re-encode the rest.

[creaothceann]

I don't really know what I should be looking for with Process Explorer anyway

I always activate these: http://i.imgur.com/tu3dxRh.png

Look at "CPU", "Threads", memory, "GPU", I/O and in the statusbar "Physical Usage (of RAM)".

[StainlessS]

I have no idea if this can help at all, BUT ...

Here a plug CacheTest (for want of a better name), not much tested, only started on it an hour or so ago.

CacheTest.cpp

#include <windows.h>
#include <stdio.h>
#include "avisynth.h"

class CacheTest : public GenericVideoFilter {
const char *Text;
const bool Always;
//
int Last;
int Instance;
char printString[2048];
void dprintf(char* fmt, ...);
static int InstCnt;
public:
PVideoFrame __stdcall GetFrame(int n, IScriptEnvironment *env);
CacheTest(PClip _child, const char* _text,bool _always,IScriptEnvironment *env);
~CacheTest(){};
};

int CacheTest::InstCnt = 0;

CacheTest::CacheTest(PClip _child, const char* _text,bool _always, IScriptEnvironment *env) :
GenericVideoFilter(_child),Text(_text),Always(_always),Last(-1) {
Instance = ++InstCnt;
}

PVideoFrame __stdcall CacheTest::GetFrame(int n, IScriptEnvironment *env) {
n = (n<0) ? 0 : (n >= vi.num_frames) ? vi.num_frames-1 : n;
if(n == Last) dprintf("%d] *** REPEATED REQUEST ***",n);
else if(n != Last+1) dprintf("%d] *** OUT OF ORDER REQUEST *** Previous frame requested was %d",n,Last);
else if(Always) dprintf("%d]",n);
Last = n;
PVideoFrame src = child->GetFrame(n, env);
return src;
}

void CacheTest::dprintf(char* fmt, ...) {
char *p=printString;
if(*Text=='\0') sprintf(p,"CacheTest_%04d: ",Instance);
else sprintf(p,"CacheTest_%04d_%s: ",Instance,Text);
while(*p++);
--p; // @ nul term
va_list argp;
va_start(argp, fmt);
vsprintf(p, fmt, argp);
va_end(argp);
while(*p++);
--p; // @ nul term
if(printString == p || p[-1] != '\n') {
p[0]='\n'; // append n/l if not there already
p[1]='\0';
}
OutputDebugString(printString);
}

AVSValue __cdecl Create_CacheTest(AVSValue args, void* user_data, IScriptEnvironment* env) {
return new CacheTest(args[0].AsClip(),args[1].AsString(""),args[2].AsBool(false),env);
}

extern "C" __declspec(dllexport) const char* __stdcall AvisynthPluginInit2(IScriptEnvironment* env) {
env->AddFunction("CacheTest", "c[text]s[Always]b",Create_CacheTest, 0);
return "`CacheTest' CacheTest plugin";
}


CacheRequestTwice.avs

# CacheRequestTwice.avs
#
# CacheTest(clip c, text="",Always=False)
# Sends text message to DebugView when frame requested is not previous frame + 1.
# Text allows add some kind of text label, Always==true = always output to debugview at each frame.
# Returns original frame, un-alterered.


TWICE = True
#TWICE = False

ALWAYS= False
TXT_A = "Porridge"
TXT_B = "Ham&Eggs"

AVISource("E:\V\StarWars.avi")
ORG=Last

A=((TWICE) ? Last.Invert : Last).CacheTest(Text=TXT_A,Always=ALWAYS)
B=((TWICE) ? Last.Invert : Last).CacheTest(Text=TXT_B,Always=ALWAYS)

D=Subtract(A,B)
# Return D # On about 7300 frames does not request any frame twice
L=Stackvertical(ORG,D)
# Return L # On about 7300 frames does not request any frame twice
R=StackVertical(A,B)
# Return R # On about 7300 frames does not request any frame twice (D and L play no part in output clip)
StackHorizontal(L,R) # Request frame twice every 30 frames (when TWICE=True)
return Last # Trim(2,0) here makes little difference


Output of script

00000002 2.03807402 [2496] CacheTest_0001_Porridge: 0] *** REPEATED REQUEST *** ???
00000003 2.07498646 [2496] CacheTest_0001_Porridge: 1] *** REPEATED REQUEST *** ???
00000004 3.19154382 [2496] CacheTest_0001_Porridge: 29] *** REPEATED REQUEST ***
00000005 4.38426638 [2496] CacheTest_0001_Porridge: 59] *** REPEATED REQUEST ***
00000006 5.58689880 [2496] CacheTest_0001_Porridge: 89] *** REPEATED REQUEST ***
00000007 6.78673887 [2496] CacheTest_0001_Porridge: 119] *** REPEATED REQUEST ***
00000008 7.98776102 [2496] CacheTest_0001_Porridge: 149] *** REPEATED REQUEST ***
00000009 9.18688488 [2496] CacheTest_0001_Porridge: 179] *** REPEATED REQUEST ***
00000010 10.38794994 [2496] CacheTest_0001_Porridge: 209] *** REPEATED REQUEST ***
00000011 11.58447838 [2496] CacheTest_0001_Porridge: 239] *** REPEATED REQUEST ***
00000012 12.78538609 [2496] CacheTest_0001_Porridge: 269] *** REPEATED REQUEST ***
00000013 13.98657513 [2496] CacheTest_0001_Porridge: 299] *** REPEATED REQUEST ***
00000014 15.18677521 [2496] CacheTest_0001_Porridge: 329] *** REPEATED REQUEST ***
00000015 16.38424683 [2496] CacheTest_0001_Porridge: 359] *** REPEATED REQUEST ***
00000016 17.58536720 [2496] CacheTest_0001_Porridge: 389] *** REPEATED REQUEST ***
00000017 18.78520393 [2496] CacheTest_0001_Porridge: 419] *** REPEATED REQUEST ***
00000018 19.98438835 [2496] CacheTest_0001_Porridge: 449] *** REPEATED REQUEST ***
00000019 21.18526459 [2496] CacheTest_0001_Porridge: 479] *** REPEATED REQUEST ***
00000020 22.38645744 [2496] CacheTest_0001_Porridge: 509] *** REPEATED REQUEST ***
00000021 23.58498955 [2496] CacheTest_0001_Porridge: 539] *** REPEATED REQUEST ***
00000022 24.78506088 [2496] CacheTest_0001_Porridge: 569] *** REPEATED REQUEST ***
00000023 25.98512840 [2496] CacheTest_0001_Porridge: 599] *** REPEATED REQUEST ***
00000024 27.18493271 [2496] CacheTest_0001_Porridge: 629] *** REPEATED REQUEST ***
00000025 28.38457108 [2496] CacheTest_0001_Porridge: 659] *** REPEATED REQUEST ***
00000026 29.58569908 [2496] CacheTest_0001_Porridge: 689] *** REPEATED REQUEST ***
00000027 30.78671837 [2496] CacheTest_0001_Porridge: 719] *** REPEATED REQUEST ***
00000028 31.98684120 [2496] CacheTest_0001_Porridge: 749] *** REPEATED REQUEST ***
00000029 33.18586731 [2496] CacheTest_0001_Porridge: 779] *** REPEATED REQUEST ***
00000030 34.38511658 [2496] CacheTest_0001_Porridge: 809] *** REPEATED REQUEST ***
00000031 35.58439636 [2496] CacheTest_0001_Porridge: 839] *** REPEATED REQUEST ***
00000032 36.78484726 [2496] CacheTest_0001_Porridge: 869] *** REPEATED REQUEST ***
00000033 37.98514175 [2496] CacheTest_0001_Porridge: 899] *** REPEATED REQUEST ***
00000034 39.18694305 [2496] CacheTest_0001_Porridge: 929] *** REPEATED REQUEST ***
00000035 40.38560486 [2496] CacheTest_0001_Porridge: 959] *** REPEATED REQUEST ***
00000036 41.58621597 [2496] CacheTest_0001_Porridge: 989] *** REPEATED REQUEST ***


You problem still tastes a little like this cache thing to me:- http://forum.doom9.org/showthread.php?p=1682827#post1682827

Anyways, here temp link (27KB dll + CacheTest.cpp only):- LINK REMOVED, See Here:- https://forum.doom9.org/showthread.php?t=184920

Hope I'm not sending you on a wild goose chase.

EDIT: The number after CacheTest_ is plugin instance number.

[hello_hello]

I have no idea if this can help at all, BUT ...

Here a plug CacheTest (for want of a better name), not much tested, only started on it an hour or so ago.

At the moment I'm running short on time, my brain's stubbornly refusing to engage for the day (I think I'm getting sick) and I'm using DebugView for the first time, so I did what I thought seemed correct..... added your CacheRequest script to my script, the cachetest.dll to the plugins folder, opened DebugView and ran the encode. Hopfully that's what I should be doing......

Is there a logical explanation as to why QTGMC 3.33d and 3.33s (reverted) run at different speeds without the CacheRequest stuff in the script, but when it's included they do?
They managed 2.8fps, which isn't as fast as without CacheRequest included, but I assume that's due to the increased resolution and it'd be "normal" speed. I ran those encodes twice to make sure I hadn't made a mistake, but they ran at the same speed again.

Am I doing it vaguely right? Here's the script I used:

LoadPlugin("C:\Program Files\MeGUI\tools\ffms\ffms2.dll")
FFVideoSource("E:\test.mkv", cachefile="D:\test.mkv.ffindex", fpsnum=24, fpsden=1, threads=1)

TWICE = True
#TWICE = False

ALWAYS= False
TXT_A = "Porridge"
TXT_B = "Ham&Eggs"

QTGMC(InputType=1, Preset="slow", EzDenoise=1)
crop(4, 2, -4, -2)
Spline36Resize(1280,720)
LSFMod(strength=75)
gradfun3()

ORG=Last
A=((TWICE) ? Last.Invert : Last).CacheTest(Text=TXT_A,Always=ALWAYS)
B=((TWICE) ? Last.Invert : Last).CacheTest(Text=TXT_B,Always=ALWAYS)

D=Subtract(A,B)
# Return D # On about 7300 frames does not request any frame twice
L=Stackvertical(ORG,D)
# Return L # On about 7300 frames does not request any frame twice
R=StackVertical(A,B)
# Return R # On about 7300 frames does not request any frame twice (D and L play no part in output clip)
StackHorizontal(L,R) # Request frame twice every 30 frames (when TWICE=True)
return Last # Trim(2,0) here makes little difference


And here's the DebugView log files. I don't understand why RemoveDirt and SSETools make an appearance, but I've got to spend some time in the real world at the moment.....

Thanks.

QTGMC 3.33s (revert)
00000001 0.00000000 [2416] RemoveDirt 0.9
00000002 0.01150656 [2416] SSETools 0.1
00000003 1.24683654 [2808] RemoveDirt 0.9
00000004 1.25846589 [2808] SSETools 0.1
00000005 3.63619494 [2808] CacheTest_0001_Porridge: 0] *** REPEATED REQUEST ***
00000006 4.03579569 [2808] CacheTest_0001_Porridge: 1] *** REPEATED REQUEST ***
00000007 12.31108665 [2808] CacheTest_0001_Porridge: 29] *** REPEATED REQUEST ***
00000008 28.28722191 [2808] CacheTest_0001_Porridge: 59] *** REPEATED REQUEST ***
00000009 52.34462738 [2808] CacheTest_0001_Porridge: 89] *** REPEATED REQUEST ***
00000010 71.32291412 [2808] CacheTest_0001_Porridge: 119] *** REPEATED REQUEST ***
00000011 80.03551483 [2808] CacheTest_0001_Porridge: 149] *** REPEATED REQUEST ***
00000012 88.79595947 [2808] CacheTest_0001_Porridge: 179] *** REPEATED REQUEST ***
00000013 97.56908417 [2808] CacheTest_0001_Porridge: 209] *** REPEATED REQUEST ***
00000014 106.45343781 [2808] CacheTest_0001_Porridge: 239] *** REPEATED REQUEST ***
00000015 115.41027069 [2808] CacheTest_0001_Porridge: 269] *** REPEATED REQUEST ***
00000016 124.43800354 [2808] CacheTest_0001_Porridge: 299] *** REPEATED REQUEST ***
00000017 133.76379395 [2808] CacheTest_0001_Porridge: 329] *** REPEATED REQUEST ***
00000018 143.15376282 [2808] CacheTest_0001_Porridge: 359] *** REPEATED REQUEST ***
00000019 152.19247437 [2808] CacheTest_0001_Porridge: 389] *** REPEATED REQUEST ***
00000020 161.25598145 [2808] CacheTest_0001_Porridge: 419] *** REPEATED REQUEST ***
00000021 170.26434326 [2808] CacheTest_0001_Porridge: 449] *** REPEATED REQUEST ***
00000022 179.31782532 [2808] CacheTest_0001_Porridge: 479] *** REPEATED REQUEST ***
00000023 188.51396179 [2808] CacheTest_0001_Porridge: 509] *** REPEATED REQUEST ***
00000024 197.82969666 [2808] CacheTest_0001_Porridge: 539] *** REPEATED REQUEST ***
00000025 207.34350586 [2808] CacheTest_0001_Porridge: 569] *** REPEATED REQUEST ***
00000026 217.89701843 [2808] CacheTest_0001_Porridge: 599] *** REPEATED REQUEST ***
00000027 227.41085815 [2808] CacheTest_0001_Porridge: 629] *** REPEATED REQUEST ***
00000028 236.44493103 [2808] CacheTest_0001_Porridge: 659] *** REPEATED REQUEST ***
00000029 245.54722595 [2808] CacheTest_0001_Porridge: 689] *** REPEATED REQUEST ***
00000030 262.36642456 [2416] RemoveDirt 0.9
00000031 262.37792969 [2416] SSETools 0.1


QTGMC 3.33d
00000001 0.00000000 [2416] RemoveDirt 0.9
00000002 0.01142434 [2416] SSETools 0.1
00000003 7.82843876 [2416] RemoveDirt 0.9
00000004 7.84005737 [2416] SSETools 0.1
00000005 9.08288383 [2344] RemoveDirt 0.9
00000006 9.09452724 [2344] SSETools 0.1
00000007 11.57814884 [2344] CacheTest_0001_Porridge: 0] *** REPEATED REQUEST ***
00000008 12.07485294 [2344] CacheTest_0001_Porridge: 1] *** REPEATED REQUEST ***
00000009 24.30343246 [2344] CacheTest_0001_Porridge: 29] *** REPEATED REQUEST ***
00000010 36.43482590 [2344] CacheTest_0001_Porridge: 59] *** REPEATED REQUEST ***
00000011 46.81768036 [2344] CacheTest_0001_Porridge: 89] *** REPEATED REQUEST ***
00000012 56.76725769 [2344] CacheTest_0001_Porridge: 119] *** REPEATED REQUEST ***
00000013 66.44585419 [2344] CacheTest_0001_Porridge: 149] *** REPEATED REQUEST ***
00000014 76.06328583 [2344] CacheTest_0001_Porridge: 179] *** REPEATED REQUEST ***
00000015 85.59259796 [2344] CacheTest_0001_Porridge: 209] *** REPEATED REQUEST ***
00000016 95.26169586 [2344] CacheTest_0001_Porridge: 239] *** REPEATED REQUEST ***
00000017 105.05858612 [2344] CacheTest_0001_Porridge: 269] *** REPEATED REQUEST ***
00000018 114.89687347 [2344] CacheTest_0001_Porridge: 299] *** REPEATED REQUEST ***
00000019 124.96822357 [2344] CacheTest_0001_Porridge: 329] *** REPEATED REQUEST ***
00000020 134.88223267 [2344] CacheTest_0001_Porridge: 359] *** REPEATED REQUEST ***
00000021 144.54713440 [2344] CacheTest_0001_Porridge: 389] *** REPEATED REQUEST ***
00000022 154.18771362 [2344] CacheTest_0001_Porridge: 419] *** REPEATED REQUEST ***
00000023 163.82351685 [2344] CacheTest_0001_Porridge: 449] *** REPEATED REQUEST ***
00000024 173.55781555 [2344] CacheTest_0001_Porridge: 479] *** REPEATED REQUEST ***
00000025 183.33503723 [2344] CacheTest_0001_Porridge: 509] *** REPEATED REQUEST ***
00000026 193.13240051 [2344] CacheTest_0001_Porridge: 539] *** REPEATED REQUEST ***
00000027 203.16264343 [2344] CacheTest_0001_Porridge: 569] *** REPEATED REQUEST ***
00000028 213.75897217 [2344] CacheTest_0001_Porridge: 599] *** REPEATED REQUEST ***
00000029 223.78259277 [2344] CacheTest_0001_Porridge: 629] *** REPEATED REQUEST ***
00000030 233.47032166 [2344] CacheTest_0001_Porridge: 659] *** REPEATED REQUEST ***
00000031 243.13763428 [2344] CacheTest_0001_Porridge: 689] *** REPEATED REQUEST ***
00000032 260.11117554 [2416] RemoveDirt 0.9
00000033 260.12280273 [2416] SSETools 0.1

[StainlessS]

Sorry, I should have explained a little better.

The script given was just a demo, shows that with that particular script that every 30 frames the cache 'dont work'.
(dont ask me why it dont work, 'its a mysterwy' [as Toyah Wilcox used to pronounce it]).
Dont use given script, use your own labels if required eg 'Node_A1", or whatever (Porridge etc was just demo hehe :) ).

Intention is that an instance of plug be inserted between some number of clips (between filters) to see what is happening.
If you eg inserted an instance of the plug between ALL filters then if cache failure is responsible at a particular location,
then you should be able to find it and might be able to play around with the script and try to make it go away.
You might have to be somewhat determined to track it down. Anyway, the idea occurred to me that it might be handy to have
a plug that does this, and so I did it and hoped that it might be of use, if not then I'm sure that I might one day have use of it
(or a modification thereof to pin point other anomalous behaviour).

By the way, the plug should have little effect on speed (provided it dont find gazillions of out of order frame requests
which might suggest that a plug or script aint playing nice).

EDIT: This GetFrame func, does not take much time unless it has to print to DebugView window (fast anyway),
The actual request for a frame just passes a pointer to a cached frame.

PVideoFrame __stdcall CacheTest::GetFrame(int n, IScriptEnvironment *env) {
n = (n<0) ? 0 : (n >= vi.num_frames) ? vi.num_frames-1 : n; // range limit frame n to legal values
if(n == Last) dprintf("%d] *** REPEATED REQUEST ***",n);
else if(n != Last+1) dprintf("%d] *** OUT OF ORDER REQUEST *** Previous frame requested was %d",n,Last);
else if(Always) dprintf("%d]",n);
Last = n; // remember last frame for next time around
PVideoFrame src = child->GetFrame(n, env); // get pointer to current frame and pass on to next filter. (almost no time)
return src;
}


EDIT: I guess I should say that I assumed best place to scatter some instances would be inside QTGMC(),
perhaps best done by script author.

that every 30 frames the cache 'dont work'.
See the frame numbers in DebugView log as in "Porridge: 29] *** ".

EDIT: Its 03:00 AM right now and I've gotta get some shut eye. I'll take a look at the scripts tomorrow and see if I can
find some good places to insert a few instances of the cache plug thing. I will be unlikely to be able to test,
I'm on lowly duel core Core Duo 2.4Ghz XP32 and dont usually have the patience to deal with QTGMC.

[hello_hello]

Thanks. I'll await your suggestion before I do any more testing.

Mind you I'm starting to think I'm losing my mind. I ran the encode on my test sample again using QTGMC 3.33d today it ran at normal speed. I tested it twice. Then I reverted back to the previous ffms2, tested it again and it still ran at normal speed. Suddenly my 100% repeatable problem can't be repeated.

Okay.... the penny dropped..... I couldn't think of a single thing that'd changed in the last few days. Same programs running, I hadn't rebooted.....
Then I realised, the one change I did make was to put CacheTest.dll in the Avisynth plugins folder, so I deleted it and tested again. Encoding speed dropped from 3.27fps to 1.28fps. There's nothing CacheTest related in the script (it's the original script I've been using for testing), but with CacheTest.dll in the plugins folder QTGMC 3.33d runs at normal speed. Without CacheTest.dll there it runs at half speed. I've heard fact is often stranger than fiction, but that's a true story. I've tested it twice.

[StainlessS]

Can you empty out your plugins folder with exception of plugs in-use, and for luck do a reboot.
I know all you out there believe that you can run a machine without reboot forever and it always gonna be hunky dory,
but, I dont have as much faith in MS as you-all do.

The CacheTest thing (inserted between two filters) will insert an extra instance of an avisynth cache, so when it says
"repeated request", it means repeated request on the cache nearer to output than the CacheTest thing, there is still a
cache on the nearer to input side, so that could actually help things where repeat requests are flagged.
If you added two instances of CacheTest between two filters and only one of them issues messages, then the first instance
extra cache is beneficial and the additional cache provided by second instance Cachetest is not of use.
I think I'll add a "Silent" arg to the Cachetest thing which will allow switching off the messages, so you can just leave in-situ
to keep permanent extra cache without messages.

I've only just woken up, I must have slept for at least 18 hours, I knew I was a bit knackered, but more so than I had thought.
Gonna have something to eat and a coffee, I'll make mod to CacheTest and up soon.

[Groucho2004]

Can you empty out you plugins folder with exception of plugs in-use
I asked him/her to run the AVS Info tool and post the logs (http://forum.doom9.org/showthread.php?p=1744020#post1744020) to see if there's anything fishy in the plugin directory but he/she didn't seem to think it would be useful.

[StainlessS]

He/she/it, should do as Groucho suggests. :)

Here update to CacheTest() with added Bool Silent arg (default false).


#include <windows.h>
#include <stdio.h>
#include "avisynth.h" // Avisynth VERSION 3 HEADER (Avisynth v2.58, OK for v2.6 too)

class CacheTest : public GenericVideoFilter {
// args
const char *Text;
const bool Always;
const bool Silent;
// vars
int PrevFrm;
int Instance;
char printString[2048];
static int InstCnt; // Single unique variable, common to all instances of the plugin.
// private member funcs
void dprintf(char* fmt, ...);
public:
PVideoFrame __stdcall GetFrame(int n, IScriptEnvironment *env);
CacheTest(PClip _child, const char* _text,bool _always,bool _silent,IScriptEnvironment *env);
~CacheTest(){};
};

int CacheTest::InstCnt = 0; // Initialise single instance variable on dll load.

CacheTest::CacheTest(PClip _child, const char* _text,bool _always,bool _silent, IScriptEnvironment *env) :
GenericVideoFilter(_child),Text(_text),Always(_always),Silent(_silent),PrevFrm(-1) {
Instance = ++InstCnt; // Instance identifier number of this instance of the plugin.
}

PVideoFrame __stdcall CacheTest::GetFrame(int n, IScriptEnvironment *env) {
n = (n<0) ? 0 : (n >= vi.num_frames) ? vi.num_frames-1 : n; // Range limit frame number n
if(!Silent) { // Messages permitted ?
if(n == PrevFrm) dprintf("%4d] *** REPEAT REQUEST",n);
else if(n != PrevFrm+1) dprintf("%4d] *** OUT OF ORDER REQUEST, Previous [%d]",n,PrevFrm);
else if(Always) dprintf("%4d]",n);
PrevFrm = n; // Remember frame requested for next iteration.
}
PVideoFrame src = child->GetFrame(n, env); // Get pointer to cached frame (un-altered frame)
return src; // Pass pointer to next filter in chain.
}

void CacheTest::dprintf(char* fmt, ...) {
char *p=printString; // address of buffer in class
if(*Text=='\0') sprintf(p,"CacheTest_%04d: ",Instance); // Prepend desired identifier string
else sprintf(p,"CacheTest_%04d_%s: ",Instance,Text); //
while(*p++); // Find end of identifier string, End @ nul + 1
--p; // @ nul term (back up 1 to point at nul)
va_list argp;
va_start(argp, fmt);
vsprintf(p, fmt, argp); // Add the message to the prepended identifier string
va_end(argp);
while(*p++); // Find end of message string, End @ nul + 1
--p; // @ nul term (back up 1 to point at nul)
if(printString == p || p[-1] != '\n') {
p[0]='\n'; // append n/l if not there already
p[1]='\0';
}
OutputDebugString(printString); // Write to DebugView window (google)
}

AVSValue __cdecl Create_CacheTest(AVSValue args, void* user_data, IScriptEnvironment* env) {
return new CacheTest(args[0].AsClip(),args[1].AsString(""),args[2].AsBool(false),args[3].AsBool(false),env);
}

extern "C" __declspec(dllexport) const char* __stdcall AvisynthPluginInit2(IScriptEnvironment* env) {
env->AddFunction("CacheTest", "c[text]s[Always]b[Silent]b",Create_CacheTest, 0);
return "`CacheTest' CacheTest plugin";
}


and DEMO test script CacheRequestTwice.avs

### CacheRequestTwice.avs
#
# CacheTest(clip c,String "text"="",Bool "Always"=False,Bool "Silent"=False)
#
# Sends text message to DebugView when frame requested is not previous frame + 1.
# Text allows add some kind of text label, Always==true = always output to debugview at each frame.
# Silent==True switches off ALL messages (overrides ALWAYS).
# Returns original frame, un-alterered.
# Insert between filters to see if there are any repeat requests for frame, or out of order frame requests.
# With Silent==True, Leaves an additional Cache between filters, without writing messages to DebugView.
#
# Shows messages as in "CacheTest_0005_Node_A1: 1001] *** REPEAT REQUEST" for plugin instance 5 where text = "Node_A1" and
# there is a repeat request for frame 1001.
###

TWICE = True # Causes repeat requests for some reason ("it's a mysterwy")
#TWICE = False # No repeat requests

TXT_A = "Porridge"
TXT_B = "Ham&Eggs"
ALWAYS= False
SILENT=False

AVISource("E:\V\StarWars.avi")
ORG=Last

A=((TWICE) ? Last.Invert : Last).CacheTest(Text=TXT_A,Always=ALWAYS,Silent=SILENT)
B=((TWICE) ? Last.Invert : Last).CacheTest(Text=TXT_B,Always=ALWAYS,Silent=SILENT)

D=Subtract(A,B)
# Return D # On about 7300 frames does not request any frame twice
L=Stackvertical(ORG,D)
# Return L # On about 7300 frames does not request any frame twice
R=StackVertical(A,B)
# Return R # On about 7300 frames does not request any frame twice (D and L play no part in output clip)
StackHorizontal(L,R) # Request frame twice every 30 frames (when TWICE=True)
return Last


Temp link here (28kb):- LINK REMOVED see here:- https://forum.doom9.org/showthread.php?t=184920


CacheTest.cpp + dll + CacheRequestTwice.avs ONLY.
Need Avisynth.h VERSION 3 (for v2.58), compile with any compiler.

EDIT: Note, you can add a filter to DebugView to only show messages with eg ":" in them (CacheTest puts a ':' in every message).
Also note, any process can send stuff to DebugView, not just CacheTest, the filter helps reduce number of messages to inspect.

EDIT: NOTE, from original issue posted here:- http://forum.doom9.org/showthread.php?p=1682827#post1682827
Affects:- Avisynth v2.6Alpha4, Avisynth v2.6Alpha5, Avisynth v2.6+r1576
Not Affected:- Avisynth v2.57, Avisynth v2.58, Avisynth v2.6Alpha3
I assume that it is also valid for the above DEMO script, but not gonna test it all out again.

[kuchikirukia]

I asked him/her to run the AVS Info tool and post the logs (http://forum.doom9.org/showthread.php?p=1744020#post1744020) to see if there's anything fishy in the plugin directory but he/she didn't seem to think it would be useful.

I don't even have an auto-load directory and not only have I been repeating his findings, I noticed them first.

This is repeatable. Why would you try to troubleshoot it on his machine when you can watch it in action on yours?

Anyway, just checked masktools2 vs mt_masktools-26. Same on both.
rgtools vs repairsse2 and removegrainsse2 in the qtgmc plugins pack. Same on both. (Not a comprehensive test of speeds and with all the qtgmc versions, just ran a preset=slower run and noticed both still caused ffms2 to act up past 25%.)
Considering it does this with inputtype=1 and deinterlacing, and I don't see in process explorer that nnedi3 is being called in inputtype=1, that shouldn't have anything to do with it.

[real.finder]

after seeing the replies, I think it cache bug as StainlessS said

[Groucho2004]

I don't even have an auto-load directory and not only have I been repeating his findings, I noticed them first.

This is repeatable. Why would you try to troubleshoot it on his machine when you can watch it in action on yours?
Mainly because of these findings which seem odd:
Then I realised, the one change I did make was to put CacheTest.dll in the Avisynth plugins folder, so I deleted it and tested again. Encoding speed dropped from 3.27fps to 1.28fps. There's nothing CacheTest related in the script (it's the original script I've been using for testing), but with CacheTest.dll in the plugins folder QTGMC 3.33d runs at normal speed. Without CacheTest.dll there it runs at half speed. I've heard fact is often stranger than fiction, but that's a true story. I've tested it twice.
Avisynth, particularly in combination with several plugins, is a highly complex and rather buggy system that can produce different results on different hardware/OS.

Stainless' suggestion to start with a clean slate in the plugin directory makes sense and removes some of the complexity.

[hello_hello]

I've been sick which is why I haven't posted for a bit.

When I first noticed the problem I tried testing a few different versions of QTGMC with various flavours of the plugins it uses, and the only thing that fixed the problem (aside from Trim(50,0) and MP_Pipeline), was using a version of QTGMC prior to 3.33d. I also tried emptying out the plugins folder (aside from those required) but that didn't help. I tried the "starting with a clean slate" test weeks ago.

I tested again today using a second PC after emptying the auto-loading plugins folder of everything but the plugins listed below. The PC in question had a hard drive die a little while ago and I restored an XP image with no software. All I've installed on it since is MeGUI, Avisynth and the various runtimes required for plugins. Adding CacheTest.dll to the Avisynth plugins folder didn't cause QTGMC 3.33d to encode at normal speed (which was disappointing in a way).

LoadPlugin("C:\Program Files\MeGUI\tools\ffms\ffms2.dll")
FFVideoSource("E:\test.mkv", cachefile="E:\test.mkv.ffindex", fpsnum=24, fpsden=1, threads=1)
QTGMC(InputType=1, Preset="medium", EzDenoise=1)
crop(4, 2, -4, -2)
Spline36Resize(1280,720)
LSFMod(strength=75)
gradfun3()

QTGMC 3.33d ran at 1.17fps
QTGMC 3.33e (reverted) ran at 3.09fps

dither.avsi
dither.dll
FFT3DFilter.dll
LSFmod.avsi
masktools2.dll
mt_xxpand_multi.avsi
mvtools2.dll
nnedi3.dll
QTGMC.avsi (3.33d or 3.33s reverted)
RgTools.dll

AvisynthPluginInfo
C:\Program Files\AviSynth\plugins\dither.dll
Timestamp: July 16, 2015, 19:46:00
MD5 Hash: FB53AB5DFB051297B353B90767C4D060
DLL Dependencies: KERNEL32.dll
Plugin version: AVS 2.5 Plugin
No VersionInfo available

C:\Program Files\AviSynth\plugins\FFT3DFilter.dll
Timestamp: February 20, 2007, 22:43:00
MD5 Hash: 2DDD22752BBAF5943A4B208AEFCD9E93
DLL Dependencies: USER32.dll, KERNEL32.dll
Plugin version: AVS 2.5 Plugin
FILEVERSION: 2.1.1.0
PRODUCTVERSION: 2.1.1.0
Language: Language Neutral
Comments: Frequency Domain filter. Uses external FFTW3.DLL library.
CompanyName: A.G.Balakhnin aka Fizick, bag@hotmail.ru, http://avisynth.org.ru
FileDescription: FFT3DFilter plugin for Avisynth 2.5
FileVersion: 2, 1, 1, 0
ProductVersion: 2, 1, 1, 0
InternalName: FFT3DFilter
LegalCopyright: Copyright © 2004-2006 A.G.Balakhnin
LegalTrademarks:
OriginalFilename: FFT3DFilter.dll
PrivateBuild:
ProductName: FFT3DFilter
SpecialBuild:

C:\Program Files\AviSynth\plugins\masktools2.dll
Timestamp: December 20, 2013, 20:02:00
MD5 Hash: 05370E2F53AA48DFCED0E54B0C0F458E
DLL Dependencies: KERNEL32.dll, MSVCP110.dll, MSVCR110.dll
Plugin version: AVS 2.6 Plugin
FILEVERSION: 2.1.0.0
PRODUCTVERSION: 2.1.0.0
Language: English (United States)
Comments:
CompanyName:
FileDescription: Masktools Dynamic Link Library
FileVersion: 2.1.0.0
ProductVersion: 2.1.0.0
InternalName: Masktools 2.0
LegalCopyright: Copyright (C) 2013
LegalTrademarks:
OriginalFilename: masktools2.dll
PrivateBuild:
ProductName: Masktools Dynamic Link Library
SpecialBuild:

C:\Program Files\AviSynth\plugins\mvtools2.dll
Timestamp: July 17, 2012, 21:37:00
MD5 Hash: 9AFD5E0AC0E329761DFCC6F98FF04566
DLL Dependencies: KERNEL32.dll
Plugin version: AVS 2.5 Plugin
FILEVERSION: 2.6.0.5
PRODUCTVERSION: 2.6.0.5
Language: Process Default Language
Comments: Motion estimation and compensation
CompanyName: A.G.Balakhnin aka Fizick, fizick@avisynth.org.ru
FileDescription: MVTools plugin for AviSynth
FileVersion: 2.6.0.5
ProductVersion: 2, 6, 0, 5
InternalName: mvtools
LegalCopyright: ©2004 Manao, ©2005 Fizick, ©2008 TSchniede under GNU GPL v2
LegalTrademarks:
OriginalFilename: mvtools.dll
PrivateBuild:
ProductName: mvtools
SpecialBuild:

C:\Program Files\AviSynth\plugins\nnedi3.dll
Timestamp: May 27, 2015, 04:17:14
MD5 Hash: 3B72B24C7DD548ED1FA9CC04B3221AA0
DLL Dependencies: KERNEL32.dll
Plugin version: AVS 2.6 Plugin
FILEVERSION: 0.9.4.10
PRODUCTVERSION: 0.9.4.10
Language: English (United States)
Comments:
CompanyName:
FileDescription: nnedi3 v0.9.4.10 for Avisynth 2.6.x
FileVersion: 0.9.4.10
ProductVersion: 0.9.4.10
InternalName:
LegalCopyright: Copyright (C) 2010-2011 Kevin Stone
LegalTrademarks:
OriginalFilename: nnedi3.dll
PrivateBuild:
ProductName:
SpecialBuild:

C:\Program Files\AviSynth\plugins\RgTools.dll
Timestamp: February 12, 2014, 21:18:00
MD5 Hash: 92BA2165C2DB0E3694B0213024F12C52
DLL Dependencies: MSVCR110.dll, KERNEL32.dll
Plugin version: AVS 2.6 Plugin
No VersionInfo available

Now I've got a setup where I know trying to find the problem doesn't fix the problem, therefore making it impossible to find (ie putting CacheTest.dll in the plugins folder doesn't change anything on it's own), I'll go through StainlessS's cachetest instructions and try some more testing, but it'll have to be later on today, or maybe tomorrow.

Cheers.

PS One thing I don't think I have tried is reverting back to Avisynth 2.5.8. I'm not sure if the above plugins are 2.5.8 compatible though.
I'm reasonably sure, when I first discovered the problem, I tested both Avisynth and Avisynth+ (probably Avisynth 2.6.0.5 or 2.6.0.6, but I'm not 100% sure about the Avisynth+ version) with the same result, which made me think it's most likely a plugin issue and not an Avisynth one. Maybe that was a bad assumption, and it's a problem Avisynth and Avisynth+ have in common?
Anyone got a setup where they can easily switch between Avisynth versions for testing? Maybe I need to start paying attention to the thread on that subject.

[kuchikirukia]

Versions prior to 3.33d aren't good, they're just not as broken. As I said, I found slowdowns in 3.32 and 3.33 while using preset=slower. They just don't drop to half.

[LouieChuckyMerry]

I hope your crud is clearing up, hello_hello :) . Maybe this would help your testing: Conveniently switching Avisynth versions (https://www.doom9.org/showthread.php?p=1720988#post1720988). I can barely use a single version of AviSynth, ha ha, but I thought it was a pretty cool concept and had it set up quite quickly so it must be foolproof ;) .

[hello_hello]

Versions prior to 3.33d aren't good, they're just not as broken. As I said, I found slowdowns in 3.32 and 3.33 while using preset=slower. They just don't drop to half.

Yeah.... I ran some DVD encodes today and was disappointed to discover that seems to be the case. I experienced slowdowns again. Well... I was using the reverted version of 3.33s so that's not the fix I hoped it'd be.

The first two DVD encodes I ran simultaneously encoded at an average of 7.21fps and 3.10fps, so one ran at full speed while the other ran at half speed.

I didn't realise real.finder had posted a link to an earlier Avisynth version a while back. I thought it was an earlier QTGMC and I hadn't got around to testing it yet. So I replaced avisynth.dll with that version (2.6.0.3) and tested the problem sample/script with QTGMC 3.33d. It encoded at normal speed. Actually, it encoded at 4.00fps, which is just a fraction faster than normal speed for Avisynth 2.6.0.6 using this PC. That seems quite promising.

I've switched to QTGMC 3.33s (not the reverted version) with Avisynth 2.6.0.3 and gone back to the DVD encodes I was running. When I aborted the last two, they were both sitting on a steady 2.10fps. I've restarted them both and the one I restarted from the middle (using Trim) has settled down to a steady 6.91fps. The second one restarted from scratch and it's dropping slowly but steadily. It's down to 3.85fps and falling. &^*%!!!!!!!!!!!

This is starting to do my head in. The DVD encodes I'm running look like this (with DGDecode).

AssumeTFF()
Trim(0,724).TFM().ChangeFPS(50,1)\
++Trim(725,34993).QTGMC(sharpness=0.7)\
++Trim(34994,0).TFM().ChangeFPS(50,1)
crop(20, 8, -18, -8)
Spline36Resize(640,480)
gradfun3()

I've tried QTGMC 3.32, 3.33, and 3.33d and the result is the same (with Avisynth 2.6.0.3). As soon as the encode hits frame 725 it slows down (naturally) but continues to gradually slow. I'm watching QTGMC 3.33 slow down to 3.76fps at frame 3000 and still falling (that'd be frame 1500 in the source video as the output has double the frame rate).
If I remove the first trim from the script and start encoding at frame 725, encoding speed settles down to a steady 7.90fps by the 3000th frame.

I guess getting lucky isn't going to happen. The fact Avisynth 2.6.0.3 and 2.6.0.6 produce different results with my problem sample seems to indicate it's an Avisynth issue, but QTGMC makes them both misbehave with other encodes.
I want to go back to finishing my current encoding jobs, then I guess I'll look at experimenting with cachetest.

[hello_hello]

Maybe this would help your testing: Conveniently switching Avisynth versions (https://www.doom9.org/showthread.php?p=1720988#post1720988). I can barely use a single version of AviSynth, ha ha, but I thought it was a pretty cool concept and had it set up quite quickly so it must be foolproof ;) .

I'll definitely have a look. For the moment I'm going to finish these encodes by splitting the scripts to prevent any slowdowns (hopefully) then I'll try to find the motivation to start testing again.

Cheers.

[hello_hello]

I'm starting to think this problem's been around for quite a while. Back in July 2013 (that's the file dates of the scripts) I encoded some DVDs while de-interlacing with QTGMC. I also used a whole bunch of trims to do colour adjustments. I then used that script as the source for another script with a whole bunch of different trims for cropping and resizing. In the end I gave up because each and every time the encodes would start off fine but gradually slow to almost nothing. My way around it was to do the encoding in two steps using a lossless intermediate but it seemed like the kind of thing that should have worked fine. I was probably still using QTGMC 3.32 and Avisynth 2.5.8 back than. Maybe it's completely unrelated....

[real.finder]

I'm starting to think this problem's been around for quite a while. Back in July 2013 (that's the file dates of the scripts) I encoded some DVDs while de-interlacing with QTGMC. I also used a whole bunch of trims to do colour adjustments. I then used that script as the source for another script with a whole bunch of different trims for cropping and resizing. In the end I gave up because each and every time the encodes would start off fine but gradually slow to almost nothing. My way around it was to do the encoding in two steps using a lossless intermediate but it seemed like the kind of thing that should have worked fine. I was probably still using QTGMC 3.32 and Avisynth 2.5.8 back than. Maybe it's completely unrelated....

try 2012.03.31 and 2012.04.03 and 2012.05.16 from http://forum.doom9.org/showthread.php?t=148782

it should work with last avs 2.6 plugins and in the same time it should hasn't avs 2.6 cache issues

If it work or not then try a newer one (2012.08.28 and up) until face the one that has these issues and tell us the results

[hello_hello]

real.finder,

I'll give them a try but it's not an easy thing to test as it's not always possible to find a sample that reproduces the problem every time with different Aviynth versions.

The versions you linked to are MT Avisynth. I'm running in single threaded mode. I assume that doesn't matter?
If I make any interesting discoveries I'll report back, but it mightn't be overly quickly given QTGMC is slow which makes testing slow and tedious.

Cheers.

[real.finder]

real.finder,

I'll give them a try but it's not an easy thing to test as it's not always possible to find a sample that reproduces the problem every time with different Aviynth versions.

The versions you linked to are MT Avisynth. I'm running in single threaded mode. I assume that doesn't matter?
If I make any interesting discoveries I'll report back, but it mightn't be overly quickly given QTGMC is slow which makes testing slow and tedious.

Cheers.

if you didn't use (setmtmode) it will be like normal avs

you can test with official alpha 3 but you will need old avs 2.6 plugins (Avisynth VERSION 4 HEADER) and the one that must you have for this is http://manao4.free.fr/masktools-v2.0a48.zip (or from Modded Plugins Package by -Vit- in QTGMC thread) you will need it for mt (2012.03.31 and 2012.04.03 and 2012.05.16) too to avoid access violation errors

[hello_hello]

Yeah.... I've just been through an access violation error frenzy while trying those older versions. I've tried both mt_masktools-25.dll and mt_masktools-26.dll from the zip file you linked to but still all I'm getting are access violation errors. That's sapped my enthusiasm for testing pretty substantially at the moment. I was going to switch Avisynth versions between encoding jobs and try to test while I encode, but it looks like it's not going to be anywhere near that simple.

[real.finder]

Yeah.... I've just been through an access violation error frenzy while trying those older versions. I've tried both mt_masktools-25.dll and mt_masktools-26.dll from the zip file you linked to but still all I'm getting are access violation errors. That's sapped my enthusiasm for testing pretty substantially at the moment. I was going to switch Avisynth versions between encoding jobs and try to test while I encode, but it looks like it's not going to be anywhere near that simple.

use the 2.5 plugins (for all plugins that QTGMC need) except for masktools

[hello_hello]

I'm fairly sure I've had enough for a while. I can go back to testing at some stage soon but I need a break for now. The video I was trying to encode today gave me so much grief I finished up converting it to lossless AVIs in sections, appended the AVIs together and re-encoding that. If I tried to combine multiple scripts using Import (I was taking sections from two different sources) encoding speed slowed to a crawl.

I've run a few quick tests using the second PC and it's not looking promising. I used avisynth 2012.03.31 and the plugins from the original QTGMC plugins package, mvtools 2.6.0.5 (originally supplied as part of the dither package), the dither 1.24 plugin and QTGMC 3.33d (not reverted). I tried a script and DVD source that was giving me trouble earlier, and it seemed to behave itself when I ran an encode using MeGUI/x264 (although maybe not when I converted it to lossless AVI with VirtualDub, but I only tried that once).
The big let-down was my original test sample. Using an older version of Avisynth with older plugins seems a little slower anyway (hard to know for sure given I was using a different PC) but the first encode I ran with the test sample/script managed 1.17fps according to MeGUI's log file. When I put Trim(50,0) at the end and tried again, it averaged 3.09fps. Bummer.

[hello_hello]

One last try for the moment. Replaced avisynth.dll with version 2.5.8.5. Replaced mt_masktools-26.dll with mt_masktools-25.dll from the original QTGMC plugins package. Tested QTGMC 3.33d (not reverted).

Test sample/script without Trim - 1.17fps

Test sample/script with Trim(50,0) - 3.08fps

I don't mind coming back to this some time in the near future. I can play around with cachetest if there's a chance it might provide some sort of insight, but for now I've definitely had enough. At least it seems certain if it's an Avisynth problem it's not something new to version 2.6, and it appears unlikely to be a plugin given I've reverted to the original QTGMC plugins package. Could it be a problem with the QTGMC script itself?

[sneaker_ger]

I'm fairly sure I've had enough for a while. I can go back to testing at some stage soon but I need a break for now. The video I was trying to encode today gave me so much grief I finished up converting it to lossless AVIs in sections, appended the AVIs together and re-encoding that. If I tried to combine multiple scripts using Import (I was taking sections from two different sources) encoding speed slowed to a crawl.
Try VapourSynth's QTGMC if you need to do "productive" work and cannot wait for a fix.

[hello_hello]

I've pretty much finished what I wanted to get done for the moment, but I'll have to build a new PC and install a new OS for VapourSynth. I don't think it runs on XP. Mind you I was planning on doing exactly that this week but between getting sick and spending a lot more time messing around with encoding than I thought I would, it looks like it'll be next week now.

I haven't read your more recent cachetest instructions thoroughly yet, but do you still think it'd be worth trying? I don't mind experimenting a bit more in a few days... once I've had a break from it.

[StainlessS]

If same problems exhibited by Avisynth prior to v2.6Alpha3 (inclusive) then Cachetest (cache dont work every 30th frame) problem
is probably not helpful. (I'm guessing, think that is what you suggested as being true).

EDIT: I have however downloaded pretty much everything mentioned in this and associated threads, and will play a little with CacheTest dll.

[kuchikirukia]

Try VapourSynth's QTGMC if you need to do "productive" work and cannot wait for a fix.

Does VapourSynth have a usable installer and syntax yet?

<3 MeGUI. It's a god-tier program that makes it easy to get into Avisynth. There's no need to try to piece together an idea of Avisynth from scratch from a manual, you can just watch how MeGUI changes the script when you check various boxes or pick various settings from a dropdown. While the Avisynth language is powerful, by calling scripts it can be reduced to the simplicity of:
<input>
<filter>

VapourSynth's "Getting Started," is "Learn Python."
I think I'll use Avisynth and Trim.

[hello_hello]

I think I've been experiencing this problem on and off for quite a while. Probably for as long as I've been using QTGMC. I'm not sure whether it's happening more regularly now or if I'm just more aware of it.... probably a bit of both.... and maybe I'm more likely to use a script for encoding that'll cause a slowdown these days.

I'll have to ask Zathor how MeGUI determines the processing rate it displays because if nothing else, I've become aware it's not terribly accurate. The rate displayed appears to be an average taken over a considerable period of time. As a result if I encode the first section of a video without any processing (via Trim), it might run at 30 or 40 fps, then when encoding reaches the first frame processed by QTGMC it might drop to 7fps, but the rate displayed by MeGUI doesn't change quickly. It gradually decreases over minutes which makes it fairly useless for determining if the speed dropped to a "normal" level or if it tanked. It might also be a reason why I've not always noticed slowdowns in the past.
Unless encoding started off slower than it should to make it obvious, for the testing I've been doing recently I'd encode a specific amount of video each time and check MeGUI's log file for x264's reported encoding speed. There's probably a better way to do it.

[real.finder]

I think I've been experiencing this problem on and off for quite a while. Probably for as long as I've been using QTGMC. I'm not sure whether it's happening more regularly now or if I'm just more aware of it.... probably a bit of both.... and maybe I'm more likely to use a script for encoding that'll cause a slowdown these days.

I'll have to ask Zathor how MeGUI determines the processing rate it displays because if nothing else, I've become aware it's not terribly accurate. The rate displayed appears to be an average taken over a considerable period of time. As a result if I encode the first section of a video without any processing (via Trim), it might run at 30 or 40 fps, then when encoding reaches the first frame processed by QTGMC it might drop to 7fps, but the rate displayed by MeGUI doesn't change quickly. It gradually decreases over minutes which makes it fairly useless for determining if the speed dropped to a "normal" level or if it tanked. It might also be a reason why I've not always noticed slowdowns in the past.
Unless encoding started off slower than it should to make it obvious, for the testing I've been doing recently I'd encode a specific amount of video each time and check MeGUI's log file for x264's reported encoding speed. There's probably a better way to do it.

use http://forum.doom9.org/showthread.php?t=165528

this will show the real speed and give you a lot of options for testing

and I suggest using MP_Pipeline in the encoding, it will keep you away from a lot of problems, if you see it complex, then use it simply like this


MP_Pipeline("""
### platform: win32
your usual script
### ###
""")


that will keep avs processes away from x264 process and that will speed your encoding and keep you away from a lot of crashes or deadlock

[Groucho2004]

I think I've been experiencing this problem on and off for quite a while. Probably for as long as I've been using QTGMC. I'm not sure whether it's happening more regularly now or if I'm just more aware of it.... probably a bit of both.... and maybe I'm more likely to use a script for encoding that'll cause a slowdown these days.

I'll have to ask Zathor how MeGUI determines the processing rate it displays because if nothing else, I've become aware it's not terribly accurate. The rate displayed appears to be an average taken over a considerable period of time. As a result if I encode the first section of a video without any processing (via Trim), it might run at 30 or 40 fps, then when encoding reaches the first frame processed by QTGMC it might drop to 7fps, but the rate displayed by MeGUI doesn't change quickly. It gradually decreases over minutes which makes it fairly useless for determining if the speed dropped to a "normal" level or if it tanked. It might also be a reason why I've not always noticed slowdowns in the past.
Unless encoding started off slower than it should to make it obvious, for the testing I've been doing recently I'd encode a specific amount of video each time and check MeGUI's log file for x264's reported encoding speed. There's probably a better way to do it.
Agree with real.finder. You're making things unnecessarily difficult for yourself. By including the encoder and a Gui frontend in your testing scenario, the complexity increases significantly and results will be even more random. The problem clearly is with the frame-serving so you should test just that.
AVSMeter even allows you to export the performance data to a csv file for import in a spread sheet program so you can create pretty diagrams like here (http://forum.doom9.org/showthread.php?p=1736090#post1736090). :D

[hello_hello]

I suspect the encoding does sometimes change the result, but I'm not sure that means it should be excluded from all testing. Afterall, in the end we use Avisynth to encode. Anyway.....

I gave AVSMeter a quick spin on the problem sample/script and it confirmed what I already knew. I didn't bother running the encodes to the end. Without Trim at the end of the script vs Trim(50,0) at the end of the script.

http://s21.postimg.org/jxmml3y43/test1.jpg (http://postimg.org/image/jxmml3y43/)

http://s8.postimg.org/hplyhwbwh/test2.jpg (http://postimg.org/image/hplyhwbwh/)

PS. When I ran the above encodes it was using the second PC and I forgot to restore my current Avisynth plugins folder first, so the above encodes were run with Avisynth 2.6.0.6 and the original QTGMC plugins. I guess that's another combination tested.

I'm still not motivated to get back into much more testing yet but I might need to create pretty diagrams when I do. Unless there's a way to get AVSMeter to run a complete script but only meter part of it? Because when I tried the following script:

AssumeTFF()
Trim(0,719).ChangeFPS(50,1).crop(20, 8, -18, -8).Spline36Resize(640,480)\
++Trim(720,1784).QTGMC(sharpness=0.7).crop(20, 8, -18, -8).Spline36Resize(640,480)
gradfun3()

and then compared it to this:

AssumeTFF()
Trim(720,1784).QTGMC(sharpness=0.7).crop(20, 8, -18, -8).Spline36Resize(640,480)
gradfun3()

I could visually see frames 720 to 1784 were being processed about 1fps to 1.5fps faster the second time, but naturally the average/min/max frame rates don't reflect that. Mind you that's not a huge difference, although that's the script I'm sure has tanked at times after frame 720 while encoding. I'll have to experiment some more with that one. That's the problem.... aside from the original sample I posted the issue isn't 100% repeatable. I can abort an encode that's obviously running slow and when I restart it it runs at twice the speed from start to finish. It'll be interesting to see if when I test a script with AVSMeter multiple times it'll always run at the same speed.

[hello_hello]

and I suggest using MP_Pipeline in the encoding, it will keep you away from a lot of problems, if you see it complex, then use it simply like this


MP_Pipeline("""
### platform: win32
your usual script
### ###
""")


that will keep avs processes away from x264 process and that will speed your encoding and keep you away from a lot of crashes or deadlock

While MP_Pipeline has helped in the past I'm certain there's been a few occasions where it didn't (I had to use Trim instead), but isn't kuchikirukia using avs4x264mod and wouldn't that also be keeping avs processes away from x264, or is it not that easy?

[Groucho2004]

Afterall, in the end we use Avisynth to encode.:confused:

Unless there's a way to get AVSMeter to run a complete script but only meter part of it?
Run the whole script, export to CSV, import to LibreOffice (or MS Excel), select the rows with the frames you're interested in, create a graph.

[Groucho2004]

isn't kuchikirukia using avs4x264mod and wouldn't that also be keeping avs processes away from x264, or is it not that easy?
avs4x264mod or any other piping tool will indeed run x264 in a separate process.

[hello_hello]

:confused:

I was simply wondering if frame serving to an encoder such as x264, rather than running a script in AVSMeter, might sometimes produce a different result. If that's impossible and Avisynth will process the video at the same rate either way, then obviously there's no point encoding while testing, but I assume real.finder didn't suggest trying to keep the Avisynth and x264 processes separate if doing so can't make any difference.

Run the whole script, export to CSV, import to LibreOffice (or MS Excel), select the rows with the frames you're interested in, create a graph.

Maybe early next week when I'm motivated again, although I'm not sure if it'll achieve much. I've provided one sample for which the problem is 100% repeatable, and from there it'll require someone more clever than I am to work out what's wrong and how to fix it. I might be able to create a few more samples/scripts that are likely to cause slowdowns if it helps, but so far nothing else has been 100% consistently slow.

[Groucho2004]

I was simply wondering if frame serving to an encoder such as x264, rather than running a script in AVSMeter, might sometimes produce a different result.
The only difference I can think of is when the process memory consumption (Avisynth + x264) gets close to the limit of 2GB. The advantage of using AVSMeter is that it tells you how much memory is allocated by Avisynth alone. If that is already at ~1.5 GB, adding the encoder into the process can have the effects you are seeing. Sending the frames through stdout to x264 eliminates this particular problem.

[Groucho2004]

AssumeTFF()
Trim(0,719).ChangeFPS(50,1).crop(20, 8, -18, -8).Spline36Resize(640,480)\
++Trim(720,1784).QTGMC(sharpness=0.7).crop(20, 8, -18, -8).Spline36Resize(640,480)
gradfun3()

and then compared it to this:

AssumeTFF()
Trim(720,1784).QTGMC(sharpness=0.7).crop(20, 8, -18, -8).Spline36Resize(640,480)
gradfun3()

I could visually see frames 720 to 1784 were being processed about 1fps to 1.5fps faster the second time, but naturally the average/min/max frame rates don't reflect that.
AVSMeter records the timing for each frame (if the average FPS < 50) and the min/max values will definitely reflect that.

[real.finder]

I was simply wondering if frame serving to an encoder such as x264, rather than running a script in AVSMeter, might sometimes produce a different result. If that's impossible and Avisynth will process the video at the same rate either way, then obviously there's no point encoding while testing, but I assume real.finder didn't suggest trying to keep the Avisynth and x264 processes separate if doing so can't make any difference.



Maybe early next week when I'm motivated again, although I'm not sure if it'll achieve much. I've provided one sample for which the problem is 100% repeatable, and from there it'll require someone more clever than I am to work out what's wrong and how to fix it. I might be able to create a few more samples/scripts that are likely to cause slowdowns if it helps, but so far nothing else has been 100% consistently slow.

did you see this http://forum.doom9.org/showthread.php?p=1736090#post1736090 ?

Reel.Deel use QTGMC with these testes, and avs 2.6 slowdown from > 20 fps to < 20 fps

did you try avs+ ?

[hello_hello]

I'm fairly certain when I found the problem with the sample I've been using for testing in this thread, switching to Avisynth+ was one of the first things I tried. MeGUI was using Avisynth+ as it's own "portable" Avisynth at the time, but which version it was using..... I'm not sure. I could maybe hunt through old log files to see if I can work it out but I wouldn't trust that to be completely accurate anyway because I switch versions now and then anyway and there's log files on two PCs.

I'm not sure it's the same problem as Avisynth+ either. I'm reasonably sure there's no "slowdown" taking place. In my case I think encoding tends to progress at normal speed, then suddenly drop by half or more. I say "I think" because I've been watching the rate displayed by MeGUI but it's not accurate at any given moment. Encoding may progress along at 30fps and suddenly drop to 10fps (as an example), but the rate being displayed by MeGUI drops ever so slowly.... so it looks like there's a gradual slowdown when in fact there was a sudden change in speed..

I base much of that on the fact certain encodes obviously start off at a reduced speed and stay at the reduced speed until they're done, rather than start off much faster than they finish, but I don't know for certain there's no slowdowns taking place. The few tests I've run with AVSMeter seem to confirm it's a sudden speed change, but I've not performed extensive tests with it yet.

[kuchikirukia]

I don't know why you're using such vague metrics such as "feel" of whether an encode has slowed down. L-SMASH should not be creating and destroying threads. FFMS2 should not be running at ridiculous CPU util. These correspond to slowdowns.
If L-SMASH is going Christmas or FFMS2 is spiking CPU, Avisynth is choking.

It does this in QTGMC 3.32 and with Avisynth+, 2.6MT, and 2.6. Since none of the changes from 3.32 were made to address this, I don't know why you're flipping through scripts at random. Do you think someone accidentally fixed this?
Just use Trim until a programmer decides to chase this down. You don't need to fill this thread with meaningless garbage as to whether you "feel" an unstated script using unstated settings is "working." You don't have a baseline and you're not looking at anything that might give you a clue of what's going on.

[c8rag]

I had this problem too, so I registered this account.:p This problem is unlike the Avisynth+ slowdown.(https://github.com/AviSynth/AviSynthPlus/issues/63)

My setting is Avisynth official 2.6.0.6, QTGMC 3.33 Mod20151023, nnedi_0.9.4.20, others are recommended here (http://forum.doom9.org/showthread.php?p=1733741#post1733741).

I tried ICL10 built by Groucho2004, got same result; QTGMC 3.33 original , same result; with or without avstp.dll, same result.

nnedi_0.9.4 can fix this problem in my test , also the trim method is ok.

[c8rag]

with 0.9.4
http://s10.postimg.org/v6pcdv84n/image.png
with 0.9.4.20
http://s29.postimg.org/4x0ndjgt1/9420.png

[AzraelNewtype]

Lemme help you out there:

0.9.4
http://s10.postimg.org/fxzf03eg5/image.png (http://postimg.org/image/fxzf03eg5/)

0.9.4.20
http://s29.postimg.org/ormoznw0j/9420.jpg (http://postimg.org/image/ormoznw0j/)

Guess it didn't like the hotlinking.

[hello_hello]

I don't know why you're using such vague metrics such as "feel" of whether an encode has slowed down. L-SMASH should not be creating and destroying threads. FFMS2 should not be running at ridiculous CPU util. These correspond to slowdowns.
If L-SMASH is going Christmas or FFMS2 is spiking CPU, Avisynth is choking.

Read my post again. I was asked about Avisynth+ and I replied I'm fairly sure the problem isn't one involving gradual slowdowns as was the issue there, but I can't be certain that's always the case because the encoding rate displayed by MeGUI changes quite gradually even when the actual speed drops quite quickly.

It does this in QTGMC 3.32 and with Avisynth+, 2.6MT, and 2.6. Since none of the changes from 3.32 were made to address this, I don't know why you're flipping through scripts at random. Do you think someone accidentally fixed this?

I'm fairly sure I've also experienced slow encoding speeds on occasion with DGDecode. I wasn't flipping through scripts at random, I was testing earlier versions of Avisynth with the known problem sample/script each time while attempting to find another example of the problem that'd also be 100% repeatable.

You don't need to fill this thread with meaningless garbage as to whether you "feel" an unstated script using unstated settings is "working." You don't have a baseline and you're not looking at anything that might give you a clue of what's going on.

If anything, I've been asking how to more accurately test the speed of particular scripts so I don't need to guess what's going on, and I haven't used the word "feel" anywhere so I've no idea what you're on about.

[hello_hello]

I had this problem too, so I registered this account.:p This problem is unlike the Avisynth+ slowdown.(https://github.com/AviSynth/AviSynthPlus/issues/63)

nnedi_0.9.4 can fix this problem in my test , also the trim method is ok.

I'll confess given kuchikirukia has instructed me to cease testing I wasn't sure if I should to try a different version of nnedi3, but I gave it a spin. I had tested at least one earlier version in the past with no success, but I thought it couldn't hurt to try again.

I don't know how or why but when I initially switched to nnedi3 version 0.9.4 (I'd been using 0.9.4.10) my test sample/script behaved perfectly. It encoded at normal speed and there were no ffms2 CPU spikes. It's CPU usage stayed very low. I ran the test encode with the same result three times in succession. I got excited....

I switched to the second PC to try again but unfortunately this time 0.9.4 made no difference. In fact one of the plugin folders I'd created for testing last week included nnedi3 0.9.4, but I tested it again and encoding speed was still slow.

Most disappointing was returning to this PC to discover the problem had returned. I know it sounds a bit mental and it's enough to make a person question their grip on reality, but 0.9.4 fixed the problem, and then it didn't. :(

Anyway, if you registered and posted here specifically to suggest a fix, the effort is very much appreciated.

[AzraelNewtype]

If anything, I've been asking how to more accurately test the speed of particular scripts so I don't need to guess what's going on, and I haven't used the word "feel" anywhere so I've no idea what you're on about.

AVSMeter with the full logging is what you want. Especially the new fun csv output that lets you make nice graphs with minimal effort.

Also, it's very strange that someone advocating a solution that amounts to "this rock repels tigers" is all of a sudden very concerned enough about objective, rational thinking to complain to you about it more than once, but I digress.

[real.finder]

I did a test and...

ColorBars(width=720, height=480, pixel_type="RGB32")
ConvertToYV12()
QTGMC(InputType=1, Ezdenoise=2)
LSFMod(strength=66)
gradfun3()

http://i.imgur.com/mwsuZ4K.png

ColorBars(width=720, height=480, pixel_type="RGB32")
ConvertToYV12()
QTGMC(InputType=1, Ezdenoise=2)
LSFMod(strength=66)
gradfun3()
Trim(50,0)

http://i.imgur.com/BMnHIWR.png

wow!

[StainlessS]

Perhaps better use pixel_type="YV12" in colorbars rather than ConvertToYV12, take that effect out of numbers.

[real.finder]

Perhaps better use pixel_type="YV12" in colorbars rather than ConvertToYV12, take that effect out of numbers.

I did (and usually do) this because colorbars output is Rec. ITU-R BT.801-1 (http://avisynth.nl/index.php/ColorBars) for YUV

Nothing to do with this here, but I used to use it like this

[AzraelNewtype]

What version of nnedi3 are you using for qtgmc there? That's probably important too, given c8rag's testing. Also, because I sort of misread his tests I did a little thing of my own and just tested some nnedi3 versions alone, not in the script, and lo!

http://i.imgur.com/eTFA2wuh.png (http://i.imgur.com/eTFA2wu.png)

Same nearly vertical dip c8rag was seeing in the script. Also, for the record, this was tested on an AMD cpu, and I guess the icl10 used for that build wasn't patched to not disable a lot of optimizations on AMD cpus, hence it being utter garbage by comparison.

Might try the same clip (this is real footage, not colorbars) with qtgmc and a couple of the nnedi3s, but I have a feeling it's just going to be roughly the same lines, but lower on the y-axis.

[kuchikirukia]

Does inputtype=1 even call nnedi3? nnedi3 usually spawns additional threads which I don't see.

E: Nope, it doesn't complain when I don't load the dll.
Since it does this under inputtype=1 as well as deinterlacing, it seems to be unrelated to nnedi3.


Oh, and hello_hello, my apologies for the rant. I misread your post and thought you were saying something you weren't. I read, "I'm not sure it's the same problem as Avisynth+ either. I'm reasonably sure there's no "slowdown" taking place," as, "I'm not sure there's the same problem (as we've been talking about) using Avisynth+. I'm reasonably sure there's no slowdown taking place." I didn't catch that you were referencing the separate problem in Avisynth+ r1779+ and thought you were throwing out info that conflicted with what I had seen while testing with Avisynth+. After having sat there for hours watching process explorer through dozens of tests and seeing Avisynth+ crap out time and again, I wasn't too happy to see what looked like, "Avisynth+ is fine."

[real.finder]

What version of nnedi3 are you using for qtgmc there? That's probably important too

NNEDI3_v0_9_4_20 x86 Release_Intel_XP_Core2_SSE4.2

[Groucho2004]

Also, for the record, this was tested on an AMD cpu, and I guess the icl10 used for that build wasn't patched to not disable a lot of optimizations on AMD cpus, hence it being utter garbage by comparison.
I'm not using the automatic CPU dispatcher for my ICL builds so there is no disadvantage for AMD CPUs.
Without seeing the script or which ICL NNEDI3 DLL you used I obviously can't tell you why you're experiencing this poor performance.

[AzraelNewtype]

Does inputtype=1 even call nnedi3? nnedi3 usually spawns additional threads which I don't see.

E: Nope, it doesn't complain when I don't load the dll.
Since it does this under inputtype=1 as well as deinterlacing, it seems to be unrelated to nnedi3.


Oh, right it obviously wouldn't, I'm an idiot.

I'm not using the automatic CPU dispatcher for my ICL builds so there is no disadvantage for AMD CPUs.
Without seeing the script or which ICL NNEDI3 DLL you used I obviously can't tell you why you're experiencing this poor performance.

The script was literally just a trim and nnedi3(field=-2). As for the dll, it's hard to say. The date I have on it is 8/1/2013, though I'm not sure if that's the date it was built before putting it into a zip or the date I unzipped it. If there's any symbols inside that could help you narrow down anything about it, the exact dll is here (https://dl.dropboxusercontent.com/u/21987967/nnedi3.dll). The version number is just 0.9.4.0.

[Groucho2004]

As for the dll, it's hard to say. The date I have on it is 8/1/2013, though I'm not sure if that's the date it was built before putting it into a zip or the date I unzipped it. If there's any symbols inside that could help you narrow down anything about it, the exact dll is here (https://dl.dropboxusercontent.com/u/21987967/nnedi3.dll). The version number is just 0.9.4.0.
Try the one from here (https://www.sendspace.com/folder/10dsem) (nnedi3_0.9.4_fturnmod.7z). Don't forget to also put fturn.dll (https://github.com/tp7/fturn/releases) into the same directory.

[c8rag]

I had this problem too, so I registered this account.:p This problem is unlike the Avisynth+ slowdown.(https://github.com/AviSynth/AviSynthPlus/issues/63)

My setting is Avisynth official 2.6.0.6, QTGMC 3.33 Mod20151023, nnedi_0.9.4.20, others are recommended here (http://forum.doom9.org/showthread.php?p=1733741#post1733741).

I tried ICL10 built by Groucho2004, got same result; QTGMC 3.33 original , same result; with or without avstp.dll, same result.

nnedi_0.9.4 can fix this problem in my test , also the trim method is ok.

I drew a wrong conclusion. I think the main reason of my problem is the source filter:ffms, I used 2.22RC2 updated by megui. Other versions works fine with nnedi3 0.9.4 or 0.9.4.20. Thanks for all your help.:p

[StainlessS]

c8rag, MeGUI (EDIT: Development) update server now issues filter:ffms v2.22 rather than 2.22RC2, dont know if there is much if any difference.

[hello_hello]

Does inputtype=1 even call nnedi3? nnedi3 usually spawns additional threads which I don't see.

E: Nope, it doesn't complain when I don't load the dll.
Since it does this under inputtype=1 as well as deinterlacing, it seems to be unrelated to nnedi3.

Howdy. I've been busy in the real world so away from this for a bit.

Thinking about it, you're probably right there (I don't want to mess around myself right now as I've got an encode running at the moment and I'd prefer to let it finish first) but that means so far I've seen two "impossible" things happen. When I first replaced nnedi3 with an older version in the auto-loading plugin folder it temporarily fixed the problem. At one stage simply putting cachetest.dll in that folder also fixed the problem. I haven't tried that again using this PC but I tried it with the second PC and it made no difference, however for one PC changing or adding a plugin to the auto-loading folder certainly did seem to make a difference even though the plugin in question wasn't being used.
I know that sounds mental and it makes me wonder if I'm going mad, but the 100% repeatable problem stopped happening right after I changed or added those plugins, even if only temporarily, and while I know that's the sort of co-incidence only PCs can manage, it's still a particularly bizarre co-incidence if that's all it was.

Oh, and hello_hello, my apologies for the rant. I misread your post and thought you were saying something you weren't.

I know I'd been stumbling about with testing a little and trying to describe that thoroughly resulted in a few posts that didn't really amount to much, so I guess at the time I had a "I'm being told off for trying" moment, but it's all good. Cheers.

It's kind of hard for me as for ages I "suspected" there was a problem, and then I became sure of it even though I could never reproduce it, but this thread (with your help) is the first time I've reached the stage where I can at least be sure there is an Avisynth problem that, as I've also long suspected, doesn't have anything to do with how much RAM I have installed or support for XP having ended, but unfortunately I can't do much aside from maybe trying different versions of plugins or different plugin combinations in the hope maybe that's where the problem lies.

I drew a wrong conclusion. I think the main reason of my problem is the source filter:ffms, I used 2.22RC2 updated by megui. Other versions works fine with nnedi3 0.9.4 or 0.9.4.20. Thanks for all your help.:p

I'll be interested to learn if that fixes it for good, or if it's some sort of co-incidence, given for me I'm sure the problem can also occur when decoding with L-Smash and DGDecode.
I'm certain for me changing ffms2 versions has made no difference in the past. I'm also sure early on switching to L-Smaszh was one of the first things I tried. I went back to using ffms2 2.20 for quite a while after having a problem with 2.21 or 2.22RC and I'm quite sure I tested again after updating to 2.22 recently... with no change.

[real.finder]

after I edit MPP (http://forum.doom9.org/showpost.php?p=1746479&postcount=235) I did some testing in avs MT

and your script is ok but with some complex scripts I got crash in the beginning of encoding or deadlock later, and some times every thing running OK (with the same script of course)

and after that I did some searches and find this http://forum.doom9.org/showpost.php?p=1716446&postcount=979

I know you not using MT but that maybe has related to your problem, Especially that the change I did here (http://forum.doom9.org/showpost.php?p=1743994&postcount=13) is nothing but switch from masktools2 function to removegrain one in some lines

so, I think it's masktools2 issue

[hello_hello]

real.finder,
The modification you made to the QTGMC script stopped the problem from occurring with the sample I've been using for testing (the slow speed is pretty much 100% repeatable with QTGMC 3.33d) but the problem hasn't gone away entirely. I'm certain I've had encodes running at half speed using your modified QTGMC and sometimes after aborting the encode and starting again it'll run fine, or I've used Trim to continue encoding from where it stopped and it's continued at normal speed.

It wouldn't surprise me if it's a masktools2 issue though, or some other plugin for that matter. I'm fairly sure I tested using different versions of masktools2 at one stage but sometime fairly soon I'll try again just to be sure. There's another issue I sometimes have which is mostly a problem of artefacts when using SRestore, but I'm certain I've seen similar artefacts with QTGMC, only for QTGMC they're less common and fairly minor. I use SRestore for double blend removal now and then, and mostly it works well, but occasionally artefacts will appear (http://forum.doom9.org/showthread.php?p=1696179&highlight=srestore#post1696179) for a single frame and for some videos it happens so much it's more annoying than the blending I'm wanting to remove. I tried ExBlend and FixBlendIVTC but the same thing happened. I suspect it might be a plugin problem and the four scripts all have masktools2 in common, but then again it could be completely unrelated to the issue here. When encoding speed slows using QTGMC it doesn't seem to cause the video to be processed any differently, just slower.

[VideoFanatic]

I'm using Avisynth 2.6 MT, QTGMC 3.31, by Vit (2011), mvtools2.dll (2.6.0.5). I've got a 544 x 576 MPEG2 video I'm encoding to 720 x 576.
I can use any QTGMC preset but if I also use the McTemporalDenoise Low preset then the encode always fails. Yet the McTemp Medium preset encodes fine! Cropping the video or not makes no difference. Here's my script:


setmtmode(5,6)
mpeg2source("M:\Video.d2v")
setmtmode(2)
McTemporalDenoise(settings="low", interlaced=true)
AssumeTFF()
QTGMC(Preset="Slow")
Crop(10,2,-10,-8)
nnedi3_rpow2(2, cshift="Spline36Resize", fwidth=720, fheight=576)
SeparateFields() SelectEvery(4,0,3) Weave()

[Groucho2004]

I'm using Avisynth 2.6 MT, QTGMC 3.31, by Vit (2011), mvtools2.dll (2.6.0.5). I've got a 544 x 576 MPEG2 video I'm encoding to 720 x 576.
I can use any QTGMC preset but if I also use the McTemporalDenoise Low preset then the encode always fails. Yet the McTemp Medium preset encodes fine! Cropping the video or not makes no difference. Here's my script:


setmtmode(5,6)
mpeg2source("M:\Video.d2v")
setmtmode(2)
McTemporalDenoise(settings="low", interlaced=true)
AssumeTFF()
QTGMC(Preset="Slow")
Crop(10,2,-10,-8)
nnedi3_rpow2(2, cshift="Spline36Resize", fwidth=720, fheight=576)
SeparateFields() SelectEvery(4,0,3) Weave()

QTGMC() combined with McTemporalDenoise() using 6 threads will exhaust your available memory very quickly.
Run the script through AVSMeter and tell us what happens.

[VideoFanatic]

I don't know how to do that.

[StainlessS]

I don't know how to do that.

Suggest that you download AVSMeter, and read the docs, then you would. :)

[VideoFanatic]

I dragged the avs file into AVSMeter.exe. The script is running. Do I have to wait 3 hours for it to finish? Then what do I do? What info do you need?

[Groucho2004]

How much physical memory is it using? Is it climbing/constant?

I suggest you set a time limit (30 minutes, for example) and create a log file which you can post on pastebin. Command line would be:
avsmeter script.avs -log -timelimit=1800

[VideoFanatic]

I opened AVSMeter in CMD. When I then try to run this it says "M:Working" is not recognized as an internal or external command, operable program or batch file:
M:\1Working Videos\Impact 2015\Impact 2015 Nov 18.avs -log -timelimit=1800

[StainlessS]

I presume that path to AVSMeter is in your path (and reboot may be necessary).

Also, ensure that name of avs file is enclosed in quotes as it contains SPACES.

EDIT: Also, is that '1' supposed to be there ? [M:\1Working Videos\Impact 2015\Impact 2015 Nov 18.avs]

EDIT: Something like

AVSMeter.Exe "M:\1Working Videos\Impact 2015\Impact 2015 Nov 18.avs" -log -timelimit=1800

[VideoFanatic]

Got it running now. So where does AVSMeter save the log to?

[StainlessS]

Documentation does not seem to specify output log location, suggest inspect,
same directory as "avs" file,
same directory as "AvsMeter.exe"
"C:\" directory.
"C:\Documents And Settings\YOUR NAME\"

[Groucho2004]

So where does AVSMeter save the log to?Same directory as the script.
I'll have to add that info to the documentation.

[VideoFanatic]

Log is attached.

[Groucho2004]

Log is attached.
It may take days for the attachment to be approved. Please post it to pastebin.com.

[VideoFanatic]

Too many characters for pastebin. Google Drive: https://drive.google.com/file/d/0B7SrUmaXghlPUFg0MjV0VURVbmc/view?usp=sharing

[StainlessS]

I guess that you discovered that the log does not appear in avs file directory, until completed.
(Info for other users).

[VideoFanatic]

See my previous post. I've attached the log.

[Groucho2004]

See my previous post. I've attached the log.I can't see anything out of the ordinary in the log. The memory consumption is actually very moderate, probably because it's SD resolution.
You have to elaborate a bit on your statement above "but if I also use the McTemporalDenoise Low preset then the encode always fails."
What fails?
Any error message?
How long does it run before it fails?
What tool do you use for encoding?

[Groucho2004]

I guess that you discovered that the log does not appear in avs file directory, until completed.
(Info for other users).
Correct. The data is collected in memory and written to the log file just before the program terminates.

[VideoFanatic]

Fails in MeGUI x264 or Simple x264 Launcher. McTemporalDenoise Low and any QTGMC preset results in the encoding failing. But McTemp Medium and and QTGMC preset does NOT crash. In MeGUI for example, it doesn't actually crash. What happens is after an hour or so the video simply stops encoding. I can still see the video "encoding" in MeGUI but the CPU usage falls to 20% so the CPU isn't being used. I can see in the encoding window that the remaining time goes up instead of down and the encoding speed gradually goes down to zero where it then crashes. It just says something like the avsx264.exe crashed.

Any idea what's causing the crash? What extra filters does McTemporalDenoise low use that medium doesn't?

What's strange about this is that on a h264 720 x 576i source I can use McTemp Low and QTGMC SuperFast and it does NOT crash.

[Groucho2004]

What happens is after an hour or so the video simply stops encoding.
In that case you should run the whole script through AVSMeter and check if it slows down in a similar fashion.

As for troubleshooting I would increase the memory for Avisynth from the default (512MB) to 1000~1500. Put "SetmemoryMax(1000)" at the beginning of your script. Increase the value as needed, but not beyond 1500.

[VideoFanatic]

I'll try running the whole script through AVSMeter. I've never seen SetMemoryMax work before. Doesn't seem to do anything as I still got crashes. Are you sure it goes at the very start of my script? The docs say to put it after the first setmtmode line.

[VideoFanatic]

It seems that now I'm even getting crashes on McTemporalDenoise medium. Not sure why. I'm running the whole video in AVSMeter to see if it crashes and I'll post the results once it's finished. The script runs fine in non-MT and doesn't crash. I encoded loads of videos with this script in MT in the past and it rarely crashed. Now it seems to crash all the time and I don't know why.

I also notice that CPU usage is around 98% with the script when I'm sure it used to be around 75% before since it's only using 6 out of 8 cores as specified in my script.

[VideoFanatic]

At 1 hour 14 minutes the AVSMeter window froze - it stopped updating the time elapsed / estimated. Pressing Escape did nothing and it looks like the log is only written when you press Escape.

[Groucho2004]

At 1 hour 14 minutes the AVSMeter window froze - it stopped updating the time elapsed / estimated. Pressing Escape did nothing and it looks like the log is only written when you press Escape.
There's a very high number of useless nnedi3 threads being spawned because nnedi3 features internal multi-threading. Try reducing them like this:
setmtmode(5,6)
mpeg2source("M:\Video.d2v")
setmtmode(2)
McTemporalDenoise(settings="low", interlaced=true)
AssumeTFF()
QTGMC(Preset="Slow", EDithreads=1)
Crop(10,2,-10,-8)
nnedi3_rpow2(2, cshift="Spline36Resize", fwidth=720, fheight=576, threads=1)
SeparateFields() SelectEvery(4,0,3) Weave()
In my test, this reduced the number of threads from 93 to 39 and it was actually slightly faster.
If that does not work, reduce the number of threads in SetMTMode().

Edit1: I just tried the script above and it also freezes after a while.

Edit2: Excluding McTemporalDenoise from MT (i.e. moving "setmtmode(2)" after MCTD) seems to make the whole thing stable.

[VideoFanatic]

Thanks. Yes moving setmtmode makes it stable but that's only because it's basically running in non-MT and you get a slow speed!

So do you think it's Nnedi causing these problems? Is there nothing else I can do to get this script to run stable? It's weird. I thought maybe it was my PC that might have been the problem so I restored a backup image and it worked perfectly for several days but now the problem is back!

[Groucho2004]

Thanks. Yes moving setmtmode makes it stable but that's only because it's basically running in non-MT and you get a slow speed!
When I tested this it wasn't that much slower, maybe 20%. MCTD makes use of avstp.dll which comes with mvtools2 2.6.0.5. Make sure you have it in your auto-load directory.

Also, the CPU cycles that Avisynth isn't using can be used by the encoder, at least to some extent.

[VideoFanatic]

I already had those files in the directory. I have an 8 core 3.9 Ghz CPU. I'm getting maybe 3fps when avisynth has the slowdown. I normally get up to 7fps. I don't know what else I can do to fix this issue.

[Groucho2004]

I already had those files in the directory. I have an 8 core 3.9 Ghz CPU. I'm getting maybe 3fps when avisynth has the slowdown. I normally get up to 7fps. I don't know what else I can do to fix this issue.
OK, here's what I tried (with my i5 2500K, 4 cores @4GHz):

Script(basically your exact script which will eventually slow down and freeze):
LoadPlugin("E:\Apps\VideoTools\DGDec\DGDecode.dll")
Import("E:\Apps\VideoTools\AVSPlugins\qtgmc.avsi")
setmtmode(5,6)
MPEG2Source("F:\DVD_Interlaced\test.d2v", idct = 4).loop(100)

setmtmode(2)
McTemporalDenoise(settings="low", interlaced=true)
AssumeTFF()
QTGMC(Preset="Slow", EDithreads=1)
Crop(10,2,-10,-8)
nnedi3_rpow2(2, cshift="Spline36Resize", fwidth=720, fheight=576, threads=1)
SeparateFields() SelectEvery(4,0,3) Weave()


Result of running 2000 frames with AVSMeter:
Frames processed: 2000 (0 - 1999)
FPS (min | max | average): 1.710 | 91783 | 12.63
Memory usage (phys | virt): 855 | 1014 MB
Thread count: 39
CPU usage (average): 99%


When I move the setmtmode(2) below MCTD() I get this:
Frames processed: 2000 (0 - 1999)
FPS (min | max | average): 1.677 | 35.16 | 10.11
Memory usage (phys | virt): 679 | 759 MB
Thread count: 35
CPU usage (average): 76%

So, the second script runs at about 80% of the first one, uses less CPU/memory resources and won't freeze.
When you include the encoder in the process, the difference in speed will be negligible (actually, the second one will always be faster since the first one never gets to the end :rolleyes:).

[VideoFanatic]

Yes your speed was correct if you use Low for McTemporalDenoise. I was talking about using it with Medium. Speed in non-MT is too slow for Medium. Also I checked on my TV to compare the picture difference between QTGMC Slow and Super Fast and there was no difference so I'm using Super Fast. I'm encoding 2 videos at once in non-MT and I'm getting around 4fps each. I've encoded several videos without problems. But today when encoding 2 videos at once, one of the encoding has the slowdown again where the time remaining goes up instead of down. So it seems this bug happens even in non-MT! I'm encoding it again as hopefully this will just be a rare bug in non-MT instead of all the time like in MT!

[kuchikirukia]

Ok, currently trying for a better fix to this. Also here:
http://forum.doom9.org/showthread.php?t=173308

Best I've come up with so far that doesn't involve 2 encodes is:

Trim(4,-1) ++ Trim(1,0)

Blips frame 4 at the beginning, then continues on at frame 1 (skipping 0).
Anyone have a better idea? Trim(4,-1) ++ Trim(0,0) does work (avisynth behaves), so can we output the first trim to null?
Or can we use the first script and overlay frame 0 onto the out-of-place 4 instead?

EDIT:
Ok, someone tell me if this is stupid, because it seems to work:

clip1 = trim(4,-1)
clip2 = trim(0,-1)
Overlay(clip1, clip2, mode="blend", opacity=1.0) ++ trim(1,0)

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

Test 1:

setmemorymax(900)
LWLibavVideoSource("d:\video\00004.m2ts",threads=2)
QTGMC(preset="slower")

result:

http://s8.postimg.org/frh026tx1/Untitled.png

Test 2:
setmemorymax(900)
LWLibavVideoSource("d:\video\00004.m2ts",threads=2)
QTGMC(preset="slower")
clip1 = trim(4,-1)
clip2 = trim(0,-1)
Overlay(clip1, clip2, mode="blend", opacity=1.0) ++ trim(1,0)

result:

http://s8.postimg.org/hurf9utpx/Untitled1.png

Edit 2: 3000 frames in and it's still behaving! 4.3fps and no destroying and creating of MSVCR120 threads.

[StainlessS]

Its kinda ridiculous that you have to do this at all, but does the below have +ve effect ?


Colorbars
ShowFrameNumber

Trim(Trim(4,-1)++Trim(0,0),1,0) # -1 is 1 frame (Length=1 is v2.6 only)


Edit: or the even more ridiculous

Colorbars
ShowFrameNumber

Trim(Trim(4,-1)++Trim(0,-1)++Trim(1,0),1,0)


or


Colorbars
ShowFrameNumber

Trim(Trim(0,-1)++Trim(1,0),0,0)


Or wrap in a function and install in plugins (so you dont have to remember what to do)


Colorbars
ShowFrameNumber

Function PlayNice(clip c) {c Return Trim(Trim(0,-1)++Trim(1,0),0,0)}

PlayNice

[kuchikirukia]

I don't get what that's supposed to do. It gives me almost 108k frames of color bars and qtgmc doesn't seem to act on it. It doesn't break the input filter, but I don't think it would without the trim.

Did you mean without the Colorbars?
Frame 0 shows up as Frame 00000, it's the right frame, they're in order, and it runs...
... broken.

http://s12.postimg.org/881y3h2m5/Untitled.png

Oh, and I went and replaced the "length=1" in mine with "-1" to make it pre-2.6 safe. Confirmed it still works. Previous post edited.



Edit: or the even more ridiculous

Trim(Trim(4,-1)++Trim(0,-1)++Trim(1,0),1,0)


Broken.

or


Trim(Trim(0,-1)++Trim(1,0),0,0)


Broken.

Or wrap in a function and install in plugins (so you dont have to remember what to do)


Function PlayNice(clip c) {c Return Trim(Trim(0,-1)++Trim(1,0),0,0)}

PlayNice


Pretty sure that will be broken because it starts at frame 0.
Yup.

It needs to be >=4. Once we call a trim of (4,x) it doesn't seem to care if we go back to frame 0. But it doesn't like to start at 0.

[StainlessS]

Yeh, the colorbars and ShowFrameNumber should be replaced with whatever you want, I dont have your clip and wanted to verify that it works proper.

Try the edits also.

[kuchikirukia]

Hm, I suppose I don't need to specify that opacity and mode since they're the default.

Should it use something other than clip1 and clip2 as names, or should that be ok?

[StainlessS]

The other stuff is just to test function returns correct frames.

Colorbars.ShowFrameNumber.ConvertToYV12

Function PlayNice(clip c) {Return Overlay(c.trim(4,-1),c.trim(0,-1)) ++ c.trim(1,0)}

PlayNice


EDIT: Maybe add it as first line inside QTGMC

something like


Function QTGMC(clip Input, ...) {
Input = Playnice(Input)
}


or

Function QTGMC(clip Input, ...) {
Input = Overlay(Input.trim(4,-1), Input.trim(0,-1)) ++ Input.trim(1,0)
}


Fixed error, added stuff in BLUE.

[kuchikirukia]

PlayNice works. Is that just what I wrote just condensed to a single line?

I just get syntax errors trying the rest.

[StainlessS]

Is that just what I wrote just condensed to a single line?

Yes.

Sorry, missed out the Overlay( bit for some reason, fixed in post above (I hope).

EDIT: And you do understand that
Function QTGMC(clip Input, ...) {

is supposed to be the function description for QTGMC and '...' just means I missed out most of it, ie
you only ADD either

Input = Playnice(Input)

or

Input = Overlay(Input.trim(4,-1), Input.trim(0,-1)) ++ Input.trim(1,0)

as the first line inside of the QTGMC function.

[kuchikirukia]

Yeah, no clue.
Throwing Playnice into QTGMC and calling QTGMC().playnice is as far as I can get.

[kuchikirukia]

Ok, 4 frames doesn't seem to quite be enough. I just had a QTGMC + smdegrain script (that wanted at least setmemorymax(1900)) where I was getting slowdowns and corruption ~1000 frames in. I've bumped it to:

Function PlayNice(clip c) {Return Overlay(c.trim(100,-1),c.trim(0,-1)) ++ c.trim(1,0)}

And that's working.

I'll move this to my main machine and run some tests to see where the cutoff seems to be.

E1: Ok, even 100 isn't enough to stop MSVCR120 from going Christmas. It just stops it from slowing down as much.
E2: 1000 doesn't do it either. Though trim(999,0) without PlayNice is working.
E3: Trim(4,0) works. So it seems the PlayNice function jumping right back to frame 0 is partially reinserting the original problem. Its jump ahead mitigates whatever's going on, but doesn't fix it.

E4: Ok, apparently PlayNice doesn't play nice with smdegrain(lsb=true). It's actually introducing this slowdown in the script I'm using.
e5: ... if placed after?

Ok, I can't make heads or tails of this.


Function PlayNice(clip c) {Return Overlay(c.trim(1,-1),c.trim(0,-1)) ++ c.trim(1,0)}
Causes christmas lights if called before or after smdegrain(lsb=true), but minimal slowdown

Function PlayNice(clip c) {Return Overlay(c.trim(4,-1),c.trim(0,-1)) ++ c.trim(1,0)}
Works if called before smdegrain(lsb=true). Christmas + slowdown if placed after.

Function PlayNice(clip c) {Return Overlay(c.trim(10,-1),c.trim(0,-1)) ++ c.trim(1,0)}
Christmas + slowdown if placed before or after smdegrain(lsb=true).

And what's going on with this:

assumetff()
QTGMC(preset="medium",sharpness=0.9)
smdegrain(lsb_in=false,lsb=true,lsb_out=false,tr=4,prefilter=3,thSAD=150,contrasharp=true,refinemotion=true,plane=0,chroma=false,interlaced=false)
trim(20,0)

2.66 fps

https://s31.postimg.org/qk02zijx3/Untitled1.png (https://postimg.org/image/qk02zijx3/)


assumetff()
trim(10,0)
QTGMC(preset="medium",sharpness=0.9)
smdegrain(lsb_in=false,lsb=true,lsb_out=false,tr=4,prefilter=3,thSAD=150,contrasharp=true,refinemotion=true,plane=0,chroma=false,interlaced=false)


2.79 fps

https://s31.postimg.org/akhffynvb/Untitled.png (https://postimg.org/image/akhffynvb/)

e6: except Trim before QTGMC breaks it. 100 frames in I'm getting green screens.

e7: Ok, what I'm seeing is that PlayNice doesn't necessarily play nice if used after other filters or in conjunction with another trim command that doesn't start with 0. So it should be used QTGMC().playnice() and only when starting at the beginning of a video.

[ravewulf]

I don't know if this will be of any use to anyone, but I figured I'd post what works for me (using MeGUI's present syntax, but manually filling in the x's):

SetMemoryMax(x)
SetMTMode(3,x)
<input>
SetMTMode(2)
QTGMC(EdiThreads=1)
<crop>
<resize>
<denoise>
SetMTMode(1)
GetMTMode(false) > 0 ? distributor() : last

Basically ALWAYS use EdiThreads=1 and let SetMTMode handle the threading. I've also just started experimenting with removing AVSTP and sometimes that helps.

SetMTMode(3,x) for most source filters, but SetMTMode(5,x) for hardware decoders (DGIndexNV). I tend to use # threads = 1.5x # of cores (6 threads for a quad core processor) when going to huffyuv for further processing and 0 (aka same number of threads as cores) if I'm going to x264. Tweak memory up as needed (I've gone as high as 2000 as for me the amount needed to prevent crashes seems to increase as both the length of the video and the number of threads increases). Although I imagine I'll probably tweak my methodology once I upgrade past a quadcore processor. Lastly,

SetMTMode(1)
GetMTMode(false) > 0 ? distributor() : last

is only for going to ffmpeg to encode as huffyuv or previewing in AvsPmod (uses ffmpeg), do not use with x264/avsmeter or other programs that recognize AviSynth MT and add the Distributor call internally.

[real.finder]

So far the new QTGMC mod is behaving itself with that sample for me. Even when using preset="slow".

Have I mentioned that for this sample at least (and for me), the other fix, aside from Trim(50,0) was to use MP_Pipeline? It fixed the problem for these particular encodes, but I'm fairly sure there's been a few encodes since where it didn't. Why MP_Pipeline changes things in relation to slowdowns, I have no idea.

I'm copying the numbers from MeGUI's log file, and keep in mind this PC's old so it's slow. I've listed the encoding speed for comparing QTGMC versions.

QTGMC 3.33s (new version) - 3.89fps.
QTGMC 3.33s with Preset="slow" - 3.11fps
QTGMC 3.33s with MP_Pipeline - 4.66fps

QTGMC 3.33d (original version) - around 1fps (I didn't bother running the whole encode)
QTGMC 3.33d with Preset="slow" - around 1fps (I didn't bother running the whole encode)
QTGMC 3.33d with MP_Pipeline - 4.69fps

I did add xflateMaTo parameter to use masktools2 deflate and inflate, so it worth doing some test again with last avs+ and plugins updates

I think it maybe also worth check for deinterlace quality with xflateMaTo=ture vs xflateMaTo=false