From 5ee854c4eb4320756da57a1644e49b9e84ff778f Mon Sep 17 00:00:00 2001 From: "Pohsiang (John) Hsu" Date: Thu, 15 May 2025 17:20:13 -0700 Subject: [PATCH] mediafoundation: add ETW event for perf analysis Add perf ETW events using TraceLogging API, the following are adding: - MFT receives fence (FenceCompletion). - MFT has output MFSample (METransformHaveOutput). - MFT calls to pipe end_frame (PipeEndFrame) -- bracketed. - MFT calls to pipe flush (PipeFlush) -- bracketed. - MFT submits a frame to pipe (PipeSubmitFrame) -- bracketed from begine_frame to encode_bitstream/encode_bitstream_sliced - MFT processinput (ProcessInput) -- bracketed - MFT processoutput (ProcessOutput) -- bracketed The ETW provider(s) are: - H264Enc: 0000e264-0dc9-401d-b9b8-05e4eca4977e - H265Enc: 0000e265-0dc9-401d-b9b8-05e4eca4977e - AV1Enc: 0000eaa1-0dc9-401d-b9b8-05e4eca4977e Note that the provider is mostly the same as the WPPTrace provider for each codec, with the additional 'e' (e.g. 0000e264 vs 00000264) Reviewed-by: Yubo Xie Reviewed-by: Sil Vilerino Part-of: --- .../frontends/mediafoundation/mftransform.cpp | 21 +++++++ .../frontends/mediafoundation/wpptrace.cpp | 35 +++++++++++- .../frontends/mediafoundation/wpptrace.h | 55 +++++++++++++++++++ 3 files changed, 110 insertions(+), 1 deletion(-) diff --git a/src/gallium/frontends/mediafoundation/mftransform.cpp b/src/gallium/frontends/mediafoundation/mftransform.cpp index 8aa15b4948a..609e7918732 100644 --- a/src/gallium/frontends/mediafoundation/mftransform.cpp +++ b/src/gallium/frontends/mediafoundation/mftransform.cpp @@ -1116,10 +1116,12 @@ CDX12EncHMFT::xThreadProc( void *pCtx ) { // Wait for completion hr = d3d12_encoder_fence->SetEventOnCompletion( encoder_fence_value, NULL ); + HMFT_ETW_EVENT_INFO( "FenceCompletion", pThis ); } CloseHandle( encoder_fence_shared_handle ); } + assert( SUCCEEDED( hr ) ); if( SUCCEEDED( hr ) ) { @@ -1279,6 +1281,7 @@ CDX12EncHMFT::xThreadProc( void *pCtx ) spOutputSample->SetUINT32( MF_NALU_LENGTH_SET, 1 ); { auto lock = pThis->m_OutputQueueLock.lock(); + HMFT_ETW_EVENT_INFO( "METransformHaveOutput", pThis ); if( SUCCEEDED( pThis->QueueEvent( METransformHaveOutput, GUID_NULL, S_OK, nullptr ) ) ) { pThis->m_OutputQueue.push( spOutputSample.Detach() ); @@ -1816,6 +1819,7 @@ done: HRESULT CDX12EncHMFT::ProcessInput( DWORD dwInputStreamIndex, IMFSample *pSample, DWORD dwFlags ) { + HMFT_ETW_EVENT_START( "ProcessInput", this ); HRESULT hr = S_OK; wil::unique_cotaskmem_array_ptr pMBData = nullptr; UINT32 unChromaOnly = 0; @@ -1879,6 +1883,8 @@ CDX12EncHMFT::ProcessInput( DWORD dwInputStreamIndex, IMFSample *pSample, DWORD { auto lock = m_encoderLock.lock(); + HMFT_ETW_EVENT_START( "PipeSubmitFrame", this ); + m_pPipeVideoCodec->begin_frame( m_pPipeVideoCodec, pDX12EncodeContext->pPipeVideoBuffer, &pDX12EncodeContext->encoderPicInfo.base ); @@ -1902,17 +1908,26 @@ CDX12EncHMFT::ProcessInput( DWORD dwInputStreamIndex, IMFSample *pSample, DWORD &pDX12EncodeContext->pAsyncCookie ); } + HMFT_ETW_EVENT_STOP( "PipeSubmitFrame", this ); + pDX12EncodeContext->encoderPicInfo.base.fence = &pDX12EncodeContext->pAsyncFence; // end_frame will fill in the fence as output param + + HMFT_ETW_EVENT_START( "PipeEndFrame", this ); int status = m_pPipeVideoCodec->end_frame( m_pPipeVideoCodec, pDX12EncodeContext->pPipeVideoBuffer, &pDX12EncodeContext->encoderPicInfo.base ); + HMFT_ETW_EVENT_STOP( "PipeEndFrame", this ); + CHECKBOOL_GOTO( ( m_spDevice->GetDeviceRemovedReason() == S_OK ), DXGI_ERROR_DEVICE_REMOVED, done ); // NULL returned fence indicates encode error CHECKNULL_GOTO( pDX12EncodeContext->pAsyncFence, MF_E_UNEXPECTED, done ); // non zero status indicates encode error CHECKBOOL_GOTO( ( status == 0 ), MF_E_UNEXPECTED, done ); + + HMFT_ETW_EVENT_START( "PipeFlush", this ); m_pPipeVideoCodec->flush( m_pPipeVideoCodec ); + HMFT_ETW_EVENT_STOP( "PipeFlush", this ); } m_EncodingQueue.push( pDX12EncodeContext ); // Moves the GOP tracker state to the next frame for having next @@ -1949,6 +1964,8 @@ done: { MFE_ERROR( "[dx12 hmft 0x%p] ProcessInput - hr=0x%x", this, hr ); } + + HMFT_ETW_EVENT_STOP( "ProcessInput", this ); return hr; } @@ -1957,6 +1974,8 @@ done: HRESULT CDX12EncHMFT::ProcessOutput( DWORD dwFlags, DWORD cOutputBufferCount, MFT_OUTPUT_DATA_BUFFER *pOutputSamples, OUT DWORD *pdwStatus ) { + HMFT_ETW_EVENT_START( "ProcessOutput", this ); + HRESULT hr = S_OK; auto lock = m_lock.lock(); IMFSample *pSample = nullptr; @@ -2009,6 +2028,8 @@ done: { MFE_ERROR( "[dx12 hmft 0x%p] ProcessOutput - hr=0x%x", this, hr ); } + + HMFT_ETW_EVENT_STOP( "ProcessOutput", this ); return hr; } diff --git a/src/gallium/frontends/mediafoundation/wpptrace.cpp b/src/gallium/frontends/mediafoundation/wpptrace.cpp index 1fce0b4fbf4..31692bb2317 100644 --- a/src/gallium/frontends/mediafoundation/wpptrace.cpp +++ b/src/gallium/frontends/mediafoundation/wpptrace.cpp @@ -20,13 +20,44 @@ * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS * IN THE SOFTWARE. */ - #include "wpptrace.h" + #include "wpptrace.tmh" + +#if VIDEO_CODEC_H264ENC + +TRACELOGGING_DEFINE_PROVIDER( // defines g_hProvider + g_hEtwProvider, // Name of the provider handle + "h264enc.etw", // Human-readable name for the provider + // 0000e264-0dc9-401d-b9b8-05e4eca4977e + ( 0x0000e264, 0x0dc9, 0x401d, 0xb9, 0xb8, 0x05, 0xe4, 0xec, 0xa4, 0x97, 0x7e ) ); + +#elif VIDEO_CODEC_H265ENC + +TRACELOGGING_DEFINE_PROVIDER( // defines g_hProvider + g_hEtwProvider, // Name of the provider handle + "h265enc.etw", // Human-readable name for the provider + // 0000e265-0dc9-401d-b9b8-05e4eca4977e + ( 0x0000e265, 0x0dc9, 0x401d, 0xb9, 0xb8, 0x05, 0xe4, 0xec, 0xa4, 0x97, 0x7e ) ); + +#elif VIDEO_CODEC_AV1ENC + +TRACELOGGING_DEFINE_PROVIDER( // defines g_hProvider + g_hEtwProvider, // Name of the provider handle + "av1enc.etw", // Human-readable name for the provider + // 0000eaa1-0dc9-401d-b9b8-05e4eca4977e + ( 0x0000eaa1, 0x0dc9, 0x401d, 0xb9, 0xb8, 0x05, 0xe4, 0xec, 0xa4, 0x97, 0x7e ) ); + +#else +#error VIDEO_CODEC_xxx must be defined +#endif + void WppInit() { + TraceLoggingRegister( g_hEtwProvider ); + WPP_INIT_TRACING( L"MFEncoder" ); MFE_INFO( "MFEncoder trace is enabled." ); } @@ -36,4 +67,6 @@ WppClean() { MFE_INFO( "MFEncoder trace is shutdown." ); WPP_CLEANUP(); + + TraceLoggingUnregister( g_hEtwProvider ); } diff --git a/src/gallium/frontends/mediafoundation/wpptrace.h b/src/gallium/frontends/mediafoundation/wpptrace.h index 61e56863010..ea7538c1a7f 100644 --- a/src/gallium/frontends/mediafoundation/wpptrace.h +++ b/src/gallium/frontends/mediafoundation/wpptrace.h @@ -23,6 +23,10 @@ #pragma once +#include + +#include + #if VIDEO_CODEC_H264ENC #define DEFINE_MFE_WPP_GUID ( 264, 0dc9, 401d, b9b8, 05e4eca4977e ) #elif VIDEO_CODEC_H265ENC @@ -43,6 +47,7 @@ #define WPP_LEVEL_FLAGS_ENABLED( lvl, flags ) ( WPP_LEVEL_ENABLED( flags ) && WPP_CONTROL( WPP_BIT_##flags ).Level >= lvl ) + // begin_wpp config // // FUNC MFE_INFO{FLAG=MFE_ALL,LEVEL=TRACE_LEVEL_INFORMATION}(MSG, ...); @@ -51,3 +56,53 @@ // FUNC MFE_VERBOSE{FLAG=MFE_ALL,LEVEL=TRACE_LEVEL_VERBOSE}(MSG, ...); // // end_wpp + +// +// TraceLogging ETW +// + +TRACELOGGING_DECLARE_PROVIDER( g_hEtwProvider ); + + +#if VIDEO_CODEC_H264ENC + +#define ETW_MODULE_STR "H264Enc" + +#elif VIDEO_CODEC_H265ENC + +#define ETW_MODULE_STR "H265Enc" + +#elif VIDEO_CODEC_AV1ENC + +#define ETW_MODULE_STR "AV1Enc" + +#else +#error VIDEO_CODEC_xxx must be defined +#endif + +#define HMFT_ETW_EVENT_START( EventId, this ) \ + if( g_hEtwProvider ) \ + { \ + TraceLoggingWrite( g_hEtwProvider, \ + EventId, \ + TraceLoggingOpcode( EVENT_TRACE_TYPE_START ), \ + TraceLoggingPointer( this, ETW_MODULE_STR ) ); \ + } + +#define HMFT_ETW_EVENT_STOP( EventId, this ) \ + if( g_hEtwProvider ) \ + { \ + TraceLoggingWrite( g_hEtwProvider, \ + EventId, \ + TraceLoggingOpcode( EVENT_TRACE_TYPE_STOP ), \ + TraceLoggingPointer( this, ETW_MODULE_STR ) ); \ + } + +#define HMFT_ETW_EVENT_INFO( EventId, this ) \ + if( g_hEtwProvider ) \ + { \ + TraceLoggingWrite( g_hEtwProvider, \ + EventId, \ + TraceLoggingOpcode( EVENT_TRACE_TYPE_INFO ), \ + TraceLoggingPointer( this, ETW_MODULE_STR ) ); \ + }