diff --git a/BeefLibs/corlib/src/Diagnostics/Profiler.bf b/BeefLibs/corlib/src/Diagnostics/Profiler.bf index f9fdbf54..f221cd70 100644 --- a/BeefLibs/corlib/src/Diagnostics/Profiler.bf +++ b/BeefLibs/corlib/src/Diagnostics/Profiler.bf @@ -10,12 +10,23 @@ namespace System.Diagnostics struct ProfileInstance : int32 { - public void Dispose() + public bool HasValue { + get + { + return this != 0; + } + } + + public void Dispose() mut + { + if (this == 0) + return; String str = scope String(); str.Append("StopSampling\t"); ((int32)this).ToString(str); Internal.ProfilerCmd(str); + this = 0; } } diff --git a/IDE/src/Compiler/BfParser.bf b/IDE/src/Compiler/BfParser.bf index 15ab5174..ae592597 100644 --- a/IDE/src/Compiler/BfParser.bf +++ b/IDE/src/Compiler/BfParser.bf @@ -79,6 +79,7 @@ namespace IDE.Compiler public int32 mTextVersion = -1; public bool mIsUserRequested; public Stopwatch mStopwatch ~ delete _; + public ProfileInstance mProfileInstance ~ _.Dispose(); } public class BfParser : ILeakIdentifiable diff --git a/IDE/src/ui/ProfilePanel.bf b/IDE/src/ui/ProfilePanel.bf index 2ca2beb8..033c553e 100644 --- a/IDE/src/ui/ProfilePanel.bf +++ b/IDE/src/ui/ProfilePanel.bf @@ -293,6 +293,10 @@ namespace IDE.ui } } + struct ThreadEntry : this(int32 mThreadId, int32 mCPUUsage, StringView mName) + { + } + void PopulateThreadList(Menu menu) { if (mProfiler == null) @@ -307,6 +311,7 @@ namespace IDE.ui var threadListStr = scope String(); mProfiler.GetThreadList(threadListStr); + List entries = scope .(); for (var entry in threadListStr.Split('\n')) { if (entry.Length == 0) @@ -314,20 +319,35 @@ namespace IDE.ui var dataItr = entry.Split('\t'); - int32 threadId = int32.Parse(dataItr.GetNext()); - StringView threadName = dataItr.GetNext(); + ThreadEntry threadEntry = default; + threadEntry.mThreadId = int32.Parse(dataItr.GetNext()); + threadEntry.mCPUUsage = int32.Parse(dataItr.GetNext()); + threadEntry.mName = dataItr.GetNext(); + entries.Add(threadEntry); + } + entries.Sort(scope (lhs, rhs) => + { + int cmp = rhs.mCPUUsage <=> lhs.mCPUUsage; + if (cmp == 0) + cmp = lhs.mThreadId <=> rhs.mThreadId; + return cmp; + }); + + for (var entry in entries) + { String threadStr = null; var str = scope String(); - str.AppendF("{0}", threadId); - if (!threadName.IsEmpty) + str.AppendF("{0}", entry.mThreadId); + str.AppendF($" ({entry.mCPUUsage}%)"); + if (!entry.mName.IsEmpty) { - threadStr = new String(threadName); - str.AppendF(" - {0}", threadName); + threadStr = new String(entry.mName); + str.AppendF($" - {entry.mName}"); } subItem = menu.AddItem(str); - subItem.mOnMenuItemSelected.Add(new (item) => { Show(threadId, threadStr); } ~ delete threadStr); + subItem.mOnMenuItemSelected.Add(new (item) => { Show(entry.mThreadId, threadStr); } ~ delete threadStr); } } diff --git a/IDE/src/ui/SourceViewPanel.bf b/IDE/src/ui/SourceViewPanel.bf index 29441252..8e75ddb1 100644 --- a/IDE/src/ui/SourceViewPanel.bf +++ b/IDE/src/ui/SourceViewPanel.bf @@ -620,6 +620,8 @@ namespace IDE.ui ResolveParams resolveParams = new ResolveParams(); if (gApp.mDbgTimeAutocomplete) resolveParams.mStopwatch = new .()..Start(); + if (gApp.mDbgPerfAutocomplete) + resolveParams.mProfileInstance = Profiler.StartSampling("Autocomplete").GetValueOrDefault(); resolveParams.mIsUserRequested = options.HasFlag(.UserRequested); Classify(.Autocomplete, resolveParams); if (!resolveParams.mInDeferredList) diff --git a/IDEHelper/Profiler.cpp b/IDEHelper/Profiler.cpp index 1cca8c3c..ba6e6c8b 100644 --- a/IDEHelper/Profiler.cpp +++ b/IDEHelper/Profiler.cpp @@ -8,12 +8,12 @@ typedef LONG KPRIORITY; USING_NS_BF_DBG; -enum SYSTEM_INFORMATION_CLASS +enum SYSTEM_INFORMATION_CLASS { SystemProcessInformation = 5 }; // SYSTEM_INFORMATION_CLASS -struct CLIENT_ID +struct CLIENT_ID { HANDLE UniqueProcess; HANDLE UniqueThread; @@ -81,14 +81,14 @@ struct SYSTEM_PROCESS_INFORMATION SYSTEM_THREAD Threads[1]; }; -typedef NTSTATUS(NTAPI *NtQuerySystemInformation_t)(SYSTEM_INFORMATION_CLASS, PVOID, ULONG, PULONG); +typedef NTSTATUS(NTAPI* NtQuerySystemInformation_t)(SYSTEM_INFORMATION_CLASS, PVOID, ULONG, PULONG); static NtQuerySystemInformation_t NtQuerySystemInformation = NULL; static HMODULE ntdll = NULL; DbgProfiler::DbgProfiler(WinDebugger* debugger) : mShutdownEvent(true) { mDebugger = debugger; - mIsRunning = false; + mIsRunning = false; mWantsClear = false; mSamplesPerSecond = 1000; @@ -101,6 +101,12 @@ DbgProfiler::DbgProfiler(WinDebugger* debugger) : mShutdownEvent(true) mEndTick = 0; mDebugger->AddProfiler(this); + + mIdleSymbolNames.Add("ZwDelayExecution"); + mIdleSymbolNames.Add("ZwWaitForWorkViaWorkerFactory"); + mIdleSymbolNames.Add("NtWaitForAlertByThreadId"); + mIdleSymbolNames.Add("NtWaitForSingleObject"); + mIdleSymbolNames.Add("NtWaitForMultipleObjects"); } DbgProfiler::~DbgProfiler() @@ -113,14 +119,14 @@ DbgProfiler::~DbgProfiler() } static SYSTEM_PROCESS_INFORMATION* CaptureProcessInfo() -{ +{ WCHAR path[MAX_PATH]; GetSystemDirectory(path, MAX_PATH); - wcscat(path, L"\\ntdll.dll"); - ntdll = GetModuleHandle(path); + wcscat(path, L"\\ntdll.dll"); + ntdll = GetModuleHandle(path); if (ntdll == NULL) return NULL; - NtQuerySystemInformation = (NtQuerySystemInformation_t)GetProcAddress(ntdll, "NtQuerySystemInformation"); + NtQuerySystemInformation = (NtQuerySystemInformation_t)GetProcAddress(ntdll, "NtQuerySystemInformation"); uint allocSize = 1024; uint8* data = NULL; @@ -134,7 +140,7 @@ static SYSTEM_PROCESS_INFORMATION* CaptureProcessInfo() if (status != STATUS_INFO_LENGTH_MISMATCH) return (SYSTEM_PROCESS_INFORMATION*)data; - + allocSize = wantSize + 4096; delete data; } @@ -148,8 +154,8 @@ void DbgProfiler::DoClear() delete val.mProcId; } -ProfileProcId* DbgProfiler::Get(const StringImpl& str) -{ +ProfileProcId* DbgProfiler::Get(const StringImpl& str, bool* outIsNew) +{ ProfileProdIdEntry checkEntry; checkEntry.mProcId = (ProfileProcId*)&str; @@ -158,11 +164,16 @@ ProfileProcId* DbgProfiler::Get(const StringImpl& str) { auto procId = new ProfileProcId(); procId->mProcName = str; - entryPtr->mProcId = procId; + procId->mIsIdle = false; + entryPtr->mProcId = procId; + if (outIsNew != NULL) + *outIsNew = true; return procId; } else { + if (outIsNew != NULL) + *outIsNew = false; return entryPtr->mProcId; } } @@ -170,7 +181,7 @@ ProfileProcId* DbgProfiler::Get(const StringImpl& str) void DbgProfiler::ThreadProc() { //TODO: Do timing smarter, handle delays and slow stack traces and stuff - + //timeBeginPeriod(1); BF_ASSERT(mTotalVirtualSamples == 0); @@ -184,7 +195,7 @@ void DbgProfiler::ThreadProc() uint32 accumMS = 0; int totalWait = 0; - int totalWait2 = 0; + int totalWait2 = 0; int iterations = 0; HashSet idleThreadSet; @@ -218,9 +229,11 @@ void DbgProfiler::ThreadProc() iterations++; DWORD startTick0 = timeGetTime(); idleThreadSet.Clear(); - + SYSTEM_PROCESS_INFORMATION* processData = NULL; - std::unique_ptr ptrDelete(processData); + std::unique_ptr ptrDelete(processData); + + //processData = CaptureProcessInfo(); auto curProcessData = processData; while (true) @@ -235,6 +248,7 @@ void DbgProfiler::ThreadProc() auto& threadInfo = curProcessData->Threads[threadIdx]; if ((threadInfo.State == StateWait) || (threadInfo.State == StateTerminated)) idleThreadSet.Add((int)(intptr)threadInfo.ClientId.UniqueThread); + break; } } @@ -242,12 +256,12 @@ void DbgProfiler::ThreadProc() break; curProcessData = (SYSTEM_PROCESS_INFORMATION*)((intptr)curProcessData + curProcessData->NextEntryOffset); } - + if (mShutdownEvent.WaitFor(0)) { break; } - + DWORD tickNow = timeGetTime(); accumMS += (int)(tickNow - prevSampleTick); prevSampleTick = tickNow; @@ -284,21 +298,21 @@ void DbgProfiler::ThreadProc() mTotalVirtualSamples += curSampleCount; mTotalActualSamples++; - + int threadIdx = 0; while (true) - { + { int startTick = timeGetTime(); - AutoCrit autoCrit(mDebugger->mDebugManager->mCritSect); - - if (mDebugger->mRunState != RunState_Running) - break; + AutoCrit autoCrit(mDebugger->mDebugManager->mCritSect); + + if (mDebugger->mRunState != RunState_Running) + break; if (threadIdx >= mDebugger->mThreadList.size()) break; - auto thread = mDebugger->mThreadList[threadIdx]; + auto thread = mDebugger->mThreadList[threadIdx]; if ((mTargetThreadId > 0) && (thread->mThreadId != mTargetThreadId)) { @@ -321,20 +335,22 @@ void DbgProfiler::ThreadProc() profileThreadInfo = *profileThreadInfoPtr; } - profileThreadInfo->mTotalSamples += curSampleCount; - bool isThreadIdle = idleThreadSet.Contains(thread->mThreadId); + profileThreadInfo->mTotalSamples += curSampleCount; + if (isThreadIdle) + profileThreadInfo->mTotalIdleSamples += curSampleCount; + mDebugger->mActiveThread = thread; - - ::SuspendThread(thread->mHThread); + + ::SuspendThread(thread->mHThread); CPURegisters registers; mDebugger->PopulateRegisters(®isters); int stackSize = 0; - for (int stackIdx = 0 ; stackIdx < maxStackTrace; stackIdx++) - { + for (int stackIdx = 0; stackIdx < maxStackTrace; stackIdx++) + { auto pc = registers.GetPC(); if (pc <= 0xFFFF) { @@ -353,7 +369,7 @@ void DbgProfiler::ThreadProc() ProfileAddrEntry* insertedProfileEntry = AddToSet(mProfileAddrEntrySet, stackTrace, stackSize); if (insertedProfileEntry->mEntryIdx == -1) - { + { insertedProfileEntry->mEntryIdx = (int)mProfileAddrEntrySet.size(); // Starts at '1' mPendingProfileEntries.Add(*insertedProfileEntry); } @@ -365,7 +381,7 @@ void DbgProfiler::ThreadProc() entryIdx = -entryIdx; profileThreadInfo->mProfileAddrEntries.push_back(entryIdx); } - + ::ResumeThread(thread->mHThread); int elapsedTime = timeGetTime() - startTick; @@ -379,7 +395,7 @@ void DbgProfiler::ThreadProc() } } - mIsRunning = false; + mIsRunning = false; mEndTick = BFTickCount(); } @@ -394,7 +410,7 @@ void DbgProfiler::Start() BF_ASSERT(!mIsRunning); mNeedsProcessing = true; - mIsRunning = true; + mIsRunning = true; auto thread = BfpThread_Create(ThreadProcThunk, (void*)this, 128 * 1024, BfpThreadCreateFlag_StackSizeReserve); BfpThread_Release(thread); } @@ -439,22 +455,25 @@ String DbgProfiler::GetThreadList() for (auto threadId : mThreadIdList) { auto threadInfo = mThreadInfo[threadId]; - result += StrFormat("%d\t%s\n", threadId, threadInfo->mName.c_str()); + int cpuUsage = 0; + if (threadInfo->mTotalSamples > 0) + cpuUsage = 100 - (threadInfo->mTotalIdleSamples * 100 / threadInfo->mTotalSamples); + result += StrFormat("%d\t%d\t%s\n", threadId, cpuUsage, threadInfo->mName.c_str()); } return result; } void DbgProfiler::AddEntries(String& str, Array& procEntries, int rangeStart, int rangeEnd, int stackIdx, ProfileProcId* findProc) -{ +{ struct _QueuedEntry { int mRangeIdx; int mRangeEnd; - int mStackIdx; + int mStackIdx; }; Array<_QueuedEntry> workQueue; - + auto _AddEntries = [&](int rangeStart, int rangeEnd, int stackIdx, ProfileProcId* findProc) { int selfSampleCount = 0; @@ -521,7 +540,7 @@ void DbgProfiler::AddEntries(String& str, Array& procEntries, _QueuedEntry entry; entry.mRangeIdx = rangeStart; entry.mRangeEnd = rangeEnd; - entry.mStackIdx = stackIdx; + entry.mStackIdx = stackIdx; workQueue.Add(entry); }; _AddEntries(rangeStart, rangeEnd, stackIdx, findProc); @@ -529,7 +548,7 @@ void DbgProfiler::AddEntries(String& str, Array& procEntries, while (!workQueue.IsEmpty()) { auto& entry = workQueue.back(); - + bool addedChild = false; while (entry.mRangeIdx < entry.mRangeEnd) { @@ -539,7 +558,7 @@ void DbgProfiler::AddEntries(String& str, Array& procEntries, entry.mRangeIdx++; continue; } - + int nextStackIdx = entry.mStackIdx + 1; auto nextFindProc = procEntry->mData[procEntry->mSize - 1 - nextStackIdx]; _AddEntries(entry.mRangeIdx, entry.mRangeEnd, nextStackIdx, nextFindProc); @@ -552,7 +571,7 @@ void DbgProfiler::AddEntries(String& str, Array& procEntries, if (entry.mStackIdx != -1) str += "-\n"; workQueue.pop_back(); - } + } } } @@ -608,7 +627,10 @@ void DbgProfiler::HandlePendingEntries() symbolName += StrFormat("0x%@", addr); } - procId = Get(symbolName); + bool isNew = false; + procId = Get(symbolName, &isNew); + if (isNew) + procId->mIsIdle = mIdleSymbolNames.Contains(symbolName); } if (reverse) @@ -640,11 +662,11 @@ void DbgProfiler::Process() AutoCrit autoCrit(mDebugger->mDebugManager->mCritSect); mNeedsProcessing = false; - + int time = mTotalActiveSamplingMS; BF_ASSERT(mProfileAddrEntries.IsEmpty()); - + mProfileAddrEntries.Resize(mProfileAddrEntrySet.size() + 1); for (auto& val : mProfileAddrEntrySet) mProfileAddrEntries[val.mEntryIdx] = &val; @@ -654,16 +676,35 @@ void DbgProfiler::Process() for (auto& val : mProfileProcEntrySet) mProfileProcEntries[val.mEntryIdx] = &val; + for (auto threadKV : mThreadInfo) + { + auto threadInfo = threadKV.mValue; + + for (auto addrEntryIdx : threadInfo->mProfileAddrEntries) + { + if (addrEntryIdx < 0) + { + addrEntryIdx = -addrEntryIdx; + } + + int procEntryIdx = mProfileAddrToProcMap[addrEntryIdx]; + auto procEntry = mProfileProcEntries[procEntryIdx]; + + auto curProc = procEntry->mData[0]; + if (curProc->mIsIdle) + threadInfo->mTotalIdleSamples++; + } + } } String DbgProfiler::GetCallTree(int threadId, bool reverse) -{ +{ if (mNeedsProcessing) Process(); AutoCrit autoCrit(mDebugger->mDebugManager->mCritSect); - BF_ASSERT(!mIsRunning); + BF_ASSERT(!mIsRunning); Array procEntries; @@ -714,10 +755,10 @@ String DbgProfiler::GetCallTree(int threadId, bool reverse) int idleTicks = totalSampleCount - totalActiveSampleCount; if (idleTicks != 0) str += StrFormat("\t%d\t0\n-\n", idleTicks); - + AddEntries(str, procEntries, 0, (int)procEntries.size(), -1, NULL); - - str += "-\n"; + + str += "-\n"; //BF_ASSERT(childSampleCount == totalSampleCount); diff --git a/IDEHelper/Profiler.h b/IDEHelper/Profiler.h index b8a0a64a..018fa548 100644 --- a/IDEHelper/Profiler.h +++ b/IDEHelper/Profiler.h @@ -67,6 +67,7 @@ class ProfileProcId { public: String mProcName; + bool mIsIdle; }; class ProfileProdIdEntry @@ -104,12 +105,14 @@ class ProfileThreadInfo public: Array mProfileAddrEntries; int mTotalSamples; + int mTotalIdleSamples; String mName; public: ProfileThreadInfo() { mTotalSamples = 0; + mTotalIdleSamples = 0; } }; @@ -143,6 +146,7 @@ public: Dictionary mProcMap; // Keyed on either DwSubprogram or DwSymbol. Multiple pointers can reference the same ProfileProcId (in the case of inlined functions, for example) HashSet mUniqueProcSet; + HashSet mIdleSymbolNames; public: void ThreadProc(); @@ -171,7 +175,7 @@ public: void HandlePendingEntries(); void Process(); void DoClear(); - ProfileProcId* Get(const StringImpl& str); + ProfileProcId* Get(const StringImpl& str, bool* outIsNew = NULL); public: DbgProfiler(WinDebugger* debugger);