none
How to filter managed threads that are unsafe or during JIT compilation or garbage collection for sampling profiler? RRS feed

  • Question

  • Hi,

    I am writing a  sampling profiler, but I get some trouble.

    I make a profiler for iis. When the site start and start sampling at the same time, the site will be very very slow , and then  about 2~3 min the w3wp.exe  seems to be killed.

    I think the problem is due to sampling a thread that is JIT compiling or garbage collection.

    How to filter managed threads that are unsafe for CLR or during JIT compilation or garbage collection?


    Tuesday, November 29, 2016 2:53 AM

Answers

  • 1. On the Profiler Stack Walking in the .NET Framework 2.0: Basics and Beyond 

    >> You can get this function information right away, during your stack walk, or alternatively save the funcId values and get the function information later, which reduces your impact on the running application. 

    This means it's bug for CLR? 

    I can't say for certain if there is a CLR bug here or not, but I wouldn't expect so. This is just a natural consequence of suspending a thread holding a lock you want.

    2. I test many times, and found that my sampler thread will block on another call.

    Does it mean that I can not use any function that will trigger allocate heap in DoStackSnapshotCallback?

    No, there can be more than one heap and if you allocate from a heap that no other thread uses, then you won't get a deadlock ... or at least not from the allocation.

    Ideally, if the suspended thread held a lock you wanted, then you would let it run just until it released the lock. Unfortunately, I'm not aware of any way to actually achieve this, so you will just have to make sure that your sampling thread doesn't need anything that the suspended thread *might* have locked.

    • Marked as answer by IMMark Saturday, December 3, 2016 4:33 PM
    Friday, December 2, 2016 1:15 PM
  • I don't think there is anything that provides that information directly, but you can register for callbacks on JIT begin/end and GC begin/end. If these callbacks happen on the thread doing the work (I haven't verified, but it would make sense if they were) then you can track the state yourself.

    Having said that, it seems odd a sampling profiler is having such performance issues. Just how frequently are you taking your samples? How long does it take to capture each sample? (QueryPerformanceCounter)

    • Marked as answer by IMMark Saturday, December 3, 2016 4:34 PM
    Tuesday, November 29, 2016 7:37 AM

All replies

  • It seems you're doing something really cool. Are you making somthing like CLR Profiler? I'm not familiar with so underlying implementation, But CLR Profiler is an Open Source Project, you can check the API and the source at http://clrprofiler.codeplex.com/.  Maybe you can find the answer there.
    Tuesday, November 29, 2016 6:25 AM
  • I have been read it, and there is no code about filter a thread during JIT compilation , or even doStackSnapShot.

    Thanks for your reply.

    Tuesday, November 29, 2016 6:52 AM
  • Hi IMMark,

    Thanks for posing here.

    >>How to filter managed threads that are unsafe for CLR or during JIT compilation or garbage collection?

    Sorry I am not very clear about your question. What do you mean by "filter managed threads that are unsafe for CLR "?

    If you want to how to distinguish GC thread or JIT thread

    Maybe WinDbg.exe helps, the main executable of the Debugging Tools for Windows package, can analyze CLR heaps with SoS extension.

    https://channel9.msdn.com/Series/-NET-Debugging-Stater-Kit-for-the-Production-Environment/How-to-Identify-CLR-threads-in-a-dump-08

    If I misunderstood you, please feel free to let me know.

    Best regards,

    Kristin


    MSDN Community Support
    Please remember to click "Mark as Answer" the responses that resolved your issue, and to click "Unmark as Answer" if not. This can be beneficial to other community members reading this thread. If you have any compliments or complaints to MSDN Support, feel free to contact MSDNFSF@microsoft.com.

    Tuesday, November 29, 2016 7:21 AM
  • I don't think there is anything that provides that information directly, but you can register for callbacks on JIT begin/end and GC begin/end. If these callbacks happen on the thread doing the work (I haven't verified, but it would make sense if they were) then you can track the state yourself.

    Having said that, it seems odd a sampling profiler is having such performance issues. Just how frequently are you taking your samples? How long does it take to capture each sample? (QueryPerformanceCounter)

    • Marked as answer by IMMark Saturday, December 3, 2016 4:34 PM
    Tuesday, November 29, 2016 7:37 AM
  • Hi,

    I should use the word 'distinguish', not 'filter'.

    I am writing a sampling profiler following the Profiler Stack Walking in the .NET Framework 2.0: Basics and Beyond.

    But I just want to sampling 'normal' managed threads (not in gc or jit compilation), my problem is how to  distinguish these threads?


    • Edited by IMMark Tuesday, November 29, 2016 7:58 AM
    Tuesday, November 29, 2016 7:57 AM
  • Thanks for your reply.

    take samples -> wait 200ms ->take samples->wait 200ms

    1.It's very fast without JITCompilationStarted.

    2016-11-29 16:04:30.306 DEBUG RequestProfile g_native2ManagedMap is 51, localList is 52
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x282af70) nativeThreadId(0xc50c) 
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x718a340) nativeThreadId(0xdb40)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x7422010) nativeThreadId(0xd64c)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x2871dd0) nativeThreadId(0xc4dc)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x658e320) nativeThreadId(0xdb90)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x67c3520) nativeThreadId(0xd4f4)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x6ecd310) nativeThreadId(0xdbe0)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x6fbb080) nativeThreadId(0xbdd4)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x6fbb790) nativeThreadId(0xd728)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x645b8e0) nativeThreadId(0xbfe0)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x645cff0) nativeThreadId(0xcd48)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x717d1f0) nativeThreadId(0xc788)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x741aa40) nativeThreadId(0xda5c)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x741a330) nativeThreadId(0xd754)
    2016-11-29 16:04:30.306 DEBUG DoStackSnapShot Suspend managedThreadId(0x741d990) nativeThreadId(0xbc50)
    2016-11-29 16:04:30.306 DEBUG RequestProfile:  Ending!

    2.But it seems deadlock when Sampling and JITCompilationStarted

    2016-11-29 16:04:30.524 DEBUG RequestProfile g_native2ManagedMap is 52, localList is 51
    2016-11-29 16:04:30.524 DEBUG JITCompilationStarted: functionID(8791827841800): MySql.Data.MySqlClient.NativeDriver.ReadPacket()
    2016-11-29 16:04:30.524 DEBUG DoStackSnapShot Suspend managedThreadId(0x282af70) nativeThreadId(0xc50c)
    2016-11-29 16:04:30.524 DEBUG JITCompilationStarted: functionID(8791827841816): MySql.Data.MySqlClient.NativeDriver.ReadOk(System.Boolean)
    2016-11-29 16:04:30.524 DEBUG DoStackSnapShot Suspend managedThreadId(0x718a340) nativeThreadId(0xdb40)
    2016-11-29 16:04:30.524 DEBUG DoStackSnapShot Suspend managedThreadId(0x7422010) nativeThreadId(0xd64c)
    2016-11-29 16:04:30.524 DEBUG DoStackSnapShot Suspend managedThreadId(0x2871dd0) nativeThreadId(0xc4dc)
    2016-11-29 16:04:30.524 DEBUG DoStackSnapShot Suspend managedThreadId(0x658e320) nativeThreadId(0xdb90)
    2016-11-29 16:04:30.524 DEBUG JITCompilationStarted: functionID(8791827845008): MySql.Data.MySqlClient.MySqlPacket.ReadFieldLength()
    2016-11-29 16:04:30.524 DEBUG DoStackSnapShot Suspend managedThreadId(0x67c3520) nativeThreadId(0xd4f4)
    2016-11-29 16:04:30.524 DEBUG DoStackSnapShot Suspend managedThreadId(0x6ecd310) nativeThreadId(0xdbe0)
    2016-11-29 16:04:30.524 DEBUG JITCompilationStarted: functionID(8791827849336): MySql.Data.MySqlClient.Authentication.MySqlAuthenticationPlugin.AuthenticationSuccessful()
    2016-11-29 16:04:30.524 DEBUG DoStackSnapShot Suspend managedThreadId(0x6fbb080) nativeThreadId(0xbdd4)

    I have a separate and the only thread to suspend other threads. This thread never run managed code as well.And this thread only wait for a event to trigger sampling.  
    • Edited by IMMark Tuesday, November 29, 2016 8:24 AM delete useless log
    Tuesday, November 29, 2016 8:19 AM
  • Sounds kinda like the JITCompilationStarted event might be calling back into managed code (any profiler callback that tries to re-enter managed code is just asking for dead-lock trouble). Try breaking into the debugger while in the deadlocked state and check the stack trace of the profiler.
    Tuesday, November 29, 2016 8:57 AM
  • I debug and snapshot when deadlock.

    And I found that my sampler thread is blocked at a function , but I don't know how to check,here is my sampler thread's stack:

    ntoskrnl.exe!KeWaitForMultipleObjects+0xc0a
    ntoskrnl.exe!KeAcquireSpinLockAtDpcLevel+0x712
    ntoskrnl.exe!KeWaitForMutexObject+0x19f
    ntoskrnl.exe!_misaligned_access+0xba0
    ntoskrnl.exe!_misaligned_access+0x183d
    ntoskrnl.exe!KeAcquireSpinLockAtDpcLevel+0x91d
    ntoskrnl.exe!KeWaitForMutexObject+0x19f
    ntoskrnl.exe!NtWaitForSingleObject+0xde
    ntoskrnl.exe!KeSynchronizeExecution+0x3a23
    ntdll.dll!NtWaitForSingleObject+0xa
    ntdll.dll!RtlpWaitOnCriticalSection+0xe8
    ntdll.dll!RtlEnterCriticalSection+0xd1
    ntdll.dll!RtlpAllocateHeap+0x1cc
    ntdll.dll!RtlAllocateHeap+0x16c
    clr.dll!EEHeapAllocInProcessHeap+0x5f
    clr.dll!operator new[]+0x36
    clr.dll!MDInternalRW::InitWithRO+0x57
    clr.dll!ConvertRO2RW+0xb2
    clr.dll!ConvertMDInternalImport+0x41
    clr.dll!PEFile::ConvertMDInternalToReadWrite+0x3b
    clr.dll!PEFile::OpenImporter+0xe
    clr.dll!PEFile::GetRWImporter+0x15
    clr.dll!ProfToEEInterfaceImpl::GetModuleMetaData+0xf6
    Profiler.dll!Sampler::CacheFrame+0xa2
    Profiler.dll!Sampler::DoStackSnapshotCallback+0x1c2
    clr.dll!ProfilerStackWalkCallback+0xd4
    clr.dll!Thread::MakeStackwalkerCallback+0x2f
    clr.dll!Thread::StackWalkFramesEx+0x8d
    clr.dll!Thread::StackWalkFrames+0xb1
    clr.dll!ProfToEEInterfaceImpl::ProfilerStackWalkFramesWrapper+0x1c
    clr.dll!ProfToEEInterfaceImpl::DoStackSnapshotHelper+0x6f
    clr.dll!ProfToEEInterfaceImpl::DoStackSnapshot+0x305
    RichAPM.Profiler.dll!Sampler::GetStackTrace+0xfd
    RichAPM.Profiler.dll!Sampler::Loop+0x1dc
    RichAPM.Profiler.dll!Sampler::ThreadProc+0x13e
    kernel32.dll!BaseThreadInitThunk+0xd
    ntdll.dll!RtlUserThreadStart+0x1d

    the function CacheFrame is to get the function's class name and method name.

    HRESULT Sampler::CacheFrame(FunctionID funcId, COR_PRF_FRAME_INFO frameInfo, Frame* frame)
    {
    HRESULT hr = S_OK;

    ModuleID moduleId;
    ClassID classId;
    mdMethodDef methodToken = mdTypeDefNil;
    ULONG32 retrieved = 0;
    hr = m_info->GetFunctionInfo2(
    funcId, frameInfo, &classId, &moduleId,
    &methodToken, 0, &retrieved, NULL);
    if (hr != S_OK)
    {
    return hr;
    }

    IMetaDataImport2* metadata2 = NULL;
    hr = m_info->GetModuleMetaData(
    moduleId, ofRead, IID_IMetaDataImport2,
    (IUnknown **)&metadata2);
    if (hr != S_OK)
    {
    return hr;
    }

    ULONG cchMethod;
    WCHAR szMethod[MAX_LENGTH] = L"";
    mdTypeDef typeDefToken = mdTypeDefNil;
    hr = metadata2->GetMethodProps(
    methodToken,
    &typeDefToken, szMethod,
    _countof(szMethod), &cchMethod,
    NULL, NULL, NULL, NULL, NULL);
    if (hr != S_OK)
    {
    return hr;
    }
    frame->szMethod = szMethod;

    ULONG cchClass;
    WCHAR szClass[MAX_LENGTH] = L"<CLR>";
    if (!IsNilToken(typeDefToken))
    {
    hr = metadata2->GetTypeDefProps(
    typeDefToken, szClass, _countof(szClass),
    &cchClass, 0, NULL);
    if (hr != S_OK)
    {
    return hr;
    }
    }
    frame->szClass = szClass;

    return S_OK;
    }

    And I suspend a thread before walk it's stack. Here is the suspended thread 's stack, maybe it will help?

    ntdll.dll!RtlpAllocateHeap+0x620
    ntdll.dll!RtlAllocateHeap+0x16c
    clr.dll!EEHeapAllocInProcessHeap+0x5f
    clrjit.dll+0x4d795
    clrjit.dll+0x7654e
    clrjit.dll+0x369e
    clrjit.dll+0x164d
    clrjit.dll+0x1a01e
    clr.dll!invokeCompileMethodHelper+0xa7
    clr.dll!invokeCompileMethod+0x63
    clr.dll!CallCompileMethodWithSEHWrapper+0x46
    clr.dll!UnsafeJitFunction+0x270
    clr.dll!MethodDesc::MakeJitWorker+0x1dd
    clr.dll!MethodDesc::DoPrestub+0x522
    clr.dll!PreStubWorker+0x1df
    clr.dll!ThePreStubAMD64+0x87
    [Managed to Unmanaged Transition]
    System.Core.dll!System.Linq.Expressions.Expression.Lambda+0x9c
    System.Core.dll!System.Linq.Expressions.Expression.Lambda+0x89
    System.Core.dll!System.Linq.Expressions.Expression.Lambda+0x99
    Microsoft.Web.Infrastructure.dll!Microsoft.Web.Infrastructure.DynamicValidationHelper.GranularValidationReflectionUtil.MakeFieldGetterFunc+0x141
    Microsoft.Web.Infrastructure.dll!Microsoft.Web.Infrastructure.DynamicValidationHelper.GranularValidationReflectionUtil.GetInstance+0x2b6
    Microsoft.Web.Infrastructure.dll!Microsoft.Web.Infrastructure.DynamicValidationHelper.GranularValidationReflectionUtil..cctor+0x1e
    [Unmanaged to Managed Transition]
    clr.dll!CallDescrWorker+0x84
    clr.dll!CallDescrWorkerWithHandler+0xa9
    clr.dll!DispatchCallDebuggerWrapper+0x74
    clr.dll!MethodTable::RunClassInitEx+0x1ff
    clr.dll!MethodTable::DoRunClassInitThrowing+0x55e
    clr.dll!MethodTable::CheckRunClassInitThrowing+0xe3
    clr.dll!JIT_GetSharedGCStaticBase_Helper+0x146
    [Managed to Unmanaged Transition]
    Microsoft.Web.Infrastructure.dll!CollectionReplacer..cctor+0x29
    [Unmanaged to Managed Transition]
    clr.dll!CallDescrWorker+0x84
    clr.dll!CallDescrWorkerWithHandler+0xa9
    clr.dll!DispatchCallDebuggerWrapper+0x74
    clr.dll!MethodTable::RunClassInitEx+0x1ff
    clr.dll!MethodTable::DoRunClassInitThrowing+0x55e
    clr.dll!MethodTable::CheckRunClassInitThrowing+0xe3
    clr.dll!JIT_GetSharedGCStaticBase_Helper+0x146
    [Managed to Unmanaged Transition]
    Microsoft.Web.Infrastructure.dll!CollectionReplacer.IsValidationEnabled+0x5b
    Microsoft.Web.Infrastructure.dll!Microsoft.Web.Infrastructure.DynamicValidationHelper.ValidationUtility.IsValidationEnabled+0xba
    System.Web.Mvc.dll!System.Web.Mvc.MvcHandler.ProcessRequestInit+0x5c
    System.Web.Mvc.dll!<>c__DisplayClass6.<BeginProcessRequest>b__2+0x105
    System.Web.Mvc.dll!<>c__DisplayClassb`1.<ProcessInApplicationTrust>b__a+0x47
    System.Web.Mvc.dll!System.Web.Mvc.SecurityUtil.<GetCallInAppTrustThunk>b__0+0x2f
    System.Web.Mvc.dll!System.Web.Mvc.SecurityUtil.ProcessInApplicationTrust+0x51
    System.Web.Mvc.dll!System.Web.Mvc.SecurityUtil.ProcessInApplicationTrust+0x147
    System.Web.Mvc.dll!System.Web.Mvc.MvcHandler.BeginProcessRequest+0x106
    System.Web.Mvc.dll!System.Web.Mvc.MvcHandler.BeginProcessRequest+0x8d
    System.Web.Mvc.dll!System.Web.Mvc.MvcHandler.System.Web.IHttpAsyncHandler.BeginProcessRequest+0x50
    System.Web.dll!CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute+0x301
    System.Web.dll!System.Web.HttpApplication.ExecuteStep+0x235
    System.Web.dll!PipelineStepManager.ResumeSteps+0x82a
    System.Web.dll!System.Web.HttpApplication.ResumeSteps+0x4a
    System.Web.dll!System.Web.HttpApplication.BeginProcessRequestNotification+0xd4
    System.Web.dll!System.Web.HttpRuntime.ProcessRequestNotificationPrivate+0x2f5
    System.Web.dll!System.Web.HttpRuntime.ProcessRequestNotification+0x73
    System.Web.dll!System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper+0x2c5
    System.Web.dll!System.Web.Hosting.PipelineRuntime.ProcessRequestNotification+0x5c
    [Unmanaged to Managed Transition]
    [Native Frame: IL Method without Metadata]
    clr.dll!UMThunkStubAMD64+0x77
    webengine4.dll!W3_MGD_HANDLER::ProcessNotification+0x79
    webengine4.dll!W3_MGD_HANDLER::DoWork+0x310
    webengine4.dll!RequestDoWork+0x42d
    webengine4.dll!CMgdEngHttpModule::OnExecuteRequestHandler+0x24
    iiscore.dll+0x2de7
    iiscore.dll+0x46a4
    iiscore.dll+0xa775
    iiscore.dll+0x5a03
    iiscore.dll+0xa81c
    webengine4.dll!W3_MGD_HANDLER::IndicateCompletion+0x59
    webengine4.dll!MgdIndicateCompletion+0x22
    clr.dll!DoNDirectCall__PatchGetThreadCall+0x7b
    [Native Frame: IL Method without Metadata]
    [Managed to Unmanaged Transition]
    System.Web.dll!System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper+0x3b0
    System.Web.dll!System.Web.Hosting.PipelineRuntime.ProcessRequestNotification+0x5c
    [Unmanaged to Managed Transition]
    [Native Frame: IL Method without Metadata]
    clr.dll!UM2MThunk_WrapperHelper+0x4b
    clr.dll!UM2MThunk_Wrapper+0x90
    [Managed to Unmanaged Transition]
    [AppDomain Transition]
    [Unmanaged to Managed Transition]
    clr.dll!Thread::DoADCallBack+0x127
    clr.dll!UM2MDoADCallBack+0x9e
    clr.dll!UMThunkStubAMD64+0x273
    webengine4.dll!W3_MGD_HANDLER::ProcessNotification+0x79
    webengine4.dll!ProcessNotificationCallback+0x43
    clr.dll!UnManagedPerAppDomainTPCount::DispatchWorkItem+0x181
    clr.dll!ThreadpoolMgr::NewWorkerThreadStart+0x2e5
    clr.dll!ThreadpoolMgr::WorkerThreadStart+0x3b
    clr.dll!Thread::intermediateThreadProc+0x7d
    kernel32.dll!BaseThreadInitThunk+0xd
    ntdll.dll!RtlUserThreadStart+0x1d

    ==================

    My sampler  thread seems blocking on ::GetModuleMetaData which new[] sth?


    • Edited by IMMark Friday, December 2, 2016 2:10 AM Update Symbols
    Thursday, December 1, 2016 7:59 AM
  • My guess would be that you suspended a thread that was in the process of allocating memory in the "process heap" (in the critical section), and then tried to allocate from the same heap, leading to a deadlock (cannot completed the allocation until the suspended thread is done with the critical section).

    Are you able to capture the FunctionID's in the callback and defer the metadata lookup until after resuming the thread?

    Friday, December 2, 2016 8:22 AM
  • 1. On the Profiler Stack Walking in the .NET Framework 2.0: Basics and Beyond 

    >> You can get this function information right away, during your stack walk, or alternatively save the funcId values and get the function information later, which reduces your impact on the running application. 

    This means it's bug for CLR? 

    2. I test many times, and found that my sampler thread will block on another call.

    Does it mean that I can not use any function that will trigger allocate heap in DoStackSnapshotCallback?

    My sampler thread stack:

    ntoskrnl.exe!KeWaitForMultipleObjects+0xc0a
    ntoskrnl.exe!KeAcquireSpinLockAtDpcLevel+0x712
    ntoskrnl.exe!KeWaitForMutexObject+0x19f
    ntoskrnl.exe!_misaligned_access+0xba0
    ntoskrnl.exe!_misaligned_access+0x183d
    ntoskrnl.exe!KeAcquireSpinLockAtDpcLevel+0x91d
    ntoskrnl.exe!KeWaitForMutexObject+0x19f
    ntoskrnl.exe!NtWaitForSingleObject+0xde
    ntoskrnl.exe!KeSynchronizeExecution+0x3a23
    ntdll.dll!NtWaitForSingleObject+0xa
    ntdll.dll!RtlpWaitOnCriticalSection+0xe8
    ntdll.dll!RtlEnterCriticalSection+0xd1
    !_lock+0x50
    !_heap_alloc_dbg_impl+0x32
    !_nh_malloc_dbg_impl+0x39
    !_nh_malloc_dbg+0x49
    !malloc+0x2a
    !operator new+0x13
    !std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> >+0x30
    !Sampler::DoStackSnapshotCallback+0x1a4
    !ProfilerStackWalkCallback+0xd4
    !Thread::MakeStackwalkerCallback+0x2f
    !Thread::StackWalkFramesEx+0x8d
    !Thread::StackWalkFrames+0xb1
    !ProfToEEInterfaceImpl::ProfilerStackWalkFramesWrapper+0x1c
    !ProfToEEInterfaceImpl::DoStackSnapshotHelper+0x6f
    !ProfToEEInterfaceImpl::DoStackSnapshot+0x305
    !Sampler::GetStackTrace+0xfd
    !Sampler::Loop+0x1dc
    !Sampler::ThreadProc+0x13e
    !BaseThreadInitThunk+0xd
    ntdll.dll!RtlUserThreadStart+0x1d

    In DoStackSnapshotCallback,I push back functionID to a std::vector<FUNCTIONID>.  It seems blocking again.

    And I suspend a thread before walk it's stack. Here is the suspended thread 's stack.

    !_free_dbg_nolock+0x50d
    !_free_dbg+0x26
    !operator delete+0xb5
    !FunctionInfo::GetClassFullName+0x636
    !FunctionInfo::GetMethodInfo+0x1e0
    !FunctionInfo::Parse+0xda
    !Profiler::JITCompilationStarted+0xb9
    !EEToProfInterfaceImpl::JITCompilationStarted+0x6e
    ! ?? ::FNODOBFM::`string'+0xb3f31
    !MethodDesc::DoPrestub+0x522
    !PreStubWorker+0x1df
    !ThePreStubAMD64+0x87
    [Managed to Unmanaged Transition]
    System.Web.Mvc.dll!<>c__DisplayClass1e.<InvokeActionResultWithFilters>b__1b+0x42
    System.Web.Mvc.dll!System.Web.Mvc.ControllerActionInvoker.InvokeActionResultWithFilters+0x1fd
    System.Web.Mvc.dll!System.Web.Mvc.ControllerActionInvoker.InvokeAction+0x520
    System.Web.Mvc.dll!System.Web.Mvc.Controller.ExecuteCore+0xb2
    System.Web.Mvc.dll!System.Web.Mvc.ControllerBase.Execute+0x12b
    System.Web.Mvc.dll!System.Web.Mvc.ControllerBase.System.Web.Mvc.IController.Execute+0x3c
    System.Web.Mvc.dll!<>c__DisplayClassb.<BeginProcessRequest>b__5+0x6e
    System.Web.Mvc.dll!<>c__DisplayClass1.<MakeVoidDelegate>b__0+0x42
    System.Web.Mvc.dll!<>c__DisplayClass8`1.<BeginSynchronous>b__7+0x42
    System.Web.Mvc.dll!WrappedAsyncResult`1.End+0xcf
    System.Web.Mvc.dll!System.Web.Mvc.Async.AsyncResultWrapper.End+0x49
    System.Web.Mvc.dll!System.Web.Mvc.Async.AsyncResultWrapper.End+0x32
    System.Web.Mvc.dll!<>c__DisplayClasse.<EndProcessRequest>b__d+0x50
    System.Web.Mvc.dll!System.Web.Mvc.SecurityUtil.<GetCallInAppTrustThunk>b__0+0x2f
    System.Web.Mvc.dll!System.Web.Mvc.SecurityUtil.ProcessInApplicationTrust+0x51
    System.Web.Mvc.dll!System.Web.Mvc.MvcHandler.EndProcessRequest+0xad
    System.Web.Mvc.dll!System.Web.Mvc.MvcHandler.System.Web.IHttpAsyncHandler.EndProcessRequest+0x3b
    System.Web.dll!CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute+0x39c
    System.Web.dll!System.Web.HttpApplication.ExecuteStep+0x235
    System.Web.dll!PipelineStepManager.ResumeSteps+0x82a
    System.Web.dll!System.Web.HttpApplication.ResumeSteps+0x4a
    System.Web.dll!System.Web.HttpApplication.BeginProcessRequestNotification+0xd4
    System.Web.dll!System.Web.HttpRuntime.ProcessRequestNotificationPrivate+0x2f5
    System.Web.dll!System.Web.HttpRuntime.ProcessRequestNotification+0x73
    System.Web.dll!System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper+0x2c5
    System.Web.dll!System.Web.Hosting.PipelineRuntime.ProcessRequestNotification+0x5c
    [Unmanaged to Managed Transition]
    [Native Frame: IL Method without Metadata]
    !UMThunkStubAMD64+0x77
    !W3_MGD_HANDLER::ProcessNotification+0x79
    !W3_MGD_HANDLER::DoWork+0x310
    !RequestDoWork+0x42d
    !CMgdEngHttpModule::OnExecuteRequestHandler+0x24
    !NOTIFICATION_CONTEXT::RequestDoWork+0x233
    !NOTIFICATION_CONTEXT::CallModulesInternal+0x174
    !NOTIFICATION_CONTEXT::CallModules+0x25
    !W3_CONTEXT::DoWork+0x34d
    !W3_CONTEXT::IndicateCompletion+0x8c
    !W3_MGD_HANDLER::IndicateCompletion+0x59
    !MgdIndicateCompletion+0x22
    !DoNDirectCall__PatchGetThreadCall+0x7b
    [Native Frame: IL Method without Metadata]
    [Managed to Unmanaged Transition]
    System.Web.dll!System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper+0x3b0
    System.Web.dll!System.Web.Hosting.PipelineRuntime.ProcessRequestNotification+0x5c
    [Unmanaged to Managed Transition]
    [Native Frame: IL Method without Metadata]
    !UM2MThunk_WrapperHelper+0x4b
    !UM2MThunk_Wrapper+0x90
    [Managed to Unmanaged Transition]
    [AppDomain Transition]
    [Unmanaged to Managed Transition]
    !Thread::DoADCallBack+0x127
    !UM2MDoADCallBack+0x9e
    !UMThunkStubAMD64+0x273
    !W3_MGD_HANDLER::ProcessNotification+0x79
    !ProcessNotificationCallback+0x43
    !UnManagedPerAppDomainTPCount::DispatchWorkItem+0x181
    !ThreadpoolMgr::NewWorkerThreadStart+0x2e5
    !ThreadpoolMgr::WorkerThreadStart+0x3b
    !Thread::intermediateThreadProc+0x7d
    !BaseThreadInitThunk+0xd
    ntdll.dll!RtlUserThreadStart+0x1d

    Thanks a lot.



    • Edited by IMMark Friday, December 2, 2016 9:00 AM
    Friday, December 2, 2016 8:58 AM
  • 1. On the Profiler Stack Walking in the .NET Framework 2.0: Basics and Beyond 

    >> You can get this function information right away, during your stack walk, or alternatively save the funcId values and get the function information later, which reduces your impact on the running application. 

    This means it's bug for CLR? 

    I can't say for certain if there is a CLR bug here or not, but I wouldn't expect so. This is just a natural consequence of suspending a thread holding a lock you want.

    2. I test many times, and found that my sampler thread will block on another call.

    Does it mean that I can not use any function that will trigger allocate heap in DoStackSnapshotCallback?

    No, there can be more than one heap and if you allocate from a heap that no other thread uses, then you won't get a deadlock ... or at least not from the allocation.

    Ideally, if the suspended thread held a lock you wanted, then you would let it run just until it released the lock. Unfortunately, I'm not aware of any way to actually achieve this, so you will just have to make sure that your sampling thread doesn't need anything that the suspended thread *might* have locked.

    • Marked as answer by IMMark Saturday, December 3, 2016 4:33 PM
    Friday, December 2, 2016 1:15 PM