Possible bug?

[colordog]

Howdy -

I might be encountering a bug - or a screw-up on my end; I'm not sure yet. Also, I can't recount whether this started happening just after I upgraded to DivX 5.1, or GKnot 0.28.5.3 - I think the latter though.

About 15-20% of the time, VDubMod will error when starting the 2nd pass (I only do a 2-pass encode). Never on the 1st pass, and never on the assembly. When trying to start the second pass, I get the error: "FastWriteStream: Open Failed". I can't find a reference to this specific error in the archives. Additionally, I think this error isn't source dependent - if I manually start the 2nd pass, it works just fine. Any ideas? Log below.



Gordian Knot -
Encoding Job Data:

Type: EncD5_All_CreditsSep
Number: 2
Name: movie
Platform: WinXP (5.1.2600).2

Files:
VirtualDubModExe: C:\PROGRA~1\GORDIA~1\VirtualDubMod\VirtualDubMod.exe
NandubExe: C:\PROGRA~1\GORDIA~1\nandub\Nandub.exe
AviFinal: C:\vobs\movie Ver.1\VIDEO_TS\movie.avi
AviMovie: C:\vobs\movie Ver.1\VIDEO_TS\movie_Movie.avi
AviCredits: C:\vobs\movie Ver.1\VIDEO_TS\movie_Credits.avi
MovieFS: C:\vobs\movie Ver.1\VIDEO_TS\movie.avs
CreditsFS: C:\vobs\movie Ver.1\VIDEO_TS\movie_Credits.avs
Log : C:\vobs\movie Ver.1\VIDEO_TS\movie.log
Stats: C:\vobs\movie Ver.1\VIDEO_TS\movie.stats
Ecf : C:\vobs\movie Ver.1\VIDEO_TS\movie.ecf

Options:
Quality/DRF: 20
CreditsStart: 209020
UseEcf: 1
CreditsIVTC: 1
CreditsAppend: 1
DeleteInterm.: 0
EnforceBitrate: 0
AntiShit: 0
Split final file at CD size:700

Calculator:
VideoSize: 604596 kbyte.
Audio1Size: 98587 kbyte.
Audio2Size: 0 kbyte.
Overhead: 13616 kbyte.
AviSize: 716800 kbyte (700 mbyte).
FilesSize: 0 kbyte.
TotalSize: 716800 kbyte (700 mbyte).
Interleaving: vbrmp3
Bitrate: 687 k(=1000)Bits/s
Frames: 216122
FPS: 29.970
Duration: 20:11
Quality: 0.221 bits/(pixel*frame).
CompCheck3: 0.000 bits/(pixel*frame).
CompCheck5: 0.526 bits/(pixel*frame).
Resolution: 432 x 240

Audio 1:
Mode: ac3 -> mp3
SourceFile: C:\vobs\movie Ver.1\VIDEO_TS\movie AC3 T01 2_0ch 192Kbps DELAY 0ms.ac3
WavFile: C:\vobs\movie Ver.1\VIDEO_TS\movie AC3 T01 2_0ch 192Kbps DELAY 0ms.wav
Mp3File: C:\vobs\movie Ver.1\VIDEO_TS\movie AC3 T01 2_0ch 192Kbps DELAY 0ms.mp3
Azid: -L -3db -s stereo -c normal
Lame: --alt-preset 112
Delay: 0
Interval: 1
Preload: 500
Mux: 1
Recalc: 1
DeleteWav: 1

Audio 2:
none.

5:02:47 AM: Re-Calculating Frame Count.
5:02:47 AM: FrameRate was 29.970 fps
5:02:47 AM: FrameRate now is 23.976 fps
5:02:47 AM: IVTC: 172891 Frames.

5:02:47 AM: Started Transcoding Audio.

5:02:47 AM: Using "BeSweet" to transcode C:\vobs\movie Ver.1\VIDEO_TS\movie AC3 T01 2_0ch 192Kbps DELAY 0ms.ac3
CommandLine: C:\PROGRA~1\GORDIA~1\BeSweet.exe -core( -input "C:\vobs\movie Ver.1\VIDEO_TS\movie AC3 T01 2_0ch 192Kbps DELAY 0ms.ac3" -output "C:\vobs\movie Ver.1\VIDEO_TS\movie AC3 T01 2_0ch 192Kbps DELAY 0ms.mp3" -logfile "C:\vobs\movie Ver.1\VIDEO_TS\movie AC3 T01 2_0ch 192Kbps DELAY 0ms.log" ) -ota( -hybridgain ) -azid( -L -3db -s stereo -c normal ) -lame( --alt-preset 112 ) -profile( Gordian Knot 0.28 )
5:26:10 AM: Finished. Duration: 23 minutes, 23 seconds.

5:26:10 AM: Audio Done.
5:26:10 AM: MP3-File-Size is 96672 kb.
5:26:10 AM: Audio 1, determined: 96672 kb
5:26:10 AM: Audio 1, calc: 98587 kb
5:26:10 AM: New Bitrate for Movie = 692 k(=1000)Bits/s

Adding this script to C:\PROGRA~1\GORDIA~1\VirtualDubMod\LastJob.vcf :

// $job "DivX5 Single Pass"
// $input "C:\vobs\movie Ver.1\VIDEO_TS\movie_Credits.avs"
// $output "C:\vobs\movie Ver.1\VIDEO_TS\movie_Credits.avi"
// $state 0
// $start_time 0 0
// $end_time 0 0
// $script

VirtualDub.Open("C:\\vobs\\movie Ver.1\\VIDEO_TS\\movie_Credits.avs",0,0);
VirtualDub.video.SetDepth(24,24);
VirtualDub.video.SetMode(1);
VirtualDub.video.SetFrameRate(0,1);
VirtualDub.video.SetIVTC(0,0,-1,0);
VirtualDub.video.SetRange(0,0);
VirtualDub.video.SetCompression(0x78766964,0,10000,0);
VirtualDub.video.filters.Clear();
VirtualDub.subset.Delete();
VirtualDub.SaveAVI("C:\\vobs\\movie Ver.1\\VIDEO_TS\\movie_Credits.avi");
VirtualDub.Close();

// $endjob
//
//--------------------------------------------------
// $done

5:26:11 AM: Started DivX5-Single, Quality 20: C:\vobs\movie Ver.1\VIDEO_TS\movie_Credits.avs
5:33:50 AM: Finished DivX5-Single, Quality 20: Duration: 7 minutes, 38 seconds.
5:33:50 AM: Assumed: Main Movie has 167216 Frames.
5:33:50 AM: Assumed: Credits Part has 5675 Frames.
5:33:50 AM: Credits Size = 1112 Kb
5:33:50 AM: New Bitrate for Movie = 715 k(=1000)Bits/s

Adding this script to C:\PROGRA~1\GORDIA~1\VirtualDubMod\LastJob.vcf :

// $job "DivX5-First Pass"
// $input "C:\vobs\movie Ver.1\VIDEO_TS\movie.avs"
// $output "C:\vobs\movie Ver.1\VIDEO_TS\movie_Movie.avi"
// $state 0
// $start_time 0 0
// $end_time 0 0
// $script

VirtualDub.Open("C:\\vobs\\movie Ver.1\\VIDEO_TS\\movie.avs",0,0);
VirtualDub.video.SetDepth(24,24);
VirtualDub.video.SetMode(1);
VirtualDub.video.SetFrameRate(0,1);
VirtualDub.video.SetIVTC(0,0,-1,0);
VirtualDub.video.SetRange(0,0);
VirtualDub.video.SetCompression(0x78766964,0,10000,0);
VirtualDub.video.filters.Clear();
VirtualDub.subset.Delete();
VirtualDub.SaveAVI("C:\\vobs\\movie Ver.1\\VIDEO_TS\\movie_Movie.avi");
VirtualDub.Close();

// $endjob
//
//--------------------------------------------------
// $done

5:33:50 AM: Started DivX5-First Pass: C:\vobs\movie Ver.1\VIDEO_TS\movie.avs
8:48:39 AM: Finished DivX5-First Pass: Duration: 3 hours, 14 minutes, 48 seconds.
8:48:39 AM: Trying to open Log-file.
8:48:39 AM: Success: Log-file open.
8:48:39 AM: Encoded: 167216 Frames.
8:48:39 AM: Speed: 14.305 Frames per Second.

Adding this script to C:\PROGRA~1\GORDIA~1\VirtualDubMod\LastJob.vcf :

// $job "DivX5-Second Pass"
// $input "C:\vobs\movie Ver.1\VIDEO_TS\movie.avs"
// $output "C:\vobs\movie Ver.1\VIDEO_TS\movie_Movie.avi"
// $state 0
// $start_time 0 0
// $end_time 0 0
// $script

VirtualDub.Open("C:\\vobs\\movie Ver.1\\VIDEO_TS\\movie.avs",0,0);
VirtualDub.video.SetDepth(24,24);
VirtualDub.video.SetMode(1);
VirtualDub.video.SetFrameRate(0,1);
VirtualDub.video.SetIVTC(0,0,-1,0);
VirtualDub.video.SetRange(0,0);
VirtualDub.video.SetCompression(0x78766964,0,10000,0);
VirtualDub.video.filters.Clear();
VirtualDub.subset.Delete();
VirtualDub.SaveAVI("C:\\vobs\\movie Ver.1\\VIDEO_TS\\movie_Movie.avi");
VirtualDub.Close();

// $endjob
//
//--------------------------------------------------
// $done

8:48:39 AM: Started DivX5 - Pass: 2: C:\vobs\movie Ver.1\VIDEO_TS\movie.avs
***ERROR WINDOW HERE - Waits for me to hit 'OK'***
9:14:52 AM: Finished DivX5 - Pass: 2: Duration: 26 minutes, 13 seconds.
9:14:52 AM: Speed: 106.282 Frames per Second.

Adding this script to C:\PROGRA~1\GORDIA~1\VirtualDubMod\LastJob.vcf :

// $job "DivX5 Append"
// $input "C:\vobs\movie Ver.1\VIDEO_TS\movie_Movie.avi"
// $output "C:\vobs\movie Ver.1\VIDEO_TS\movie.avi"
// $state 0
// $start_time 0 0
// $end_time 0 0
// $script

VirtualDub.Open("C:\\vobs\\movie Ver.1\\VIDEO_TS\\movie_Movie.avi",0,0);
VirtualDub.Append("C:\\vobs\\movie Ver.1\\VIDEO_TS\\movie_Credits.avi");
VirtualDub.RemoveInputStreams();
VirtualDub.stream[0].SetSource("C:\\vobs\\movie Ver.1\\VIDEO_TS\\movie AC3 T01 2_0ch 192Kbps DELAY 0ms.mp3",0x00000202,1);
VirtualDub.stream[0].SetMode(0);
VirtualDub.stream[0].SetInterleave(1,500,1,0,0);
VirtualDub.stream[0].SetClipMode(1,1);
VirtualDub.stream[0].SetConversion(0,0,0,0,0);
VirtualDub.stream[0].SetVolume();
VirtualDub.stream[0].SetCompression();
VirtualDub.video.SetDepth(24,24);
VirtualDub.video.SetMode(0);
VirtualDub.video.SetFrameRate(0,1);
VirtualDub.video.SetIVTC(0,0,-1,0);
VirtualDub.video.SetRange(0,0);
VirtualDub.video.SetCompression();
VirtualDub.video.filters.Clear();
VirtualDub.subset.Delete();
VirtualDub.SaveAVI("C:\\vobs\\movie Ver.1\\VIDEO_TS\\movie.avi");
VirtualDub.Close();

// $endjob
//
//--------------------------------------------------
// $done

9:14:52 AM: Started Appending Credits and Muxing Audio.: C:\vobs\movie Ver.1\VIDEO_TS\movie_Movie.avi
9:14:56 AM: Finished Appending Credits and Muxing Audio.: Duration: 3 seconds.
9:14:56 AM: Error analysing file " "C:\vobs\movie Ver.1\VIDEO_TS\movie.avi" " for splitting

9:14:56 AM: Done.
9:14:56 AM: Movie = C:\vobs\movie Ver.1\VIDEO_TS\movie.avi
Total Encoding Time: 4 hours, 12 minutes, 9 seconds.
10/2/2003 9:14:56 AM: Job "movie" finished.

[len0x]

it's not probably GK related, but rather DivX 5.1.
Try 0.28.5.2 again and see if you have the error (I think you will).

P.S. also you may wanna try latest VDubMod from here:
http://cyrius.bunkus.org/VDubMod_Release.zip

[colordog]

len0x: Thanks for the updated files.

I'm still periodically getting an error, although it's slightly different, but still involves FastWriteStream:

"FastWriteStream: couldn't open "C:\vobs\movie\movie.avi": The process cannot access the file because it is being used by another process.

Again, this sometimes occurs at low frequency when starting the 2nd pass.

This is really driving me crazy, as it interferes with my ability to automate encoding - I'll set up a large set of encoding while at work or sleeping, but GKnot/VDubMod stop while waiting for someone to hit the "ok" button to continue.

Any other suggestions you can think of?

[len0x]

Originally posted by colordog
Again, this sometimes occurs at low frequency when starting the 2nd pass.


my guess is that file lock is not being released after the first pass (by codec/vdubmod???) Gk itself is not involved in dealing with those files... Did you try going back to divx 5.0.5?

[colordog]

No, I haven't tried going back to 5.0.5 yet - I was first thinking that it must be a VDubMod error, but then I realize there wasn't a change in VDubMod when going to GKnot ....3 (was just the exe update).

I'm wondering if this error is due to the fact that I do the "1st pass normal / 2nd pass slow" pass encoding, rather than how it was meant. Still, I can't figure out why this happens at a low frequency, and not 'never or always'. Do you think that's a possibility?

I wish I could troubleshoot this better. I've searched the VDub/VDubMod forums and google for "FastWriteStream" and found hardly anything, none useful. Can you think of any other forum that I might want to look at?

[len0x]

Originally posted by colordog
Can you think of any other forum that I might want to look at?

divx5 forum would be your best bet...
But you should definitely try 5.0.5 before you can tell for sure...

[colordog]

No, you're right, I need to finish testing the other major change.

Thanks again for your help!