Generational aware analysis based on environment variable.

[cshung]

Generational aware analysis

This PR is intended to instrument the runtime so that it is possible to diagnose occasionally long ephemeral GC for .NET 5.0. This is meant to be a stop-gap before we have completed the long term TODOs and for advanced users who know exactly what they want only.

What is the problem?

Long GCs are bad. Sometimes, these long GCs are ephemeral GCs (i.e. gen0 or gen1). This is often caused by accidental promotion (i.e. some gen0/gen1 objects are accidentally referenced by gen2 objects), causing us time to mark and promote them. That only happens once in a while. Once the objects are promoted, they are no longer gen0/gen1, so it won't cause long ephemeral GC anymore, but they become long-term debt. To diagnose issues like this, we would like to inspect the heap right at the spot when the ephemeral GC is long, and currently, there is no way to do that in .NET Core.

How did we diagnose this?

Back in .NET framework days (dated back to at least 2010), we had an internal tool called CrossGenerationLivenessCollector in PerfView. The tool served as a debugger and installed a conditional breakpoint in the runtime. When it hits, the tool captures a heap dump so that we can analyze the heap at that point in time.

What is wrong with the approach above?

1. It requires embedding WinDBG binaries into PerfView.
2. It requires private symbols of clr.dll.
3. It does NOT work on .NET Core.

While it could be adapted so that it works on .NET Core for Windows, it certainly won't work on any platforms other than Windows.

The proposed solution

Instead of having the tool to inspect the target process and capture a dump, we can have the runtime to evaluate the condition and have it emitting traces that allow PerfView to reconstruct the heap graph. This eliminates the need to have a debugger inspecting the runtime as well as the private symbols. By working within the runtime, we also have the advantage that the capability is automatically available across all platforms .NET Core supports. The reconstruction of the heap graph based on traces is currently available through PerfView and therefore is still Windows only.

This proposal does not change what we will do for .NET framework. It is still going to be using CrossGenerationLivenessCollector. Requiring private symbols is just unfortunate and the analysis will be scoped for Microsoft internals only.

How to use

If we happen to know once in a while we have a gen 1 GC that promoted more than 1,500,000 = (0x16E360) bytes. We can set these environment variables before starting up the process.

set COMPLUS_GCGenAnalysisGen=1
set COMPLUS_GCGenAnalysisBytes=16E360

The runtime will start monitoring GC. A file named trace.nettrace will be created upon the 1st GC. When the application moves on, the GC that hit the condition will eventually happen, the runtime will emit traces into the file that allows PerfView to reconstruct the heap graph. When that GC completes, the file will be closed and available for inspection. To make it easier for people to know that happened, a separate empty file named "trace.nettrace.completed" will be generated to signal that the file is ready to be consumed.

Testing

Right now, I have tested that the branch builds and works on Windows. With a hacked version of PerfView, I am available to reconstruct the heap graph and have the generational aware heap graph view working. I can also see the additional delimiting events in their raw form in the trace because they are not current

Short term TODOs (Meant for .NET 5.0)

1. Naming (some of the stuff in the PR will be public (e.g. environment variable) and deserve better names)
2. More testing (cross-platform and server GC), and
3. The PerfView side changes (Not constrained for .NET 5.0 timeframe).
4. Documentation (for example, a tutorial to use this feature)

Long term TODOs (Meant for .NET 6 and beyond)

The PR is known to be incapable of:

• Enabling the analysis after the process starts.
• Canceling existing analysis.
• Having multiple pending analysis requests.
• Having some perf overhead of generating unused events.

The idea of this feature could be generalized so that the runtime waits for a general condition (instead of this specific condition) and do some general diagnostic work. We decided that this generalization is outside of the scope of the current release. A prototype is built to understand some of the complexities. It can be found here (runtime part) and here (diagnostics part).

@dotnet/dotnet-diag
@dotnet/gc

[ghost]

Tagging subscribers to this area: @dotnet/gc
See info in area-owners.md if you want to be subscribed.

[ghost]

Tagging subscribers to this area: @tommcdon
See info in area-owners.md if you want to be subscribed.

[Maoni0]

GetGCSafeMethodTable [](start = 40, length = 20)

shouldn't this also be GetGCSafeTypeHandleIfPossible?

[cshung]

This case is interesting and I am not sure what is the right thing to do here. We cannot simply skip the execution of this method because it requires a return value. Also, right after the call, the code handles collectible right away.

[jkotas]

Should this rather use regular event stream instead of ad-hoc file? Do we have ad-hoc file like this anywhere else?

[cshung]

Should this rather use regular event stream instead of ad-hoc file?

The regular event pipe worked by having a client connecting to it, that gives us a socket where the events can write to. In this case, we do not have a client, therefore there is no socket, the only alternative is a file.

Do we have ad-hoc file like this anywhere else?

We have a precedent of writing to a file here.

runtime/src/coreclr/src/vm/eventpipe.cpp

Lines 134 to 147 in 6072e4d

	void EventPipe::EnableViaEnvironmentVariables()
	{
	STANDARD_VM_CONTRACT;
	if (CLRConfig::GetConfigValue(CLRConfig::INTERNAL_EnableEventPipe) != 0)
	{
	CLRConfigStringHolder eventpipeConfig(CLRConfig::GetConfigValue(CLRConfig::INTERNAL_EventPipeConfig));
	CLRConfigStringHolder configOutputPath(CLRConfig::GetConfigValue(CLRConfig::INTERNAL_EventPipeOutputPath));
	uint32_t eventpipeCircularBufferMB = CLRConfig::GetConfigValue(CLRConfig::INTERNAL_EventPipeCircularMB);
	LPCWSTR outputPath = nullptr;
	if (configOutputPath == NULL)
	{
	outputPath = W("trace.nettrace");
	}

[jkotas]

I do not think we should be trying to get this feature into .NET 5 at the last minute. It looks too unbaked.

[Maoni0]

had conversation with @mangod9, @jkotas and @jeffschwMSFT about this.

we are working to keep the risk low for .net 5 -

• when the env var is not enabled, the risk should be basically zero - it's checking whether a var is set so we don't foresee a problem there;
• when the env var is enabled, the first order of things is to not cause reliability issues (no crash, no hang). we are doing some stress testing (triggering this in a GC stress run; making sure if we have trouble writing to files this this wouldn't cause the process to crash/hang) and also avoiding to introduce any new scenario as much as we can (eg, we already have precedence enabling event pipe on startup and we have moved the heavylifting of enabling/disabling eventpipe out of SuspendEE/RestartEE code path. enabling is now done at the same place where we are handling the EnableEventPipe env var);
• if there is corner cases that would make data collection not work it's an acceptable risk for the benefit this provides;

there's no timeline for a generic triggering mechanism in our tooling so this is what we are doing before that's available meaning that if we delay this to .net 6 we'd be doing the same thing anyway. since this is a very important diagnostics feature, we'll do our best to keep the risk low for .net 5 so we can get it out to customers sooner.

[cshung]

In this new iteration, I have done some extensive stress testing and fixed a few bugs. With this fix, the code survived 12 hours of ReliabilityFramework stress and a full CoreCLR test pass with the stress mode on.

The basic idea of the stress mode is to trigger the GCProfileWalkHeap() during mark_phase() as much as possible. We also turn the EventPipe on and off to make sure we also stress the flushing of data.

Before the stress test, the EventPipe is enabled conditionally on process startup, and it is disabled in the finalizer thread after the desired GC is captured. In stress mode, the EventPipe is turned on unconditionally, all GCs are desired, and when it is disabled, it is turned back on right away to repeatedly stress the capability.

The test discovered a couple of issues, and they are fixed now:

• When EventPipe encounters a File I/O error, it asserts (which it should not, the code cannot guarantee no file I/O error happens), and then it ignores all the File I/O by doing nothing. For a quick fix, I just commented out the assert.
• When there are RCW/CCW, the code asserts because the method table are marked. The code is fixed so that it logs the event only when it is safe to do so.

[cshung]

I have also run a full pass of CoreCLR tests with runincontext turned on to stress unloadable types and didn't find any bugs for this feature.

[josalem]

The eventing aspects look good to me. I think we should document in comments what the specific use case is for the EventPipeSession pausing feature is. It is exclusive to this tracing mechanism and isn't necessarily safe for use outside of the isolated use during a GC.

[noahfalk]

Sorry I know this waiting for me for a while - I had a fair backlog of stuff to review + some time OOF. All the comments that are code refactoring I'd be having you defer to a .NET6 PR if that helps make this more expedient (as long as they don't get forgotten : ). The others are probably important to at least consider now.

[sywhang]

Eventing side changes LGTM modulo few nits 👍

[sywhang]

Is there a corresponding change to TraceEvent? If so it might be good to link it from the PR.

[sywhang]

You could still use the COMPlus_EventPipeCircularMB here to make this configurable, right?

[Maoni0]

I think this is a good suggestion and we should use the value specified by this env var if it's set. if you have a big heap and there are a lot of edges/etc 1gb may not be enough and since we already have an env var why not take advantage of it. @cshung, is there any reason why you wouldn't want to use the env var here?

[cshung]

See #40918

[noahfalk]

This looks good to me! If you do wind up changing the code for the open issue in HeapWalkHelper I'd like to know, but as-is I think its likely to be correct and I am fine signing off under that presumption.