[SVN 2030] Encoding stops at 100% of first pass

[burns1111]

Hey there. Updated the other day to SVN 2030. Some titles have stopped at the first pass of encoding. It goes to 100% but does not continue on to the second pass. It does not crash, but after hours of leaving the file to see if it finished (say, if there was a problem with the progress bar advancing), nothing. I also attempted the encode with only one-pass, but the same results happen (stops at 100% without completing).

The source was originally an M2TS file which pulled in fine. After the troubles, I remuxed things to a TS file (using TSMuxer), but that didn't help (see log below). As a side note, the new video preview (in picture settings) encodes and plays just fine (the feature is amazing).

Setup: Ubuntu 8.10 (Q6600, 4gb RAM)
Source: 1h59m TS (mt2s, tsmuxed, h264, AC3, English-Subtitle)
Activity Log:

Code: Select all

[11:15:57] lingui: Handbrake Version: svn2030 (2008121301)
[11:15:58] hb_init: checking cpu count
[11:15:58] hb_init: starting libhb thread
[11:15:58] hb_init: checking cpu count
[11:15:58] hb_init: starting libhb thread
[11:16:10] hb_scan: path=/encodes/Amelie/amelie.ts, title_index=0
[11:16:10] scan: trying to open with libdvdread
[11:16:10] dvd: not a dvd - trying as a stream/file instead
[11:16:10] file is MPEG Transport Stream with 188 byte packets offset 0 bytes
[11:16:10] hb_ts_stream_find_pids - found the following PIDS
[11:16:10]     Video PIDS : 
[11:16:10]       0x1011 type H.264 (0x1b)
[11:16:10]     Audio PIDS : 
[11:16:10]       0x1100 type AC-3 (0x81)
[11:16:10]       0x1200 type Unknown (0x90)
[11:16:10] transport stream pid 0x1100 (type 0x81) may be AC-3 audio (id 0x1)
[11:16:10] transport stream pid 0x1200 (type 0x90, substream 0xbd) isn't audio
[11:16:10] scan: decoding previews for title 1
[11:16:10] scan: audio 0x1: AC-3, rate=48000Hz, bitrate=448000 Francais (AC3) (5.1 ch)
[11:16:12] scan: 10 previews, 1920x1080, 29.970 fps, autocrop = 132/132/2/4, aspect 16:9, PAR 1:1
[11:16:12] scan: title (0) job->width:1920, job->height:816
[11:16:12] stream: 3 good frames, 0 errors (0%)
[11:16:12] libhb: scan thread found 1 valid title(s)
[11:17:28] hb_scan: path=/encodes/Amelie/amelie.ts, title_index=1
[11:17:28] scan: trying to open with libdvdread
[11:17:28] dvd: not a dvd - trying as a stream/file instead
[11:17:28] file is MPEG Transport Stream with 188 byte packets offset 0 bytes
[11:17:28] hb_ts_stream_find_pids - found the following PIDS
[11:17:28]     Video PIDS : 
[11:17:28]       0x1011 type H.264 (0x1b)
[11:17:28]     Audio PIDS : 
[11:17:28]       0x1100 type AC-3 (0x81)
[11:17:28]       0x1200 type Unknown (0x90)
[11:17:28] transport stream pid 0x1100 (type 0x81) may be AC-3 audio (id 0x1)
[11:17:28] transport stream pid 0x1200 (type 0x90, substream 0xbd) isn't audio
[11:17:28] scan: decoding previews for title 1
[11:17:28] scan: audio 0x1: AC-3, rate=48000Hz, bitrate=448000 Francais (AC3) (5.1 ch)
[11:17:29] scan: 10 previews, 1920x1080, 29.970 fps, autocrop = 132/132/2/4, aspect 16:9, PAR 1:1
[11:17:29] scan: title (0) job->width:1920, job->height:816
[11:17:29] stream: 3 good frames, 0 errors (0%)
[11:17:29] libhb: scan thread found 1 valid title(s)
[11:17:29] lingui: Modified Custom Preset: Set1
[11:17:29] 2 job(s) to process
[11:17:29] starting job
[11:17:29] job configuration:
[11:17:29]  * source
[11:17:29]    + /encodes/Amelie/amelie.ts
[11:17:29]    + title 1, chapter(s) 1 to 1
[11:17:29]  * destination
[11:17:29]    + /encodes/amelie.ts.mkv
[11:17:29]    + container: Matroska (.mkv)
[11:17:29]  * video track
[11:17:29]    + decoder: h264
[11:17:29]      + bitrate 200 kbps
[11:17:29]    + frame rate: same as source (around 29.970 fps)
[11:17:29]    + loose anamorphic
[11:17:29]      + storage dimensions: 1920 * 1080 -> 1920 * 816, crop 132/132/2/4
[11:17:29]      + pixel aspect ratio: 319 / 320
[11:17:29]      + display dimensions: 1914 * 816
[11:17:29]    + filter
[11:17:29]      + Deinterlaces selectively with yadif/mcdeint and lowpass5 blending (default settings)
[11:17:29]    + encoder: x264
[11:17:29]      + options: ref=5:mixed-refs:bframes=6:weightb:direct=auto:b-pyramid:me=umh:subme=7:analyse=all:8x8dct:trellis=1:no-fast-pskip:psy-rd=1,1:merange=24:ref=1:subme=1:me=dia:analyse=none:trellis=0:no-fast-pskip=0:8x8dct=0:weightb=0
[11:17:29]      + bitrate: 8648 kbps, pass: 1
[11:17:29]  * audio track 0
[11:17:29]    + decoder: Francais (AC3) (5.1 ch) (track 1, id 1)
[11:17:29]      + bitrate: 448 kbps, samplerate: 48000 Hz
[11:17:29]    + AC3 passthrough
[11:17:29] dvd: not a dvd - trying as a stream/file instead
[11:17:29] reader: first SCR 53955000
[11:17:29] yadif thread started for segment 0
[11:17:29] yadif thread started for segment 1
[11:17:29] yadif thread started for segment 2
[11:17:29] yadif thread started for segment 3
[11:17:29] decomb thread started for segment 0
[11:17:29] decomb thread started for segment 1
[11:17:29] decomb thread started for segment 2
[11:17:29] decomb thread started for segment 3
[11:17:29] encx264: keyint-min: 30, keyint-max: 300
[11:17:29] encx264: encoding with stored aspect 319/320
x264 [info]: using SAR=319/320
x264 [info]: using cpu capabilities: MMX2 SSE2Fast SSSE3 Cache64
x264 [info]: profile Main, level 4.0
No accelerated IMDCT transform found
[11:17:29] sync: expecting 215528 video frames
[11:17:30] sync: first pts is 3003

[burns1111]

Bit of an update here. I updated to 2049 and am still able to reproduce the problem. However, I found I had more of an activity log after I stopped the encode when it hit 100% and didn't go any further. Since it was not obvious at all to me where the problem lied by what the last log said, maybe this will help a little more:

Code: Select all

[22:05:44] lingui: Handbrake Version: svn2049 (2008122901)
[22:05:45] hb_init: checking cpu count
[22:05:45] hb_init: starting libhb thread
[22:05:45] thread 41003950 started ("libhb")
[22:05:45] hb_init: checking cpu count
[22:05:45] hb_init: starting libhb thread
[22:05:45] thread 41804950 started ("libhb")
[22:06:18] hb_scan: path=/encodes/Amelie/amelie.ts, title_index=0
[22:06:18] thread 40802950 started ("scan")
[22:06:18] scan: trying to open with libdvdread
[22:06:18] dvd: not a dvd - trying as a stream/file instead
[22:06:18] file is MPEG Transport Stream with 188 byte packets offset 0 bytes
[22:06:18] hb_ts_stream_find_pids - found the following PIDS
[22:06:18]     Video PIDS : 
[22:06:18]       0x1011 type H.264 (0x1b)
[22:06:18]     Audio PIDS : 
[22:06:18]       0x1100 type AC-3 (0x81)
[22:06:19] transport stream pid 0x1100 (type 0x81) may be AC-3 audio (id 0x1)
[22:06:19] scan: decoding previews for title 1
[22:06:19] scan: preview 1
[22:06:19] scan: audio 0x1: AC-3, rate=48000Hz, bitrate=448000 English (AC3) (5.1 ch)
[22:06:19] scan: preview 2
[22:06:19] scan: preview 3
[22:06:20] scan: preview 4
[22:06:20] Interlacing detected in preview frame 4
[22:06:20] scan: preview 5
[22:06:21] scan: preview 6
[22:06:21] scan: preview 7
[22:06:21] scan: preview 8
[22:06:21] Interlacing detected in preview frame 8
[22:06:21] scan: preview 9
[22:06:22] scan: preview 10
[22:06:23] scan: 10 previews, 1920x1080, 29.970 fps, autocrop = 132/132/2/4, aspect 16:9, PAR 1:1
[22:06:23] scan: title (0) job->width:1920, job->height:816
[22:06:23] stream: 3 good frames, 0 errors (0%)
[22:06:23] thread 40802950 exited ("scan")
[22:06:23] thread 40802950 joined ("scan")
[22:06:23] libhb: scan thread found 1 valid title(s)
[22:07:32] hb_scan: path=/encodes/Amelie/amelie.ts, title_index=1
[22:07:32] thread 42005950 started ("scan")
[22:07:32] scan: trying to open with libdvdread
[22:07:32] dvd: not a dvd - trying as a stream/file instead
[22:07:32] file is MPEG Transport Stream with 188 byte packets offset 0 bytes
[22:07:32] hb_ts_stream_find_pids - found the following PIDS
[22:07:32]     Video PIDS : 
[22:07:32]       0x1011 type H.264 (0x1b)
[22:07:32]     Audio PIDS : 
[22:07:32]       0x1100 type AC-3 (0x81)
[22:07:32] transport stream pid 0x1100 (type 0x81) may be AC-3 audio (id 0x1)
[22:07:32] scan: decoding previews for title 1
[22:07:32] scan: preview 1
[22:07:32] scan: audio 0x1: AC-3, rate=48000Hz, bitrate=448000 English (AC3) (5.1 ch)
[22:07:32] scan: preview 2
[22:07:32] scan: preview 3
[22:07:32] scan: preview 4
[22:07:32] Interlacing detected in preview frame 4
[22:07:32] scan: preview 5
[22:07:32] scan: preview 6
[22:07:32] scan: preview 7
[22:07:33] scan: preview 8
[22:07:33] Interlacing detected in preview frame 8
[22:07:33] scan: preview 9
[22:07:33] scan: preview 10
[22:07:33] scan: 10 previews, 1920x1080, 29.970 fps, autocrop = 132/132/2/4, aspect 16:9, PAR 1:1
[22:07:33] scan: title (0) job->width:1920, job->height:816
[22:07:33] stream: 3 good frames, 0 errors (0%)
[22:07:33] thread 42005950 exited ("scan")
[22:07:33] thread 42005950 joined ("scan")
[22:07:33] libhb: scan thread found 1 valid title(s)
[22:07:33] lingui: Modified Custom Preset: Set1
[22:07:33] thread 42005950 started ("work")
[22:07:33] 2 job(s) to process
[22:07:33] starting job
[22:07:33] job configuration:
[22:07:33]  * source
[22:07:33]    + /encodes/Amelie/amelie.ts
[22:07:33]    + title 1, chapter(s) 1 to 1
[22:07:33]  * destination
[22:07:33]    + /encodes/amelie.ts.mkv
[22:07:33]    + container: Matroska (.mkv)
[22:07:33]      + chapter markers
[22:07:33]  * video track
[22:07:33]    + decoder: h264
[22:07:33]      + bitrate 200 kbps
[22:07:33]    + frame rate: same as source (around 29.970 fps)
[22:07:33]    + loose anamorphic
[22:07:33]      + storage dimensions: 1920 * 1080 -> 1920 * 816, crop 132/132/2/4
[22:07:33]      + pixel aspect ratio: 319 / 320
[22:07:33]      + display dimensions: 1914 * 816
[22:07:33]    + filter
[22:07:33]      + Deinterlaces selectively with yadif/mcdeint and lowpass5 blending (default settings)
[22:07:33]    + encoder: x264
[22:07:33]      + options: ref=5:mixed-refs:bframes=6:weightb:direct=auto:b-pyramid:me=umh:subme=7:analyse=all:8x8dct:trellis=1:no-fast-pskip:psy-rd=1,1:merange=24:ref=1:subme=1:me=dia:analyse=none:trellis=0:no-fast-pskip=0:8x8dct=0:weightb=0
[22:07:33]      + bitrate: 8417 kbps, pass: 1
[22:07:33]  * audio track 0
[22:07:33]    + decoder: English (AC3) (5.1 ch) (track 1, id 1)
[22:07:33]      + bitrate: 448 kbps, samplerate: 48000 Hz
[22:07:33]    + AC3 passthrough
[22:07:33] thread 40802950 started ("reader")
[22:07:33] dvd: not a dvd - trying as a stream/file instead
[22:07:33] thread 42806950 started ("Video decoder (libavcodec)")
[22:07:33] reader: first SCR 53955000
[22:07:33] thread 43007950 started ("yadif_filter_segment")
[22:07:33] yadif thread started for segment 0
[22:07:33] thread 43808950 started ("yadif_filter_segment")
[22:07:33] yadif thread started for segment 1
[22:07:33] thread 44009950 started ("yadif_filter_segment")
[22:07:33] yadif thread started for segment 2
[22:07:33] thread 4480a950 started ("yadif_filter_segment")
[22:07:33] yadif thread started for segment 3
[22:07:33] thread 4500b950 started ("decomb_filter_segment")
[22:07:33] decomb thread started for segment 0
[22:07:33] thread 4580c950 started ("decomb_filter_segment")
[22:07:33] decomb thread started for segment 1
[22:07:33] thread 4600d950 started ("decomb_filter_segment")
[22:07:33] decomb thread started for segment 2
[22:07:33] thread 4680e950 started ("decomb_filter_segment")
[22:07:33] decomb thread started for segment 3
[22:07:33] thread 4700f950 started ("Renderer")
[22:07:33] encx264: keyint-min: 30, keyint-max: 300
[22:07:33] encx264: encoding with stored aspect 319/320
[22:07:33] encx264: opening libx264 (pass 1)
x264 [info]: using SAR=319/320
x264 [info]: using cpu capabilities: MMX2 SSE2Fast SSSE3 Cache64
x264 [info]: profile Main, level 4.0
[22:07:33] thread 47810950 started ("H.264/AVC encoder (libx264)")
No accelerated IMDCT transform found
[22:07:33] thread 48011950 started ("AC3 decoder")
[22:07:33] thread 48812950 started ("muxer")
[22:07:33] sync: expecting 215465 video frames
[22:07:33] sync: first pts is 3003
[07:32:11] sync: got 218817 frames, 215465 expected
[07:32:11] work: average encoding speed for job is 19.626898 fps
[07:32:11] thread 48812950 exited ("muxer")
[07:32:11] thread 48812950 joined ("muxer")
[07:32:11] thread 42806950 exited ("Video decoder (libavcodec)")
[07:32:11] thread 42806950 joined ("Video decoder (libavcodec)")
[07:32:11] h264-decoder done: 218818 frames, 0 decoder errors, 0 drops
[07:32:11] thread 4700f950 exited ("Renderer")
[07:32:11] thread 4700f950 joined ("Renderer")
[07:32:11] render: lost time: 0 (0 frames)
[07:32:11] render: gained time: 0 (0 frames) (0 not accounted for)
[07:32:11] fifo_close: trashing 1 buffer(s)
[07:32:11] fifo_close: trashing 0 buffer(s)
[07:32:11] thread 47810950 exited ("H.264/AVC encoder (libx264)")
[07:32:11] thread 47810950 joined ("H.264/AVC encoder (libx264)")
x264 [info]: slice I:1693  Avg QP:16.59  size:140995  PSNR Mean Y:47.38 U:48.95 V:49.31 Avg:47.82 Global:46.96
x264 [info]: slice P:77061 Avg QP:18.36  size: 59287  PSNR Mean Y:44.98 U:46.62 V:47.36 Avg:45.49 Global:44.41
x264 [info]: slice B:140051 Avg QP:20.36  size: 20143  PSNR Mean Y:43.72 U:45.63 V:46.56 Avg:44.33 Global:43.52
x264 [info]: consecutive B-frames: 11.3% 20.2%  6.7% 10.3% 22.4% 26.6%  2.5%
x264 [info]: mb I  I16..4: 23.7%  0.0% 76.3%
x264 [info]: mb P  I16..4: 27.1%  0.0%  0.0%  P16..4: 67.3%  0.0%  0.0%  0.0%  0.0%    skip: 5.5%
x264 [info]: mb B  I16..4:  3.8%  0.0%  0.0%  B16..8: 32.3%  0.0%  0.0%  direct:32.7%  skip:31.2%  L0:33.4% L1:53.4% BI:13.2%
x264 [info]: final ratefactor: 21.76
x264 [info]: direct mvs  spatial:100.0%  temporal:0.0%
x264 [info]: SSIM Mean Y:0.9798066
x264 [info]: PSNR Mean Y:44.193 U:46.001 V:46.864 Avg:44.764 Global:43.833 kb/s:8359.09
[07:32:11] stream: 218820 good frames, 0 errors (0%)
[07:32:11] reader: done. 1 scr changes
[07:32:11] thread 40802950 exited ("reader")
[07:32:11] thread 48011950 exited ("AC3 decoder")
[07:32:11] thread 48011950 joined ("AC3 decoder")
[07:32:11] thread 40802950 joined ("reader")
[07:32:11] fifo_close: trashing 1 buffer(s)
[07:32:11] fifo_close: trashing 0 buffer(s)
[07:32:11] fifo_close: trashing 0 buffer(s)
[07:32:11] fifo_close: trashing 0 buffer(s)
[07:32:11] fifo_close: trashing 0 buffer(s)
[07:32:11] fifo_close: trashing 34 buffer(s)
[07:32:11] fifo_close: trashing 32 buffer(s)
[07:32:11] fifo_close: trashing 0 buffer(s)
[07:32:11] fifo_close: trashing 32 buffer(s)
[07:32:11] decomb: yadif deinterlaced 74842 | blend deinterlaced 4916 | unfiltered 139058 | total 218816
[07:32:11] thread 43007950 exited ("yadif_filter_segment")
[07:32:11] thread 43007950 joined ("yadif_filter_segment")
[07:32:11] thread 43808950 exited ("yadif_filter_segment")
[07:32:11] thread 43808950 joined ("yadif_filter_segment")
[07:32:11] thread 44009950 exited ("yadif_filter_segment")
[07:32:11] thread 44009950 joined ("yadif_filter_segment")
[07:32:11] thread 4480a950 exited ("yadif_filter_segment")
[07:32:11] thread 4480a950 joined ("yadif_filter_segment")
[07:32:11] thread 4500b950 exited ("decomb_filter_segment")
[07:32:11] thread 4500b950 joined ("decomb_filter_segment")
[07:32:11] thread 4580c950 exited ("decomb_filter_segment")
[07:32:11] thread 4580c950 joined ("decomb_filter_segment")
[07:32:11] thread 4600d950 exited ("decomb_filter_segment")
[07:32:11] thread 4600d950 joined ("decomb_filter_segment")
[07:32:11] thread 4680e950 exited ("decomb_filter_segment")
[07:32:11] thread 4680e950 joined ("decomb_filter_segment")
[07:32:11] Freed 1 buffers of size 1024
[07:32:11] Freed 32 buffers of size 2048
[07:32:11] Freed 32 buffers of size 262144
[07:32:11] Freed 32 buffers of size 524288
[07:32:11] Freed 32 buffers of size 4194304
[07:32:11] Allocated 159450112 bytes of buffers on this pass and Freed 159450112 bytes, 0 bytes leaked
[07:32:11] thread 42005950 exited ("work")
[07:32:11] thread 42005950 joined ("work")
[07:32:11] libhb: work result = 0

[JohnAStebbins]

Your problem may be the known "mkv stall" problem. There's a few things you could try. Since it's not stalling till 100%, you could try doing a single pass encode. Then have a look to see how much (if any) of the end is missing. You'll get better quality with single pass constant quality anyway. You can also try using mp4 instead of mkv. This would tell us more definitively that its the known mkv problem. Since your building from svn, you could also make a small change in libhb/work.c that may help. Change "#define FIFO_CPU_MULT 8" to "#define FIFO_CPU_MULT 32". This often helps get past the stall, but in my experience, there's always some sort of video glitch at the point that it would have stalled.

[burns1111]

Thanks for the reply. I started with changing up the work.c, but that didn't solve the problem. I then encoded it into an AVI and it worked just fine. No video corruption that I could see during the movie. I was able to re-mux it into a MKV after that with the subtitles I had for the film.

Strange problem! Thanks for the solution!


Cheers.