Memory usage on coverage analysis

[oliwennell]

Under certain circumstances the memory usage of Fettle increases by a very large amount during coverage analysis.

This has been noticed because of out-of-memory errors can sometimes occur, causing Fettle to exit.

We should capture a memory dump and investigate.

My suspicion is it's caused by the console output generated by the instrumented methods, in which case perhaps we can prevent a method from outputting if it's already done so for a given test.

[Scooletz]

Could you provide a repro for this? It'd make it easier a new contributor to just windbg it (or Benchmarkdotnet it) ;-)

[oliwennell]

Good point, I will try to find a minimal repro 👍

[oliwennell]

When running fettle over its example project (HasSurvivingMutants in the examples directory, config file: fettle.config.example.yml), memory usage during the coverage analysis phase is roughly 40MB on my development machine.

However if I add this test method to HasSurvivingMutants.Tests.PartialNumberComparisonTests.cs:

[Test]
public void MakeFettleUseLotsOfMemory()
{
    for (int i = 0; i < 1000000; ++i)
        PartiallyTestedNumberComparison.IsZero(1);
}

...then I see memory usage peak at 1.3GB

[Scooletz]

Looks like a good repro. At the end of the week I should have some time. If you want @oliwennell assign this issue to me.

[oliwennell]

Will do, thank you @Scooletz

[Scooletz]

@oliwennell I added this test, rebuilt solution and tried to run it. According to my understanding of Readme.md my call looked like this (fettle was located in C:\GIT\fettle

 C:\GIT\fettle\src\Console\bin\Release> .\Fettle.Console.exe --config C:\GIT\fettle\fettle.config.example.yml

The output was following

Analysing test coverage....................


Mutation testing starting...

Looking in plementation\SkipAbstractMethodMutation.cs (1/2):
  Found method: SkipAbstractMethodMutation.AddTwoNumbers        ....

Looking in plementation\PartiallyTestedNumberComparison.cs (2/2):
  Found method: PartiallyTestedNumberComparison.IsPositive      ..?
  Found method: PartiallyTestedNumberComparison.IsNegative      ...?
  Found method: PartiallyTestedNumberComparison.IsZero  .?
  Found method: PartiallyTestedNumberComparison.AreBothZero     .?..
  Found method: PartiallyTestedNumberComparison.Sum     .?
  Found method: PartiallyTestedNumberComparison.Preincrement    .?
  Found method: PartiallyTestedNumberComparison.Postincrement   .?
  Found method: PartiallyTestedNumberComparison.PositiveOrNegative      .?
  Found method: PartiallyTestedNumberComparison.PositiveOrNegativeAsExpressionBody      .?

which not included the MakeFettleUseLotsOfMemory. Also I didn't notice the spike. Could you provide me some guidance, how I should run it to repro it @oliwennell ?

[oliwennell]

@Scooletz Ah, ok. The output only specifies the code being mutated, which is the implementation. As you only changed a test, I wouldn't expect that to change.

One thing I forgot to mention though, was that the config file points to the Debug version of the example project binaries. So you may need to recompile the example projects in Debug mode.

Regarding the spike, this is in the first phase so you may miss it. You could perhaps make the increase in memory even bigger by increasing the number of iterations in the sample:

for (int i = 0; i < 1000000; ++i) // increase the 1000000 to a much bigger number

[Scooletz]

I was able to reproduce it and run an initial scan with a profiler. Will write a bit more this evening.

[Scooletz]

I run the tests and took several snapshots of memory. I need to remark, that I don't know fettle well and I'm not aware of all the design choices you made, so I'll try to describe what I found. The image of the snapshot is added below. Now a few remarks related to the profiling:

• I run 1 million sample
• the allocations that are most significant are related to string (over 400MBs)
• the reason for this allocations is passing the NUnit event as a string (initally it's XNode that turned into a string with .ToString(), the one that is processed by fettle's NUnitCoverageCollector.

At this moment, I see no way to augment NUnit to act differently, it's NUnit's API, so we cannot change it that easily. What we could change (but due to my limited knowledge of fettle I cannot point to) is the way fettle reports/interacts with NUnit test result. If we could pass this information in an alternative way, we could make the report smaller, and omit allocating the big chunk of memory just to get it parsed again.

If you could provide some guidance about this piece of fettle, maybe I'd be able to move it forward.

[oliwennell]

Thank you for the analysis @Scooletz , that's very useful :)

I think there may be a way to reduce the size of the output that goes into that NUnit XML. This should make the memory increase more slowly, but won't remove the issue entirely.

I'll have a think about that and get back to you.

[oliwennell]

Apologies for the late response @Scooletz Here are my thoughts:

To perform the coverage analysis, Fettle instruments the code being mutated so that it outputs a GUID to stdout for every method call, see:
https://github.com/ComparetheMarket/fettle/blob/master/src/Core/CoverageAnalyser.cs#L177

This stdout is then part of the NUnit event you mentioned, and the more times methods are called, the bigger the output. And as your analysis showed, this turns out to use a significant amount of memory.

This GUID is designed to represent the method uniquely. However I don't think we need to use a GUID, and could instead use something that takes up less memory when written to stdout. E.g. a long.

For this to work we'd need to modify this line to increment a numeric value, instead of generating a GUID:
https://github.com/ComparetheMarket/fettle/blob/master/src/Core/CoverageAnalyser.cs#L164

Please let me know what you think

[Scooletz]

Thank you for providing this in-depth description. This showed not only the allocation path, but also enhanced my understanding of fettle. I think that using long would be beneficial, especially if it was stringified to hex (even less characters). I'm offline this week, but give it a try (and retest it) near the end of the week. One more thought. Holding longs in a dictionary translating ids to method names could also reduce the overhead (or even creating a better structure to map this many-to-one relation).

…

On Tue, 17 Jul 2018, 10:14 Oli Wennell, ***@***.***> wrote: Apologies for the late response @Scooletz <https://github.com/Scooletz> Here are my thoughts: To perform the coverage analysis, Fettle instruments the code being mutated so that it outputs a GUID to stdout for every method call, see: https://github.com/ComparetheMarket/fettle/blob/master/src/Core/CoverageAnalyser.cs#L177 This stdout is then part of the NUnit event you mentioned, and the more times methods are called, the bigger the output. And as your analysis showed, this turns out to use a significant amount of memory. This GUID is designed to represent the method uniquely. However I don't think we need to use a GUID, and could instead use something that takes up less memory when written to stdout. E.g. a long. For this to work we'd need to modify this line to increment a numeric value, instead of generating a GUID: https://github.com/ComparetheMarket/fettle/blob/master/src/Core/CoverageAnalyser.cs#L164 Please let me know what you think — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#20 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAfuG6ydZbFRwoYOh3_Rf-WXSMOS120cks5uHZz2gaJpZM4UFAJF> .

[oliwennell]

Ok, sounds good, let me know if you need any help @Scooletz 👍

[Scooletz]

I just noticed mmap_file_spike branch. Is this something you're going to pursue? This is a much better way for reporting across processes (although it might require elevated permissions when used as shared mem).

[oliwennell]

Yeah it would be much better I agree but unfortunately I wasn't able to get it working :(

The idea, as I think you saw, was to instrument the code-under-test to write to a memory-mapped file whenever a method was called. Then when a test completes, all method names/IDs written to that file are collected and the file is cleared.

Unfortunately, I found that NUnit wasn't calling the API to signal a test completing in a synchronous manner. Once a test finished, it would run a few more before calling the NUnit API to signal that the first test had completed. So the file would contain a mix of methods called by different tests.

I wasn't able to think of a way around this but maybe there is? You're more than welcome to play around with this approach if you want :)

[Scooletz]

@oliwennell I think I'm not able to invest my time now 😢 Could you unassign me from the issue?

[oliwennell]

That's fine @Scooletz , no problem, thanks for your help :)

[oliwennell]

Have changed from using GUIDs for member IDs to longs as discussed
b899ae5

[oliwennell]

There may be a way to solve this: Fettle could instrument each test so that the current test's ID is assigned to an environment variable when the test starts. This would allow the instrumented code-under-test to know the currently executing test (by reading the environment variable).

Once this was done, the memory leak could be fixed by changing the instrumentation of the code-under-test. Instead of logging each called method ID to stdout, it would keep track of which methods have been reported for a given test and only output each method once per test.

(Alternatively, knowing the current test could allow this to be fixed another way. The executed method IDs could be written to files: one per test)

Instrumenting tests is do-able but has implications:

• If the test instrumentation was done by manipulating the source code: Fettle would need to know which projects to compile. But right now users specify tests assembly file paths in the config file.
• Or, if the test instrumentation was done by manipulating the assemblies (i.e. via Mono.Cecil): there would then be two different ways that Fettle instruments code (tests via Mono.Cecil, code-under-test via Roslyn) which would be wierd.