Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Duplicate ManagedToUnmanagedTransition and UnmanagedToManagedTransition calls in profiler #69717

Closed
ww898 opened this issue May 24, 2022 · 3 comments · Fixed by #69761
Closed

Duplicate ManagedToUnmanagedTransition and UnmanagedToManagedTransition calls in profiler #69717

ww898 opened this issue May 24, 2022 · 3 comments · Fixed by #69761
Labels
area-Diagnostics-coreclr
Milestone
7.0.0

Comments

@ww898
Copy link
Contributor

ww898 commented May 24, 2022 •
edited
Loading

.NET 6.0. x64, Windows 21H2 x64 19044.1706

My question is about duplicate manaded-unmanaged transitions in profiler. Interop+User32+WNDPROC.Invoke() and Interop+User32+WndProc.Invoke() methods always reported twice:

00008858 1 0000024764AFB010 PTProf::RdtscFastEnter fuid=0060122E
00008858 1 0000024764AFB010 PTProf::ManagedToUnmanagedTransition fid=00007FF8F64E5F20 fuid=006003F8 reason=call fname='RegisterWindowMessageW' cname='Interop+User32'
00008858 1 0000024764AFB010 PTProf::UnmanagedToManagedTransition fid=00007FF8F64E5F20 fuid=006003F8 reason=return fname='RegisterWindowMessageW' cname='Interop+User32'
00008858 1 0000024764AFB010 PTProf::RdtscFastLeave fuid=0060122E
00008858 1 0000024764AFB010 PTProf::FunctionIdMapper fid=00007FF8F65F0CF8 res=ok fuid=006000F9
00008858 1 0000024764AFB010 PTProf::RdtscFastEnter fuid=006000F9
00008858 1 0000024764AFB010 PTProf::RdtscFastLeave fuid=006000F9
00008858 1 0000024764AFB010 PTProf::RdtscFastLeave fuid=00402F45
00008858 1 0000024764AFB010 PTProf::RdtscFastLeave fuid=00405B2C
00008858 1 0000024764AFB010 PTProf::ManagedToUnmanagedTransition fid=00007FF8F654BB78 fuid=00601231 reason=return fname='Invoke' cname='Interop+User32+WNDPROC'
00008858 1 0000024764AFB010 PTProf::ManagedToUnmanagedTransition fid=00007FF8F654BB78 fuid=00601231 reason=return fname='Invoke' cname='Interop+User32+WNDPROC'
00008858 1 0000024764AFB010 PTProf::UnmanagedToManagedTransition fid=00007FF8F654BB78 fuid=00601231 reason=call fname='Invoke' cname='Interop+User32+WNDPROC'
00008858 1 0000024764AFB010 PTProf::UnmanagedToManagedTransition fid=00007FF8F654BB78 fuid=00601231 reason=call fname='Invoke' cname='Interop+User32+WNDPROC'
00008858 1 0000024764AFB010 PTProf::RdtscFastEnter fuid=00402F45

00005F54 1 000002476DEE6B50 PTProf::RdtscFastLeave fuid=00104C7A
00005F54 1 000002476DEE6B50 PTProf::ManagedToUnmanagedTransition fid=00007FF8F662DD00 fuid=01600089 reason=call fname='DefWindowProcW' cname='Interop+User32'
00005F54 1 000002476DEE6B50 PTProf::UnmanagedToManagedTransition fid=00007FF8F662DD00 fuid=01600089 reason=return fname='DefWindowProcW' cname='Interop+User32'
00005F54 1 000002476DEE6B50 PTProf::RdtscFastLeave fuid=01600071
00005F54 1 000002476DEE6B50 PTProf::ManagedToUnmanagedTransition fid=00007FF8F662F160 fuid=016000B2 reason=return fname='Invoke' cname='Interop+User32+WndProc'
00005F54 1 000002476DEE6B50 PTProf::ManagedToUnmanagedTransition fid=00007FF8F662F160 fuid=016000B2 reason=return fname='Invoke' cname='Interop+User32+WndProc'
00005F54 1 000002476DEE6B50 PTProf::UnmanagedToManagedTransition fid=00007FF8F662F160 fuid=016000B2 reason=call fname='Invoke' cname='Interop+User32+WndProc'
00005F54 1 000002476DEE6B50 PTProf::UnmanagedToManagedTransition fid=00007FF8F662F160 fuid=016000B2 reason=call fname='Invoke' cname='Interop+User32+WndProc'
00005F54 1 000002476DEE6B50 PTProf::RdtscFastEnter fuid=01600071
00005F54 1 000002476DEE6B50 PTProf::ManagedToUnmanagedTransition fid=00007FF8F662DD00 fuid=01600089 reason=call fname='DefWindowProcW' cname='Interop+User32'
00005F54 1 000002476DEE6B50 PTProf::UnmanagedToManagedTransition fid=00007FF8F662DD00 fuid=01600089 reason=return fname='DefWindowProcW' cname='Interop+User32'
00005F54 1 000002476DEE6B50 PTProf::RdtscFastLeave fuid=01600071

Here two callstacks for duplicated transitions:

№1:

0:000> k
 # Child-SP          RetAddr               Call Site
00 00000068`d5b7d0e0 00007ff9`3fff4156     JetBrains_Profiler_Core!`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2>::operator()+0x188 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\profilers\performance\tracing\performance_tracing_profiler.transition.cpp @ 93] 
01 00000068`d5b7d1d0 00007ff9`3fff411b     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2>,`jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2> >'::`2'::<lambda_1> >+0x26 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 21] 
02 00000068`d5b7d200 00007ff9`3f88bb33     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2> >+0x2b [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 34] 
03 00000068`d5b7d240 00007ff9`43f62899     JetBrains_Profiler_Core!jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition+0x2f3 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\profilers\performance\tracing\performance_tracing_profiler.transition.cpp @ 101] 
04 00000068`d5b7d3b0 00007ff9`43fa1073     coreclr!EEToProfInterfaceImpl::ManagedToUnmanagedTransition+0x79 [D:\a\_work\1\s\src\coreclr\vm\eetoprofinterfaceimpl.cpp @ 4421] 
05 (Inline Function) --------`--------     coreclr!ManagedToUnmanagedTransitionHelper+0xb [D:\a\_work\1\s\src\coreclr\inc\profilepriv.inl @ 1004] 
06 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoProfilerCallbackHelper+0x22 [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 283] 
07 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoOneProfilerIteration+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 199] 
08 (Inline Function) --------`--------     coreclr!ProfControlBlock::IterateProfilers+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 207] 
09 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoProfilerCallback+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 295] 
0a (Inline Function) --------`--------     coreclr!ProfControlBlock::ManagedToUnmanagedTransition+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.inl @ 1011] 
0b 00000068`d5b7d3f0 00007ff9`43fab759     coreclr!ProfilerManagedToUnmanagedTransitionMD+0x8f [D:\a\_work\1\s\src\coreclr\vm\proftoeeinterfaceimpl.cpp @ 10513] 
0c 00000068`d5b7d440 00007ff8`e452fbdd     coreclr!StubHelpers::ProfilerEndTransitionCallback+0x119 [D:\a\_work\1\s\src\coreclr\vm\stubhelpers.cpp @ 704] 
0d 00000068`d5b7d5d0 00007ff9`aaeee858     0x00007ff8`e452fbdd
0e 00000068`d5b7d660 00007ff9`aaeee3dc     USER32!UserCallWinProcCheckWow+0x2f8
0f 00000068`d5b7d7f0 00007ff9`aaf03d62     USER32!DispatchClientMessage+0x9c
10 00000068`d5b7d850 00007ff9`acf30b74     USER32!_fnINOUTLPPOINT5+0x32
11 00000068`d5b7d8b0 00007ff9`aac51ec4     ntdll!KiUserCallbackDispatcherContinue
12 00000068`d5b7d958 00007ff9`aaee7d8b     win32u!NtUserCreateWindowEx+0x14
13 00000068`d5b7d960 00007ff9`aaee7958     USER32!VerNtUserCreateWindowEx+0x20f
14 00000068`d5b7dcf0 00007ff9`aaee77a2     USER32!CreateWindowInternal+0x1a4
15 00000068`d5b7de50 00007ff8`e452f837     USER32!CreateWindowExW+0x82
16 00000068`d5b7dee0 00007ff8`e452f625     0x00007ff8`e452f837
17 00000068`d5b7e080 00007ff8`e452abdd     0x00007ff8`e452f625
18 00000068`d5b7e120 00007ff8`e452a1bb     0x00007ff8`e452abdd
19 00000068`d5b7e280 00007ff8`e4527428     0x00007ff8`e452a1bb
1a 00000068`d5b7e370 00007ff8`e452730e     0x00007ff8`e4527428
1b 00000068`d5b7e3a0 00007ff8`e4525fd9     0x00007ff8`e452730e
1c 00000068`d5b7e400 00007ff8`e4524dc3     0x00007ff8`e4525fd9
1d 00000068`d5b7e440 00007ff8`e4313d5b     0x00007ff8`e4524dc3
1e 00000068`d5b7e4a0 00007ff8`e4311cc3     0x00007ff8`e4313d5b
1f 00000068`d5b7e5e0 00007ff8`e4311c27     0x00007ff8`e4311cc3
20 00000068`d5b7e610 00007ff8`e4311a3b     0x00007ff8`e4311c27
21 00000068`d5b7e640 00007ff8`e431179a     0x00007ff8`e4311a3b
22 00000068`d5b7e680 00007ff8`e4311619     0x00007ff8`e431179a
23 00000068`d5b7e6f0 00007ff8`e43034f0     0x00007ff8`e4311619
24 00000068`d5b7e720 00007ff9`43e5a863     0x00007ff8`e43034f0
25 00000068`d5b7e760 00007ff9`43d5ff96     coreclr!CallDescrWorkerInternal+0x83
26 00000068`d5b7e7a0 00007ff9`43dd1107     coreclr!MethodDescCallSite::CallTargetWorker+0x176 [D:\a\_work\1\s\src\coreclr\vm\callhelpers.cpp @ 551] 
27 (Inline Function) --------`--------     coreclr!MethodDescCallSite::Call+0xb [D:\a\_work\1\s\src\coreclr\vm\callhelpers.h @ 458] 
28 00000068`d5b7e8d0 00007ff9`43dd0f86     coreclr!RunMainInternal+0x11f [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1483] 
29 00000068`d5b7ea00 00007ff9`43dd0e35     coreclr!RunMain+0xd2 [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1554] 
2a 00000068`d5b7eab0 00007ff9`43dd0bf6     coreclr!Assembly::ExecuteMainMethod+0x1c9 [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1672] 
2b 00000068`d5b7ee40 00007ff9`43e05352     coreclr!CorHost2::ExecuteAssembly+0x1c6 [D:\a\_work\1\s\src\coreclr\vm\corhost.cpp @ 384] 
2c 00000068`d5b7efb0 00007ff9`7b0d96db     coreclr!coreclr_execute_assembly+0xe2 [D:\a\_work\1\s\src\coreclr\dlls\mscoree\unixinterface.cpp @ 446] 
2d (Inline Function) --------`--------     hostpolicy!coreclr_t::execute_assembly+0x2a [D:\a\_work\1\s\src\native\corehost\hostpolicy\coreclr.cpp @ 89] 
2e 00000068`d5b7f050 00007ff9`7b0d9a0c     hostpolicy!run_app_for_context+0x56b [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 255] 
2f 00000068`d5b7f1f0 00007ff9`7b0da3a7     hostpolicy!run_app+0x3c [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 284] 
30 00000068`d5b7f230 00007ff9`7d35b539     hostpolicy!corehost_main+0x107 [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 430] 
31 00000068`d5b7f3e0 00007ff9`7d35e506     hostfxr!execute_app+0x2e9 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 146] 
32 00000068`d5b7f4e0 00007ff9`7d360821     hostfxr!`anonymous namespace'::read_config_and_execute+0xa6 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 533] 
33 00000068`d5b7f5e0 00007ff9`7d35eb62     hostfxr!fx_muxer_t::handle_exec_host_command+0x161 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 1018] 
34 00000068`d5b7f690 00007ff9`7d3582ab     hostfxr!fx_muxer_t::execute+0x482 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 579] 
35 00000068`d5b7f7d0 00007ff6`059d24b8     hostfxr!hostfxr_main_startupinfo+0xab [D:\a\_work\1\s\src\native\corehost\fxr\hostfxr.cpp @ 61] 
36 00000068`d5b7f8d0 00007ff6`059d282b     WinFormsApp1_exe!exe_start+0x8d8 [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 235] 
37 00000068`d5b7faa0 00007ff6`059d3cd8     WinFormsApp1_exe!wmain+0xab [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 304] 
38 (Inline Function) --------`--------     WinFormsApp1_exe!invoke_main+0x22 [d:\a01\_work\12\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 90] 
39 00000068`d5b7fad0 00007ff9`abf87034     WinFormsApp1_exe!__scrt_common_main_seh+0x10c [d:\a01\_work\12\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288] 
3a 00000068`d5b7fb10 00007ff9`acee2651     KERNEL32!BaseThreadInitThunk+0x14
3b 00000068`d5b7fb40 00000000`00000000     ntdll!RtlUserThreadStart+0x21
0:000> !clrstack
OS Thread Id: 0x9990 (0)
        Child SP               IP Call Site
00000068D5B7D4B8 00007ff93f88cbc8 [HelperMethodFrame: 00000068d5b7d4b8] System.StubHelpers.StubHelpers.ProfilerEndTransitionCallback(IntPtr, IntPtr)
00000068D5B7D5D0 00007ff8e452fbdd ILStubClass.IL_STUB_ReversePInvoke(Int64, UInt32, Int64, Int64)
00000068D5B7DF88 00007ff9aaeee858 [InlinedCallFrame: 00000068d5b7df88] Interop+User32.CreateWindowExW(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7DF88 00007ff8e452f837 [InlinedCallFrame: 00000068d5b7df88] Interop+User32.CreateWindowExW(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7DF10 00007ff8e452f837 ILStubClass.IL_STUB_PInvoke(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7E080 00007ff8e452f625 Interop+User32.CreateWindowExW(WS_EX, System.String, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object) [/_/src/System.Windows.Forms.Primitives/src/Interop/User32/Interop.CreateWindowExW.cs @ 42]
00000068D5B7E120 00007ff8e452abdd System.Windows.Forms.NativeWindow.CreateHandle(System.Windows.Forms.CreateParams) [/_/src/System.Windows.Forms/src/System/Windows/Forms/NativeWindow.cs @ 459]
00000068D5B7E280 00007ff8e452a1bb System.Windows.Forms.Control.CreateHandle() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 4967]
00000068D5B7E370 00007ff8e4527428 System.Windows.Forms.Application+MarshalingControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Application.MarshallingControl.cs @ 26]
00000068D5B7E3A0 00007ff8e452730e System.Windows.Forms.Application+ThreadContext.get_MarshalingControl() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Application.ThreadContext.cs @ 374]
00000068D5B7E400 00007ff8e4525fd9 System.Windows.Forms.WindowsFormsSynchronizationContext..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/WindowsFormsSynchronizationContext.cs @ 33]
00000068D5B7E440 00007ff8e4524dc3 System.Windows.Forms.WindowsFormsSynchronizationContext.InstallIfNeeded() [/_/src/System.Windows.Forms/src/System/Windows/Forms/WindowsFormsSynchronizationContext.cs @ 145]
00000068D5B7E4A0 00007ff8e4313d5b System.Windows.Forms.Control..ctor(Boolean) [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 446]
00000068D5B7E5E0 00007ff8e4311cc3 System.Windows.Forms.Control..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 370]
00000068D5B7E610 00007ff8e4311c27 System.Windows.Forms.ScrollableControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/ScrollableControl.cs @ 78]
00000068D5B7E640 00007ff8e4311a3b System.Windows.Forms.ContainerControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/ContainerControl.cs @ 94]
00000068D5B7E680 00007ff8e431179a System.Windows.Forms.Form..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Form.cs @ 163]
00000068D5B7E6F0 00007ff8e4311619 WinFormsApp1.Form1..ctor() [D:\Work\DTRC-28226 Repro\WinFormsApp1\WinFormsApp1\Form1.cs @ 7]
00000068D5B7E720 00007ff8e43034f0 WinFormsApp1.Program.Main() [D:\Work\DTRC-28226 Repro\WinFormsApp1\WinFormsApp1\Program.cs @ 14]

№2

0:000> k
 # Child-SP          RetAddr               Call Site
00 00000068`d5b7d240 00007ff9`3fff4156     JetBrains_Profiler_Core!`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2>::operator()+0x188 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\profilers\performance\tracing\performance_tracing_profiler.transition.cpp @ 93] 
01 00000068`d5b7d330 00007ff9`3fff411b     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2>,`jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2> >'::`2'::<lambda_1> >+0x26 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 21] 
02 00000068`d5b7d360 00007ff9`3f88bb33     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2> >+0x2b [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 34] 
03 00000068`d5b7d3a0 00007ff9`43f62899     JetBrains_Profiler_Core!jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition+0x2f3 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\profilers\performance\tracing\performance_tracing_profiler.transition.cpp @ 101] 
04 00000068`d5b7d510 00007ff9`43fa1073     coreclr!EEToProfInterfaceImpl::ManagedToUnmanagedTransition+0x79 [D:\a\_work\1\s\src\coreclr\vm\eetoprofinterfaceimpl.cpp @ 4421] 
05 (Inline Function) --------`--------     coreclr!ManagedToUnmanagedTransitionHelper+0xb [D:\a\_work\1\s\src\coreclr\inc\profilepriv.inl @ 1004] 
06 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoProfilerCallbackHelper+0x22 [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 283] 
07 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoOneProfilerIteration+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 199] 
08 (Inline Function) --------`--------     coreclr!ProfControlBlock::IterateProfilers+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 207] 
09 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoProfilerCallback+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 295] 
0a (Inline Function) --------`--------     coreclr!ProfControlBlock::ManagedToUnmanagedTransition+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.inl @ 1011] 
0b 00000068`d5b7d550 00007ff9`43e57711     coreclr!ProfilerManagedToUnmanagedTransitionMD+0x8f [D:\a\_work\1\s\src\coreclr\vm\proftoeeinterfaceimpl.cpp @ 10513] 
0c 00000068`d5b7d5a0 00007ff8`e452fbe7     coreclr!JIT_ReversePInvokeExitTrackTransitions+0x31 [D:\a\_work\1\s\src\coreclr\vm\jithelpers.cpp @ 5579] 
0d 00000068`d5b7d5d0 00007ff9`aaeee858     0x00007ff8`e452fbe7
0e 00000068`d5b7d660 00007ff9`aaeee3dc     USER32!UserCallWinProcCheckWow+0x2f8
0f 00000068`d5b7d7f0 00007ff9`aaf03d62     USER32!DispatchClientMessage+0x9c
10 00000068`d5b7d850 00007ff9`acf30b74     USER32!_fnINOUTLPPOINT5+0x32
11 00000068`d5b7d8b0 00007ff9`aac51ec4     ntdll!KiUserCallbackDispatcherContinue
12 00000068`d5b7d958 00007ff9`aaee7d8b     win32u!NtUserCreateWindowEx+0x14
13 00000068`d5b7d960 00007ff9`aaee7958     USER32!VerNtUserCreateWindowEx+0x20f
14 00000068`d5b7dcf0 00007ff9`aaee77a2     USER32!CreateWindowInternal+0x1a4
15 00000068`d5b7de50 00007ff8`e452f837     USER32!CreateWindowExW+0x82
16 00000068`d5b7dee0 00007ff8`e452f625     0x00007ff8`e452f837
17 00000068`d5b7e080 00007ff8`e452abdd     0x00007ff8`e452f625
18 00000068`d5b7e120 00007ff8`e452a1bb     0x00007ff8`e452abdd
19 00000068`d5b7e280 00007ff8`e4527428     0x00007ff8`e452a1bb
1a 00000068`d5b7e370 00007ff8`e452730e     0x00007ff8`e4527428
1b 00000068`d5b7e3a0 00007ff8`e4525fd9     0x00007ff8`e452730e
1c 00000068`d5b7e400 00007ff8`e4524dc3     0x00007ff8`e4525fd9
1d 00000068`d5b7e440 00007ff8`e4313d5b     0x00007ff8`e4524dc3
1e 00000068`d5b7e4a0 00007ff8`e4311cc3     0x00007ff8`e4313d5b
1f 00000068`d5b7e5e0 00007ff8`e4311c27     0x00007ff8`e4311cc3
20 00000068`d5b7e610 00007ff8`e4311a3b     0x00007ff8`e4311c27
21 00000068`d5b7e640 00007ff8`e431179a     0x00007ff8`e4311a3b
22 00000068`d5b7e680 00007ff8`e4311619     0x00007ff8`e431179a
23 00000068`d5b7e6f0 00007ff8`e43034f0     0x00007ff8`e4311619
24 00000068`d5b7e720 00007ff9`43e5a863     0x00007ff8`e43034f0
25 00000068`d5b7e760 00007ff9`43d5ff96     coreclr!CallDescrWorkerInternal+0x83
26 00000068`d5b7e7a0 00007ff9`43dd1107     coreclr!MethodDescCallSite::CallTargetWorker+0x176 [D:\a\_work\1\s\src\coreclr\vm\callhelpers.cpp @ 551] 
27 (Inline Function) --------`--------     coreclr!MethodDescCallSite::Call+0xb [D:\a\_work\1\s\src\coreclr\vm\callhelpers.h @ 458] 
28 00000068`d5b7e8d0 00007ff9`43dd0f86     coreclr!RunMainInternal+0x11f [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1483] 
29 00000068`d5b7ea00 00007ff9`43dd0e35     coreclr!RunMain+0xd2 [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1554] 
2a 00000068`d5b7eab0 00007ff9`43dd0bf6     coreclr!Assembly::ExecuteMainMethod+0x1c9 [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1672] 
2b 00000068`d5b7ee40 00007ff9`43e05352     coreclr!CorHost2::ExecuteAssembly+0x1c6 [D:\a\_work\1\s\src\coreclr\vm\corhost.cpp @ 384] 
2c 00000068`d5b7efb0 00007ff9`7b0d96db     coreclr!coreclr_execute_assembly+0xe2 [D:\a\_work\1\s\src\coreclr\dlls\mscoree\unixinterface.cpp @ 446] 
2d (Inline Function) --------`--------     hostpolicy!coreclr_t::execute_assembly+0x2a [D:\a\_work\1\s\src\native\corehost\hostpolicy\coreclr.cpp @ 89] 
2e 00000068`d5b7f050 00007ff9`7b0d9a0c     hostpolicy!run_app_for_context+0x56b [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 255] 
2f 00000068`d5b7f1f0 00007ff9`7b0da3a7     hostpolicy!run_app+0x3c [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 284] 
30 00000068`d5b7f230 00007ff9`7d35b539     hostpolicy!corehost_main+0x107 [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 430] 
31 00000068`d5b7f3e0 00007ff9`7d35e506     hostfxr!execute_app+0x2e9 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 146] 
32 00000068`d5b7f4e0 00007ff9`7d360821     hostfxr!`anonymous namespace'::read_config_and_execute+0xa6 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 533] 
33 00000068`d5b7f5e0 00007ff9`7d35eb62     hostfxr!fx_muxer_t::handle_exec_host_command+0x161 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 1018] 
34 00000068`d5b7f690 00007ff9`7d3582ab     hostfxr!fx_muxer_t::execute+0x482 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 579] 
35 00000068`d5b7f7d0 00007ff6`059d24b8     hostfxr!hostfxr_main_startupinfo+0xab [D:\a\_work\1\s\src\native\corehost\fxr\hostfxr.cpp @ 61] 
36 00000068`d5b7f8d0 00007ff6`059d282b     WinFormsApp1_exe!exe_start+0x8d8 [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 235] 
37 00000068`d5b7faa0 00007ff6`059d3cd8     WinFormsApp1_exe!wmain+0xab [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 304] 
38 (Inline Function) --------`--------     WinFormsApp1_exe!invoke_main+0x22 [d:\a01\_work\12\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 90] 
39 00000068`d5b7fad0 00007ff9`abf87034     WinFormsApp1_exe!__scrt_common_main_seh+0x10c [d:\a01\_work\12\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288] 
3a 00000068`d5b7fb10 00007ff9`acee2651     KERNEL32!BaseThreadInitThunk+0x14
3b 00000068`d5b7fb40 00000000`00000000     ntdll!RtlUserThreadStart+0x21
0:000> !clrstack
OS Thread Id: 0x9990 (0)
        Child SP               IP Call Site
00000068D5B7DF88 00007ff93f88cbc8 [InlinedCallFrame: 00000068d5b7df88] Interop+User32.CreateWindowExW(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7DF88 00007ff8e452f837 [InlinedCallFrame: 00000068d5b7df88] Interop+User32.CreateWindowExW(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7DF10 00007ff8e452f837 ILStubClass.IL_STUB_PInvoke(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7E080 00007ff8e452f625 Interop+User32.CreateWindowExW(WS_EX, System.String, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object) [/_/src/System.Windows.Forms.Primitives/src/Interop/User32/Interop.CreateWindowExW.cs @ 42]
00000068D5B7E120 00007ff8e452abdd System.Windows.Forms.NativeWindow.CreateHandle(System.Windows.Forms.CreateParams) [/_/src/System.Windows.Forms/src/System/Windows/Forms/NativeWindow.cs @ 459]
00000068D5B7E280 00007ff8e452a1bb System.Windows.Forms.Control.CreateHandle() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 4967]
00000068D5B7E370 00007ff8e4527428 System.Windows.Forms.Application+MarshalingControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Application.MarshallingControl.cs @ 26]
00000068D5B7E3A0 00007ff8e452730e System.Windows.Forms.Application+ThreadContext.get_MarshalingControl() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Application.ThreadContext.cs @ 374]
00000068D5B7E400 00007ff8e4525fd9 System.Windows.Forms.WindowsFormsSynchronizationContext..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/WindowsFormsSynchronizationContext.cs @ 33]
00000068D5B7E440 00007ff8e4524dc3 System.Windows.Forms.WindowsFormsSynchronizationContext.InstallIfNeeded() [/_/src/System.Windows.Forms/src/System/Windows/Forms/WindowsFormsSynchronizationContext.cs @ 145]
00000068D5B7E4A0 00007ff8e4313d5b System.Windows.Forms.Control..ctor(Boolean) [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 446]
00000068D5B7E5E0 00007ff8e4311cc3 System.Windows.Forms.Control..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 370]
00000068D5B7E610 00007ff8e4311c27 System.Windows.Forms.ScrollableControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/ScrollableControl.cs @ 78]
00000068D5B7E640 00007ff8e4311a3b System.Windows.Forms.ContainerControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/ContainerControl.cs @ 94]
00000068D5B7E680 00007ff8e431179a System.Windows.Forms.Form..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Form.cs @ 163]
00000068D5B7E6F0 00007ff8e4311619 WinFormsApp1.Form1..ctor() [D:\Work\DTRC-28226 Repro\WinFormsApp1\WinFormsApp1\Form1.cs @ 7]
00000068D5B7E720 00007ff8e43034f0 WinFormsApp1.Program.Main() [D:\Work\DTRC-28226 Repro\WinFormsApp1\WinFormsApp1\Program.cs @ 14]

The real difference between two sequential callstacks here: coreclr!StubHelpers::ProfilerEndTransitionCallback and coreclr!JIT_ReversePInvokeExitTrackTransitions.
@dotnet-issue-labeler
Copy link

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

@ghost ghost added the untriaged New issue has not been triaged by the area owner label May 24, 2022
@ghost
Copy link

ghost commented May 24, 2022

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

Issue Details

.NET 6.0. x64, Windows 21H2 x64 19044.1706

My question is about duplicate manaded-unmanaged transitions in profiler. Interop+User32+WNDPROC.Invoke() and Interop+User32+WndProc.Invoke() methods always reported twice:

00008858 1 0000024764AFB010 PTProf::RdtscFastEnter fuid=0060122E
00008858 1 0000024764AFB010 PTProf::ManagedToUnmanagedTransition fid=00007FF8F64E5F20 fuid=006003F8 reason=call fname='RegisterWindowMessageW' cname='Interop+User32'
00008858 1 0000024764AFB010 PTProf::UnmanagedToManagedTransition fid=00007FF8F64E5F20 fuid=006003F8 reason=return fname='RegisterWindowMessageW' cname='Interop+User32'
00008858 1 0000024764AFB010 PTProf::RdtscFastLeave fuid=0060122E
00008858 1 0000024764AFB010 PTProf::FunctionIdMapper fid=00007FF8F65F0CF8 res=ok fuid=006000F9
00008858 1 0000024764AFB010 PTProf::RdtscFastEnter fuid=006000F9
00008858 1 0000024764AFB010 PTProf::RdtscFastLeave fuid=006000F9
00008858 1 0000024764AFB010 PTProf::RdtscFastLeave fuid=00402F45
00008858 1 0000024764AFB010 PTProf::RdtscFastLeave fuid=00405B2C
00008858 1 0000024764AFB010 PTProf::ManagedToUnmanagedTransition fid=00007FF8F654BB78 fuid=00601231 reason=return fname='Invoke' cname='Interop+User32+WNDPROC'
00008858 1 0000024764AFB010 PTProf::ManagedToUnmanagedTransition fid=00007FF8F654BB78 fuid=00601231 reason=return fname='Invoke' cname='Interop+User32+WNDPROC'
00008858 1 0000024764AFB010 PTProf::UnmanagedToManagedTransition fid=00007FF8F654BB78 fuid=00601231 reason=call fname='Invoke' cname='Interop+User32+WNDPROC'
00008858 1 0000024764AFB010 PTProf::UnmanagedToManagedTransition fid=00007FF8F654BB78 fuid=00601231 reason=call fname='Invoke' cname='Interop+User32+WNDPROC'
00008858 1 0000024764AFB010 PTProf::RdtscFastEnter fuid=00402F45

00005F54 1 000002476DEE6B50 PTProf::RdtscFastLeave fuid=00104C7A
00005F54 1 000002476DEE6B50 PTProf::ManagedToUnmanagedTransition fid=00007FF8F662DD00 fuid=01600089 reason=call fname='DefWindowProcW' cname='Interop+User32'
00005F54 1 000002476DEE6B50 PTProf::UnmanagedToManagedTransition fid=00007FF8F662DD00 fuid=01600089 reason=return fname='DefWindowProcW' cname='Interop+User32'
00005F54 1 000002476DEE6B50 PTProf::RdtscFastLeave fuid=01600071
00005F54 1 000002476DEE6B50 PTProf::ManagedToUnmanagedTransition fid=00007FF8F662F160 fuid=016000B2 reason=return fname='Invoke' cname='Interop+User32+WndProc'
00005F54 1 000002476DEE6B50 PTProf::ManagedToUnmanagedTransition fid=00007FF8F662F160 fuid=016000B2 reason=return fname='Invoke' cname='Interop+User32+WndProc'
00005F54 1 000002476DEE6B50 PTProf::UnmanagedToManagedTransition fid=00007FF8F662F160 fuid=016000B2 reason=call fname='Invoke' cname='Interop+User32+WndProc'
00005F54 1 000002476DEE6B50 PTProf::UnmanagedToManagedTransition fid=00007FF8F662F160 fuid=016000B2 reason=call fname='Invoke' cname='Interop+User32+WndProc'
00005F54 1 000002476DEE6B50 PTProf::RdtscFastEnter fuid=01600071
00005F54 1 000002476DEE6B50 PTProf::ManagedToUnmanagedTransition fid=00007FF8F662DD00 fuid=01600089 reason=call fname='DefWindowProcW' cname='Interop+User32'
00005F54 1 000002476DEE6B50 PTProf::UnmanagedToManagedTransition fid=00007FF8F662DD00 fuid=01600089 reason=return fname='DefWindowProcW' cname='Interop+User32'
00005F54 1 000002476DEE6B50 PTProf::RdtscFastLeave fuid=01600071

Here two callstacks for duplicated transitions:

№1:

0:000> k
 # Child-SP          RetAddr               Call Site
00 00000068`d5b7d0e0 00007ff9`3fff4156     JetBrains_Profiler_Core!`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2>::operator()+0x188 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\profilers\performance\tracing\performance_tracing_profiler.transition.cpp @ 93] 
01 00000068`d5b7d1d0 00007ff9`3fff411b     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2>,`jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2> >'::`2'::<lambda_1> >+0x26 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 21] 
02 00000068`d5b7d200 00007ff9`3f88bb33     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2> >+0x2b [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 34] 
03 00000068`d5b7d240 00007ff9`43f62899     JetBrains_Profiler_Core!jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition+0x2f3 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\profilers\performance\tracing\performance_tracing_profiler.transition.cpp @ 101] 
04 00000068`d5b7d3b0 00007ff9`43fa1073     coreclr!EEToProfInterfaceImpl::ManagedToUnmanagedTransition+0x79 [D:\a\_work\1\s\src\coreclr\vm\eetoprofinterfaceimpl.cpp @ 4421] 
05 (Inline Function) --------`--------     coreclr!ManagedToUnmanagedTransitionHelper+0xb [D:\a\_work\1\s\src\coreclr\inc\profilepriv.inl @ 1004] 
06 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoProfilerCallbackHelper+0x22 [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 283] 
07 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoOneProfilerIteration+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 199] 
08 (Inline Function) --------`--------     coreclr!ProfControlBlock::IterateProfilers+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 207] 
09 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoProfilerCallback+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 295] 
0a (Inline Function) --------`--------     coreclr!ProfControlBlock::ManagedToUnmanagedTransition+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.inl @ 1011] 
0b 00000068`d5b7d3f0 00007ff9`43fab759     coreclr!ProfilerManagedToUnmanagedTransitionMD+0x8f [D:\a\_work\1\s\src\coreclr\vm\proftoeeinterfaceimpl.cpp @ 10513] 
0c 00000068`d5b7d440 00007ff8`e452fbdd     coreclr!StubHelpers::ProfilerEndTransitionCallback+0x119 [D:\a\_work\1\s\src\coreclr\vm\stubhelpers.cpp @ 704] 
0d 00000068`d5b7d5d0 00007ff9`aaeee858     0x00007ff8`e452fbdd
0e 00000068`d5b7d660 00007ff9`aaeee3dc     USER32!UserCallWinProcCheckWow+0x2f8
0f 00000068`d5b7d7f0 00007ff9`aaf03d62     USER32!DispatchClientMessage+0x9c
10 00000068`d5b7d850 00007ff9`acf30b74     USER32!_fnINOUTLPPOINT5+0x32
11 00000068`d5b7d8b0 00007ff9`aac51ec4     ntdll!KiUserCallbackDispatcherContinue
12 00000068`d5b7d958 00007ff9`aaee7d8b     win32u!NtUserCreateWindowEx+0x14
13 00000068`d5b7d960 00007ff9`aaee7958     USER32!VerNtUserCreateWindowEx+0x20f
14 00000068`d5b7dcf0 00007ff9`aaee77a2     USER32!CreateWindowInternal+0x1a4
15 00000068`d5b7de50 00007ff8`e452f837     USER32!CreateWindowExW+0x82
16 00000068`d5b7dee0 00007ff8`e452f625     0x00007ff8`e452f837
17 00000068`d5b7e080 00007ff8`e452abdd     0x00007ff8`e452f625
18 00000068`d5b7e120 00007ff8`e452a1bb     0x00007ff8`e452abdd
19 00000068`d5b7e280 00007ff8`e4527428     0x00007ff8`e452a1bb
1a 00000068`d5b7e370 00007ff8`e452730e     0x00007ff8`e4527428
1b 00000068`d5b7e3a0 00007ff8`e4525fd9     0x00007ff8`e452730e
1c 00000068`d5b7e400 00007ff8`e4524dc3     0x00007ff8`e4525fd9
1d 00000068`d5b7e440 00007ff8`e4313d5b     0x00007ff8`e4524dc3
1e 00000068`d5b7e4a0 00007ff8`e4311cc3     0x00007ff8`e4313d5b
1f 00000068`d5b7e5e0 00007ff8`e4311c27     0x00007ff8`e4311cc3
20 00000068`d5b7e610 00007ff8`e4311a3b     0x00007ff8`e4311c27
21 00000068`d5b7e640 00007ff8`e431179a     0x00007ff8`e4311a3b
22 00000068`d5b7e680 00007ff8`e4311619     0x00007ff8`e431179a
23 00000068`d5b7e6f0 00007ff8`e43034f0     0x00007ff8`e4311619
24 00000068`d5b7e720 00007ff9`43e5a863     0x00007ff8`e43034f0
25 00000068`d5b7e760 00007ff9`43d5ff96     coreclr!CallDescrWorkerInternal+0x83
26 00000068`d5b7e7a0 00007ff9`43dd1107     coreclr!MethodDescCallSite::CallTargetWorker+0x176 [D:\a\_work\1\s\src\coreclr\vm\callhelpers.cpp @ 551] 
27 (Inline Function) --------`--------     coreclr!MethodDescCallSite::Call+0xb [D:\a\_work\1\s\src\coreclr\vm\callhelpers.h @ 458] 
28 00000068`d5b7e8d0 00007ff9`43dd0f86     coreclr!RunMainInternal+0x11f [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1483] 
29 00000068`d5b7ea00 00007ff9`43dd0e35     coreclr!RunMain+0xd2 [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1554] 
2a 00000068`d5b7eab0 00007ff9`43dd0bf6     coreclr!Assembly::ExecuteMainMethod+0x1c9 [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1672] 
2b 00000068`d5b7ee40 00007ff9`43e05352     coreclr!CorHost2::ExecuteAssembly+0x1c6 [D:\a\_work\1\s\src\coreclr\vm\corhost.cpp @ 384] 
2c 00000068`d5b7efb0 00007ff9`7b0d96db     coreclr!coreclr_execute_assembly+0xe2 [D:\a\_work\1\s\src\coreclr\dlls\mscoree\unixinterface.cpp @ 446] 
2d (Inline Function) --------`--------     hostpolicy!coreclr_t::execute_assembly+0x2a [D:\a\_work\1\s\src\native\corehost\hostpolicy\coreclr.cpp @ 89] 
2e 00000068`d5b7f050 00007ff9`7b0d9a0c     hostpolicy!run_app_for_context+0x56b [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 255] 
2f 00000068`d5b7f1f0 00007ff9`7b0da3a7     hostpolicy!run_app+0x3c [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 284] 
30 00000068`d5b7f230 00007ff9`7d35b539     hostpolicy!corehost_main+0x107 [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 430] 
31 00000068`d5b7f3e0 00007ff9`7d35e506     hostfxr!execute_app+0x2e9 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 146] 
32 00000068`d5b7f4e0 00007ff9`7d360821     hostfxr!`anonymous namespace'::read_config_and_execute+0xa6 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 533] 
33 00000068`d5b7f5e0 00007ff9`7d35eb62     hostfxr!fx_muxer_t::handle_exec_host_command+0x161 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 1018] 
34 00000068`d5b7f690 00007ff9`7d3582ab     hostfxr!fx_muxer_t::execute+0x482 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 579] 
35 00000068`d5b7f7d0 00007ff6`059d24b8     hostfxr!hostfxr_main_startupinfo+0xab [D:\a\_work\1\s\src\native\corehost\fxr\hostfxr.cpp @ 61] 
36 00000068`d5b7f8d0 00007ff6`059d282b     WinFormsApp1_exe!exe_start+0x8d8 [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 235] 
37 00000068`d5b7faa0 00007ff6`059d3cd8     WinFormsApp1_exe!wmain+0xab [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 304] 
38 (Inline Function) --------`--------     WinFormsApp1_exe!invoke_main+0x22 [d:\a01\_work\12\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 90] 
39 00000068`d5b7fad0 00007ff9`abf87034     WinFormsApp1_exe!__scrt_common_main_seh+0x10c [d:\a01\_work\12\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288] 
3a 00000068`d5b7fb10 00007ff9`acee2651     KERNEL32!BaseThreadInitThunk+0x14
3b 00000068`d5b7fb40 00000000`00000000     ntdll!RtlUserThreadStart+0x21
0:000> !clrstack
OS Thread Id: 0x9990 (0)
        Child SP               IP Call Site
00000068D5B7D4B8 00007ff93f88cbc8 [HelperMethodFrame: 00000068d5b7d4b8] System.StubHelpers.StubHelpers.ProfilerEndTransitionCallback(IntPtr, IntPtr)
00000068D5B7D5D0 00007ff8e452fbdd ILStubClass.IL_STUB_ReversePInvoke(Int64, UInt32, Int64, Int64)
00000068D5B7DF88 00007ff9aaeee858 [InlinedCallFrame: 00000068d5b7df88] Interop+User32.CreateWindowExW(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7DF88 00007ff8e452f837 [InlinedCallFrame: 00000068d5b7df88] Interop+User32.CreateWindowExW(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7DF10 00007ff8e452f837 ILStubClass.IL_STUB_PInvoke(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7E080 00007ff8e452f625 Interop+User32.CreateWindowExW(WS_EX, System.String, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object) [/_/src/System.Windows.Forms.Primitives/src/Interop/User32/Interop.CreateWindowExW.cs @ 42]
00000068D5B7E120 00007ff8e452abdd System.Windows.Forms.NativeWindow.CreateHandle(System.Windows.Forms.CreateParams) [/_/src/System.Windows.Forms/src/System/Windows/Forms/NativeWindow.cs @ 459]
00000068D5B7E280 00007ff8e452a1bb System.Windows.Forms.Control.CreateHandle() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 4967]
00000068D5B7E370 00007ff8e4527428 System.Windows.Forms.Application+MarshalingControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Application.MarshallingControl.cs @ 26]
00000068D5B7E3A0 00007ff8e452730e System.Windows.Forms.Application+ThreadContext.get_MarshalingControl() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Application.ThreadContext.cs @ 374]
00000068D5B7E400 00007ff8e4525fd9 System.Windows.Forms.WindowsFormsSynchronizationContext..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/WindowsFormsSynchronizationContext.cs @ 33]
00000068D5B7E440 00007ff8e4524dc3 System.Windows.Forms.WindowsFormsSynchronizationContext.InstallIfNeeded() [/_/src/System.Windows.Forms/src/System/Windows/Forms/WindowsFormsSynchronizationContext.cs @ 145]
00000068D5B7E4A0 00007ff8e4313d5b System.Windows.Forms.Control..ctor(Boolean) [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 446]
00000068D5B7E5E0 00007ff8e4311cc3 System.Windows.Forms.Control..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 370]
00000068D5B7E610 00007ff8e4311c27 System.Windows.Forms.ScrollableControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/ScrollableControl.cs @ 78]
00000068D5B7E640 00007ff8e4311a3b System.Windows.Forms.ContainerControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/ContainerControl.cs @ 94]
00000068D5B7E680 00007ff8e431179a System.Windows.Forms.Form..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Form.cs @ 163]
00000068D5B7E6F0 00007ff8e4311619 WinFormsApp1.Form1..ctor() [D:\Work\DTRC-28226 Repro\WinFormsApp1\WinFormsApp1\Form1.cs @ 7]
00000068D5B7E720 00007ff8e43034f0 WinFormsApp1.Program.Main() [D:\Work\DTRC-28226 Repro\WinFormsApp1\WinFormsApp1\Program.cs @ 14]

№2

0:000> k
 # Child-SP          RetAddr               Call Site
00 00000068`d5b7d240 00007ff9`3fff4156     JetBrains_Profiler_Core!`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2>::operator()+0x188 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\profilers\performance\tracing\performance_tracing_profiler.transition.cpp @ 93] 
01 00000068`d5b7d330 00007ff9`3fff411b     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2>,`jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2> >'::`2'::<lambda_1> >+0x26 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 21] 
02 00000068`d5b7d360 00007ff9`3f88bb33     JetBrains_Profiler_Core!jbprof::do_noexcept_log<`jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition'::`2'::<lambda_2> >+0x2b [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\utility\do_noexcept_log.hpp @ 34] 
03 00000068`d5b7d3a0 00007ff9`43f62899     JetBrains_Profiler_Core!jbprof::performance_tracing_profiler::ManagedToUnmanagedTransition+0x2f3 [C:\Work\dotnet-products\Profiler\Kernel\Windows\Native\Solution\core\src\profilers\performance\tracing\performance_tracing_profiler.transition.cpp @ 101] 
04 00000068`d5b7d510 00007ff9`43fa1073     coreclr!EEToProfInterfaceImpl::ManagedToUnmanagedTransition+0x79 [D:\a\_work\1\s\src\coreclr\vm\eetoprofinterfaceimpl.cpp @ 4421] 
05 (Inline Function) --------`--------     coreclr!ManagedToUnmanagedTransitionHelper+0xb [D:\a\_work\1\s\src\coreclr\inc\profilepriv.inl @ 1004] 
06 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoProfilerCallbackHelper+0x22 [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 283] 
07 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoOneProfilerIteration+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 199] 
08 (Inline Function) --------`--------     coreclr!ProfControlBlock::IterateProfilers+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 207] 
09 (Inline Function) --------`--------     coreclr!ProfControlBlock::DoProfilerCallback+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.h @ 295] 
0a (Inline Function) --------`--------     coreclr!ProfControlBlock::ManagedToUnmanagedTransition+0x4b [D:\a\_work\1\s\src\coreclr\inc\profilepriv.inl @ 1011] 
0b 00000068`d5b7d550 00007ff9`43e57711     coreclr!ProfilerManagedToUnmanagedTransitionMD+0x8f [D:\a\_work\1\s\src\coreclr\vm\proftoeeinterfaceimpl.cpp @ 10513] 
0c 00000068`d5b7d5a0 00007ff8`e452fbe7     coreclr!JIT_ReversePInvokeExitTrackTransitions+0x31 [D:\a\_work\1\s\src\coreclr\vm\jithelpers.cpp @ 5579] 
0d 00000068`d5b7d5d0 00007ff9`aaeee858     0x00007ff8`e452fbe7
0e 00000068`d5b7d660 00007ff9`aaeee3dc     USER32!UserCallWinProcCheckWow+0x2f8
0f 00000068`d5b7d7f0 00007ff9`aaf03d62     USER32!DispatchClientMessage+0x9c
10 00000068`d5b7d850 00007ff9`acf30b74     USER32!_fnINOUTLPPOINT5+0x32
11 00000068`d5b7d8b0 00007ff9`aac51ec4     ntdll!KiUserCallbackDispatcherContinue
12 00000068`d5b7d958 00007ff9`aaee7d8b     win32u!NtUserCreateWindowEx+0x14
13 00000068`d5b7d960 00007ff9`aaee7958     USER32!VerNtUserCreateWindowEx+0x20f
14 00000068`d5b7dcf0 00007ff9`aaee77a2     USER32!CreateWindowInternal+0x1a4
15 00000068`d5b7de50 00007ff8`e452f837     USER32!CreateWindowExW+0x82
16 00000068`d5b7dee0 00007ff8`e452f625     0x00007ff8`e452f837
17 00000068`d5b7e080 00007ff8`e452abdd     0x00007ff8`e452f625
18 00000068`d5b7e120 00007ff8`e452a1bb     0x00007ff8`e452abdd
19 00000068`d5b7e280 00007ff8`e4527428     0x00007ff8`e452a1bb
1a 00000068`d5b7e370 00007ff8`e452730e     0x00007ff8`e4527428
1b 00000068`d5b7e3a0 00007ff8`e4525fd9     0x00007ff8`e452730e
1c 00000068`d5b7e400 00007ff8`e4524dc3     0x00007ff8`e4525fd9
1d 00000068`d5b7e440 00007ff8`e4313d5b     0x00007ff8`e4524dc3
1e 00000068`d5b7e4a0 00007ff8`e4311cc3     0x00007ff8`e4313d5b
1f 00000068`d5b7e5e0 00007ff8`e4311c27     0x00007ff8`e4311cc3
20 00000068`d5b7e610 00007ff8`e4311a3b     0x00007ff8`e4311c27
21 00000068`d5b7e640 00007ff8`e431179a     0x00007ff8`e4311a3b
22 00000068`d5b7e680 00007ff8`e4311619     0x00007ff8`e431179a
23 00000068`d5b7e6f0 00007ff8`e43034f0     0x00007ff8`e4311619
24 00000068`d5b7e720 00007ff9`43e5a863     0x00007ff8`e43034f0
25 00000068`d5b7e760 00007ff9`43d5ff96     coreclr!CallDescrWorkerInternal+0x83
26 00000068`d5b7e7a0 00007ff9`43dd1107     coreclr!MethodDescCallSite::CallTargetWorker+0x176 [D:\a\_work\1\s\src\coreclr\vm\callhelpers.cpp @ 551] 
27 (Inline Function) --------`--------     coreclr!MethodDescCallSite::Call+0xb [D:\a\_work\1\s\src\coreclr\vm\callhelpers.h @ 458] 
28 00000068`d5b7e8d0 00007ff9`43dd0f86     coreclr!RunMainInternal+0x11f [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1483] 
29 00000068`d5b7ea00 00007ff9`43dd0e35     coreclr!RunMain+0xd2 [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1554] 
2a 00000068`d5b7eab0 00007ff9`43dd0bf6     coreclr!Assembly::ExecuteMainMethod+0x1c9 [D:\a\_work\1\s\src\coreclr\vm\assembly.cpp @ 1672] 
2b 00000068`d5b7ee40 00007ff9`43e05352     coreclr!CorHost2::ExecuteAssembly+0x1c6 [D:\a\_work\1\s\src\coreclr\vm\corhost.cpp @ 384] 
2c 00000068`d5b7efb0 00007ff9`7b0d96db     coreclr!coreclr_execute_assembly+0xe2 [D:\a\_work\1\s\src\coreclr\dlls\mscoree\unixinterface.cpp @ 446] 
2d (Inline Function) --------`--------     hostpolicy!coreclr_t::execute_assembly+0x2a [D:\a\_work\1\s\src\native\corehost\hostpolicy\coreclr.cpp @ 89] 
2e 00000068`d5b7f050 00007ff9`7b0d9a0c     hostpolicy!run_app_for_context+0x56b [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 255] 
2f 00000068`d5b7f1f0 00007ff9`7b0da3a7     hostpolicy!run_app+0x3c [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 284] 
30 00000068`d5b7f230 00007ff9`7d35b539     hostpolicy!corehost_main+0x107 [D:\a\_work\1\s\src\native\corehost\hostpolicy\hostpolicy.cpp @ 430] 
31 00000068`d5b7f3e0 00007ff9`7d35e506     hostfxr!execute_app+0x2e9 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 146] 
32 00000068`d5b7f4e0 00007ff9`7d360821     hostfxr!`anonymous namespace'::read_config_and_execute+0xa6 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 533] 
33 00000068`d5b7f5e0 00007ff9`7d35eb62     hostfxr!fx_muxer_t::handle_exec_host_command+0x161 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 1018] 
34 00000068`d5b7f690 00007ff9`7d3582ab     hostfxr!fx_muxer_t::execute+0x482 [D:\a\_work\1\s\src\native\corehost\fxr\fx_muxer.cpp @ 579] 
35 00000068`d5b7f7d0 00007ff6`059d24b8     hostfxr!hostfxr_main_startupinfo+0xab [D:\a\_work\1\s\src\native\corehost\fxr\hostfxr.cpp @ 61] 
36 00000068`d5b7f8d0 00007ff6`059d282b     WinFormsApp1_exe!exe_start+0x8d8 [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 235] 
37 00000068`d5b7faa0 00007ff6`059d3cd8     WinFormsApp1_exe!wmain+0xab [D:\a\_work\1\s\src\native\corehost\corehost.cpp @ 304] 
38 (Inline Function) --------`--------     WinFormsApp1_exe!invoke_main+0x22 [d:\a01\_work\12\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 90] 
39 00000068`d5b7fad0 00007ff9`abf87034     WinFormsApp1_exe!__scrt_common_main_seh+0x10c [d:\a01\_work\12\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288] 
3a 00000068`d5b7fb10 00007ff9`acee2651     KERNEL32!BaseThreadInitThunk+0x14
3b 00000068`d5b7fb40 00000000`00000000     ntdll!RtlUserThreadStart+0x21
0:000> !clrstack
OS Thread Id: 0x9990 (0)
        Child SP               IP Call Site
00000068D5B7DF88 00007ff93f88cbc8 [InlinedCallFrame: 00000068d5b7df88] Interop+User32.CreateWindowExW(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7DF88 00007ff8e452f837 [InlinedCallFrame: 00000068d5b7df88] Interop+User32.CreateWindowExW(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7DF10 00007ff8e452f837 ILStubClass.IL_STUB_PInvoke(WS_EX, Char*, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object)
00000068D5B7E080 00007ff8e452f625 Interop+User32.CreateWindowExW(WS_EX, System.String, System.String, WS, Int32, Int32, Int32, Int32, IntPtr, IntPtr, IntPtr, System.Object) [/_/src/System.Windows.Forms.Primitives/src/Interop/User32/Interop.CreateWindowExW.cs @ 42]
00000068D5B7E120 00007ff8e452abdd System.Windows.Forms.NativeWindow.CreateHandle(System.Windows.Forms.CreateParams) [/_/src/System.Windows.Forms/src/System/Windows/Forms/NativeWindow.cs @ 459]
00000068D5B7E280 00007ff8e452a1bb System.Windows.Forms.Control.CreateHandle() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 4967]
00000068D5B7E370 00007ff8e4527428 System.Windows.Forms.Application+MarshalingControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Application.MarshallingControl.cs @ 26]
00000068D5B7E3A0 00007ff8e452730e System.Windows.Forms.Application+ThreadContext.get_MarshalingControl() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Application.ThreadContext.cs @ 374]
00000068D5B7E400 00007ff8e4525fd9 System.Windows.Forms.WindowsFormsSynchronizationContext..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/WindowsFormsSynchronizationContext.cs @ 33]
00000068D5B7E440 00007ff8e4524dc3 System.Windows.Forms.WindowsFormsSynchronizationContext.InstallIfNeeded() [/_/src/System.Windows.Forms/src/System/Windows/Forms/WindowsFormsSynchronizationContext.cs @ 145]
00000068D5B7E4A0 00007ff8e4313d5b System.Windows.Forms.Control..ctor(Boolean) [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 446]
00000068D5B7E5E0 00007ff8e4311cc3 System.Windows.Forms.Control..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Control.cs @ 370]
00000068D5B7E610 00007ff8e4311c27 System.Windows.Forms.ScrollableControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/ScrollableControl.cs @ 78]
00000068D5B7E640 00007ff8e4311a3b System.Windows.Forms.ContainerControl..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/ContainerControl.cs @ 94]
00000068D5B7E680 00007ff8e431179a System.Windows.Forms.Form..ctor() [/_/src/System.Windows.Forms/src/System/Windows/Forms/Form.cs @ 163]
00000068D5B7E6F0 00007ff8e4311619 WinFormsApp1.Form1..ctor() [D:\Work\DTRC-28226 Repro\WinFormsApp1\WinFormsApp1\Form1.cs @ 7]
00000068D5B7E720 00007ff8e43034f0 WinFormsApp1.Program.Main() [D:\Work\DTRC-28226 Repro\WinFormsApp1\WinFormsApp1\Program.cs @ 14]

The real difference between two sequential callstacks here: coreclr!StubHelpers::ProfilerEndTransitionCallback and coreclr!JIT_ReversePInvokeExitTrackTransitions.

Author: ww898
Assignees: -
Labels:

area-Diagnostics-coreclr, untriaged
Milestone: -

@jkotas
Copy link
Member

jkotas commented May 24, 2022

cc @jkoritzinsky

@jkoritzinsky jkoritzinsky mentioned this issue May 24, 2022
Merged
@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label May 24, 2022
@AaronRobinsonMSFT AaronRobinsonMSFT removed the untriaged New issue has not been triaged by the area owner label May 24, 2022
@AaronRobinsonMSFT AaronRobinsonMSFT added this to the 7.0.0 milestone May 24, 2022
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label May 25, 2022
@ghost ghost locked as resolved and limited conversation to collaborators Jun 24, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
area-Diagnostics-coreclr
Projects
None yet
Milestone
7.0.0
4 participants
@vcsjones @ww898 @jkotas @AaronRobinsonMSFT