Stutter in source causes loss of video (possible Handbrake issue), add warning?

[lambdan]

I'm ripping and transcoding my Sopranos DVD boxset. Luckily for me I started also watching the show before finishing all of the episodes (about 25% left) and I noticed S01E01 ended at 53:15 (it's susposed to be around 1 hour). So I went to look at the log for the particular episode and see this:

Encoding: task 1 of 1, 88.58 % (139.56 fps, avg 137.33 fps, ETA 00h01m15s) 
Encoding: task 1 of 1, 88.62 % (139.56 fps, avg 137.33 fps, ETA 00h01m15s)[18:12:38] reader: done. 1 scr changes

Encoding: task 1 of 1, 88.68 % (139.56 fps, avg 137.33 fps, ETA 00h01m15s)
Encoding: task 1 of 1, 88.68 % (139.56 fps, avg 137.33 fps, ETA 00h01m15s)[18:12:39] work: average encoding speed for job is 137.333069 fps

Encoding: task 1 of 1, 88.68 % (139.56 fps, avg 137.33 fps, ETA 00h01m15s)[18:12:39] sync: got 79895 frames, 90088 expected
[18:12:39] render: lost time: 0 (0 frames)
[18:12:39] render: gained time: 0 (0 frames) (0 not accounted for)
[18:12:39] mpeg2video-decoder done: 79895 frames, 0 decoder errors, 0 drops

I went and checked the raw mkv file (from MakeMKV) and it was full-length, however at the 53:15 mark there is a stutter where it seems to freeze for 1 second (probably from the source dvd being scratched or the dvd-drive being bad I'm guessing.) I tried encoding the same episode using Handbrake GUI (High Profile, burned in subtitles) and the same issue happened there, so it's an issue with Handbrake, and not your script particularly.

So that's fine, I can just re-rip that particular episode (S01E02 and S01E03 from the same disc seems fine) and hope I don't get a stutter in the same spot again. But I would like if your script warned me with something similar to "This transcode is shorter than the source, possibly bad source." and paused the script so I could acknowledge it and know to make a new rip (I made a shell script with a bunch of transcode-video commands for each episode (because some are interlaced and some aren't for example) so I didn't see when it jumped from Encoding: 88.68% to completion because it had moved on to the next episode. I'm now gonna have to check every transcoded episode and make sure I see the credits at the end.

I'm attaching mediainfo for the transcode and raw mkv and log from your script. s01e01.mp4.log.txt mediainfo_title00.mkv.txt mediainfo_s01e01.mp4.txt

Here's the transcode-video command I used for S01E01:

transcode-video --mp4 --720p --burn-subtitle 1 --filter deinterlace=1 /Volumes/1tb/SOPRANOS_SEASON1_DISC2/title00.mkv --o "Sopranos S01E04 [swesub-burned, dvdrip, x264, donmelton-script, 2-1-2016].mp4"

[lambdan]

I wrote a little Python script to solve it for me in the meantime. It reads the log files your script creates to see where the source file is, then mediainfo's that and the transcoded output and compares the duration output from mediainfo.

import os
from subprocess import check_output

SOURCE_TIME = 0
TRANSCODE_TIME = 0

for file in os.listdir('.'):
    if file.endswith(".log"):
        for line in open(file):
            if "Opening " in line: # find source in the log
                #print "Log file: " + file
                SOURCE = line[8:-4] # strip Opening and ...
                if not os.path.exists(SOURCE): # check if source exists
                    exit("Source file " + SOURCE + " not found")

                TRANSCODE = file[:-4] # strip .log, should be transcoded file
                if not os.path.exists(TRANSCODE):
                    exit("Transcoded file " + TRANSCODE + " not found")

                for line in check_output(["mediainfo", SOURCE]).split('\n'):
                    if "Duration" in line:
                        DATA = line.split(':',1) # only split 1 so we don't split the timestamp
                        SOURCE_TIME = DATA[1].strip() # duration time, remove spaces
                        break

                for line in check_output(["mediainfo", TRANSCODE]).split('\n'):
                    if "Duration" in line:
                        DATA = line.split(':',1) # only split 1 so we don't split the timestamp
                        TRANSCODE_TIME = DATA[1].strip() # duration time, remove spaces
                        break

                if SOURCE_TIME == TRANSCODE_TIME:
                    print TRANSCODE + ": Good (" + TRANSCODE_TIME + " == " + SOURCE_TIME + ")"
                else:
                    print TRANSCODE + ": Bad (" + TRANSCODE_TIME + " != " + SOURCE_TIME + "), source file: " + SOURCE

Usage:

djss-Mac-Pro:a djs$ python check_length.py | grep "Bad"
s01e01.mp4: Bad (53mn 15s != 1h 0mn), source file: /Volumes/1tb/advent/SOPRANOS_SEASON1_DISC1/title00.mkv
Sopranos S01E12 [swesub-burned, dvdrip, x264, donmelton-script, 2-1-2016].mp4: Bad (43mn 37s != 47mn 24s), source file: /Volumes/1tb/advent/SOPRANOS_SEASON1_DISC4/title02.mkv
Sopranos S05E07 [swesub-burned, dvdrip, x264, donmelton-script, 2-1-2016].mp4: Bad (47mn 51s != 54mn 56s), source file: /Volumes/1tb/advent/SOPRANOS_SEASON5_DISC3/title00.mkv

Turns out I had a few bad ones =)

[lisamelton]

@lambdan Yikes! I've never seen that error before. I may have to haul out my old "Sopranos" DVDs to see if it happens to me.

This is definitely a HandBrake decoder failure as the log indicates. But it's unclear whether that failure is due to errors in the original media or the ripped MKV file.

Does HandBrake return an error code when this happens? Because if it doesn't, it's very hard for me to issue a warning from my code.

[lambdan]

@donmelton Please note that I'm in Sweden so I have PAL DVD which runs at 25 fps which is annoying in a lot of ways (every second there is a judder, like the motion slows down for a split second that continues again, probably PAL 4% speedup related, and I don't think there is anything I can do about that)

You'll probably not notice the same thing anyway because I just did a new rip of the disc using MakeMKV and it worked fine now in Handbrake, so the first rip was just a fluke. Probably due to using a very old laptop from 2008 to rip it (My "Mac Pro" doesn't have a disk drive so have to use old laptops I have lying around for ripping the discs.)

As for the warning, no, Handbrake does not report anything. In fact if you run the GUI application it just celebrates and shows the "Your queue is done" message. You could issue a warning from your code since you get the input file and the output file, and run mediainfo on them and compare the lengths (like my Python script above), but that is now entirely up to you if you wanna do it as that script I made fulfills my need (it's not perfect though as it will trigger on a video having a second in difference of length.)

Optimally MakeMKV would have a warning for it so you could notice it immediately and not after having encoded and swapped discs.

My current strategy is to just rip it into MKV, and then throw it into Handbrake and just run it in the Apple TV 2 Preset and on ultrafast preset, takes roughly 1.5 minutes for my i7 to do that and I can just jump to the end of the video and see if the credits are there. If they are, I write out a transcode-video line and add it to my batch file, if it's bad then I re-rip it and try again. After all the transcoding is done I just run check_length.py in the root folder and make sure it's okay.

[lisamelton]

@lambdan OK, that seems like a prudent plan. Since I can't really do anything to help on my end, I'll close this for now.