Page 1 of 1

Encoding speed slows by half

Posted: Sun Jan 10, 2010 10:37 pm
by Hi Ho
I am using Handbrake to convert some DVD .ISO's to MP4 video files. It is working but it is not very fast. I am using the "High Profile" preset. My machine is running a Core i7 860 with 8 GB of RAM and a 1 TB Seagate 7200.12 hard drive. When the encoding starts it goes steady at about 60 FPS for about ten minutes. After that point it slows down and eventually ends up at about 30 FPS. Why would it slow down like this? When I do similar conversions in MediaCoder it takes about ten to fifteen minutes to completely finish a 1.5 hour video and it regularly encodes at speeds of 230 FPS and above. After ten minutes, Handbrake is barely 1/4 the way done.

Code: Select all

[13:37:23] hb_init: checking cpu count
[13:37:23] hb_init: starting libhb thread
HandBrake 0.9.4 (2009112300) - MinGW i386 - http://handbrake.fr
8 CPUs detected
Opening M:\DVD ISO\BILL_MONROE1.ISO...
[13:37:23] hb_scan: path=M:\DVD ISO\BILL_MONROE1.ISO, title_index=1
[13:37:23] scan: trying to open with libdvdread
libdvdnav: Using dvdnav version 4.1.3
libdvdread: Encrypted DVD support unavailable.
libdvdnav: DVD Title: BILL_MONROE1
libdvdnav: DVD Serial Number: 0F2A7B9001C42FF2
libdvdnav: DVD Title (Alternative): PrassiPrassiPrassi
libdvdnav: Unable to find home directorylibdvdnav: DVD disk reports itself with Region mask 0x00000000. Regions: 1 2 3 4 5 6 7 8
libdvdread: Encrypted DVD support unavailable.
[13:37:23] scan: DVD has 1 title(s)
[13:37:23] scan: scanning title 1
[13:37:23] scan: opening IFO for VTS 1
[13:37:23] pgc_id: 1, pgn: 1: pgc: 0x16aecb0
[13:37:23] scan: vts=1, ttn=1, cells=0->39, blocks=0->2195154, 2195155 blocks
[13:37:23] scan: duration is 01:30:29 (5429120 ms)
[13:37:23] scan: checking audio 1
[13:37:23] scan: id=80bd, lang=Unknown (AC3), 3cc=und ext=0
[13:37:23] scan: title 1 has 40 chapters
[13:37:23] scan: chap 1 c=0->0, b=0->30669 (30670), 80405 ms
[13:37:23] scan: chap 2 c=1->1, b=30670->163132 (132463), 358740 ms
[13:37:23] scan: chap 3 c=2->2, b=163133->226442 (63310), 156356 ms
[13:37:23] scan: chap 4 c=3->3, b=226443->266465 (40023), 96199 ms
[13:37:23] scan: chap 5 c=4->4, b=266466->318566 (52101), 125527 ms
[13:37:23] scan: chap 6 c=5->5, b=318567->362055 (43489), 105492 ms
[13:37:23] scan: chap 7 c=6->6, b=362056->379932 (17877), 42072 ms
[13:37:23] scan: chap 8 c=7->7, b=379933->409649 (29717), 70354 ms
[13:37:23] scan: chap 9 c=8->8, b=409650->465128 (55479), 133530 ms
[13:37:23] scan: chap 10 c=9->9, b=465129->495156 (30028), 73226 ms
[13:37:23] scan: chap 11 c=10->10, b=495157->514785 (19629), 48383 ms
[13:37:23] scan: chap 12 c=11->11, b=514786->537416 (22631), 52300 ms
[13:37:23] scan: chap 13 c=12->12, b=537417->595402 (57986), 137513 ms
[13:37:23] scan: chap 14 c=13->13, b=595403->634559 (39157), 94439 ms
[13:37:23] scan: chap 15 c=14->14, b=634560->674353 (39794), 97311 ms
[13:37:23] scan: chap 16 c=15->15, b=674354->699648 (25295), 60157 ms
[13:37:23] scan: chap 17 c=16->16, b=699649->715712 (16064), 38118 ms
[13:37:23] scan: chap 18 c=17->17, b=715713->760297 (44585), 105248 ms
[13:37:23] scan: chap 19 c=18->18, b=760298->815667 (55370), 130511 ms
[13:37:23] scan: chap 20 c=19->19, b=815668->850453 (34786), 84211 ms
[13:37:23] scan: chap 21 c=20->20, b=850454->907345 (56892), 135320 ms
[13:37:23] scan: chap 22 c=21->21, b=907346->967140 (59795), 148322 ms
[13:37:23] scan: chap 23 c=22->22, b=967141->987864 (20724), 50252 ms
[13:37:23] scan: chap 24 c=23->23, b=987865->1064009 (76145), 187444 ms
[13:37:23] scan: chap 25 c=24->24, b=1064010->1124067 (60058), 148389 ms
[13:37:23] scan: chap 26 c=25->25, b=1124068->1173135 (49068), 120461 ms
[13:37:23] scan: chap 27 c=26->26, b=1173136->1231604 (58469), 141320 ms
[13:37:23] scan: chap 28 c=27->27, b=1231605->1292729 (61125), 144515 ms
[13:37:23] scan: chap 29 c=28->28, b=1292730->1342157 (49428), 115365 ms
[13:37:23] scan: chap 30 c=29->29, b=1342158->1383230 (41073), 92392 ms
[13:37:23] scan: chap 31 c=30->30, b=1383231->1432401 (49171), 114363 ms
[13:37:23] scan: chap 32 c=31->31, b=1432402->1489226 (56825), 132381 ms
[13:37:23] scan: chap 33 c=32->32, b=1489227->1792366 (303140), 757463 ms
[13:37:23] scan: chap 34 c=33->33, b=1792367->1886991 (94625), 232602 ms
[13:37:23] scan: chap 35 c=34->34, b=1886992->1957528 (70537), 173586 ms
[13:37:23] scan: chap 36 c=35->35, b=1957529->2007410 (49882), 129223 ms
[13:37:23] scan: chap 37 c=36->36, b=2007411->2072763 (65353), 167489 ms
[13:37:23] scan: chap 38 c=37->37, b=2072764->2122092 (49329), 125416 ms
[13:37:23] scan: chap 39 c=38->38, b=2122093->2190825 (68733), 203384 ms
[13:37:23] scan: chap 40 c=39->39, b=2190826->2195154 (4329), 19319 ms
[13:37:23] scan: aspect = 0
[13:37:23] scan: decoding previews for title 1
[13:37:23] scan: title angle(s) 1
[13:37:23] scan: audio 0x80bd: AC-3, rate=48000Hz, bitrate=224000 Unknown (AC3) (2.0 ch)
[13:37:23] scan: 10 previews, 720x480, 29.970 fps, autocrop = 0/0/4/12, aspect 4:3, PAR 8:9
[13:37:23] scan: title (0) job->width:624, job->height:480
[13:37:23] libhb: scan thread found 1 valid title(s)
+ title 1:
  + vts 1, ttn 1, cells 0->39 (2195155 blocks)
  + angle(s) 1
  + duration: 01:30:29
  + size: 720x480, pixel aspect: 8/9, display aspect: 1.33, 29.970 fps
  + autocrop: 0/0/4/12
  + chapters:
    + 1: cells 0->0, 30670 blocks, duration 00:01:20
    + 2: cells 1->1, 132463 blocks, duration 00:05:59
    + 3: cells 2->2, 63310 blocks, duration 00:02:36
    + 4: cells 3->3, 40023 blocks, duration 00:01:36
    + 5: cells 4->4, 52101 blocks, duration 00:02:06
    + 6: cells 5->5, 43489 blocks, duration 00:01:45
    + 7: cells 6->6, 17877 blocks, duration 00:00:42
    + 8: cells 7->7, 29717 blocks, duration 00:01:10
    + 9: cells 8->8, 55479 blocks, duration 00:02:14
    + 10: cells 9->9, 30028 blocks, duration 00:01:13
    + 11: cells 10->10, 19629 blocks, duration 00:00:48
    + 12: cells 11->11, 22631 blocks, duration 00:00:52
    + 13: cells 12->12, 57986 blocks, duration 00:02:18
    + 14: cells 13->13, 39157 blocks, duration 00:01:34
    + 15: cells 14->14, 39794 blocks, duration 00:01:37
    + 16: cells 15->15, 25295 blocks, duration 00:01:00
    + 17: cells 16->16, 16064 blocks, duration 00:00:38
    + 18: cells 17->17, 44585 blocks, duration 00:01:45
    + 19: cells 18->18, 55370 blocks, duration 00:02:11
    + 20: cells 19->19, 34786 blocks, duration 00:01:24
    + 21: cells 20->20, 56892 blocks, duration 00:02:15
    + 22: cells 21->21, 59795 blocks, duration 00:02:28
    + 23: cells 22->22, 20724 blocks, duration 00:00:50
    + 24: cells 23->23, 76145 blocks, duration 00:03:07
    + 25: cells 24->24, 60058 blocks, duration 00:02:28
    + 26: cells 25->25, 49068 blocks, duration 00:02:00
    + 27: cells 26->26, 58469 blocks, duration 00:02:21
    + 28: cells 27->27, 61125 blocks, duration 00:02:25
    + 29: cells 28->28, 49428 blocks, duration 00:01:55
    + 30: cells 29->29, 41073 blocks, duration 00:01:32
    + 31: cells 30->30, 49171 blocks, duration 00:01:54
    + 32: cells 31->31, 56825 blocks, duration 00:02:12
    + 33: cells 32->32, 303140 blocks, duration 00:12:37
    + 34: cells 33->33, 94625 blocks, duration 00:03:53
    + 35: cells 34->34, 70537 blocks, duration 00:02:54
    + 36: cells 35->35, 49882 blocks, duration 00:02:09
    + 37: cells 36->36, 65353 blocks, duration 00:02:47
    + 38: cells 37->37, 49329 blocks, duration 00:02:05
    + 39: cells 38->38, 68733 blocks, duration 00:03:23
    + 40: cells 39->39, 4329 blocks, duration 00:00:19
  + audio tracks:
    + 1, Unknown (AC3) (2.0 ch) (iso639-2: und), 48000Hz, 224000bps
  + subtitle tracks:
Reading chapter markers from file C:\Users\Jackson\AppData\Local\Temp\Bill Monroe-1-chapters.csv
Invalid sample rate 0, using input rate 48000
[13:37:23] 1 job(s) to process
[13:37:23] starting job
[13:37:23] work: sanitizing track 0 mixdown Dolby Pro Logic II to Stereo
[13:37:23] job configuration:
[13:37:23]  * source
[13:37:23]    + M:\DVD ISO\BILL_MONROE1.ISO
[13:37:23]    + title 1, chapter(s) 1 to 40
[13:37:23]  * destination
[13:37:23]    + M:\Video\Mando Vids\Bill Monroe.m4v
[13:37:23]    + container: MPEG-4 (.mp4 and .m4v)
[13:37:23]      + chapter markers
[13:37:23]  * video track
[13:37:23]    + decoder: mpeg2
[13:37:23]      + bitrate 7000 kbps
[13:37:23]    + frame rate: same as source (around 29.970 fps)
[13:37:23]    + loose anamorphic
[13:37:23]      + modulus: 0
[13:37:23]      + storage dimensions: 720 * 480 -> 720 * 496, crop 0/0/4/12
[13:37:23]      + pixel aspect ratio: 43 / 48
[13:37:23]      + display dimensions: 645 * 496
[13:37:23]    + filters
[13:37:23]      + Detelecine (pullup) (default settings)
[13:37:23]      + Decomb (default settings)
[13:37:23]    + encoder: x264
[13:37:23]      + options: b-adapt=2:rc-lookahead=50
[13:37:23]      + quality: 20.00 (RF)
[13:37:23]  * audio track 0
[13:37:23]    + decoder: Unknown (AC3) (2.0 ch) (track 1, id 80bd)
[13:37:23]      + bitrate: 224 kbps, samplerate: 48000 Hz
[13:37:23]    + mixdown: Stereo
[13:37:23]    + encoder: faac
[13:37:23]      + bitrate: 160 kbps, samplerate: 48000 Hz
[13:37:23]  * audio track 1
[13:37:23]    + decoder: Unknown (AC3) (2.0 ch) (track 1, id 80bd)
[13:37:23]      + bitrate: 224 kbps, samplerate: 48000 Hz
[13:37:23]    + AC3 passthrough
libdvdnav: Using dvdnav version 4.1.3
libdvdread: Encrypted DVD support unavailable.
libdvdnav: DVD Title: BILL_MONROE1
libdvdnav: DVD Serial Number: 0F2A7B9001C42FF2
libdvdnav: DVD Title (Alternative): PrassiPrassiPrassi
libdvdnav: Unable to find home directorylibdvdnav: DVD disk reports itself with Region mask 0x00000000. Regions: 1 2 3 4 5 6 7 8
libdvdread: Encrypted DVD support unavailable.
[13:37:23] reader: first SCR 146 id 224 DTS 22254
[13:37:23] yadif thread started for segment 0
[13:37:23] yadif thread started for segment 1
[13:37:23] yadif thread started for segment 2
[13:37:23] yadif thread started for segment 3
[13:37:23] yadif thread started for segment 4
[13:37:23] yadif thread started for segment 5
[13:37:23] yadif thread started for segment 6
[13:37:23] yadif thread started for segment 7
[13:37:23] decomb thread started for segment 0
[13:37:23] decomb thread started for segment 1
[13:37:23] decomb thread started for segment 2
[13:37:23] decomb thread started for segment 3
[13:37:23] decomb thread started for segment 4
[13:37:23] decomb thread started for segment 5
[13:37:23] decomb thread started for segment 6
[13:37:23] decomb thread started for segment 7
[13:37:23] encx264: keyint-min: 30, keyint-max: 300
[13:37:23] encx264: encoding with stored aspect 43/48
[13:37:23] encx264: Encoding at constant RF 20.000000
x264 [info]: using SAR=43/48
x264 [info]: using cpu capabilities: MMX2 SSE2Fast SSSE3 FastShuffle SSE4.2
[13:37:23] mpeg2: "Chapter 1" (1) at frame 0 time 3003
x264 [info]: profile High, level 3.1
No accelerated IMDCT transform found
No accelerated IMDCT transform found
[13:37:23] sync: expecting 162740 video frames
[ac3 @ 0x8c9df70]No channel layout specified. The encoder will guess the layout, but it might be incorrect.
[13:37:23] sync: first pts is 3003
[13:38:14] mpeg2: "Chapter 2" (2) at frame 2408 time 7234227
[13:42:02] mpeg2: "Chapter 3" (3) at frame 13173 time 39561522
[13:43:59] mpeg2: "Chapter 4" (4) at frame 17875 time 53681628
[13:45:20] mpeg2: "Chapter 5" (5) at frame 20756 time 62333271
[13:47:06] mpeg2: "Chapter 6" (6) at frame 24525 time 73651578
[13:48:36] mpeg2: "Chapter 7" (7) at frame 27692 time 83162079
[13:49:14] mpeg2: "Chapter 8" (8) at frame 28954 time 86951865
[13:50:16] mpeg2: "Chapter 9" (9) at frame 31061 time 93279186
[13:52:18] mpeg2: "Chapter 10" (10) at frame 35060 time 105288183
[13:53:24] mpeg2: "Chapter 11" (11) at frame 37253 time 111873762
[13:54:02] mpeg2: "Chapter 12" (12) at frame 38700 time 116219103
[13:54:53] mpeg2: "Chapter 13" (13) at frame 40278 time 120957837
[13:56:56] mpeg2: "Chapter 14" (14) at frame 44406 time 133354221
[13:58:24] mpeg2: "Chapter 15" (15) at frame 47244 time 141876735
[13:59:45] mpeg2: "Chapter 16" (16) at frame 50168 time 150657507
[14:00:40] mpeg2: "Chapter 17" (17) at frame 51987 time 156119964
[14:01:15] mpeg2: "Chapter 18" (18) at frame 53148 time 159606447
[14:02:53] mpeg2: "Chapter 19" (19) at frame 56302 time 169077909
[14:04:50] mpeg2: "Chapter 20" (20) at frame 60230 time 180873693
[14:06:04] mpeg2: "Chapter 21" (21) at frame 62752 time 188447259
[14:08:08] mpeg2: "Chapter 22" (22) at frame 66822 time 200669469
[14:10:06] mpeg2: "Chapter 23" (23) at frame 71266 time 214014801
[14:10:49] mpeg2: "Chapter 24" (24) at frame 72771 time 218534316
[14:13:28] mpeg2: "Chapter 25" (25) at frame 78404 time 235450215
[14:15:31] mpeg2: "Chapter 26" (26) at frame 82848 time 248795547
[14:17:13] mpeg2: "Chapter 27" (27) at frame 86473 time 259681422
[14:19:21] mpeg2: "Chapter 28" (28) at frame 90717 time 272426154
[14:21:37] mpeg2: "Chapter 29" (29) at frame 95045 time 285423138
[14:23:29] mpeg2: "Chapter 30" (30) at frame 98500 time 295798503
[14:25:03] mpeg2: "Chapter 31" (31) at frame 101265 time 304101798
[14:26:55] mpeg2: "Chapter 32" (32) at frame 104692 time 314393079
[14:29:07] mpeg2: "Chapter 33" (33) at frame 108676 time 326357031

Re: Encoding speed slows by half

Posted: Mon Jan 11, 2010 7:39 pm
by rhester
You're doing CRF encoding, so it sounds like the complexity of the title increases at some point, which will reduce encoding speed. If I had to guess, MediaCoder is encoding via ABR, which will result in more consistent performance (at the expense of inconsistent quality).

Rodney

Re: Encoding speed slows by half

Posted: Tue Jan 12, 2010 4:10 am
by mduell
230FPS also smells like MPEG4 (divx, xvid, ffmpeg) or really low quality H.264 settings.

Re: Encoding speed slows by half

Posted: Tue Jan 12, 2010 10:01 am
by tlindgren
Hi Ho wrote:I am using the "High Profile" preset. My machine is running a Core i7 860 with 8 GB of RAM and a 1 TB Seagate 7200.12 hard drive. When the encoding starts it goes steady at about 60 FPS for about ten minutes. After that point it slows down and eventually ends up at about 30 FPS. Why would it slow down like this? When I do similar conversions in MediaCoder it takes about ten to fifteen minutes to completely finish a 1.5 hour video and it regularly encodes at speeds of 230 FPS and above.
HandBrake and MediaCoder is very similar in speed when using the same settings on several different machines I have, but you may have to go to MC's Advanced button to find some of the settings to actually make it use the same x264 settings. MC also has CUDA accelerated h.264 encoding, it's fast if you have a good GPU but from all comments significantly lower quality. If the 230 fps figure is with this in MC you're comparing apples and oranges.

If you do a 2-pass (or 3-pass in MC) encode the first pass will likely be faster in MC, but that's because they're using settings which the x264 developers say they shouldn't be using in the x264 version they're now using (it was OK when they added it, HB changed when x264 changed, MC hasn't yet and you can override it either)... An i7 860 is a powerful machine, I never used one but I have to say that 30 fps sounds a bit low for it on High Profile, perhaps it's hitting something it has to work harder to handle (perhaps heavily interlaced and decomb is running yadif on every frame?).

If you had posted the full log people might have been able to come with guesses but you only posted a small fragment with no encoding information (scan log perhaps).