Handbrake and confused audio settings

[rch2]

Just for the record, Handbrake is mostly working for me on Ubuntu.

Meanwhile, I ran into a problem with Audio settings. While encoding MP4 from a DVD, I specified a certain set of settings, specifically, using DVD audio track #2, 96kbps, and 24 kHz sampling.
The video settings were uncharged from the regular iPhone preset.

The resulting file has correct video settings, but the audio is totally off. Audio: aac, 48000 Hz, stereo, 384 kbps.

Haven't tried this on Windows yet. Any ideas what can be a problem?

Code: Select all

[00:03:28] lingui: Handbrake Version: 0.9.3 (2008121800)
[00:03:28] hb_init: checking cpu count
[00:03:28] hb_init: starting libhb thread
[00:03:28] hb_init: checking cpu count
[00:03:28] hb_init: starting libhb thread
[00:03:33] hb_scan: path=/opt/Movies/Multiki/VINNI_PUH_2007/VIDEO_TS, title_index=0
[00:03:33] scan: trying to open with libdvdread
[00:03:33] scan: DVD has 10 title(s)
[00:03:33] scan: scanning title 1
[00:03:33] scan: opening IFO for VTS 1
[00:03:33] pgc_id: 1, pgn: 1: pgc: 0x97af8f0
[00:03:33] scan: vts=1, ttn=1, cells=0->0, blocks=0->14485, 14486 blocks
[00:03:33] scan: duration is 00:00:30 (30000 ms)
[00:03:33] scan: checking audio 1
[00:03:33] scan: id=80bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: checking audio 2
[00:03:33] scan: audio channel is not active
[00:03:33] scan: checking audio 3
[00:03:33] scan: audio channel is not active
[00:03:33] scan: checking audio 4
[00:03:33] scan: audio channel is not active
[00:03:33] scan: checking audio 5
[00:03:33] scan: audio channel is not active
[00:03:33] scan: checking audio 6
[00:03:33] scan: audio channel is not active
[00:03:33] scan: checking audio 7
[00:03:33] scan: audio channel is not active
[00:03:33] scan: checking audio 8
[00:03:33] scan: audio channel is not active
[00:03:33] scan: checking subtitle 1
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 2
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 3
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 4
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 5
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 6
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 7
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 8
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 9
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 10
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 11
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 12
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 13
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 14
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 15
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 16
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 17
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 18
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 19
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 20
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 21
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 22
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 23
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 24
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 25
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 26
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 27
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 28
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 29
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 30
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 31
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: checking subtitle 32
[00:03:33] scan: subtitle channel is not active
[00:03:33] scan: title 1 has 1 chapters
[00:03:33] scan: chap 1 c=0->0, b=0->14485 (14486), 30000 ms
[00:03:33] scan: aspect = 0
[00:03:33] scan: scanning title 2
[00:03:33] scan: opening IFO for VTS 2
[00:03:33] pgc_id: 1, pgn: 1: pgc: 0x97ace90
[00:03:33] scan: vts=2, ttn=1, cells=0->0, blocks=0->12719, 12720 blocks
[00:03:33] scan: duration is 00:00:34 (34080 ms)
[00:03:33] scan: ignoring title (no audio track)
[00:03:33] scan: scanning title 3
[00:03:33] scan: opening IFO for VTS 3
[00:03:33] pgc_id: 1, pgn: 1: pgc: 0x97af7e0
[00:03:33] scan: vts=3, ttn=1, cells=0->2, blocks=0->1317469, 1317470 blocks
[00:03:33] scan: duration is 00:39:42 (2382180 ms)
[00:03:33] scan: checking audio 1
[00:03:33] scan: id=80bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: checking audio 2
[00:03:33] scan: id=81bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: title 3 has 3 chapters
[00:03:33] scan: chap 1 c=0->0, b=0->340580 (340581), 615411 ms
[00:03:33] scan: chap 2 c=1->1, b=340581->671924 (331344), 599326 ms
[00:03:33] scan: chap 3 c=2->2, b=671925->1317469 (645545), 1167442 ms
[00:03:33] scan: aspect = 0
[00:03:33] scan: scanning title 4
[00:03:33] scan: opening IFO for VTS 4
[00:03:33] pgc_id: 1, pgn: 1: pgc: 0x97ace90
[00:03:33] scan: vts=4, ttn=1, cells=0->0, blocks=0->318132, 318133 blocks
[00:03:33] scan: duration is 00:09:50 (590010 ms)
[00:03:33] scan: checking audio 1
[00:03:33] scan: id=80bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: checking audio 2
[00:03:33] scan: id=81bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: title 4 has 1 chapters
[00:03:33] scan: chap 1 c=0->0, b=0->318132 (318133), 590010 ms
[00:03:33] scan: aspect = 0
[00:03:33] scan: scanning title 5
[00:03:33] scan: opening IFO for VTS 5
[00:03:33] pgc_id: 1, pgn: 1: pgc: 0x97ace90
[00:03:33] scan: vts=5, ttn=1, cells=0->0, blocks=0->303110, 303111 blocks
[00:03:33] scan: duration is 00:09:22 (562320 ms)
[00:03:33] scan: checking audio 1
[00:03:33] scan: id=80bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: checking audio 2
[00:03:33] scan: id=81bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: title 5 has 1 chapters
[00:03:33] scan: chap 1 c=0->0, b=0->303110 (303111), 562320 ms
[00:03:33] scan: aspect = 0
[00:03:33] scan: scanning title 6
[00:03:33] scan: opening IFO for VTS 6
[00:03:33] pgc_id: 1, pgn: 1: pgc: 0x97ace90
[00:03:33] scan: vts=6, ttn=1, cells=0->0, blocks=0->300515, 300516 blocks
[00:03:33] scan: duration is 00:09:03 (543060 ms)
[00:03:33] scan: checking audio 1
[00:03:33] scan: id=80bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: checking audio 2
[00:03:33] scan: id=81bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: title 6 has 1 chapters
[00:03:33] scan: chap 1 c=0->0, b=0->300515 (300516), 543060 ms
[00:03:33] scan: aspect = 0
[00:03:33] scan: scanning title 7
[00:03:33] scan: opening IFO for VTS 7
[00:03:33] pgc_id: 1, pgn: 1: pgc: 0x97ace90
[00:03:33] scan: vts=7, ttn=1, cells=0->0, blocks=0->314821, 314822 blocks
[00:03:33] scan: duration is 00:09:44 (584130 ms)
[00:03:33] scan: checking audio 1
[00:03:33] scan: id=80bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: checking audio 2
[00:03:33] scan: id=81bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: title 7 has 1 chapters
[00:03:33] scan: chap 1 c=0->0, b=0->314821 (314822), 584130 ms
[00:03:33] scan: aspect = 0
[00:03:33] scan: scanning title 8
[00:03:33] scan: opening IFO for VTS 8
[00:03:33] pgc_id: 1, pgn: 1: pgc: 0x97ace90
[00:03:33] scan: vts=8, ttn=1, cells=0->0, blocks=0->311803, 311804 blocks
[00:03:33] scan: duration is 00:09:38 (578250 ms)
[00:03:33] scan: checking audio 1
[00:03:33] scan: id=80bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: checking audio 2
[00:03:33] scan: id=81bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: title 8 has 1 chapters
[00:03:33] scan: chap 1 c=0->0, b=0->311803 (311804), 578250 ms
[00:03:33] scan: aspect = 0
[00:03:33] scan: scanning title 9
[00:03:33] scan: opening IFO for VTS 9
[00:03:33] pgc_id: 1, pgn: 1: pgc: 0x97ace90
[00:03:33] scan: vts=9, ttn=1, cells=0->0, blocks=0->313362, 313363 blocks
[00:03:33] scan: duration is 00:09:41 (581250 ms)
[00:03:33] scan: checking audio 1
[00:03:33] scan: id=80bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: checking audio 2
[00:03:33] scan: id=81bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: title 9 has 1 chapters
[00:03:33] scan: chap 1 c=0->0, b=0->313362 (313363), 581250 ms
[00:03:33] scan: aspect = 0
[00:03:33] scan: scanning title 10
[00:03:33] scan: opening IFO for VTS 10
[00:03:33] pgc_id: 1, pgn: 1: pgc: 0x97ace90
[00:03:33] scan: vts=10, ttn=1, cells=0->0, blocks=0->210045, 210046 blocks
[00:03:33] scan: duration is 00:06:29 (389100 ms)
[00:03:33] scan: checking audio 1
[00:03:33] scan: id=80bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: checking audio 2
[00:03:33] scan: id=81bd, lang=Russian (AC3), 3cc=rus ext=0
[00:03:33] scan: title 10 has 1 chapters
[00:03:33] scan: chap 1 c=0->0, b=0->210045 (210046), 389100 ms
[00:03:33] scan: aspect = 0
[00:03:33] scan: decoding previews for title 1
[00:03:33] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (5.1 ch)
[00:03:34] scan: content PAR gives wrong aspect 1.78; using container aspect 1.78
[00:03:34] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/0/0/0, aspect 1.78:1, PAR 341:240
[00:03:34] scan: decoding previews for title 3
[00:03:34] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (5.1 ch)
[00:03:34] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (1.0 ch)
[00:03:36] scan: content PAR gives wrong aspect 1.33; using container aspect 1.33
[00:03:36] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/2/0/4, aspect 1.33:1, PAR 767:720
[00:03:36] scan: decoding previews for title 4
[00:03:36] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=224000 Russian (AC3) (1.0 ch)
[00:03:36] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (5.1 ch)
[00:03:37] scan: content PAR gives wrong aspect 1.33; using container aspect 1.33
[00:03:37] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/0/0/0, aspect 1.33:1, PAR 767:720
[00:03:37] scan: decoding previews for title 5
[00:03:37] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (5.1 ch)
[00:03:37] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=224000 Russian (AC3) (1.0 ch)
[00:03:38] scan: content PAR gives wrong aspect 1.33; using container aspect 1.33
[00:03:38] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/0/0/0, aspect 1.33:1, PAR 767:720
[00:03:38] scan: decoding previews for title 6
[00:03:38] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (5.1 ch)
[00:03:38] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (1.0 ch)
[00:03:39] scan: content PAR gives wrong aspect 1.33; using container aspect 1.33
[00:03:39] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/2/0/0, aspect 1.33:1, PAR 767:720
[00:03:39] scan: decoding previews for title 7
[00:03:39] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (5.1 ch)
[00:03:39] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=224000 Russian (AC3) (1.0 ch)
[00:03:40] scan: content PAR gives wrong aspect 1.33; using container aspect 1.33
[00:03:40] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/0/0/0, aspect 1.33:1, PAR 767:720
[00:03:40] scan: decoding previews for title 8
[00:03:41] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (5.1 ch)
[00:03:41] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=224000 Russian (AC3) (1.0 ch)
[00:03:41] scan: content PAR gives wrong aspect 1.33; using container aspect 1.33
[00:03:41] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/0/0/0, aspect 1.33:1, PAR 767:720
[00:03:41] scan: decoding previews for title 9
[00:03:42] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (5.1 ch)
[00:03:42] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=224000 Russian (AC3) (1.0 ch)
[00:03:43] scan: content PAR gives wrong aspect 1.33; using container aspect 1.33
[00:03:43] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/0/0/0, aspect 1.33:1, PAR 767:720
[00:03:43] scan: decoding previews for title 10
[00:03:43] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (5.1 ch)
[00:03:43] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=224000 Russian (AC3) (1.0 ch)
[00:03:44] scan: content PAR gives wrong aspect 1.33; using container aspect 1.33
[00:03:44] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/0/0/0, aspect 1.33:1, PAR 767:720
[00:03:44] scan: title (0) job->width:720, job->height:400
[00:03:44] scan: title (1) job->width:720, job->height:544
[00:03:44] scan: title (2) job->width:720, job->height:544
[00:03:44] scan: title (3) job->width:720, job->height:544
[00:03:44] scan: title (4) job->width:720, job->height:544
[00:03:44] scan: title (5) job->width:720, job->height:544
[00:03:44] scan: title (6) job->width:720, job->height:544
[00:03:44] scan: title (7) job->width:720, job->height:544
[00:03:44] scan: title (8) job->width:720, job->height:544
[00:03:44] libhb: scan thread found 9 valid title(s)
[00:04:51] hb_scan: path=/opt/Movies/Multiki/VINNI_PUH_2007/VIDEO_TS, title_index=10
[00:04:51] scan: trying to open with libdvdread
[00:04:52] scan: DVD has 10 title(s)
[00:04:52] scan: scanning title 10
[00:04:52] scan: opening IFO for VTS 10
[00:04:52] pgc_id: 1, pgn: 1: pgc: 0x98a7628
[00:04:52] scan: vts=10, ttn=1, cells=0->0, blocks=0->210045, 210046 blocks
[00:04:52] scan: duration is 00:06:29 (389100 ms)
[00:04:52] scan: checking audio 1
[00:04:52] scan: id=80bd, lang=Russian (AC3), 3cc=rus ext=0
[00:04:52] scan: checking audio 2
[00:04:52] scan: id=81bd, lang=Russian (AC3), 3cc=rus ext=0
[00:04:52] scan: title 10 has 1 chapters
[00:04:52] scan: chap 1 c=0->0, b=0->210045 (210046), 389100 ms
[00:04:52] scan: aspect = 0
[00:04:52] scan: decoding previews for title 10
[00:04:52] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 Russian (AC3) (5.1 ch)
[00:04:52] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=224000 Russian (AC3) (1.0 ch)
[00:04:52] scan: content PAR gives wrong aspect 1.33; using container aspect 1.33
[00:04:52] scan: 10 previews, 720x576, 25.000 fps, autocrop = 0/0/0/0, aspect 1.33:1, PAR 767:720
[00:04:52] scan: title (0) job->width:720, job->height:544
[00:04:52] libhb: scan thread found 1 valid title(s)
[00:04:52] lingui: Modified Preset: Apple->iPhone & iPod Touch
[00:04:52] 2 job(s) to process
[00:04:52] starting job
[00:04:52] job configuration:
[00:04:52]  * source
[00:04:52]    + /opt/Movies/Multiki/VINNI_PUH_2007/VIDEO_TS
[00:04:52]    + title 10, chapter(s) 1 to 1
[00:04:52]  * destination
[00:04:52]    + /opt/Videos/test.mp4
[00:04:52]    + container: MPEG-4 (.mp4 and .m4v)
[00:04:52]      + chapter markers
[00:04:52]  * video track
[00:04:52]    + decoder: mpeg2
[00:04:52]      + bitrate 8000 kbps
[00:04:52]    + frame rate: same as source (around 25.000 fps)
[00:04:52]    + dimensions: 720 * 576 -> 480 * 368, crop 0/0/0/0
[00:04:52]    + encoder: x264
[00:04:52]      + options: level=30:cabac=0:ref=2:mixed-refs:analyse=all:me=umh:no-fast-pskip=1:ref=1:subme=1:me=dia:analyse=none:trellis=0:no-fast-pskip=0:8x8dct=0:weightb=0
[00:04:52]      + bitrate: 768 kbps, pass: 1
[00:04:52]  * audio track 0
[00:04:52]    + decoder: Russian (AC3) (1.0 ch) (track 2, id 81bd)
[00:04:52]      + bitrate: 224 kbps, samplerate: 48000 Hz
[00:04:52]    + mixdown: Mono
[00:04:52]    + encoder: faac
[00:04:52]      + bitrate: 96 kbps, samplerate: 24000 Hz
[00:04:52] reader: first SCR 146
[00:04:52] mpeg2: "Chapter  1" (1) at frame 0 time 10800
x264 [info]: using cpu capabilities: MMX2
x264 [info]: profile Baseline, level 3.0
No accelerated IMDCT transform found
[00:04:53] sync: expecting 9752 video frames
[00:04:53] sync: first pts is 10800
[00:11:23] reader: done. 0 scr changes
[00:11:23] sync: got 9744 frames, 9752 expected
[00:11:23] work: average encoding speed for job is 24.919884 fps
[00:11:24] mpeg2 done: 9745 frames
[00:11:24] render: lost time: 0 (0 frames)
[00:11:24] render: gained time: 0 (0 frames) (0 not accounted for)
x264 [info]: slice I:67    Avg QP:26.35  size: 18820  PSNR Mean Y:37.89 U:41.80 V:41.02 Avg:38.75 Global:37.48
x264 [info]: slice P:9677  Avg QP:29.56  size:  3794  PSNR Mean Y:34.21 U:38.80 V:37.92 Avg:35.16 Global:34.57
x264 [info]: mb I  I16..4: 27.2%  0.0% 72.8%
x264 [info]: mb P  I16..4: 15.0%  0.0%  0.0%  P16..4: 58.8%  0.0%  0.0%  0.0%  0.0%    skip:26.2%
x264 [info]: final ratefactor: 26.11
x264 [info]: SSIM Mean Y:0.9253100
x264 [info]: PSNR Mean Y:34.234 U:38.820 V:37.938 Avg:35.180 Global:34.582 kb/s:779.56
[00:11:24] starting job
[00:11:24] job configuration:
[00:11:24]  * source
[00:11:24]    + /opt/Movies/Multiki/VINNI_PUH_2007/VIDEO_TS
[00:11:24]    + title 10, chapter(s) 1 to 1
[00:11:24]  * destination
[00:11:24]    + /opt/Videos/test.mp4
[00:11:24]    + container: MPEG-4 (.mp4 and .m4v)
[00:11:24]      + chapter markers
[00:11:24]  * video track
[00:11:24]    + decoder: mpeg2
[00:11:24]      + bitrate 8000 kbps
[00:11:24]    + frame rate: same as source (around 25.000 fps)
[00:11:24]    + dimensions: 720 * 576 -> 480 * 368, crop 0/0/0/0
[00:11:24]    + encoder: x264
[00:11:24]      + options: level=30:cabac=0:ref=2:mixed-refs:analyse=all:me=umh:no-fast-pskip=1
[00:11:24]      + bitrate: 768 kbps, pass: 2
[00:11:24]  * audio track 0
[00:11:24]    + decoder: Russian (AC3) (1.0 ch) (track 2, id 81bd)
[00:11:24]      + bitrate: 224 kbps, samplerate: 48000 Hz
[00:11:24]    + mixdown: Mono
[00:11:24]    + encoder: faac
[00:11:24]      + bitrate: 96 kbps, samplerate: 24000 Hz
x264 [info]: using cpu capabilities: MMX2
[00:11:24] reader: first SCR 146
[00:11:24] mpeg2: "Chapter  1" (1) at frame 0 time 10800
x264 [info]: profile Baseline, level 3.0
No accelerated IMDCT transform found
[00:11:25] sync: expecting 9752 video frames
[00:11:25] sync: first pts is 10800
[00:31:14] reader: done. 0 scr changes
[00:31:17] sync: got 9744 frames, 9752 expected
[00:31:17] work: average encoding speed for job is 8.178814 fps
[00:31:19] mpeg2 done: 9745 frames
[00:31:19] render: lost time: 0 (0 frames)
[00:31:19] render: gained time: 0 (0 frames) (0 not accounted for)
x264 [info]: slice I:67    Avg QP:25.93  size: 20291  PSNR Mean Y:38.27 U:42.83 V:42.10 Avg:39.26 Global:38.21
x264 [info]: slice P:9677  Avg QP:28.89  size:  3724  PSNR Mean Y:35.09 U:39.93 V:39.01 Avg:36.08 Global:35.75
x264 [info]: mb I  I16..4:  9.3%  0.0% 90.7%
x264 [info]: mb P  I16..4:  1.5%  0.0%  3.5%  P16..4: 58.2% 14.3%  7.0%  0.5%  0.5%    skip:14.5%
x264 [info]: ref P L0  73.6% 26.4%
x264 [info]: SSIM Mean Y:0.9343407
x264 [info]: PSNR Mean Y:35.108 U:39.945 V:39.030 Avg:36.102 Global:35.763 kb/s:767.60
[00:31:19] libhb: work result = 0

Result:

Code: Select all

~/Videos$ ffmpeg -i test.mp4 
FFmpeg version SVN-rUNKNOWN, Copyright (c) 2000-2007 Fabrice Bellard, et al.
  configuration: --enable-gpl --enable-pp --enable-swscaler --enable-pthreads --enable-libvorbis --enable-libtheora --enable-libogg --enable-libgsm --enable-dc1394 --disable-debug --enable-libmp3lame --enable-libfaadbin --enable-libfaad --enable-libfaac --enable-xvid --enable-x264 --enable-liba52 --enable-amr_nb --enable-amr_wb --enable-shared --prefix=/usr
  libavutil version: 1d.49.3.0
  libavcodec version: 1d.51.38.0
  libavformat version: 1d.51.10.0
  built on Jul 29 2008 18:21:25, gcc: 4.2.3 (Ubuntu 4.2.3-2ubuntu7)
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'test.mp4':
  Duration: 00:06:29.8, start: 0.000000, bitrate: 810 kb/s
  Stream #0.0(eng): Video: h264, yuv420p, 480x368, 25.00 fps(r)
  Stream #0.1(rus): Audio: aac, 48000 Hz, stereo
  Stream #0.2(eng): Data: text / 0x74786574
Must supply at least one output file

[JohnAStebbins]

I've tried, but have been unsuccessful at reproducing this. Your log looks normal. Any chance ffmpeg is lying to you? I tried several discs including a PAL disc.
Here's a log of one of my attempts and ffmpeg output for comparison.

Code: Select all

[08:09:24] lingui: Handbrake Version: 0.9.3 (2009030400)
[08:09:24] hb_init: checking cpu count
[08:09:24] hb_init: starting libhb thread
[08:09:24] hb_init: checking cpu count
[08:09:24] hb_init: starting libhb thread
[08:09:29] hb_scan: path=/dev/sr1, title_index=0
[08:09:29] scan: trying to open with libdvdread
[08:09:29] scan: DVD has 9 title(s)
[08:09:29] scan: scanning title 1
[08:09:29] scan: opening IFO for VTS 1
[08:09:29] pgc_id: 1, pgn: 1: pgc: 0x25a0bf0
[08:09:29] scan: vts=1, ttn=1, cells=0->16, blocks=0->2630074, 2630075 blocks
[08:09:29] scan: duration is 01:42:40 (6160110 ms)
[08:09:29] scan: checking audio 1
[08:09:29] scan: id=80bd, lang=English (AC3), 3cc=eng ext=0
[08:09:29] scan: checking audio 2
[08:09:29] scan: id=81bd, lang=Francais (AC3), 3cc=fra ext=0
[08:09:29] scan: checking audio 3
[08:09:29] scan: id=82bd, lang=Espanol (AC3), 3cc=spa ext=0
[08:09:29] scan: checking subtitle 1
[08:09:29] scan: id=21bd, lang=English, 3cc=eng
[08:09:29] scan: checking subtitle 2
[08:09:29] scan: id=23bd, lang=Francais, 3cc=fra
[08:09:29] scan: checking subtitle 3
[08:09:29] scan: id=25bd, lang=Espanol, 3cc=spa
[08:09:29] scan: title 1 has 16 chapters
[08:09:29] scan: chap 1 c=0->0, b=0->163732 (163733), 400358 ms
[08:09:29] scan: chap 2 c=1->1, b=163733->344934 (181202), 436396 ms
[08:09:29] scan: chap 3 c=2->2, b=344935->434651 (89717), 205161 ms
[08:09:29] scan: chap 4 c=3->3, b=434652->643586 (208935), 524733 ms
[08:09:29] scan: chap 5 c=4->5, b=643587->854356 (210770), 466430 ms
[08:09:29] scan: chap 6 c=6->6, b=854357->1010935 (156579), 364430 ms
[08:09:29] scan: chap 7 c=7->7, b=1010936->1130778 (119843), 282422 ms
[08:09:29] scan: chap 8 c=8->8, b=1130779->1252003 (121225), 271346 ms
[08:09:29] scan: chap 9 c=9->9, b=1252004->1465574 (213571), 481379 ms
[08:09:29] scan: chap 10 c=10->10, b=1465575->1565866 (100292), 232268 ms
[08:09:29] scan: chap 11 c=11->11, b=1565867->1732583 (166717), 403527 ms
[08:09:29] scan: chap 12 c=12->12, b=1732584->1929840 (197257), 454658 ms
[08:09:29] scan: chap 13 c=13->13, b=1929841->2100260 (170420), 406520 ms
[08:09:29] scan: chap 14 c=14->14, b=2100261->2385445 (285185), 666545 ms
[08:09:29] scan: chap 15 c=15->15, b=2385446->2475884 (90439), 190335 ms
[08:09:29] scan: chap 16 c=16->16, b=2475885->2630074 (154190), 373594 ms
[08:09:29] scan: aspect = 0
[08:09:29] scan: scanning title 2
[08:09:29] scan: opening IFO for VTS 2
[08:09:30] pgc_id: 1, pgn: 1: pgc: 0x25a94f0
[08:09:30] scan: vts=2, ttn=1, cells=0->1, blocks=0->2769, 2770 blocks
[08:09:30] scan: duration is 00:00:13 (13176 ms)
[08:09:30] scan: checking audio 1
[08:09:30] scan: id=81bd, lang=English (AC3), 3cc=eng ext=0
[08:09:30] scan: checking audio 2
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking audio 3
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking subtitle 1
[08:09:30] scan: id=20bd, lang=English, 3cc=eng
[08:09:30] scan: checking subtitle 2
[08:09:30] scan: id=20bd, lang=Francais, 3cc=fra
[08:09:30] scan: checking subtitle 3
[08:09:30] scan: id=20bd, lang=Espanol, 3cc=spa
[08:09:30] scan: title 2 has 2 chapters
[08:09:30] scan: chap 1 c=0->0, b=0->2747 (2748), 13000 ms
[08:09:30] scan: chap 2 c=1->1, b=2748->2769 (22), 176 ms
[08:09:30] scan: aspect = 0
[08:09:30] scan: scanning title 3
[08:09:30] scan: opening IFO for VTS 2
[08:09:30] pgc_id: 2, pgn: 1: pgc: 0x25ab140
[08:09:30] scan: vts=2, ttn=2, cells=0->0, blocks=4969->4989, 21 blocks
[08:09:30] scan: duration is 00:00:00 (176 ms)
[08:09:30] scan: ignoring title (too short)
[08:09:30] scan: scanning title 4
[08:09:30] scan: opening IFO for VTS 2
[08:09:30] pgc_id: 3, pgn: 1: pgc: 0x25ab3d0
[08:09:30] scan: vts=2, ttn=3, cells=0->1, blocks=2770->4989, 2220 blocks
[08:09:30] scan: duration is 00:00:10 (10286 ms)
[08:09:30] scan: checking audio 1
[08:09:30] scan: id=80bd, lang=English (AC3), 3cc=eng ext=0
[08:09:30] scan: checking audio 2
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking audio 3
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking subtitle 1
[08:09:30] scan: id=20bd, lang=English, 3cc=eng
[08:09:30] scan: checking subtitle 2
[08:09:30] scan: id=20bd, lang=Francais, 3cc=fra
[08:09:30] scan: checking subtitle 3
[08:09:30] scan: id=20bd, lang=Espanol, 3cc=spa
[08:09:30] scan: title 4 has 2 chapters
[08:09:30] scan: chap 1 c=0->0, b=2770->4968 (2199), 10110 ms
[08:09:30] scan: chap 2 c=1->1, b=4969->4989 (21), 176 ms
[08:09:30] scan: aspect = 0
[08:09:30] scan: scanning title 5
[08:09:30] scan: opening IFO for VTS 2
[08:09:30] pgc_id: 4, pgn: 1: pgc: 0x25ab420
[08:09:30] scan: vts=2, ttn=4, cells=0->1, blocks=4969->4989, 42 blocks
[08:09:30] scan: duration is 00:00:01 (1000 ms)
[08:09:30] scan: ignoring title (too short)
[08:09:30] scan: scanning title 6
[08:09:30] scan: opening IFO for VTS 3
[08:09:30] pgc_id: 1, pgn: 1: pgc: 0x25a94a0
[08:09:30] scan: vts=3, ttn=1, cells=0->1, blocks=0->1801, 1802 blocks
[08:09:30] scan: duration is 00:00:11 (11000 ms)
[08:09:30] scan: checking audio 1
[08:09:30] scan: id=80bd, lang=English (AC3), 3cc=eng ext=0
[08:09:30] scan: checking audio 2
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking audio 3
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking subtitle 1
[08:09:30] scan: id=20bd, lang=English, 3cc=eng
[08:09:30] scan: checking subtitle 2
[08:09:30] scan: id=20bd, lang=Francais, 3cc=fra
[08:09:30] scan: checking subtitle 3
[08:09:30] scan: id=20bd, lang=Espanol, 3cc=spa
[08:09:30] scan: title 6 has 2 chapters
[08:09:30] scan: chap 1 c=0->0, b=0->1792 (1793), 10812 ms
[08:09:30] scan: chap 2 c=1->1, b=1793->1801 (9), 187 ms
[08:09:30] scan: aspect = 0
[08:09:30] scan: scanning title 7
[08:09:30] scan: opening IFO for VTS 4
[08:09:30] pgc_id: 1, pgn: 1: pgc: 0x25a2060
[08:09:30] scan: vts=4, ttn=1, cells=0->1, blocks=0->32469, 32470 blocks
[08:09:30] scan: duration is 00:01:41 (101200 ms)
[08:09:30] scan: checking audio 1
[08:09:30] scan: id=80bd, lang=English (AC3), 3cc=eng ext=0
[08:09:30] scan: checking audio 2
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking audio 3
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking subtitle 1
[08:09:30] scan: id=20bd, lang=English, 3cc=eng
[08:09:30] scan: checking subtitle 2
[08:09:30] scan: id=20bd, lang=Francais, 3cc=fra
[08:09:30] scan: checking subtitle 3
[08:09:30] scan: id=20bd, lang=Espanol, 3cc=spa
[08:09:30] scan: title 7 has 2 chapters
[08:09:30] scan: chap 1 c=0->0, b=0->32456 (32457), 101022 ms
[08:09:30] scan: chap 2 c=1->1, b=32457->32469 (13), 177 ms
[08:09:30] scan: aspect = 0
[08:09:30] scan: scanning title 8
[08:09:30] scan: opening IFO for VTS 5
[08:09:30] pgc_id: 1, pgn: 1: pgc: 0x25e9e10
[08:09:30] scan: vts=5, ttn=1, cells=0->1, blocks=0->30092, 30093 blocks
[08:09:30] scan: duration is 00:01:34 (94176 ms)
[08:09:30] scan: checking audio 1
[08:09:30] scan: id=80bd, lang=English (AC3), 3cc=eng ext=0
[08:09:30] scan: checking audio 2
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking audio 3
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking subtitle 1
[08:09:30] scan: id=20bd, lang=English, 3cc=eng
[08:09:30] scan: checking subtitle 2
[08:09:30] scan: id=20bd, lang=Francais, 3cc=fra
[08:09:30] scan: checking subtitle 3
[08:09:30] scan: id=20bd, lang=Espanol, 3cc=spa
[08:09:30] scan: title 8 has 2 chapters
[08:09:30] scan: chap 1 c=0->0, b=0->30077 (30078), 94000 ms
[08:09:30] scan: chap 2 c=1->1, b=30078->30092 (15), 176 ms
[08:09:30] scan: aspect = 0
[08:09:30] scan: scanning title 9
[08:09:30] scan: opening IFO for VTS 5
[08:09:30] pgc_id: 2, pgn: 1: pgc: 0x25df190
[08:09:30] scan: vts=5, ttn=2, cells=0->1, blocks=30093->51563, 21471 blocks
[08:09:30] scan: duration is 00:01:07 (67243 ms)
[08:09:30] scan: checking audio 1
[08:09:30] scan: id=80bd, lang=English (AC3), 3cc=eng ext=0
[08:09:30] scan: checking audio 2
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking audio 3
[08:09:30] scan: duplicate audio track
[08:09:30] scan: checking subtitle 1
[08:09:30] scan: id=20bd, lang=English, 3cc=eng
[08:09:30] scan: checking subtitle 2
[08:09:30] scan: id=20bd, lang=Francais, 3cc=fra
[08:09:30] scan: checking subtitle 3
[08:09:30] scan: id=20bd, lang=Espanol, 3cc=spa
[08:09:30] scan: title 9 has 2 chapters
[08:09:30] scan: chap 1 c=0->0, b=30093->51467 (21375), 67067 ms
[08:09:30] scan: chap 2 c=1->1, b=51468->51563 (96), 176 ms
[08:09:30] scan: aspect = 0
[08:09:30] scan: decoding previews for title 1
[08:09:30] scan: audio 0x82bd: AC-3, rate=48000Hz, bitrate=448000 Espanol (AC3) (5.1 ch)
[08:09:30] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=448000 Francais (AC3) (5.1 ch)
[08:09:30] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 English (AC3) (5.1 ch)
[08:09:32] scan: 10 previews, 720x480, 23.976 fps, autocrop = 0/8/0/2, aspect 16:9, PAR 32:27
[08:09:32] scan: decoding previews for title 2
[08:09:32] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=384000 English (AC3) (5.1 ch)
[08:09:32] 4.615111s: Film -> Video
[08:09:33] scan: 10 previews, 720x480, 29.970 fps, autocrop = 0/0/0/0, aspect 4:3, PAR 8:9
[08:09:33] scan: decoding previews for title 4
[08:09:33] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 English (AC3) (5.1 ch)
[08:09:34] 3.630789s: Video -> Film
[08:09:34] scan: 10 previews, 720x480, 29.970 fps, autocrop = 0/0/0/0, aspect 4:3, PAR 8:9
[08:09:34] scan: decoding previews for title 6
[08:09:34] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=384000 English (AC3) (5.1 ch)
[08:09:34] 3.115233s: Film -> Video
[08:09:35] scan: 10 previews, 720x480, 29.970 fps, autocrop = 0/0/0/0, aspect 16:9, PAR 32:27
[08:09:35] scan: decoding previews for title 7
[08:09:35] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=192000 English (AC3) (2.0 ch)
[08:09:35] 11.640411s: Video -> Film
[08:09:37] scan: 10 previews, 720x480, 23.976 fps, autocrop = 0/8/2/0, aspect 16:9, PAR 32:27
[08:09:37] scan: decoding previews for title 8
[08:09:37] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=192000 English (AC3) (2.0 ch)
[08:09:37] 20.132233s: Film -> Video
[08:09:39] scan: 10 previews, 720x480, 29.970 fps, autocrop = 0/0/0/2, aspect 4:3, PAR 8:9
[08:09:39] scan: decoding previews for title 9
[08:09:39] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=192000 English (AC3) (2.0 ch)
[08:09:41] scan: 10 previews, 720x480, 29.970 fps, autocrop = 0/0/4/4, aspect 4:3, PAR 8:9
[08:09:41] scan: title (0) job->width:720, job->height:400
[08:09:41] scan: title (1) job->width:640, job->height:480
[08:09:41] scan: title (2) job->width:640, job->height:480
[08:09:41] scan: title (3) job->width:720, job->height:400
[08:09:41] scan: title (4) job->width:720, job->height:400
[08:09:41] scan: title (5) job->width:640, job->height:480
[08:09:41] scan: title (6) job->width:640, job->height:480
[08:09:41] libhb: scan thread found 7 valid title(s)
[08:10:57] hb_scan: path=/dev/sr1, title_index=1
[08:10:57] scan: trying to open with libdvdread
[08:10:57] scan: DVD has 9 title(s)
[08:10:57] scan: scanning title 1
[08:10:57] scan: opening IFO for VTS 1
[08:10:57] pgc_id: 1, pgn: 1: pgc: 0x26cbcb0
[08:10:57] scan: vts=1, ttn=1, cells=0->16, blocks=0->2630074, 2630075 blocks
[08:10:57] scan: duration is 01:42:40 (6160110 ms)
[08:10:57] scan: checking audio 1
[08:10:57] scan: id=80bd, lang=English (AC3), 3cc=eng ext=0
[08:10:57] scan: checking audio 2
[08:10:57] scan: id=81bd, lang=Francais (AC3), 3cc=fra ext=0
[08:10:57] scan: checking audio 3
[08:10:57] scan: id=82bd, lang=Espanol (AC3), 3cc=spa ext=0
[08:10:57] scan: checking subtitle 1
[08:10:57] scan: id=21bd, lang=English, 3cc=eng
[08:10:57] scan: checking subtitle 2
[08:10:57] scan: id=23bd, lang=Francais, 3cc=fra
[08:10:57] scan: checking subtitle 3
[08:10:57] scan: id=25bd, lang=Espanol, 3cc=spa
[08:10:57] scan: title 1 has 16 chapters
[08:10:57] scan: chap 1 c=0->0, b=0->163732 (163733), 400358 ms
[08:10:57] scan: chap 2 c=1->1, b=163733->344934 (181202), 436396 ms
[08:10:57] scan: chap 3 c=2->2, b=344935->434651 (89717), 205161 ms
[08:10:57] scan: chap 4 c=3->3, b=434652->643586 (208935), 524733 ms
[08:10:57] scan: chap 5 c=4->5, b=643587->854356 (210770), 466430 ms
[08:10:57] scan: chap 6 c=6->6, b=854357->1010935 (156579), 364430 ms
[08:10:57] scan: chap 7 c=7->7, b=1010936->1130778 (119843), 282422 ms
[08:10:57] scan: chap 8 c=8->8, b=1130779->1252003 (121225), 271346 ms
[08:10:57] scan: chap 9 c=9->9, b=1252004->1465574 (213571), 481379 ms
[08:10:57] scan: chap 10 c=10->10, b=1465575->1565866 (100292), 232268 ms
[08:10:57] scan: chap 11 c=11->11, b=1565867->1732583 (166717), 403527 ms
[08:10:57] scan: chap 12 c=12->12, b=1732584->1929840 (197257), 454658 ms
[08:10:57] scan: chap 13 c=13->13, b=1929841->2100260 (170420), 406520 ms
[08:10:57] scan: chap 14 c=14->14, b=2100261->2385445 (285185), 666545 ms
[08:10:57] scan: chap 15 c=15->15, b=2385446->2475884 (90439), 190335 ms
[08:10:57] scan: chap 16 c=16->16, b=2475885->2630074 (154190), 373594 ms
[08:10:57] scan: aspect = 0
[08:10:57] scan: decoding previews for title 1
[08:10:57] scan: audio 0x82bd: AC-3, rate=48000Hz, bitrate=448000 Espanol (AC3) (5.1 ch)
[08:10:57] scan: audio 0x81bd: AC-3, rate=48000Hz, bitrate=448000 Francais (AC3) (5.1 ch)
[08:10:57] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 English (AC3) (5.1 ch)
[08:10:57] 584.996521s: Video -> Film
[08:10:57] scan: 10 previews, 720x480, 23.976 fps, autocrop = 0/8/0/2, aspect 16:9, PAR 32:27
[08:10:57] scan: title (0) job->width:720, job->height:400
[08:10:57] libhb: scan thread found 1 valid title(s)
[08:10:57] lingui: Modified Preset: Apple->iPhone & iPod Touch
[08:10:57] 2 job(s) to process
[08:10:57] starting job
[08:10:57] job configuration:
[08:10:57]  * source
[08:10:57]    + /dev/sr1
[08:10:57]    + title 1, chapter(s) 1 to 1
[08:10:57]  * destination
[08:10:57]    + /home/jstebbins/Videos/Robocop.mp4
[08:10:57]    + container: MPEG-4 (.mp4 and .m4v)
[08:10:57]      + chapter markers
[08:10:57]  * video track
[08:10:57]    + decoder: mpeg2
[08:10:57]      + bitrate 7500 kbps
[08:10:57]    + frame rate: same as source (around 23.976 fps)
[08:10:57]    + dimensions: 720 * 480 -> 480 * 272, crop 0/8/0/2
[08:10:57]    + encoder: x264
[08:10:57]      + options: level=30:cabac=0:ref=2:mixed-refs:analyse=all:me=umh:no-fast-pskip=1:ref=1:subme=1:me=dia:analyse=none:trellis=0:no-fast-pskip=0:8x8dct=0:weightb=0
[08:10:57]      + bitrate: 768 kbps, pass: 1
[08:10:57]  * audio track 0
[08:10:57]    + decoder: Francais (AC3) (5.1 ch) (track 2, id 81bd)
[08:10:57]      + bitrate: 448 kbps, samplerate: 48000 Hz
[08:10:57]    + mixdown: Mono
[08:10:57]    + encoder: faac
[08:10:57]      + bitrate: 96 kbps, samplerate: 24000 Hz
[08:10:57] encx264: keyint-min: 24, keyint-max: 240
x264 [info]: using cpu capabilities: MMX2 SSE2Fast SSSE3 PHADD SSE4.1 Cache64
x264 [info]: profile Baseline, level 3.0
No accelerated IMDCT transform found
[08:10:57] sync: expecting 9622 video frames
[08:10:58] reader: first SCR 146
[08:10:59] mpeg2: "Chapter  1" (1) at frame 0 time 10510
[08:10:59] sync: first pts is 10510
[08:10:59] sync: adding 116 ms of silence to audio 0  start 10509, next 0
[08:10:59] sync: video time didn't advance - dropped 10 frames (delta 408 ms, current 51048, next 51798, dur 750)
[08:10:59] sync: video time didn't advance - dropped 10 frames (delta 408 ms, current 54801, next 55551, dur 750)
[08:11:56] reader: end of chapter 1 (media 1) reached at media chapter 2
[08:11:56] reader: done. 4 scr changes
[08:11:56] sync: got 9584 frames, 9622 expected
[08:11:56] work: average encoding speed for job is 166.103073 fps
[08:11:56] mpeg2 done: 9605 frames
[08:11:56] render: lost time: 0 (0 frames)
[08:11:56] render: gained time: 0 (0 frames) (0 not accounted for)
x264 [info]: slice I:78    Avg QP:18.57  size: 15283  PSNR Mean Y:44.44 U:47.77 V:48.50 Avg:45.33 Global:44.56
x264 [info]: slice P:9506  Avg QP:21.82  size:  3900  PSNR Mean Y:40.89 U:44.64 V:45.35 Avg:41.81 Global:41.27
x264 [info]: mb I  I16..4: 26.2%  0.0% 73.8%
x264 [info]: mb P  I16..4: 11.9%  0.0%  0.0%  P16..4: 73.4%  0.0%  0.0%  0.0%  0.0%    skip:14.6%
x264 [info]: final ratefactor: 22.55
x264 [info]: SSIM Mean Y:0.9683794
x264 [info]: PSNR Mean Y:40.923 U:44.666 V:45.375 Avg:41.843 Global:41.292 kb/s:765.79
[08:11:56] starting job
[08:11:56] job configuration:
[08:11:56]  * source
[08:11:56]    + /dev/sr1
[08:11:56]    + title 1, chapter(s) 1 to 1
[08:11:56]  * destination
[08:11:56]    + /home/jstebbins/Videos/Robocop.mp4
[08:11:56]    + container: MPEG-4 (.mp4 and .m4v)
[08:11:56]      + chapter markers
[08:11:56]  * video track
[08:11:56]    + decoder: mpeg2
[08:11:56]      + bitrate 7500 kbps
[08:11:56]    + frame rate: same as source (around 23.976 fps)
[08:11:56]    + dimensions: 720 * 480 -> 480 * 272, crop 0/8/0/2
[08:11:56]    + encoder: x264
[08:11:56]      + options: level=30:cabac=0:ref=2:mixed-refs:analyse=all:me=umh:no-fast-pskip=1
[08:11:56]      + bitrate: 768 kbps, pass: 2
[08:11:56]  * audio track 0
[08:11:56]    + decoder: Francais (AC3) (5.1 ch) (track 2, id 81bd)
[08:11:56]      + bitrate: 448 kbps, samplerate: 48000 Hz
[08:11:56]    + mixdown: Mono
[08:11:56]    + encoder: faac
[08:11:56]      + bitrate: 96 kbps, samplerate: 24000 Hz
[08:11:56] encx264: keyint-min: 24, keyint-max: 240
x264 [info]: using cpu capabilities: MMX2 SSE2Fast SSSE3 PHADD SSE4.1 Cache64
[08:11:56] reader: first SCR 146
[08:11:56] mpeg2: "Chapter  1" (1) at frame 0 time 10510
x264 [info]: profile Baseline, level 3.0
No accelerated IMDCT transform found
[08:11:57] sync: expecting 9622 video frames
[08:11:57] sync: first pts is 10510
[08:11:57] sync: adding 116 ms of silence to audio 0  start 10509, next 0
[08:11:57] sync: video time didn't advance - dropped 10 frames (delta 408 ms, current 51048, next 51798, dur 750)
[08:11:57] sync: video time didn't advance - dropped 10 frames (delta 408 ms, current 54801, next 55551, dur 750)
[08:14:59] reader: end of chapter 1 (media 1) reached at media chapter 2
[08:14:59] reader: done. 4 scr changes
[08:15:00] sync: got 9584 frames, 9622 expected
[08:15:00] work: average encoding speed for job is 52.458065 fps
[08:15:00] mpeg2 done: 9605 frames
[08:15:00] render: lost time: 0 (0 frames)
[08:15:00] render: gained time: 0 (0 frames) (0 not accounted for)
x264 [info]: slice I:78    Avg QP:19.01  size: 14955  PSNR Mean Y:44.27 U:48.49 V:49.15 Avg:45.30 Global:44.49
x264 [info]: slice P:9506  Avg QP:21.33  size:  3913  PSNR Mean Y:41.47 U:45.62 V:46.38 Avg:42.48 Global:42.06
x264 [info]: mb I  I16..4: 15.0%  0.0% 85.0%
x264 [info]: mb P  I16..4:  0.7%  0.0%  2.7%  P16..4: 54.8% 23.7% 10.0%  0.7%  0.8%    skip: 6.7%
x264 [info]: ref P L0  75.6% 24.4%
x264 [info]: SSIM Mean Y:0.9714972
x264 [info]: PSNR Mean Y:41.492 U:45.645 V:46.398 Avg:42.498 Global:42.071 kb/s:767.79
[08:15:00] libhb: work result = 0

Code: Select all

FFmpeg version SVN-r15261, Copyright (c) 2000-2008 Fabrice Bellard, et al.
  configuration: --prefix=/usr --incdir=/usr/include/ffmpeg --libdir=/usr/lib64 --mandir=/usr/share/man --arch=x86_64 --extra-cflags=-O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic --enable-bzlib --enable-libdc1394 --enable-libfaac --enable-libfaad --enable-libgsm --enable-libmp3lame --enable-libschroedinger --enable-libtheora --enable-libvorbis --enable-libx264 --enable-libxvid --enable-x11grab --enable-avfilter --enable-avfilter-lavf --enable-postproc --enable-swscale --enable-pthreads --disable-static --enable-shared --enable-gpl --disable-debug --disable-optimizations --disable-stripping --shlibdir=/usr/lib64
  libavutil     49.10. 0 / 49.10. 0
  libavcodec    51.71. 0 / 51.71. 0
  libavformat   52.22. 1 / 52.22. 1
  libavdevice   52. 1. 0 / 52. 1. 0
  libavfilter    0. 1. 0 /  0. 1. 0
  libswscale     0. 6. 1 /  0. 6. 1
  libpostproc   51. 2. 0 / 51. 2. 0
  built on Feb  4 2009 14:16:07, gcc: 4.3.2 20081105 (Red Hat 4.3.2-7)
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from '/home/jstebbins/Videos/Robocop.mp4':
  Duration: 00:06:39.82, start: 0.000000, bitrate: 812 kb/s
    Stream #0.0(eng): Video: h264, yuv420p, 480x272, 24000.00 tb(r)
    Stream #0.1(fra): Audio: aac, 24000 Hz, mono, s16
    Stream #0.2(eng): Subtitle: text / 0x74786574
Must supply at least one output file

[rch2]

I've tried, but have been unsuccessful at reproducing this. Your log looks normal. Any chance ffmpeg is lying to you? I tried several discs including a PAL disc.

The output audio stream problem is apparently for real. If ffmpeg were lying to me, then so would mplayer and vlc (although they are somewhat related I guess).

I was able to reproduce this problem with Handbrake on Windows. Then, I reproduced the same problem using ffmpeg without Handbrake by converting a VOB file from the offending DVD.

Good news and bad news. Apparently, isn't neither Handbrake problem nor platform problem. It this point I am suspecting a bug in ffmpeg itself. Bad news is I have never interfaced with ffmpeg developers. Any help in directing me to the right resource is appreciated.

[refulgentis]

I've tried, but have been unsuccessful at reproducing this. Your log looks normal. Any chance ffmpeg is lying to you? I tried several discs including a PAL disc.

The output audio stream problem is apparently for real. If ffmpeg were lying to me, then so would mplayer and vlc (although they are somewhat related I guess).

I was able to reproduce this problem with Handbrake on Windows. Then, I reproduced the same problem using ffmpeg without Handbrake by converting a VOB file from the offending DVD.

Good news and bad news. Apparently, isn't neither Handbrake problem nor platform problem. It this point I am suspecting a bug in ffmpeg itself. Bad news is I have never interfaced with ffmpeg developers. Any help in directing me to the right resource is appreciated.

they want a rather large mount of material for bug reporting. if you get really lucky, show up in #ffmpeg on freenode at the right time, have the problem down to a specific codec/muxer, and the maintainer for said codec/muxer is interested in hearing from users, and they're around to listen, then you might get some help. i would have a small sample clip uploaded somewhere in case an altruistic soul takes interest as well.

your best bet is to try to nail it down further in ffmpeg before going to them.

EDIT - they'll want you to be using SVN code too, the speed of development there has rapidly accelerated over the past couple years.

[rch2]

EDIT - they'll want you to be using SVN code too, the speed of development there has rapidly accelerated over the past couple years.

and that's what fixes it. The problem is reproducible with older ffmpeg (circa June 2008) and is fixed with ffmpeg circa January 2009 (specifically, SNV-r16596). I presume handbrake is using the older library?

[cvk_b]

The problem is reproducible with older ffmpeg (circa June 2008) and is fixed with ffmpeg circa January 2009 (specifically, SNV-r16596). I presume handbrake is using the older library?

FFMPEG.FETCH.url = /handbrake/contrib/ffmpeg-r15974.tar.gz

[rch2]

The problem is reproducible with older ffmpeg (circa June 2008) and is fixed with ffmpeg circa January 2009 (specifically, SNV-r16596). I presume handbrake is using the older library?

FFMPEG.FETCH.url = /handbrake/contrib/ffmpeg-r15974.tar.gz

Gotcha. Well, that explains the problem.

[Ritsuka]

Explain what? The only thing from ffmpeg you're using in HandBrake is the image scaler. ffmpeg cli and muxers bugs have nothing to do with handbrake.

[JohnAStebbins]

rch2, when you say "and that's what fixes it", do you mean that after installing the svn version of ffmpeg, it reported the correct information about your files? If so, then this problem has nothing to do with handbrake. Updating ffmpeg does not change how handbrake works since the libraries we use from ffmpeg are statically linked. The bug was in the version of ffmpeg you were using to examine the files. That's why in my original post I asked if there was any chance ffmpeg was lying to you.

[rch2]

rch2, when you say "and that's what fixes it", do you mean that after installing the svn version of ffmpeg, it reported the correct information about your files? If so, then this problem has nothing to do with handbrake. Updating ffmpeg does not change how handbrake works since the libraries we use from ffmpeg are statically linked. The bug was in the version of ffmpeg you were using to examine the files. That's why in my original post I asked if there was any chance ffmpeg was lying to you.

When I say it fixes it, I am saying that I am getting the expected result when using new (SVN-r17854) ffmpeg to decode and encode. I haven't rebuilt Handbrake -- I took the one from the Ubuntu ppa repository -- and I presume it was built against much older ffmpeg.