Skip to content

Commit

Permalink
MediaCapabilities - sanitize DB data
Browse files Browse the repository at this point in the history
UKM shows that 0.0025621 % of reports have a weird quirk where dropped
frames exceed decoded frames by 1. I've been unable to determine the
cause of the off-by-one, but we don't want to simply throw out the data
because this is a very strong signal the machine can't keep up. Instead,
this CL just caps all frame counts to the total number of decoded frames.

Additionally, 0.385807851 % of records in the DB appear to be corrupted.
This causes our proto's double fields to contain crazy high values,
triggering exceptions (crashes) in floating point math. This CL will
discard any DB data that is obviously corrupt. This is tied to the
above fix because we can now consider dropped > decoded to reliably be
DB corruption.

Bug: 796885,982009
Change-Id: Id7d0adb509d7e20b3b61453e7407c8efff9feb86
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1717403
Reviewed-by: Frank Liberato <liberato@chromium.org>
Reviewed-by: Steven Holte <holte@chromium.org>
Commit-Queue: Chrome Cunningham <chcunningham@chromium.org>
Auto-Submit: Chrome Cunningham <chcunningham@chromium.org>
Cr-Commit-Position: refs/heads/master@{#681187}
  • Loading branch information
chcunningham authored and Commit Bot committed Jul 26, 2019
1 parent 89eb64a commit b75411b
Show file tree
Hide file tree
Showing 6 changed files with 242 additions and 50 deletions.
18 changes: 13 additions & 5 deletions media/blink/video_decode_stats_reporter.cc
Original file line number Diff line number Diff line change
Expand Up @@ -188,7 +188,6 @@ bool VideoDecodeStatsReporter::UpdateDecodeProgress(
const PipelineStatistics& stats) {
DCHECK_GE(stats.video_frames_decoded, last_frames_decoded_);
DCHECK_GE(stats.video_frames_dropped, last_frames_dropped_);
DCHECK_GE(stats.video_frames_decoded, stats.video_frames_dropped);

// Check if additional frames decoded since last stats update.
if (stats.video_frames_decoded == last_frames_decoded_) {
Expand Down Expand Up @@ -309,11 +308,20 @@ void VideoDecodeStatsReporter::UpdateStats() {
if (stats.video_frames_decoded == frames_decoded_offset_)
return;

// Cap all counts to |frames_decoded|. We should never exceed this cap, but
// we have some hard to track bug where we accumulate 1 extra dropped frame
// in a tiny minority of cases. Dropping all frames is a strong signal we
// don't want to discard, so just sanitize the data and carry on.
uint32_t frames_decoded = stats.video_frames_decoded - frames_decoded_offset_;
uint32_t frames_dropped = std::min(
stats.video_frames_dropped - frames_dropped_offset_, frames_decoded);
uint32_t frames_power_efficient =
std::min(stats.video_frames_decoded_power_efficient -
frames_decoded_power_efficient_offset_,
frames_decoded);

mojom::PredictionTargetsPtr targets = mojom::PredictionTargets::New(
stats.video_frames_decoded - frames_decoded_offset_,
stats.video_frames_dropped - frames_dropped_offset_,
stats.video_frames_decoded_power_efficient -
frames_decoded_power_efficient_offset_);
frames_decoded, frames_dropped, frames_power_efficient);

DVLOG(2) << __func__ << " Recording -- dropped:" << targets->frames_dropped
<< "/" << targets->frames_decoded
Expand Down
120 changes: 81 additions & 39 deletions media/blink/video_decode_stats_reporter_unittest.cc
Original file line number Diff line number Diff line change
Expand Up @@ -120,7 +120,7 @@ class VideoDecodeStatsReporterTest : public ::testing::Test {
// Start each test with no decodes, no drops, and steady framerate.
pipeline_decoded_frames_ = 0;
pipeline_dropped_frames_ = 0;
pipeline_decoded_power_efficient_frames_ = 0;
pipeline_power_efficient_frames_ = 0;
pipeline_framerate_ = kDefaultFps;
}

Expand All @@ -136,21 +136,19 @@ class VideoDecodeStatsReporterTest : public ::testing::Test {
PipelineStatistics MakeAdvancingDecodeStats() {
pipeline_decoded_frames_ += kDecodeCountIncrement;
pipeline_dropped_frames_ += kDroppedCountIncrement;
pipeline_decoded_power_efficient_frames_ +=
kDecodePowerEfficientCountIncrement;
pipeline_power_efficient_frames_ += kDecodePowerEfficientCountIncrement;
return MakeStats(pipeline_decoded_frames_, pipeline_dropped_frames_,
pipeline_decoded_power_efficient_frames_,
pipeline_framerate_);
pipeline_power_efficient_frames_, pipeline_framerate_);
}

// Peek at what MakeAdvancingDecodeStats() will return next without advancing
// the tracked counts.
PipelineStatistics PeekNextDecodeStats() const {
return MakeStats(pipeline_decoded_frames_ + kDecodeCountIncrement,
pipeline_dropped_frames_ + kDroppedCountIncrement,
pipeline_decoded_power_efficient_frames_ +
kDecodePowerEfficientCountIncrement,
pipeline_framerate_);
return MakeStats(
pipeline_decoded_frames_ + kDecodeCountIncrement,
pipeline_dropped_frames_ + kDroppedCountIncrement,
pipeline_power_efficient_frames_ + kDecodePowerEfficientCountIncrement,
pipeline_framerate_);
}

protected:
Expand Down Expand Up @@ -334,7 +332,7 @@ class VideoDecodeStatsReporterTest : public ::testing::Test {
// frames should at least not move backward.
EXPECT_GT(next_stats.video_frames_decoded, pipeline_decoded_frames_);
EXPECT_GT(next_stats.video_frames_decoded_power_efficient,
pipeline_decoded_power_efficient_frames_);
pipeline_power_efficient_frames_);
EXPECT_GE(next_stats.video_frames_dropped, pipeline_dropped_frames_);

// Verify that UpdateRecord calls come at the recording interval with
Expand All @@ -347,6 +345,8 @@ class VideoDecodeStatsReporterTest : public ::testing::Test {
next_stats.video_frames_decoded_power_efficient -
decoded_power_efficient_offset));
FastForward(kRecordingInterval);
testing::Mock::VerifyAndClearExpectations(this);
testing::Mock::VerifyAndClearExpectations(interceptor_);
}

// Injected callback for fetching statistics. Each test will manage
Expand All @@ -357,7 +357,7 @@ class VideoDecodeStatsReporterTest : public ::testing::Test {
// SetUp() for initialization.
uint32_t pipeline_decoded_frames_;
uint32_t pipeline_dropped_frames_;
uint32_t pipeline_decoded_power_efficient_frames_;
uint32_t pipeline_power_efficient_frames_;
double pipeline_framerate_;

// Placed as a class member to avoid static initialization costs.
Expand Down Expand Up @@ -403,8 +403,7 @@ TEST_F(VideoDecodeStatsReporterTest, RecordWhilePlaying) {
// last provided to GetPipelineStatsCB.
uint32_t decoded_offset = pipeline_decoded_frames_;
uint32_t dropped_offset = pipeline_dropped_frames_;
uint32_t decoded_power_efficient_offset =
pipeline_decoded_power_efficient_frames_;
uint32_t decoded_power_efficient_offset = pipeline_power_efficient_frames_;

// Verify that UpdateRecord calls come at the recording interval with
// correct values.
Expand All @@ -423,8 +422,7 @@ TEST_F(VideoDecodeStatsReporterTest, RecordingStopsWhenPaused) {
// last provided to GetPipelineStatsCB.
uint32_t decoded_offset = pipeline_decoded_frames_;
uint32_t dropped_offset = pipeline_dropped_frames_;
uint32_t decoded_power_efficient_offset =
pipeline_decoded_power_efficient_frames_;
uint32_t decoded_power_efficient_offset = pipeline_power_efficient_frames_;

AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);
Expand Down Expand Up @@ -452,8 +450,7 @@ TEST_F(VideoDecodeStatsReporterTest, RecordingStopsWhenHidden) {
// last provided to GetPipelineStatsCB.
uint32_t decoded_offset = pipeline_decoded_frames_;
uint32_t dropped_offset = pipeline_dropped_frames_;
uint32_t decoded_power_efficient_offset =
pipeline_decoded_power_efficient_frames_;
uint32_t decoded_power_efficient_offset = pipeline_power_efficient_frames_;

AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);
Expand All @@ -478,7 +475,7 @@ TEST_F(VideoDecodeStatsReporterTest, RecordingStopsWhenHidden) {
// Update offsets for new record and verify updates resume as time advances.
decoded_offset = pipeline_decoded_frames_;
dropped_offset = pipeline_dropped_frames_;
decoded_power_efficient_offset = pipeline_decoded_power_efficient_frames_;
decoded_power_efficient_offset = pipeline_power_efficient_frames_;
AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);
}
Expand All @@ -490,17 +487,16 @@ TEST_F(VideoDecodeStatsReporterTest, RecordingStopsWhenNoDecodeProgress) {
// last provided to GetPipelineStatsCB.
uint32_t decoded_offset = pipeline_decoded_frames_;
uint32_t dropped_offset = pipeline_dropped_frames_;
uint32_t decoded_power_efficient_offset =
pipeline_decoded_power_efficient_frames_;
uint32_t decoded_power_efficient_offset = pipeline_power_efficient_frames_;

AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);

// Freeze decode stats at current values, simulating network underflow.
ON_CALL(*this, GetPipelineStatsCB())
.WillByDefault(Return(MakeStats(
pipeline_decoded_frames_, pipeline_dropped_frames_,
pipeline_decoded_power_efficient_frames_, pipeline_framerate_)));
.WillByDefault(Return(
MakeStats(pipeline_decoded_frames_, pipeline_dropped_frames_,
pipeline_power_efficient_frames_, pipeline_framerate_)));

// Verify record updates stop while decode is not progressing. Fast forward
// through several recording intervals to be sure we never call UpdateRecord.
Expand All @@ -525,8 +521,7 @@ TEST_F(VideoDecodeStatsReporterTest, NewRecordStartsForFpsChange) {
// last provided to GetPipelineStatsCB.
uint32_t decoded_offset = pipeline_decoded_frames_;
uint32_t dropped_offset = pipeline_dropped_frames_;
uint32_t decoded_power_efficient_offset =
pipeline_decoded_power_efficient_frames_;
uint32_t decoded_power_efficient_offset = pipeline_power_efficient_frames_;

AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);
Expand All @@ -551,7 +546,7 @@ TEST_F(VideoDecodeStatsReporterTest, NewRecordStartsForFpsChange) {
// Offsets should be adjusted so the new record starts at zero.
decoded_offset = pipeline_decoded_frames_;
dropped_offset = pipeline_dropped_frames_;
decoded_power_efficient_offset = pipeline_decoded_power_efficient_frames_;
decoded_power_efficient_offset = pipeline_power_efficient_frames_;

// Stats callbacks and record updates should proceed as usual.
AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
Expand Down Expand Up @@ -635,7 +630,7 @@ TEST_F(VideoDecodeStatsReporterTest, FpsStabilizationFailed_TinyWindows) {
// last provided to GetPipelineStatsCB.
decoded_offset = pipeline_decoded_frames_;
dropped_offset = pipeline_dropped_frames_;
decoded_power_efficient_offset = pipeline_decoded_power_efficient_frames_;
decoded_power_efficient_offset = pipeline_power_efficient_frames_;

AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);
Expand Down Expand Up @@ -698,9 +693,9 @@ TEST_F(VideoDecodeStatsReporterTest, ThrottleFpsTimerIfNoDecodeProgress) {
// With stabilization still ongoing, freeze decode progress by repeatedly
// returning the same stats from before.
ON_CALL(*this, GetPipelineStatsCB())
.WillByDefault(Return(MakeStats(
pipeline_decoded_frames_, pipeline_dropped_frames_,
pipeline_decoded_power_efficient_frames_, pipeline_framerate_)));
.WillByDefault(Return(
MakeStats(pipeline_decoded_frames_, pipeline_dropped_frames_,
pipeline_power_efficient_frames_, pipeline_framerate_)));

// Advance another fps detection interval to detect that no progress was made.
// Verify this decreases timer frequency to standard reporting interval.
Expand Down Expand Up @@ -732,8 +727,7 @@ TEST_F(VideoDecodeStatsReporterTest, ThrottleFpsTimerIfNoDecodeProgress) {
// last provided to GetPipelineStatsCB.
uint32_t decoded_offset = pipeline_decoded_frames_;
uint32_t dropped_offset = pipeline_dropped_frames_;
uint32_t decoded_power_efficient_offset =
pipeline_decoded_power_efficient_frames_;
uint32_t decoded_power_efficient_offset = pipeline_power_efficient_frames_;

AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);
Expand All @@ -748,8 +742,7 @@ TEST_F(VideoDecodeStatsReporterTest, FpsBucketing) {
// last provided to GetPipelineStatsCB.
uint32_t decoded_offset = pipeline_decoded_frames_;
uint32_t dropped_offset = pipeline_dropped_frames_;
uint32_t decoded_power_efficient_offset =
pipeline_decoded_power_efficient_frames_;
uint32_t decoded_power_efficient_offset = pipeline_power_efficient_frames_;

// Verify that UpdateRecord calls come at the recording interval with
// correct values.
Expand Down Expand Up @@ -783,7 +776,7 @@ TEST_F(VideoDecodeStatsReporterTest, FpsBucketing) {
// Update offsets for new record and verify recording.
decoded_offset = pipeline_decoded_frames_;
dropped_offset = pipeline_dropped_frames_;
decoded_power_efficient_offset = pipeline_decoded_power_efficient_frames_;
decoded_power_efficient_offset = pipeline_power_efficient_frames_;
AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);

Expand All @@ -804,7 +797,7 @@ TEST_F(VideoDecodeStatsReporterTest, FpsBucketing) {
// Update offsets for new record and verify recording.
decoded_offset = pipeline_decoded_frames_;
dropped_offset = pipeline_dropped_frames_;
decoded_power_efficient_offset = pipeline_decoded_power_efficient_frames_;
decoded_power_efficient_offset = pipeline_power_efficient_frames_;
AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);
}
Expand Down Expand Up @@ -869,8 +862,7 @@ TEST_F(VideoDecodeStatsReporterTest, ResolutionTooSmall) {
// last provided to GetPipelineStatsCB.
uint32_t decoded_offset = pipeline_decoded_frames_;
uint32_t dropped_offset = pipeline_dropped_frames_;
uint32_t decoded_power_efficient_offset =
pipeline_decoded_power_efficient_frames_;
uint32_t decoded_power_efficient_offset = pipeline_power_efficient_frames_;
AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);
}
Expand Down Expand Up @@ -898,4 +890,54 @@ TEST_F(VideoDecodeStatsReporterTest, VaryEmeProperties) {
kFooKeySystem, kNonDefaultHwSecureCodecs);
}

TEST_F(VideoDecodeStatsReporterTest, SanitizeFrameCounts) {
StartPlayingAndStabilizeFramerate();

// Framerate is now stable! Recorded stats should be offset by the values
// last provided to GetPipelineStatsCB.
uint32_t decoded_offset = pipeline_decoded_frames_;
uint32_t dropped_offset = pipeline_dropped_frames_;
uint32_t decoded_power_efficient_offset = pipeline_power_efficient_frames_;

// Verify that UpdateRecord calls come at the recording interval with
// correct values.
AdvanceTimeAndVerifyRecordUpdate(decoded_offset, dropped_offset,
decoded_power_efficient_offset);

// On next call for stats, advance decoded count a little and advance dropped
// and power efficient counts beyond the decoded count.
pipeline_decoded_frames_ += 10;
pipeline_dropped_frames_ = pipeline_decoded_frames_ + 1;
pipeline_power_efficient_frames_ = pipeline_decoded_frames_ + 2;
EXPECT_CALL(*this, GetPipelineStatsCB())
.WillOnce(Return(
MakeStats(pipeline_decoded_frames_, pipeline_dropped_frames_,
pipeline_power_efficient_frames_, pipeline_framerate_)));

// Expect that record update caps dropped and power efficient counts to the
// offset decoded count.
EXPECT_CALL(*interceptor_,
MockUpdateRecord(pipeline_decoded_frames_ - decoded_offset,
pipeline_decoded_frames_ - decoded_offset,
pipeline_decoded_frames_ - decoded_offset));
FastForward(kRecordingInterval);
testing::Mock::VerifyAndClearExpectations(this);
testing::Mock::VerifyAndClearExpectations(interceptor_);

// Dropped and efficient counts should record correctly if subsequent updates
// cease to exceed decoded frame count.
pipeline_decoded_frames_ += 1000;
EXPECT_CALL(*this, GetPipelineStatsCB())
.WillOnce(Return(
MakeStats(pipeline_decoded_frames_, pipeline_dropped_frames_,
pipeline_power_efficient_frames_, pipeline_framerate_)));

EXPECT_CALL(*interceptor_,
MockUpdateRecord(pipeline_decoded_frames_ - decoded_offset,
pipeline_dropped_frames_ - dropped_offset,
pipeline_power_efficient_frames_ -
decoded_power_efficient_offset));
FastForward(kRecordingInterval);
}

} // namespace media
40 changes: 36 additions & 4 deletions media/capabilities/video_decode_stats_db_impl.cc
Original file line number Diff line number Diff line change
Expand Up @@ -166,8 +166,40 @@ void VideoDecodeStatsDBImpl::GetDecodeStats(const VideoDescKey& key,
weak_ptr_factory_.GetWeakPtr(), std::move(get_stats_cb)));
}

bool VideoDecodeStatsDBImpl::AreStatsExpired(
bool VideoDecodeStatsDBImpl::AreStatsUsable(
const DecodeStatsProto* const stats_proto) {
// CHECK FOR CORRUPTION
// We've observed this in a tiny fraction of reports, but the consequences can
// lead to crashes due floating point math exceptions. http://crbug.com/982009

bool are_stats_valid =
// All frame counts should be capped by |frames_decoded|.
stats_proto->frames_dropped() <= stats_proto->frames_decoded() &&
stats_proto->frames_power_efficient() <= stats_proto->frames_decoded() &&

// You can't drop or power-efficiently decode more than 100% of frames.
stats_proto->unweighted_average_frames_dropped() <= 1 &&
stats_proto->unweighted_average_frames_efficient() <= 1 &&

// |last_write_date| represents base::Time::ToJsTime(), a number of msec
// since the epoch, so it should never be negative (zero is valid, as a
// default for this field, indicating the last write was made before we
// added time stamping). The converted time should also never be in the
// future.
stats_proto->last_write_date() >= 0 &&
base::Time::FromJsTime(stats_proto->last_write_date()) <=
wall_clock_->Now();

UMA_HISTOGRAM_BOOLEAN("Media.VideoDecodeStatsDB.OpSuccess.Validate",
are_stats_valid);

if (!are_stats_valid)
return false;

// CHECK FOR EXPIRATION
// Avoid keeping old data forever so users aren't stuck with predictions after
// upgrading their machines (e.g. driver updates or new hardware).

double last_write_date = stats_proto->last_write_date();
if (last_write_date == 0) {
// Set a default time if the write date is zero (no write since proto was
Expand All @@ -178,7 +210,7 @@ bool VideoDecodeStatsDBImpl::AreStatsExpired(
const int kMaxDaysToKeepStats = GetMaxDaysToKeepStats();
DCHECK_GT(kMaxDaysToKeepStats, 0);

return wall_clock_->Now() - base::Time::FromJsTime(last_write_date) >
return wall_clock_->Now() - base::Time::FromJsTime(last_write_date) <=
base::TimeDelta::FromDays(kMaxDaysToKeepStats);
}

Expand All @@ -202,7 +234,7 @@ void VideoDecodeStatsDBImpl::WriteUpdatedEntry(
return;
}

if (!stats_proto || AreStatsExpired(stats_proto.get())) {
if (!stats_proto || !AreStatsUsable(stats_proto.get())) {
// Default instance will have all zeros for numeric types.
stats_proto.reset(new DecodeStatsProto());
}
Expand Down Expand Up @@ -319,7 +351,7 @@ void VideoDecodeStatsDBImpl::OnGotDecodeStats(

std::unique_ptr<DecodeStatsEntry> entry;

if (stats_proto && !AreStatsExpired(stats_proto.get())) {
if (stats_proto && AreStatsUsable(stats_proto.get())) {
DCHECK(success);

if (GetEnableUnweightedEntries()) {
Expand Down
8 changes: 6 additions & 2 deletions media/capabilities/video_decode_stats_db_impl.h
Original file line number Diff line number Diff line change
Expand Up @@ -114,8 +114,12 @@ class MEDIA_EXPORT VideoDecodeStatsDBImpl : public VideoDecodeStatsDB {
void OnStatsCleared(base::OnceClosure clear_done_cb, bool success);

// Return true if:
// "now" - stats_proto.last_write_date > GeMaxDaysToKeepStats()
bool AreStatsExpired(const DecodeStatsProto* const stats_proto);
// values aren't corrupted nonsense (e.g. way more frames dropped than
// decoded, or number of frames_decoded < frames_power_efficient)
// &&
// stats aren't expired.
// ("now" - stats_proto.last_write_date > GeMaxDaysToKeepStats())
bool AreStatsUsable(const DecodeStatsProto* const stats_proto);

void set_wall_clock_for_test(const base::Clock* tick_clock) {
wall_clock_ = tick_clock;
Expand Down
Loading

0 comments on commit b75411b

Please sign in to comment.