media: Limit number of audio timestamp gap MediaLog warnings

This is avoid flooding about://media-internals with too many audio
timestamp gap warnings.

For an example of excessive audio timestamp gap warnings, and the
result after this CL: https://photos.app.goo.gl/9QiPxCVmJLtZNoIV2

Test: Manually verified
Cq-Include-Trybots: luci.chromium.try:android_optional_gpu_tests_rel;luci.chromium.try:linux_optional_gpu_tests_rel;luci.chromium.try:mac_optional_gpu_tests_rel;luci.chromium.try:win_optional_gpu_tests_rel
Change-Id: Ic2570d98419407dde0643e62fe62975fddf2ef14
Reviewed-on: https://chromium-review.googlesource.com/1072027
Commit-Queue: Xiaohan Wang <xhwang@chromium.org>
Reviewed-by: Matthew Wolenetz <wolenetz@chromium.org>
Reviewed-by: Dale Curtis <dalecurtis@chromium.org>
Cr-Commit-Position: refs/heads/master@{#561649}

media/base/mock_media_log.h

@@ -16,10 +16,17 @@
 // |outer| is the std::string searched for substring |sub|.
 #define CONTAINS_STRING(outer, sub) (std::string::npos != (outer).find(sub))
 
-// "media_log_" is expected to be a MockMediaLog, optionally a NiceMock or
-// StrictMock, in scope of the usage of this macro.
+// Assumes |media_log_| is available which is a MockMediaLog, optionally a
+// NiceMock or StrictMock, in scope of the usage of this macro.
 #define EXPECT_MEDIA_LOG(x) EXPECT_MEDIA_LOG_ON(media_log_, x)
 
+// Same as EXPECT_MEDIA_LOG, but for LIMITED_MEDIA_LOG.
+#define EXPECT_LIMITED_MEDIA_LOG(x, count, max) \
+  if (count < max) {                            \
+    EXPECT_MEDIA_LOG_ON(media_log_, x);         \
+    count++;                                    \
+  }
+
 // |log| is expected to evaluate to a MockMediaLog, optionally a NiceMock or
 // StrictMock, in scope of the usage of this macro.
 #define EXPECT_MEDIA_LOG_ON(log, x) EXPECT_CALL((log), DoAddEventLogString((x)))

media/filters/audio_timestamp_validator.cc

@@ -23,6 +23,9 @@ const int kLimitTriesForStableTiming = 5;
 // CheckForTimestampGap().
 const int kStableTimeGapThrsholdMsec = 1;
 
+// Maximum number of timestamp gap warnings sent to MediaLog.
+const int kMaxTimestampGapWarnings = 10;
+
 AudioTimestampValidator::AudioTimestampValidator(
     const AudioDecoderConfig& decoder_config,
     MediaLog* media_log)
@@ -111,7 +114,8 @@ void AudioTimestampValidator::CheckForTimestampGap(
   }
 
   if (std::abs(ts_delta.InMilliseconds()) > drift_warning_threshold_msec_) {
-    MEDIA_LOG(WARNING, media_log_)
+    LIMITED_MEDIA_LOG(WARNING, media_log_, num_timestamp_gap_warnings_,
+                      kMaxTimestampGapWarnings)
         << " Large timestamp gap detected; may cause AV sync to drift."
         << " time:" << buffer.timestamp().InMicroseconds() << "us"
         << " expected:" << expected_ts.InMicroseconds() << "us"

media/filters/audio_timestamp_validator.h

@@ -59,6 +59,9 @@ class MEDIA_EXPORT AudioTimestampValidator {
   // logs if things get worse. See CheckTimestampForGap().
   uint32_t drift_warning_threshold_msec_;
 
+  // Tracks the number of MEDIA_LOG warnings when large timestamp gap detected.
+  int num_timestamp_gap_warnings_ = 0;
+
   DISALLOW_COPY_AND_ASSIGN(AudioTimestampValidator);
 };
 

media/filters/audio_timestamp_validator_unittest.cc

@@ -204,6 +204,9 @@ TEST_P(AudioTimestampValidatorTest, RepeatedWarnForSlowAccumulatingDrift) {
                              "with decoded output."))
       .Times(0);
 
+  int num_timestamp_gap_warnings = 0;
+  const int kMaxTimestampGapWarnings = 10;  // Must be the same as in .cc
+
   for (int i = 0; i < 100; ++i) {
     // Wait for delayed output to begin plus an additional two iterations to
     // start using drift offset. The the two iterations without offset will
@@ -218,9 +221,12 @@ TEST_P(AudioTimestampValidatorTest, RepeatedWarnForSlowAccumulatingDrift) {
     encoded_buffer->set_timestamp((i * kBufferDuration) + offset);
 
     // Expect gap warnings to start when drift hits 50 milliseconds. Warnings
-    // should continue as the gap widens.
+    // should continue as the gap widens until log limit is hit.
+
     if (offset > base::TimeDelta::FromMilliseconds(50)) {
-      EXPECT_MEDIA_LOG(HasSubstr("timestamp gap detected"));
+      EXPECT_LIMITED_MEDIA_LOG(HasSubstr("timestamp gap detected"),
+                               num_timestamp_gap_warnings,
+                               kMaxTimestampGapWarnings);
     }
 
     validator.CheckForTimestampGap(*encoded_buffer);