Skip to content

Commit eb65022

Browse files
jkoritzinskyjkoritzinsky
authored
Change the stresslog message layout to support extra-large modules and modules loaded at far-apart addresses that use the stresslog (#83855)
1 parent 6c3a197 commit eb65022

File tree

9 files changed

+376
-304
lines changed

9 files changed

+376
-304
lines changed

‎src/coreclr/inc/sospriv.idl

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -442,7 +442,7 @@ interface ISOSDacInterface8 : IUnknown
442442
// Increment anytime there is a change in the data structures that SOS depends on like
443443
// stress log structs (StressMsg, StressLogChunck, ThreadStressLog, etc), exception
444444
// stack traces (StackTraceElement), the PredefinedTlsSlots enums, etc.
445-
cpp_quote("#define SOS_BREAKING_CHANGE_VERSION 3")
445+
cpp_quote("#define SOS_BREAKING_CHANGE_VERSION 4")
446446

447447
[
448448
object,

‎src/coreclr/inc/stresslog.h

Lines changed: 68 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -544,31 +544,74 @@ inline BOOL StressLog::LogOn(unsigned facility, unsigned level)
544544
#pragma warning(disable:4200 4201) // don't warn about 0 sized array below or unnamed structures
545545
#endif
546546

547-
// The order of fields is important. Keep the prefix length as the first field.
548-
// And make sure the timeStamp field is naturally aligned, so we don't waste
549-
// space on 32-bit platforms
550-
struct StressMsg {
551-
static const size_t formatOffsetBits = 26;
552-
union {
553-
struct {
554-
uint32_t numberOfArgs : 3; // at most 7 arguments here
555-
uint32_t formatOffset : formatOffsetBits; // offset of string in mscorwks
556-
uint32_t numberOfArgsX : 3; // extend number of args in a backward compat way
557-
};
558-
uint32_t fmtOffsCArgs; // for optimized access
559-
};
560-
uint32_t facility; // facility used to log the entry
561-
uint64_t timeStamp; // time when mssg was logged
562-
void* args[0]; // size given by numberOfArgs
547+
// The order of fields is important. Ensure that we minimize padding
548+
// to fit more messages in a chunk.
549+
struct StressMsg
550+
{
551+
private:
552+
static const size_t formatOffsetLowBits = 26;
553+
static const size_t formatOffsetHighBits = 13;
554+
555+
// We split the format offset to ensure that we utilize every bit and that
556+
// the compiler does not align the format offset to a new 64-bit boundary.
557+
uint64_t facility: 32; // facility used to log the entry
558+
uint64_t numberOfArgs : 6; // number of arguments
559+
uint64_t formatOffsetLow: formatOffsetLowBits; // offset of format string in modules
560+
uint64_t formatOffsetHigh: formatOffsetHighBits; // offset of format string in modules
561+
uint64_t timeStamp: 51; // time when msg was logged (100ns ticks since runtime start)
562+
563+
public:
564+
void* args[0]; // size given by numberOfArgs
565+
566+
void SetFormatOffset(uint64_t offset)
567+
{
568+
formatOffsetLow = (uint32_t)(offset & ((1 << formatOffsetLowBits) - 1));
569+
formatOffsetHigh = offset >> formatOffsetLowBits;
570+
}
571+
572+
uint64_t GetFormatOffset()
573+
{
574+
return (formatOffsetHigh << formatOffsetLowBits) | formatOffsetLow;
575+
}
576+
577+
void SetNumberOfArgs(uint32_t num)
578+
{
579+
numberOfArgs = num;
580+
}
581+
582+
uint32_t GetNumberOfArgs()
583+
{
584+
return numberOfArgs;
585+
}
586+
587+
void SetFacility(uint32_t fac)
588+
{
589+
facility = fac;
590+
}
591+
592+
uint32_t GetFacility()
593+
{
594+
return facility;
595+
}
596+
597+
uint64_t GetTimeStamp()
598+
{
599+
return timeStamp;
600+
}
601+
602+
void SetTimeStamp(uint64_t time)
603+
{
604+
timeStamp = time;
605+
}
563606

564607
static const size_t maxArgCnt = 63;
565-
static const size_t maxOffset = 1 << formatOffsetBits;
608+
static const int64_t maxOffset = (int64_t)1 << (formatOffsetLowBits + formatOffsetHighBits);
566609
static size_t maxMsgSize ()
567610
{ return sizeof(StressMsg) + maxArgCnt*sizeof(void*); }
568-
569-
friend class ThreadStressLog;
570-
friend class StressLog;
571611
};
612+
613+
static_assert(sizeof(StressMsg) == sizeof(uint64_t) * 2, "StressMsg bitfields aren't aligned correctly");
614+
572615
#ifdef HOST_64BIT
573616
#define STRESSLOG_CHUNK_SIZE (32 * 1024)
574617
#else //HOST_64BIT
@@ -679,7 +722,7 @@ class ThreadStressLog {
679722
long chunkListLength; // how many stress log chunks are in this stress log
680723

681724
#ifdef STRESS_LOG_READONLY
682-
FORCEINLINE StressMsg* AdvanceRead();
725+
FORCEINLINE StressMsg* AdvanceRead(uint32_t cArgs);
683726
#endif //STRESS_LOG_READONLY
684727
FORCEINLINE StressMsg* AdvanceWrite(int cArgs);
685728

@@ -814,7 +857,7 @@ class ThreadStressLog {
814857
// Called while dumping. Returns true after all messages in log were dumped
815858
FORCEINLINE BOOL CompletedDump ()
816859
{
817-
return readPtr->timeStamp == 0
860+
return readPtr->GetTimeStamp() == 0
818861
//if read has passed end of list but write has not passed head of list yet, we are done
819862
//if write has also wrapped, we are at the end if read pointer passed write pointer
820863
|| (readHasWrapped &&
@@ -844,10 +887,10 @@ class ThreadStressLog {
844887
// Called when dumping the log (by StressLog::Dump())
845888
// Updates readPtr to point to next stress messaage to be dumped
846889
// For convenience it returns the new value of readPtr
847-
inline StressMsg* ThreadStressLog::AdvanceRead() {
890+
inline StressMsg* ThreadStressLog::AdvanceRead(uint32_t cArgs) {
848891
STATIC_CONTRACT_LEAF;
849892
// advance the marker
850-
readPtr = (StressMsg*)((char*)readPtr + sizeof(StressMsg) + readPtr->numberOfArgs*sizeof(void*));
893+
readPtr = (StressMsg*)((char*)readPtr + sizeof(StressMsg) + cArgs * sizeof(void*));
851894
// wrap around if we need to
852895
if (readPtr >= (StressMsg *)curReadChunk->EndPtr ())
853896
{
@@ -874,7 +917,7 @@ inline StressMsg* ThreadStressLog::AdvReadPastBoundary() {
874917
}
875918
curReadChunk = curReadChunk->next;
876919
void** p = (void**)curReadChunk->StartPtr();
877-
while (*p == NULL && (size_t)(p-(void**)curReadChunk->StartPtr ()) < (StressMsg::maxMsgSize()/sizeof(void*)))
920+
while (*p == NULL && (size_t)(p-(void**)curReadChunk->StartPtr()) < (StressMsg::maxMsgSize() / sizeof(void*)))
878921
{
879922
++p;
880923
}

‎src/coreclr/nativeaot/Runtime/DebugHeader.cpp

Lines changed: 0 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -239,9 +239,6 @@ extern "C" void PopulateDebugHeaders()
239239
MAKE_DEBUG_FIELD_ENTRY(StressLogChunk, dwSig2);
240240

241241
MAKE_SIZE_ENTRY(StressMsg);
242-
MAKE_DEBUG_FIELD_ENTRY(StressMsg, fmtOffsCArgs);
243-
MAKE_DEBUG_FIELD_ENTRY(StressMsg, facility);
244-
MAKE_DEBUG_FIELD_ENTRY(StressMsg, timeStamp);
245242
MAKE_DEBUG_FIELD_ENTRY(StressMsg, args);
246243

247244
MAKE_SIZE_ENTRY(RuntimeInstance);

‎src/coreclr/nativeaot/Runtime/inc/stressLog.h

Lines changed: 65 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -488,36 +488,76 @@ class StressLog {
488488
#endif
489489

490490
//==========================================================================================
491-
// StressMsg
492-
//
493-
// The order of fields is important. Keep the prefix length as the first field.
494-
// And make sure the timeStamp field is naturally aligned, so we don't waste
495-
// space on 32-bit platforms
496-
//
497-
struct StressMsg {
498-
static const size_t formatOffsetBits = 26;
499-
union {
500-
struct {
501-
uint32_t numberOfArgs : 3; // at most 7 arguments
502-
uint32_t formatOffset : formatOffsetBits; // offset of string in mscorwks
503-
uint32_t numberOfArgsX : 3; // extend number of args in a backward compat way
504-
};
505-
uint32_t fmtOffsCArgs; // for optimized access
506-
};
507-
uint32_t facility; // facility used to log the entry
508-
unsigned __int64 timeStamp; // time when mssg was logged
509-
void* args[0]; // size given by numberOfArgs
491+
// The order of fields is important. Ensure that we minimize padding
492+
// to fit more messages in a chunk.
493+
struct StressMsg
494+
{
495+
private:
496+
static const size_t formatOffsetLowBits = 26;
497+
static const size_t formatOffsetHighBits = 13;
498+
499+
// We split the format offset to ensure that we utilize every bit and that
500+
// the compiler does not align the format offset to a new 64-bit boundary.
501+
uint64_t facility: 32; // facility used to log the entry
502+
uint64_t numberOfArgs : 6; // number of arguments
503+
uint64_t formatOffsetLow: formatOffsetLowBits; // offset of format string in modules
504+
uint64_t formatOffsetHigh: formatOffsetHighBits; // offset of format string in modules
505+
uint64_t timeStamp: 51; // time when msg was logged (100ns ticks since runtime start)
506+
507+
public:
508+
void* args[0]; // size given by numberOfArgs
509+
510+
void SetFormatOffset(uint64_t offset)
511+
{
512+
formatOffsetLow = (uint32_t)(offset & ((1 << formatOffsetLowBits) - 1));
513+
formatOffsetHigh = offset >> formatOffsetLowBits;
514+
}
515+
516+
uint64_t GetFormatOffset()
517+
{
518+
return (formatOffsetHigh << formatOffsetLowBits) | formatOffsetLow;
519+
}
520+
521+
void SetNumberOfArgs(uint32_t num)
522+
{
523+
numberOfArgs = num;
524+
}
525+
526+
uint32_t GetNumberOfArgs()
527+
{
528+
return numberOfArgs;
529+
}
530+
531+
void SetFacility(uint32_t fac)
532+
{
533+
facility = fac;
534+
}
535+
536+
uint32_t GetFacility()
537+
{
538+
return facility;
539+
}
540+
541+
uint64_t GetTimeStamp()
542+
{
543+
return timeStamp;
544+
}
545+
546+
void SetTimeStamp(uint64_t time)
547+
{
548+
timeStamp = time;
549+
}
510550

511551
static const size_t maxArgCnt = 63;
512-
static const size_t maxOffset = 1 << formatOffsetBits;
552+
static const int64_t maxOffset = (int64_t)1 << (formatOffsetLowBits + formatOffsetHighBits);
513553
static size_t maxMsgSize ()
514554
{ return sizeof(StressMsg) + maxArgCnt*sizeof(void*); }
515555

516556
friend void PopulateDebugHeaders();
517-
friend class ThreadStressLog;
518-
friend class StressLog;
519557
};
520558

559+
static_assert(sizeof(StressMsg) == sizeof(uint64_t) * 2, "StressMsg bitfields aren't aligned correctly");
560+
521561
#ifdef _WIN64
522562
#define STRESSLOG_CHUNK_SIZE (32 * 1024)
523563
#else //_WIN64
@@ -624,7 +664,7 @@ class ThreadStressLog {
624664

625665
private:
626666
FORCEINLINE bool IsReadyForRead() { return readPtr != NULL; }
627-
FORCEINLINE StressMsg* AdvanceRead();
667+
FORCEINLINE StressMsg* AdvanceRead(uint32_t cArgs);
628668
inline StressMsg* AdvReadPastBoundary();
629669
#endif //!DACCESS_COMPILE
630670

@@ -662,9 +702,9 @@ FORCEINLINE bool ThreadStressLog::CompletedDump ()
662702
//------------------------------------------------------------------------------------------
663703
// Called when dumping the log (by StressLog::Dump())
664704
// Updates readPtr to point to next stress messaage to be dumped
665-
inline StressMsg* ThreadStressLog::AdvanceRead() {
705+
inline StressMsg* ThreadStressLog::AdvanceRead(uint32_t cArgs) {
666706
// advance the marker
667-
readPtr = (StressMsg*)((char*)readPtr + sizeof(StressMsg) + readPtr->numberOfArgs*sizeof(void*));
707+
readPtr = (StressMsg*)((char*)readPtr + sizeof(StressMsg) + cArgs * sizeof(void*));
668708
// wrap around if we need to
669709
if (readPtr >= (StressMsg *)curReadChunk->EndPtr ())
670710
{

‎src/coreclr/nativeaot/Runtime/stressLog.cpp

Lines changed: 17 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -167,7 +167,7 @@ ThreadStressLog* StressLog::CreateThreadStressLogHelper(Thread * pThread) {
167167
if (msgs->isDead)
168168
{
169169
bool hasTimeStamp = msgs->curPtr != (StressMsg *)msgs->chunkListTail->EndPtr();
170-
if (hasTimeStamp && msgs->curPtr->timeStamp < recycleStamp)
170+
if (hasTimeStamp && msgs->curPtr->GetTimeStamp() < recycleStamp)
171171
{
172172
skipInsert = TRUE;
173173
PalInterlockedDecrement(&theLog.deadCount);
@@ -178,7 +178,7 @@ ThreadStressLog* StressLog::CreateThreadStressLogHelper(Thread * pThread) {
178178
{
179179
oldestDeadMsg = msgs;
180180
}
181-
else if (hasTimeStamp && oldestDeadMsg->curPtr->timeStamp > msgs->curPtr->timeStamp)
181+
else if (hasTimeStamp && oldestDeadMsg->curPtr->GetTimeStamp() > msgs->curPtr->GetTimeStamp())
182182
{
183183
oldestDeadMsg = msgs;
184184
}
@@ -307,26 +307,24 @@ void ThreadStressLog::LogMsg ( uint32_t facility, int cArgs, const char* format,
307307

308308
size_t offs = ((size_t)format - StressLog::theLog.moduleOffset);
309309

310-
ASSERT(offs < StressMsg::maxOffset);
311-
if (offs >= StressMsg::maxOffset)
310+
if (offs > StressMsg::maxOffset)
312311
{
313-
// Set it to this string instead.
314-
offs =
315-
#ifdef _DEBUG
316-
(size_t)"<BUG: StressLog format string beyond maxOffset>";
317-
#else // _DEBUG
318-
0; // a 0 offset is ignored by StressLog::Dump
319-
#endif // _DEBUG else
312+
// This string is at a location that is too far away from the base address of the module.
313+
// We can handle up to 68GB of native modules registered in the stresslog.
314+
// If you hit this break, and the NativeAOT image is not around 68GB,
315+
// there's either a bug or the string that was passed in is not a static string
316+
// in the module.
317+
PalDebugBreak();
318+
offs = 0;
320319
}
321320

322321
// Get next available slot
323322
StressMsg* msg = AdvanceWrite(cArgs);
324323

325-
msg->timeStamp = getTimeStamp();
326-
msg->facility = facility;
327-
msg->formatOffset = offs;
328-
msg->numberOfArgs = cArgs & 0x7;
329-
msg->numberOfArgsX = cArgs >> 3;
324+
msg->SetTimeStamp(getTimeStamp());
325+
msg->SetFacility(facility);
326+
msg->SetFormatOffset(offs);
327+
msg->SetNumberOfArgs(cArgs);
330328

331329
for ( int i = 0; i < cArgs; ++i )
332330
{
@@ -487,7 +485,7 @@ ThreadStressLog* StressLog::FindLatestThreadLog() const
487485
for (const ThreadStressLog* ptr = this->logs; ptr != NULL; ptr = ptr->next)
488486
{
489487
if (ptr->readPtr != NULL)
490-
if (latestLog == 0 || ptr->readPtr->timeStamp > latestLog->readPtr->timeStamp)
488+
if (latestLog == 0 || ptr->readPtr->GetTimeStamp() > latestLog->readPtr->GetTimeStamp())
491489
latestLog = ptr;
492490
}
493491
return const_cast<ThreadStressLog*>(latestLog);
@@ -517,14 +515,14 @@ void StressLog::EnumerateStressMsgs(/*STRESSMSGCALLBACK*/void* smcbWrapper, /*EN
517515
if (hr != S_OK)
518516
strcpy_s(format, _countof(format), "Could not read address of format string");
519517

520-
double deltaTime = ((double) (latestMsg->timeStamp - this->startTimeStamp)) / this->tickFrequency;
518+
double deltaTime = ((double) (latestMsg->GetTimeStamp() - this->startTimeStamp)) / this->tickFrequency;
521519

522520
// Pass a copy of the args to the callback to avoid foreign code overwriting the stress log
523521
// entries (this was the case for %s arguments)
524522
memcpy_s(argsCopy, sizeof(argsCopy), latestMsg->args, (latestMsg->numberOfArgs)*sizeof(void*));
525523

526524
// @TODO: Truncating threadId to 32-bit
527-
if (!smcb((UINT32)latestLog->threadId, deltaTime, latestMsg->facility, format, argsCopy, token))
525+
if (!smcb((UINT32)latestLog->threadId, deltaTime, latestMsg->GetFacility(), format, argsCopy, token))
528526
break;
529527
}
530528

0 commit comments

Comments
 (0)