Bug 1800547 - add some profiler markers for media engine playback. r=padenot

Differential Revision: https://phabricator.services.mozilla.com/D162055

dom/media/ipc/MFMediaEngineParent.cpp

@@ -87,6 +87,7 @@ MFMediaEngineParent::~MFMediaEngineParent() {
 void MFMediaEngineParent::DestroyEngineIfExists(
     const Maybe<MediaResult>& aError) {
   LOG("DestroyEngineIfExists, hasError=%d", aError.isSome());
+  ENGINE_MARKER("MFMediaEngineParent::DestroyEngineIfExists");
   mMediaEngineNotify = nullptr;
   mMediaEngineExtension = nullptr;
   mMediaSource = nullptr;
@@ -167,6 +168,7 @@ void MFMediaEngineParent::CreateMediaEngine() {
 
   LOG("Created media engine successfully");
   mIsCreatedMediaEngine = true;
+  ENGINE_MARKER("MFMediaEngineParent::CreatedMediaEngine");
   errorExit.release();
 }
 
@@ -234,6 +236,9 @@ void MFMediaEngineParent::InitializeVirtualVideoWindow() {
 void MFMediaEngineParent::HandleMediaEngineEvent(
     MFMediaEngineEventWrapper aEvent) {
   AssertOnManagerThread();
+  ENGINE_MARKER_TEXT(
+      "MFMediaEngineParent::HandleMediaEngineEvent",
+      nsPrintfCString("%s", MediaEngineEventToStr(aEvent.mEvent)));
   switch (aEvent.mEvent) {
     case MF_MEDIA_ENGINE_EVENT_ERROR: {
       MOZ_ASSERT(aEvent.mParam1 && aEvent.mParam2);
@@ -289,6 +294,9 @@ void MFMediaEngineParent::NotifyError(MF_MEDIA_ENGINE_ERR aError,
     return;
   }
   LOG("Notify error '%s', hr=%lx", MFMediaEngineErrorToStr(aError), aResult);
+  ENGINE_MARKER_TEXT(
+      "MFMediaEngineParent::NotifyError",
+      nsPrintfCString("%s, hr=%lx", MFMediaEngineErrorToStr(aError), aResult));
   switch (aError) {
     case MF_MEDIA_ENGINE_ERR_ABORTED:
     case MF_MEDIA_ENGINE_ERR_NETWORK:
@@ -380,6 +388,14 @@ mozilla::ipc::IPCResult MFMediaEngineParent::RecvNotifyMediaInfo(
       IPC_OK());
 
   LOG("Finished setup our custom media source to the media engine");
+  ENGINE_MARKER_TEXT(
+      "MFMediaEngineParent,FinishedSetupMediaSource",
+      nsPrintfCString(
+          "audio=%s, video=%s",
+          aInfo.audioInfo() ? aInfo.audioInfo()->mMimeType.BeginReading()
+                            : "none",
+          aInfo.videoInfo() ? aInfo.videoInfo()->mMimeType.BeginReading()
+                            : "none"));
   mRequestSampleListener = mMediaSource->RequestSampleEvent().Connect(
       mManagerThread, this, &MFMediaEngineParent::HandleRequestSample);
 
@@ -391,6 +407,7 @@ mozilla::ipc::IPCResult MFMediaEngineParent::RecvPlay() {
   AssertOnManagerThread();
   if (mMediaEngine) {
     LOG("Play, in playback rate %f", mPlaybackRate);
+    ENGINE_MARKER("MFMediaEngineParent,Play");
     NS_ENSURE_TRUE(SUCCEEDED(mMediaEngine->Play()), IPC_OK());
     // The media engine has some undocumented behaviors for setting playback
     // rate, it will set the rate to 0 when it pauses, and set the rate to 1
@@ -408,6 +425,7 @@ mozilla::ipc::IPCResult MFMediaEngineParent::RecvPause() {
   AssertOnManagerThread();
   if (mMediaEngine) {
     LOG("Pause");
+    ENGINE_MARKER("MFMediaEngineParent,Pause");
     NS_ENSURE_TRUE(SUCCEEDED(mMediaEngine->Pause()), IPC_OK());
   }
   return IPC_OK();
@@ -431,6 +449,8 @@ mozilla::ipc::IPCResult MFMediaEngineParent::RecvSeek(
   }
 
   LOG("Seek to %f", aTargetTimeInSecond);
+  ENGINE_MARKER_TEXT("MFMediaEngineParent,Seek",
+                     nsPrintfCString("%f", aTargetTimeInSecond));
   NS_ENSURE_TRUE(SUCCEEDED(mMediaEngine->SetCurrentTime(aTargetTimeInSecond)),
                  IPC_OK());
 
@@ -441,6 +461,8 @@ mozilla::ipc::IPCResult MFMediaEngineParent::RecvSetVolume(double aVolume) {
   AssertOnManagerThread();
   if (mMediaEngine) {
     LOG("SetVolume=%f", aVolume);
+    ENGINE_MARKER_TEXT("MFMediaEngineParent,SetVolume",
+                       nsPrintfCString("%f", aVolume));
     NS_ENSURE_TRUE(SUCCEEDED(mMediaEngine->SetVolume(aVolume)), IPC_OK());
   }
   return IPC_OK();
@@ -454,6 +476,8 @@ mozilla::ipc::IPCResult MFMediaEngineParent::RecvSetPlaybackRate(
     return IPC_OK();
   }
   LOG("SetPlaybackRate=%f", aPlaybackRate);
+  ENGINE_MARKER_TEXT("MFMediaEngineParent,SetPlaybackRate",
+                     nsPrintfCString("%f", aPlaybackRate));
   mPlaybackRate = aPlaybackRate;
   NS_ENSURE_TRUE(SUCCEEDED(mMediaEngine->SetPlaybackRate(mPlaybackRate)),
                  IPC_OK());
@@ -479,6 +503,7 @@ mozilla::ipc::IPCResult MFMediaEngineParent::RecvNotifyEndOfStream(
 mozilla::ipc::IPCResult MFMediaEngineParent::RecvShutdown() {
   AssertOnManagerThread();
   LOG("Shutdown");
+  ENGINE_MARKER("MFMediaEngineParent,Shutdown");
   DestroyEngineIfExists();
   return IPC_OK();
 }
@@ -519,12 +544,16 @@ void MFMediaEngineParent::EnsureDcompSurfaceHandle() {
         nullptr /* pSrc */, &rect, nullptr /* pBorderClr */));
     LOG("Updated video size for engine=[%lux%lu]", mDisplayWidth,
         mDisplayHeight);
+    ENGINE_MARKER_TEXT(
+        "MFMediaEngineParent,UpdateVideoSize",
+        nsPrintfCString("%lux%lu", mDisplayWidth, mDisplayHeight));
   }
 
   if (!mIsEnableDcompMode) {
     RETURN_VOID_IF_FAILED(mediaEngineEx->EnableWindowlessSwapchainMode(true));
     LOG("Enabled dcomp swap chain mode");
     mIsEnableDcompMode = true;
+    ENGINE_MARKER("MFMediaEngineParent,EnabledSwapChain");
   }
 
   HANDLE surfaceHandle = INVALID_HANDLE_VALUE;

dom/media/ipc/MFMediaEngineUtils.h

@@ -8,6 +8,7 @@
 #include "MFMediaEngineExtra.h"
 #include "ipc/EnumSerializer.h"
 #include "mozilla/Logging.h"
+#include "mozilla/ProfilerMarkerTypes.h"
 
 namespace mozilla {
 
@@ -48,6 +49,13 @@ using MFMediaEngineError = MF_MEDIA_ENGINE_ERR;
     } while (false)
 #endif
 
+#define ENGINE_MARKER(markerName) \
+  PROFILER_MARKER(markerName, MEDIA_PLAYBACK, {}, MediaEngineMarker, Id())
+
+#define ENGINE_MARKER_TEXT(markerName, text)                                   \
+  PROFILER_MARKER(markerName, MEDIA_PLAYBACK, {}, MediaEngineTextMarker, Id(), \
+                  text)
+
 const char* MediaEventTypeToStr(MediaEventType aType);
 const char* MediaEngineEventToStr(MF_MEDIA_ENGINE_EVENT aEvent);
 const char* MFMediaEngineErrorToStr(MFMediaEngineError aError);

dom/media/platforms/wmf/MFMediaSource.cpp

@@ -330,6 +330,8 @@ IFACEMETHODIMP MFMediaSource::QueueEvent(MediaEventType aType,
   RETURN_IF_FAILED(mMediaEventQueue->QueueEventParamVar(aType, aExtendedType,
                                                         aStatus, aValue));
   LOG("Queued event %s", MediaEventTypeToStr(aType));
+  PROFILER_MARKER_TEXT("MFMediaSource::QueueEvent", MEDIA_PLAYBACK, {},
+                       nsPrintfCString("%s", MediaEventTypeToStr(aType)));
   return S_OK;
 }
 
@@ -377,6 +379,10 @@ void MFMediaSource::HandleStreamEnded(TrackInfo::TrackType aType) {
   mPresentationEnded = mIsAudioEnded && mIsVideoEnded;
   LOG("PresentationEnded=%d, audioEnded=%d, videoEnded=%d",
       !!mPresentationEnded, mIsAudioEnded, mIsVideoEnded);
+  PROFILER_MARKER_TEXT(
+      " MFMediaSource::HandleStreamEnded", MEDIA_PLAYBACK, {},
+      nsPrintfCString("PresentationEnded=%d, audioEnded=%d, videoEnded=%d",
+                      !!mPresentationEnded, mIsAudioEnded, mIsVideoEnded));
   if (mPresentationEnded) {
     RETURN_VOID_IF_FAILED(
         QueueEvent(MEEndOfPresentation, GUID_NULL, S_OK, nullptr));

mozglue/baseprofiler/public/BaseProfilerMarkerTypes.h

@@ -85,6 +85,41 @@ struct ContentBuildMarker {
   }
 };
 
+struct MediaEngineMarker {
+  static constexpr Span<const char> MarkerTypeName() {
+    return MakeStringSpan("MediaEngine");
+  }
+  static void StreamJSONMarkerData(baseprofiler::SpliceableJSONWriter& aWriter,
+                                   uint64_t aMediaEngineId) {
+    aWriter.IntProperty("id", aMediaEngineId);
+  }
+  static MarkerSchema MarkerTypeDisplay() {
+    using MS = MarkerSchema;
+    MS schema{MS::Location::MarkerChart, MS::Location::MarkerTable};
+    schema.AddKeyLabelFormat("id", "Id", MS::Format::Integer);
+    return schema;
+  }
+};
+
+struct MediaEngineTextMarker {
+  static constexpr Span<const char> MarkerTypeName() {
+    return MakeStringSpan("MediaEngineText");
+  }
+  static void StreamJSONMarkerData(baseprofiler::SpliceableJSONWriter& aWriter,
+                                   uint64_t aMediaEngineId,
+                                   const ProfilerString8View& aText) {
+    aWriter.IntProperty("id", aMediaEngineId);
+    aWriter.StringProperty("text", aText);
+  }
+  static MarkerSchema MarkerTypeDisplay() {
+    using MS = MarkerSchema;
+    MS schema{MS::Location::MarkerChart, MS::Location::MarkerTable};
+    schema.AddKeyLabelFormat("id", "Id", MS::Format::Integer);
+    schema.AddKeyLabelFormat("text", "Details", MS::Format::String);
+    return schema;
+  }
+};
+
 }  // namespace mozilla::baseprofiler::markers
 
 #endif  // BaseProfilerMarkerTypes_h

tools/profiler/public/ProfilerMarkerTypes.h

@@ -32,6 +32,9 @@ using MediaSampleMarker = mozilla::baseprofiler::markers::MediaSampleMarker;
 using VideoFallingBehindMarker =
     mozilla::baseprofiler::markers::VideoFallingBehindMarker;
 using ContentBuildMarker = mozilla::baseprofiler::markers::ContentBuildMarker;
+using MediaEngineMarker = mozilla::baseprofiler::markers::MediaEngineMarker;
+using MediaEngineTextMarker =
+    mozilla::baseprofiler::markers::MediaEngineTextMarker;
 
 }  // namespace geckoprofiler::markers