CODEWITHSUNDEEP
memory-managementf#garbage-collection
MiMo
MiMo

Reputation: 11953

Interpreting F# garbage collection report

I have a fairly complex F# application, and I use a F# script to check its performance using the #time directive. The idea is that I run the script after changes to the code to keep track of performances and avoid introducing speed or memory problems.

The report I was getting was something like this:

Real: 00:00:02.908, CPU: 00:00:02.948, GC gen0: 237, gen1: 3, gen2: 1

but after the last change I get this:

Real: 00:00:03.058, CPU: 00:00:03.057, GC gen0: 262, gen1: 262, gen2: 0

and I have some trouble figuring out what's going on.

More generation 1 garbage collection means (?) that there are more long-lived object that survive garbage collection in generation 0 - but why the sudden jump from 3 to 262? And why the number of garbage collection on generation 0 and 1 are identical? If for some reason after the code changes there are more long-lived objects I would have expected something like:

Real: 00:00:02.908, CPU: 00:00:02.948, GC gen0: 212, gen1: 54, gen2: 1

i.e. the total number of garbage collected objects being similar but with more on generation 1.

Or am I totally misunderstanding those numbers (I could not find a description in the documentation)?

UPDATE

As pointed out in the comments I totally misunderstood the numbers: they are the number of garbage collections executed for each generation, not the number of objects.

Having said that I am even more puzzled: it seems that my application put the memory in such a state that every generation-0 garbage collection triggers also a generation-1 one, and I cannot imagine what this state could be. I tried various test programs to replicate such behavior without luck.

I still have to try the profilers as suggested in the comments and pad's answer.

UPDATE 2

I tried the CLR profiler as suggested in the comments - to do it I converted my F# script into a program and run it from the profiler.

The report I get is completely different from the #time one - garbage collections:

Mistery - strage side-effect of using FSI.exe compared with a stand-alone program? Bug in #time?

Upvotes: 1

Views: 2041

Answers (1)

pad
pad

Reputation: 41290

.NET GC is a three-generation GC. As John Palmer pointed out, the last three numbers are the number of collections run at these generations. Bigger numbers in gen1 and gen2 often indicate bad performance since GC has to mark those unused objects again and again in each garbage collection process. For more in depth introduction of .NET GC, take a look at this nice article.

Here are a few suggestions:

  1. Make sure to "Reset Sessions" between two measurements so that unused objects of the first session doesn't have an influence on the second one.
  2. Find three bigger inputs to measure. Though execution times in these two reports are similar, I would expect the first approach to be more scalable. It's great if you have several input sizes to test scalability.
  3. Measure a few times to record a pattern because you may just observe an abnormal session.
  4. If in doubt, do a full-range profiling in Visual Studio. Their reports are much more comprehensive and reliable for performance prediction.

Upvotes: 2

Related Questions