[FFmpeg-user] Out of virtual memory (swap, I assume) = telecine filter

[Mark Filipak (ffmpeg)]

On 02/03/2021 12:23 AM, Carl Zwanzig wrote:
> On 2/2/2021 2:52 PM, Mark Filipak (ffmpeg) wrote:
>> If that's true, what's eating the swap? Transcoding parts 1, 2, 3, & 4 all succeeded when running 
>> concurrently. Transcoding part 5 fails, even when ffmpeg is the only app running.
> 
> Out of curiosity, have you tried looking at the file with an mkv analyzer like MediaInfo, Elecard's 
> analyzer* or maybe another one? (Is there metadata towards the end of the file containing junk info?)
> 
> How does it behave if you drop the minterpolate or one of the other filters, output to a null file, 
> or use a different output codec? (Anything to try isolating the problem.)

If rising memory allocation and rising swap commit indicates a memory leak, then the telecine filter 
has a memory leak.

=====
part5.cmd
-----
ffmpeg -i "THE LAST EMPEROR [1987] source part5.mkv" -map 0 -filter_complex 
"minterpolate=fps=48000/1001:mi_mode=mci:mc_mode=obmc:scd=fdiff:scd_threshold=10:vsbmc=1:search_param=32, 
telecine=pattern=3322,pp=linblenddeint, setpts=N*1001/60000/TB" -codec:v libx265 -x265-params 
crf=20:qcomp=0.60 -codec:a copy -codec:s copy "THE LAST EMPEROR [1987] part5.mkv"
pause
exit

Results:
Though 'part1.cmd', 'part2.cmd', 'part3.cmd', and 'part4.cmd' completed when running concurrently, 
'part5.cmd' died.
I then twice ran 'part5.cmd' in isolation and it died twice.
=====
part5 without minterpolate.cmd
-----
ffmpeg -i "THE LAST EMPEROR [1987] source part5 (44561 frames).mkv" -map 0 -filter_complex 
"telecine=pattern=3322,pp=linblenddeint, setpts=N*1001/30000/TB" -codec:v libx265 -x265-params 
crf=20:qcomp=0.60 -codec:a copy -codec:s copy "THE LAST EMPEROR [1987] part5 without minterpolate.mkv"
pause
exit

Results:

Expecting 55700 output frames.

1:07AM start.
Memory (of 32GB): 13.2GB
Swap commit (of 128GB): 14.2GB

1:32AM
Memory (of 32GB): 25.4GB
Swap commit (of 128GB): 27.3GB
A great number of "Starting new cluster due to timestamp" notices, a continuous stream -- coming so 
fast & furious that I can't read what the current frame number is before "Starting new cluster due 
to timestamp" overwrites it.

1:47AM
Memory (of 32GB): 31GB
Swap commit (of 128GB): 33GB

2:32AM
Memory (of 32GB): Hovering between 31GB & 31.6GB -- ramp up then drop, ramp up then drop: I imagine 
that's normal malloc-free cycles. But why would ffmpeg defer free'ing until it had filled memory?
Swap commit (of 128GB): 46GB, rising steadily... Aha! Then leveling off at 46.3GB. But why would 
swap commits begin immediately instead of when memory has been filled?

Ah! The "Starting new cluster due to timestamp" stream has ended, and it ended at the same time that 
swap commit leveled off.

Is that a clue?

3:07AM done.
This contrasts with the original run (that included minterpolate) which ran all night, then died.

You know what I think? From the behavior of memory & swap commits, it looks to me that it's a 
combination of "Starting new cluster due to timestamp" persisting for so many hours longer during 
the original run.

Actually, there were 3 original runs because I tried it 3 times; all died.
=====
part5 with solely minterpolate.cmd
-----
ffmpeg -i "THE LAST EMPEROR [1987] part5.mkv" -map 0 -filter_complex 
"minterpolate=fps=48000/1001:mi_mode=mci:mc_mode=obmc:scd=fdiff:scd_threshold=10:vsbmc=1:search_param=32, 
setpts=N*1001/48000/TB" -codec:v libx265 -x265-params crf=20:qcomp=0.60 -codec:a copy -codec:s copy 
"THE LAST EMPEROR [1987] part5 with solely minterpolate.mkv"
pause
exit

Results:

Expecting 89120 output frames.

2:14PM start.
Memory (of 32GB):= 10.3GB
Swap commit (of 128GB): 10.6GB

Thereafter, both memory and swap commit are flat.
Note: I let it run awhile after "Starting new cluster due to timestamp" began appearing.
There were much fewer "Starting new cluster due to timestamp" notices.

2:40PM
Memory = 10.6GB
Swap commit = 10.9GB

3:37 stopped.
=====
part5 with solely telecine.cmd
-----
ffmpeg -i "THE LAST EMPEROR [1987] source part5 (44561 frames).mkv" -map 0 -filter_complex 
"telecine=pattern=3322, setpts=N*1001/30000/TB" -codec:v libx265 -x265-params crf=20:qcomp=0.60 
-codec:a copy -codec:s copy "THE LAST EMPEROR [1987] part5 with solely telecine.mkv"
pause
exit

Results:

3:43PM start.
Memory (of 32GB): 9.9GB
Swap commit (of 128GB): 10.2GB

3:47PM
Memory (of 32GB): 11.4GB
Swap commit (of 128GB): 11.9GB

3:52PM begin getting "Starting new cluster due to timestamp" notices.
Memory (of 32GB): 13.2
Swap commit (of 128GB): 13.8GB

4:00
Memory (of 32GB): 17
Swap commit (of 128GB): 17.5GB

4:00 stopped.
=====