Merge pull request #475 from GameTechDev/feature/virt-pm-sesh

Feature/virt pm sesh

Author: markgalvan-intel

ETLTrimmer/CliOptions.h

@@ -17,6 +17,7 @@ namespace clio
 		Flag provider{ this, "--provider,-p", "Enable pruning by provider (uses same provider set as PresentMon)" };
 		Flag event{ this, "--event,-e", "Enable pruning by event (uses same event set as PresentMon)" };
 		Flag trimState{ this, "--trim-state,-s", "Override default behavior that avoids discarding stateful events like process and DC start/stop when trimming by timestamp range" };
+		Flag listProcesses{ this, "--list-processes", "Generate a report of all processes ranked by event count" };
 		Option<std::pair<uint64_t, uint64_t>> trimRangeQpc{ this, "--trim-range-qpc", {}, "Range of QPC timestamps outside of which to trim", RemoveCommas };
 		Option<std::pair<uint64_t, uint64_t>> trimRangeNs{ this, "--trim-range-ns", {}, "Range of nanosecond times outside of which to trim", RemoveCommas };
 		Option<std::pair<double, double>> trimRangeMs{ this, "--trim-range-ms", {}, "Range of millisecond times outside of which to trim" };

ETLTrimmer/ETLTrimmer.args.json

@@ -6,6 +6,10 @@
       "Id": "0f02ddbd-6110-43dd-982a-900bffd8549c",
       "Command": "--input-file original.etl"
     },
+    {
+      "Id": "f3106862-df2c-4138-802c-c0fd1bed132d",
+      "Command": "--input-file hea-win.etl"
+    },
     {
       "Id": "ca527fdf-cf0c-4bc6-a5e5-362394a8487d",
       "Command": "--output-file output-trim-start.etl"
@@ -30,6 +34,10 @@
       "Id": "72aa3f3a-db72-48e5-93ec-11ef00ccf00e",
       "Command": "--trim-state"
     },
+    {
+      "Id": "57780d91-1c4e-41e3-be08-af75d87aa4f5",
+      "Command": "--list-processes"
+    },
     {
       "Id": "ee3aa6c6-1568-4347-8847-ad556ceedbdd",
       "Command": "--help"

ETLTrimmer/main.cpp

@@ -14,6 +14,7 @@
 #include <memory>
 #include <unordered_map>
 #include <unordered_set>
+#include <ranges>
 #include "CliOptions.h"
 #include "../PresentData/PresentMonTraceSession.hpp"
 #include "../PresentData/PresentMonTraceConsumer.hpp"
@@ -22,6 +23,9 @@
 #include "../PresentData/ETW/Microsoft_Windows_Kernel_Process.h"
 #include "../PresentData/ETW/Microsoft_Windows_DxgKrnl.h"
 
+namespace rn = std::ranges;
+namespace vi = rn::views;
+
 DEFINE_GUID(IID_ITraceRelogger, 0xF754AD43, 0x3BCC, 0x4286, 0x80, 0x09, 0x9C, 0x5D, 0xA2, 0x14, 0xE8, 0x4E); // {F754AD43-3BCC-4286-8009-9C5DA214E84E}
 DEFINE_GUID(IID_ITraceEventCallback, 0x3ED25501, 0x593F, 0x43E9, 0x8F, 0x38, 0x3A, 0xB4, 0x6F, 0x5A, 0x4A, 0x52); // {3ED25501-593F-43E9-8F38-3AB46F5A4A52}
 
@@ -116,6 +120,7 @@ class EventCallback : public ITraceEventCallback
     DWORD ref_count_ = 0;
     // operation mode
     Mode mode_;
+    bool listProcesses_ = false;
     // trim region
     std::optional<std::pair<uint64_t, uint64_t>> trimRangeQpc_;
     std::optional<std::pair<double, double>> trimRangeMs_;
@@ -129,14 +134,16 @@ class EventCallback : public ITraceEventCallback
     int keepCount_ = 0;
     std::optional<uint64_t> firstTimestamp_;
     uint64_t lastTimestamp_ = 0;
+    std::unordered_map<uint32_t, uint64_t> eventCountByProcess_;
 
 public:
-    EventCallback(bool infoOnly, std::shared_ptr<Filter> pFilter, bool trimState, bool byId)
+    EventCallback(bool infoOnly, std::shared_ptr<Filter> pFilter, bool trimState, bool byId, bool listProcesses)
         :
         mode_{ infoOnly ? Mode::Analysis : Mode::Trim },
         pFilter_{ std::move(pFilter) },
         trimState_{ trimState },
-        byId_{ byId }
+        byId_{ byId },
+        listProcesses_{ listProcesses }
     {
         // when trimming by timestamp, we must take care not to remove the state data psuedo-events generated
         // at the beginning of the trace (also true state events coming before the trim region)
@@ -244,6 +251,9 @@ class EventCallback : public ITraceEventCallback
         if (mode_ == Mode::Trim) {
             pRelogger->Inject(pEvent);
         }
+        if (listProcesses_) {
+            eventCountByProcess_[hdr.ProcessId]++;
+        }
         return S_OK;
     }
     HRESULT STDMETHODCALLTYPE OnFinalizeProcessTrace(ITraceRelogger* pRelogger)
@@ -270,6 +280,12 @@ class EventCallback : public ITraceEventCallback
     {
         return keepCount_;
     }
+    auto GetProcessList() const
+    {
+        return eventCountByProcess_
+            | vi::transform([](auto const& kv) {return std::pair{ kv.first, kv.second };})
+            | rn::to<std::vector>();
+    }
 };
 
 class TempFile
@@ -362,7 +378,7 @@ int main(int argc, const char** argv)
     }
 
     auto pCallbackProcessor = std::make_unique<EventCallback>(!opt.outputFile,
-        pFilter, (bool)opt.trimState, (bool)opt.event);
+        pFilter, (bool)opt.trimState, (bool)opt.event, (bool)opt.listProcesses);
     if (auto hr = pRelogger->RegisterCallback(pCallbackProcessor.get()); FAILED(hr)) {
         std::cout << "Failed to register callback" << std::endl;
     }
@@ -396,8 +412,37 @@ int main(int argc, const char** argv)
         pCallbackProcessor->GetEventCount() - pCallbackProcessor->GetKeepCount());
     std::cout << std::format("Count of persisted events: {:L}\n", pCallbackProcessor->GetKeepCount());
 
+    if (opt.listProcesses) {
+        std::cout << "\n ======== Processes ========\n\n";
+        auto procs = pCallbackProcessor->GetProcessList();
+        std::erase_if(procs, [](auto& p) { return p.first == 0xFFFF'FFFF; });
+        rn::sort(procs, std::greater{}, &decltype(procs)::value_type::second);
+
+        // figure out how wide each column must be (based on the values)
+        size_t pidW = 0, cntW = 0;
+        for (auto& [pid, cnt] : procs) {
+            pidW = std::max(pidW, std::to_string(pid).size());
+            cntW = std::max(cntW, std::to_string(cnt).size());
+        }
+
+        // print header
+        std::cout
+            << std::format("{:>{}}  {:>{}}\n", "PID", pidW, "EVTs", cntW)
+            << std::string(pidW + 2 + cntW, '-') << "\n";
+
+        // print each row, right-aligned into those widths
+        for (auto& [pid, cnt] : procs) {
+            std::cout << std::format("{:>{}}  {:>{}}\n",
+                pid, pidW,
+                cnt, cntW);
+        }
+
+        std::cout << std::endl;
+    }
+
+
     if (!opt.outputFile) {
-        std::cout << "No output specified; running in analysis mode\n";
+        std::cout << "No output specified; ran in analysis mode\n";
     }
     else {
         std::cout << "Output written to: " << *opt.outputFile << std::endl;

IntelPresentMon/AppCef/CefNano.vcxproj

@@ -48,6 +48,7 @@
     <ClInclude Include="source\util\cact\PresentmonInitFailedAction.h" />
     <ClInclude Include="source\util\cact\StalePidAction.h" />
     <ClInclude Include="source\util\cact\TargetLostAction.h" />
+    <ClInclude Include="source\util\CefLog.h" />
     <ClInclude Include="source\util\CliOptions.h" />
     <ClInclude Include="source\util\IpcInvocationManager.h" />
     <ClInclude Include="source\util\AsyncEndpoint.h" />

IntelPresentMon/AppCef/source/NanoCefBrowserClient.h

@@ -37,12 +37,6 @@ namespace p2c::client::cef
             int line) override;
 
     protected:
-        // this semaphore protects from race condition between normal shutdown ack sequence and timeout fallback sequence
-        std::binary_semaphore shutdownSemaphore{ 1 };
-        // indicates whether ack was received from render process (or timeout fired)
-        std::atomic<bool> shutdownAcknowledgementFlag = false;
-        bool shutdownRequestFlag = false;
-
         CefRefPtr<CefContextMenuHandler> pContextMenuHandler;
         CefRefPtr<CefBrowser> pBrowser;
         util::AsyncEndpointCollection endpoints;

IntelPresentMon/AppCef/source/util/CefLog.h

@@ -0,0 +1,18 @@
+#pragma once
+#include <include/internal/cef_types.h>
+#include "Logging.h"
+
+constexpr cef_log_severity_t ToCefLogLevel(::pmon::util::log::Level level)
+{
+	using ::pmon::util::log::Level;
+	switch (level) {
+	case Level::Verbose: return cef_log_severity_t::LOGSEVERITY_VERBOSE;
+	case Level::Debug: // in CEF, debug and verbose are the same, so we use cef.info for debug
+	case Level::Performance:
+	case Level::Info: return cef_log_severity_t::LOGSEVERITY_INFO;
+	case Level::Warning: return cef_log_severity_t::LOGSEVERITY_WARNING;
+	case Level::Error: return cef_log_severity_t::LOGSEVERITY_ERROR;
+	case Level::Fatal: return cef_log_severity_t::LOGSEVERITY_FATAL;
+	default: return cef_log_severity_t::LOGSEVERITY_DEFAULT;
+	}
+}

IntelPresentMon/AppCef/source/winmain.cpp

@@ -15,6 +15,7 @@
 #include <Shobjidl.h>
 #include <ShellScalingApi.h>
 #include <include/cef_version.h>
+#include "util/CefLog.h"
 
 
 #pragma comment(lib, "Dwmapi.lib")
@@ -72,14 +73,10 @@ LRESULT CALLBACK BrowserWindowWndProc(HWND window_handle, UINT message, WPARAM w
             && (pBrowserClient->GetBrowser()))
         {
             CefWindowHandle hwnd(pBrowserClient->GetBrowser()->GetHost()->GetWindowHandle());
-            if (hwnd)
-            {
-                RECT rect = { 0 };
+            if (hwnd) {
+                RECT rect{};
                 GetClientRect(window_handle, &rect);
-                HDWP hdwp = BeginDeferWindowPos(1);
-                hdwp = DeferWindowPos(hdwp, hwnd, NULL, rect.left,
-                    rect.top, rect.right - rect.left, rect.bottom - rect.top, SWP_NOZORDER);
-                EndDeferWindowPos(hdwp);
+                SetWindowPos(hwnd, NULL, rect.left, rect.top, rect.right - rect.left, rect.bottom - rect.top, SWP_NOZORDER);
             }
         }
         break;
@@ -92,14 +89,12 @@ LRESULT CALLBACK BrowserWindowWndProc(HWND window_handle, UINT message, WPARAM w
         }
         break;
     case WM_ENTERMENULOOP:
-        if (!w_param)
-        {
+        if (!w_param) {
             CefSetOSModalLoop(true);
         }
         break;
     case WM_EXITMENULOOP:
-        if (!w_param)
-        {
+        if (!w_param) {
             CefSetOSModalLoop(false);
         }
         break;
@@ -112,8 +107,7 @@ LRESULT CALLBACK MessageWindowWndProc(HWND window_handle, UINT message, WPARAM w
     switch (message)
     {
     case WM_COMMAND:
-        if (w_param == quitCefCode)
-        {
+        if (w_param == quitCefCode) {
             PostQuitMessage(0);
         }
         break;
@@ -129,7 +123,7 @@ HWND CreateBrowserWindow(HINSTANCE instance_handle, int show_minimize_or_maximiz
     wcex.lpfnWndProc = BrowserWindowWndProc;
     wcex.hInstance = instance_handle;
     wcex.hCursor = LoadCursor(nullptr, IDC_ARROW);
-    wcex.hbrBackground = (HBRUSH)GetStockObject(WHITE_BRUSH);
+    wcex.hbrBackground = (HBRUSH)GetStockObject(BLACK_BRUSH);
     wcex.lpszClassName = BrowserWindowClassName;
     wcex.hIcon = static_cast<HICON>(LoadImage(
         instance_handle, MAKEINTRESOURCE(IDI_ICON1),
@@ -233,15 +227,15 @@ int APIENTRY WinMain(HINSTANCE hInstance, HINSTANCE hPrevInstance, LPSTR lpCmdLi
             settings.multi_threaded_message_loop = true;
             settings.no_sandbox = true;
             settings.remote_debugging_port = is_debug || opt.enableChromiumDebug ? 9009 : 0;
-            settings.background_color = { 0x000000 };
+            settings.background_color = CefColorSetARGB(255, 0, 0, 0);
             CefString(&settings.cache_path).FromWString(folderResolver.Resolve(infra::util::FolderResolver::Folder::App, L"cef-cache"));
             if (opt.logFolder) {
                 CefString(&settings.log_file).FromString(*opt.logFolder + "\\cef-debug.log");
             }
             else {
                 CefString(&settings.log_file).FromWString(folderResolver.Resolve(infra::util::FolderResolver::Folder::App, L"logs\\cef-debug.log"));
             }
-            settings.log_severity = is_debug ? cef_log_severity_t::LOGSEVERITY_DEFAULT : cef_log_severity_t::LOGSEVERITY_ERROR;
+            settings.log_severity = ToCefLogLevel(util::log::GlobalPolicy::Get().GetLogLevel());
             CefInitialize(main_args, settings, app.get(), nullptr);
         }
         auto hwndBrowser = CreateBrowserWindow(hInstance, nCmdShow);

IntelPresentMon/CommonUtilities/CommonUtilities.vcxproj

@@ -94,6 +94,8 @@
     <ClInclude Include="win\MessageBox.h" />
     <ClInclude Include="win\Overlapped.h" />
     <ClInclude Include="win\Privileges.h" />
+    <ClInclude Include="win\Process.h" />
+    <ClInclude Include="win\ProcessMapBuilder.h" />
     <ClInclude Include="win\Utilities.h" />
     <ClInclude Include="win\WinAPI.h" />
   </ItemGroup>
@@ -143,6 +145,7 @@
     <ClCompile Include="win\HrError.cpp" />
     <ClCompile Include="win\MessageBox.cpp" />
     <ClCompile Include="win\Privileges.cpp" />
+    <ClCompile Include="win\ProcessMapBuilder.cpp" />
     <ClCompile Include="win\Utilities.cpp" />
   </ItemGroup>
   <ItemGroup>

IntelPresentMon/CommonUtilities/CommonUtilities.vcxproj.filters

@@ -246,6 +246,12 @@
     <ClInclude Include="win\Privileges.h">
       <Filter>Header Files</Filter>
     </ClInclude>
+    <ClInclude Include="win\ProcessMapBuilder.h">
+      <Filter>Header Files</Filter>
+    </ClInclude>
+    <ClInclude Include="win\Process.h">
+      <Filter>Header Files</Filter>
+    </ClInclude>
   </ItemGroup>
   <ItemGroup>
     <ClCompile Include="cli\CliFramework.cpp">
@@ -386,6 +392,9 @@
     <ClCompile Include="win\Privileges.cpp">
       <Filter>Source Files</Filter>
     </ClCompile>
+    <ClCompile Include="win\ProcessMapBuilder.cpp">
+      <Filter>Source Files</Filter>
+    </ClCompile>
   </ItemGroup>
   <ItemGroup>
     <None Include="vcpkg.json" />

IntelPresentMon/CommonUtilities/Qpc.cpp

@@ -6,13 +6,13 @@
 
 namespace pmon::util
 {
-	uint64_t GetCurrentTimestamp() noexcept
+	int64_t GetCurrentTimestamp() noexcept
 	{
 		LARGE_INTEGER timestamp;
 		if (!QueryPerformanceCounter(&timestamp)) {
 			pmlog_error("qpc failed").hr().every(50);
 		}
-		return (uint64_t)timestamp.QuadPart;
+		return (int64_t)timestamp.QuadPart;
 	}
 	double GetTimestampPeriodSeconds() noexcept
 	{
@@ -22,13 +22,13 @@ namespace pmon::util
 		}
 		return 1.0 / double(freq.QuadPart);
 	}
-	void SpinWaitUntilTimestamp(uint64_t timestamp) noexcept
+	void SpinWaitUntilTimestamp(int64_t timestamp) noexcept
 	{
 		while (GetCurrentTimestamp() < timestamp) {
 			std::this_thread::yield();
 		}
 	}
-	double TimestampDeltaToSeconds(uint64_t start, uint64_t end, double period) noexcept
+	double TimestampDeltaToSeconds(int64_t start, int64_t end, double period) noexcept
 	{
 		return double(end - start) * period;
 	}
@@ -52,7 +52,7 @@ namespace pmon::util
 		const auto delta = TimestampDeltaToSeconds(startTimestamp_, newTimestamp, performanceCounterPeriod_);
 		return delta;
 	}
-	uint64_t QpcTimer::GetStartTimestamp() const noexcept
+	int64_t QpcTimer::GetStartTimestamp() const noexcept
 	{
 		return startTimestamp_;
 	}