Bug 58270 - Mono 5.0.1.1 runtime uses a lot more memory than 3.8 on ARM
Summary: Mono 5.0.1.1 runtime uses a lot more memory than 3.8 on ARM
Status: RESOLVED NORESPONSE
Alias: None
Product: Runtime
Classification: Mono
Component: General (show other bugs)
Version: 5.0 (2017-02)
Hardware: Other Linux
: --- normal
Target Milestone: ---
Assignee: Bugzilla
URL:
Depends on:
Blocks:
 
Reported: 2017-07-20 14:31 UTC by Dirk Groot
Modified: 2017-10-11 17:53 UTC (History)
5 users (show)

See Also:
Tags:
Is this bug a regression?: ---
Last known good build:


Attachments
Memory usage mono 3 (deleted)
2017-07-20 14:31 UTC, Dirk Groot
Details
Startup memory usage 3.8.txt (4.85 KB, text/plain)
2017-07-20 14:34 UTC, Dirk Groot
Details
Startup memory usage 5.0.1.1.txt (4.85 KB, text/plain)
2017-07-20 14:34 UTC, Dirk Groot
Details

Description Dirk Groot 2017-07-20 14:31:59 UTC
Created attachment 23697 [details]
Memory usage mono 3

### Some background

We're maintaining quite a large application for ARM hardware using Mono. Currently we use Mono 3.8. Because we want to support TLS 1.2 and because we want to stay up-to-date in general, we're trying to migrate to Mono 5.0.1.1.

### The issue

With Mono 5.0.1.1 we observe a big increase in memory usage compared to Mono 3.8. With the default compile options, this causes out-of-memory errors on our hardware. When we added CFLAGS=-Os, we don't seem to have these errors anymore, but memory usage is still a lot higher than 3.8.

### Minimal reproducable example

The following simple test program shows that even a simple "Hello world" application uses about 8Mb more memory on Mono 5.0.1.1:

using System;
using System.Diagnostics;

namespace MemoryTest
{
    internal class Program
    {
        public static void Main(string[] args)
        {
            var currentProcess = Process.GetCurrentProcess();

            Console.WriteLine("PagedMemorySize64:          {0}", currentProcess.PagedMemorySize64);
            Console.WriteLine("PeakVirtualMemorySize64:    {0}", currentProcess.PeakVirtualMemorySize64);
            Console.WriteLine("PagedSystemMemorySize64:    {0}", currentProcess.PagedSystemMemorySize64);
            Console.WriteLine("PrivateMemorySize64:        {0}", currentProcess.PrivateMemorySize64);
            Console.WriteLine("NonpagedSystemMemorySize64: {0}", currentProcess.NonpagedSystemMemorySize64);
        }
    }
}

Output with Mono 3.8:

PagedMemorySize64:          0
PeakVirtualMemorySize64:    29245440
PagedSystemMemorySize64:    0
PrivateMemorySize64:        16650240
NonpagedSystemMemorySize64: 0

Output with Mono 5.0.1.1:

PagedMemorySize64:          0
PeakVirtualMemorySize64:    37044224
PagedSystemMemorySize64:    0
PrivateMemorySize64:        24903680
NonpagedSystemMemorySize64: 0

When we monitor this in our own application, the difference in memory usage gradually grows to 20+ Mb. The attachments 'Startup memory usage 3.8.txt' and 'Startup memory usage 5.0.1.1.txt' show the memory usage logging of a part of the startup of our application (not all the way to 20+ Mb difference).

### Our analysis

We've tried running the application with garbage collection debug logging (using MONO_LOG_LEVEL=debug and MONO_LOG_MASK=gc) to see if there's any major difference in the sizeo of the major heap and the large object space. While we do see that the Mono 3.8 garbage collector is a bit more "aggressive" when it comes to freeing memory, the peak memory usage of both Mono 3.8 and 5.0.1.1 is roughly the same. There is a small difference of about 2-3 Mb between Mono 3.8 and 5.0.1.1, but this doesn't explain the previously mentioned 20+ Mb difference.

We've also run our application with the --stats option on both versions. The results are in the following gists:

Mono 3.8     : https://gist.github.com/Dricus/3c75ac1246f3a61554c27d5d395134b6
Mono 5.0.1.1 : https://gist.github.com/Dricus/bf44effada4a3f657d708cc9e104d112

### Hardware/software environment

CPU as reported by dmesg:

   CPU: ARMv6-compatible processor [4117b363] revision 3 (ARMv6TEJ), cr=00c5387f
   CPU: VIPT nonaliasing data cache, VIPT nonaliasing instruction cache

Linux kernel    : v2.6.38.8
Physical memory : 128Mb (no swap)

Mono cross-compiled with a toolchain based on GCC version 4.9.3

For compiling Mono 3.8 we use no optimization switches.
For compiling Mono 5.0.1.1 we use --enable-small-config, --enable-minimal=aot,profiler,debug,logging,com,ssa and CFLAGS=-Os
Comment 1 Dirk Groot 2017-07-20 14:34:17 UTC
Created attachment 23698 [details]
Startup memory usage 3.8.txt
Comment 2 Dirk Groot 2017-07-20 14:34:39 UTC
Created attachment 23699 [details]
Startup memory usage 5.0.1.1.txt
Comment 5 Ludovic Henry 2017-07-27 22:03:30 UTC
Hello,

I can't find any information in what you provided that would allow us to pinpoint exactly what triggered the increase of memory usage.

Could you please run on both mono versions with `--profile=log:heap=10000ms`. This will run mono with the log profiler enabled, which will make a heapshot at least every 10s. Please provide us with the `output.mlpd` files for both runs. You can examine what data the `output.mlpd` file contains by running mprof-report on it (look at `mprof-report` man page for more documentation)

Thank you
Comment 6 Dirk Groot 2017-07-28 07:07:52 UTC
When I try to do that, I'm getting the following error: "The 'log' profiler wasn't found in the main executable nor could it be loaded from 'mono-profiler-log'."

We're not deploying all files to our target, maybe I'm missing some? I already tried installing libmono-profile-log.* in /usr/lib, but that didn't make it work.
Comment 8 Ludovic Henry 2017-07-28 13:49:33 UTC
Hello,

I took a look at the output.mlpd files you provided. Some ideas that pop to mind to explain the increase in memory usage:

 - the generated code size goes from 3M to 6M
   - the number of jitted method goes from 12380 to 15208
 - the number of loaded assemblies goes from 74 to 171
 - the number of threads goes from 11 to 18

The headshots indicate that the managed memory size doesn't change in any drastic manner between 3.8 and 5.0, both stays at around 6.5M.

So I would explain the difference in memory by the number of threads which is higher in 5.0 than in 3.8. This might be due to the change of implementation of the threadpool, since we switched to the Microsoft threadpool implementation. Could you run mono 5.0 with `MONO_LOG_LEVEL=info MONO_LOG_MASK=threadpool`, this will log some information about the lifetime of threadpool threads.

Thank you,
Comment 9 Rodrigo Kumpera 2017-10-11 17:53:35 UTC
We have not received the requested information. If you are still experiencing this issue please provide all the requested information and reopen the bug report.

Thank you!

Note You need to log in before you can comment on or make changes to this bug.