[svn1566] Encode ends early when resuming from pause

Archive of historical bug reports.
Please use the GitHub link above to report issues.
Forum rules
*******************************
Please be aware we are now using GitHub for issue tracking and feature requests.
- This section of the forum is now closed to new topics.

*******************************
Locked
jzietman
Enlightened
Posts: 146
Joined: Mon Feb 04, 2008 3:29 pm

[svn1566] Encode ends early when resuming from pause

Post by jzietman »

I've had this happen to me a few times now (maybe three), where I've paused Handbrake for a while to watch a movie on my computer, and when I resume, it encodes for a minute or two, and then muxes and complete the encode as if it were finished, even though it's nowhere near done. I was just encoding Forest Gump, and here's the activity log that comes along with it:

Code: Select all

[17:01:19] macgui: Handbrake Version: svn1566 (2008071101)
[17:01:20] hb_init: checking cpu count
[17:01:20] hb_init: starting libhb thread
[17:01:20] thread b01c9000 started ("libhb")
[17:01:25] macgui: trying to open video_ts folder (parent directory chosen)
[17:01:25] hb_scan: path=/Volumes/Movies/FOREST, title_index=0
[17:01:25] thread b00c5000 started ("scan")
[17:01:25] scan: trying to open with libdvdread
[17:01:25] scan: DVD has 1 title(s)
[17:01:25] scan: scanning title 1
[17:01:25] scan: opening IFO for VTS 1
[17:01:25] pgc_id: 1, pgn: 1: pgc: 0xec43480
[17:01:25] scan: vts=1, ttn=1, cells=0->52, blocks=0->3559574, 3559575 blocks
[17:01:25] scan: duration is 02:21:56 (8516320 ms)
[17:01:25] scan: checking audio 1
[17:01:25] scan: id=80bd, lang=English (AC3), 3cc=eng
[17:01:25] scan: title 1 has 19 chapters
[17:01:25] scan: chap 1 c=0->5, b=0->173218 (173219), 399423 ms
[17:01:25] scan: chap 2 c=6->8, b=173219->304465 (131247), 339966 ms
[17:01:25] scan: chap 3 c=9->10, b=304466->504327 (199862), 452122 ms
[17:01:25] scan: chap 4 c=11->16, b=504328->788791 (284464), 676555 ms
[17:01:25] scan: chap 5 c=17->19, b=788792->1015341 (226550), 566499 ms
[17:01:25] scan: chap 6 c=20->20, b=1015342->1103290 (87949), 217433 ms
[17:01:25] scan: chap 7 c=21->24, b=1103291->1459272 (355982), 735133 ms
[17:01:25] scan: chap 8 c=25->29, b=1459273->1632013 (172741), 416319 ms
[17:01:25] scan: chap 9 c=30->33, b=1632014->1893696 (261683), 601280 ms
[17:01:25] scan: chap 10 c=34->34, b=1893697->1977266 (83570), 208540 ms
[17:01:25] scan: chap 11 c=35->36, b=1977267->2130027 (152761), 409201 ms
[17:01:25] scan: chap 12 c=37->39, b=2130028->2409887 (279860), 666738 ms
[17:01:25] scan: chap 13 c=40->41, b=2409888->2508977 (99090), 235554 ms
[17:01:25] scan: chap 14 c=42->42, b=2508978->2628184 (119207), 297520 ms
[17:01:25] scan: chap 15 c=43->44, b=2628185->2806389 (178205), 454824 ms
[17:01:25] scan: chap 16 c=45->46, b=2806390->3002306 (195917), 445998 ms
[17:01:25] scan: chap 17 c=47->48, b=3002307->3138367 (136061), 353794 ms
[17:01:25] scan: chap 18 c=49->50, b=3138368->3406177 (267810), 637590 ms
[17:01:25] scan: chap 19 c=51->52, b=3406178->3559574 (153397), 401822 ms
[17:01:25] scan: aspect = 16
[17:01:25] scan: decoding previews for title 1
[17:01:27] scan: preview 1
[17:01:27] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=448000 English (AC3) (5.1 ch)
[17:01:27] scan: preview 2
[17:01:27] scan: preview 3
[17:01:27] scan: preview 4
[17:01:27] scan: preview 5
[17:01:27] scan: preview 6
[17:01:28] Title's mostly NTSC Film, setting fps to 23.976
[17:01:28] scan: preview 7
[17:01:28] scan: preview 8
[17:01:28] scan: preview 9
[17:01:28] scan: preview 10
[17:01:28] scan: 10 previews, 720x480, 23.976 fps, autocrop = 58/64/2/0, aspect 16:9, PAR 32:27
[17:01:28] scan: title (0) job->width:720, job->height:304
[17:01:28] thread b00c5000 exited ("scan")
[17:01:28] thread b00c5000 joined ("scan")
[17:01:28] libhb: scan thread found 1 valid title(s)
[17:02:55] thread b00c5000 started ("work")
[17:02:55] 1 job(s) to process
[17:02:55] starting job
[17:02:55]  + device /Volumes/Movies/FOREST
[17:02:55]  + title 1, chapter(s) 1 to 19
[17:02:55]  + 720x480 -> 720x352, crop 58/64/2/0
[17:02:55]  + filters
[17:02:55]    + Detelecine (pullup) (default settings)
[17:02:55]    + Deinterlaces selectively with yadif/mcdeint or lowpass5 blending (1:2:6:9:80:16:16)
[17:02:55]  + video frame rate: 23.976 fps -> variable fps
[17:02:55]  + video quality 0.65
[17:02:55]  + PixelRatio: 2, width:720, height: 352
[17:02:55]  + encoder x264
[17:02:55]    + x264 options: ref=6:mixed-refs=1:bframes=9:bime=1:brdo=1:me=umh:subq=6:trellis=1:analyse=all:no-fast-pskip=1:direct=auto:no-dct-decimate=1:merange=24:vbv-maxrate=4900:vbv-bufsize=3500:weightb=1:8x8dct=1:b-pyramid=1
[17:02:55]  + audio track 0
[17:02:55]    + input track 0
[17:02:55]    + audio 128 kbps, 48000 Hz
[17:02:55]    + encoder faac
[17:02:55]      + 80bd, English (AC3) (5.1 ch)
[17:02:55]        + Requested mixdown: Dolby Pro Logic II (HB_AMIXDOWN_DOLBYPLII)
[17:02:55]        + Actual mixdown: Dolby Pro Logic II (HB_AMIXDOWN_DOLBYPLII)
[17:02:55] thread b04d5000 started ("reader")
[17:02:55]  + output: /Users/jzietman/Movies/Forest Gump.m4v
[17:02:55] thread b0579000 started ("muxer")
[17:02:55] thread b05fb000 started ("MPEG-2 decoder (libmpeg2)")
[17:02:55] thread b09fe000 started ("Renderer")
[17:02:55] encx264: keyint-min: 24, keyint-max: 240
[17:02:55] encx264: encoding with stored aspect 167/144
[17:02:55] encx264: Encoding at constant RF 17.850002
[17:02:55] encx264: opening libx264 (pass 0)
x264 [info]: using SAR=167/144
x264 [info]: using cpu capabilities: MMX2 SSE2Fast SSSE3 Cache64
[17:02:55] thread b0a80000 started ("H.264/AVC encoder (libx264)")
No accelerated IMDCT transform found
[17:02:55] reader: first SCR 146 scr_offset 14788
[17:02:55] thread b0b02000 started ("AC3 decoder")
[17:02:55] mpeg2: "Chapter  1" (1) at frame 0 time 3003
[17:02:55] thread b0b84000 started ("AAC encoder (libfaac)")
[17:02:55] sync: expecting 204211 video frames
[17:02:55] sync: first pts is 3003
[17:02:56] macgui: Using preset: CQ good
[17:14:34] sync: adding 74 ms of silence to audio 0  start 25442820, next 25436160
[17:21:21] mpeg2: "Chapter  2" (2) at frame 9616 time 36101086
[17:35:23] mpeg2: "Chapter  3" (3) at frame 17792 time 66790354
[17:58:01] mpeg2: "Chapter  4" (4) at frame 28624 time 107451457
[18:32:33] mpeg2: "Chapter  5" (5) at frame 44864 time 168411908
[18:57:02] mpeg2: "Chapter  6" (6) at frame 58444 time 219390308
[19:08:16] mpeg2: "Chapter  7" (7) at frame 63669 time 239002901
[19:55:09] mpeg2: "Chapter  8" (8) at frame 81320 time 305261152
[20:13:13] mpeg2: "Chapter  9" (9) at frame 91341 time 342877798
[20:32:28] sync: adding 239 ms of silence to audio 0  start 377240028, next 377218452
[20:32:49] encx264: init_delay too small: is 15012 need 19210
[20:32:49] encx264: init_delay too small: is 15012 need 26717
[20:43:34] mpeg2: "Chapter 10" (10) at frame 105770 time 397057114
[20:53:18] mpeg2: "Chapter 11" (11) at frame 110774 time 415840879
[21:12:13] mpeg2: "Chapter 12" (12) at frame 120593 time 452700017
[21:46:59] mpeg2: "Chapter 13" (13) at frame 136598 time 512778929
[22:00:31] mpeg2: "Chapter 14" (14) at frame 142249 time 533992838
[22:13:43] mpeg2: "Chapter 15" (15) at frame 149377 time 560748533
[22:36:12] mpeg2: "Chapter 16" (16) at frame 160297 time 601738332
GUI ERROR dialog: dvd: DVDReadBlocks failed (2856865), skipping to vobu 2857094
[00:24:44] dvd: Read Error on blk 2857094, attempt 0
[00:24:44] dvd: Read Error on blk 2857094, attempt 1
[00:24:44] dvd: Read Error on blk 2857094, attempt 2
[00:24:44] dvd: vobu read error blk 2857094 - skipping to cell 46
[00:24:44] dvd: Read Error on blk 2932261, attempt 0
[00:24:44] dvd: Read Error on blk 2932261, attempt 1
[00:24:44] dvd: Read Error on blk 2932261, attempt 2
[00:24:44] dvd: vobu read error blk 2932261 - skipping to cell 47
[00:24:44] dvd: Read Error on blk 3002307, attempt 0
[00:24:44] dvd: Read Error on blk 3002307, attempt 1
[00:24:44] dvd: Read Error on blk 3002307, attempt 2
[00:24:44] dvd: vobu read error blk 3002307 - skipping to cell 48
[00:24:44] dvd: Read Error on blk 3119537, attempt 0
[00:24:44] dvd: Read Error on blk 3119537, attempt 1
[00:24:44] dvd: Read Error on blk 3119537, attempt 2
[00:24:44] dvd: vobu read error blk 3119537 - skipping to cell 49
[00:24:44] dvd: Read Error on blk 3138368, attempt 0
[00:24:44] dvd: Read Error on blk 3138368, attempt 1
[00:24:44] dvd: Read Error on blk 3138368, attempt 2
[00:24:44] dvd: vobu read error blk 3138368 - skipping to cell 50
[00:24:44] dvd: Read Error on blk 3308811, attempt 0
[00:24:44] dvd: Read Error on blk 3308811, attempt 1
[00:24:44] dvd: Read Error on blk 3308811, attempt 2
[00:24:44] dvd: vobu read error blk 3308811 - skipping to cell 51
[00:24:44] dvd: Read Error on blk 3406178, attempt 0
[00:24:44] dvd: Read Error on blk 3406178, attempt 1
[00:24:44] dvd: Read Error on blk 3406178, attempt 2
[00:24:44] dvd: vobu read error blk 3406178 - skipping to cell 52
[00:24:44] dvd: Read Error on blk 3557213, attempt 0
[00:24:44] dvd: Read Error on blk 3557213, attempt 1
[00:24:44] dvd: Read Error on blk 3557213, attempt 2
[00:24:44] dvd: vobu read error blk 3557213 - skipping to cell 53
[00:24:44] reader: done. 31 scr changes
[00:24:44] thread b04d5000 exited ("reader")
[00:24:44] sync: reader has exited, adding silence to audio 0
[00:24:56] sync: got 163170 frames, 204211 expected
[00:24:56] sync: added 5088 ms of silence to audio 0
[00:24:56] thread b0b02000 exited ("AC3 decoder")
[00:24:56] thread b09fe000 exited ("Renderer")
[00:24:56] thread b05fb000 exited ("MPEG-2 decoder (libmpeg2)")
[00:24:56] thread b05fb000 joined ("MPEG-2 decoder (libmpeg2)")
[00:24:56] mpeg2 done: 163171 frames
[00:24:56] thread b09fe000 joined ("Renderer")
[00:24:56] render: lost time: 12012 (4 frames)
[00:24:56] render: gained time: 12012 (13 frames) (0 not accounted for)
[00:24:56] render: average dropped frame duration: 3003
[00:24:56] fifo_close: trashing 1 buffer(s)
[00:24:56] fifo_close: trashing 2 buffer(s)
[00:24:56] thread b0a80000 exited ("H.264/AVC encoder (libx264)")
[00:24:56] thread b0a80000 joined ("H.264/AVC encoder (libx264)")
[00:24:56] thread b0b84000 exited ("AAC encoder (libfaac)")
x264 [info]: slice I:1282  Avg QP:17.83  size: 40286  PSNR Mean Y:44.87 U:47.06 V:47.72 Avg:45.52 Global:44.58
x264 [info]: slice P:74446 Avg QP:19.66  size: 15913  PSNR Mean Y:42.95 U:46.27 V:46.98 Avg:43.83 Global:43.24
x264 [info]: slice B:87435 Avg QP:21.78  size:  4224  PSNR Mean Y:42.03 U:45.97 V:46.70 Avg:43.01 Global:42.49
x264 [info]: mb I  I16..4: 17.8% 66.7% 15.5%
x264 [info]: mb P  I16..4:  4.0% 13.0%  3.1%  P16..4: 39.2% 21.6% 16.4%  1.2%  0.7%    skip: 0.9%
x264 [info]: mb B  I16..4:  0.6%  1.4%  0.4%  B16..8: 40.3%  2.8%  4.8%  direct: 3.9%  skip:45.6%
x264 [info]: 8x8 transform  intra:63.8%  inter:51.4%
x264 [info]: direct mvs  spatial:99.7%  temporal:0.3%
x264 [info]: ref P  69.4% 14.5%  6.7%  3.9%  2.7%  2.8%
x264 [info]: ref B  78.9% 12.8%  4.1%  2.5%  1.7%
x264 [info]: SSIM Mean Y:0.9795570
x264 [info]: PSNR Mean Y:42.471 U:46.112 V:46.834 Avg:43.403 Global:42.830 kb/s:1887.53
[00:24:56] thread b0b02000 joined ("AC3 decoder")
[00:24:56] thread b0b84000 joined ("AAC encoder (libfaac)")
[00:24:56] thread b04d5000 joined ("reader")
[00:24:57] mux: file size, 1718947727 bytes
[00:24:57] mux: track 0, 1605642436 bytes, 1887.43 kbps
[00:24:57] mux: track 1, 108867487 bytes, 127.97 kbps
[00:24:57] mux: overhead, 9.20 bytes per frame
[00:24:57] thread b0579000 exited ("muxer")
[00:24:57] thread b0579000 joined ("muxer")
[00:24:57] fifo_close: trashing 0 buffer(s)
[00:24:57] fifo_close: trashing 1 buffer(s)
[00:24:57] fifo_close: trashing 0 buffer(s)
[00:24:57] fifo_close: trashing 0 buffer(s)
[00:24:57] fifo_close: trashing 0 buffer(s)
[00:24:57] fifo_close: trashing 0 buffer(s)
[00:24:57] fifo_close: trashing 0 buffer(s)
[00:24:57] fifo_close: trashing 0 buffer(s)
[00:24:57] fifo_close: trashing 2 buffer(s)
[00:24:57] decomb: yadif deinterlaced 0 | blend deinterlaced 71 | unfiltered 163094 | total 163165
[00:24:57] Freed 15 buffers of size 1024
[00:24:57] Freed 32 buffers of size 2048
[00:24:57] Freed 32 buffers of size 16384
[00:24:57] Freed 32 buffers of size 524288
[00:24:57] Allocated 17382400 bytes of buffers on this pass and Freed 17382400 bytes, 0 bytes leaked
[00:24:57] thread b00c5000 exited ("work")
[00:24:57] thread b00c5000 joined ("work")
[00:24:57] libhb: work result = 0
jbrjake
Veteran User
Posts: 4805
Joined: Wed Dec 13, 2006 1:38 am

Re: [svn1566] Encode ends early when resuming from pause

Post by jbrjake »

That's funny, I don't remember us releasing a snapshot of 1566.

*LOCKING*
Locked