SampleProfiler incorrectly marks all samples as external code on Windows

[josalem]

The SampleProfiler sends ThreadSample events that reference stacks. The payload of these events is supposed to indicate what type of code was executing in the leaf frame at the time of suspension.

runtime/src/coreclr/src/vm/sampleprofiler.cpp

Lines 238 to 250 in 3f89665

	// Set the payload. If the GC mode on suspension > 0, then the thread was in cooperative mode.
	// Even though there are some cases where this is not managed code, we assume it is managed code here.
	// If the GC mode on suspension == 0 then the thread was in preemptive mode, which we qualify as external here.
	// Write the sample.
	EventPipe::WriteSampleProfileEvent(
	s_pSamplingThread,
	s_pThreadTimeEvent,
	pTargetThread,
	stackContents,
	pTargetThread->GetGCModeOnSuspension() ? s_ManagedPayload.Rawdata : s_ExternalPayload.Rawdata,
	c_payloadSize);
	}

The SampleProfiler uses a cached value of m_fPreemptiveGCDisabled to determine whether to mark a sample as "managed" (GC was in COOP mode) or "external" (GC was in preemptive mode).

runtime/src/coreclr/src/vm/threads.h

Lines 4627 to 4654 in 73a7993

	#ifdef FEATURE_PERFTRACING
	private:
	// SampleProfiler thread state. This is set on suspension and cleared before restart.
	// True if the thread was in cooperative mode. False if it was in preemptive when the suspension started.
	Volatile<ULONG> m_gcModeOnSuspension;
	// The activity ID for the current thread.
	// An activity ID of zero means the thread is not executing in the context of an activity.
	GUID m_activityId;
	public:
	bool GetGCModeOnSuspension()
	{
	LIMITED_METHOD_CONTRACT;
	return m_gcModeOnSuspension != 0U;
	}
	void SaveGCModeOnSuspension()
	{
	LIMITED_METHOD_CONTRACT;
	m_gcModeOnSuspension = m_fPreemptiveGCDisabled;
	}
	void ClearGCModeOnSuspension()
	{
	m_gcModeOnSuspension = 0;
	}

Currently, SaveGCModeOnSuspension is only called from HandleGCSuspensionForInterruptedThread.

runtime/src/coreclr/src/vm/threadsuspend.cpp

Lines 6071 to 6096 in c8c0790

	// This function is called when a GC is pending. It tries to ensure that the current
	// thread is taken to a GC-safe place as quickly as possible. It does this by doing
	// one of the following:
	//
	// - If the thread is in native code or preemptive GC is not disabled, there's
	// nothing to do, so we return.
	//
	// - If the thread is in interruptible managed code, we will push a frame that
	// has information about the context that was interrupted and then switch to
	// preemptive GC mode so that the pending GC can proceed, and then switch back.
	//
	// - If the thread is in uninterruptible managed code, we will patch the return
	// address to take the thread to the appropriate stub (based on the return
	// type of the method) which will then handle preparing the thread for GC.
	//
	void HandleGCSuspensionForInterruptedThread(CONTEXT *interruptedContext)
	{
	Thread *pThread = GetThread();
	if (pThread->PreemptiveGCDisabled() != TRUE)
	return;
	#ifdef FEATURE_PERFTRACING
	// Mark that the thread is currently in managed code.
	pThread->SaveGCModeOnSuspension();
	#endif // FEATURE_PERFTRACING

Unfortunately, this code is only used for thread suspension on non-Windows platforms. This means that all sample events on Windows are marked as "external" code since the underlying value is never changed from the uninitialized value of 0 (meaning preemptive mode). On Linux/Mac systems, however, stacks are correctly labeled.

This value is used in tools like PerfView to do analysis on things like CPU blocking time.

We need to determine a location to call SaveGCModeOnSuspension that works for both platforms or add a call to the equivalent location on Windows.

One spot I'm vetting is here:

runtime/src/coreclr/src/vm/threadsuspend.cpp

Lines 3519 to 3526 in 93cbc09

	while (true)
	{
	Thread* thread = NULL;
	while ((thread = ThreadStore::GetThreadList(thread)) != NULL)
	{
	if (thread == pCurThread)
	continue;

in ThreadSuspend::SuspendRuntime where it enumerates all the threads it is about to suspend.

I'm not sure how long this has been an issue, but I'm guessing it has been since this logic went in (~4 years ago circa .NET Core 2.2).

Is there another way we could transmit this information? We could save the 4 bytes per sample event if we do away with this payload. That can add up fast when you have ~1000 samples per thread per second. That's roughly 4 kb/s per thread for a value that will always be 1 or 2. Could we intern this information directly into the stack events? That would require a format change, though.

CC @sywhang @noahfalk @brianrob @tommcdon

[ghost]

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

Issue Details

---

The SampleProfiler sends ThreadSample events that reference stacks. The payload of these events is supposed to indicate what type of code was executing in the leaf frame at the time of suspension.

runtime/src/coreclr/src/vm/sampleprofiler.cpp

Lines 238 to 250 in 3f89665

	// Set the payload. If the GC mode on suspension > 0, then the thread was in cooperative mode.
	// Even though there are some cases where this is not managed code, we assume it is managed code here.
	// If the GC mode on suspension == 0 then the thread was in preemptive mode, which we qualify as external here.
	// Write the sample.
	EventPipe::WriteSampleProfileEvent(
	s_pSamplingThread,
	s_pThreadTimeEvent,
	pTargetThread,
	stackContents,
	pTargetThread->GetGCModeOnSuspension() ? s_ManagedPayload.Rawdata : s_ExternalPayload.Rawdata,
	c_payloadSize);
	}

The SampleProfiler uses a cached value of m_fPreemptiveGCDisabled to determine whether to mark a sample as "managed" (GC was in COOP mode) or "external" (GC was in preemptive mode).

runtime/src/coreclr/src/vm/threads.h

Lines 4627 to 4654 in 73a7993

	#ifdef FEATURE_PERFTRACING
	private:
	// SampleProfiler thread state. This is set on suspension and cleared before restart.
	// True if the thread was in cooperative mode. False if it was in preemptive when the suspension started.
	Volatile<ULONG> m_gcModeOnSuspension;
	// The activity ID for the current thread.
	// An activity ID of zero means the thread is not executing in the context of an activity.
	GUID m_activityId;
	public:
	bool GetGCModeOnSuspension()
	{
	LIMITED_METHOD_CONTRACT;
	return m_gcModeOnSuspension != 0U;
	}
	void SaveGCModeOnSuspension()
	{
	LIMITED_METHOD_CONTRACT;
	m_gcModeOnSuspension = m_fPreemptiveGCDisabled;
	}
	void ClearGCModeOnSuspension()
	{
	m_gcModeOnSuspension = 0;
	}

Currently, SaveGCModeOnSuspension is only called from HandleGCSuspensionForInterruptedThread.

runtime/src/coreclr/src/vm/threadsuspend.cpp

Lines 6071 to 6096 in c8c0790

	// This function is called when a GC is pending. It tries to ensure that the current
	// thread is taken to a GC-safe place as quickly as possible. It does this by doing
	// one of the following:
	//
	// - If the thread is in native code or preemptive GC is not disabled, there's
	// nothing to do, so we return.
	//
	// - If the thread is in interruptible managed code, we will push a frame that
	// has information about the context that was interrupted and then switch to
	// preemptive GC mode so that the pending GC can proceed, and then switch back.
	//
	// - If the thread is in uninterruptible managed code, we will patch the return
	// address to take the thread to the appropriate stub (based on the return
	// type of the method) which will then handle preparing the thread for GC.
	//
	void HandleGCSuspensionForInterruptedThread(CONTEXT *interruptedContext)
	{
	Thread *pThread = GetThread();
	if (pThread->PreemptiveGCDisabled() != TRUE)
	return;
	#ifdef FEATURE_PERFTRACING
	// Mark that the thread is currently in managed code.
	pThread->SaveGCModeOnSuspension();
	#endif // FEATURE_PERFTRACING

Unfortunately, this code is only used for thread suspension on non-Windows platforms. This means that all sample events on Windows are marked as "external" code since the underlying value is never changed from the uninitialized value of 0 (meaning preemptive mode). On Linux/Mac systems, however, stacks are correctly labeled.

This value is used in tools like PerfView to do analysis on things like CPU blocking time.

We need to determine a location to call SaveGCModeOnSuspension that works for both platforms or add a call to the equivalent location on Windows.

One spot I'm vetting is here:

runtime/src/coreclr/src/vm/threadsuspend.cpp

Lines 3519 to 3526 in 93cbc09

	while (true)
	{
	Thread* thread = NULL;
	while ((thread = ThreadStore::GetThreadList(thread)) != NULL)
	{
	if (thread == pCurThread)
	continue;

in ThreadSuspend::SuspendRuntime where it enumerates all the threads it is about to suspend.

I'm not sure how long this has been an issue, but I'm guessing it has been since this logic went in (~4 years ago circa .NET Core 2.2).

Is there another way we could transmit this information? We could save the 4 bytes per sample event if we do away with this payload. That can add up fast when you have ~1000 samples per thread per second. That's roughly 4kb/s for a value that will always be 1 or 2. Could we intern this information directly into the stack events? That would require a format change, though.

CC @sywhang @noahfalk @brianrob @tommcdon

Author:	josalem
Assignees:	-
Labels:	area-Diagnostics-coreclr
Milestone:	6.0.0

[brianrob]

Good catch @josalem. I suspect you are right that this has been this way since 2.2, as the initial EventPipe implementation in 2.0 was limited to UNIX which uses a different suspension mechanism.