Lots of "Encode Failed"

Dec 31, 2013 at 11:28 PM
I'm converting a lot of MPEG2 files to MP4 to reduce storage required.

Most go through OK, but about 5% have "Encode Failed" in red in the list. I've tried v1.4.25 as well as beta versions.

I check these failed files and as near as I can tell by playing a bit from start, middle and end they are fine. It destroys my confidence though and it would be good if this behaviour could be looked into.

A typical log follows. There's a lot of stuff in there I don't get, e.g. references to BD when I've loaded a *.mpg file, and the program knows that my processor has 8 cores, but doesn't say if it's using them and I can't see anywhere to change it anyway. I suppose that's HB-specific anyway. Here's a log...

VidCoder 1.5.14.0 (x64)

Starting job 72/72

Path: K:...ate.mpg

Title: 1

Range: All

Worker ready: Service state is Opened on pipe VidCoderWorker.923e97dd-bfc0-45ad-9bab-baa56d0520f4

Connecting to process 5352 on pipe VidCoderWorker.923e97dd-bfc0-45ad-9bab-baa56d0520f4

[07:48:48] hb_init: starting libhb thread
[07:48:48] CPU: Intel(R) Core(TM) i7-4700HQ CPU @ 2.40GHz
[07:48:48] - Intel microarchitecture Haswell
[07:48:48] - logical processor count: 8
[07:48:49] OpenCL device #1: Intel(R) Corporation Intel(R) HD Graphics 4600
[07:48:49] - OpenCL version: 1.2
[07:48:49] - driver version: 9.18.10.3111
[07:48:49] - device type: GPU
[07:48:49] - supported: YES
[07:48:49] OpenCL device #2: NVIDIA Corporation GeForce GT 750M
[07:48:49] - OpenCL version: 1.1 CUDA
[07:48:49] - driver version: 311.54
[07:48:49] - device type: GPU
[07:48:49] - supported: no
[07:48:49] Intel Quick Sync Video support: yes
[07:48:49] - Intel Media SDK hardware: API 1.6 (minimum: 1.3)
[07:48:49] - Preferred implementation: hardware (any)
[07:48:49] hb_scan: path=K:...ate.mpg, title_index=1
libbluray/bdnav/index_parse.c:162: indx_parse(): error opening K:...ate.mpg/BDMV/index.bdmv
libbluray/bdnav/index_parse.c:162: indx_parse(): error opening K:...ate.mpg/BDMV/BACKUP/index.bdmv
libbluray/bluray.c:1725: nav_get_title_list(K:...ate.mpg) failed (000000001e135b30)
[07:48:49] bd: not a bd - trying as a stream/file instead
libdvdnav: Using dvdnav version 4.1.3
libdvdread: Encrypted DVD support unavailable.
libdvdnav:DVDOpenFileUDF:UDFFindFile /VIDEO_TS/VIDEO_TS.IFO failed
libdvdnav:DVDOpenFileUDF:UDFFindFile /VIDEO_TS/VIDEO_TS.BUP failed
libdvdread: Can't open file VIDEO_TS.IFO.
libdvdnav: vm: failed to read VIDEO_TS.IFO
[07:48:49] dvd: not a dvd - trying as a stream/file instead
[07:48:49] file is MPEG Program Stream
[07:48:49] Probing 1 unknown stream
[07:48:49] Probe: Found stream mpeg2video. stream id 0xe0-0x0
[07:48:49] Found the following streams
[07:48:49] Video Streams :
[07:48:49] 0xe0-0x0 type MPEG2 (0x2)
[07:48:49] Audio Streams :
[07:48:49] 0xc0-0x0 type MPEG2 (0x4)
[07:48:49] Subtitle Streams :
[07:48:49] Other Streams :
[07:48:49] stream id 0xc0 (type 0x4 substream 0x0) audio 0xc0
[07:48:49] scan: decoding previews for title 1
[07:48:49] scan: audio 0xc0: mp2, rate=48000Hz, bitrate=200000 Unknown (MPEG2) (2.0 ch)
[07:48:49] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/0/0/0, aspect 16:9, PAR 64:45
[07:48:49] stream: 65 good frames, 0 errors (0%)
[07:48:49] libhb: scan thread found 1 valid title(s)
[07:48:49] 1 job(s) to process
[07:48:49] starting job
[07:48:49] yadif thread started for segment 0
[07:48:49] yadif thread started for segment 4
[07:48:49] yadif thread started for segment 1
[07:48:49] yadif thread started for segment 3
[07:48:49] yadif thread started for segment 2
[07:48:49] yadif thread started for segment 5
[07:48:49] yadif thread started for segment 6
[07:48:49] yadif thread started for segment 7
[07:48:49] mask erode thread started for segment 2
[07:48:49] mask erode thread started for segment 7
[07:48:49] decomb filter thread started for segment 2
[07:48:49] decomb filter thread started for segment 3
[07:48:49] Passthru requested and input codec is not the same as output codec for track 2, dropping track
[07:48:49] decomb filter thread started for segment 4
[07:48:49] sync: expecting 41720 video frames
[07:48:49] decomb filter thread started for segment 5
[07:48:49] decomb filter thread started for segment 6
[07:48:49] work: only 1 chapter, disabling chapter markers
[07:48:49] decomb filter thread started for segment 7
[07:48:49] job configuration:
[07:48:49] * source
[07:48:49] decomb check thread started for segment 0
[07:48:49] + K:...ate.mpg
[07:48:49] + title 1, chapter(s) 1 to 1
[07:48:49] * destination
[07:48:49] decomb check thread started for segment 1
[07:48:49] + K:...ate.mp4
[07:48:49] decomb check thread started for segment 2
[07:48:49] + container: MPEG-4 (avformat)
[07:48:49] * video track
[07:48:49] decomb check thread started for segment 3
[07:48:49] + decoder: mpeg2
[07:48:49] decomb check thread started for segment 4
[07:48:49] + bitrate 10000 kbps
[07:48:49] + filters
[07:48:49] decomb check thread started for segment 5
[07:48:49] + Decomb (default settings)
[07:48:49] decomb check thread started for segment 6
[07:48:49] + Framerate Shaper (1:27000000:1080000)
[07:48:49] + frame rate: 25.000 fps -> constant 25.000 fps
[07:48:49] + Crop and Scale (720:576:0:0:0:0)
[07:48:49] + source: 720 * 576, crop (0/0/0/0): 720 * 576, scale: 720 * 576
[07:48:49] decomb check thread started for segment 7
[07:48:49] + custom anamorphic
[07:48:49] mask filter thread started for segment 0
[07:48:49] + keeping source display aspect ratio
[07:48:49] mask filter thread started for segment 1
[07:48:49] + storage dimensions: 720 * 576, mod 16
[07:48:49] + pixel aspect ratio: 64 / 45
[07:48:49] mask filter thread started for segment 2
[07:48:49] + display dimensions: 1024 * 576
[07:48:49] + encoder: H.264 (x264)
[07:48:49] + x264 preset: medium
[07:48:49] mask filter thread started for segment 3
[07:48:49] + h264 profile: high
[07:48:49] mask filter thread started for segment 4
[07:48:49] + h264 level: 4.1
[07:48:49] + quality: 25.00 (RF)
[07:48:49] mask filter thread started for segment 5
[07:48:49] * audio track 1
[07:48:49] + decoder: Unknown (MPEG2) (2.0 ch) (track 2, id 0xc0)
[07:48:49] mask filter thread started for segment 6
[07:48:49] + bitrate: 200 kbps, samplerate: 48000 Hz
[07:48:49] + mixdown: Stereo
[07:48:49] + encoder: AAC (avcodec)
[07:48:49] mask filter thread started for segment 7
[07:48:49] + bitrate: 160 kbps, samplerate: 48000 Hz
[07:48:49] mask erode thread started for segment 0
[07:48:49] file is MPEG Program Stream
[07:48:49] mask erode thread started for segment 1
[07:48:49] decomb filter thread started for segment 0
[07:48:49] mask erode thread started for segment 3
[07:48:49] mask erode thread started for segment 4
[07:48:49] mask erode thread started for segment 5
[07:48:49] mask erode thread started for segment 6
[07:48:49] decomb filter thread started for segment 1
[07:48:49] mask dilate thread started for segment 0
[07:48:49] mask dilate thread started for segment 1
[07:48:49] mask dilate thread started for segment 2
[07:48:49] mask dilate thread started for segment 3
[07:48:49] mask dilate thread started for segment 4
[07:48:49] mask dilate thread started for segment 5
[07:48:49] mask dilate thread started for segment 6
[07:48:49] mask dilate thread started for segment 7
[07:48:49] Probing 1 unknown stream
[07:48:49] Probe: Found stream mpeg2video. stream id 0xe0-0x0
[07:48:49] encx264: encoding at constant RF 25.000000
[07:48:49] encx264: unparsed options: level=4.1:vbv-bufsize=78125:vbv-maxrate=62500
[07:48:49] reader: first SCR 288 id 0xe0 DTS 18000
x264 [info]: x264 [info]: [07:48:49] mpeg2: "Chapter 1" (1) at frame 0 time 3600
x264 [info]: [07:48:49] sync: first pts is 3600
[07:54:10] reader: done. 1 scr changes
[07:54:10] work: average encoding speed for job is 131.039429 fps
[07:54:10] sync: got 42173 frames, 41720 expected
[07:54:10] decomb: deinterlaced 29 | blended 41 | unfiltered 42102 | total 42172
[07:54:10] render: 42172 frames output, 0 dropped and 0 duped for CFR/PFR
[07:54:10] render: lost time: 0 (0 frames)
[07:54:10] render: gained time: 0 (0 frames) (0 not accounted for)
[07:54:10] mpeg2 done: 42173 frames
x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: x264 [info]: [07:54:10] mp2-decoder done: 0 frames, 0 decoder errors, 0 drops
[07:54:13] mux: track 0, 42172 frames, 168207411 bytes, 797.68 kbps, fifo 4096
[07:54:13] mux: track 1, 79077 frames, 33823582 bytes, 160.40 kbps, fifo 8192
[07:54:13] stream: 459880 good frames, 0 errors (0%)

Worker process exited unexpectedly; no additional details are available. This may be due to a HandBrake engine crash.

Encode failed.

Job completed (Elapsed Time: 5m 31s)

Queue completed

Sleeping.

Coordinator
Jan 5 at 9:06 PM
I looked into this and it really was a HandBrake crash. On the latest build it doesn't seem to happen, so it should be fixed in the next Beta release of VidCoder.
Marked as answer by jaydear on 1/7/2014 at 2:17 PM
Jan 9 at 2:58 PM
Running the 1.5.14 Beta I get this 100% of the time now. I can't get any video to start the 2nd pass on a 2-pass encode as I get the Handbrake engine crash error. The good thing is I can use vidcoder to set my target size and use the avg bitrate calculation within Handbrake to emulate the Target Size feature.

Anxiously awaiting the next beta release so I can start using Vidcoder again.
Coordinator
Jan 9 at 3:42 PM
You're actually running into a different problem with 2-pass on the x64 version. I'm still investigating that one but you should be able to use the x86 version for now.
Jan 9 at 4:39 PM
Yup, that looks to have done it. the x86 version has gone past the 50% mark (entered successfully into 2nd pass).

Thanks for the suggestion as this lets me continue to use Vidcoder again.
Jan 9 at 9:34 PM
I wondered why this problem was happening and glad to see others addressing it. I thought it was some error I was making or that something new had been added to source material. It should be possible to back out of the beta stuff and install an older version
which, in the event of necessity, I will do. As it is I found my current source responds to my previous methods before using Handbrake and Vidcoder.
Jan 10 at 4:47 AM
Ioninappleton: You can run the stable version in parallel, which I do, but it fails also, but not necessarily with the same settings. I have found that making small changes to settings, e.g. changing Constant Quality by one point up or down or changing x264 preset by one point e.g. from medium to fast does affect whether the 'worker process' fails or not. A quick check I have discovered is to do a preview render. It too will fail to complete if HB objects to something you've set. I have to point out again though, that in my case at least, I can't fault the failed files using VLC and/or MediaInfo.
Coordinator
Jan 12 at 7:06 PM
Okay this should be fixed in 1.5.15 Beta.
Jan 14 at 2:43 AM
Not fixed in .15, still getting it doing 2 pass...

Lost communication with worker process: System.TimeoutException: This request operation sent to net.pipe://localhost/VidCoderWorker.758d46e3-ee8c-4b2a-8041-69161b071fa9 did not receive a reply within the configured timeout (00:00:05). The time allotted to this operation may have been a portion of a longer timeout. This may be because the service is still processing the operation or because the service was unable to send a reply message. Please consider increasing the operation timeout (by casting the channel/proxy to IContextChannel and setting the OperationTimeout property) and ensure that the service is able to connect to the client.

Server stack trace:
at System.ServiceModel.Dispatcher.DuplexChannelBinder.SyncDuplexRequest.WaitForReply(TimeSpan timeout)
at System.ServiceModel.Dispatcher.DuplexChannelBinder.Request(Message message, TimeSpan timeout)
at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)
at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)
at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)

Exception rethrown at [0]:
at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
at VidCoderWorker.IHandBrakeEncoder.Ping()
at VidCoder.RemoteEncodeProxy.<>c__DisplayClass7.<StartEncode>b__6(Object o, ElapsedEventArgs e) in d:\docs\projects\VidCoder\VidCoder\Services\EncodeProxy\RemoteEncodeProxy.cs:line 149

Encode failed.

Job completed (Elapsed Time: 4m 29s)

Coordinator
Jan 14 at 3:12 AM
2-pass is still broken. The original problem (false positive "failed" messages) is fixed.