1 | // Licensed to the .NET Foundation under one or more agreements. |
2 | // The .NET Foundation licenses this file to you under the MIT license. |
3 | // See the LICENSE file in the project root for more information. |
4 | |
5 | |
6 | /*************************************************************************************/ |
7 | /* StressLog.h */ |
8 | /*************************************************************************************/ |
9 | |
10 | /* StressLog is a binary, memory based circular queue of logging messages. It is |
11 | intended to be used in retail builds during stress runs (activated |
12 | by registry key), so to help find bugs that only turn up during stress runs. |
13 | |
14 | It is meant to have very low overhead and can not cause deadlocks, etc. It is |
15 | however thread safe */ |
16 | |
17 | /* The log has a very simple structure, and it meant to be dumped from a NTSD |
18 | extention (eg. strike). There is no memory allocation system calls etc to purtub things */ |
19 | |
20 | /* see the tools/strike/stressdump.cpp for the dumper utility that parses this log */ |
21 | |
22 | /*************************************************************************************/ |
23 | |
24 | #ifndef StressLog_h |
25 | #define StressLog_h 1 |
26 | |
27 | #include "log.h" |
28 | |
29 | #if defined(STRESS_LOG) && !defined(FEATURE_NO_STRESSLOG) |
30 | #include "holder.h" |
31 | #include "staticcontract.h" |
32 | #include "mscoree.h" |
33 | #include "clrinternal.h" |
34 | #ifdef STRESS_LOG_READONLY |
35 | #include <stddef.h> // offsetof |
36 | #else //STRESS_LOG_READONLY |
37 | #include "clrhost.h" |
38 | #endif //STRESS_LOG_READONLY |
39 | |
40 | #ifndef _ASSERTE |
41 | #define _ASSERTE(expr) |
42 | #endif |
43 | |
44 | /* The STRESS_LOG* macros work like printf. In fact the use printf in their implementation |
45 | so all printf format specifications work. In addition the Stress log dumper knows |
46 | about certain suffixes for the %p format specification (normally used to print a pointer) |
47 | |
48 | %pM // The pointer is a MethodDesc |
49 | %pT // The pointer is a type (MethodTable) |
50 | %pV // The pointer is a C++ Vtable pointer (useful for distinguishing different types of frames |
51 | %pK // The pointer is a code address (used for stack track) |
52 | */ |
53 | |
54 | /* STRESS_LOG_VA was added to allow sendign GC trace output to the stress log. msg must be enclosed |
55 | in ()'s and contain a format string followed by 0 - 4 arguments. The arguments must be numbers or |
56 | string literals. LogMsgOL is overloaded so that all of the possible sets of parameters are covered. |
57 | This was done becasue GC Trace uses dprintf which dosen't contain info on how many arguments are |
58 | getting passed in and using va_args would require parsing the format string during the GC |
59 | */ |
60 | #define STRESS_LOG_VA(msg) do { \ |
61 | if (StressLog::LogOn(LF_GC, LL_ALWAYS)) \ |
62 | StressLog::LogMsgOL msg; \ |
63 | LogSpewAlways msg; \ |
64 | } while(0) |
65 | |
66 | #define STRESS_LOG0(facility, level, msg) do { \ |
67 | if (StressLog::LogOn(facility, level)) \ |
68 | StressLog::LogMsg(level, facility, 0, msg); \ |
69 | LOG((facility, level, msg)); \ |
70 | } while(0) |
71 | |
72 | #define STRESS_LOG1(facility, level, msg, data1) do { \ |
73 | if (StressLog::LogOn(facility, level)) \ |
74 | StressLog::LogMsg(level, facility, 1, msg, (void*)(size_t)(data1));\ |
75 | LOG((facility, level, msg, data1)); \ |
76 | } while(0) |
77 | |
78 | #define STRESS_LOG2(facility, level, msg, data1, data2) do { \ |
79 | if (StressLog::LogOn(facility, level)) \ |
80 | StressLog::LogMsg(level, facility, 2, msg, \ |
81 | (void*)(size_t)(data1), (void*)(size_t)(data2)); \ |
82 | LOG((facility, level, msg, data1, data2)); \ |
83 | } while(0) |
84 | |
85 | #define STRESS_LOG2_CHECK_EE_STARTED(facility, level, msg, data1, data2) do { \ |
86 | if (g_fEEStarted) \ |
87 | STRESS_LOG2(facility, level, msg, data1, data2); \ |
88 | else \ |
89 | LOG((facility, level, msg, data1, data2)); \ |
90 | } while(0) |
91 | |
92 | #define STRESS_LOG3(facility, level, msg, data1, data2, data3) do { \ |
93 | if (StressLog::LogOn(facility, level)) \ |
94 | StressLog::LogMsg(level, facility, 3, msg, \ |
95 | (void*)(size_t)(data1),(void*)(size_t)(data2),(void*)(size_t)(data3)); \ |
96 | LOG((facility, level, msg, data1, data2, data3)); \ |
97 | } while(0) |
98 | |
99 | #define STRESS_LOG4(facility, level, msg, data1, data2, data3, data4) do { \ |
100 | if (StressLog::LogOn(facility, level)) \ |
101 | StressLog::LogMsg(level, facility, 4, msg, (void*)(size_t)(data1), \ |
102 | (void*)(size_t)(data2),(void*)(size_t)(data3),(void*)(size_t)(data4)); \ |
103 | LOG((facility, level, msg, data1, data2, data3, data4)); \ |
104 | } while(0) |
105 | |
106 | #define STRESS_LOG5(facility, level, msg, data1, data2, data3, data4, data5) do { \ |
107 | if (StressLog::LogOn(facility, level)) \ |
108 | StressLog::LogMsg(level, facility, 5, msg, (void*)(size_t)(data1), \ |
109 | (void*)(size_t)(data2),(void*)(size_t)(data3),(void*)(size_t)(data4), \ |
110 | (void*)(size_t)(data5)); \ |
111 | LOG((facility, level, msg, data1, data2, data3, data4, data5)); \ |
112 | } while(0) |
113 | |
114 | #define STRESS_LOG6(facility, level, msg, data1, data2, data3, data4, data5, data6) do { \ |
115 | if (StressLog::LogOn(facility, level)) \ |
116 | StressLog::LogMsg(level, facility, 6, msg, (void*)(size_t)(data1), \ |
117 | (void*)(size_t)(data2),(void*)(size_t)(data3),(void*)(size_t)(data4), \ |
118 | (void*)(size_t)(data5), (void*)(size_t)(data6)); \ |
119 | LOG((facility, level, msg, data1, data2, data3, data4, data5, data6)); \ |
120 | } while(0) |
121 | |
122 | #define STRESS_LOG7(facility, level, msg, data1, data2, data3, data4, data5, data6, data7) do { \ |
123 | if (StressLog::LogOn(facility, level)) \ |
124 | StressLog::LogMsg(level, facility, 7, msg, (void*)(size_t)(data1), \ |
125 | (void*)(size_t)(data2),(void*)(size_t)(data3),(void*)(size_t)(data4), \ |
126 | (void*)(size_t)(data5), (void*)(size_t)(data6), (void*)(size_t)(data7)); \ |
127 | LOG((facility, level, msg, data1, data2, data3, data4, data5, data6, data7)); \ |
128 | } while(0) |
129 | |
130 | #define STRESS_LOG_COND0(facility, level, msg) do { \ |
131 | if (StressLog::LogOn(facility, level) && (cond)) \ |
132 | StressLog::LogMsg(level, facility, 0, msg); \ |
133 | LOG((facility, level, msg)); \ |
134 | } while(0) |
135 | |
136 | #define STRESS_LOG_COND1(facility, level, cond, msg, data1) do { \ |
137 | if (StressLog::LogOn(facility, level) && (cond)) \ |
138 | StressLog::LogMsg(level, facility, 1, msg, (void*)(size_t)(data1)); \ |
139 | LOG((facility, level, msg, data1)); \ |
140 | } while(0) |
141 | |
142 | #define STRESS_LOG_COND2(facility, level, cond, msg, data1, data2) do { \ |
143 | if (StressLog::LogOn(facility, level) && (cond)) \ |
144 | StressLog::LogMsg(level, facility, 2, msg, \ |
145 | (void*)(size_t)(data1), (void*)(size_t)(data2)); \ |
146 | LOG((facility, level, msg, data1, data2)); \ |
147 | } while(0) |
148 | |
149 | #define STRESS_LOG_COND3(facility, level, cond, msg, data1, data2, data3) do { \ |
150 | if (StressLog::LogOn(facility, level) && (cond)) \ |
151 | StressLog::LogMsg(level, facility, 3, msg, \ |
152 | (void*)(size_t)(data1),(void*)(size_t)(data2),(void*)(size_t)(data3)); \ |
153 | LOG((facility, level, msg, data1, data2, data3)); \ |
154 | } while(0) |
155 | |
156 | #define STRESS_LOG_COND4(facility, level, cond, msg, data1, data2, data3, data4) do { \ |
157 | if (StressLog::LogOn(facility, level) && (cond)) \ |
158 | StressLog::LogMsg(level, facility, 4, msg, (void*)(size_t)(data1), \ |
159 | (void*)(size_t)(data2),(void*)(size_t)(data3),(void*)(size_t)(data4)); \ |
160 | LOG((facility, level, msg, data1, data2, data3, data4)); \ |
161 | } while(0) |
162 | |
163 | #define STRESS_LOG_COND5(facility, level, cond, msg, data1, data2, data3, data4, data5) do { \ |
164 | if (StressLog::LogOn(facility, level) && (cond)) \ |
165 | StressLog::LogMsg(level, facility, 5, msg, (void*)(size_t)(data1), \ |
166 | (void*)(size_t)(data2),(void*)(size_t)(data3),(void*)(size_t)(data4), \ |
167 | (void*)(size_t)(data5)); \ |
168 | LOG((facility, level, msg, data1, data2, data3, data4, data5)); \ |
169 | } while(0) |
170 | |
171 | #define STRESS_LOG_COND6(facility, level, cond, msg, data1, data2, data3, data4, data5, data6) do { \ |
172 | if (StressLog::LogOn(facility, level) && (cond)) \ |
173 | StressLog::LogMsg(level, facility, 6, msg, (void*)(size_t)(data1), \ |
174 | (void*)(size_t)(data2),(void*)(size_t)(data3),(void*)(size_t)(data4), \ |
175 | (void*)(size_t)(data5), (void*)(size_t)(data6)); \ |
176 | LOG((facility, level, msg, data1, data2, data3, data4, data5, data6)); \ |
177 | } while(0) |
178 | |
179 | #define STRESS_LOG_COND7(facility, level, cond, msg, data1, data2, data3, data4, data5, data6, data7) do { \ |
180 | if (StressLog::LogOn(facility, level) && (cond)) \ |
181 | StressLog::LogMsg(level, facility, 7, msg, (void*)(size_t)(data1), \ |
182 | (void*)(size_t)(data2),(void*)(size_t)(data3),(void*)(size_t)(data4), \ |
183 | (void*)(size_t)(data5), (void*)(size_t)(data6), (void*)(size_t)(data7)); \ |
184 | LOG((facility, level, msg, data1, data2, data3, data4, data5, data6, data7)); \ |
185 | } while(0) |
186 | |
187 | #define STRESS_LOG_RESERVE_MEM(numChunks) do { \ |
188 | if (StressLog::StressLogOn(LF_ALL, LL_ALWAYS)) \ |
189 | {StressLog::ReserveStressLogChunks (numChunks);} \ |
190 | } while(0) |
191 | // !!! WARNING !!! |
192 | // !!! DO NOT ADD STRESS_LOG8, as the stress log infrastructure supports a maximum of 7 arguments |
193 | // !!! WARNING !!! |
194 | |
195 | #define STRESS_LOG_PLUG_MOVE(plug_start, plug_end, plug_delta) do { \ |
196 | if (StressLog::LogOn(LF_GC, LL_INFO1000)) \ |
197 | StressLog::LogMsg(LL_INFO1000, LF_GC, 3, ThreadStressLog::gcPlugMoveMsg(), \ |
198 | (void*)(size_t)(plug_start), (void*)(size_t)(plug_end), (void*)(size_t)(plug_delta)); \ |
199 | LOG((LF_GC, LL_INFO10000, ThreadStressLog::gcPlugMoveMsg(), (plug_start), (plug_end), (plug_delta))); \ |
200 | } while(0) |
201 | |
202 | #define STRESS_LOG_ROOT_PROMOTE(root_addr, objPtr, methodTable) do { \ |
203 | if (StressLog::LogOn(LF_GC|LF_GCROOTS, LL_INFO1000)) \ |
204 | StressLog::LogMsg(LL_INFO1000, LF_GC|LF_GCROOTS, 3, ThreadStressLog::gcRootPromoteMsg(), \ |
205 | (void*)(size_t)(root_addr), (void*)(size_t)(objPtr), (void*)(size_t)(methodTable)); \ |
206 | LOG((LF_GC|LF_GCROOTS, LL_INFO1000000, ThreadStressLog::gcRootPromoteMsg(), (root_addr), (objPtr), (methodTable))); \ |
207 | } while(0) |
208 | |
209 | #define STRESS_LOG_ROOT_RELOCATE(root_addr, old_value, new_value, methodTable) do { \ |
210 | if (StressLog::LogOn(LF_GC|LF_GCROOTS, LL_INFO1000) && ((size_t)(old_value) != (size_t)(new_value))) \ |
211 | StressLog::LogMsg(LL_INFO1000, LF_GC|LF_GCROOTS, 4, ThreadStressLog::gcRootMsg(), \ |
212 | (void*)(size_t)(root_addr), (void*)(size_t)(old_value), \ |
213 | (void*)(size_t)(new_value), (void*)(size_t)(methodTable)); \ |
214 | LOG((LF_GC|LF_GCROOTS, LL_INFO10000, ThreadStressLog::gcRootMsg(), (root_addr), (old_value), (new_value), (methodTable))); \ |
215 | } while(0) |
216 | |
217 | #define STRESS_LOG_GC_START(gcCount, Gen, collectClasses) do { \ |
218 | if (StressLog::LogOn(LF_GCROOTS|LF_GC|LF_GCALLOC, LL_INFO10)) \ |
219 | StressLog::LogMsg(LL_INFO10, LF_GCROOTS|LF_GC|LF_GCALLOC, 3, ThreadStressLog::gcStartMsg(), \ |
220 | (void*)(size_t)(gcCount), (void*)(size_t)(Gen), (void*)(size_t)(collectClasses)); \ |
221 | LOG((LF_GCROOTS|LF_GC|LF_GCALLOC, LL_INFO10, ThreadStressLog::gcStartMsg(), (gcCount), (Gen), (collectClasses))); \ |
222 | } while(0) |
223 | |
224 | #define STRESS_LOG_GC_END(gcCount, Gen, collectClasses) do { \ |
225 | if (StressLog::LogOn(LF_GCROOTS|LF_GC|LF_GCALLOC, LL_INFO10)) \ |
226 | StressLog::LogMsg(LL_INFO10, LF_GCROOTS|LF_GC|LF_GCALLOC, 3, ThreadStressLog::gcEndMsg(), \ |
227 | (void*)(size_t)(gcCount), (void*)(size_t)(Gen), (void*)(size_t)(collectClasses), 0); \ |
228 | LOG((LF_GCROOTS|LF_GC|LF_GCALLOC, LL_INFO10, ThreadStressLog::gcEndMsg(), (gcCount), (Gen), (collectClasses))); \ |
229 | } while(0) |
230 | |
231 | #if defined(_DEBUG) |
232 | #define MAX_CALL_STACK_TRACE 20 |
233 | #define STRESS_LOG_OOM_STACK(size) do { \ |
234 | CantAllocHolder caHolder; \ |
235 | if (StressLog::LogOn(LF_EEMEM, LL_ALWAYS)) \ |
236 | { \ |
237 | StressLog::LogMsgOL("OOM on alloc of size %x \n", (void*)(size_t)(size)); \ |
238 | StressLog::LogCallStack ("OOM"); \ |
239 | } \ |
240 | } while(0) |
241 | #define STRESS_LOG_GC_STACK do { \ |
242 | if (StressLog::LogOn(LF_GC |LF_GCINFO, LL_ALWAYS)) \ |
243 | { \ |
244 | StressLog::LogMsgOL("GC is triggered \n"); \ |
245 | StressLog::LogCallStack ("GC"); \ |
246 | } \ |
247 | } while(0) |
248 | |
249 | #else //!_DEBUG |
250 | #define STRESS_LOG_OOM_STACK(size) |
251 | #define STRESS_LOG_GC_STACK |
252 | #endif //_DEBUG |
253 | |
254 | class ThreadStressLog; |
255 | |
256 | /*************************************************************************************/ |
257 | /* a log is a circular queue of messages */ |
258 | |
259 | class StressLog { |
260 | public: |
261 | static void Initialize(unsigned facilities, unsigned level, unsigned maxBytesPerThread, |
262 | unsigned maxBytesTotal, HMODULE hMod); |
263 | static void Terminate(BOOL fProcessDetach=FALSE); |
264 | static void ThreadDetach(ThreadStressLog *msgs); // call at DllMain THREAD_DETACH if you want to recycle thread logs |
265 | static int NewChunk () |
266 | { |
267 | return InterlockedIncrement (&theLog.totalChunk); |
268 | } |
269 | static int ChunkDeleted () |
270 | { |
271 | return InterlockedDecrement (&theLog.totalChunk); |
272 | } |
273 | |
274 | //the result is not 100% accurate. If multiple threads call this funciton at the same time, |
275 | //we could allow the total size be bigger than required. But the memory won't grow forever |
276 | //and this is not critical so we don't try to fix the race |
277 | static BOOL AllowNewChunk (LONG numChunksInCurThread); |
278 | |
279 | //preallocate Stress log chunks for current thread. The memory we could preallocate is still |
280 | //bounded by per thread size limit and total size limit. If chunksToReserve is 0, we will try to |
281 | //preallocate up to per thread size limit |
282 | static BOOL ReserveStressLogChunks (unsigned chunksToReserve); |
283 | |
284 | // used by out of process debugger to dump the stress log to 'fileName' |
285 | // IDebugDataSpaces is the NTSD execution callback for getting process memory. |
286 | // This function is defined in the tools\strike\stressLogDump.cpp file |
287 | static HRESULT Dump(ULONG64 logAddr, const char* fileName, struct IDebugDataSpaces* memCallBack); |
288 | |
289 | static BOOL StressLogOn(unsigned facility, unsigned level); |
290 | static BOOL ETWLogOn(unsigned facility, unsigned level); |
291 | static BOOL LogOn(unsigned facility, unsigned level); |
292 | |
293 | // private: |
294 | unsigned facilitiesToLog; // Bitvector of facilities to log (see loglf.h) |
295 | unsigned levelToLog; // log level (see log.h) |
296 | unsigned MaxSizePerThread; // maximum number of bytes each thread should have before wrapping |
297 | unsigned MaxSizeTotal; //maximum memory allowed for stress log |
298 | Volatile<LONG> totalChunk; //current number of total chunks allocated |
299 | Volatile<ThreadStressLog*> logs; // the list of logs for every thread. |
300 | Volatile<unsigned> TLSslot; // Each thread gets a log this is used to fetch each threads log |
301 | Volatile<LONG> deadCount; // count of dead threads in the log |
302 | CRITSEC_COOKIE lock; // lock |
303 | unsigned __int64 tickFrequency; // number of ticks per second |
304 | unsigned __int64 startTimeStamp; // start time from when tick counter started |
305 | FILETIME startTime; // time the application started |
306 | SIZE_T moduleOffset; // Used to compute format strings. |
307 | |
308 | // private: |
309 | static void Enter(CRITSEC_COOKIE dummy = NULL); |
310 | static void Leave(CRITSEC_COOKIE dummy = NULL); |
311 | static ThreadStressLog* CreateThreadStressLog(); |
312 | static ThreadStressLog* CreateThreadStressLogHelper(); |
313 | |
314 | static BOOL InlinedStressLogOn(unsigned facility, unsigned level); |
315 | static BOOL InlinedETWLogOn(unsigned facility, unsigned level); |
316 | |
317 | static void LogMsg(unsigned level, unsigned facility, int cArgs, const char* format, ... ); |
318 | |
319 | // Support functions for STRESS_LOG_VA |
320 | // We disable the warning "conversion from 'type' to 'type' of greater size" since everything will |
321 | // end up on the stack, and LogMsg will know the size of the variable based on the format string. |
322 | #ifdef _MSC_VER |
323 | #pragma warning( push ) |
324 | #pragma warning( disable : 4312 ) |
325 | #endif |
326 | static void LogMsgOL(const char* format) |
327 | { LogMsg(LL_ALWAYS, LF_GC, 0, format); } |
328 | |
329 | template < typename T1 > |
330 | static void LogMsgOL(const char* format, T1 data1) |
331 | { |
332 | static_assert_no_msg(sizeof(T1) <= sizeof(void*)); |
333 | LogMsg(LL_ALWAYS, LF_GC, 1, format, (void*)(size_t)data1); |
334 | } |
335 | |
336 | template < typename T1, typename T2 > |
337 | static void LogMsgOL(const char* format, T1 data1, T2 data2) |
338 | { |
339 | static_assert_no_msg(sizeof(T1) <= sizeof(void*) && sizeof(T2) <= sizeof(void*)); |
340 | LogMsg(LL_ALWAYS, LF_GC, 2, format, (void*)(size_t)data1, (void*)(size_t)data2); |
341 | } |
342 | |
343 | template < typename T1, typename T2, typename T3 > |
344 | static void LogMsgOL(const char* format, T1 data1, T2 data2, T3 data3) |
345 | { |
346 | static_assert_no_msg(sizeof(T1) <= sizeof(void*) && sizeof(T2) <= sizeof(void*) && sizeof(T3) <= sizeof(void*)); |
347 | LogMsg(LL_ALWAYS, LF_GC, 3, format, (void*)(size_t)data1, (void*)(size_t)data2, (void*)(size_t)data3); |
348 | } |
349 | |
350 | template < typename T1, typename T2, typename T3, typename T4 > |
351 | static void LogMsgOL(const char* format, T1 data1, T2 data2, T3 data3, T4 data4) |
352 | { |
353 | static_assert_no_msg(sizeof(T1) <= sizeof(void*) && sizeof(T2) <= sizeof(void*) && sizeof(T3) <= sizeof(void*) && sizeof(T4) <= sizeof(void*)); |
354 | LogMsg(LL_ALWAYS, LF_GC, 4, format, (void*)(size_t)data1, (void*)(size_t)data2, (void*)(size_t)data3, (void*)(size_t)data4); |
355 | } |
356 | |
357 | template < typename T1, typename T2, typename T3, typename T4, typename T5 > |
358 | static void LogMsgOL(const char* format, T1 data1, T2 data2, T3 data3, T4 data4, T5 data5) |
359 | { |
360 | static_assert_no_msg(sizeof(T1) <= sizeof(void*) && sizeof(T2) <= sizeof(void*) && sizeof(T3) <= sizeof(void*) && sizeof(T4) <= sizeof(void*) && sizeof(T5) <= sizeof(void*)); |
361 | LogMsg(LL_ALWAYS, LF_GC, 5, format, (void*)(size_t)data1, (void*)(size_t)data2, (void*)(size_t)data3, (void*)(size_t)data4, (void*)(size_t)data5); |
362 | } |
363 | |
364 | template < typename T1, typename T2, typename T3, typename T4, typename T5, typename T6 > |
365 | static void LogMsgOL(const char* format, T1 data1, T2 data2, T3 data3, T4 data4, T5 data5, T6 data6) |
366 | { |
367 | static_assert_no_msg(sizeof(T1) <= sizeof(void*) && sizeof(T2) <= sizeof(void*) && sizeof(T3) <= sizeof(void*) && sizeof(T4) <= sizeof(void*) && sizeof(T5) <= sizeof(void*) && sizeof(T6) <= sizeof(void*)); |
368 | LogMsg(LL_ALWAYS, LF_GC, 6, format, (void*)(size_t)data1, (void*)(size_t)data2, (void*)(size_t)data3, (void*)(size_t)data4, (void*)(size_t)data5, (void*)(size_t)data6); |
369 | } |
370 | |
371 | template < typename T1, typename T2, typename T3, typename T4, typename T5, typename T6, typename T7 > |
372 | static void LogMsgOL(const char* format, T1 data1, T2 data2, T3 data3, T4 data4, T5 data5, T6 data6, T7 data7) |
373 | { |
374 | static_assert_no_msg(sizeof(T1) <= sizeof(void*) && sizeof(T2) <= sizeof(void*) && sizeof(T3) <= sizeof(void*) && sizeof(T4) <= sizeof(void*) && sizeof(T5) <= sizeof(void*) && sizeof(T6) <= sizeof(void*) && sizeof(T7) <= sizeof(void*)); |
375 | LogMsg(LL_ALWAYS, LF_GC, 7, format, (void*)(size_t)data1, (void*)(size_t)data2, (void*)(size_t)data3, (void*)(size_t)data4, (void*)(size_t)data5, (void*)(size_t)data6, (void*)(size_t)data7); |
376 | } |
377 | |
378 | #ifdef _MSC_VER |
379 | #pragma warning( pop ) |
380 | #endif |
381 | |
382 | // We can only log the stacktrace on DEBUG builds! |
383 | #ifdef _DEBUG |
384 | typedef USHORT |
385 | (__stdcall *PFNRtlCaptureStackBackTrace)( |
386 | IN ULONG FramesToSkip, |
387 | IN ULONG FramesToCapture, |
388 | OUT PVOID * BackTrace, |
389 | OUT PULONG BackTraceHash); |
390 | |
391 | PFNRtlCaptureStackBackTrace RtlCaptureStackBackTrace; |
392 | |
393 | static void LogCallStack(const char *const callTag); |
394 | #endif //_DEBUG |
395 | |
396 | // private: // static variables |
397 | static StressLog theLog; // We only have one log, and this is it |
398 | }; |
399 | |
400 | typedef Holder<CRITSEC_COOKIE, StressLog::Enter, StressLog::Leave, NULL, CompareDefault<CRITSEC_COOKIE>, HSV_NoValidation> StressLogLockHolder; |
401 | |
402 | #if defined(DACCESS_COMPILE) |
403 | inline BOOL StressLog::LogOn(unsigned facility, unsigned level) |
404 | { |
405 | STATIC_CONTRACT_LEAF; |
406 | STATIC_CONTRACT_SUPPORTS_DAC; |
407 | |
408 | // StressLog isn't dacized, and besides we don't want to log to it in DAC builds. |
409 | return FALSE; |
410 | } |
411 | #endif |
412 | |
413 | /*************************************************************************************/ |
414 | /* private classes */ |
415 | |
416 | #if defined(_MSC_VER) |
417 | #pragma warning(disable:4200 4201) // don't warn about 0 sized array below or unnamed structures |
418 | #endif |
419 | |
420 | // The order of fields is important. Keep the prefix length as the first field. |
421 | // And make sure the timeStamp field is naturally alligned, so we don't waste |
422 | // space on 32-bit platforms |
423 | struct StressMsg { |
424 | union { |
425 | struct { |
426 | uint32_t numberOfArgs : 3; // at most 7 arguments |
427 | uint32_t formatOffset : 29; // offset of string in mscorwks |
428 | }; |
429 | uint32_t fmtOffsCArgs; // for optimized access |
430 | }; |
431 | uint32_t facility; // facility used to log the entry |
432 | uint64_t timeStamp; // time when mssg was logged |
433 | void* args[0]; // size given by numberOfArgs |
434 | |
435 | static const size_t maxArgCnt = 7; |
436 | static const size_t maxOffset = 0x20000000; |
437 | static size_t maxMsgSize () |
438 | { return sizeof(StressMsg) + maxArgCnt*sizeof(void*); } |
439 | |
440 | friend class ThreadStressLog; |
441 | friend class StressLog; |
442 | }; |
443 | #ifdef _WIN64 |
444 | #define STRESSLOG_CHUNK_SIZE (32 * 1024) |
445 | #else //_WIN64 |
446 | #define STRESSLOG_CHUNK_SIZE (16 * 1024) |
447 | #endif //_WIN64 |
448 | #define GC_STRESSLOG_MULTIPLY 5 |
449 | |
450 | // a chunk of memory for stress log |
451 | struct StressLogChunk |
452 | { |
453 | StressLogChunk * prev; |
454 | StressLogChunk * next; |
455 | char buf[STRESSLOG_CHUNK_SIZE]; |
456 | DWORD dwSig1; |
457 | DWORD dwSig2; |
458 | |
459 | #if !defined(STRESS_LOG_READONLY) |
460 | static HANDLE s_LogChunkHeap; |
461 | |
462 | void * operator new (size_t) throw() |
463 | { |
464 | if (IsInCantAllocStressLogRegion ()) |
465 | { |
466 | return NULL; |
467 | } |
468 | |
469 | _ASSERTE (s_LogChunkHeap != NULL); |
470 | //no need to zero memory because we could handle garbage contents |
471 | return ClrHeapAlloc (s_LogChunkHeap, 0, S_SIZE_T(sizeof (StressLogChunk))); |
472 | } |
473 | |
474 | void operator delete (void * chunk) |
475 | { |
476 | _ASSERTE (s_LogChunkHeap != NULL); |
477 | ClrHeapFree (s_LogChunkHeap, 0, chunk); |
478 | } |
479 | #endif //!STRESS_LOG_READONLY |
480 | |
481 | StressLogChunk (StressLogChunk * p = NULL, StressLogChunk * n = NULL) |
482 | :prev (p), next (n), dwSig1 (0xCFCFCFCF), dwSig2 (0xCFCFCFCF) |
483 | {} |
484 | |
485 | char * StartPtr () |
486 | { |
487 | return buf; |
488 | } |
489 | |
490 | char * EndPtr () |
491 | { |
492 | return buf + STRESSLOG_CHUNK_SIZE; |
493 | } |
494 | |
495 | BOOL IsValid () const |
496 | { |
497 | return dwSig1 == 0xCFCFCFCF && dwSig2 == 0xCFCFCFCF; |
498 | } |
499 | }; |
500 | |
501 | // This class implements a circular stack of variable sized elements |
502 | // .The buffer between startPtr-endPtr is used in a circular manner |
503 | // to store instances of the variable-sized struct StressMsg. |
504 | // The StressMsg are always aligned to endPtr, while the space |
505 | // left between startPtr and the last element is 0-padded. |
506 | // .curPtr points to the most recently written log message |
507 | // .readPtr points to the next log message to be dumped |
508 | // .hasWrapped is TRUE while dumping the log, if we had wrapped |
509 | // past the endPtr marker, back to startPtr |
510 | // The AdvanceRead/AdvanceWrite operations simply update the |
511 | // readPtr / curPtr fields. thecaller is responsible for reading/writing |
512 | // to the corresponding field |
513 | class ThreadStressLog { |
514 | ThreadStressLog* next; // we keep a linked list of these |
515 | uint64_t threadId; // the id for the thread using this buffer |
516 | uint8_t isDead; // Is this thread dead |
517 | uint8_t readHasWrapped; // set when read ptr has passed chunListTail |
518 | uint8_t writeHasWrapped; // set when write ptr has passed chunListHead |
519 | StressMsg* curPtr; // where packets are being put on the queue |
520 | StressMsg* readPtr; // where we are reading off the queue (used during dumping) |
521 | StressLogChunk * chunkListHead; //head of a list of stress log chunks |
522 | StressLogChunk * chunkListTail; //tail of a list of stress log chunks |
523 | StressLogChunk * curReadChunk; //the stress log chunk we are currently reading |
524 | StressLogChunk * curWriteChunk; //the stress log chunk we are currently writing |
525 | long chunkListLength; // how many stress log chunks are in this stress log |
526 | |
527 | #ifdef STRESS_LOG_READONLY |
528 | FORCEINLINE StressMsg* AdvanceRead(); |
529 | #endif //STRESS_LOG_READONLY |
530 | FORCEINLINE StressMsg* AdvanceWrite(int cArgs); |
531 | |
532 | #ifdef STRESS_LOG_READONLY |
533 | inline StressMsg* AdvReadPastBoundary(); |
534 | #endif //STRESS_LOG_READONLY |
535 | inline StressMsg* AdvWritePastBoundary(int cArgs); |
536 | |
537 | #ifdef STRESS_LOG_READONLY |
538 | ThreadStressLog* FindLatestThreadLog() const; |
539 | #endif //STRESS_LOG_READONLY |
540 | friend class StressLog; |
541 | |
542 | #ifndef STRESS_LOG_READONLY |
543 | FORCEINLINE BOOL GrowChunkList () |
544 | { |
545 | _ASSERTE (chunkListLength >= 1); |
546 | if (!StressLog::AllowNewChunk (chunkListLength)) |
547 | { |
548 | return FALSE; |
549 | } |
550 | StressLogChunk * newChunk = new StressLogChunk (chunkListTail, chunkListHead); |
551 | if (newChunk == NULL) |
552 | { |
553 | return FALSE; |
554 | } |
555 | StressLog::NewChunk (); |
556 | chunkListLength++; |
557 | chunkListHead->prev = newChunk; |
558 | chunkListTail->next = newChunk; |
559 | chunkListHead = newChunk; |
560 | |
561 | return TRUE; |
562 | } |
563 | #endif //!STRESS_LOG_READONLY |
564 | |
565 | public: |
566 | #ifndef STRESS_LOG_READONLY |
567 | ThreadStressLog () |
568 | { |
569 | chunkListHead = chunkListTail = curWriteChunk = NULL; |
570 | StressLogChunk * newChunk =new StressLogChunk; |
571 | //OOM or in cantalloc region |
572 | if (newChunk == NULL) |
573 | { |
574 | return; |
575 | } |
576 | StressLog::NewChunk (); |
577 | |
578 | newChunk->prev = newChunk; |
579 | newChunk->next = newChunk; |
580 | |
581 | chunkListHead = chunkListTail = newChunk; |
582 | |
583 | next = NULL; |
584 | threadId = 0; |
585 | isDead = TRUE; |
586 | curPtr = NULL; |
587 | readPtr = NULL; |
588 | writeHasWrapped = FALSE; |
589 | curReadChunk = NULL; |
590 | curWriteChunk = NULL; |
591 | chunkListLength = 1; |
592 | } |
593 | |
594 | #endif //!STRESS_LOG_READONLY |
595 | ~ThreadStressLog () |
596 | { |
597 | //no thing to do if the list is empty (failed to initialize) |
598 | if (chunkListHead == NULL) |
599 | { |
600 | return; |
601 | } |
602 | #ifndef STRESS_LOG_READONLY |
603 | _ASSERTE (chunkListLength >= 1 && chunkListLength <= StressLog::theLog.totalChunk); |
604 | #endif //!STRESS_LOG_READONLY |
605 | StressLogChunk * chunk = chunkListHead; |
606 | |
607 | do |
608 | { |
609 | StressLogChunk * tmp = chunk; |
610 | chunk = chunk->next; |
611 | delete tmp; |
612 | #ifndef STRESS_LOG_READONLY |
613 | StressLog::ChunkDeleted (); |
614 | #endif //!STRESS_LOG_READONLY |
615 | } while (chunk != chunkListHead); |
616 | } |
617 | |
618 | void Activate () |
619 | { |
620 | #ifndef STRESS_LOG_READONLY |
621 | //there is no need to zero buffers because we could handle garbage contents |
622 | threadId = GetCurrentThreadId (); |
623 | isDead = FALSE; |
624 | curWriteChunk = chunkListTail; |
625 | curPtr = (StressMsg *)curWriteChunk->EndPtr (); |
626 | writeHasWrapped = FALSE; |
627 | #else //STRESS_LOG_READONLY |
628 | curReadChunk = curWriteChunk; |
629 | readPtr = curPtr; |
630 | readHasWrapped = FALSE; |
631 | // the last written log, if it wrapped around may have partially overwritten |
632 | // a previous record. Update curPtr to reflect the last safe beginning of a record, |
633 | // but curPtr shouldn't wrap around, otherwise it'll break our assumptions about stress |
634 | // log |
635 | curPtr = (StressMsg*)((char*)curPtr - StressMsg::maxMsgSize()); |
636 | if (curPtr < (StressMsg*)curWriteChunk->StartPtr()) |
637 | { |
638 | curPtr = (StressMsg *)curWriteChunk->StartPtr(); |
639 | } |
640 | //corner case: the log is empty |
641 | if (readPtr == (StressMsg *)curReadChunk->EndPtr ()) |
642 | { |
643 | AdvReadPastBoundary(); |
644 | } |
645 | #endif //!STRESS_LOG_READONLY |
646 | } |
647 | |
648 | BOOL IsValid () const |
649 | { |
650 | return chunkListHead != NULL && (!curWriteChunk || curWriteChunk->IsValid ()); |
651 | } |
652 | |
653 | #ifdef STRESS_LOG_READONLY |
654 | // Called while dumping. Returns true after all messages in log were dumped |
655 | FORCEINLINE BOOL CompletedDump () |
656 | { |
657 | return readPtr->timeStamp == 0 |
658 | //if read has passed end of list but write has not passed head of list yet, we are done |
659 | //if write has also wrapped, we are at the end if read pointer passed write pointer |
660 | || (readHasWrapped && |
661 | (!writeHasWrapped || (curReadChunk == curWriteChunk && readPtr >= curPtr))); |
662 | } |
663 | #endif //STRESS_LOG_READONLY |
664 | |
665 | static const char* gcStartMsg() |
666 | { |
667 | STATIC_CONTRACT_LEAF; |
668 | return "{ =========== BEGINGC %d, (requested generation = %lu, collect_classes = %lu) ==========\n" ; |
669 | } |
670 | |
671 | static const char* gcEndMsg() |
672 | { |
673 | STATIC_CONTRACT_LEAF; |
674 | return "========== ENDGC %d (gen = %lu, collect_classes = %lu) ===========}\n" ; |
675 | } |
676 | |
677 | static const char* gcRootMsg() |
678 | { |
679 | STATIC_CONTRACT_LEAF; |
680 | return " GC Root %p RELOCATED %p -> %p MT = %pT\n" ; |
681 | } |
682 | |
683 | static const char* gcRootPromoteMsg() |
684 | { |
685 | STATIC_CONTRACT_LEAF; |
686 | return " IGCHeap::Promote: Promote GC Root *%p = %p MT = %pT\n" ; |
687 | } |
688 | |
689 | static const char* gcPlugMoveMsg() |
690 | { |
691 | STATIC_CONTRACT_LEAF; |
692 | return "GC_HEAP RELOCATING Objects in heap within range [%p %p) by -0x%x bytes\n" ; |
693 | } |
694 | |
695 | static const char* TaskSwitchMsg() |
696 | { |
697 | STATIC_CONTRACT_LEAF; |
698 | return "StressLog TaskSwitch Marker\n" ; |
699 | } |
700 | |
701 | void LogMsg (unsigned facility, int cArgs, const char* format, ... ) |
702 | { |
703 | va_list Args; |
704 | va_start(Args, format); |
705 | LogMsg (facility, cArgs, format, Args); |
706 | va_end(Args); |
707 | } |
708 | void LogMsg (unsigned facility, int cArgs, const char* format, va_list Args); |
709 | #ifdef STRESS_LOG_READONLY |
710 | static size_t OffsetOfNext () {return offsetof (ThreadStressLog, next);} |
711 | static size_t OffsetOfListHead () {return offsetof (ThreadStressLog, chunkListHead);} |
712 | #endif //STRESS_LOG_READONLY |
713 | }; |
714 | |
715 | #ifdef STRESS_LOG_READONLY |
716 | /*********************************************************************************/ |
717 | // Called when dumping the log (by StressLog::Dump()) |
718 | // Updates readPtr to point to next stress messaage to be dumped |
719 | // For convenience it returns the new value of readPtr |
720 | inline StressMsg* ThreadStressLog::AdvanceRead() { |
721 | STATIC_CONTRACT_LEAF; |
722 | // advance the marker |
723 | readPtr = (StressMsg*)((char*)readPtr + sizeof(StressMsg) + readPtr->numberOfArgs*sizeof(void*)); |
724 | // wrap around if we need to |
725 | if (readPtr >= (StressMsg *)curReadChunk->EndPtr ()) |
726 | { |
727 | AdvReadPastBoundary(); |
728 | } |
729 | return readPtr; |
730 | } |
731 | |
732 | // It's the factored-out slow codepath for AdvanceRead() and |
733 | // is only called by AdvanceRead(). |
734 | // Updates readPtr to and returns the first stress message >= startPtr |
735 | inline StressMsg* ThreadStressLog::AdvReadPastBoundary() { |
736 | STATIC_CONTRACT_LEAF; |
737 | //if we pass boundary of tail list, we need to set has Wrapped |
738 | if (curReadChunk == chunkListTail) |
739 | { |
740 | readHasWrapped = TRUE; |
741 | //If write has not wrapped, we know the contents from list head to |
742 | //cur pointer is garbage, we don't need to read them |
743 | if (!writeHasWrapped) |
744 | { |
745 | return readPtr; |
746 | } |
747 | } |
748 | curReadChunk = curReadChunk->next; |
749 | void** p = (void**)curReadChunk->StartPtr(); |
750 | while (*p == NULL && (size_t)(p-(void**)curReadChunk->StartPtr ()) < (StressMsg::maxMsgSize()/sizeof(void*))) |
751 | { |
752 | ++p; |
753 | } |
754 | // if we failed to find a valid start of a StressMsg fallback to startPtr (since timeStamp==0) |
755 | if (*p == NULL) |
756 | { |
757 | p = (void**) curReadChunk->StartPtr (); |
758 | } |
759 | readPtr = (StressMsg*)p; |
760 | |
761 | return readPtr; |
762 | } |
763 | #endif //STRESS_LOG_READONLY |
764 | /*********************************************************************************/ |
765 | // Called at runtime when writing the log (by StressLog::LogMsg()) |
766 | // Updates curPtr to point to the next spot in the log where we can write |
767 | // a stress message with cArgs arguments |
768 | // For convenience it returns a pointer to the empty slot where we can |
769 | // write the next stress message. |
770 | // cArgs is the number of arguments in the message to be written. |
771 | inline StressMsg* ThreadStressLog::AdvanceWrite(int cArgs) { |
772 | STATIC_CONTRACT_LEAF; |
773 | // _ASSERTE(cArgs <= StressMsg::maxArgCnt); |
774 | // advance the marker |
775 | StressMsg* p = (StressMsg*)((char*)curPtr - sizeof(StressMsg) - cArgs*sizeof(void*)); |
776 | |
777 | //past start of current chunk |
778 | //wrap around if we need to |
779 | if (p < (StressMsg*)curWriteChunk->StartPtr ()) |
780 | { |
781 | curPtr = AdvWritePastBoundary(cArgs); |
782 | } |
783 | else |
784 | { |
785 | curPtr = p; |
786 | } |
787 | |
788 | return curPtr; |
789 | } |
790 | |
791 | // It's the factored-out slow codepath for AdvanceWrite() and |
792 | // is only called by AdvanceWrite(). |
793 | // Returns the stress message flushed against endPtr |
794 | // In addition it writes NULLs b/w the startPtr and curPtr |
795 | inline StressMsg* ThreadStressLog::AdvWritePastBoundary(int cArgs) { |
796 | STATIC_CONTRACT_WRAPPER; |
797 | #ifndef STRESS_LOG_READONLY |
798 | //zeroed out remaining buffer |
799 | memset (curWriteChunk->StartPtr (), 0, (BYTE *)curPtr - (BYTE *)curWriteChunk->StartPtr ()); |
800 | |
801 | //if we are already at head of the list, try to grow the list |
802 | if (curWriteChunk == chunkListHead) |
803 | { |
804 | GrowChunkList (); |
805 | } |
806 | #endif //!STRESS_LOG_READONLY |
807 | |
808 | curWriteChunk = curWriteChunk->prev; |
809 | #ifndef STRESS_LOG_READONLY |
810 | if (curWriteChunk == chunkListTail) |
811 | { |
812 | writeHasWrapped = TRUE; |
813 | } |
814 | #endif //STRESS_LOG_READONLY |
815 | curPtr = (StressMsg*)((char*)curWriteChunk->EndPtr () - sizeof(StressMsg) - cArgs * sizeof(void*)); |
816 | return curPtr; |
817 | } |
818 | |
819 | #else // STRESS_LOG |
820 | |
821 | #define STRESS_LOG_VA(msg) do { } while(0) |
822 | #define STRESS_LOG0(facility, level, msg) do { } while(0) |
823 | #define STRESS_LOG1(facility, level, msg, data1) do { } while(0) |
824 | #define STRESS_LOG2(facility, level, msg, data1, data2) do { } while(0) |
825 | #define STRESS_LOG2_CHECK_EE_STARTED(facility, level, msg, data1, data2)do { } while(0) |
826 | #define STRESS_LOG3(facility, level, msg, data1, data2, data3) do { } while(0) |
827 | #define STRESS_LOG4(facility, level, msg, data1, data2, data3, data4) do { } while(0) |
828 | #define STRESS_LOG5(facility, level, msg, data1, data2, data3, data4, data5) do { } while(0) |
829 | #define STRESS_LOG6(facility, level, msg, data1, data2, data3, data4, data5, data6) do { } while(0) |
830 | #define STRESS_LOG7(facility, level, msg, data1, data2, data3, data4, data5, data6, data7) do { } while(0) |
831 | #define STRESS_LOG_PLUG_MOVE(plug_start, plug_end, plug_delta) do { } while(0) |
832 | #define STRESS_LOG_ROOT_PROMOTE(root_addr, objPtr, methodTable) do { } while(0) |
833 | #define STRESS_LOG_ROOT_RELOCATE(root_addr, old_value, new_value, methodTable) do { } while(0) |
834 | #define STRESS_LOG_GC_START(gcCount, Gen, collectClasses) do { } while(0) |
835 | #define STRESS_LOG_GC_END(gcCount, Gen, collectClasses) do { } while(0) |
836 | #define STRESS_LOG_OOM_STACK(size) do { } while(0) |
837 | #define STRESS_LOG_GC_STACK(size) do { } while(0) |
838 | #define STRESS_LOG_RESERVE_MEM(numChunks) do {} while (0) |
839 | #endif // STRESS_LOG |
840 | |
841 | #endif // StressLog_h |
842 | |