Problem in Debugging .NET Reflection Code
The other day I was delivering a session on .net reflection and during the course of the session there were a few console based demo applications that I was showing to the audience. During one such demo, there was some change in code I did based on a query raised by one of the participants and to show how it worked, I put a breakpoint and happily started to debug.
Murphy, I guess had something against me that day and the debugging just won't work correctly.
The code as such worked fine, so if I just ran the application, I got the right results, but during debugging, nothing worked and in the local window in debugging, none of the reflected variables like MethodInfo, FieldInfo, PropertyInfo etc showed any values and the message displayed was - "Function evaluation disabled because a previous function evaluation timed out. You must continue execution to reenable function evaluation."
This was really strange. At this time if I would hit F5, to not worry about watching locals anymore and just the application run, it won't ! The application would hang. No further results were displayed and the process won't terminate. I could still stop the debugging from Visual Studio and that's about it.
I have been debugging code many times, but never seen this issue before. So I decided to take a dump and see if I could gather anything from it. Being on Vista, I could take the dump of the process directly from task manager by just right clicking on the process and selecting - Create Dump File. I then opened this in Windbg and started by displaying the currently executing threads.
0:000> !threads
ThreadCount: 11
UnstartedThread: 0
BackgroundThread: 7
PendingThread: 0
DeadThread: 2
Hosted Runtime: no
PreEmptive GC Alloc Lock
ID OSID ThreadOBJ State GC Context Domain Count APT Exception
0 1 ce4 00264498 201a228 Enabled 01f108dc:01f11fe8 00223438 0 MTA
2 2 1f9c 0026cff0 b228 Enabled 00000000:00000000 00223438 0 MTA (Finalizer)
XXXX 3 1e90 04f35520 80010228 Enabled 00000000:00000000 00223438 0 Ukn
XXXX 4 370 04f49618 80010228 Enabled 01f192d8:01f19fe8 00223438 0 Ukn
XXXX 5 0 04f48ca8 9820 Enabled 00000000:00000000 00223438 0 MTA
XXXX 6 0 04f65728 9820 Enabled 00000000:00000000 00223438 0 MTA
5 7 1a84 04f66ae8 180b228 Enabled 00000000:00000000 00223438 0 MTA (Threadpool Worker)
9 8 273c 04f6b988 8b028 Enabled 01f24698:01f24798 00223438 0 MTA
6 9 d38 04f66620 228 Enabled 00000000:00000000 00223438 0 Ukn
10 a 1b04 04f65fa8 8b228 Enabled 01f1e38c:01f1ffe8 00223438 0 MTA
11 b 1720 04f8a1b8 87028 Enabled 01f33b8c:01f33fe8 00223438 0 STA System.Threading.ThreadAbortException (01f33a34)
Interestingly, there is a ThreadAbortException on thread 11. It is an STA thread and in all likelihood, the thread on which my console application code was executing. Doing a dump of the clrstack for thread 11 confirmed it.
0:011> !clrstack
OS Thread Id: 0x1720 (11)
ESP EIP
0623e994 009216a2 Reflection_Basics.Reflection.Main(System.String[])
0623ec74 6cf51b4c [GCFrame: 0623ec74]
0623f0bc 6cf51b4c [HelperMethodFrame_PROTECTOBJ: 0623f0bc] System.AppDomain._nExecuteAssembly(System.Reflection.Assembly, System.String[])
0623f34c 5f4d4aae System.AppDomain.ExecuteAssembly(System.String, System.Security.Policy.Evidence, System.String[])
0623f368 009214eb Microsoft.VisualStudio.HostingProcess.HostProc.RunUsersAssembly()
0623f390 5f036cf6 System.Threading.ThreadHelper.ThreadStart_Context(System.Object)
0623f39c 5f04019f System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
0623f3b4 5f036c74 System.Threading.ThreadHelper.ThreadStart()
0623f5dc 6cf51b4c [GCFrame: 0623f5dc]
The top statement showed that this was indeed executing the main method of my demo sample, which is where my sample code was and the one I was trying to debug by putting a breakpoint. Next I tried to see where the exception was actually raised and this is what I got
0:011> !pe 01f33a34
Exception object: 01f33a34
Exception type: System.Threading.ThreadAbortException
Message: Thread was being aborted.
InnerException: <none>
StackTrace (generated):
SP IP Function
0623E1AC 5FDCA22A System_ni!System.Diagnostics.DiagnosticsConfiguration.Initialize()+0x3a
0623E1DC 5FDA5449 System_ni!System.Diagnostics.DiagnosticsConfiguration.get_IndentSize()+0x9
0623E1E8 5FDEECCF System_ni!System.Diagnostics.TraceInternal.InitializeSettings()+0x4f
0623E1F4 5FDCDD8F System_ni!System.Diagnostics.TraceInternal.get_Listeners()+0x1f
StackTraceString: <none>
HResult: 80131530
Seems like the exception happened when trying to Initialize the DiagnosticsConfiguration. To get to know what really was happening there I unassembled the code.
0:011> !u 5FDCA22A
preJIT generated code
System.Diagnostics.DiagnosticsConfiguration.Initialize()
Begin 5fdca1f0, size 11f
5fdca1f0 55 push ebp
5fdca1f1 8bec mov ebp,esp
5fdca1f3 57 push edi
5fdca1f4 56 push esi
5fdca1f5 53 push ebx
5fdca1f6 83ec1c sub esp,1Ch
5fdca1f9 8d7dd8 lea edi,[ebp-28h]
5fdca1fc b906000000 mov ecx,6
5fdca201 33c0 xor eax,eax
5fdca203 f3ab rep stos dword ptr es:[edi]
5fdca205 33c0 xor eax,eax
5fdca207 8945e8 mov dword ptr [ebp-18h],eax
*** WARNING: Unable to verify checksum for System.ni.dll
5fdca20a 8b0d0013c95f mov ecx,dword ptr [System_ni+0x1300 (5fc91300)]
5fdca210 bad7010000 mov edx,1D7h
5fdca215 e82e8cfbff call System_ni+0xf2e48 (5fd82e48) (System_ni)
5fdca21a 8b80a8040000 mov eax,dword ptr [eax+4A8h]
5fdca220 8945dc mov dword ptr [ebp-24h],eax
5fdca223 8bc8 mov ecx,eax
5fdca225 e8de4dfbff call System_ni+0xef008 (5fd7f008) (System.Threading.Monitor.Enter(System.Object), mdToken: 0600122f)
>>> 5fdca22a 8b0d0013c95f mov ecx,dword ptr [System_ni+0x1300 (5fc91300)]
5fdca230 e8838cfbff call System_ni+0xf2eb8 (5fd82eb8) (System_ni)
5fdca235 83b8ac08000000 cmp dword ptr [eax+8ACh],0
5fdca23c 7418 je System_ni+0x13a256 (5fdca256)
5fdca23e c745e400000000 mov dword ptr [ebp-1Ch],0
5fdca245 c745e8fc000000 mov dword ptr [ebp-18h],0FCh
5fdca24c 6806a3dc5f push offset System_ni+0x13a306 (5fdca306)
5fdca251 e994000000 jmp System_ni+0x13a2ea (5fdca2ea)
5fdca256 e81da2fbff call System_ni+0xf4478 (5fd84478) (System.Configuration.ConfigurationManagerInternalFactory.get_Instance(), mdToken: 060035ac)
5fdca25b 8bc8 mov ecx,eax
5fdca25d ff154462cb5f call dword ptr [System_ni+0x26244 (5fcb6244)] (System_ni)
5fdca263 85c0 test eax,eax
5fdca265 75d7 jne System_ni+0x13a23e (5fdca23e)
5fdca267 8b0d0013c95f mov ecx,dword ptr [System_ni+0x1300 (5fc91300)]
5fdca26d e8468cfbff call System_ni+0xf2eb8 (5fd82eb8) (System_ni)
5fdca272 c780ac08000001000000 mov dword ptr [eax+8ACh],1
5fdca27c 8b0d0013c95f mov ecx,dword ptr [System_ni+0x1300 (5fc91300)]
5fdca282 e8898cfbff call System_ni+0xf2f10 (5fd82f10) (System_ni)
5fdca287 8945d8 mov dword ptr [ebp-28h],eax
5fdca28a e81193fbff call System_ni+0xf35a0 (5fd835a0) (System.Diagnostics.DiagnosticsConfiguration.GetConfigSection(), mdToken: 06000e14)
5fdca28f 8bc8 mov ecx,eax
5fdca291 8b45d8 mov eax,dword ptr [ebp-28h]
5fdca294 8d9034040000 lea edx,[eax+434h]
5fdca29a e8c98bfbff call System_ni+0xf2e68 (5fd82e68) (System_ni)
5fdca29f c745e400000000 mov dword ptr [ebp-1Ch],0
5fdca2a6 c745e8fc000000 mov dword ptr [ebp-18h],0FCh
5fdca2ad 68e1a2dc5f push offset System_ni+0x13a2e1 (5fdca2e1)
5fdca2b2 eb00 jmp System_ni+0x13a2b4 (5fdca2b4)
5fdca2b4 8b0d0013c95f mov ecx,dword ptr [System_ni+0x1300 (5fc91300)]
5fdca2ba e8f98bfbff call System_ni+0xf2eb8 (5fd82eb8) (System_ni)
5fdca2bf c780ac08000002000000 mov dword ptr [eax+8ACh],2
5fdca2c9 58 pop eax
5fdca2ca ffe0 jmp eax
5fdca2cc c745e400000000 mov dword ptr [ebp-1Ch],0
5fdca2d3 c745e8fc000000 mov dword ptr [ebp-18h],0FCh
5fdca2da 68fda2dc5f push offset System_ni+0x13a2fd (5fdca2fd)
5fdca2df eb09 jmp System_ni+0x13a2ea (5fdca2ea)
5fdca2e1 c745e800000000 mov dword ptr [ebp-18h],0
5fdca2e8 ebe2 jmp System_ni+0x13a2cc (5fdca2cc)
5fdca2ea 8b4ddc mov ecx,dword ptr [ebp-24h]
5fdca2ed e8264dfbff call System_ni+0xef018 (5fd7f018) (System.Threading.Monitor.Exit(System.Object), mdToken: 06001231)
5fdca2f2 58 pop eax
5fdca2f3 ffe0 jmp eax
5fdca2f5 8d65f4 lea esp,[ebp-0Ch]
5fdca2f8 5b pop ebx
5fdca2f9 5e pop esi
5fdca2fa 5f pop edi
5fdca2fb 5d pop ebp
5fdca2fc c3 ret
5fdca2fd c745e800000000 mov dword ptr [ebp-18h],0
5fdca304 ebef jmp System_ni+0x13a2f5 (5fdca2f5)
5fdca306 c745e800000000 mov dword ptr [ebp-18h],0
5fdca30d ebe6 jmp System_ni+0x13a2f5 (5fdca2f5)
Comparing the IP where the exception happened, I got to what was happening at the time the exception was raised. The code seems to have entered a monitor and then tried to move some data to ecx and that seems to have caused the exception. At this point, unfortunately, my debugging skills failed me and I could go further.
However here are some other findings
1. This issue happened only with a console based application. If I had the same code in a winform application, the debugging worked perfectly.
2. The issue also didn't happen if I disabled the Visual Studio host process. This meant that when I was debugging earlier the code was running inside of <app>.vshost.exe and with it switched of, it was the EXE that was directly being debugged and it worked fine.
So conclusion is something went wrong when debugging via VS host process for a console based application. If you have seen similar issue and know what really has gone wrong, I will be happy to hear from you. If you have any tips on how to further debug in Windbg, even that will be welcome.

