不知道各位使用.NET开发的朋友是否有遇到过一些非常奇怪的问题而不知道如何下手呢?这个时侯CLR本身提供的StressLog功能就非常有用了。这个StressLog可以在很多时候把CLR所做的事情记录下来,比如,对于一个很简单的最后抛出异常的.NET程序Log大致如下:
STRESS LOG: facilitiesToLog = 0x8000ffff levelToLog = 16 MaxLogSizePerThread = 0x20000 (131072) MaxTotalLogSize = 0x2000000 (33554432) CurrentTotalLogChunk = 6 ThreadsWithLogs = 3 Clock frequency = 0.014 GHz Start time 22:47:37 Last message time 22:47:44 Total elapsed time 6.520 sec THREAD TIMESTAMP FACILITY MESSAGE ID (sec from start) -------------------------------------------------------------------------------------- 1638 6.519607729 : `SYNC` SafeExitProcesses: exitcode = -2146233082 1638 0.842361250 : `GC` CreateHandle: 0000000000261338 1638 0.838161973 : `EH` In CLRVectoredExceptionHandler, Exception = e0434f4d, Context = 00000000001AE4C0, IP = 00000000779B649D SP = 00000000001AEA60 1638 0.837840633 : `GC` CreateHandle: 0000000000261340 1638 0.837838329 : `EH` in Thread::SetLastThrownObject: obj = 0000000002B76238 1638 0.837837281 : `EH` Exception HRESULT = 0x80131600 Message String 0x0000000002B96188 (db will display) InnerException 0000000000000000 MT 0000000000000000 (BAD MethodTable) 1638 0.837834418 : `EH` ******* MANAGED EXCEPTION THROWN: Object thrown: 0000000002B76238 MT 000007FEF40FADC8 (System.ApplicationException) rethrow 0 1638 0.837646265 : `CLASSLOADER` DoRunClassInit: returning SUCCESS for init 000007FEF40F2E10 (System.Collections.HashHelpers) in appdomain 000000000035CCC0 1638 0.837618049 : `CLASSLOADER` RunClassInit: Returned Successfully from class contructor for type 000007FEF40F2E10 (System.Collections.HashHelpers) 1638 0.837617141 : `CLASSLOADER` DoRunClassInit: returning SUCCESS for init 000007FEF40F2E10 (System.Collections.HashHelpers) in appdomain 000000000035CCC0 … … (中间省去1000余行) … 1638 0.328838232 : `GC` CreateHandle: 00000000002613E0 1638 0.312699170 : `CLASSLOADER` Attempted to set new native file 02088e80, old file was 00000000, location in the image=f3cc1008 1754 0.269468466 : `ALWAYS` SetupThread managed Thread 00000000020815D0 Thread Id = 2 ------------ Last message from thread 1754 ----------- 1638 0.268254415 : `GC` CreateHandle: 00000000002613E8 1638 0.268252879 : `GC` CreateHandle: 00000000002615F0 1638 0.219663812 : `ALWAYS` SetupThread managed Thread 00000000003B8BC0 Thread Id = 1 1638 0.219644256 : `GC` CreateHandle: 00000000002613F0 1638 0.219643209 : `GC` CreateHandle: 00000000002615F8 1d9c 0.200751492 : `CORDB`ALWAYS` Debugger Thread spinning up ------------ Last message from thread 1d9c ----------- 1638 0.187761783 : `GC` CreateHandle: 00000000002613F8 1638 0.187758151 : `GC` CreateHandle: 00000000002611F8 ------------ Last message from thread 1638 ----------- ---------------------------- 625 total entries ------------------------------------ |
可以看到这个程序最后(注意Log的最前面是程序最后发生的事情,是反过来的)抛出了一个System.ApplicationException, HR=0x80131600,导致程序终止。当然了,实际的情况会比这个复杂得多,这里只是一个例子而已。这些信息详细说明了CLR的运行情况,主要供CLR小组的开发人员使用。但是这并不意味着这些信息对于一般.NET开发人员没有用处,其实这些信息对于了解托管程序的运行状况是很有用的,并且如果运行中出现了错误,这些错误也会被写到StressLog中。当然了,解决一般的问题也许并不需要使用StressLog,但是如果你手头的问题没有任何线索可循,不妨试一下StressLog,也许会有意想不到的效果。如果想对某条有疑问的具体信息进行解读,除了参考错误信息之外,也可以在Rotor代码中查找相应代码行,从而确定大概是什么意思。比如AppDomain::Unload方法中可以查找到STRESS_LOG宏输出了Unload domain这条信息:
1: void AppDomain::Unload(BOOL fForceUnload)
2: {
3: …
4: STRESS_LOG3 (LF_APPDOMAIN, LL_INFO100, “Unload domain [%d, %d] %p\n”, GetId().m_dwId, GetIndex().m_dwIndex, this);
5: …
6: }
不过注意不是所有信息都可以在Rotor中查找到,因为Rotor中并不包含所有CLR 2.0的代码。
获得StressLog的方法如下:
1. 在命令行中输入:set COMPLUS_StressLog=1
2. 在命令行中启动WinDbg,然后通过WinDbg开始调试程序,直到程序运行到出问题的地方
3. 在WinDbg中输入:.loadby sos mscorwks。这一步骤是用来加载SOS的。SOS是一个用来调试CLR的一个WinDbg的Extension,有机会我会专门写篇文章讲用SOS来调试托管程序,CLR小组内部调试托管程序很多时候都用这个。
4. 在WinDbg中输入!DumpLog
5. 在程序启动的目录下查找StressLog.txt文件,StressLog信息就在里面了
第一步第二步也可以在HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\.NETFramework建立一个DWORD类型的名为StressLog的值,设置为1也可以,只是效果是全局的,不如set COMPLUS_StressLog灵活。