diff --git a/IntelPresentMon/PresentMonService/RealtimePresentMonSession.cpp b/IntelPresentMon/PresentMonService/RealtimePresentMonSession.cpp index 7a3d56e1..f94f4c71 100644 --- a/IntelPresentMon/PresentMonService/RealtimePresentMonSession.cpp +++ b/IntelPresentMon/PresentMonService/RealtimePresentMonSession.cpp @@ -1,4 +1,4 @@ -// Copyright (C) 2022-2023 Intel Corporation +// Copyright (C) 2022-2023 Intel Corporation // SPDX-License-Identifier: MIT #include "Logging.h" #include "RealtimePresentMonSession.h" @@ -17,53 +17,97 @@ RealtimePresentMonSession::RealtimePresentMonSession(svc::FrameBroadcaster& broa { pBroadcaster = &broadcaster; ResetEtwFlushPeriod(); + StartEtwSession(); } bool RealtimePresentMonSession::IsTraceSessionActive() { return session_active_.load(std::memory_order_acquire); } +// Transitions the session to an inactive state without tearing down the ETW session. +// Safe to call multiple times. +void RealtimePresentMonSession::StopProvidersAndResetConsumer(bool shrink) +{ + if (pm_consumer_) { + pm_consumer_->SetEventProcessingEnabled(false); + } + + trace_session_.StopProviders(); + + if (pm_consumer_) { + pm_consumer_->ResetPresentTrackingData(shrink); + } + + evtStreamingStarted_.Reset(); +} + PM_STATUS RealtimePresentMonSession::UpdateTracking(const std::unordered_set& trackedPids) { - const bool wasActive = HasLiveTargets(); + // Ensure ETW session exists (StartTraceW done once; providers may be off). + if (!IsTraceSessionActive()) { + // If the session isn't active, then we need to start it before we can update tracking. + auto const status = StartEtwSession(); + if (status != PM_STATUS_SUCCESS) { + return status; + } + } + + // Snapshot state so we can rollback tracking on failure. std::unordered_map previousState; { std::lock_guard lock(tracked_processes_mutex_); previousState = tracked_pid_live_; } + SyncTrackedPidState(trackedPids); const bool isActive = HasLiveTargets(); - if (isActive && (!wasActive || !IsTraceSessionActive())) { - auto status = StartTraceSession(); - if (status != PM_STATUS_SUCCESS) { + bool const providersEnabled = (bool)util::win::WaitAnyEventFor(0ms, evtStreamingStarted_); + + // Stop transition: targets went from some->none; providers currently enabled + if(!isActive && providersEnabled) { + pmlog_info("All targets inactive: Disabling ETW Providers"); + StopProvidersAndResetConsumer(true); + evtStreamingStarted_.Reset(); + return PM_STATUS::PM_STATUS_SUCCESS; + } + + // Start transition: targets went from none->some; providers currently disabled + // This also handles the case where there was a StartProviders failure for some + // reason. + if (isActive && !providersEnabled) { + // Enable present tracking before enabling providers so any immediately-arriving + // events are accounted for by the quiesce logic on StopStreaming. + if (pm_consumer_) { + // Drop any lingering present tracking state from previous streams + pm_consumer_->ResetPresentTrackingData(false); + // Allow event processing before enabling providers + pm_consumer_->SetEventProcessingEnabled(true); + } + pmlog_info("Active targets detected: Enabling ETW Providers"); + auto const providerStatus = trace_session_.StartProviders(); + if (providerStatus != ERROR_SUCCESS) { + pmlog_info("Enabling of ETW Providers failed"); + StopProvidersAndResetConsumer(true); + evtStreamingStarted_.Reset(); { std::lock_guard lock(tracked_processes_mutex_); tracked_pid_live_ = std::move(previousState); } - return status; + return PM_STATUS::PM_STATUS_FAILURE; } - } - if (isActive && evtStreamingStarted_) { evtStreamingStarted_.Set(); + return PM_STATUS::PM_STATUS_SUCCESS; } - if (!isActive) { - if (evtStreamingStarted_) { - evtStreamingStarted_.Reset(); - } - StopTraceSession(); - } + + // No transition: either active with providers enabled, or inactive with providers disabled return PM_STATUS::PM_STATUS_SUCCESS; } bool RealtimePresentMonSession::CheckTraceSessions(bool forceTerminate) { if (forceTerminate) { - StopTraceSession(); + StopEtwSession(); ClearTrackedProcesses(); return true; } - if (!HasLiveTargets() && (IsTraceSessionActive() == true)) { - StopTraceSession(); - return true; - } return false; } @@ -83,7 +127,6 @@ void RealtimePresentMonSession::FlushEvents() pmlog_warn("Failed manual flush of ETW event buffer").hr(); } } - } void RealtimePresentMonSession::ResetEtwFlushPeriod() @@ -91,8 +134,8 @@ void RealtimePresentMonSession::ResetEtwFlushPeriod() etw_flush_period_ms_ = default_realtime_etw_flush_period_ms_; } -PM_STATUS RealtimePresentMonSession::StartTraceSession() { - std::lock_guard lock(session_mutex_); +PM_STATUS RealtimePresentMonSession::StartEtwSession() { + std::lock_guard lock(session_mutex_); if (pm_consumer_) { return PM_STATUS::PM_STATUS_SERVICE_ERROR; @@ -120,6 +163,9 @@ PM_STATUS RealtimePresentMonSession::StartTraceSession() { pm_consumer_->mTrackAppTiming = true; pm_consumer_->mTrackPcLatency = true; + // Service uses provider toggling; enable quiesce gate for safe state reset on start/stop + pm_consumer_->SetProviderToggleMode(true); + auto& opt = clio::Options::Get(); pm_session_name_ = util::str::ToWide(*opt.etwSessionName); @@ -128,12 +174,12 @@ PM_STATUS RealtimePresentMonSession::StartTraceSession() { // it and start a new session. This is useful if a previous process failed to // properly shut down the session for some reason. trace_session_.mPMConsumer = pm_consumer_.get(); - auto status = trace_session_.Start(etl_file_name, pm_session_name_.c_str()); + auto status = trace_session_.Start(etl_file_name, pm_session_name_.c_str(), false); if (status == ERROR_ALREADY_EXISTS) { status = StopNamedTraceSession(pm_session_name_.c_str()); if (status == ERROR_SUCCESS) { - status = trace_session_.Start(etl_file_name, pm_session_name_.c_str()); + status = trace_session_.Start(etl_file_name, pm_session_name_.c_str(), false); } } @@ -167,7 +213,7 @@ PM_STATUS RealtimePresentMonSession::StartTraceSession() { return PM_STATUS::PM_STATUS_SUCCESS; } -void RealtimePresentMonSession::StopTraceSession() { +void RealtimePresentMonSession::StopEtwSession() { // PHASE 1: Signal shutdown and wait for threads to observe it // this also enforces "only_once" semantics for multiple stop callers if (session_active_.exchange(false, std::memory_order_acq_rel)) { @@ -182,9 +228,7 @@ void RealtimePresentMonSession::StopTraceSession() { // PHASE 2: Safe cleanup after threads have finished std::lock_guard lock(session_mutex_); - if (evtStreamingStarted_) { - evtStreamingStarted_.Reset(); - } + evtStreamingStarted_.Reset(); if (pm_consumer_) { pm_consumer_.reset(); @@ -479,11 +523,8 @@ void RealtimePresentMonSession::UpdateProcesses( } void RealtimePresentMonSession::HandleTerminatedProcess(uint32_t processId) { - // TODO(megalvan): Need to figure this out - // Close this process' CSV. - // CloseOutputCsv(processInfo); MarkProcessExited(processId); - if (!HasLiveTrackedProcesses() && evtStreamingStarted_) { + if (!HasLiveTrackedProcesses()) { evtStreamingStarted_.Reset(); } } @@ -496,4 +537,4 @@ void RealtimePresentMonSession::HandleTerminatedProcess(uint32_t processId) { void RealtimePresentMonSession::CheckForTerminatedRealtimeProcesses( std::vector>* terminatedProcesses) { (void)terminatedProcesses; -} +} \ No newline at end of file diff --git a/IntelPresentMon/PresentMonService/RealtimePresentMonSession.h b/IntelPresentMon/PresentMonService/RealtimePresentMonSession.h index 54be3135..32e8c7e1 100644 --- a/IntelPresentMon/PresentMonService/RealtimePresentMonSession.h +++ b/IntelPresentMon/PresentMonService/RealtimePresentMonSession.h @@ -22,8 +22,8 @@ class RealtimePresentMonSession : public PresentMonSession private: // functions - PM_STATUS StartTraceSession(); - void StopTraceSession(); + PM_STATUS StartEtwSession(); + void StopEtwSession(); void DequeueAnalyzedInfo( std::vector* processEvents, @@ -51,6 +51,7 @@ class RealtimePresentMonSession : public PresentMonSession void CheckForTerminatedRealtimeProcesses( std::vector>* terminatedProcesses); + void StopProvidersAndResetConsumer(bool shrink); // data std::wstring pm_session_name_; diff --git a/PresentData/PresentMonTraceConsumer.cpp b/PresentData/PresentMonTraceConsumer.cpp index e75f4718..a48db047 100644 --- a/PresentData/PresentMonTraceConsumer.cpp +++ b/PresentData/PresentMonTraceConsumer.cpp @@ -89,6 +89,31 @@ static inline void SetScreenTime(std::shared_ptr const& p, uint64_ } } +namespace { + struct WaitOnAddressShim { + using WaitOnAddressFn = BOOL(WINAPI*)(volatile VOID* Address, PVOID CompareAddress, SIZE_T AddressSize, DWORD dwMilliseconds); + using WakeByAddressAllFn = VOID(WINAPI*)(PVOID Address); + + WaitOnAddressFn Wait = nullptr; + WakeByAddressAllFn WakeAll = nullptr; + + bool Available() const noexcept { return Wait && WakeAll; } + }; + + static const WaitOnAddressShim& GetWaitOnAddressShim() + { + static WaitOnAddressShim shim = [] { + WaitOnAddressShim s{}; + HMODULE k32 = ::GetModuleHandleW(L"kernel32.dll"); + if (!k32) return s; + s.Wait = reinterpret_cast(::GetProcAddress(k32, "WaitOnAddress")); + s.WakeAll = reinterpret_cast(::GetProcAddress(k32, "WakeByAddressAll")); + return s; + }(); + return shim; + } +} // namespace + PresentEvent::PresentEvent() : PresentStartTime(0) , ProcessId(0) @@ -3466,6 +3491,182 @@ void PMTraceConsumer::DequeuePresentEvents(std::vector= timeoutMs) { + pmlog_warn("Timed out waiting for event processing to quiesce; skipping present tracking reset"); + return; + } + DWORD remaining = timeoutMs - (DWORD)elapsed; + if (shim.Available()) { + LONG expected = ::InterlockedCompareExchange(&mEventProcessingInFlight, 0, 0); + if (expected != 0) { + // Wait until the value at the address changes from 'expected'. + // Spurious wakeups are possible; loop re-check handles it. + shim.Wait(&mEventProcessingInFlight, &expected, sizeof(expected), remaining); + } + } + else { + // Win7 fallback + ::Sleep(1); + } + } + + pmlog_info("Present tracking reset: Event processing quiesced; proceeding with present tracking reset shrink =" + + std::to_string(shrink)); + // Now it is safe to clear the state + { + std::lock_guard lock(mPresentEventMutex); + // Clear rings and counters + for(auto& p : mTrackedPresents) { + p.reset(); + } + for(auto& p : mCompletedPresents) { + p.reset(); + } + mNextFreeRingIndex = 0; + mCompletedIndex = 0; + mCompletedCount = 0; + mReadyCount = 0; + mNumOverflowedPresents = 0; + + // We need to see a completed present again after the providers restart + mHasCompletedAPresent = false; + + // DWM tracking + mPresentsWaitingForDWM.clear(); + DwmProcessId = 0; + DwmPresentThreadId = 0; + + // Deferred frame-type association state + mPendingPresentFrameTypeEvents.clear(); + mPendingFlipFrameTypeEvents.clear(); + mEnableFlipFrameTypeEvents = false; + } + + // Clear process events + { + std::lock_guard lock(mProcessEventMutex); + mProcessEvents.clear(); + } + + // Clear and potentially shrink present tracking maps + if (shrink) { + decltype(mPresentByThreadId){}.swap(mPresentByThreadId); + decltype(mOrderedPresentsByProcessId){}.swap(mOrderedPresentsByProcessId); + decltype(mPresentBySubmitSequence){}.swap(mPresentBySubmitSequence); + decltype(mPresentByWin32KPresentHistoryToken){}.swap(mPresentByWin32KPresentHistoryToken); + decltype(mPresentByDxgkPresentHistoryToken){}.swap(mPresentByDxgkPresentHistoryToken); + decltype(mPresentByDxgkPresentHistoryTokenData){}.swap(mPresentByDxgkPresentHistoryTokenData); + decltype(mPresentByDxgkContext){}.swap(mPresentByDxgkContext); + decltype(mPresentByVidPnLayerId){}.swap(mPresentByVidPnLayerId); + decltype(mLastPresentByWindow){}.swap(mLastPresentByWindow); + decltype(mPresentByAppFrameId){}.swap(mPresentByAppFrameId); + decltype(mAppTimingDataByAppFrameId){}.swap(mAppTimingDataByAppFrameId); + decltype(mPclTimingDataByPclFrameId){}.swap(mPclTimingDataByPclFrameId); + decltype(mHybridPresentModeBySwapChainPid){}.swap(mHybridPresentModeBySwapChainPid); + decltype(mLatestPingTimestampByProcessId){}.swap(mLatestPingTimestampByProcessId); + } else { + mPresentByThreadId.clear(); + mOrderedPresentsByProcessId.clear(); + mPresentBySubmitSequence.clear(); + mPresentByWin32KPresentHistoryToken.clear(); + mPresentByDxgkPresentHistoryToken.clear(); + mPresentByDxgkPresentHistoryTokenData.clear(); + mPresentByDxgkContext.clear(); + mPresentByVidPnLayerId.clear(); + mLastPresentByWindow.clear(); + mPresentByAppFrameId.clear(); + mAppTimingDataByAppFrameId.clear(); + mPclTimingDataByPclFrameId.clear(); + mHybridPresentModeBySwapChainPid.clear(); + mLatestPingTimestampByProcessId.clear(); + } + + // Input association state + mReceivedMouseClickByHwnd.clear(); + mRetrievedInput.clear(); + mLastInputDeviceReadTime = 0; + mLastInputDeviceType = InputDeviceType::None; + + // Reset PCL State + mUsingOutOfBoundPresentStart = false; + + // Reset GPU/NV tracking helpers + mGpuTrace.~GpuTrace(); + new (&mGpuTrace) GpuTrace(this); + mNvTraceConsumer.~NVTraceConsumer(); + new (&mNvTraceConsumer) NVTraceConsumer(); +} + +PMTraceConsumer::EventProcessingScope::EventProcessingScope(PMTraceConsumer& consumer) + : Consumer(consumer) +{ + // If provider-toggle mode is not enabled, do nothing. + if (!Consumer.mProviderToggleMode.load(std::memory_order_acquire)) { + active = true; + counted = false; + return; + } + + counted = true; + ::InterlockedIncrement(&Consumer.mEventProcessingInFlight); + + if (!Consumer.mEventProcessingEnabled.load(std::memory_order_acquire)) { + LONG v = ::InterlockedDecrement(&Consumer.mEventProcessingInFlight); + if (v == 0) { + auto const& shim = GetWaitOnAddressShim(); + if (shim.Available()) { + shim.WakeAll((PVOID)&Consumer.mEventProcessingInFlight); + } + } + + active = false; + counted = false; + return; + } + + active = true; +} + +PMTraceConsumer::EventProcessingScope::~EventProcessingScope() +{ + if (!counted) { + return; + } + + LONG v = ::InterlockedDecrement(&Consumer.mEventProcessingInFlight); + if (v == 0) { + auto const& shim = GetWaitOnAddressShim(); + if (shim.Available()) { + shim.WakeAll((PVOID)&Consumer.mEventProcessingInFlight); + } + } +} + AppTimingData* PMTraceConsumer::ExtractAppTimingData( std::unordered_map, AppTimingData, PairHash>& timingDataByFrameId, uint32_t processId, uint32_t appFrameId, uint64_t presentStartTime, std::function timingSelector) { diff --git a/PresentData/PresentMonTraceConsumer.hpp b/PresentData/PresentMonTraceConsumer.hpp index 6d8aec97..cf547613 100644 --- a/PresentData/PresentMonTraceConsumer.hpp +++ b/PresentData/PresentMonTraceConsumer.hpp @@ -8,6 +8,7 @@ #endif #include +#include #include #include #include @@ -335,6 +336,14 @@ struct PMTraceConsumer void DequeueProcessEvents(std::vector& outProcessEvents); void DequeuePresentEvents(std::vector>& outPresentEvents); + // Control of general event processing state for service capture start/stop without + // tearing down the underlying ETW session + // + // Provider-toggle mode enables a quiesce gate in the session callback so we can safely + // clear internal present tracking state from a controller thread. + void SetProviderToggleMode(bool enabled); + void SetEventProcessingEnabled(bool enabled); + void ResetPresentTrackingData(bool shrink = false); // ------------------------------------------------------------------------------------------- // The rest of this structure are internal data and functions for analysing the collected ETW @@ -449,6 +458,28 @@ struct PMTraceConsumer } }; + // Guard used to safely mutate/clear all Present tracking structures + // without taking a mutex on every ETW event. ResetPresentTrackingData() disables + // tracking and then waits for in-flight scopes to drain before clearing the maps. + struct EventProcessingScope { + PMTraceConsumer& Consumer; + // Whether event processing is active for the scope duration + bool active = false; + // Whether we incremented the in-flight counter + bool counted = false; + explicit EventProcessingScope(PMTraceConsumer& consumer); + ~EventProcessingScope(); + EventProcessingScope(const EventProcessingScope&) = delete; + EventProcessingScope& operator=(const EventProcessingScope&) = delete; + explicit operator bool() const noexcept { return active; } + }; + + std::atomic mProviderToggleMode{ false }; + std::atomic mEventProcessingEnabled{ true }; + // WaitOnAddress needs a 1/2/4/8-byte memory location. Using LONG makes it + // Win7-compatible (via Interlocked ops) and Win8+ compatible (via WaitOnAddress shim). + volatile LONG mEventProcessingInFlight = 0; + std::unordered_map> mPresentByThreadId; // ThreadId -> PresentEvent std::unordered_map mOrderedPresentsByProcessId; // ProcessId -> ordered PresentStartTime -> PresentEvent std::unordered_map>> diff --git a/PresentData/PresentMonTraceSession.cpp b/PresentData/PresentMonTraceSession.cpp index d9caadbf..3eefb3da 100644 --- a/PresentData/PresentMonTraceSession.cpp +++ b/PresentData/PresentMonTraceSession.cpp @@ -284,6 +284,7 @@ void DisableProviders(TRACEHANDLE sessionHandle) status = EnableTraceEx2(sessionHandle, &Microsoft_Windows_Kernel_Process::GUID, EVENT_CONTROL_CODE_DISABLE_PROVIDER, 0, 0, 0, 0, nullptr); status = EnableTraceEx2(sessionHandle, &Microsoft_Windows_Win32k::GUID, EVENT_CONTROL_CODE_DISABLE_PROVIDER, 0, 0, 0, 0, nullptr); status = EnableTraceEx2(sessionHandle, &NvidiaDisplayDriver_Events::GUID, EVENT_CONTROL_CODE_DISABLE_PROVIDER, 0, 0, 0, 0, nullptr); + status = EnableTraceEx2(sessionHandle, &Nvidia_PCL::GUID, EVENT_CONTROL_CODE_DISABLE_PROVIDER, 0, 0, 0, 0, nullptr); } template< @@ -297,6 +298,11 @@ void CALLBACK EventRecordCallback(EVENT_RECORD* pEventRecord) auto session = (PMTraceSession*) pEventRecord->UserContext; const auto& hdr = pEventRecord->EventHeader; + PMTraceConsumer::EventProcessingScope processingScope(*session->mPMConsumer); + if (!processingScope) { + return; + } + if constexpr (!IS_REALTIME_SESSION) { if (session->mStartTimestamp.QuadPart == 0) { session->mStartTimestamp = hdr.TimeStamp; @@ -458,7 +464,8 @@ ULONG CALLBACK BufferCallback(EVENT_TRACE_LOGFILE* pLogFile) ULONG PMTraceSession::Start( wchar_t const* etlPath, - wchar_t const* sessionName) + wchar_t const* sessionName, + bool enableProviders) { assert(mPMConsumer != nullptr); assert(mSessionHandle == 0); @@ -487,10 +494,15 @@ ULONG PMTraceSession::Start( return status; } - status = EnableProviders(mSessionHandle, sessionProps.Wnode.Guid, mPMConsumer); - if (status != ERROR_SUCCESS) { - Stop(); - return status; + // Set the session GUID + mSessionGuid = sessionProps.Wnode.Guid; + + if (enableProviders) { + status = EnableProviders(mSessionHandle, sessionProps.Wnode.Guid, mPMConsumer); + if (status != ERROR_SUCCESS) { + Stop(); + return status; + } } } @@ -679,6 +691,7 @@ bool PMTraceSession::QueryEtwStatus(EtwStatus* status) const mCachedEtwStatus.mEtwTotalBuffers = sessionProps.NumberOfBuffers; mCachedEtwStatus.mEtwEventsLost = sessionProps.EventsLost; mCachedEtwStatus.mEtwBuffersLost = sessionProps.LogBuffersLost + sessionProps.RealTimeBuffersLost; + mCachedEtwStatus.mNumOverflowedPresents = mPMConsumer->mNumOverflowedPresents; if (sessionProps.NumberOfBuffers > 0) { mCachedEtwStatus.mEtwBufferFillPct = 100.0 * mCachedEtwStatus.mEtwBuffersInUse / sessionProps.NumberOfBuffers; @@ -694,6 +707,16 @@ bool PMTraceSession::QueryEtwStatus(EtwStatus* status) const return true; } +ULONG PMTraceSession::StartProviders() +{ + return EnableProviders(mSessionHandle, mSessionGuid, mPMConsumer); +} + +void PMTraceSession::StopProviders() +{ + DisableProviders(mSessionHandle); +} + ULONG EnableProvidersListing( TRACEHANDLE sessionHandle, const GUID* pSessionGuid, diff --git a/PresentData/PresentMonTraceSession.hpp b/PresentData/PresentMonTraceSession.hpp index 7d170fdf..fb07d1a5 100644 --- a/PresentData/PresentMonTraceSession.hpp +++ b/PresentData/PresentMonTraceSession.hpp @@ -12,6 +12,7 @@ struct EtwStatus { ULONG mEtwTotalBuffers; ULONG mEtwEventsLost; ULONG mEtwBuffersLost; + ULONG mNumOverflowedPresents; }; struct PMTraceSession { @@ -36,6 +37,7 @@ struct PMTraceSession { uint64_t mStartFileTime = 0; TimestampType mTimestampType = TIMESTAMP_TYPE_QPC; + GUID mSessionGuid = {}; TRACEHANDLE mSessionHandle = 0; // invalid session handles are 0 TRACEHANDLE mTraceHandle = INVALID_PROCESSTRACE_HANDLE; // invalid trace handles are INVALID_PROCESSTRACE_HANDLE @@ -49,9 +51,12 @@ struct PMTraceSession { // Cached ETW status for CSV output (updated periodically via QueryEtwStatus) mutable EtwStatus mCachedEtwStatus = {}; - ULONG Start(wchar_t const* etlPath, // If nullptr, start a live/realtime tracing session - wchar_t const* sessionName); // Required session name + ULONG Start(wchar_t const* etlPath, // If nullptr, start a live/realtime tracing session + wchar_t const* sessionName, // Required session name + bool enableProviders = true); // Enable providers on start void Stop(); + ULONG StartProviders(); + void StopProviders(); double TimestampDeltaToMilliSeconds(uint64_t timestampDelta) const; double TimestampDeltaToMilliSeconds(uint64_t timestampFrom, uint64_t timestampTo) const; diff --git a/PresentMon/CsvOutput.cpp b/PresentMon/CsvOutput.cpp index 329898da..ccbbc383 100644 --- a/PresentMon/CsvOutput.cpp +++ b/PresentMon/CsvOutput.cpp @@ -187,7 +187,8 @@ void WriteCsvHeader(FILE* fp) L",EtwBuffersInUse" L",EtwTotalBuffers" L",EtwEventsLost" - L",EtwBuffersLost"); + L",EtwBuffersLost" + L",OverflowedPresents"); } fwprintf(fp, L"\n"); @@ -270,12 +271,13 @@ void WriteCsvRow( fwprintf(fp, L",%u", p.FrameId); } if (args.mTrackEtwStatus) { - fwprintf(fp, L",%.1lf,%lu,%lu,%lu,%lu", + fwprintf(fp, L",%.1lf,%lu,%lu,%lu,%lu,%lu", pmSession.mCachedEtwStatus.mEtwBufferFillPct, pmSession.mCachedEtwStatus.mEtwBuffersInUse, pmSession.mCachedEtwStatus.mEtwTotalBuffers, pmSession.mCachedEtwStatus.mEtwEventsLost, - pmSession.mCachedEtwStatus.mEtwBuffersLost); + pmSession.mCachedEtwStatus.mEtwBuffersLost, + pmSession.mCachedEtwStatus.mNumOverflowedPresents); } fwprintf(fp, L"\n"); @@ -496,7 +498,8 @@ void WriteCsvHeader(FILE* fp) L",EtwBuffersInUse" L",EtwTotalBuffers" L",EtwEventsLost" - L",EtwBuffersLost"); + L",EtwBuffersLost" + L",OverflowedPresents"); } fwprintf(fp, L"\n"); @@ -847,12 +850,13 @@ void WriteCsvRow( } } if (args.mTrackEtwStatus) { - fwprintf(fp, L",%.1lf,%lu,%lu,%lu,%lu", + fwprintf(fp, L",%.1lf,%lu,%lu,%lu,%lu,%lu", pmSession.mCachedEtwStatus.mEtwBufferFillPct, pmSession.mCachedEtwStatus.mEtwBuffersInUse, pmSession.mCachedEtwStatus.mEtwTotalBuffers, pmSession.mCachedEtwStatus.mEtwEventsLost, - pmSession.mCachedEtwStatus.mEtwBuffersLost); + pmSession.mCachedEtwStatus.mEtwBuffersLost, + pmSession.mCachedEtwStatus.mNumOverflowedPresents); } fwprintf(fp, L"\n"); diff --git a/PresentMon/MainThread.cpp b/PresentMon/MainThread.cpp index d2741553..f75c8744 100644 --- a/PresentMon/MainThread.cpp +++ b/PresentMon/MainThread.cpp @@ -89,12 +89,13 @@ static void OutputEtwStatus() EtwStatus status = {}; if (gPMTraceSession->QueryEtwStatus(&status)) { - wprintf(L"[ETW Status] BufferFillPct=%.1f%% BuffersInUse=%lu TotalBuffers=%lu EventsLost=%lu BuffersLost=%lu\n", + wprintf(L"[ETW Status] BufferFillPct=%.1f%% BuffersInUse=%lu TotalBuffers=%lu EventsLost=%lu BuffersLost=%lu, OverflowedPresents=%lu\n", status.mEtwBufferFillPct, status.mEtwBuffersInUse, status.mEtwTotalBuffers, status.mEtwEventsLost, - status.mEtwBuffersLost); + status.mEtwBuffersLost, + status.mNumOverflowedPresents); } } diff --git a/PresentMon/PresentMon.args.json b/PresentMon/PresentMon.args.json index 3b3942b9..4497ccf1 100644 --- a/PresentMon/PresentMon.args.json +++ b/PresentMon/PresentMon.args.json @@ -68,7 +68,7 @@ }, { "Id": "8f014852-6512-466b-99cb-0a8724c36862", - "Command": "--output_file \"E:\\EtlTesting\\ETLDebugging\\test_case_8_unified-fid.csv\"" + "Command": "--output_file \"C:\\DataAnalysis\\BG6-Bug\\out.csv\"" }, { "Id": "1606ee3e-ac1c-4fea-9a87-736864dd1f00",