Commit 75ab8715 authored by Stephen McGruer's avatar Stephen McGruer Committed by Commit Bot

Revert "Add underflow duration to our media UKM reporting."

This reverts commit 29a875e1.

Reason for revert: Strong suspect for compile failure blocking the tree: https://logs.chromium.org/logs/chromium/buildbucket/cr-buildbucket.appspot.com/8898774375244271360/+/steps/compile/0/stdout

Original change's description:
> Add underflow duration to our media UKM reporting.
> 
> This associates a completed underflow count and total underflow duration
> with each segment of watch time reported to UKM.
> 
> Generally the completion will always fall within a given segment of
> watch time, however it is possible that a completion can happen after a
> resolution change or other secondary property update and thus end up in
> a subsequent segment.
> 
> We impose impose a maximum value of 1 minute for rebuffer durations to
> avoid noise from rebuffers which may cross a suspend/resume boundary.
> 
> BUG=994021
> TEST=new unittests
> R=​sandersd
> 
> Change-Id: I1b4386845e21ec17472cbf8c85bf62185e28eb25
> Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1869023
> Reviewed-by: Mustafa Emre Acer <meacer@chromium.org>
> Reviewed-by: Steven Holte <holte@chromium.org>
> Reviewed-by: Dan Sanders <sandersd@chromium.org>
> Commit-Queue: Dale Curtis <dalecurtis@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#708778}

TBR=dalecurtis@chromium.org,meacer@chromium.org,sandersd@chromium.org,holte@chromium.org

Change-Id: I6bdff8dee0fb365eabee3bea8501a22155059d0d
No-Presubmit: true
No-Tree-Checks: true
No-Try: true
Bug: 994021
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1877192Reviewed-by: default avatarStephen McGruer <smcgruer@chromium.org>
Commit-Queue: Stephen McGruer <smcgruer@chromium.org>
Cr-Commit-Position: refs/heads/master@{#708784}
parent d737e07b
...@@ -22,7 +22,6 @@ class WatchTimeInterceptor : public mojom::WatchTimeRecorder { ...@@ -22,7 +22,6 @@ class WatchTimeInterceptor : public mojom::WatchTimeRecorder {
MOCK_METHOD1(FinalizeWatchTime, void(const std::vector<WatchTimeKey>&)); MOCK_METHOD1(FinalizeWatchTime, void(const std::vector<WatchTimeKey>&));
MOCK_METHOD1(OnError, void(PipelineStatus)); MOCK_METHOD1(OnError, void(PipelineStatus));
MOCK_METHOD1(UpdateUnderflowCount, void(int32_t count)); MOCK_METHOD1(UpdateUnderflowCount, void(int32_t count));
MOCK_METHOD2(UpdateUnderflowDuration, void(int32_t, base::TimeDelta));
MOCK_METHOD1( MOCK_METHOD1(
UpdateSecondaryProperties, UpdateSecondaryProperties,
void(mojom::SecondaryPlaybackPropertiesPtr secondary_properties)); void(mojom::SecondaryPlaybackPropertiesPtr secondary_properties));
......
...@@ -4,12 +4,8 @@ ...@@ -4,12 +4,8 @@
#include "media/blink/watch_time_reporter.h" #include "media/blink/watch_time_reporter.h"
#include <numeric>
#include "base/bind.h" #include "base/bind.h"
#include "base/power_monitor/power_monitor.h" #include "base/power_monitor/power_monitor.h"
#include "base/time/time.h"
#include "media/base/timestamp_constants.h"
#include "media/base/watch_time_keys.h" #include "media/base/watch_time_keys.h"
namespace media { namespace media {
...@@ -240,35 +236,10 @@ void WatchTimeReporter::OnUnderflow() { ...@@ -240,35 +236,10 @@ void WatchTimeReporter::OnUnderflow() {
if (!reporting_timer_.IsRunning()) if (!reporting_timer_.IsRunning())
return; return;
if (!pending_underflow_events_.empty())
DCHECK_NE(pending_underflow_events_.back().duration, kNoTimestamp);
// In the event of a pending finalize, we don't want to count underflow events // In the event of a pending finalize, we don't want to count underflow events
// that occurred after the finalize time. Yet if the finalize is canceled we // that occurred after the finalize time. Yet if the finalize is canceled we
// want to ensure they are all recorded. // want to ensure they are all recorded.
pending_underflow_events_.push_back( pending_underflow_events_.push_back(get_media_time_cb_.Run());
{false, get_media_time_cb_.Run(), kNoTimestamp});
}
void WatchTimeReporter::OnUnderflowComplete(base::TimeDelta elapsed) {
if (background_reporter_)
background_reporter_->OnUnderflowComplete(elapsed);
if (muted_reporter_)
muted_reporter_->OnUnderflowComplete(elapsed);
if (!reporting_timer_.IsRunning())
return;
// Drop this underflow completion if we don't have a corresponding underflow
// start event; this can happen if a finalize occurs between the underflow and
// the completion.
if (pending_underflow_events_.empty())
return;
// There should only ever be one outstanding underflow, so stick the duration
// in the last underflow event.
DCHECK_EQ(pending_underflow_events_.back().duration, kNoTimestamp);
pending_underflow_events_.back().duration = elapsed;
} }
void WatchTimeReporter::OnNativeControlsEnabled() { void WatchTimeReporter::OnNativeControlsEnabled() {
...@@ -404,7 +375,9 @@ void WatchTimeReporter::MaybeStartReportingTimer( ...@@ -404,7 +375,9 @@ void WatchTimeReporter::MaybeStartReportingTimer(
if (!should_start) if (!should_start)
return; return;
ResetUnderflowState(); underflow_count_ = 0;
pending_underflow_events_.clear();
base_component_->OnReportingStarted(start_timestamp); base_component_->OnReportingStarted(start_timestamp);
power_component_->OnReportingStarted(start_timestamp); power_component_->OnReportingStarted(start_timestamp);
...@@ -450,46 +423,19 @@ void WatchTimeReporter::RecordWatchTime() { ...@@ -450,46 +423,19 @@ void WatchTimeReporter::RecordWatchTime() {
// Pass along any underflow events which have occurred since the last report. // Pass along any underflow events which have occurred since the last report.
if (!pending_underflow_events_.empty()) { if (!pending_underflow_events_.empty()) {
const int last_underflow_count = total_underflow_count_; if (!base_component_->NeedsFinalize()) {
const int last_completed_underflow_count = total_completed_underflow_count_; // The maximum value here per period is ~5 events, so int cast is okay.
underflow_count_ += static_cast<int>(pending_underflow_events_.size());
for (auto& ufe : pending_underflow_events_) { } else {
// Since the underflow occurred after finalize, ignore the event and mark // Only count underflow events prior to finalize.
// it for deletion. for (auto& ts : pending_underflow_events_) {
if (ufe.timestamp > current_timestamp) { if (ts <= base_component_->end_timestamp())
ufe.reported = true; underflow_count_++;
ufe.duration = base::TimeDelta();
continue;
}
if (!ufe.reported) {
ufe.reported = true;
++total_underflow_count_;
}
// Drop any rebuffer completions that took more than a minute. For our
// purposes these are considered as timeouts. We want a maximum since
// rebuffer duration is in real time and not media time, which means if
// the rebuffer spans a suspend/resume the time can be arbitrarily long.
constexpr base::TimeDelta kMaximumRebufferDuration =
base::TimeDelta::FromMinutes(1);
if (ufe.duration != kNoTimestamp &&
ufe.duration <= kMaximumRebufferDuration) {
++total_completed_underflow_count_;
total_underflow_duration_ += ufe.duration;
} }
} }
base::EraseIf(pending_underflow_events_, [](const UnderflowEvent& ufe) { recorder_->UpdateUnderflowCount(underflow_count_);
return ufe.reported && ufe.duration != kNoTimestamp; pending_underflow_events_.clear();
});
if (last_underflow_count != total_underflow_count_)
recorder_->UpdateUnderflowCount(total_underflow_count_);
if (last_completed_underflow_count != total_completed_underflow_count_) {
recorder_->UpdateUnderflowDuration(total_completed_underflow_count_,
total_underflow_duration_);
}
} }
// Record watch time for all components. // Record watch time for all components.
...@@ -527,16 +473,10 @@ void WatchTimeReporter::UpdateWatchTime() { ...@@ -527,16 +473,10 @@ void WatchTimeReporter::UpdateWatchTime() {
recorder_->FinalizeWatchTime({}); recorder_->FinalizeWatchTime({});
// Stop the timer if this is supposed to be our last tick. // Stop the timer if this is supposed to be our last tick.
ResetUnderflowState(); underflow_count_ = 0;
reporting_timer_.Stop(); reporting_timer_.Stop();
} }
void WatchTimeReporter::ResetUnderflowState() {
total_underflow_count_ = total_completed_underflow_count_ = 0;
total_underflow_duration_ = base::TimeDelta();
pending_underflow_events_.clear();
}
#define NORMAL_KEY(key) \ #define NORMAL_KEY(key) \
((properties_->has_video && properties_->has_audio) \ ((properties_->has_video && properties_->has_audio) \
? (is_background_ ? WatchTimeKey::kAudioVideoBackground##key \ ? (is_background_ ? WatchTimeKey::kAudioVideoBackground##key \
......
...@@ -121,7 +121,6 @@ class MEDIA_BLINK_EXPORT WatchTimeReporter : base::PowerObserver { ...@@ -121,7 +121,6 @@ class MEDIA_BLINK_EXPORT WatchTimeReporter : base::PowerObserver {
// finalized the total watch time for a given category will be divided by the // finalized the total watch time for a given category will be divided by the
// number of rebuffering events. Reset to zero after a finalize event. // number of rebuffering events. Reset to zero after a finalize event.
void OnUnderflow(); void OnUnderflow();
void OnUnderflowComplete(base::TimeDelta elapsed);
// These methods are used to ensure that the watch time is reported relative // These methods are used to ensure that the watch time is reported relative
// to whether the media is using native controls. // to whether the media is using native controls.
...@@ -184,8 +183,6 @@ class MEDIA_BLINK_EXPORT WatchTimeReporter : base::PowerObserver { ...@@ -184,8 +183,6 @@ class MEDIA_BLINK_EXPORT WatchTimeReporter : base::PowerObserver {
void RecordWatchTime(); void RecordWatchTime();
void UpdateWatchTime(); void UpdateWatchTime();
void ResetUnderflowState();
// Helper methods for creating the components that make up the watch time // Helper methods for creating the components that make up the watch time
// report. All components except the base component require a creation method // report. All components except the base component require a creation method
// and a conversion method to get the correct WatchTimeKey. // and a conversion method to get the correct WatchTimeKey.
...@@ -223,15 +220,8 @@ class MEDIA_BLINK_EXPORT WatchTimeReporter : base::PowerObserver { ...@@ -223,15 +220,8 @@ class MEDIA_BLINK_EXPORT WatchTimeReporter : base::PowerObserver {
// transitioning above/below kMinimumVideoSize. // transitioning above/below kMinimumVideoSize.
gfx::Size natural_size_; gfx::Size natural_size_;
int total_underflow_count_ = 0; int underflow_count_ = 0;
int total_completed_underflow_count_ = 0; std::vector<base::TimeDelta> pending_underflow_events_;
base::TimeDelta total_underflow_duration_;
struct UnderflowEvent {
bool reported = false;
base::TimeDelta timestamp = kNoTimestamp;
base::TimeDelta duration = kNoTimestamp;
};
std::vector<UnderflowEvent> pending_underflow_events_;
// The various components making up WatchTime. If the |base_component_| is // The various components making up WatchTime. If the |base_component_| is
// finalized, all reporting will be stopped and finalized using its ending // finalized, all reporting will be stopped and finalized using its ending
......
This diff is collapsed.
...@@ -2102,9 +2102,7 @@ void WebMediaPlayerImpl::OnBufferingStateChangeInternal( ...@@ -2102,9 +2102,7 @@ void WebMediaPlayerImpl::OnBufferingStateChangeInternal(
// Report the amount of time it took to leave the underflow state. // Report the amount of time it took to leave the underflow state.
if (underflow_timer_) { if (underflow_timer_) {
auto elapsed = underflow_timer_->Elapsed(); RecordUnderflowDuration(underflow_timer_->Elapsed());
RecordUnderflowDuration(elapsed);
watch_time_reporter_->OnUnderflowComplete(elapsed);
underflow_timer_.reset(); underflow_timer_.reset();
} }
} else { } else {
......
...@@ -86,7 +86,5 @@ interface WatchTimeRecorder { ...@@ -86,7 +86,5 @@ interface WatchTimeRecorder {
// Indicates that an underflow event has occurred while collecting watch time. // Indicates that an underflow event has occurred while collecting watch time.
// Used to report mean values for rebuffering metrics. As with watch time, // Used to report mean values for rebuffering metrics. As with watch time,
// this is an absolute count and not relative since the last call. // this is an absolute count and not relative since the last call.
UpdateUnderflowCount(int32 total_count); UpdateUnderflowCount(int32 count);
UpdateUnderflowDuration(int32 total_completed_count,
mojo_base.mojom.TimeDelta total_duration);
}; };
...@@ -238,15 +238,9 @@ void WatchTimeRecorder::FinalizeWatchTime( ...@@ -238,15 +238,9 @@ void WatchTimeRecorder::FinalizeWatchTime(
} }
// Ensure values are cleared in case the reporter is reused. // Ensure values are cleared in case the reporter is reused.
if (!ukm_records_.empty()) { if (!ukm_records_.empty())
auto& last_record = ukm_records_.back(); ukm_records_.back().total_underflow_count += underflow_count_;
last_record.total_underflow_count += underflow_count_; underflow_count_ = 0;
last_record.total_completed_underflow_count += completed_underflow_count_;
last_record.total_underflow_duration += underflow_duration_;
}
underflow_count_ = completed_underflow_count_ = 0;
underflow_duration_ = base::TimeDelta();
watch_time_info_.clear(); watch_time_info_.clear();
} }
...@@ -304,15 +298,11 @@ void WatchTimeRecorder::UpdateSecondaryProperties( ...@@ -304,15 +298,11 @@ void WatchTimeRecorder::UpdateSecondaryProperties(
for (auto& kv : watch_time_info_) for (auto& kv : watch_time_info_)
last_record.aggregate_watch_time_info[kv.first] += kv.second; last_record.aggregate_watch_time_info[kv.first] += kv.second;
last_record.total_underflow_count += underflow_count_; last_record.total_underflow_count += underflow_count_;
last_record.total_completed_underflow_count += completed_underflow_count_;
last_record.total_underflow_duration += underflow_duration_;
// If we flushed any watch time or underflow counts which hadn't been // If we flushed any watch time or underflow counts which hadn't been
// finalized we'll need to ensure the eventual Finalize() correctly accounts // finalized we'll need to ensure the eventual Finalize() correctly accounts
// for those values at the time of the secondary property update. // for those values at the time of the secondary property update.
last_record_was_unfinalized = last_record_was_unfinalized = !watch_time_info_.empty() || underflow_count_;
!watch_time_info_.empty() || underflow_count_ ||
completed_underflow_count_ || !underflow_duration_.is_zero();
} }
ukm_records_.emplace_back(std::move(secondary_properties)); ukm_records_.emplace_back(std::move(secondary_properties));
...@@ -334,8 +324,6 @@ void WatchTimeRecorder::UpdateSecondaryProperties( ...@@ -334,8 +324,6 @@ void WatchTimeRecorder::UpdateSecondaryProperties(
if (last_record_was_unfinalized) { if (last_record_was_unfinalized) {
auto& last_record = ukm_records_.back(); auto& last_record = ukm_records_.back();
last_record.total_underflow_count = -underflow_count_; last_record.total_underflow_count = -underflow_count_;
last_record.total_completed_underflow_count = -completed_underflow_count_;
last_record.total_underflow_duration = -underflow_duration_;
for (auto& kv : watch_time_info_) for (auto& kv : watch_time_info_)
last_record.aggregate_watch_time_info[kv.first] = -kv.second; last_record.aggregate_watch_time_info[kv.first] = -kv.second;
} }
...@@ -350,15 +338,8 @@ void WatchTimeRecorder::OnDurationChanged(base::TimeDelta duration) { ...@@ -350,15 +338,8 @@ void WatchTimeRecorder::OnDurationChanged(base::TimeDelta duration) {
duration_ = duration; duration_ = duration;
} }
void WatchTimeRecorder::UpdateUnderflowCount(int32_t total_count) { void WatchTimeRecorder::UpdateUnderflowCount(int32_t count) {
underflow_count_ = total_count; underflow_count_ = count;
}
void WatchTimeRecorder::UpdateUnderflowDuration(
int32_t total_completed_count,
base::TimeDelta total_duration) {
completed_underflow_count_ = total_completed_count;
underflow_duration_ = total_duration;
} }
void WatchTimeRecorder::RecordUkmPlaybackData() { void WatchTimeRecorder::RecordUkmPlaybackData() {
...@@ -492,12 +473,6 @@ void WatchTimeRecorder::RecordUkmPlaybackData() { ...@@ -492,12 +473,6 @@ void WatchTimeRecorder::RecordUkmPlaybackData() {
builder.SetIsMSE(properties_->is_mse); builder.SetIsMSE(properties_->is_mse);
builder.SetLastPipelineStatus(pipeline_status_); builder.SetLastPipelineStatus(pipeline_status_);
builder.SetRebuffersCount(ukm_record.total_underflow_count); builder.SetRebuffersCount(ukm_record.total_underflow_count);
builder.SetCompletedRebuffersCount(
ukm_record.total_completed_underflow_count);
if (ukm_record.total_completed_underflow_count) {
builder.SetCompletedRebuffersDuration(
ukm_record.total_underflow_duration.InMilliseconds());
}
builder.SetVideoNaturalWidth( builder.SetVideoNaturalWidth(
ukm_record.secondary_properties->natural_size.width()); ukm_record.secondary_properties->natural_size.width());
builder.SetVideoNaturalHeight( builder.SetVideoNaturalHeight(
......
...@@ -38,9 +38,7 @@ class MEDIA_MOJO_EXPORT WatchTimeRecorder : public mojom::WatchTimeRecorder { ...@@ -38,9 +38,7 @@ class MEDIA_MOJO_EXPORT WatchTimeRecorder : public mojom::WatchTimeRecorder {
mojom::SecondaryPlaybackPropertiesPtr secondary_properties) override; mojom::SecondaryPlaybackPropertiesPtr secondary_properties) override;
void SetAutoplayInitiated(bool value) override; void SetAutoplayInitiated(bool value) override;
void OnDurationChanged(base::TimeDelta duration) override; void OnDurationChanged(base::TimeDelta duration) override;
void UpdateUnderflowCount(int32_t total_count) override; void UpdateUnderflowCount(int32_t count) override;
void UpdateUnderflowDuration(int32_t total_completed_count,
base::TimeDelta total_duration) override;
private: private:
// Records a UKM event based on |aggregate_watch_time_info_|; only recorded // Records a UKM event based on |aggregate_watch_time_info_|; only recorded
...@@ -91,10 +89,8 @@ class MEDIA_MOJO_EXPORT WatchTimeRecorder : public mojom::WatchTimeRecorder { ...@@ -91,10 +89,8 @@ class MEDIA_MOJO_EXPORT WatchTimeRecorder : public mojom::WatchTimeRecorder {
// Sum of all watch time data since the last complete finalize. // Sum of all watch time data since the last complete finalize.
WatchTimeInfo aggregate_watch_time_info; WatchTimeInfo aggregate_watch_time_info;
// Total underflow count and duration for this segment of UKM watch time. // Total underflow count for this segment of UKM watch time.
int total_underflow_count = 0; int total_underflow_count = 0;
int total_completed_underflow_count = 0;
base::TimeDelta total_underflow_duration;
}; };
// List of all watch time segments. A new entry is added for every secondary // List of all watch time segments. A new entry is added for every secondary
...@@ -102,9 +98,6 @@ class MEDIA_MOJO_EXPORT WatchTimeRecorder : public mojom::WatchTimeRecorder { ...@@ -102,9 +98,6 @@ class MEDIA_MOJO_EXPORT WatchTimeRecorder : public mojom::WatchTimeRecorder {
std::vector<WatchTimeUkmRecord> ukm_records_; std::vector<WatchTimeUkmRecord> ukm_records_;
int underflow_count_ = 0; int underflow_count_ = 0;
int completed_underflow_count_ = 0;
base::TimeDelta underflow_duration_;
PipelineStatus pipeline_status_ = PIPELINE_OK; PipelineStatus pipeline_status_ = PIPELINE_OK;
base::TimeDelta duration_ = kNoTimestamp; base::TimeDelta duration_ = kNoTimestamp;
......
...@@ -3712,18 +3712,6 @@ be describing additional metrics about the same event. ...@@ -3712,18 +3712,6 @@ be describing additional metrics about the same event.
activation on the page or without a user initiated same-domain navigation. activation on the page or without a user initiated same-domain navigation.
</summary> </summary>
</metric> </metric>
<metric name="CompletedRebuffersCount">
<summary>
Integer count of the number of times a previous rebuffer succeeded and
playback continued.
</summary>
</metric>
<metric name="CompletedRebuffersDuration">
<summary>
Sum in milliseconds of all completed rebuffering events. Only reported if
a rebuffering completion occurred.
</summary>
</metric>
<metric name="Duration"> <metric name="Duration">
<summary> <summary>
Duration in milliseconds, rounded to the most significant digit, of the Duration in milliseconds, rounded to the most significant digit, of the
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment