Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Truncated BAD encodes (bad sources) being indicated with GREEN queue success status and result=0 in log! #1517

Closed
CollinChaffin opened this issue Aug 3, 2018 · 7 comments

Comments

@CollinChaffin
Copy link

Description of the problem

Encode movie with apparent bad source disc. Handbrake encodes less than 10%, shows a green SUCCESSFUL finish in queue as shown here (last on the list):

snag_8-3-2018_10-28-36

And the end of encode log as:

[04:04:07] libhb: work result = 0

# Encode Completed ...

Yet only after manually determining (obvious in this case) that encode not complete, and parsing through what end as an "error free" return code log, do I see entries like this:

src/libbluray/bluray.c:696: Skipping broken unit at 6708854784
[04:03:57] reader: done. 1 scr changes

As a test, which has only upset me more, when I run this source media through multiple other encoder/video tools that even just copy the streams, literally every one but Handbrake quickly return errors like this (MakeMKV identified source as bad within 2 min into stream RIP and gave a very clear indication there was a problem with source):

snag_8-3-2018_10-59-24

With HB the result of this reported successful encode job is ultimately a truncated 21 minute BAD video file - accompanied with two thumbs up from Handbrake. I do not nor ever have expected Handbrake to work any magic with a bad source, but any encoder should at least know when it has failed due to having a bad source, and in such until now I thought had been properly returning the job as failed on a bad source. My HUGE concern now is as it stands that I have to go back and hand-parse EVERY encode log and watch every video to determine if the job was truly a success because, had this one instead been a 98% complete encode, seeing "success" in both the GUI and looking at the end of the the log for failure (which I would never usually even do unless the job showed as failed) I would have never caught the failure and simply moved it to my library and then wondered why parts either stuttered or did not play at all or in this case, the movie just stopped prematurely. And given this example and depending on how long this bug has been in place, I'm sure it has already occurred for me and this is going to become VERY time-consuming to hand-parse logs or re-run my media through other tools to verify source media was readable or not. Parsing this known bad encode log for the word "errors" renders exactly twelve lines ending in "errors"....and all twelve have ZERO before the word errors. I can't stress enough how big of an issue this is.

With all that said, if possible to nail it down, I would be interested in knowing how long this issue has existed so I can have an idea of just how long I have to back-trace my encodes and manually review all logs to ensure I don't have not yet watched bad encodes (that HB returned as good) now sitting in my media folders. Also, is parsing for "skipping broken unit" in bad HB versions the best/only way to truly determine when an otherwise successful returned job was really a failure due to bad source media? TIA!

Steps to reproduce the problem

Select source
Add to queue
Start encode queue
Encode job shows erroneously shows success

HandBrake version (e.g., 1.0.0)

20180729125104-ecf8523-master (2018073001)

Operating system and version (e.g., Ubuntu 16.04 LTS, macOS 10.3 High Sierra, Windows 10 Creators Update)

Win7x64

Error message text or screenshot

Last job on the list is job in question showing as successful completion:

snag_8-3-2018_10-28-36

HandBrake Activity Log required (see https://handbrake.fr/docs/en/latest/help/activity-log.html)

HandBrake Nightly 20180729125104-ecf8523-master (2018073001)
OS: Microsoft Windows NT 6.1.7601 Service Pack 1
Ram: 16366 MB, 
GPU Information:
  AMD Radeon HD 7470 - 8.922.0.0
  AMD Radeon HD 7470 - 8.922.0.0
Screen: 1920x1080
Temp Dir: C:\Temp\
Install Dir: C:\Program Files\HandBrake Nightly
Data Dir: C:\Users\Encoder\AppData\Roaming\HandBrake\Nightly

-------------------------------------------


# Starting Encode ...

[02:56:28] hb_init: starting libhb thread
[02:56:28] 1 job(s) to process
[02:56:28] json job:
{
  "Audio": {
    "AudioList": [
      {
        "DRC": 0.0,
        "Encoder": "copy",
        "Gain": 0.0,
        "Mixdown": -1,
        "NormalizeMixLevel": false,
        "Samplerate": 48000,
        "Track": 0,
        "DitherMethod": 0
      },
      {
        "DRC": 0.0,
        "Encoder": "copy",
        "Gain": 0.0,
        "Mixdown": -1,
        "NormalizeMixLevel": false,
        "Samplerate": 48000,
        "Track": 1,
        "DitherMethod": 0
      },
      {
        "DRC": 0.0,
        "Encoder": "copy",
        "Gain": 0.0,
        "Mixdown": -1,
        "NormalizeMixLevel": false,
        "Samplerate": 48000,
        "Track": 4,
        "DitherMethod": 0
      }
    ],
    "CopyMask": [
      "copy:ac3",
      "copy:dtshd",
      "copy:dts",
      "copy:truehd"
    ],
    "FallbackEncoder": "ac3"
  },
  "Destination": {
    "ChapterList": [
      {
        "Name": "Chapter 1"
      },
      {
        "Name": "Chapter 2"
      },
      {
        "Name": "Chapter 3"
      },
      {
        "Name": "Chapter 4"
      },
      {
        "Name": "Chapter 5"
      },
      {
        "Name": "Chapter 6"
      },
      {
        "Name": "Chapter 7"
      },
      {
        "Name": "Chapter 8"
      },
      {
        "Name": "Chapter 9"
      },
      {
        "Name": "Chapter 10"
      },
      {
        "Name": "Chapter 11"
      },
      {
        "Name": "Chapter 12"
      },
      {
        "Name": "Chapter 13"
      },
      {
        "Name": "Chapter 14"
      },
      {
        "Name": "Chapter 15"
      },
      {
        "Name": "Chapter 16"
      }
    ],
    "ChapterMarkers": true,
    "AlignAVStart": false,
    "File": "J:\\RIP\\MKV\\Startrek 11.mkv",
    "Mp4Options": {
      "IpodAtom": false,
      "Mp4Optimize": false
    },
    "Mux": "mkv"
  },
  "Filters": {
    "FilterList": [
      {
        "ID": 2,
        "Settings": {}
      },
      {
        "ID": 4,
        "Settings": {
          "mode": "7"
        }
      },
      {
        "ID": 11,
        "Settings": {
          "crop-bottom": "140",
          "crop-left": "0",
          "crop-right": "0",
          "crop-top": "140",
          "height": "800",
          "width": "1920"
        }
      },
      {
        "ID": 6,
        "Settings": {
          "mode": "1"
        }
      }
    ]
  },
  "PAR": {
    "Num": 1,
    "Den": 1
  },
  "Metadata": {},
  "SequenceID": 0,
  "Source": {
    "Angle": 1,
    "Range": {
      "Type": "chapter",
      "Start": 1,
      "End": 16
    },
    "Title": 1,
    "Path": "U:\\"
  },
  "Subtitle": {
    "Search": {
      "Burn": false,
      "Default": true,
      "Enable": true,
      "Forced": true
    },
    "SubtitleList": [
      {
        "Burn": false,
        "Default": false,
        "Forced": false,
        "ID": 1,
        "Offset": 0,
        "Track": 0
      },
      {
        "Burn": false,
        "Default": false,
        "Forced": false,
        "ID": 2,
        "Offset": 0,
        "Track": 1
      }
    ]
  },
  "Video": {
    "Encoder": "x264",
    "Bitrate": 10000,
    "TwoPass": true,
    "Turbo": true,
    "ColorMatrixCode": 0,
    "Options": "weightb=1:open-gop=0:scenecut=40:rc-lookahead=60:chroma-me=1:fast-pskip=0:nr=0:bluray-compat=0:constrained-intra=0:b-bias=0:intra-refresh=0:ref=4:bframes=8:b-adapt=2:direct=auto:me=umh:subme=9:merange=24:analyse=all:no-dct-decimate=1:deblock=-1,-1",
    "QSV": {
      "Decode": true,
      "AsyncDepth": 0
    }
  }
}
[02:56:28] CPU: Intel(R) Core(TM) i7-3770 CPU @ 3.40GHz
[02:56:28]  - Intel microarchitecture Ivy Bridge
[02:56:28]  - logical processor count: 8
[02:56:28] Intel Quick Sync Video support: yes
[02:56:28]  - Intel Media SDK software: API 1.23 (minimum: 1.3)
[02:56:28]  - H.264 encoder: yes
[02:56:28]     - preferred implementation: software (null)
[02:56:28]     - capabilities (software):  bpyramid vsinfo opt1 opt2
[02:56:28]  - H.265 encoder: no
[02:56:28] hb_scan: path=U:\, title_index=1
src/libbluray/bdj/bdj.c:549: libbluray-j2se-1.0.2.jar not found.
src/libbluray/bdj/bdj.c:695: BD-J check: Failed to load libbluray.jar
src/libbluray/bdj/bdj.c:549: libbluray-j2se-1.0.2.jar not found.
src/libbluray/bdj/bdj.c:695: BD-J check: Failed to load libbluray.jar
[02:56:28] scan: BD has 19 title(s)
[02:56:28] bd: scanning title 1
[02:56:28] bd: playlist 00000.MPLS
[02:56:28] bd: duration is 02:06:50 (7610269 ms)
[02:56:28] bd: video id=0x1011, stream type=H.264, format 1080p
[02:56:28] bd: aspect = 16:9
[02:56:28] bd: audio id=0x761100, lang=English (AC3), 3cc=eng
[02:56:28] bd: audio id=0x721100, lang=English (TrueHD), 3cc=eng
[02:56:28] bd: audio id=0x1101, lang=Francais (AC3), 3cc=fra
[02:56:28] bd: audio id=0x1102, lang=español (AC3), 3cc=spa
[02:56:28] bd: audio id=0x1103, lang=English (AC3), 3cc=eng
[02:56:28] bd: subtitle id=0x1200, lang=English [PGS], 3cc=eng
[02:56:28] bd: subtitle id=0x1201, lang=English [PGS], 3cc=eng
[02:56:28] bd: subtitle id=0x1202, lang=Francais [PGS], 3cc=fra
[02:56:28] bd: subtitle id=0x1203, lang=español [PGS], 3cc=spa
[02:56:28] bd: subtitle id=0x1204, lang=Portugues [PGS], 3cc=por
[02:56:28] bd: subtitle id=0x1205, lang=Francais [PGS], 3cc=fra
[02:56:28] bd: subtitle id=0x1206, lang=español [PGS], 3cc=spa
[02:56:28] bd: chap 1 packet=768, 717216 ms
[02:56:28] bd: chap 2 packet=3734035584, 467884 ms
[02:56:28] bd: chap 3 packet=6214336896, 504003 ms
[02:56:28] bd: chap 4 packet=8885081472, 444402 ms
[02:56:28] bd: chap 5 packet=11234502336, 516891 ms
[02:56:28] bd: chap 6 packet=13994168448, 491324 ms
[02:56:28] bd: chap 7 packet=16621220352, 551884 ms
[02:56:28] bd: chap 8 packet=19544962368, 606480 ms
[02:56:28] bd: chap 9 packet=22751003520, 539413 ms
[02:56:28] bd: chap 10 packet=25570130112, 415790 ms
[02:56:28] bd: chap 11 packet=27759434880, 534283 ms
[02:56:28] bd: chap 12 packet=30594421440, 484692 ms
[02:56:28] bd: chap 13 packet=33140312448, 519143 ms
[02:56:28] bd: chap 14 packet=35858720256, 307140 ms
[02:56:28] bd: chap 15 packet=37505899392, 509467 ms
[02:56:28] bd: chap 16 packet=39567801216, 250 ms
[02:56:28] bd: title 1 has 16 chapters
[02:56:28] scan: decoding previews for title 1
[02:56:28] scan: title angle(s) 1
[02:56:28] scan: audio 0x721100: truehd, rate=48000Hz, bitrate=128000 English (TrueHD) (5.1 ch)
[02:56:28] scan: audio 0x1103: ac3, rate=48000Hz, bitrate=224000 English (AC3) (2.0 ch)
[02:56:28] scan: audio 0x761100: ac3, rate=48000Hz, bitrate=640000 English (AC3) (5.1 ch)
[02:56:28] scan: audio 0x1101: ac3, rate=48000Hz, bitrate=640000 Francais (AC3) (5.1 ch)
[02:56:28] scan: audio 0x1102: ac3, rate=48000Hz, bitrate=640000 español (AC3) (5.1 ch)
[02:56:30] scan: 10 previews, 1920x1080, 23.976 fps, autocrop = 140/140/0/0, aspect 16:9, PAR 1:1
[02:56:30] scan: supported video decoders: avcodec qsv
[02:56:30] stream: 10 good frames, 0 errors (0%)
[02:56:30] libhb: scan thread found 1 valid title(s)
[02:56:30] starting job
[02:56:30] yadif thread started for segment 0
[02:56:30] yadif thread started for segment 1
[02:56:30] yadif thread started for segment 3
[02:56:30] yadif thread started for segment 2
[02:56:30] yadif thread started for segment 4
[02:56:30] yadif thread started for segment 5
[02:56:30] yadif thread started for segment 6
[02:56:30] yadif thread started for segment 7
[02:56:30] job configuration:
[02:56:30]  * source
[02:56:30]    + U:\
[02:56:30]    + title 1, chapter(s) 1 to 16
[02:56:30]  * destination
[02:56:30]    + J:\RIP\MKV\Startrek 11.mkv
[02:56:30]    + container: Matroska (libavformat)
[02:56:30]      + chapter markers
[02:56:30]  * video track
[02:56:30]    + decoder: h264_qsv
[02:56:30]      + bitrate 200 kbps
[02:56:30]    + filters
[02:56:30]      + Detelecine (pullup) ()
[02:56:30]      + Decomb (mode=7)
[02:56:30]      + Framerate Shaper (mode=1)
[02:56:30]        + frame rate: 23.976 fps -> constant 23.976 fps
[02:56:30]      + Crop and Scale (width=1920:height=800:crop-top=140:crop-bottom=140:crop-left=0:crop-right=0)
[02:56:30]        + source: 1920 * 1080, crop (140/140/0/0): 1920 * 800, scale: 1920 * 800
[02:56:30]    + Output geometry
[02:56:30]      + storage dimensions: 1920 x 800
[02:56:30]      + pixel aspect ratio: 1 : 1
[02:56:30]      + display dimensions: 1920 x 800
[02:56:30]  * Foreign Audio Search: Passthrough, Forced Only, Default
[02:56:30]    + subtitle, English [PGS] (track 0, id 0x1200, Picture)
[02:56:30]    + subtitle, English [PGS] (track 1, id 0x1201, Picture)
src/libbluray/bdj/bdj.c:549: libbluray-j2se-1.0.2.jar not found.
src/libbluray/bdj/bdj.c:695: BD-J check: Failed to load libbluray.jar
src/libbluray/bdj/bdj.c:549: libbluray-j2se-1.0.2.jar not found.
src/libbluray/bdj/bdj.c:695: BD-J check: Failed to load libbluray.jar
[02:56:30] sync: expecting 182464 video frames
src/libbluray/bluray.c:696: Skipping broken unit at 6708854784
[02:58:20] reader: done. 1 scr changes
[02:58:20] work: average encoding speed for job is 0.000000 fps
[02:58:20] decomb: deinterlaced 0 | blended 0 | unfiltered 0 | total 0
[02:58:20] vfr: 0 frames output, 0 dropped and 0 duped for CFR/PFR
[02:58:20] vfr: lost time: 0 (0 frames)
[02:58:20] vfr: gained time: 0 (0 frames) (0 not accounted for)
[02:58:20] stream: 30674 good frames, 0 errors (0%)
[02:58:20] sync: got 0 frames, 182464 expected
[02:58:20] Subtitle track 0 (id 0x1200) 'English [PGS]': 206 hits (0 forced)
[02:58:20] Subtitle track 1 (id 0x1201) 'English [PGS]': 268 hits (0 forced)
[02:58:20] No candidate detected during subtitle scan
[02:58:20] starting job
[02:58:20] yadif thread started for segment 0
[02:58:20] yadif thread started for segment 1
[02:58:20] yadif thread started for segment 2
[02:58:20] yadif thread started for segment 3
[02:58:20] yadif thread started for segment 4
[02:58:20] yadif thread started for segment 5
[02:58:20] yadif thread started for segment 6
[02:58:20] yadif thread started for segment 7
[02:58:20] Auto Passthru: allowed codecs are AC3, TrueHD, DTS, DTS-HD
[02:58:20] Auto Passthru: fallback is AC3
[02:58:20] Auto Passthru: using AC3 Passthru for track 1
[02:58:20] Auto Passthru: using TrueHD Passthru for track 2
[02:58:20] Auto Passthru: using AC3 Passthru for track 3
[02:58:20] job configuration:
[02:58:20]  * source
[02:58:20]    + U:\
[02:58:20]    + title 1, chapter(s) 1 to 16
[02:58:20]  * destination
[02:58:20]    + J:\RIP\MKV\Startrek 11.mkv
[02:58:20]    + container: Matroska (libavformat)
[02:58:20]      + chapter markers
[02:58:20]  * video track
[02:58:20]    + decoder: h264_qsv
[02:58:20]      + bitrate 200 kbps
[02:58:20]    + filters
[02:58:20]      + Detelecine (pullup) ()
[02:58:20]      + Decomb (mode=7)
[02:58:20]      + Framerate Shaper (mode=1)
[02:58:20]        + frame rate: 23.976 fps -> constant 23.976 fps
[02:58:20]      + Crop and Scale (width=1920:height=800:crop-top=140:crop-bottom=140:crop-left=0:crop-right=0)
[02:58:20]        + source: 1920 * 1080, crop (140/140/0/0): 1920 * 800, scale: 1920 * 800
[02:58:20]    + Output geometry
[02:58:20]      + storage dimensions: 1920 x 800
[02:58:20]      + pixel aspect ratio: 1 : 1
[02:58:20]      + display dimensions: 1920 x 800
[02:58:20]    + encoder: H.264 (libx264)
[02:58:20]      + options: weightb=1:open-gop=0:scenecut=40:rc-lookahead=60:chroma-me=1:fast-pskip=0:nr=0:bluray-compat=0:constrained-intra=0:b-bias=0:intra-refresh=0:ref=4:bframes=8:b-adapt=2:direct=auto:me=umh:subme=9:merange=24:analyse=all:no-dct-decimate=1:deblock=-1,-1
[02:58:20]      + bitrate: 10000 kbps, pass: 1
[02:58:20]      + fast first pass
[02:58:20]      + options: ref=1:8x8dct=0:me=dia:trellis=0
[02:58:20]                 analyse=i4x4 (if originally enabled, else analyse=none)
[02:58:20]                 subq=2 (if originally greater than 2, else subq unchanged)
[02:58:20]  * subtitle track 1, English [PGS] (track 0, id 0x1200, Picture) -> Passthrough
[02:58:20]  * subtitle track 2, English [PGS] (track 1, id 0x1201, Picture) -> Passthrough
[02:58:20]  * audio track 1
[02:58:20]    + decoder: English (AC3) (5.1 ch) (track 1, id 0x761100)
[02:58:20]      + bitrate: 640 kbps, samplerate: 48000 Hz
[02:58:20]    + AC3 Passthru
[02:58:20]  * audio track 2
[02:58:20]    + decoder: English (TrueHD) (5.1 ch) (track 2, id 0x721100)
[02:58:20]      + bitrate: 128 kbps, samplerate: 48000 Hz
[02:58:20]    + TrueHD Passthru
[02:58:20]  * audio track 3
[02:58:20]    + decoder: English (AC3) (2.0 ch) (track 5, id 0x1103)
[02:58:20]      + bitrate: 224 kbps, samplerate: 48000 Hz
[02:58:20]    + AC3 Passthru
src/libbluray/bdj/bdj.c:549: libbluray-j2se-1.0.2.jar not found.
src/libbluray/bdj/bdj.c:695: BD-J check: Failed to load libbluray.jar
src/libbluray/bdj/bdj.c:549: libbluray-j2se-1.0.2.jar not found.
src/libbluray/bdj/bdj.c:695: BD-J check: Failed to load libbluray.jar
[02:58:20] sync: expecting 182464 video frames
[02:58:20] encx264: min-keyint: 24, keyint: 240
[02:58:20] encx264: encoding at average bitrate 10000
[02:58:20] encx264: unparsed options: open-gop=0:rc-lookahead=60:chroma-me=1:fast-pskip=0:nr=0:bluray-compat=0:constrained-intra=0:b-bias=0:intra-refresh=0:ref=4:bframes=8:b-adapt=2:direct=auto:me=umh:subme=9:merange=24:analyse=all:deblock=-1,-1:dct-decimate=0
x264 [info]: using SAR=1/1
x264 [info]: using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX
x264 [info]: profile Main, level 4.0
[02:58:20] sync: first pts audio 0x721100 is 0
[02:58:21] sync: first pts audio 0x1103 is 0
[02:58:21] sync: first pts video is 0
[02:58:21] sync: "Chapter 1" (1) at frame 1 time 0
[02:58:21] sync: first pts audio 0x761100 is 0
[02:59:05] sync: first pts subtitle 0x1201 is 5551796
[02:59:22] sync: first pts subtitle 0x1200 is 7105848
[03:09:34] sync: "Chapter 2" (2) at frame 17197 time 64549485
[03:16:51] sync: "Chapter 3" (3) at frame 28415 time 106659052
src/libbluray/bluray.c:696: Skipping broken unit at 6708854784
[03:18:19] reader: done. 1 scr changes
[03:18:22] work: average encoding speed for job is 25.551609 fps
[03:18:22] decomb: deinterlaced 30672 | blended 0 | unfiltered 0 | total 30672
[03:18:22] vfr: 30674 frames output, 0 dropped and 2 duped for CFR/PFR
[03:18:22] vfr: lost time: 3754 (0 frames)
[03:18:22] vfr: gained time: 3754 (4 frames) (0 not accounted for)
[03:18:22] stream: 30674 good frames, 0 errors (0%)
[03:18:22] ac3-decoder done: 39958 frames, 0 decoder errors
[03:18:22] truehd-decoder done: 1534426 frames, 0 decoder errors
[03:18:22] ac3-decoder done: 39971 frames, 0 decoder errors
[03:18:22] h264_qsv-decoder done: 30673 frames, 0 decoder errors
[03:18:23] sync: got 30673 frames, 182464 expected
[03:18:23] sync: framerate min 7.992 fps, max 23.981 fps, avg 23.974 fps
x264 [info]: frame I:177   Avg QP:15.69  size:159915
x264 [info]: frame P:9051  Avg QP:19.52  size: 71527
x264 [info]: frame B:21446 Avg QP:19.58  size: 42785
x264 [info]: consecutive B-frames:  8.6%  7.9% 15.9% 11.0% 12.0% 35.7%  4.2%  1.8%  2.8%
x264 [info]: mb I  I16..4: 42.6%  0.0% 57.4%
x264 [info]: mb P  I16..4: 69.8%  0.0%  0.0%  P16..4: 26.6%  0.0%  0.0%  0.0%  0.0%    skip: 3.5%
x264 [info]: mb B  I16..4: 26.5%  0.0%  0.0%  B16..8: 29.0%  0.0%  0.0%  direct:23.1%  skip:21.4%  L0:37.4% L1:37.5% BI:25.1%
x264 [info]: final ratefactor: 18.48
x264 [info]: direct mvs  spatial:99.7% temporal:0.3%
x264 [info]: coded y,uvDC,uvAC intra: 82.2% 62.0% 33.5% inter: 36.7% 28.6% 5.0%
x264 [info]: i16 v,h,dc,p: 20% 17% 41% 22%
x264 [info]: i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 17% 17% 17%  9%  9%  8%  8%  8%  7%
x264 [info]: i8c dc,h,v,p: 56% 19% 19%  6%
x264 [info]: Weighted P-Frames: Y:6.1% UV:4.6%
x264 [info]: kb/s:9962.88
[03:18:23] starting job
[03:18:23] yadif thread started for segment 0
[03:18:23] yadif thread started for segment 1
[03:18:23] yadif thread started for segment 2
[03:18:23] yadif thread started for segment 3
[03:18:23] yadif thread started for segment 4
[03:18:23] yadif thread started for segment 5
[03:18:23] yadif thread started for segment 6
[03:18:23] yadif thread started for segment 7
[03:18:23] Auto Passthru: allowed codecs are AC3, TrueHD, DTS, DTS-HD
[03:18:23] Auto Passthru: fallback is AC3
[03:18:23] Auto Passthru: using AC3 Passthru for track 1
[03:18:23] Auto Passthru: using TrueHD Passthru for track 2
[03:18:23] Auto Passthru: using AC3 Passthru for track 3
[03:18:23] job configuration:
[03:18:23]  * source
[03:18:23]    + U:\
[03:18:23]    + title 1, chapter(s) 1 to 16
[03:18:23]  * destination
[03:18:23]    + J:\RIP\MKV\Startrek 11.mkv
[03:18:23]    + container: Matroska (libavformat)
[03:18:23]      + chapter markers
[03:18:23]  * video track
[03:18:23]    + decoder: h264_qsv
[03:18:23]      + bitrate 200 kbps
[03:18:23]    + filters
[03:18:23]      + Detelecine (pullup) ()
[03:18:23]      + Decomb (mode=7)
[03:18:23]      + Framerate Shaper (mode=1)
[03:18:23]        + frame rate: 23.976 fps -> constant 23.976 fps
[03:18:23]      + Crop and Scale (width=1920:height=800:crop-top=140:crop-bottom=140:crop-left=0:crop-right=0)
[03:18:23]        + source: 1920 * 1080, crop (140/140/0/0): 1920 * 800, scale: 1920 * 800
[03:18:23]    + Output geometry
[03:18:23]      + storage dimensions: 1920 x 800
[03:18:23]      + pixel aspect ratio: 1 : 1
[03:18:23]      + display dimensions: 1920 x 800
[03:18:23]    + encoder: H.264 (libx264)
[03:18:23]      + options: weightb=1:open-gop=0:scenecut=40:rc-lookahead=60:chroma-me=1:fast-pskip=0:nr=0:bluray-compat=0:constrained-intra=0:b-bias=0:intra-refresh=0:ref=4:bframes=8:b-adapt=2:direct=auto:me=umh:subme=9:merange=24:analyse=all:no-dct-decimate=1:deblock=-1,-1
[03:18:23]      + bitrate: 10000 kbps, pass: 2
[03:18:23]  * subtitle track 1, English [PGS] (track 0, id 0x1200, Picture) -> Passthrough
[03:18:23]  * subtitle track 2, English [PGS] (track 1, id 0x1201, Picture) -> Passthrough
[03:18:23]  * audio track 1
[03:18:23]    + decoder: English (AC3) (5.1 ch) (track 1, id 0x761100)
[03:18:23]      + bitrate: 640 kbps, samplerate: 48000 Hz
[03:18:23]    + AC3 Passthru
[03:18:23]  * audio track 2
[03:18:23]    + decoder: English (TrueHD) (5.1 ch) (track 2, id 0x721100)
[03:18:23]      + bitrate: 128 kbps, samplerate: 48000 Hz
[03:18:23]    + TrueHD Passthru
[03:18:23]  * audio track 3
[03:18:23]    + decoder: English (AC3) (2.0 ch) (track 5, id 0x1103)
[03:18:23]      + bitrate: 224 kbps, samplerate: 48000 Hz
[03:18:23]    + AC3 Passthru
src/libbluray/bdj/bdj.c:549: libbluray-j2se-1.0.2.jar not found.
src/libbluray/bdj/bdj.c:695: BD-J check: Failed to load libbluray.jar
src/libbluray/bdj/bdj.c:549: libbluray-j2se-1.0.2.jar not found.
src/libbluray/bdj/bdj.c:695: BD-J check: Failed to load libbluray.jar
[03:18:23] sync: expecting 30673 video frames
[03:18:23] encx264: min-keyint: 24, keyint: 240
[03:18:23] encx264: encoding at average bitrate 10000
[03:18:23] encx264: unparsed options: open-gop=0:rc-lookahead=60:chroma-me=1:fast-pskip=0:nr=0:bluray-compat=0:constrained-intra=0:b-bias=0:intra-refresh=0:ref=4:bframes=8:b-adapt=2:direct=auto:me=umh:subme=9:merange=24:analyse=all:deblock=-1,-1:dct-decimate=0
x264 [info]: using SAR=1/1
x264 [info]: using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX
x264 [info]: profile High, level 4.0
[03:18:23] sync: first pts audio 0x721100 is 0
[03:18:24] sync: first pts audio 0x1103 is 0
[03:18:24] sync: first pts audio 0x761100 is 0
[03:18:24] sync: first pts video is 0
[03:18:24] sync: "Chapter 1" (1) at frame 1 time 0
[03:19:42] sync: first pts subtitle 0x1201 is 5551796
[03:20:22] sync: first pts subtitle 0x1200 is 7105848
[03:44:15] sync: "Chapter 2" (2) at frame 17197 time 64549485
[04:00:46] sync: "Chapter 3" (3) at frame 28415 time 106659052
src/libbluray/bluray.c:696: Skipping broken unit at 6708854784
[04:03:57] reader: done. 1 scr changes
[04:04:07] work: average encoding speed for job is 11.197354 fps
[04:04:07] decomb: deinterlaced 30672 | blended 0 | unfiltered 0 | total 30672
[04:04:07] vfr: 30674 frames output, 0 dropped and 2 duped for CFR/PFR
[04:04:07] vfr: lost time: 3754 (0 frames)
[04:04:07] vfr: gained time: 3754 (4 frames) (0 not accounted for)
[04:04:07] stream: 30674 good frames, 0 errors (0%)
[04:04:07] ac3-decoder done: 39958 frames, 0 decoder errors
[04:04:07] truehd-decoder done: 1534426 frames, 0 decoder errors
[04:04:07] ac3-decoder done: 39971 frames, 0 decoder errors
[04:04:07] h264_qsv-decoder done: 30673 frames, 0 decoder errors
[04:04:07] sync: got 30673 frames, 30673 expected
[04:04:07] sync: framerate min 7.992 fps, max 23.981 fps, avg 23.974 fps
x264 [info]: frame I:177   Avg QP:17.15  size:145081
x264 [info]: frame P:9051  Avg QP:19.89  size: 73396
x264 [info]: frame B:21446 Avg QP:20.33  size: 42385
x264 [info]: consecutive B-frames:  8.6%  7.9% 15.9% 11.0% 12.0% 35.7%  4.2%  1.8%  2.8%
x264 [info]: mb I  I16..4: 14.2% 69.1% 16.7%
x264 [info]: mb P  I16..4:  6.0% 29.3%  4.2%  P16..4: 37.5% 13.3%  6.3%  0.2%  0.0%    skip: 3.3%
x264 [info]: mb B  I16..4:  1.0%  4.5%  0.6%  B16..8: 44.1% 11.6%  2.7%  direct:10.5%  skip:25.0%  L0:48.2% L1:46.2% BI: 5.6%
x264 [info]: 8x8 transform intra:74.0% inter:59.2%
x264 [info]: direct mvs  spatial:98.3% temporal:1.7%
x264 [info]: coded y,uvDC,uvAC intra: 86.1% 79.6% 52.9% inter: 46.5% 43.0% 10.5%
x264 [info]: i16 v,h,dc,p: 18% 21% 19% 41%
x264 [info]: i8 v,h,dc,ddl,ddr,vr,hd,vl,hu:  6%  6%  5% 12% 17% 14% 16% 11% 12%
x264 [info]: i4 v,h,dc,ddl,ddr,vr,hd,vl,hu:  5%  6%  2% 12% 17% 15% 18% 12% 14%
x264 [info]: i8c dc,h,v,p: 44% 23% 16% 17%
x264 [info]: Weighted P-Frames: Y:6.1% UV:4.6%
x264 [info]: ref P L0: 53.8% 10.5% 22.0% 12.0%  1.7%  0.1%
x264 [info]: ref B L0: 80.8% 16.1%  3.1%
x264 [info]: ref B L1: 92.3%  7.7%
x264 [info]: kb/s:9998.64
[04:04:07] mux: track 0, 30674 frames, 1598977795 bytes, 9998.60 kbps, fifo 512
[04:04:07] mux: track 1, 39958 frames, 102292480 bytes, 639.65 kbps, fifo 512
[04:04:07] mux: track 2, 1534426 frames, 578997900 bytes, 3620.54 kbps, fifo 32768
[04:04:07] mux: track 3, 39971 frames, 35814016 bytes, 223.95 kbps, fifo 512
[04:04:07] mux: track 4, 411 frames, 5277905 bytes, 33.00 kbps, fifo 16
[04:04:07] mux: track 5, 535 frames, 6521743 bytes, 40.78 kbps, fifo 32
[04:04:07] libhb: work result = 0

# Encode Completed ...


@woodstockathbf
Copy link

[03:18:23] sync: got 30673 frames, 182464 expected

When an error occurs in the original media stream, that's "end of file" as far as handbrake is concerned. Completing the encode at that point, it has a successful result.

The question is, why did the decoder stop getting data? The answer is almost always a disk flaw, whether it be a scratch or a fingerprint.

Even MakeMKV says it can't read the disk at that point, and aborts. MakeMKV might have recorded more about the nature of the flaw it ITS log, but that's speculation about facts not in evidence. The MakeMKV forum has a topic on common read errors: https://makemkv.com/forum2/viewtopic.php?f=8&t=15055

But, as far as handbrake is concerned, this was not an error in the encoder, so it will return a zero/success response (if running from the command line) or show a green response in the GUI queue.

@sr55
Copy link
Contributor

sr55 commented Aug 3, 2018

There is a reason we tell people not to try rip directly from discs.

libbluray isn't designed for handling copy protection. (Structural protections, deliberate errors etc). MakeMKV is and they have a massive amount of experience that allows them to better detect fatal vs non fatal errors and in many cases recovery / workaround problems much better than pretty much most other tools out there. They'll have a ton of code to handle the thousands of scenarios that now come up and change with every new disc released. Much in the same way we recommend running stream repair tools before dealing with OTA recordings in HandBrake. There are tools specialised just to that file type.

As far as HandBrake can tell, there isn't a problem here so it did the correct thing in not failing the encode. The error here isn't fatal and won't always result in a failed encode.

I reckon, if we flagged every decoder error we see, we'd see a 60+% failure rate on encodes across millions of users. That's never going to end well for anyone, especially when a large percentage of those won't actually have resulted in failed encodes. So, our options are actually very limited.

Unfortunately, looking at the logs is not sufficient to tell if you have good encodes. No matter what software you use, the only way to be sure is to watch the entire file and pay very close attention to it. Same with MakeMKV. We've seen it be successful but data that it read was incorrect without error due to marks on discs or whatever.

@CollinChaffin
Copy link
Author

I've been a developer for 30 yrs (not open source where nobody can fire me) and all I can say is WOW. I'll be sure to spread the word I had no idea HB's stance was who cares if source media can be properly read and if we can't catch ALL general failures, literally why would we test for ANY of them - even the most basic PROGRAM INPUT testing. This is basic friggin I/O, not rocket science and you coded enough to log the issue, someone made a very irresponsible call to not call a total FAILURE TO READ SOURCE only 30 seconds in a success. I hear Twilight Zone music.

@sr55
Copy link
Contributor

sr55 commented Aug 3, 2018

For a developer with 30 years experience, your clearly not showing it as it's a hell of a lot more complicated than "basic IO".

Also making a lot of untrue assumptions there as well.

@sr55 sr55 closed this as completed Aug 3, 2018
@woodstockathbf
Copy link

Handbrake is not a disk ripper. You are having a problem with ripping a disk. You are attempting to use the wrong tool for the job. There are many examples of this sort of problem in the developer world, that even a "newbie" like you have encountered. (yes, I've been programming for over a decade longer than you)

A disk ripper (like MakeMKV) would tell you directly that the file isn't readable. It would stop the rip with a failure, if you were using its direct interface. Whatever you're using right now to remove the encryption from the BD is likely logging that there is a problem with the disk.

But it only tells handbrake "end of data". The program handbrake has no way to differentiate between "end of data because disk is scratched" and "end of data because you reached the end of the file". What handbrake was asked to do completed properly.

What you are feeding handbrake with is where the problem lies. How are the handbrake developers responsible for a program that isn't theirs?

@CollinChaffin
Copy link
Author

And FYI, this has ZERO to do with the PHYSICAL media it is hilarious that was the first defensive knee-jerk reaction to make this go away and close it. HB doesn't even make low-level I/O calls the failure is in the reading of the actual source file regardless of where the heck it sits. Copy a corrupt source file, any source file to the hard drive and Handbrake simply is coded so poorly that corrupt source file that fails to read, will not properly fail the job - period. I just tried it by hex-editing a source file to corrupt it and HB did the exact same thing. It is fully reproducible and to simply close this issue is absolutely unbelievable.

@bradleysepos
Copy link
Contributor

I understand you're frustrated. Regardless of the issue, you're being an ass. HandBrake is open source, free software, and nobody owes you anything, despite our efforts to provide support in our free time.

I'm going to leave these here and lock the issue. Please consider them and if you don't feel like changing your attitude, please go away.

https://github.com/HandBrake/HandBrake/blob/master/CODE_OF_CONDUCT.md

https://forum.handbrake.fr/app.php/rules?sid=fb1221fde5e3932a3c035b4bcf439b95

@HandBrake HandBrake locked as too heated and limited conversation to collaborators Aug 4, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Development

No branches or pull requests

4 participants