Handbrake: Ram usage problem while encoding 4k videos (OpenCL Scaling Memory Leak)

[marcomanieri]

Please describe the problem or feature request in detail:

I'm using Handbrake to encode a large quantity of 4k videos from a Youtube Project. There are 50 files in queue.
I'm not sure if I've well understood the issue: after every encoding ends (the videos are really short, less than 30 sec each) the Ram looks to be not cleaned. I've got only 8gb of Ram and, for this, after 3-4 encoding Windows crash while Handbrake is still trying to allocate more ram. During the first encoding the Ram usage is less than 5000mb, during the second less than 6000, during the third less than 7000, during the fourth (if it doesn't crash) reach 7800mb.

Edit: To avoid the crash I have to close Handbrake before the forth encode (if I just stop the queue the Ram usage stay the same) and reopen it.

What are the steps to reproduce this problem:

Make a batch encoding of more than four 4k videos (x265@8000kbps + aac@112kbps)

What version of HandBrake you are running:

Handbrake latest release - 1.0.1 (2016122900) 64bit

What operating system and version and you running (e.g. OSX 10.11, Windows 7, Ubuntu 14):

Windows 10, no more programs running in background than antivirus.
Hardware: [email protected], 8gb@1866mhz

Was there any error message or error dialog, if so please detail or provide screenshots:

I do not get any error message. If Windows does not crash it close every program.

Please provide the full activity log for the encode or scan attempt. You may attach the log as a file, post a pastebin URL to the log, or place the log inline below:

``` HandBrake 1.0.1 (2016122900) - 64bit
OS: Microsoft Windows NT 10.0.14393.0 - 64bit
CPU: AMD FX-8320E Eight-Core Processor
Ram: 8091 MB,
GPU Information:
AMD Radeon R9 200 Series - 21.19.407.0
Screen: 2560x1080
Temp Dir: C:\Users\Marco\AppData\Local\Temp\
Install Dir: C:\Program Files\Handbrake
Data Dir: C:\Users\Marco\AppData\Roaming\HandBrake Team\HandBrake\1.0.1.0

---

Starting Encode ...

[16:42:18] hb_init: starting libhb thread
[16:42:18] 1 job(s) to process
[16:42:18] json job:
{
"Audio": {
"AudioList": [
{
"Bitrate": 112,
"DRC": 0.0,
"Encoder": 65536,
"Gain": 0.0,
"Mixdown": 4,
"NormalizeMixLevel": false,
"Samplerate": 0,
"Name": "",
"Track": 0,
"DitherMethod": 0
}
],
"CopyMask": [
1073807360,
1073743872,
1074003968,
1073750016,
1090519040,
1074790400,
1074266112,
1107296256
],
"FallbackEncoder": 2048
},
"Destination": {
"ChapterList": [
{
"Name": "Chapter 1"
}
],
"ChapterMarkers": true,
"File": "D:\Risorse\Video\Progetti\YouTube\Video\Redmi 4 Pro Storage\Source\20170104_191112.mp4",
"Mp4Options": {
"IpodAtom": false,
"Mp4Optimize": false
},
"Mux": 131072
},
"Filters": {
"FilterList": [
{
"ID": 4,
"Settings": {
"mode": "7"
}
},
{
"ID": 3,
"Settings": {
"block-height": "16",
"block-thresh": "40",
"block-width": "16",
"filter-mode": "2",
"mode": "3",
"motion-thresh": "1",
"spatial-metric": "2",
"spatial-thresh": "1"
}
},
{
"ID": 11,
"Settings": {
"crop-bottom": "0",
"crop-left": "0",
"crop-right": "0",
"crop-top": "0",
"height": "2160",
"width": "3840"
}
},
{
"ID": 6,
"Settings": {
"mode": "2",
"rate": "27000000/900900"
}
}
]
},
"PAR": {
"Num": 1,
"Den": 1
},
"Metadata": {},
"SequenceID": 0,
"Source": {
"Angle": 1,
"Range": {
"Type": "chapter",
"Start": 1,
"End": 1
},
"Title": 20,
"Path": "D:\Risorse\Video\Progetti\YouTube\Video\Redmi 4 Pro\Source\20170104_191112.mp4"
},
"Subtitle": {
"Search": {
"Burn": true,
"Default": false,
"Enable": true,
"Forced": false
},
"SubtitleList": []
},
"Video": {
"Encoder": 4096,
"Level": "auto",
"Bitrate": 8000,
"TwoPass": false,
"Turbo": false,
"ColorMatrixCode": 0,
"Options": "",
"Preset": "faster",
"Profile": "auto",
"OpenCL": true,
"HWDecode": false,
"QSV": {
"Decode": false,
"AsyncDepth": 0
}
}
}
[16:42:18] CPU:
[16:42:18] - logical processor count: 8
[16:42:18] OpenCL device #1: Advanced Micro Devices, Inc. Tahiti
[16:42:18] - OpenCL version: 1.2 AMD-APP (2236.10)
[16:42:18] - driver version: 2236.10
[16:42:18] - device type: GPU
[16:42:18] - supported: YES
[16:42:18] Intel Quick Sync Video support: no
[16:42:18] hb_scan: path=D:\Risorse\Video\Progetti\YouTube\Video\Redmi 4 Pro\Source\20170104_191112.mp4, title_index=20
udfread ERROR: ECMA 167 Volume Recognition failed
src/libbluray/disc/disc.c:274: failed opening UDF image D:\Risorse\Video\Progetti\YouTube\Video\Redmi 4 Pro\Source\20170104_191112.mp4
src/libbluray/disc/disc.c:352: error opening file BDMV\index.bdmv
src/libbluray/disc/disc.c:352: error opening file BDMV\BACKUP\index.bdmv
[16:42:18] bd: not a bd - trying as a stream/file instead
libdvdread: Encrypted DVD support unavailable.
libdvdread:DVDOpenFileUDF:UDFFindFile /VIDEO_TS/VIDEO_TS.IFO failed
libdvdread:DVDOpenFileUDF:UDFFindFile /VIDEO_TS/VIDEO_TS.BUP failed
libdvdread: Can't open file VIDEO_TS.BUP.
[16:42:18] dvd: not a dvd - trying as a stream/file instead
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'D:\Risorse\Video\Progetti\YouTube\Video\Redmi 4 Pro\Source\20170104_191112.mp4':
Metadata:
major_brand : mp42
minor_version : 0
compatible_brands: isommp42
creation_time : 2017-01-04 18:12:04
Duration: 00:00:51.55, start: 0.000000, bitrate: 48300 kb/s
Stream #0:0(eng): Video: h264 (High) [avc1 / 0x31637661]
yuv420p, 3840x2160, 48040 kb/s
30 fps, 90k tbn (default)
Metadata:
creation_time : 2017-01-04 18:12:04
handler_name : VideoHandle
Stream #0:1(eng): Audio: aac (LC) [mp4a / 0x6134706D]
48000 Hz, stereo, fltp, 256 kb/s (default)
Metadata:
creation_time : 2017-01-04 18:12:04
handler_name : SoundHandle
[16:42:19] scan: decoding previews for title 20
[16:42:20] scan: audio 0x1: aac, rate=48000Hz, bitrate=256007 English (AAC) (2.0 ch)
[16:42:27] scan: 10 previews, 3840x2160, 30.007 fps, autocrop = 0/0/0/0, aspect 16:9, PAR 1:1
[16:42:27] scan: supported video decoders: avcodec qsv
[16:42:27] libhb: scan thread found 1 valid title(s)
[16:42:27] Skipping subtitle scan. No suitable subtitle tracks.
[16:42:27] starting job
[16:42:27] decomb filter thread started for segment 0
[16:42:27] decomb filter thread started for segment 4
[16:42:27] decomb filter thread started for segment 2
[16:42:27] decomb filter thread started for segment 3
[16:42:27] decomb filter thread started for segment 1
[16:42:27] decomb filter thread started for segment 5
[16:42:27] decomb filter thread started for segment 6
[16:42:27] decomb filter thread started for segment 7
[16:42:27] decomb check thread started for segment 0
[16:42:27] decomb check thread started for segment 1
[16:42:27] decomb check thread started for segment 2
[16:42:27] decomb check thread started for segment 3
[16:42:27] decomb check thread started for segment 4
[16:42:27] decomb check thread started for segment 5
[16:42:27] mask erode thread started for segment 3
[16:42:27] decomb check thread started for segment 7
[16:42:27] mask filter thread started for segment 0
[16:42:27] mask filter thread started for segment 1
[16:42:27] mask filter thread started for segment 2
[16:42:27] mask filter thread started for segment 3
[16:42:27] mask filter thread started for segment 4
[16:42:27] mask filter thread started for segment 5
[16:42:27] mask filter thread started for segment 6
[16:42:27] mask filter thread started for segment 7
[16:42:27] yadif thread started for segment 3
[16:42:27] mask erode thread started for segment 1
[16:42:27] mask erode thread started for segment 2
[16:42:27] decomb check thread started for segment 6
[16:42:27] mask erode thread started for segment 4
[16:42:27] work: track 1, dithering not supported by codec
[16:42:27] mask erode thread started for segment 5
[16:42:27] mask erode thread started for segment 6
[16:42:27] work: only 1 chapter, disabling chapter markers
[16:42:27] job configuration:
[16:42:27] mask erode thread started for segment 7
[16:42:27] * source
[16:42:27] + D:\Risorse\Video\Progetti\YouTube\Video\Redmi 4 Pro\Source\20170104_191112.mp4
[16:42:27] + title 20, chapter(s) 1 to 1
[16:42:27] + container: mov,mp4,m4a,3gp,3g2,mj2
[16:42:27] + data rate: 48300 kbps
[16:42:27] * destination
[16:42:27] + D:\Risorse\Video\Progetti\YouTube\Video\Redmi 4 Pro Storage\Source\20170104_191112.mp4
[16:42:27] + container: MPEG-4 (libavformat)
[16:42:27] mask dilate thread started for segment 0
[16:42:27] * video track
[16:42:27] + decoder: h264
[16:42:27] + bitrate 48040 kbps
[16:42:27] + filters
[16:42:27] + Comb Detect (mode=3:spatial-metric=2:motion-thresh=1:spatial-thresh=1:filter-mode=2:block-thresh=40:block-width=16:block-height=16)
[16:42:27] + Decomb (mode=39)
[16:42:27] + Framerate Shaper (mode=2:rate=27000000/900900)
[16:42:27] mask dilate thread started for segment 1
[16:42:27] mask dilate thread started for segment 2
[16:42:27] + frame rate: 30.007 fps -> peak rate limited to 29.970 fps
[16:42:27] + Crop and Scale (width=3840:height=2160:crop-top=0:crop-bottom=0:crop-left=0:crop-right=0)
[16:42:27] mask dilate thread started for segment 3
[16:42:27] + source: 3840 * 2160, crop (0/0/0/0): 3840 * 2160, scale: 3840 * 2160
[16:42:27] + Output geometry
[16:42:27] + storage dimensions: 3840 x 2160
[16:42:27] + pixel aspect ratio: 1 : 1
[16:42:27] + display dimensions: 3840 x 2160
[16:42:27] + encoder: H.265 (libx265)
[16:42:27] + preset: faster
[16:42:27] mask dilate thread started for segment 4
[16:42:27] mask dilate thread started for segment 5
[16:42:27] + profile: auto
[16:42:27] + bitrate: 8000 kbps, pass: 0
[16:42:27] * audio track 1
[16:42:27] + decoder: English (AAC) (2.0 ch) (track 1, id 0x1)
[16:42:27] + bitrate: 256 kbps, samplerate: 48000 Hz
[16:42:27] + mixdown: Stereo
[16:42:27] mask dilate thread started for segment 6
[16:42:27] + encoder: AAC (libavcodec)
[16:42:27] + bitrate: 112 kbps, samplerate: 48000 Hz
[16:42:27] mask dilate thread started for segment 7
[16:42:27] yadif thread started for segment 0
[16:42:27] yadif thread started for segment 1
[16:42:27] yadif thread started for segment 2
[16:42:27] mask erode thread started for segment 0
[16:42:27] yadif thread started for segment 4
[16:42:27] yadif thread started for segment 5
[16:42:27] yadif thread started for segment 6
[16:42:27] yadif thread started for segment 7
[16:42:28] sync: expecting 1547 video frames
x265 [info]: HEVC encoder version 2.1
x265 [info]: build info [Windows][GCC 5.4.0][64 bit] 8bit
x265 [info]: using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX XOP FMA4 FMA3 LZCNT BMI1
x265 [info]: Main profile, Level-5 (Main tier)
x265 [info]: Thread pool created using 8 threads
x265 [info]: Slices : 1
x265 [info]: frame threads / pool features : 3 / wpp(34 rows)
x265 [info]: Coding QT: max CU size, min CU size : 64 / 8
x265 [info]: Residual QT: max TU size, max depth : 32 / 1 inter / 1 intra
x265 [info]: ME / range / subpel / merge : hex / 57 / 2 / 2
x265 [info]: Keyframe min / max / scenecut : 30 / 300 / 40
x265 [info]: Lookahead / bframes / badapt : 15 / 4 / 0
x265 [info]: b-pyramid / weightp / weightb : 1 / 1 / 0
x265 [info]: References / ref-limit cu / depth : 2 / on / on
x265 [info]: AQ: mode / str / qg-size / cu-tree : 1 / 1.0 / 32 / 1
x265 [info]: Rate Control / qCompress : ABR-8000 kbps / 0.60
x265 [info]: tools: rd=2 psy-rd=2.00 early-skip rskip signhide tmvp fast-intra
x265 [info]: tools: strong-intra-smoothing lslices=8 deblock sao
[16:42:28] sync: first pts video is 0
[16:42:28] sync: "Chapter 1" (1) at frame 1 time 0
[16:42:28] sync: first pts audio 0x1 is 0
x265 [error]: malloc of size 2466816 failed
x265 [error]: memory allocation failure, aborting encode
```

[bradleysepos]

We are working on fixing a few memory leaks to this effect. In the meantime, disable QSV (if enabled) and let us know if that helps.

[marcomanieri]

My Cpu is AMD, so QSV can not be enabled

Edit: Log added (I hope in the right way)

[sr55]

Looks like there much be another leak we are not aware of,.

I'm seeing about 3GB Used for 4k->4k using the same settings. Only seeing about ~40MB per encode instance run leaked. Nothing major that would be hitting 5+GB anytime fast.

Going to leave this running for a bit to see if it grows over time.

EDIT: Not seeing any leak, and the 40MB lost got recovered, so just .NET being a tad slow Garbage collecting it. Even after 5 encodes.

Can you grab a nightly build on the off chance it's something we fixed?

[marcomanieri]

Where can I find a nightly?

[sr55]

https://handbrake.fr/nightly.php

[marcomanieri]

It looks to be the same. During the third encoding I got 6600mb of Ram used. It was reaching more than 7500mb (fourth encode) so I stopped it.
I tried the last nigthly build.

Edit: Latest log http://pastebin.com/AtAwq6Ex

[sr55]

Can you provide the logs for the previous encodes too? Maybe they'll have a clue.

I can't seem to reproduce this myself with any source i have. Mostly 4K h.264/aac MP4s

[marcomanieri]

I encoded about 100 videos reopening HandBrake every 3-4 encode (and with 2-3 more crashes), so I have tons of Logs. Which should I send?

[sr55]

From the start of a session, each log up until it got large. So I guess that's 1,2,3,4

[marcomanieri]

This time I left it crash. It lasted for 6 videos before to crash, probably because the videos were particullary short (I suppose?)

Video 1: http://pastebin.com/HbyWQkK3
Video 2: http://pastebin.com/TWbpyWLm
Video 3: http://pastebin.com/s0ujyFKj
Video 4: http://pastebin.com/NJFnv1Zd
Video 5: http://pastebin.com/qFXd6VAx
Video 6: http://pastebin.com/wrTaL6wq
Latest one: http://pastebin.com/kzTzsbKR

[sr55]

This is really odd. I have a test you can try. (Sorry this might be a little bit of a pain :()
In Options, set logging to Extended before doing this.

Take Video 5, Before Starting the encode, note the memory in task manager.
Start, Wait 30 seconds, Stop, Wait 30 seconds. Record memory usage
Repeat 5 times.

You should see the memory jump around around 100 to 150MB to around 3GB then back down to 100 to 150MB Repeatably.

If you see an upward trend let the app sit for 5 minutes idle and see if it recovers back.

If you don't see any leaking, try again for Video 4, 3, 2, 1 (Just loading 1 by 1) to see if you see any increase in memory after a short encode.

If we don't see anything, then I'm guessing we may have a leak in x265 that's only triggering in certain circumstances at certain points in the timeline.

I'd clear the log directory doing this, as if you do see logging at any point, I'm hoping the extended logging will atleast show us.

[sr55]

The other thing to try is encoding to x264 the same batch of files. If you don't see the increase, then it alteast isolates the area we need to look at.

[marcomanieri]

There is just a little problem.. I've finished the encoding process of all the video in that folder, so I've eliminated the source files. I'm anyway going to try with other videos of the same kind.

Edit: if You prefer I could upload some example videos and give you the link, to see if You can replicate this problem. These are just 2160p videos produced by Oneplus 3 or Samsung Galaxy s7 Edge.

[marcomanieri]

RAM USAGE:

`
RUNNING IN BACKGOUND: Opera, Antivirus

START:2070mb

1-3760mb (reached 5800 during encoding process)
2-5480mb (reached 6500 during encoding process)
3-6330mb (reached 7300 during encoding process)
4-5492mb (reached more than 7000 during encoding process)
5-3180mb (reached 7600 during encoding process)(mesuration took after more than a minute in indle)

6-5064mb (reached 6300 during encoding process)
`

Logs:
1-http://pastebin.com/tZ4jFUYB
2-http://pastebin.com/qNKFGgiY
3-http://pastebin.com/iFpYV7zv
4-http://pastebin.com/APuW47HH
5-http://pastebin.com/XVzhe0tr
6-http://pastebin.com/52n6HkiX

I suppose that after the fifth encode Windows started to compress the Ram or to extend paging file, because when I reopened opera (that was running in backgroud) it had to recover the files from my HDD.

UPDATE:
I got exactly the same problem encoding the same video with x264 at the same bitrate.

[sr55]

Let's try a sample file then please. Looks like we can rule out the encoder at least.

[sr55]

Is that system memory at the start of each encode of hb mem?

[marcomanieri]

Is the memory after 30 second after I stopped the encode

[marcomanieri]

Here is the sample: https://goo.gl/wwqoD7

[sr55]

Taking this example file, Here is what I see. (Note, I'm looking at Process Usage, not system usage)
Only seeing 5MB difference which is fine. Between the log storage etc that's easily accoutable.

Can you check that your not seeing some other app, like the Windows 10 memory compression or AV etcgoing crazy eating memory as I think you may only be looking at system memory, not HB process memory in your listing above.

[marcomanieri]

Sure, I checked it before to open this issue :)

So the problem looks to be related with my system?

Edit; After the third encode I took the screenshot too soon. The Ram usage dropped to 4250mb at the end.

[sr55]

Yeh that's definatly leaking. I need to figure out what is different from your setup to mine.

[sr55]

[00:12:21] Allocated 632211456 bytes of buffers on this pass and Freed 548325376 bytes, 83886080 bytes leaked

Looks like all 6 encodes did detect a leak of ~80MB.

Still working on trying to get it to leak 1.7GB though.

[sr55]

Success! Found it.

Tools -> Options -> Video -> Choose Lanczos Scaling

That should stop the leak from occuring. There won't be much penalty to not using that. Scaling is only 5% of the pipeline usually.

Now we have something we can fix!

[marcomanieri]

I'm sorry but... different scaler, same problem

[sr55]

Did you change the scaler, before adding anyhting to the queue? Or was it already on lanczos? I could see it turned on in your log. I'd want to see another log post -turn off.

[marcomanieri]

Ok, I could pay more attention before to give up.
Yes, I didn't thought that the scaler could be related to the sigle video in the queue, so I just tried.

Now there is no memory leak, thanks for the help :)