Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Enable StressLogAnalyzer to read stress logs from old coreclr running with a new clrgc. #88852

Merged
merged 1 commit into from
Jul 14, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 3 additions & 1 deletion src/coreclr/inc/stresslog.h
Original file line number Diff line number Diff line change
Expand Up @@ -372,7 +372,9 @@ class StressLog {
{
size_t headerSize; // size of this header including size field and moduleImage
uint32_t magic; // must be 'STRL'
uint32_t version; // must be 0x00010001
uint32_t version; // must be >=0x00010001.
// 0x00010001 is the legacy short-offset format.
// 0x00010002 is the large-module-offset format introduced in .NET 8.
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you for adding this comment!

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good to me - thank you!

uint8_t* memoryBase; // base address of the memory mapped file
uint8_t* memoryCur; // highest address currently used
uint8_t* memoryLimit; // limit that can be used
Expand Down
29 changes: 15 additions & 14 deletions src/coreclr/tools/StressLogAnalyzer/StressLogDump.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -22,10 +22,11 @@ class MapViewHolder
#endif // STRESS_LOG
#define STRESS_LOG_READONLY
#include "../../../inc/stresslog.h"
#include "StressMsgReader.h"


void GcHistClear();
void GcHistAddLog(LPCSTR msg, StressMsg* stressMsg);
void GcHistAddLog(LPCSTR msg, StressMsgReader stressMsg);


/*********************************************************************************/
Expand Down Expand Up @@ -57,7 +58,7 @@ ThreadStressLog* ThreadStressLog::FindLatestThreadLog() const
for (const ThreadStressLog* ptr = this; ptr != NULL; ptr = ptr->next)
{
if (ptr->readPtr != NULL)
if (latestLog == 0 || ptr->readPtr->GetTimeStamp() > latestLog->readPtr->GetTimeStamp())
if (latestLog == 0 || StressMsgReader(ptr->readPtr).GetTimeStamp() > StressMsgReader(latestLog->readPtr).GetTimeStamp())
latestLog = ptr;
}
return const_cast<ThreadStressLog*>(latestLog);
Expand Down Expand Up @@ -423,9 +424,9 @@ HRESULT StressLog::Dump(ULONG64 outProcLog, const char* fileName, struct IDebugD

// TODO: fix on 64 bit
inProcPtr->Activate ();
if (inProcPtr->readPtr->GetTimeStamp() > lastTimeStamp)
if (StressMsgReader(inProcPtr->readPtr).GetTimeStamp() > lastTimeStamp)
{
lastTimeStamp = inProcPtr->readPtr->GetTimeStamp();
lastTimeStamp = StressMsgReader(inProcPtr->readPtr).GetTimeStamp();
}

outProcPtr = TO_CDADDR(inProcPtr->next);
Expand Down Expand Up @@ -488,40 +489,40 @@ HRESULT StressLog::Dump(ULONG64 outProcLog, const char* fileName, struct IDebugD
break;
}

StressMsg* latestMsg = latestLog->readPtr;
if (latestMsg->GetFormatOffset() != 0 && !latestLog->CompletedDump())
StressMsgReader latestMsg = latestLog->readPtr;
if (latestMsg.GetFormatOffset() != 0 && !latestLog->CompletedDump())
{
TADDR taFmt = (latestMsg->GetFormatOffset()) + TO_TADDR(g_hThisInst);
TADDR taFmt = (latestMsg.GetFormatOffset()) + TO_TADDR(g_hThisInst);
hr = memCallBack->ReadVirtual(TO_CDADDR(taFmt), format, 256, 0);
if (hr != S_OK)
strcpy_s(format, ARRAY_SIZE(format), "Could not read address of format string");

double deltaTime = ((double) (latestMsg->GetTimeStamp() - inProcLog.startTimeStamp)) / inProcLog.tickFrequency;
double deltaTime = ((double) (latestMsg.GetTimeStamp() - inProcLog.startTimeStamp)) / inProcLog.tickFrequency;
if (bDoGcHist)
{
if (strcmp(format, ThreadStressLog::TaskSwitchMsg()) == 0)
{
latestLog->threadId = (unsigned)(size_t)latestMsg->args[0];
latestLog->threadId = (unsigned)(size_t)latestMsg.GetArgs()[0];
}
GcHistAddLog(format, latestMsg);
}
else
{
if (strcmp(format, ThreadStressLog::TaskSwitchMsg()) == 0)
{
fprintf (file, "Task was switched from %x\n", (unsigned)(size_t)latestMsg->args[0]);
latestLog->threadId = (unsigned)(size_t)latestMsg->args[0];
fprintf (file, "Task was switched from %x\n", (unsigned)(size_t)latestMsg.GetArgs()[0]);
latestLog->threadId = (unsigned)(size_t)latestMsg.GetArgs()[0];
}
else
{
args = latestMsg->args;
formatOutput(memCallBack, file, format, (unsigned)latestLog->threadId, deltaTime, latestMsg->GetFacility(), args);
args = latestMsg.GetArgs();
formatOutput(memCallBack, file, format, (unsigned)latestLog->threadId, deltaTime, latestMsg.GetFacility(), args);
}
}
msgCtr++;
}

latestLog->readPtr = latestLog->AdvanceRead(latestMsg->GetNumberOfArgs());
latestLog->readPtr = latestLog->AdvanceRead(latestMsg.GetNumberOfArgs());
if (latestLog->CompletedDump())
{
latestLog->readPtr = NULL;
Expand Down
61 changes: 32 additions & 29 deletions src/coreclr/tools/StressLogAnalyzer/StressLogPlugin.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,7 @@ bool IsInCantAllocStressLogRegion()

#include <stddef.h>
#include "../../../inc/stresslog.h"
#include "StressMsgReader.h"

size_t StressLog::writing_base_address;
size_t StressLog::reading_base_address;
Expand Down Expand Up @@ -67,7 +68,7 @@ void GcHistClear()
{
}

void GcHistAddLog(LPCSTR msg, StressMsg* stressMsg)
void GcHistAddLog(LPCSTR msg, StressMsgReader stressMsg)
{
}

Expand Down Expand Up @@ -531,7 +532,7 @@ bool FilterMessage(StressLog::StressLogHeader* hdr, ThreadStressLog* tsl, uint32
struct StressThreadAndMsg
{
uint64_t threadId;
StressMsg* msg;
StressMsgReader msg;
uint64_t msgId;
};

Expand All @@ -540,9 +541,9 @@ int CmpMsg(const void* p1, const void* p2)
const StressThreadAndMsg* msg1 = (const StressThreadAndMsg*)p1;
const StressThreadAndMsg* msg2 = (const StressThreadAndMsg*)p2;

if (msg1->msg->GetTimeStamp() < msg2->msg->GetTimeStamp())
if (msg1->msg.GetTimeStamp() < msg2->msg.GetTimeStamp())
return 1;
if (msg1->msg->GetTimeStamp() > msg2->msg->GetTimeStamp())
if (msg1->msg.GetTimeStamp() > msg2->msg.GetTimeStamp())
return -11;

if (msg1->threadId < msg2->threadId)
Expand All @@ -564,7 +565,7 @@ struct ThreadStressLogDesc
volatile LONG workStarted;
volatile LONG workFinished;
ThreadStressLog* tsl;
StressMsg* earliestMessage;
StressMsgReader earliestMessage;

ThreadStressLogDesc() : workStarted(0), workFinished(0), tsl(nullptr), earliestMessage(nullptr)
{
Expand All @@ -584,7 +585,7 @@ static double s_timeFilterStart = 0;
static double s_timeFilterEnd = 0;
static const char* s_outputFileName = nullptr;

static StressLog::StressLogHeader* s_hdr;
StressLog::StressLogHeader* s_hdr;

static bool s_fPrintFormatStrings;

Expand Down Expand Up @@ -1056,7 +1057,7 @@ bool ParseOptions(int argc, char* argv[])
return true;
}

static void IncludeMessage(uint64_t threadId, StressMsg* msg)
static void IncludeMessage(uint64_t threadId, StressMsgReader msg)
{
LONGLONG msgCount = InterlockedIncrement64(&s_msgCount) - 1;
if (msgCount < MAX_MESSAGE_COUNT)
Expand Down Expand Up @@ -1089,10 +1090,10 @@ DWORD WINAPI ProcessStresslogWorker(LPVOID)
wrappedWriteThreadCount++;
}
// printf("thread: %zx\n", tsl->threadId);
StressMsg* msg = StressLog::TranslateMemoryMappedPointer(tsl->curPtr);
void* msg = StressLog::TranslateMemoryMappedPointer(tsl->curPtr);
StressLogChunk* slc = StressLog::TranslateMemoryMappedPointer(tsl->curWriteChunk);
int chunkCount = 0;
StressMsg* prevMsg = nullptr;
void* prevMsg = nullptr;
while (true)
{
// printf("stress log chunk %zx\n", (size_t)slc);
Expand Down Expand Up @@ -1135,14 +1136,15 @@ DWORD WINAPI ProcessStresslogWorker(LPVOID)
{
while (p < end && *p == 0)
p++;
msg = (StressMsg*)p;
msg = (void*)p;
}
StressMsg* endMsg = (StressMsg*)end;
void* endMsg = (void*)end;
while (msg < endMsg)
{
StressMsgReader msgReader(msg);
totalMsgCount++;
char* format = (char*)(hdr->moduleImage + msg->GetFormatOffset());
double deltaTime = ((double)(msg->GetTimeStamp() - hdr->startTimeStamp)) / hdr->tickFrequency;
char* format = (char*)(hdr->moduleImage + msgReader.GetFormatOffset());
double deltaTime = ((double)(msgReader.GetTimeStamp() - hdr->startTimeStamp)) / hdr->tickFrequency;
bool fIgnoreMessage = false;
if (fTimeFilter)
{
Expand All @@ -1156,17 +1158,17 @@ DWORD WINAPI ProcessStresslogWorker(LPVOID)
fIgnoreMessage = true;
}
}
int numberOfArgs = msg->GetNumberOfArgs();
int numberOfArgs = msgReader.GetNumberOfArgs();
if (!fIgnoreMessage)
{
bool fIncludeMessage = s_showAllMessages || FilterMessage(hdr, tsl, msg->GetFacility(), format, deltaTime, numberOfArgs, msg->args);
bool fIncludeMessage = s_showAllMessages || FilterMessage(hdr, tsl, msgReader.GetFacility(), format, deltaTime, numberOfArgs, msgReader.GetArgs());
if (!fIncludeMessage && s_valueFilterCount > 0)
{
for (int i = 0; i < numberOfArgs; i++)
{
for (int j = 0; j < s_valueFilterCount; j++)
{
if (s_valueFilter[j].start <= (size_t)msg->args[i] && (size_t)msg->args[i] <= s_valueFilter[j].end)
if (s_valueFilter[j].start <= (size_t)msgReader.GetArgs()[i] && (size_t)msgReader.GetArgs()[i] <= s_valueFilter[j].end)
{
fIncludeMessage = true;
break;
Expand All @@ -1182,7 +1184,7 @@ DWORD WINAPI ProcessStresslogWorker(LPVOID)
}
}
prevMsg = msg;
msg = (StressMsg*)&msg->args[numberOfArgs];
msg = (StressMsg*)&msgReader.GetArgs()[numberOfArgs];
}
if (slc == StressLog::TranslateMemoryMappedPointer(tsl->chunkListTail) && !tsl->writeHasWrapped)
break;
Expand Down Expand Up @@ -1233,16 +1235,16 @@ static void PrintFriendlyNumber(LONGLONG n)
printf("%11.9f billion", n / 1000000000.0);
}

static void PrintMessage(CorClrData& corClrData, FILE *outputFile, uint64_t threadId, StressMsg* msg)
static void PrintMessage(CorClrData& corClrData, FILE *outputFile, uint64_t threadId, StressMsgReader msg)
{
void* argBuffer[StressMsg::maxArgCnt];
char* format = (char*)(s_hdr->moduleImage + msg->GetFormatOffset());
int numberOfArgs = msg->GetNumberOfArgs();
char* format = (char*)(s_hdr->moduleImage + msg.GetFormatOffset());
int numberOfArgs = msg.GetNumberOfArgs();
for (int i = 0; i < numberOfArgs; i++)
{
argBuffer[i] = msg->args[i];
argBuffer[i] = msg.GetArgs()[i];
}
double deltaTime = ((double)(msg->GetTimeStamp() - s_hdr->startTimeStamp)) / s_hdr->tickFrequency;
double deltaTime = ((double)(msg.GetTimeStamp() - s_hdr->startTimeStamp)) / s_hdr->tickFrequency;
if (!s_printHexTidForGcThreads)
{
GcThread gcThread;
Expand All @@ -1255,7 +1257,7 @@ static void PrintMessage(CorClrData& corClrData, FILE *outputFile, uint64_t thre
threadId |= 0x4000000000000000;
}
}
formatOutput(&corClrData, outputFile, format, threadId, deltaTime, msg->GetFacility(), argBuffer, s_fPrintFormatStrings);
formatOutput(&corClrData, outputFile, format, threadId, deltaTime, msg.GetFacility(), argBuffer, s_fPrintFormatStrings);
}

int ProcessStressLog(void* baseAddress, int argc, char* argv[])
Expand Down Expand Up @@ -1301,7 +1303,8 @@ int ProcessStressLog(void* baseAddress, int argc, char* argv[])
StressLog::StressLogHeader* hdr = (StressLog::StressLogHeader*)baseAddress;
if (hdr->headerSize != sizeof(*hdr) ||
hdr->magic != *(uint32_t*)"LRTS" ||
hdr->version != 0x00010001)
(hdr->version != 0x00010001 &&
hdr->version != 0x00010002))
{
printf("Unrecognized file format\n");
return 1;
Expand Down Expand Up @@ -1383,8 +1386,8 @@ int ProcessStressLog(void* baseAddress, int argc, char* argv[])
int remMsgCount = 0;
for (int msgIndex = 0; msgIndex < s_msgCount; msgIndex++)
{
StressMsg* msg = s_threadMsgBuf[msgIndex].msg;
double deltaTime = ((double)(msg->GetTimeStamp() - hdr->startTimeStamp)) / hdr->tickFrequency;
StressMsgReader msg = s_threadMsgBuf[msgIndex].msg;
double deltaTime = ((double)(msg.GetTimeStamp() - hdr->startTimeStamp)) / hdr->tickFrequency;
if (startTime <= deltaTime && deltaTime <= endTime)
{
s_threadMsgBuf[remMsgCount] = s_threadMsgBuf[msgIndex];
Expand Down Expand Up @@ -1463,7 +1466,7 @@ int ProcessStressLog(void* baseAddress, int argc, char* argv[])
for (LONGLONG i = 0; i < s_msgCount; i++)
{
uint64_t threadId = (unsigned)s_threadMsgBuf[i].threadId;
StressMsg* msg = s_threadMsgBuf[i].msg;
StressMsgReader msg = s_threadMsgBuf[i].msg;
PrintMessage(corClrData, outputFile, threadId, msg);
}

Expand Down Expand Up @@ -1500,7 +1503,7 @@ int ProcessStressLog(void* baseAddress, int argc, char* argv[])
LONGLONG earliestStartCount = s_msgCount;
for (int threadStressLogIndex = 0; threadStressLogIndex < s_threadStressLogCount; threadStressLogIndex++)
{
StressMsg* msg = s_threadStressLogDesc[threadStressLogIndex].earliestMessage;
StressMsgReader msg = s_threadStressLogDesc[threadStressLogIndex].earliestMessage;
if (msg == nullptr)
continue;
bool fIncludeMessage = s_printEarliestMessages;
Expand All @@ -1525,7 +1528,7 @@ int ProcessStressLog(void* baseAddress, int argc, char* argv[])
for (LONGLONG i = earliestStartCount; i < s_msgCount; i++)
{
uint64_t threadId = (unsigned)s_threadMsgBuf[i].threadId;
StressMsg* msg = s_threadMsgBuf[i].msg;
StressMsgReader msg = s_threadMsgBuf[i].msg;
PrintMessage(corClrData, outputFile, threadId, msg);
}
}
Expand Down
80 changes: 80 additions & 0 deletions src/coreclr/tools/StressLogAnalyzer/StressMsgReader.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,80 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.

#include <stdint.h>

extern StressLog::StressLogHeader* s_hdr;

// A version-aware reader for memory-mapped stress log messages.
struct StressMsgReader
{
private:
struct StressMsgSmallOffset
{
uint32_t numberOfArgsLow : 3; // at most 7 arguments here
uint32_t formatOffset : 26; // low bits offset of format string in modules
uint32_t numberOfArgsHigh : 3; // extend number of args in a backward compat way
uint32_t facility; // facility used to log the entry
uint64_t timeStamp; // time when mssg was logged
void* args[0]; // variable number of arguments
};

void* m_rawMsg;
public:
StressMsgReader() = default;

StressMsgReader(void* msg)
:m_rawMsg(msg)
{
}

uint64_t GetFormatOffset() const
{
if (s_hdr->version == 0x00010001)
{
return ((StressMsgSmallOffset*)m_rawMsg)->formatOffset;
}
return ((StressMsg*)m_rawMsg)->GetFormatOffset();
}

uint32_t GetNumberOfArgs() const
{
if (s_hdr->version == 0x00010001)
{
return ((StressMsgSmallOffset*)m_rawMsg)->numberOfArgsHigh << 3 | ((StressMsgSmallOffset*)m_rawMsg)->numberOfArgsLow;
}
return ((StressMsg*)m_rawMsg)->GetNumberOfArgs();
}

uint32_t GetFacility() const
{
if (s_hdr->version == 0x00010001)
{
return ((StressMsgSmallOffset*)m_rawMsg)->facility;
}
return ((StressMsg*)m_rawMsg)->GetFacility();
}

uint64_t GetTimeStamp() const
{
if (s_hdr->version == 0x00010001)
{
return ((StressMsgSmallOffset*)m_rawMsg)->timeStamp;
}
return ((StressMsg*)m_rawMsg)->GetTimeStamp();
}

void** GetArgs() const
{
if (s_hdr->version == 0x00010001)
{
return ((StressMsgSmallOffset*)m_rawMsg)->args;
}
return ((StressMsg*)m_rawMsg)->args;
}

bool operator==(std::nullptr_t) const
{
return m_rawMsg == nullptr;
}
};
2 changes: 1 addition & 1 deletion src/coreclr/utilcode/stresslog.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -266,7 +266,7 @@ void StressLog::Initialize(unsigned facilities, unsigned level, unsigned maxByte
StressLogHeader* hdr = (StressLogHeader*)(uint8_t*)(void*)theLog.hMapView;
hdr->headerSize = sizeof(StressLogHeader);
hdr->magic = *(uint32_t*)"LRTS";
hdr->version = 0x00010001;
hdr->version = 0x00010002;
hdr->memoryBase = (uint8_t*)hdr;
hdr->memoryCur = hdr->memoryBase + sizeof(StressLogHeader);
hdr->memoryLimit = hdr->memoryBase + maxBytesTotal;
Expand Down