RandomEngy / VidCoder

A Blu-ray, DVD and video file transcoder for Windows.
http://vidcoder.net
GNU General Public License v2.0
706 stars 42 forks source link

VidCoder Encodes are continually failing whereas Encodes using native Handbrake succeed #1276

Open fbagnato opened 4 months ago

fbagnato commented 4 months ago

Problem Description

I cannot get VidCoder to successfully encode ISO video files.

The encode always fails, usually within minutes of it starting.

I can encode the same file with the same settings in Handbrake without any problems.

What version of VidCoder are you running?

10.14 VelopackInstaller

Encode Log

VC [19:08:43] VidCoder 10.14
VC [19:08:43] Starting job 1/1
VC [19:08:43]   Source path: C:\Users\Flavio\Desktop\The Magnificent Seven.iso
VC [19:08:43]   Destination path: C:\Users\Flavio\Desktop\The Magnificent Seven.mp4
VC [19:08:43]   Title: 1
VC [19:08:43]   Range: All
VC [19:08:43]   Preset: HQ 2160p60 4K AV1 Surround
VC [19:08:43]   Picker: 
VC [19:08:47] Worker ready: Pipe 'VidCoderWorker.8a8ebb7f-355c-4a6f-b7fd-30073918fde9' is open
VC [19:08:47] Connecting to process 13656 on pipe VidCoderWorker.8a8ebb7f-355c-4a6f-b7fd-30073918fde9
HB [19:10:51] hb_init: starting libhb thread
[19:10:51] CPU: Intel(R) Core(TM) i5-3317U CPU @ 1.70GHz
[19:10:51]  - Intel microarchitecture Ivy Bridge
[19:10:51]  - logical processor count: 4
[19:10:51] Intel Quick Sync Video support: no
[19:10:51] hb_scan: path=C:\Users\Flavio\Desktop\The Magnificent Seven.iso, title_index=1
HB src/libbluray/disc/disc.c:437: error opening file BDMV\index.bdmv
src/libbluray/disc/disc.c:437: error opening file BDMV\BACKUP\index.bdmv
[19:10:52] bd: not a bd - trying as a stream/file instead
[19:10:59] scan: DVD has 1 title(s)
[19:10:59] scan: scanning title 1
[19:10:59] scan: duration is 02:02:40 (7360400 ms)
[19:10:59] pgc_id: 1, pgn: 1: pgc: 00000218b40ec860
[19:10:59] scan: checking audio 1
[19:10:59] scan: audio channel is not active
[19:10:59] scan: checking audio 2
[19:10:59] scan: id=0x80bd, lang=Unknown (AC3), 3cc=und ext=0
[19:10:59] scan: title 1 has 9 chapters
[19:10:59] scan: chap 1, 900280 ms
[19:10:59] scan: chap 2, 899880 ms
[19:10:59] scan: chap 3, 900000 ms
[19:10:59] scan: chap 4, 900000 ms
[19:10:59] scan: chap 5, 899760 ms
[19:10:59] scan: chap 6, 900000 ms
[19:10:59] scan: chap 7, 900120 ms
[19:10:59] scan: chap 8, 899760 ms
[19:10:59] scan: chap 9, 160600 ms
[19:10:59] scan: aspect = 16:9
[19:10:59] scan: decoding previews for title 1
[19:10:59] scan: title angle(s) 1
VC E [19:11:22] Operation 'Ping' failed: System.OperationCanceledException: The operation was canceled.
   at System.IO.Pipes.PipeStream.PipeValueTaskSource.GetResult(Int16 token)
   at System.IO.Pipes.PipeStream.PipeValueTaskSource.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
   at System.Threading.Tasks.ValueTask.ValueTaskSourceAsTask.<>c.<.cctor>b__4_0(Object state)
--- End of stack trace from previous location ---
   at PipeMethodCalls.PipeStreamWrapper.SendMessageAsync(MessageType messageType, IMessage payloadObject, CancellationToken cancellationToken)
   at PipeMethodCalls.MethodInvoker`1.GetResponseAsync(SerializedPipeRequest request, CancellationToken cancellationToken)
   at PipeMethodCalls.MethodInvoker`1.GetResponseFromExpressionAsync(Expression expression, CancellationToken cancellationToken)
   at PipeMethodCalls.MethodInvoker`1.InvokeAsync[TResult](Expression`1 expression, CancellationToken cancellationToken)
   at VidCoder.RemoteProxyBase`2.<>c__DisplayClass41_0.<<PrepareWorkerProcessAsync>b__1>d.MoveNext()
VC E [19:11:22] Encode failed with code ErrorProcessCommunication
VC [19:11:22] Job completed (Elapsed Time: 2m 39s)
RandomEngy commented 4 months ago

Does it succeed when you go to Global Options -> Process and uncheck "Use worker process to encode"?

Also it would help if I had some more logs. Global Options -> Advanced -> Logging verbosity -> Extended, then look in %appdata%\VidCoder-Beta\Logs and get the "Encode" and "PipeServer Encode" logs.

fbagnato commented 4 months ago

Hello RandomEngy,

Thanks for your reply.

Sorry I haven't replied earlier but although subscribed to notifications for this thread I didn't receive a notification so I didn't know you replied until I decided to check it days later.

Your suggestion of unchecking "Use worker process to encode" worked.

The encoding goes all the way and completes normally now.

I am now running the encode again with the Logging Verbosity set to Extended to get you the logs you requested.

I will post back once the encode concludes.

Regards,

fbagnato

fbagnato commented 4 months ago

Hello RandomEngy,

OK, turned the "Use worker process to encode" back on and changed the Logging Verbosity set to Extended then reran the test encode which failed.

I have attached all the logs even though you only asked for the "Encode" and "PipeServer Encode" logs.

Hope they help!

Regards,

fbagnato 2024-07-22 13.47.31 Combined.txt 2024-07-22 13.48.06 Combined.txt 2024-07-22 13.48.06 General.txt 2024-07-22 13.48.26 Scan The Magnificent Seven.txt 2024-07-22 13.48.56 Encode The Magnificent Seven.mp4-failed.txt 2024-07-22 13.48.59 PipeServer Encode VidCoderWorker.43cb5f2c-90c8-4601-ab42-8f07ebaaeb71.txt

RandomEngy commented 4 months ago

Thanks for the report. There's some odd stuff happening there. For one, the inter-process messages appear to be delayed by 3 or 4 seconds. Also the progress events are coming in batches. I'm curious, how many cores does your CPU have?

I see the reason for the failure is finding an unexpected message type while reporting progress: it's likely offset in the communication stream, though that shouldn't happen.

Just in case it helps, I'm trying to land a change in HandBrake to make the progress reports less frequent: https://github.com/HandBrake/HandBrake/pull/6200 .

fbagnato commented 4 months ago

Hello RandomEngy,

It is an Intel Core i5-3317U CPU @ 1.70GHz with 2 Cores and 4 Threads.

When I run a VidCoder encode, I have a few programs open and sometimes other things actively running. I rarely run an encode in a clean and quiet environment. I don't know if that is making the failures more frequent. However I can run Handbrake in the same sort of environment without failures.

So do I just wait for a new release of VidCoder then retry it again with "Use worker process to encode" checked, presuming that the problem has been fixed in Handbrake?

Regards,

fbagnato

RandomEngy commented 3 months ago

VidCoder 11.5 Beta includes a change that makes the progress reports less frequent when no updates were found. This might help you; let me know.

fbagnato commented 3 months ago

Hello RandomEngy,

I installed VidCoder 11.5 Beta and ran a test encode.

The problem is still occurring.

Unticking "Use worker process to encode" ensures a full encode without failing.

Regards,

fbagnato

JNavas2 commented 1 week ago

I'm seeing this issue occasionally in 10.15 on normal encodes with "Use worker process to encode" enabled. Usually, a retry will succeed, but of course a lot of time has been wasted. It's a fairly recent problem for me, started sometime in the past few months. I'm reverting to 11.7 Beta to see if that helps. Log from a recent failure attached. 2024-11-11 15.23.18 Encode Hemingway (2021) - S01E03 - The Blank Page (1944-1961) (1080p AMZN WEB-DL x265 t3nzin) HEVC 25.mp4-failed.zip

JNavas2 commented 4 days ago

Alas, while 11.7 Beta worked well on quite a few videos, it just failed the same way (log attached). UPDATE: Retry of that video succeeded. Is there anything else you would like from me? 2024-11-21 06.04.14 Encode failed.zip