Log in

View Full Version : Avisynth output ends after a few frames with my filter


nlemozz
15th September 2010, 22:08
I am using avisynth 2.5.8 (the one that is the default for download from sourceforge.
I have created a dll based on the official invert filter example for V2.5+ :
http://avisynth.org/mediawiki/Filter_SDK/Two-Five_Invert

I am using visual studio 2010 to compile it.
Everything's running on Win7 64 bit.

I then use a very simple script to run it.
The script is:

InputFile = "XX.MOV"
Input = DirectShowSource(InputFile, audio=false)
Input = ConvertToRGB32(Input)
Invert(Input)

I am using a quicktime for directshow codec from www.riverpast.com.

I have *.avs set to open into windows media player.
When I double click on the file windows media player only plays the fist few frames and then stops.
If I click "play again" it will then correctly show the whole clip.

This does not happen with any of the built in filters or some others I have downloaded.

I have 2 questions:
A: Has anybody seen this before or know what is happening?
B: If not then, any ideas on tracking this behaviour down?

I have debugged the process and found the following:
* My filter gets passed the correct number of frames
* There are a lot of IScriptEnvironment::NotFound's in the debug output. Is this the system looking for codecs?
* I'm not sure, but it looks like avisynth may continue on even after the clip has finished playing (early)
* There is one other exception which is a bad_alloc. There are no "new"s in the example filter.

Thanks for any help.

PS: Full text of the bad-alloc exception...
First-chance exception at 0x75e1b727 in wmplayer.exe: Microsoft C++ exception: boost::exception_detail::clone_impl<boost::exception_detail::bad_alloc_> at memory location 0x06d4d348..
First-chance exception at 0x75e1b727 in wmplayer.exe: Microsoft C++ exception: [rethrow] at memory location 0x00000000..

kemuri-_9
16th September 2010, 00:09
boost::exception_detail::bad_alloc_ != std::bad_alloc

something that is built upon the boost library is failing a memory allocation, go blame whatever that is as it's certainly not avisynth.

nlemozz
16th September 2010, 00:20
Thanks.
No doubt it's some codec or something somewhere.

Slight update:
Sometimes it does make it to the end 1st try, but still fails 90%+ of the time.

If it helps here is the output of Directshowsource log just before it fails to end:
Receive: video sample time span x100ns 4666667 to 5000000 (333333)
00:00:03.754 200 0x03A6E5A0 0x000016CC ...Receive() waiting for DoneWithSample. (video)
00:00:03.755 010 0x03A6E5A0 0x0000081C ...NextSample() done waiting for new sample (video)
00:00:03.755 004 0x03A6E588 0x0000081C GetFrame: CFR Frame 14 time span x100ns 4666667 to 5000000
00:00:03.770 004 0x03A6E588 0x0000081C GetFrame: Frame 15 start time 4964280x100ns.
00:00:03.770 010 0x03A6E5A0 0x0000081C NextSample() indicating done with previous sample...(video)
00:00:03.770 100 0x03A6E5A0 0x000016CC Receive() - returning. (video)
00:00:03.770 010 0x03A6E5A0 0x0000081C ...NextSample() waiting for new sample...(video)
00:00:03.787 002 0x03A6E5A0 0x000016CC Receive: video sample time span x100ns 5000000 to 5333333 (333333)
00:00:03.787 200 0x03A6E5A0 0x000016CC ...Receive() waiting for DoneWithSample. (video)
00:00:03.788 010 0x03A6E5A0 0x0000081C ...NextSample() done waiting for new sample (video)
00:00:03.789 004 0x03A6E588 0x0000081C GetFrame: CFR Frame 15 time span x100ns 5000000 to 5333333
00:00:03.803 004 0x03A6E588 0x0000081C GetFrame: Frame 16 start time 5295232x100ns.
00:00:03.803 010 0x03A6E5A0 0x0000081C NextSample() indicating done with previous sample...(video)
00:00:03.803 010 0x03A6E5A0 0x0000081C ...NextSample() waiting for new sample...(video)
00:00:03.803 100 0x03A6E5A0 0x000016CC Receive() - returning. (video)
00:00:03.817 002 0x03A6E5A0 0x000016CC Receive: video sample time span x100ns 5333333 to 5666667 (333334)
00:00:03.817 200 0x03A6E5A0 0x000016CC ...Receive() waiting for DoneWithSample. (video)
00:00:03.817 010 0x03A6E5A0 0x0000081C ...NextSample() done waiting for new sample (video)
00:00:03.818 004 0x03A6E588 0x0000081C GetFrame: CFR Frame 16 time span x100ns 5333333 to 5666667
00:00:03.831 004 0x03A6E588 0x0000081C GetFrame: Frame 17 start time 5626184x100ns.
00:00:03.831 010 0x03A6E5A0 0x0000081C NextSample() indicating done with previous sample...(video)
00:00:03.831 100 0x03A6E5A0 0x000016CC Receive() - returning. (video)
00:00:03.838 010 0x03A6E5A0 0x0000081C ...NextSample() waiting for new sample...(video)
00:00:03.851 002 0x03A6E5A0 0x000016CC Receive: video sample time span x100ns 5666667 to 6000000 (333333)
00:00:03.851 200 0x03A6E5A0 0x000016CC ...Receive() waiting for DoneWithSample. (video)
00:00:03.852 010 0x03A6E5A0 0x0000081C ...NextSample() done waiting for new sample (video)
00:00:03.853 004 0x03A6E588 0x0000081C GetFrame: CFR Frame 17 time span x100ns 5666667 to 6000000
00:00:06.684 080 0x03A6E588 0x000016A0 ~DirectShowSource.
00:00:06.684 008 0x03A6E5A0 0x000016A0 GetSample::GetState(), state is State_Running
00:00:06.684 008 0x03A6E5A0 0x000016A0 GetSample::Pause(), state was State_Running
00:00:06.684 008 0x03A6E5A0 0x000016A0 GetSample::ConnectedTo() is 0x03b07cf4
00:00:06.684 008 0x03A6E5A0 0x000016A0 GetSample::Stop(), state was State_Paused
00:00:06.685 100 0x03A6E5A0 0x000016CC Receive() - returning. (video)
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::ConnectedTo() is 0x03b07cf4
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::ConnectedTo() is 0x03b07cf4
00:00:06.706 010 0x03A6E5A0 0x000016A0 StopGraph() indicating done with sample - State_Stopped
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::QueryInterface({f90a6130-b658-11d2-ae49-0000f8754b99}, ppv) ** E_NOINTERFACE **
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::EnumPins()
00:00:06.706 080 0x03B23090 0x000016A0 New GetSampleEnumPins.
00:00:06.706 040 0x03A6E5A0 0x000016A0 GetSample::AddRef() -> 5
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::QueryDirection()
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::ConnectedTo() is 0x03b07cf4
00:00:06.706 080 0x03A6E5A0 0x000016A0 Releasing Allocator 0x03b118d4.
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::Disconnect()
00:00:06.706 040 0x03A6E5A0 0x000016A0 GetSample::Release() -> 4
00:00:06.706 040 0x03A6E5A0 0x000016A0 GetSample::Release() -> 3
00:00:06.706 040 0x03A6E5A0 0x000016A0 GetSample::Release() -> 2
00:00:06.706 080 0x03B23090 0x000016A0 ~GetSampleEnumPins.
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::SetSyncSource(0x00000000), was 0x00000000
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::JoinFilterGraph(0x00000000, (null))
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::QueryInterface({8e1c39a1-de53-11cf-aa63-0080c744528d}, ppv) ** E_NOINTERFACE **
00:00:06.706 008 0x03A6E5A0 0x000016A0 GetSample::GetState(), state is State_Stopped
00:00:06.706 040 0x03A6E5A0 0x000016A0 GetSample::Release() -> 1
00:00:07.210 080 0x03A6E5A0 0x000016A0 ~GetSample(video).
00:00:07.210 fff 0x00000000 Close video log 1.

nlemozz
16th September 2010, 03:41
Update and workaround.
Turns out it's nothing to do with my compiled filter. It happens with other filters as well.

Have also discovered that this only happens on monitor 2 of my dual monitor setup (2 x 2560 x1600 resolution).

For now I'm happy enough running it on monitor 1. Might be time for a reinstall of windows.

Cheers.