Bug 1755316 - Add extra logging to platforms decoders r=alwu

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

dom/media/TimeUnits.h

@@ -14,6 +14,7 @@
 #include "mozilla/FloatingPoint.h"
 #include "mozilla/Maybe.h"
 #include "mozilla/TimeStamp.h"
+#include "mozilla/IntegerPrintfMacros.h"
 
 namespace mozilla {
 namespace media {
@@ -40,6 +41,16 @@ namespace media {
 // Number of nanoseconds per second. 1e9.
 static const int64_t NSECS_PER_S = 1000000000;
 
+#ifndef PROCESS_DECODE_LOG
+#  define PROCESS_DECODE_LOG(sample)                                         \
+    MOZ_LOG(                                                                 \
+        sPDMLog, mozilla::LogLevel::Verbose,                                 \
+        ("ProcessDecode: mDuration=%" PRIu64 "µs ; mTime=%" PRIu64           \
+         "µs ; mTimecode=%" PRIu64 "µs",                                     \
+         sample->mDuration.ToMicroseconds(), sample->mTime.ToMicroseconds(), \
+         sample->mTimecode.ToMicroseconds()))
+#endif  // PROCESS_DECODE_LOG
+
 // TimeUnit at present uses a CheckedInt64 as storage.
 // INT64_MAX has the special meaning of being +oo.
 class TimeUnit final {

dom/media/platforms/agnostic/AgnosticDecoderModule.cpp

@@ -117,8 +117,8 @@ bool AgnosticDecoderModule::Supports(
       (WaveDataDecoder::IsWave(mimeType) && IsAvailable(DecoderType::Wave)) ||
       (OpusDataDecoder::IsOpus(mimeType) && IsAvailable(DecoderType::Opus));
   MOZ_LOG(sPDMLog, LogLevel::Debug,
-          ("Agnostic decoder %s requested type",
-           supports ? "supports" : "rejects"));
+          ("Agnostic decoder %s requested type '%s'",
+           supports ? "supports" : "rejects", mimeType.BeginReading()));
   return supports;
 }
 

dom/media/platforms/agnostic/OpusDecoder.cpp

@@ -180,6 +180,7 @@ nsresult OpusDataDecoder::DecodeHeader(const unsigned char* aData,
 RefPtr<MediaDataDecoder::DecodePromise> OpusDataDecoder::Decode(
     MediaRawData* aSample) {
   MOZ_ASSERT(mThread->IsOnCurrentThread());
+  PROCESS_DECODE_LOG(aSample);
   uint32_t channels = mOpusParser->mChannels;
 
   if (mPaddingDiscarded) {

dom/media/platforms/agnostic/VorbisDecoder.cpp

@@ -139,6 +139,7 @@ nsresult VorbisDataDecoder::DecodeHeader(const unsigned char* aData,
 RefPtr<MediaDataDecoder::DecodePromise> VorbisDataDecoder::Decode(
     MediaRawData* aSample) {
   MOZ_ASSERT(mThread->IsOnCurrentThread());
+  PROCESS_DECODE_LOG(aSample);
 
   const unsigned char* aData = aSample->Data();
   size_t aLength = aSample->Size();

dom/media/platforms/apple/AppleDecoderModule.cpp

@@ -76,10 +76,14 @@ already_AddRefed<MediaDataDecoder> AppleDecoderModule::CreateAudioDecoder(
 
 bool AppleDecoderModule::SupportsMimeType(
     const nsACString& aMimeType, DecoderDoctorDiagnostics* aDiagnostics) const {
-  return (aMimeType.EqualsLiteral("audio/mpeg") &&
-          !StaticPrefs::media_ffvpx_mp3_enabled()) ||
-         aMimeType.EqualsLiteral("audio/mp4a-latm") ||
-         MP4Decoder::IsH264(aMimeType) || VPXDecoder::IsVP9(aMimeType);
+  bool supports = (aMimeType.EqualsLiteral("audio/mpeg") &&
+                   !StaticPrefs::media_ffvpx_mp3_enabled()) ||
+                  aMimeType.EqualsLiteral("audio/mp4a-latm") ||
+                  MP4Decoder::IsH264(aMimeType) || VPXDecoder::IsVP9(aMimeType);
+  MOZ_LOG(sPDMLog, LogLevel::Debug,
+          ("Apple decoder %s requested type '%s'",
+           supports ? "supports" : "rejects", aMimeType.BeginReading()));
+  return supports;
 }
 
 bool AppleDecoderModule::Supports(

dom/media/platforms/apple/AppleVTDecoder.cpp

@@ -147,6 +147,7 @@ static CMSampleTimingInfo TimingInfoFromSample(MediaRawData* aSample) {
 
 void AppleVTDecoder::ProcessDecode(MediaRawData* aSample) {
   AssertOnTaskQueue();
+  PROCESS_DECODE_LOG(aSample);
 
   if (mIsFlushing) {
     MonitorAutoLock mon(mMonitor);

dom/media/platforms/ffmpeg/FFmpegAudioDecoder.cpp

@@ -186,6 +186,7 @@ MediaResult FFmpegAudioDecoder<LIBAV_VER>::DoDecode(MediaRawData* aSample,
                                                     bool* aGotFrame,
                                                     DecodedData& aResults) {
   MOZ_ASSERT(mTaskQueue->IsOnCurrentThread());
+  PROCESS_DECODE_LOG(aSample);
   AVPacket packet;
   mLib->av_init_packet(&packet);
 

dom/media/platforms/ffmpeg/FFmpegDataDecoder.cpp

@@ -141,6 +141,7 @@ RefPtr<MediaDataDecoder::DecodePromise> FFmpegDataDecoder<LIBAV_VER>::Decode(
 RefPtr<MediaDataDecoder::DecodePromise>
 FFmpegDataDecoder<LIBAV_VER>::ProcessDecode(MediaRawData* aSample) {
   MOZ_ASSERT(mTaskQueue->IsOnCurrentThread());
+  PROCESS_DECODE_LOG(aSample);
   bool gotFrame = false;
   DecodedData results;
   MediaResult rv = DoDecode(aSample, &gotFrame, results);

dom/media/platforms/ffmpeg/FFmpegDecoderModule.h

@@ -73,16 +73,26 @@ class FFmpegDecoderModule : public PlatformDecoderModule {
     // the check for alpha to PDMFactory but not itself remove the need for a
     // check.
     if (VPXDecoder::IsVPX(mimeType) && trackInfo.GetAsVideoInfo()->HasAlpha()) {
+      MOZ_LOG(sPDMLog, LogLevel::Debug,
+              ("FFmpeg decoder rejects requested type '%s'",
+               mimeType.BeginReading()));
       return false;
     }
 
     AVCodecID videoCodec = FFmpegVideoDecoder<V>::GetCodecId(mimeType);
     AVCodecID audioCodec = FFmpegAudioDecoder<V>::GetCodecId(mimeType);
     if (audioCodec == AV_CODEC_ID_NONE && videoCodec == AV_CODEC_ID_NONE) {
+      MOZ_LOG(sPDMLog, LogLevel::Debug,
+              ("FFmpeg decoder rejects requested type '%s'",
+               mimeType.BeginReading()));
       return false;
     }
     AVCodecID codec = audioCodec != AV_CODEC_ID_NONE ? audioCodec : videoCodec;
-    return !!FFmpegDataDecoder<V>::FindAVCodec(mLib, codec);
+    bool supports = !!FFmpegDataDecoder<V>::FindAVCodec(mLib, codec);
+    MOZ_LOG(sPDMLog, LogLevel::Debug,
+            ("FFmpeg decoder %s requested type '%s'",
+             supports ? "supports" : "rejects", mimeType.BeginReading()));
+    return supports;
   }
 
  protected:

dom/media/platforms/wmf/WMFDecoderModule.cpp

@@ -399,7 +399,11 @@ bool WMFDecoderModule::SupportsMimeType(
   if (!trackInfo) {
     return false;
   }
-  return Supports(SupportDecoderParams(*trackInfo), aDiagnostics);
+  bool supports = Supports(SupportDecoderParams(*trackInfo), aDiagnostics);
+  MOZ_LOG(sPDMLog, LogLevel::Debug,
+          ("WMF decoder %s requested type '%s'",
+           supports ? "supports" : "rejects", aMimeType.BeginReading()));
+  return supports;
 }
 
 }  // namespace mozilla