[BUG] Timecode Problem with Cut Support

[Lloyd Dunamis]

OS: Windows 10 1803
Hybrid Version: 2021.01.31
Input: Recorded by OBS 26.1.1 with NVENC (new), mp4
Intention: Precise cut using Hybrid's experimental Cut Support.

Problem: Muxing crashes because "<name>withTimecodes_0.mp4 was not created!"


Encoding recent OBS-recorded videos (sample) with Cut Support, IIRC start:240 end:820, it's able to encode the video stream successfully, but after all that time crashes upon muxing it and the timecode.
Tested with Cut start 0 and 1078, crashes as well.
Tested with Cut Support off, the file encoded properly, so it might be something about the Cut Support that's bugged.

I've had successes with the Cut Support with other videos, but it's been inconsistent. I was pretty much asking for it because the feature is experimental, but I was hoping that its support could improve further.


Attached are Debug logs, and the temporary Timecodes generated just in case: first the one with custom start & end cut, 2nd with 0 start & end cut, the 3rd one is with Cut Support off.

[Selur]

2021-0314 0220-13ArpieL zerocut & cut off HybridDebugOutput
->
Encoding produced: 1079 frames
Timecode file contains: 1077 frames

2021-0314 0220-13ArpieL inputtimecode & Cutstart0 HybridDebugOutput
-> same issue

2021-0314 0220-13ArpieL HybridDebugOutput
m4fpsmod aborted due to "timecode entry count differs from the movie".
Encoding produced: 1079 frames
Timecode file contains: 580 frames
seems like time codes were cut, but the input to the encoding wasn't


=> Seems like cut support does not properly work with vfr content.
Dropping the time codes (in case they are not needed) or encoding to cfr should help.
Not sure when I'll try to look into this since I doubt I can properly fix it.

Cu Selur

[Selur]

Okay, just tried to reproduce this with my current dev version and here it worked fine with the sample and cut 240-820.
-> will send you a link to a dev version via pm in ~15min.

Cu Selur

[Lloyd Dunamis]

The sent dev version worked! Testing other cuts I remember making that errored, so far they have all worked and properly cut!
Thank you!

It also seems to have fixed the x264>Quantization>Quantizer Max value that gets its max value stuck to just 51, workaroundable by changing to High10 then back but the bug survives even a saving of current x264 setting, that I mentioned in another thread.

=============================
Ramblings now:
I got worried that maybe that 240-820 Cut that I thought I used for the sample I posted wouldn't work, but after testing it myself in the old 2021.01.31 it worked; so that 240-820 Cut I mentioned wasn't even one of the derpy cuts.
But it was fixed anyway. Phew.

I tried resetting the job that had the failed result with the dev version, and it still failed. This made me rethink/understand more how the jobs were dealt with...
As I see it, any job made under (for example) v2021.01.31 will have the bugs of that version, even if that job is processed in a newer fixed version.
Attached debugs just for reference.
[attachment=1352]

=> Seems like cut support does not properly work with vfr content.
Dropping the time codes (in case they are not needed) or encoding to cfr should help.

I was hoping to preserve any VFR-like timeshift that OBS might have recorded in the video.
Though right; no sense in getting the timecodes if the source is already CFR anyway; in this case like the OBS recording sample.

2021-0314 0220-13ArpieL zerocut & cut off HybridDebugOutput
->
Encoding produced: 1079 frames
Timecode file contains: 1077 frames

Probably not related to the timecode and produced encoding frames at all, but this reminded me (and low priority, if it doesn't affect anything major).
There's I think an inconsistency in the displayed number of frames in the video stats, and the maximum mentioned in the max number of frames in the Cut.
Using the same given sample, the Video stat reads 1079, but the max I can put in the End Cut is 1078 (natural numbers vs integers, I thought). When I put 820 in the End Cut though (still 0 at Start Cut), the video stats' frame count reads 820 instead of like 821.

I got curious. Experimenting further, when I enter 1019, it reads 1019. With 1020 however, the video stats reads 1079. From 1020 to 1078, the video stats read 1079. This is a 60fps video.
Trying other videos, a 30fps 300-frame video was able to output the frames the same as whatever I put in it.
Meanwhile with a 30fps 44789-frame video, the video stats only changed down to 44759 (44760 to 44789 in End Cut all read 44789). With Start & End Cuts at 20 and 44779 respectively (=30), stat reads 44759; at 20 and 44780, stat reads 44789.
   

[Selur]

There's I think an inconsistency in the displayed number of frames in the video stats, and the maximum mentioned in the max number of frames in the Cut.

Frame number in the cut is calculated from the inputFrameRate and the inputFrameCount.
It does look at the time code count when the source is vfr.
+ Rounding errors might occur.

Cu Selur

[Lloyd Dunamis]

Ahh, it still got problems with actual vfr or only-vfr-labeled files.
Used ver: dev_2021.03.14-20413

Video was recorded using old OBS-recorded files (Classic even, not Studio), and it outputs a somewhat vfr encoding when CFR isn't checked. Unfortunately, I cannot up this sample as this one I'm encoding is recorded lossless (6GB).

On my encoding attempts, I stop it midway when the estimates tell me it's going to encode the whole thing instead of the cuts I applied.

Debug 1 (vfr to cfr, inconsistent), forgot what exact things I did here. Put for reference.

Debug 2 (Fail then success)

• Tried several cut encodes, including 4050-4618 (fail)
  
• Tried Cut 0-340 (fail)
  
• Turned on Config>Input>CFR output
  
• Tried Cut 0-340 (fail)
  
• Turned off Config>Input>CFR output
  
• (Saved Global/Config settings then) Reboot Hybrid
  
• Tried the job-saved 0-340 (fail)
  
• Open/Load up file
  
• Tried Cut 0-340 (success)
  
• Tried Cut 4050-4618 that failed before (success, finished)
  

I couldn't identify why it's inconsistent like this, using the same encode settings & cuts but failing then succeeding.

[Selur]

For the future: Do not post a debug output containing the processing of multiple jobs, since I have not clue which part of the debug output is important I have to read the whole thing which really takes a lot of my free time.
So if you do it again, do not be surprised then I simply tell you to fuck off. 


Looking at "HybridDebugOutput vfr to cfr, inconsistent.txt"

Looking at the processing of job 2021-03-16@13_50_54_8110:
1st subjob processed is 2021-03-16@13_50_54_8110_01_audio which extracts the audio using:

"C:\Program Files\Hybrid\64bit\ffmpeg.exe" -y -threads 4 -ignore_editlist true -i "D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL.mp4" -map 0:0 -vn -sn -t 00:00:05.666 -acodec copy -map_metadata -1 -metadata encoding_tool="Hybrid 2021.03.14.1" "C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_50_54_8110_01.aac"

it finished after 00:00:00.254 and created C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_50_54_8110_01.aac (0.118719 MB)
2nd job is 2021-03-16@13_50_54_8110_02_video which encodes the video using: (line 75632)

"C:\Program Files\Hybrid\64bit\ffmpeg.exe" -y -loglevel fatal -noautorotate -nostdin -threads 4 -ignore_editlist true -i "D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL.mp4" -map 0:1 -an -sn -t 00:00:05.666 -pix_fmt yuv420p -vsync 0 -f rawvideo - | "C:\Program Files\Hybrid\64bit\x264.exe" --preset veryslow --crf 19.50 --profile high --level 4.2 --ref 5 --keyint 600 --min-keyint 30 --b-adapt 1 --sync-lookahead 1 --rc-lookahead 40 --no-fast-pskip --subme 7 --aq-mode 2 --threads 1 --sar 1:1 --non-deterministic --demuxer raw --input-res 1920x1080 --input-csp i420 --input-depth 8 --fps 60/1 --stitchable --output-depth 8 --output "C:\Users\User\AppData\Local\Temp\2021-03-16@13_50_54_8110_02.264" -

in the middle of the video encoding a new job is created which really helps reading the debug output. 
encoding finished after 00:01:28.680, encoded 340 frames, 3.85 fps, 8680.35 kb/s and created C:\Users\User\AppData\Local\Temp\2021-03-16@13_50_54_8110_02.264 (5.86374 MB)
3rd subjob is 2021-03-16@13_50_54_8110_03_muxing which muxes the audio and video using:

MP4Box -add "C:\Users\User\AppData\Local\Temp\2021-03-16@13_50_54_8110_02.264"#video:fps=60:name="UTC 2018-03-06 16:56:30":lang="" -brand avc1 -add "C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_50_54_8110_01.aac"#audio:name="":lang="en" -mpeg4 -itags tool="Hybrid 2021.03.14.1" -tmp "C:\Users\User\AppData\Local\Temp" -new "D:\Videos\ArpieL\2021-03-16@13_50_54_8110__03.mp4"

is finished after 00:00:00.347 and created D:\Videos\ArpieL\2021-03-16@13_50_54_8110__03.mp4 (5.98646 MB).
4th subjob is 2021-03-16@13_50_54_8110_04_cleanUp which simply deletes 
"C:\Users\User\AppData\Local\Temp\2021-03-16@13_50_54_8110_02.264"
5th subjob is 2021-03-16@13_50_54_8110_05_cleanUp which simply deletes

"C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_50_54_8110_01.aac"

6th subjob is 2021-03-16@13_50_54_8110_06_rename which renames D:\Videos\ArpieL\2021-03-16@13_50_54_8110__03.mp4 to D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL_0-340.mp4
Job 2021-03-16@13_50_54_8110 finished without any errors.
No time code handling at all.

Looking at the processing of job 2021-03-16@13_51_51_0410:
1st subjob is 2021-03-16@13_51_51_0410_01_audio which extracts the audio using:[/b][/b]

"C:\Program Files\Hybrid\64bit\ffmpeg.exe" -y -threads 4 -ignore_editlist true -i "D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL.mp4" -map 0:0 -vn -sn -t 00:00:05.666 -acodec copy -map_metadata -1 -metadata encoding_tool="Hybrid 2021.03.14.1" "C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_51_51_0410_01.aac"

it finished after 00:00:00.252 and created C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_51_51_0410_01.aac (0.118719 MB)
2nd subjob is 2021-03-16@13_51_51_0410_02_create which creates a time code file "C:\Users\User\AppData\Local\Temp\timecodeV2_2021-03-16@13_51_51_0410.tc"
->Seems like this time codes were not ignored.
3rd subjob is 2021-03-16@13_51_51_0410_03_video which encodes the video using:

"C:\Program Files\Hybrid\64bit\ffmpeg.exe" -y -loglevel fatal -noautorotate -nostdin -threads 4 -ignore_editlist true -i "D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL.mp4" -map 0:1 -an -sn -t 00:00:05.666 -pix_fmt yuv420p -vsync 0 -f rawvideo - | "C:\Program Files\Hybrid\64bit\x264.exe" --preset veryslow --crf 19.50 --profile high --level 4.2 --ref 5 --keyint 600 --min-keyint 30 --b-adapt 1 --sync-lookahead 1 --rc-lookahead 40 --no-fast-pskip --subme 7 --aq-mode 2 --threads 1 --sar 1:1 --non-deterministic --demuxer raw --input-res 1920x1080 --input-csp i420 --input-depth 8 --fps 60/1 --stitchable --output-depth 8 --output "C:\Users\User\AppData\Local\Temp\2021-03-16@13_51_51_0410_03.264" -

it encoded 340 frames, 3.79 fps, 8680.35 kb/s, finished after 00:01:29.883 and created C:\Users\User\AppData\Local\Temp\2021-03-16@13_51_51_0410_03.264 (5.86374 MB)
4th subjob is 2021-03-16@13_51_51_0410_04_muxing which muxes the video into an mp4 container using:

"C:\Program Files\Hybrid\64bit\MP4Box.exe" -add "C:\Users\User\AppData\Local\Temp\2021-03-16@13_51_51_0410_03.264" -brand avc1 -tmp "C:\Users\User\AppData\Local\Temp" -new "D:\Videos\ArpieL\2021-03-16@13_51_51_0410__04_mp4Temp.mp4"

it finished after 00:00:00.449 and created created D:\Videos\ArpieL\2021-03-16@13_51_51_0410__04_mp4Temp.mp4 (5.86784 MB)
5th subjob is 2021-03-16@13_51_51_0410_05_cleanUp, which deletes "C:\Users\User\AppData\Local\Temp\2021-03-16@13_51_51_0410_03.264"
6th subjob is 2021-03-16@13_51_51_0410_06_muxing, which tries to add the time codes to the mp4 file using:

"C:\Program Files\Hybrid\64bit\mp4fpsmod.exe" -t "C:\Users\User\AppData\Local\Temp\timecodeV2_2021-03-16@13_51_51_0410.tc" -x "D:\Videos\ArpieL\2021-03-16@13_51_51_0410__04_mp4Temp.mp4" -o "D:\Videos\ArpieL\2021-03-16@13_51_51_0410__06_withTimeCodes_0.mp4"

it found 340 frames: time delta 16.6676 finished after 00:00:00.168 and created D:\Videos\ArpieL\2021-03-16@13_51_51_0410__06_withTimeCodes_0.mp4 (5.8709 MB)
7th subjob is 2021-03-16@13_51_51_0410_07_cleanUp which deletes "D:\Videos\ArpieL\2021-03-16@13_51_51_0410__04_mp4Temp.mp4"
8th subjob is 2021-03-16@13_51_51_0410_08_cleanUp which deletes "C:\Users\User\AppData\Local\Temp\timecodeV2_2021-03-16@13_51_51_0410.tc"
9th subjob is 2021-03-16@13_51_51_0410_09_rename which renames D:\Videos\ArpieL\2021-03-16@13_51_51_0410__06_withTimeCodes_0.mp4 to  D:\Videos\ArpieL\2021-03-16@13_51_51_0410__06_mp4Temp.mp4
10th subjob is 2021-03-16@13_51_51_0410_10_muxing which muxes  audio and video (with time codes) using:

"C:\Program Files\Hybrid\64bit\MP4Box.exe" -add "D:\Videos\ArpieL\2021-03-16@13_51_51_0410__06_mp4Temp.mp4" -add "C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_51_51_0410_01.aac"#audio:name="":lang="en" -mpeg4 -itags tool="Hybrid 2021.03.14.1" -tmp "C:\Users\User\AppData\Local\Temp" -new "D:\Videos\ArpieL\2021-03-16@13_51_51_0410__10.mp4"

it finished after 00:00:00.429 and created D:\Videos\ArpieL\2021-03-16@13_51_51_0410__10.mp4 (5.98858 MB).
11th subjob is 2021-03-16@13_51_51_0410_11_cleanUp which deletes "D:\Videos\ArpieL\2021-03-16@13_51_51_0410__06_mp4Temp.mp4"
12th subjob is 2021-03-16@13_51_51_0410_12_cleanUp which deletes "C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_51_51_0410_01.aac"
13th subjob is 2021-03-16@13_51_51_0410_13_rename which renames D:\Videos\ArpieL\2021-03-16@13_51_51_0410__10.mp4 to D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL_0-340 vfrstay.mp4
Job 2021-03-16@13_51_51_0410 finished!

<<< QUEUE FINISHED !!!! >>>> (line 207790)
Then you resetted job 2021-03-16@02_52_20_2310 and started it.

Looking at the processing of 2021-03-16@02_52_20_2310:
1st subjob is 2021-03-16@02_52_20_2310_01_audio which extracts the audio using:

"C:\Program Files\Hybrid\64bit\ffmpeg.exe" -y -threads 4 -ignore_editlist true -i "D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL.mp4" -map 0:0 -vn -sn -ss 00:00:36.866 -t 00:00:11.200 -acodec copy -map_metadata -1 -metadata encoding_tool="Hybrid 2021.03.14.1" "C:\Users\User\AppData\Local\Temp\iId_5_aid_0_lang_en_2021-03-16@02_52_20_2310_01.aac"

it finished after 00:00:05.826 and created C:\Users\User\AppData\Local\Temp\iId_5_aid_0_lang_en_2021-03-16@02_52_20_2310_01.aac (0.23377 MB)
2nd subjob is 2021-03-16@02_52_20_2310_02_create which created the time code file "C:\Users\User\AppData\Local\Temp\timecodeV2_2021-03-16@02_52_20_2310.tc"
3rd subjob is 2021-03-16@02_52_20_2310_03_video which encodes the video using:

C:\Program Files\Hybrid\64bit\ffmpeg.exe" -y -loglevel fatal -noautorotate -nostdin -threads 4 -ignore_editlist true -i "D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL.mp4" -map 0:1 -an -sn -pix_fmt yuv420p -vsync 0 -f rawvideo - | "C:\Program Files\Hybrid\64bit\x264.exe" --preset veryslow --crf 19.50 --profile high --level 4.2 --ref 5 --keyint 600 --min-keyint 30 --b-adapt 1 --sync-lookahead 1 --rc-lookahead 40 --no-fast-pskip --subme 7 --aq-mode 2 --threads 1 --sar 1:1 --non-deterministic --demuxer raw --input-res 1920x1080 --input-csp i420 --input-depth 8 --fps 60/1 --stitchable --output-depth 8 --output "C:\Users\User\AppData\Local\Temp\2021-03-16@02_52_20_2310_03.264" -

which you stopped after 266 frames.

Then you created a new job with start: 36.8667, end: 48.0667, length: 235.866.

Looking at the processing of 2021-03-16@13_56_59_2110:
1st subjob 2021-03-16@13_56_59_2110_01_audio extracts the audio using:

"C:\Program Files\Hybrid\64bit\ffmpeg.exe" -y -threads 4 -ignore_editlist true -i "D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL.mp4" -map 0:0 -vn -sn -ss 00:00:36.866 -t 00:00:11.200 -acodec copy -map_metadata -1 -metadata encoding_tool="Hybrid 2021.03.14.1" "C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_56_59_2110_01.aac"

2nd subjob is 2021-03-16@13_56_59_2110_02_create which creates a time code file C:\Users\User\AppData\Local\Temp\timecodeV2_2021-03-16@13_56_59_2110.tc
(looking at the time code file I see a potential problem, the first time code is 1 not zero)
3rd subjob is 2021-03-16@13_56_59_2110_03_video which encodes the video using:[/b]

"C:\Program Files\Hybrid\64bit\ffmpeg.exe" -y -loglevel fatal -noautorotate -nostdin -threads 4 -ignore_editlist true -i "D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL.mp4" -map 0:1 -an -sn -ss 00:00:36.866 -t 00:00:11.200 -pix_fmt yuv420p -vsync 0 -f rawvideo - | "C:\Program Files\Hybrid\64bit\x264.exe" --preset veryslow --crf 19.50 --profile high --level 4.2 --ref 5 --keyint 600 --min-keyint 30 --b-adapt 1 --sync-lookahead 1 --rc-lookahead 40 --no-fast-pskip --subme 7 --aq-mode 2 --threads 1 --sar 1:1 --non-deterministic --demuxer raw --input-res 1920x1080 --input-csp i420 --input-depth 8 --fps 60/1 --stitchable --output-depth 8 --output "C:\Users\User\AppData\Local\Temp\2021-03-16@13_56_59_2110_03.264" -

it encoded 672 frames, 3.27 fps, 10176.77 kb/s, finished after 00:03:26.069 and C:\Users\User\AppData\Local\Temp\2021-03-16@13_56_59_2110_03.264 (13.5875 MB)
4th subjob is 2021-03-16@13_56_59_2110_04_muxing which muxes the video into an mp4 container using:

"C:\Program Files\Hybrid\64bit\MP4Box.exe" -add "C:\Users\User\AppData\Local\Temp\2021-03-16@13_56_59_2110_03.264" -brand avc1 -tmp "C:\Users\User\AppData\Local\Temp" -new "D:\Videos\ArpieL\2021-03-16@13_56_59_2110__04_mp4Temp.mp4"

it finished after 00:00:00.441 and created D:\Videos\ArpieL\2021-03-16@13_56_59_2110__04_mp4Temp.mp4 (13.5948 MB)
5th subjob is 2021-03-16@13_56_59_2110_05_cleanUp which deletes "C:\Users\User\AppData\Local\Temp\2021-03-16@13_56_59_2110_03.264"
6th subjob is 2021-03-16@13_56_59_2110_06_muxing which muxes the video and the time codes using:[/b]

"C:\Program Files\Hybrid\64bit\mp4fpsmod.exe" -t "C:\Users\User\AppData\Local\Temp\timecodeV2_2021-03-16@13_56_59_2110.tc" -x "D:\Videos\ArpieL\2021-03-16@13_56_59_2110__04_mp4Temp.mp4" -o "D:\Videos\ArpieL\2021-03-16@13_56_59_2110__06_withTimeCodes_0.mp4"

672 frames: time delta 16.6667 it finished after 00:00:00.256 and created D:\Videos\ArpieL\2021-03-16@13_56_59_2110__06_withTimeCodes_0.mp4 (13.5998 MB)
(seems like the non zero starting time code didn't cause a problem)
7th subjob is 2021-03-16@13_56_59_2110_07_cleanUp which deletes "D:\Videos\ArpieL\2021-03-16@13_56_59_2110__04_mp4Temp.mp4"
8th subjob is 2021-03-16@13_56_59_2110_08_cleanUp which deletes "C:\Users\User\AppData\Local\Temp\timecodeV2_2021-03-16@13_56_59_2110.tc"
9th subjob is 2021-03-16@13_56_59_2110_09_rename which renames D:\Videos\ArpieL\2021-03-16@13_56_59_2110__06_withTimeCodes_0.mp4 to D:\Videos\ArpieL\2021-03-16@13_56_59_2110__06_mp4Temp.mp4[/b]
10th subjob is 2021-03-16@13_56_59_2110_10_muxing which muxes the audio and the video (with time codes) using:

"C:\Program Files\Hybrid\64bit\MP4Box.exe" -add "D:\Videos\ArpieL\2021-03-16@13_56_59_2110__06_mp4Temp.mp4" -add "C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_56_59_2110_01.aac"#audio:name="":lang="en" -mpeg4 -itags tool="Hybrid 2021.03.14.1" -tmp "C:\Users\User\AppData\Local\Temp" -new "D:\Videos\ArpieL\2021-03-16@13_56_59_2110__10.mp4"

it finished after 00:00:00.423 and created D:\Videos\ArpieL\2021-03-16@13_56_59_2110__10.mp4 (13.8319 MB)
11th subjob is 2021-03-16@13_56_59_2110_11_cleanUp which deletes "D:\Videos\ArpieL\2021-03-16@13_56_59_2110__06_mp4Temp.mp4"
12th subjob is 2021-03-16@13_56_59_2110_12_cleanUp which deletes "C:\Users\User\AppData\Local\Temp\iId_1_aid_0_lang_en_2021-03-16@13_56_59_2110_01.aac"
13th subjob is 2021-03-16@13_56_59_2110_13_rename which renames D:\Videos\ArpieL\2021-03-16@13_56_59_2110__10.mp4 to D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL_2212-2884 vfrstay.mp4
<<< QUEUE FINISHED !!!! >>>>

So first I spend and hour reading a "HybridDebugOutput vfr to cfr, inconsistent.txt" which contains no contained no problems,....

Looking at "HybridDebugOutput fail then success.txt".

Looking at job 2021-03-16@14_15_50_2510:
1st job extracted the audio
2nd job created a time code file
3rd job wanted to encode video but was stopped by you


Looking at job 2021-03-16@14_16_40_3410:
1st job extracted the audio
2nd job created a time code file
3rd job wanted to encode video but was stopped by you


This is getting annoying,...

Looking at job 2021-03-16@14_25_26_7310:
1st job extracted the audio
2nd job created a time code file
3rd job wanted to encode video but was stopped by you

I start to see a pattern,..

Looking at job 2021-03-16@14_26_17_4010:
1st job extracted the audio
2nd job created a time code file
3rd job wanted to encode video but was stopped by you

Yes, if you press the stop button Hybrid will stop the processing the job,...


Looking at job 2021-03-16@14_26_47_7910:
1st job extracted the audio
2nd job created a time code file
3rd job wanted to encode video but was stopped by you
   

Looking at job 2021-03-16@14_27_27_4410:
same old same old:

2021.03.16 - 14:27:50_Windows 10 Version 1803 (64bit)_2021.03.14.1 - level 9: x264 output: 71 frames: 3.28 fps, 10367.30 kb/s
2021.03.16 - 14:27:50_Windows 10 Version 1803 (64bit)_2021.03.14.1 - level 9: x264 output: 74 frames: 3.36 fps, 10014.62 kb/s
2021.03.16 - 14:27:51_Windows 10 Version 1803 (64bit)_2021.03.14.1 - level 9: on_stopJobPushButton_clicked
2021.03.16 - 14:27:51_Windows 10 Version 1803 (64bit)_2021.03.14.1 - level 9:  -> calling STOP for:
  2021-03-16@14_27_27_4410
2021.03.16 - 14:27:51_Windows 10 Version 1803 (64bit)_2021.03.14.1 - level 9: stopJobs called:
  2021-03-16@14_27_27_4410
2021.03.16 - 14:27:51_Windows 10 Version 1803 (64bit)_2021.03.14.1 - level 9: stopping Client local for parent 2021-03-16@14_27_27_4410
2021.03.16 - 14:27:51_Windows 10 Version 1803 (64bit)_2021.03.14.1 - level 9: Kill all processes of this job!
2021.03.16 - 14:27:51_Windows 10 Version 1803 (64bit)_2021.03.14.1 - level 9: Killing helper,...
2021.03.16 - 14:27:51_Windows 10 Version 1803 (64bit)_2021.03.14.1 - level 9: Killing process,...
2021.03.16 - 14:27:51_Windows 10 Version 1803 (64bit)_2021.03.14.1 - level 9: set 'STOPPED' for: 2021-03-16@14_27_27_4410_03_video

Looking at job 2021-03-16@14_28_16_8910:
1st job extracted the audio
2nd job wanted to encode video but was stopped by you

Now I'm getting curious, whether there will be a job procesisng which isn't stopped,...

Looking at job 2021-03-16@14_33_59_5710:
1st job extracted the audio
2nd job created a time code file
3rd job wanted to encode video but was stopped by you
   
not this one apperently

Looking at job 2021-03-16@14_34_34_2410:
-> this one wasn't stopped and finished!!!

<<< QUEUE FINISHED !!!! >>>>


So my conclusion is that it does not seem like a bug in Hybrid, but you or your system pressing the Stop JobPushButton (or selecting a job and using the popup menu to stop the job).

Cu Selur

[Lloyd Dunamis]

Whoa, Hoooooly carp I did not mean to be rude by the submission of multiple logs & jobs w/o verbose explanation I'm sorry! @~@;
I should not have included the 1st debug log even as some kind of reference. I thought of enumerating the jobs I remember doing for it, but forgot what exactly I did and in what order, because when I thought of enumerating that I had created the 2nd debug log already, which I actually had enumerated things for.

I pointed out earlier that "On my encoding attempts, I stop it midway when the estimates tell me it's going to encode the whole thing instead of the cuts I applied."
Though I realized only now what I failed telling: there was no error that occurred here; instead, it was not applying the custom cuts I put there. I started including "stopped" in one of my enumeration of activities I wrote earlier, but retracted it because I thought it would be redundant to the earlier note that "I stopped the job midway".

Anyway, the point of the debug logs was not for the finishing of the encoding, but of the job creation or how it extracted & processed its initialization. By that, it was intentional that I included multiple jobs in the debug log, from the creation of the job with the desired encoding settings & cuts, up to its stoppage or of letting it finish. I was hoping you'd get a pattern from the debug as to why it wouldn't process only the cuts I applied.

The moment it estimated that it's going to take an hour or so, it has already failed its job of following what I told it to do, so I stopped it.
I let the last job finish because I haven't gotten a proper output of that particular cut yet...and to see if it will succeed, which it did. This was the part about "failing then succeeding" (what a failed vague phrase I put there, I'm sorry), where an earlier attempt for cut 4050-4618 failed to be followed (2021-03-16@14_25_26_7310), then the next one I tried succeeded (2021-03-16@14_34_34_2410).


I was unable to think of anything else for having you get troubled with reading all that w/o enough verbose context, nor unable to sleep until I can finish at least this message first...though, all my fault, really... I'll be more considerate with the production of debug logs next time.

[Selur]

Okay,...
to determine whether your cur settings are applied looking at the jobs should be enough,..
If you disable 'Jobs->Base->Queue->Minimize job command line' you can the the whole encoding call.
The beginning of the call is the decoding call for example:

ffmpeg -y -ss 00:00:07.500 -loglevel fatal -noautorotate -nostdin -threads 4 -ignore_editlist true -i "D:\Videos\ArpieL\2018-03-07-0052-32_ArpieL.mp4" -map 0:1 -an -sn -ss 00:01:00.000 -t 00:00:09.466 -pix_fmt yuv420p -vsync 0 -f rawvideo - | ...

Note that there is '-ss 00:00:07.500' before the input and "-ss 00:01:00.000 -t 00:00:09.466" after the input.
(see: https://trac.ffmpeg.org/wiki/Seeking if you want to understand why)

If Hybrid does not add those cut/seek entries in a call where it should do so, create a debug output of the job creating and I can look at it.

Also if you do different things, use different sources create a new debug output.

Cu Selur