[Tizen] Unify dnetmemoryenumlib terms to match the codebase (#291)
[platform/upstream/coreclr.git] / src / utilcode / stresslog.cpp
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 /*                                   StressLog.cpp                                   */
7 /*************************************************************************************/
8
9 /*************************************************************************************/
10
11 #include "stdafx.h"                     // precompiled headers
12
13 #include "switches.h"
14 #include "stresslog.h"
15 #include "clrhost.h"
16 #define DONOT_DEFINE_ETW_CALLBACK
17 #include "eventtracebase.h"
18 #include "ex.h"
19
20  #if !defined(STRESS_LOG_READONLY)
21 HANDLE StressLogChunk::s_LogChunkHeap = NULL;
22 #endif // !STRESS_LOG_READONLY
23
24 /*********************************************************************************/
25 #if defined(_TARGET_X86_)
26
27 /* This is like QueryPerformanceCounter but a lot faster.  On machines with 
28    variable-speed CPUs (for power management), this is not accurate, but may
29    be good enough.
30 */
31 __forceinline __declspec(naked) unsigned __int64 getTimeStamp() {
32     STATIC_CONTRACT_LEAF;
33     
34    __asm {
35         RDTSC   // read time stamp counter
36         ret
37     };
38 }
39
40 #else // _TARGET_X86_ 
41 unsigned __int64 getTimeStamp() {
42     STATIC_CONTRACT_LEAF;
43     
44     LARGE_INTEGER ret;
45     ZeroMemory(&ret, sizeof(LARGE_INTEGER));
46     
47     QueryPerformanceCounter(&ret);
48
49     return ret.QuadPart;
50 }
51
52 #endif // _TARGET_X86_ 
53
54 #if defined(_TARGET_X86_) && !defined(FEATURE_PAL)
55
56 /*********************************************************************************/
57 /* Get the the frequency cooresponding to 'getTimeStamp'.  For x86, this is the
58    frequency of the RDTSC instruction, which is just the clock rate of the CPU.
59    This can vary due to power management, so this is at best a rough approximation.
60 */
61 unsigned __int64 getTickFrequency() 
62 {
63     //
64     // At startup, the OS calculates the CPU clock frequency and makes it available 
65     // at HKEY_LOCAL_MACHINE\HARDWARE\DESCRIPTION\System\CentralProcessor\0
66     //
67
68     unsigned __int64 hz = 0;
69
70     HKEY hKey;
71     if (ERROR_SUCCESS == RegOpenKeyExW(
72         HKEY_LOCAL_MACHINE, 
73         W("HARDWARE\\DESCRIPTION\\System\\CentralProcessor\\0"),
74         0,
75         KEY_QUERY_VALUE,
76         &hKey))
77     {
78         DWORD mhz;
79         DWORD mhzType;
80         DWORD cbMhz = (DWORD)sizeof(mhz);
81         if (ERROR_SUCCESS == RegQueryValueExW(
82             hKey,
83             W("~MHz"),
84             NULL,
85             &mhzType,
86             (LPBYTE)&mhz,
87             &cbMhz))
88         {
89             _ASSERTE(REG_DWORD == mhzType);
90             _ASSERTE((DWORD)sizeof(mhz) == cbMhz);
91
92             hz = (unsigned __int64)mhz * 1000000;
93         }
94
95         RegCloseKey(hKey);
96     }
97     
98     return hz;
99 }
100
101 #else // _TARGET_X86_ 
102
103
104 /*********************************************************************************/
105 /* Get the the frequency cooresponding to 'getTimeStamp'.  For non-x86 
106    architectures, this is just the performance counter frequency.
107 */
108 unsigned __int64 getTickFrequency()
109 {
110     LARGE_INTEGER ret;
111     ZeroMemory(&ret, sizeof(LARGE_INTEGER));
112     QueryPerformanceFrequency(&ret);
113     return ret.QuadPart;
114 }
115
116 #endif // _TARGET_X86_ 
117
118 #ifdef STRESS_LOG
119
120 StressLog StressLog::theLog = { 0, 0, 0, 0, 0, 0, TLS_OUT_OF_INDEXES, 0, 0, 0 };    
121 const static unsigned __int64 RECYCLE_AGE = 0x40000000L;        // after a billion cycles, we can discard old threads
122
123 /*********************************************************************************/
124 void StressLog::Enter(CRITSEC_COOKIE) {
125     STATIC_CONTRACT_LEAF;
126     
127     IncCantAllocCount();
128     ClrEnterCriticalSection(theLog.lock);
129     DecCantAllocCount();
130 }
131
132 void StressLog::Leave(CRITSEC_COOKIE) {
133     STATIC_CONTRACT_LEAF;
134     
135     IncCantAllocCount();
136     ClrLeaveCriticalSection(theLog.lock);
137     DecCantAllocCount();
138 }
139
140 /*********************************************************************************/
141 void StressLog::Initialize(unsigned facilities,  unsigned level, unsigned maxBytesPerThread, 
142             unsigned maxBytesTotal, HMODULE hMod) 
143 {
144     STATIC_CONTRACT_LEAF;
145
146     if (theLog.MaxSizePerThread != 0)
147     {
148         // guard ourself against multiple initialization. First init wins.
149         return;
150     }
151     
152     _ASSERTE (theLog.TLSslot == (unsigned int)TLS_OUT_OF_INDEXES);
153     theLog.lock = ClrCreateCriticalSection(CrstStressLog,(CrstFlags)(CRST_UNSAFE_ANYMODE|CRST_DEBUGGER_THREAD));
154     // StressLog::Terminate is going to free memory.
155     if (maxBytesPerThread < STRESSLOG_CHUNK_SIZE)
156     {
157         maxBytesPerThread = STRESSLOG_CHUNK_SIZE;
158     }
159     theLog.MaxSizePerThread = maxBytesPerThread;
160
161     if (maxBytesTotal < STRESSLOG_CHUNK_SIZE * 256)
162     {
163         maxBytesTotal = STRESSLOG_CHUNK_SIZE * 256;
164     }
165     theLog.MaxSizeTotal = maxBytesTotal;
166     theLog.totalChunk = 0;
167     theLog.facilitiesToLog = facilities | LF_ALWAYS;
168     theLog.levelToLog = level;
169     theLog.deadCount = 0;
170     theLog.TLSslot = TlsIdx_StressLog;
171         
172     theLog.tickFrequency = getTickFrequency();
173         
174     GetSystemTimeAsFileTime (&theLog.startTime);
175     theLog.startTimeStamp = getTimeStamp();
176
177 #ifndef FEATURE_PAL
178     theLog.moduleOffset = (SIZE_T)hMod; // HMODULES are base addresses.
179
180 #ifdef _DEBUG
181     HMODULE hModNtdll = GetModuleHandleA("ntdll.dll");
182     theLog.RtlCaptureStackBackTrace = reinterpret_cast<PFNRtlCaptureStackBackTrace>(
183             GetProcAddress(hModNtdll, "RtlCaptureStackBackTrace"));
184 #endif // _DEBUG
185
186 #else // !FEATURE_PAL
187     theLog.moduleOffset = (SIZE_T)PAL_GetSymbolModuleBase((void *)StressLog::Initialize);
188 #endif // !FEATURE_PAL
189
190 #if !defined (STRESS_LOG_READONLY)    
191     StressLogChunk::s_LogChunkHeap = ClrHeapCreate (0, STRESSLOG_CHUNK_SIZE * 128, 0);
192     if (StressLogChunk::s_LogChunkHeap == NULL)
193     {
194         StressLogChunk::s_LogChunkHeap = ClrGetProcessHeap ();
195     }
196     _ASSERTE (StressLogChunk::s_LogChunkHeap);
197 #endif //!STRESS_LOG_READONLY
198 }
199
200 /*********************************************************************************/
201 void StressLog::Terminate(BOOL fProcessDetach) {
202     STATIC_CONTRACT_NOTHROW;
203     STATIC_CONTRACT_FORBID_FAULT;
204     
205     if (theLog.TLSslot != (unsigned int)TLS_OUT_OF_INDEXES) {
206         theLog.facilitiesToLog = 0;
207
208         StressLogLockHolder lockh(theLog.lock, FALSE);
209         if (!fProcessDetach) {
210             lockh.Acquire(); lockh.Release();       // The Enter() Leave() forces a memory barrier on weak memory model systems
211                                     // we want all the other threads to notice that facilitiesToLog is now zero
212
213                     // This is not strictly threadsafe, since there is no way of insuring when all the
214                     // threads are out of logMsg.  In practice, since they can no longer enter logMsg
215                     // and there are no blocking operations in logMsg, simply sleeping will insure
216                     // that everyone gets out. 
217             ClrSleepEx(2, FALSE);
218             lockh.Acquire();    
219         }
220
221         // Free the log memory
222         ThreadStressLog* ptr = theLog.logs;
223         theLog.logs = 0;
224         while(ptr != 0) {
225             ThreadStressLog* tmp = ptr;
226             ptr = ptr->next;
227             delete tmp;
228         }
229
230         theLog.TLSslot = TLS_OUT_OF_INDEXES;
231         if (!fProcessDetach) {
232             lockh.Release();
233         }
234     }
235 #if !defined (STRESS_LOG_READONLY)    
236     if (StressLogChunk::s_LogChunkHeap != NULL && StressLogChunk::s_LogChunkHeap != ClrGetProcessHeap ())
237     {
238         ClrHeapDestroy (StressLogChunk::s_LogChunkHeap);
239     }
240 #endif //!STRESS_LOG_READONLY
241 }
242
243 /*********************************************************************************/
244 /* create a new thread stress log buffer associated with Thread local slot TLSslot, for the Stress log */
245
246 ThreadStressLog* StressLog::CreateThreadStressLog() {
247     CONTRACTL
248     {
249         NOTHROW;
250         GC_NOTRIGGER;
251         FORBID_FAULT;
252     }
253     CONTRACTL_END;
254     
255     static PVOID callerID = NULL;
256
257     ThreadStressLog* msgs = (ThreadStressLog*) ClrFlsGetValue(theLog.TLSslot);
258     if (msgs != NULL)
259     {
260         return msgs;
261     }
262
263     if (callerID == ClrTeb::GetFiberPtrId())
264     {
265         return NULL;
266     }
267
268     //if we are not allowed to allocate stress log, we should not even try to take the lock
269     if (!StressLogChunk::s_LogChunkHeap || !CanThisThreadCallIntoHost() || IsInCantAllocStressLogRegion ())
270     {
271         return NULL;
272     }
273
274     // if it looks like we won't be allowed to allocate a new chunk, exit early
275     if (theLog.deadCount == 0 && !AllowNewChunk (0))
276     {
277         return NULL;
278     }
279
280     StressLogLockHolder lockh(theLog.lock, FALSE);
281
282     class NestedCaller
283     {
284     public:
285         NestedCaller()
286         {
287         }
288         ~NestedCaller()
289         {
290             callerID = NULL;
291         }
292         void Mark()
293         {
294             callerID = ClrTeb::GetFiberPtrId();
295         }
296     };
297
298     NestedCaller nested;
299
300     BOOL noFLSNow = FALSE;
301     
302     PAL_CPP_TRY
303     {
304         // Acquiring the lack can throw an OOM exception the first time its called on a thread. We go
305         // ahead and try to provoke that now, before we've altered the list of available stress logs, and bail if
306         // we fail.
307         lockh.Acquire();
308         nested.Mark();
309
310         // ClrFlsSetValue can throw an OOM exception the first time its called on a thread for a given slot. We go
311         // ahead and try to provoke that now, before we've altered the list of available stress logs, and bail if
312         // we fail.
313         ClrFlsSetValue(theLog.TLSslot, NULL);
314     }
315 #pragma warning(suppress: 4101)
316     PAL_CPP_CATCH_DERIVED(OutOfMemoryException, obj)
317     {
318         // Just leave on any exception. Note: can't goto or return from within EX_CATCH...
319         noFLSNow = TRUE;
320     }
321     PAL_CPP_ENDTRY;
322
323     if (noFLSNow == FALSE && theLog.facilitiesToLog != 0)
324         msgs = CreateThreadStressLogHelper();
325
326     return msgs;
327 }
328
329 ThreadStressLog* StressLog::CreateThreadStressLogHelper() {
330     CONTRACTL
331     {
332         NOTHROW;
333         GC_NOTRIGGER;
334         FORBID_FAULT;
335         CANNOT_TAKE_LOCK;
336     }
337     CONTRACTL_END;
338
339     _ASSERTE(theLog.TLSslot != (unsigned int)TLS_OUT_OF_INDEXES); // because facilitiesToLog is != 0
340
341
342     BOOL skipInsert = FALSE;
343     ThreadStressLog* msgs = NULL;
344
345     // See if we can recycle a dead thread
346     if (theLog.deadCount > 0) 
347     {        
348         unsigned __int64 recycleStamp = getTimeStamp() - RECYCLE_AGE;
349         msgs = theLog.logs;
350         //find out oldest dead ThreadStressLog in case we can't find one within 
351         //recycle age but can't create a new chunk
352         ThreadStressLog * oldestDeadMsg = NULL;
353         
354         while(msgs != 0) 
355         {
356             if (msgs->isDead)
357             {
358                 BOOL hasTimeStamp = msgs->curPtr != (StressMsg *)msgs->chunkListTail->EndPtr();
359                 if (hasTimeStamp && msgs->curPtr->timeStamp < recycleStamp) 
360                 {
361                     skipInsert = TRUE;                
362                     InterlockedDecrement(&theLog.deadCount);
363                     break;
364                 }
365                 
366                 if (!oldestDeadMsg)
367                 {
368                     oldestDeadMsg = msgs;
369                 }                
370                 else if (hasTimeStamp && oldestDeadMsg->curPtr->timeStamp > msgs->curPtr->timeStamp)
371                 {
372                     oldestDeadMsg = msgs;
373                 }                               
374             }
375             
376             msgs = msgs->next;
377         }
378
379         //if the total stress log size limit is already passed and we can't add new chunk,
380         //always reuse the oldest dead msg
381         if (!AllowNewChunk (0) && !msgs)
382         {
383             msgs = oldestDeadMsg;
384             skipInsert = TRUE;
385             InterlockedDecrement(&theLog.deadCount);
386         }
387     }
388
389     if (msgs == 0)  {
390         FAULT_NOT_FATAL(); // We don't mind if we can't allocate here, we'll try again later.
391         if (IsInCantAllocStressLogRegion ())
392         {
393             goto LEAVE;
394         }
395         
396         msgs = new (nothrow) ThreadStressLog;
397
398         if (msgs == 0 ||!msgs->IsValid ()) 
399         {
400             delete msgs;
401             msgs = 0;
402             goto LEAVE;
403         }
404     }
405
406     msgs->Activate ();
407
408     // We know this isn't going to throw an exception now because the call to ClrFlsSetValue above succeeded for
409     // this thread.
410     {
411         CONTRACT_VIOLATION(ThrowsViolation);
412         ClrFlsSetValue(theLog.TLSslot, msgs);
413     }
414
415     if (!skipInsert) {
416 #ifdef _DEBUG
417         ThreadStressLog* walk = theLog.logs;
418         while (walk)
419         {
420             _ASSERTE (walk != msgs);
421             walk = walk->next;
422         }
423 #endif
424         // Put it into the stress log
425         msgs->next = theLog.logs;
426         theLog.logs = msgs;
427     }
428
429 LEAVE:
430     ;
431     return msgs;
432 }
433     
434 /*********************************************************************************/
435 /* static */
436 void StressLog::ThreadDetach(ThreadStressLog *msgs) {
437     STATIC_CONTRACT_NOTHROW;
438     STATIC_CONTRACT_FORBID_FAULT;
439     STATIC_CONTRACT_CANNOT_TAKE_LOCK;
440
441 #ifndef DACCESS_COMPILE
442     if (msgs == 0)
443     {
444         return;
445     }
446
447     _ASSERTE(theLog.TLSslot != (unsigned int)TLS_OUT_OF_INDEXES); // because facilitiesToLog is != 0
448     // We are deleting a fiber.  The thread is running a different fiber now.
449     // We should write this message to the StressLog for deleted fiber.
450     msgs->LogMsg (LF_STARTUP, 0, "******* DllMain THREAD_DETACH called Thread dying *******\n");
451 #endif
452
453     msgs->isDead = TRUE;
454     InterlockedIncrement(&theLog.deadCount);
455 }
456
457 BOOL StressLog::AllowNewChunk (LONG numChunksInCurThread)
458 {
459     _ASSERTE (numChunksInCurThread <= theLog.totalChunk);
460     DWORD perThreadLimit = theLog.MaxSizePerThread;
461
462 #ifndef DACCESS_COMPILE
463     if (numChunksInCurThread == 0 && IsSuspendEEThread())
464         return TRUE;
465
466     if (IsGCSpecialThread())
467     {
468         perThreadLimit *= GC_STRESSLOG_MULTIPLY;
469     }
470 #endif
471         
472     if ((DWORD)numChunksInCurThread * STRESSLOG_CHUNK_SIZE >= perThreadLimit)
473     {
474         return FALSE;
475     }
476
477     return (DWORD)theLog.totalChunk * STRESSLOG_CHUNK_SIZE < theLog.MaxSizeTotal;
478 }
479
480 BOOL StressLog::ReserveStressLogChunks (unsigned chunksToReserve)
481 {
482     ThreadStressLog* msgs = (ThreadStressLog*) ClrFlsGetValue(theLog.TLSslot);
483
484     if (msgs == 0) 
485     {
486         msgs = CreateThreadStressLog();
487
488         if (msgs == 0)
489             return FALSE;
490     }
491
492     if (chunksToReserve == 0)
493     {
494         chunksToReserve = (theLog.MaxSizePerThread + STRESSLOG_CHUNK_SIZE - 1)  / STRESSLOG_CHUNK_SIZE;
495     }
496
497     LONG numTries = (LONG)chunksToReserve - msgs->chunkListLength;
498     for (LONG i = 0; i < numTries; i++)
499     {
500         msgs->GrowChunkList ();
501     }
502
503     return msgs->chunkListLength >= (LONG)chunksToReserve;
504 }
505
506 void (*FSwitchToSOTolerant)();
507 void (*FSwitchToSOIntolerant)();
508 void TrackSO(BOOL tolerance)
509 {
510     if (tolerance)
511     {
512         if (FSwitchToSOTolerant)
513         {
514             FSwitchToSOTolerant();
515         }
516     }
517     else
518     {
519         if (FSwitchToSOIntolerant)
520         {
521             FSwitchToSOIntolerant();
522         }
523     }
524 }
525
526 /*********************************************************************************/
527 /* fetch a buffer that can be used to write a stress message, it is thread safe */
528 void ThreadStressLog::LogMsg(unsigned facility, int cArgs, const char* format, va_list Args)
529 {
530     STATIC_CONTRACT_NOTHROW;
531     STATIC_CONTRACT_FORBID_FAULT;
532
533         // Asserts in this function cause infinite loops in the asserting mechanism.
534         // Just use debug breaks instead.
535         
536 #ifndef DACCESS_COMPILE
537 #ifdef _DEBUG
538     // _ASSERTE ( cArgs >= 0 && cArgs <= 7 );
539         if (cArgs < 0 || cArgs > 7) DebugBreak();
540 #endif // 
541     
542     size_t offs = ((size_t)format - StressLog::theLog.moduleOffset);
543
544     // _ASSERTE ( offs < StressMsg::maxOffset );
545         if (offs >= StressMsg::maxOffset)
546         {
547 #ifdef _DEBUG
548                 DebugBreak(); // in lieu of the above _ASSERTE
549 #endif // _DEBUG
550                 
551                 // Set it to this string instead.
552                 offs = 
553 #ifdef _DEBUG
554                         (size_t)"<BUG: StressLog format string beyond maxOffset>";
555 #else // _DEBUG
556                         0; // a 0 offset is ignored by StressLog::Dump
557 #endif // _DEBUG else
558         }
559
560     // Get next available slot
561     StressMsg* msg = AdvanceWrite(cArgs);
562
563     msg->timeStamp = getTimeStamp();
564     msg->facility = facility;
565         msg->formatOffset = offs;
566         msg->numberOfArgs = cArgs;
567
568     for ( int i = 0; i < cArgs; ++i )
569     {
570         void* data = va_arg(Args, void*);
571         msg->args[i] = data;
572     }
573
574 #ifdef _DEBUG
575     if (!IsValid () || threadId != GetCurrentThreadId ())
576         DebugBreak();
577 #endif // _DEBUG
578 #endif //DACCESS_COMPILE
579 }
580
581 FORCEINLINE BOOL StressLog::InlinedStressLogOn(unsigned facility, unsigned level)
582 {
583     STATIC_CONTRACT_LEAF;
584     STATIC_CONTRACT_SUPPORTS_DAC;
585
586 #if defined(DACCESS_COMPILE) 
587     return FALSE;
588 #else
589     return ((theLog.facilitiesToLog & facility) && (level <= theLog.levelToLog));
590 #endif
591 }
592
593 BOOL StressLog::StressLogOn(unsigned facility, unsigned level)
594 {
595     STATIC_CONTRACT_LEAF;
596     STATIC_CONTRACT_SUPPORTS_DAC;
597
598     return InlinedStressLogOn(facility, level);
599 }
600
601 FORCEINLINE BOOL StressLog::InlinedETWLogOn(unsigned facility, unsigned level)
602 {
603     STATIC_CONTRACT_LEAF;
604     STATIC_CONTRACT_SUPPORTS_DAC;
605
606     return FALSE;
607 }
608
609 BOOL StressLog::ETWLogOn(unsigned facility, unsigned level)
610 {
611     STATIC_CONTRACT_LEAF;
612     STATIC_CONTRACT_SUPPORTS_DAC;
613
614     return InlinedETWLogOn(facility, level);
615 }
616
617 #if !defined(DACCESS_COMPILE) 
618 BOOL StressLog::LogOn(unsigned facility, unsigned level)
619 {
620     STATIC_CONTRACT_LEAF;
621     STATIC_CONTRACT_SUPPORTS_DAC;
622
623     return InlinedStressLogOn(facility, level) || InlinedETWLogOn(facility, level);
624 }
625 #endif
626
627 /* static */
628 void StressLog::LogMsg (unsigned level, unsigned facility, int cArgs, const char* format, ... )
629 {
630     STATIC_CONTRACT_SUPPORTS_DAC;
631 #ifndef DACCESS_COMPILE
632     STATIC_CONTRACT_NOTHROW;
633     STATIC_CONTRACT_GC_NOTRIGGER;
634     STATIC_CONTRACT_FORBID_FAULT;
635     STATIC_CONTRACT_SUPPORTS_DAC;
636
637     // Any stresslog LogMsg could theoretically create a new stress log and thus
638     // enter a critical section.  But we don't want these to cause violations in
639     // CANNOT_TAKE_LOCK callers, since the callers would otherwise be fine in runs that don't
640     // set the stress log config parameter.
641     CONTRACT_VIOLATION(TakesLockViolation);
642
643     _ASSERTE ( cArgs >= 0 && cArgs <= 7 );
644
645     va_list Args;
646     
647     if(InlinedStressLogOn(facility, level))
648     {
649         ThreadStressLog* msgs = (ThreadStressLog*) ClrFlsGetValue(theLog.TLSslot);
650
651         if (msgs == 0) {
652             msgs = CreateThreadStressLog();
653
654             if (msgs == 0)
655                 return;
656         }
657         va_start(Args, format);
658         msgs->LogMsg (facility, cArgs, format, Args);
659         va_end(Args);
660     }
661
662 // Stress Log ETW feature available only on the desktop versions of the runtime
663 #endif //!DACCESS_COMPILE
664 }
665
666 #ifdef _DEBUG
667 /* static */
668 void  StressLog::LogCallStack(const char *const callTag){
669    if (theLog.RtlCaptureStackBackTrace) 
670    {
671         size_t  CallStackTrace[MAX_CALL_STACK_TRACE];
672         ULONG hash;
673         USHORT stackTraceCount = theLog.RtlCaptureStackBackTrace (2, MAX_CALL_STACK_TRACE, (PVOID *)CallStackTrace, &hash);
674         if (stackTraceCount > MAX_CALL_STACK_TRACE)
675             stackTraceCount = MAX_CALL_STACK_TRACE;
676         LogMsgOL("Start of %s stack \n", callTag); 
677         USHORT i = 0;
678         for (;i < stackTraceCount; i++)
679         {
680             LogMsgOL("(%s stack)%pK\n", callTag, CallStackTrace[i]);
681         }
682         LogMsgOL("End of %s stack\n", callTag);
683         }
684 }
685 #endif //_DEBUG
686
687 #endif // STRESS_LOG
688