1 // Copyright 2014 The Chromium Authors
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
5 #include "cc/metrics/compositor_timing_history.h"
14 #include "base/memory/ptr_util.h"
15 #include "base/metrics/field_trial_params.h"
16 #include "base/metrics/histogram_macros.h"
17 #include "base/notreached.h"
18 #include "base/trace_event/trace_event.h"
19 #include "cc/base/features.h"
20 #include "cc/debug/rendering_stats_instrumentation.h"
24 class CompositorTimingHistory::UMAReporter {
26 virtual ~UMAReporter() = default;
28 // Throughput measurements
29 virtual void AddDrawInterval(base::TimeDelta interval) = 0;
31 // Latency measurements
32 virtual void AddBeginImplFrameLatency(base::TimeDelta delta) = 0;
33 virtual void AddDrawDuration(base::TimeDelta duration) = 0;
35 // crbug.com/758439: the following functions are used to report timing in
36 // certain conditions targeting blink / compositor animations.
37 // Only the renderer would get the meaningful data.
38 virtual void AddDrawIntervalWithCustomPropertyAnimations(
39 base::TimeDelta duration) = 0;
41 virtual void AddImplFrameDeadlineType(
42 CompositorTimingHistory::DeadlineMode deadline_mode) = 0;
47 // Used to generate a unique id when emitting the "Long Draw Interval" trace
49 int g_num_long_draw_intervals = 0;
51 // The threshold to emit a trace event is the 99th percentile
52 // of the histogram on Windows Stable as of Feb 26th, 2020.
53 constexpr base::TimeDelta kDrawIntervalTraceThreshold =
54 base::Microseconds(34478);
56 // Using the 90th percentile will disable latency recovery
57 // if we are missing the deadline approximately ~6 times per
59 // TODO(brianderson): Fine tune the percentiles below.
60 const size_t kDurationHistorySize = 60;
61 const double kBeginMainFrameQueueDurationEstimationPercentile = 90.0;
62 const double kBeginMainFrameQueueDurationCriticalEstimationPercentile = 90.0;
63 const double kBeginMainFrameQueueDurationNotCriticalEstimationPercentile = 90.0;
64 const double kBeginMainFrameStartToReadyToCommitEstimationPercentile = 90.0;
65 const double kCommitEstimatePercentile = 90.0;
66 const double kCommitToReadyToActivateEstimationPercentile = 90.0;
67 const double kPrepareTilesEstimationPercentile = 90.0;
68 const double kActivateEstimationPercentile = 90.0;
69 const double kDrawEstimationPercentile = 90.0;
71 double BeginMainFrameStartToReadyToCommitCriticalPercentile() {
72 if (base::FeatureList::IsEnabled(
73 features::kDurationEstimatesInCompositorTimingHistory)) {
74 double result = base::GetFieldTrialParamByFeatureAsDouble(
75 features::kDurationEstimatesInCompositorTimingHistory,
76 "BMFStartCritialPercentile", -1.0);
83 double BeginMainFrameStartToReadyToCommitNonCriticalPercentile() {
84 if (base::FeatureList::IsEnabled(
85 features::kDurationEstimatesInCompositorTimingHistory)) {
86 double result = base::GetFieldTrialParamByFeatureAsDouble(
87 features::kDurationEstimatesInCompositorTimingHistory,
88 "BMFStartNonCritialPercentile", -1.0);
95 double BeginMainFrameQueueToActivateCriticalPercentile() {
96 if (base::FeatureList::IsEnabled(
97 features::kDurationEstimatesInCompositorTimingHistory)) {
98 double result = base::GetFieldTrialParamByFeatureAsDouble(
99 features::kDurationEstimatesInCompositorTimingHistory,
100 "BMFQueueCritialPercentile", -1.0);
107 // This macro is deprecated since its bucket count uses too much bandwidth.
108 // It also has sub-optimal range and bucket distribution.
109 // TODO(brianderson): Delete this macro and associated UMAs once there is
110 // sufficient overlap with the re-bucketed UMAs.
111 #define UMA_HISTOGRAM_CUSTOM_TIMES_MICROS(name, sample) \
112 UMA_HISTOGRAM_CUSTOM_COUNTS(name, sample.InMicroseconds(), \
113 kUmaDurationMinMicros, kUmaDurationMaxMicros, \
114 kUmaDurationBucketCount);
116 // ~90 VSync aligned UMA buckets.
117 const int kUMAVSyncBuckets[] = {
118 // Powers of two from 0 to 2048 us @ 50% precision
131 // Every 8 Hz from 256 Hz to 128 Hz @ 3-6% precision
148 // Every 4 Hz from 128 Hz to 64 Hz @ 3-6% precision
165 // Every 2 Hz from 64 Hz to 32 Hz @ 3-6% precision
182 // Every 1 Hz from 32 Hz to 1 Hz @ 3-33% precision
214 // Powers of two from 1s to 32s @ 50% precision
223 // ~50 UMA buckets with high precision from ~100 us to 1s.
224 const int kUMADurationBuckets[] = {
225 // Powers of 2 from 1 us to 64 us @ 50% precision.
233 // 1.25^20, 1.25^21, ..., 1.25^62 @ 20% precision.
277 // Powers of 2 from 2s to 32s @ 50% precision.
285 #define UMA_HISTOGRAM_CUSTOM_TIMES_VSYNC_ALIGNED(name, sample) \
287 UMA_HISTOGRAM_CUSTOM_ENUMERATION( \
288 name "2", sample.InMicroseconds(), \
289 std::vector<int>(kUMAVSyncBuckets, \
290 kUMAVSyncBuckets + std::size(kUMAVSyncBuckets))); \
293 #define UMA_HISTOGRAM_CUSTOM_TIMES_DURATION_SUFFIX(name, suffix, sample) \
295 UMA_HISTOGRAM_CUSTOM_ENUMERATION( \
296 name "2" suffix, sample.InMicroseconds(), \
298 kUMADurationBuckets, \
299 kUMADurationBuckets + std::size(kUMADurationBuckets))); \
302 #define UMA_HISTOGRAM_CUSTOM_TIMES_DURATION(name, sample) \
303 UMA_HISTOGRAM_CUSTOM_TIMES_DURATION_SUFFIX(name, "", sample)
305 #define UMA_HISTOGRAM_READY_TO_ACTIVATE(name, sample, priority) \
307 UMA_HISTOGRAM_CUSTOM_TIMES_DURATION(name, sample); \
308 switch (priority) { \
309 case SAME_PRIORITY_FOR_BOTH_TREES: \
310 UMA_HISTOGRAM_CUSTOM_TIMES_DURATION_SUFFIX(name, ".Same", sample); \
312 case SMOOTHNESS_TAKES_PRIORITY: \
313 UMA_HISTOGRAM_CUSTOM_TIMES_DURATION_SUFFIX(name, ".Smoothness", \
316 case NEW_CONTENT_TAKES_PRIORITY: \
317 UMA_HISTOGRAM_CUSTOM_TIMES_DURATION_SUFFIX(name, ".NewContent", \
323 class RendererUMAReporter : public CompositorTimingHistory::UMAReporter {
325 ~RendererUMAReporter() override = default;
327 void AddDrawInterval(base::TimeDelta interval) override {
328 UMA_HISTOGRAM_CUSTOM_TIMES_VSYNC_ALIGNED("Scheduling.Renderer.DrawInterval",
332 void AddDrawIntervalWithCustomPropertyAnimations(
333 base::TimeDelta interval) override {
334 UMA_HISTOGRAM_CUSTOM_TIMES_VSYNC_ALIGNED(
335 "Scheduling.Renderer.DrawIntervalWithCustomPropertyAnimations",
339 void AddBeginImplFrameLatency(base::TimeDelta delta) override {
340 UMA_HISTOGRAM_CUSTOM_TIMES_DURATION(
341 "Scheduling.Renderer.BeginImplFrameLatency", delta);
344 void AddDrawDuration(base::TimeDelta duration) override {
345 UMA_HISTOGRAM_CUSTOM_TIMES_DURATION("Scheduling.Renderer.DrawDuration",
349 void AddImplFrameDeadlineType(
350 CompositorTimingHistory::DeadlineMode deadline_mode) override {
351 UMA_HISTOGRAM_ENUMERATION("Scheduling.Renderer.DeadlineMode",
356 class BrowserUMAReporter : public CompositorTimingHistory::UMAReporter {
358 ~BrowserUMAReporter() override = default;
360 // DrawInterval is not meaningful to measure on browser side because
361 // browser rendering fps is not at 60.
362 void AddDrawInterval(base::TimeDelta interval) override {}
364 void AddDrawIntervalWithCustomPropertyAnimations(
365 base::TimeDelta interval) override {}
367 void AddBeginImplFrameLatency(base::TimeDelta delta) override {
368 UMA_HISTOGRAM_CUSTOM_TIMES_DURATION(
369 "Scheduling.Browser.BeginImplFrameLatency", delta);
372 void AddDrawDuration(base::TimeDelta duration) override {
373 UMA_HISTOGRAM_CUSTOM_TIMES_DURATION("Scheduling.Browser.DrawDuration",
377 void AddImplFrameDeadlineType(
378 CompositorTimingHistory::DeadlineMode deadline_mode) override {
379 // The browser compositor scheduler is synchronous and only has None (or
380 // Blocked as edges cases) for deadline mode.
384 class NullUMAReporter : public CompositorTimingHistory::UMAReporter {
386 ~NullUMAReporter() override = default;
387 void AddDrawInterval(base::TimeDelta interval) override {}
388 void AddDrawIntervalWithCustomPropertyAnimations(
389 base::TimeDelta inverval) override {}
390 void AddBeginImplFrameLatency(base::TimeDelta delta) override {}
391 void AddDrawDuration(base::TimeDelta duration) override {}
392 void AddImplFrameDeadlineType(
393 CompositorTimingHistory::DeadlineMode deadline_mode) override {}
398 CompositorTimingHistory::CompositorTimingHistory(
399 bool using_synchronous_renderer_compositor,
400 UMACategory uma_category,
401 RenderingStatsInstrumentation* rendering_stats_instrumentation)
402 : using_synchronous_renderer_compositor_(
403 using_synchronous_renderer_compositor),
405 compositor_drawing_continuously_(false),
406 begin_main_frame_queue_duration_history_(kDurationHistorySize),
407 begin_main_frame_queue_duration_critical_history_(kDurationHistorySize),
408 begin_main_frame_queue_duration_not_critical_history_(
409 kDurationHistorySize),
410 begin_main_frame_start_to_ready_to_commit_duration_history_(
411 kDurationHistorySize),
412 commit_duration_history_(kDurationHistorySize),
413 commit_to_ready_to_activate_duration_history_(kDurationHistorySize),
414 prepare_tiles_duration_history_(kDurationHistorySize),
415 activate_duration_history_(kDurationHistorySize),
416 draw_duration_history_(kDurationHistorySize),
417 duration_estimates_enabled_(base::FeatureList::IsEnabled(
418 features::kDurationEstimatesInCompositorTimingHistory)),
419 bmf_start_to_ready_to_commit_critical_history_(kDurationHistorySize),
420 bmf_start_to_ready_to_commit_critical_percentile_(
421 BeginMainFrameStartToReadyToCommitCriticalPercentile()),
422 bmf_start_to_ready_to_commit_not_critical_history_(kDurationHistorySize),
423 bmf_start_to_ready_to_commit_not_critical_percentile_(
424 BeginMainFrameStartToReadyToCommitNonCriticalPercentile()),
425 bmf_queue_to_activate_critical_history_(kDurationHistorySize),
426 bmf_queue_to_activate_critical_percentile_(
427 BeginMainFrameQueueToActivateCriticalPercentile()),
428 uma_reporter_(CreateUMAReporter(uma_category)),
429 rendering_stats_instrumentation_(rendering_stats_instrumentation) {}
431 CompositorTimingHistory::~CompositorTimingHistory() = default;
433 std::unique_ptr<CompositorTimingHistory::UMAReporter>
434 CompositorTimingHistory::CreateUMAReporter(UMACategory category) {
437 return base::WrapUnique(new RendererUMAReporter);
439 return base::WrapUnique(new BrowserUMAReporter);
441 return base::WrapUnique(new NullUMAReporter);
444 return base::WrapUnique<CompositorTimingHistory::UMAReporter>(nullptr);
447 base::TimeTicks CompositorTimingHistory::Now() const {
448 return base::TimeTicks::Now();
451 void CompositorTimingHistory::SetRecordingEnabled(bool enabled) {
455 void CompositorTimingHistory::SetCompositorDrawingContinuously(bool active) {
456 if (active == compositor_drawing_continuously_)
458 draw_end_time_prev_ = base::TimeTicks();
459 compositor_drawing_continuously_ = active;
463 CompositorTimingHistory::BeginMainFrameQueueDurationCriticalEstimate() const {
464 base::TimeDelta all = begin_main_frame_queue_duration_history_.Percentile(
465 kBeginMainFrameQueueDurationEstimationPercentile);
466 base::TimeDelta critical =
467 begin_main_frame_queue_duration_critical_history_.Percentile(
468 kBeginMainFrameQueueDurationCriticalEstimationPercentile);
469 // Return the min since critical BeginMainFrames are likely fast if
470 // the non critical ones are.
471 return std::min(critical, all);
475 CompositorTimingHistory::BeginMainFrameQueueDurationNotCriticalEstimate()
477 base::TimeDelta all = begin_main_frame_queue_duration_history_.Percentile(
478 kBeginMainFrameQueueDurationEstimationPercentile);
479 base::TimeDelta not_critical =
480 begin_main_frame_queue_duration_not_critical_history_.Percentile(
481 kBeginMainFrameQueueDurationNotCriticalEstimationPercentile);
482 // Return the max since, non critical BeginMainFrames are likely slow if
483 // the critical ones are.
484 return std::max(not_critical, all);
488 CompositorTimingHistory::BeginMainFrameStartToReadyToCommitDurationEstimate()
490 return begin_main_frame_start_to_ready_to_commit_duration_history_.Percentile(
491 kBeginMainFrameStartToReadyToCommitEstimationPercentile);
494 base::TimeDelta CompositorTimingHistory::CommitDurationEstimate() const {
495 return commit_duration_history_.Percentile(kCommitEstimatePercentile);
499 CompositorTimingHistory::CommitToReadyToActivateDurationEstimate() const {
500 return commit_to_ready_to_activate_duration_history_.Percentile(
501 kCommitToReadyToActivateEstimationPercentile);
504 base::TimeDelta CompositorTimingHistory::PrepareTilesDurationEstimate() const {
505 return prepare_tiles_duration_history_.Percentile(
506 kPrepareTilesEstimationPercentile);
509 base::TimeDelta CompositorTimingHistory::ActivateDurationEstimate() const {
510 return activate_duration_history_.Percentile(kActivateEstimationPercentile);
513 base::TimeDelta CompositorTimingHistory::DrawDurationEstimate() const {
514 return draw_duration_history_.Percentile(kDrawEstimationPercentile);
518 CompositorTimingHistory::BeginMainFrameStartToReadyToCommitCriticalEstimate()
520 if (duration_estimates_enabled_) {
521 return bmf_start_to_ready_to_commit_critical_history_.Percentile(
522 bmf_start_to_ready_to_commit_critical_percentile_);
524 return BeginMainFrameStartToReadyToCommitDurationEstimate() +
525 BeginMainFrameQueueDurationCriticalEstimate();
529 CompositorTimingHistory::BeginMainFrameStartToReadyToCommitNotCriticalEstimate()
531 if (duration_estimates_enabled_) {
532 return bmf_start_to_ready_to_commit_not_critical_history_.Percentile(
533 bmf_start_to_ready_to_commit_not_critical_percentile_);
535 return BeginMainFrameStartToReadyToCommitDurationEstimate() +
536 BeginMainFrameQueueDurationNotCriticalEstimate();
540 CompositorTimingHistory::BeginMainFrameQueueToActivateCriticalEstimate() const {
541 if (duration_estimates_enabled_) {
542 return bmf_queue_to_activate_critical_history_.Percentile(
543 bmf_queue_to_activate_critical_percentile_);
545 return BeginMainFrameStartToReadyToCommitDurationEstimate() +
546 CommitDurationEstimate() + CommitToReadyToActivateDurationEstimate() +
547 ActivateDurationEstimate() +
548 BeginMainFrameQueueDurationCriticalEstimate();
551 void CompositorTimingHistory::WillBeginImplFrame(
552 const viz::BeginFrameArgs& args,
553 base::TimeTicks now) {
554 viz::BeginFrameArgs::BeginFrameArgsType frame_type = args.type;
555 base::TimeTicks frame_time = args.frame_time;
557 if (frame_type == viz::BeginFrameArgs::NORMAL)
558 uma_reporter_->AddBeginImplFrameLatency(now - frame_time);
561 void CompositorTimingHistory::WillFinishImplFrame(bool needs_redraw) {
563 SetCompositorDrawingContinuously(false);
566 void CompositorTimingHistory::BeginImplFrameNotExpectedSoon() {
567 SetCompositorDrawingContinuously(false);
570 void CompositorTimingHistory::WillBeginMainFrame(
571 const viz::BeginFrameArgs& args) {
572 DCHECK_EQ(base::TimeTicks(), begin_main_frame_sent_time_);
574 begin_main_frame_on_critical_path_ = args.on_critical_path;
575 begin_main_frame_sent_time_ = Now();
578 void CompositorTimingHistory::BeginMainFrameStarted(
579 base::TimeTicks main_thread_start_time) {
580 DCHECK_NE(base::TimeTicks(), begin_main_frame_sent_time_);
581 DCHECK_EQ(base::TimeTicks(), begin_main_frame_start_time_);
582 begin_main_frame_start_time_ = main_thread_start_time;
585 void CompositorTimingHistory::BeginMainFrameAborted() {
586 base::TimeTicks begin_main_frame_end_time = Now();
587 DidBeginMainFrame(begin_main_frame_end_time);
590 void CompositorTimingHistory::NotifyReadyToCommit() {
591 DCHECK_NE(begin_main_frame_start_time_, base::TimeTicks());
592 DCHECK_EQ(ready_to_commit_time_, base::TimeTicks());
593 ready_to_commit_time_ = Now();
594 pending_commit_on_critical_path_ = begin_main_frame_on_critical_path_;
595 if (enabled_ && duration_estimates_enabled_) {
596 bmf_start_to_ready_to_activate_duration_ =
597 ready_to_commit_time_ - begin_main_frame_start_time_;
599 base::TimeDelta bmf_duration =
600 ready_to_commit_time_ - begin_main_frame_start_time_;
601 DidBeginMainFrame(ready_to_commit_time_);
602 begin_main_frame_start_to_ready_to_commit_duration_history_.InsertSample(
604 if (enabled_ && duration_estimates_enabled_) {
605 if (pending_commit_on_critical_path_) {
606 bmf_start_to_ready_to_commit_critical_history_.InsertSample(
607 bmf_duration + begin_main_frame_queue_duration_);
609 bmf_start_to_ready_to_commit_not_critical_history_.InsertSample(
610 bmf_duration + begin_main_frame_queue_duration_);
615 void CompositorTimingHistory::WillCommit() {
616 DCHECK_NE(ready_to_commit_time_, base::TimeTicks());
617 commit_start_time_ = Now();
618 if (enabled_ && duration_estimates_enabled_) {
619 DCHECK_NE(ready_to_commit_time_, base::TimeTicks());
620 bmf_start_to_ready_to_activate_duration_ +=
621 commit_start_time_ - ready_to_commit_time_;
623 ready_to_commit_time_ = base::TimeTicks();
626 void CompositorTimingHistory::DidCommit() {
627 DCHECK_EQ(pending_tree_creation_time_, base::TimeTicks());
628 DCHECK_NE(commit_start_time_, base::TimeTicks());
630 base::TimeTicks commit_end_time = Now();
631 if (enabled_ && duration_estimates_enabled_) {
632 pending_tree_on_critical_path_ = pending_commit_on_critical_path_;
633 bmf_start_to_ready_to_activate_duration_ +=
634 (commit_end_time - commit_start_time_);
636 commit_duration_history_.InsertSample(commit_end_time - commit_start_time_);
638 pending_tree_is_impl_side_ = false;
639 pending_tree_creation_time_ = commit_end_time;
640 if (enabled_ && duration_estimates_enabled_)
641 pending_tree_bmf_queue_duration_ = begin_main_frame_queue_duration_;
644 void CompositorTimingHistory::DidBeginMainFrame(
645 base::TimeTicks begin_main_frame_end_time) {
646 DCHECK_NE(base::TimeTicks(), begin_main_frame_sent_time_);
648 // If the BeginMainFrame start time isn't known, assume it was immediate
649 // for scheduling purposes, but don't report it for UMA to avoid skewing
651 // TODO(szager): Can this be true? begin_main_frame_start_time_ should be
652 // unconditionally assigned in BeginMainFrameStarted().
653 if (begin_main_frame_start_time_.is_null())
654 begin_main_frame_start_time_ = begin_main_frame_sent_time_;
656 base::TimeDelta bmf_sent_to_commit_duration =
657 begin_main_frame_end_time - begin_main_frame_sent_time_;
658 base::TimeDelta bmf_queue_duration =
659 begin_main_frame_start_time_ - begin_main_frame_sent_time_;
661 rendering_stats_instrumentation_->AddBeginMainFrameToCommitDuration(
662 bmf_sent_to_commit_duration);
665 begin_main_frame_queue_duration_history_.InsertSample(bmf_queue_duration);
666 if (begin_main_frame_on_critical_path_) {
667 begin_main_frame_queue_duration_critical_history_.InsertSample(
670 begin_main_frame_queue_duration_not_critical_history_.InsertSample(
673 if (duration_estimates_enabled_)
674 begin_main_frame_queue_duration_ = bmf_queue_duration;
677 begin_main_frame_sent_time_ = base::TimeTicks();
678 begin_main_frame_start_time_ = base::TimeTicks();
679 begin_main_frame_on_critical_path_ = false;
682 void CompositorTimingHistory::WillInvalidateOnImplSide() {
683 DCHECK(!pending_tree_is_impl_side_);
684 DCHECK_EQ(pending_tree_creation_time_, base::TimeTicks());
686 pending_tree_is_impl_side_ = true;
687 pending_tree_on_critical_path_ = false;
688 pending_tree_bmf_queue_duration_ = base::TimeDelta();
689 pending_tree_creation_time_ = base::TimeTicks::Now();
692 void CompositorTimingHistory::WillPrepareTiles() {
693 DCHECK_EQ(base::TimeTicks(), prepare_tiles_start_time_);
694 prepare_tiles_start_time_ = Now();
697 void CompositorTimingHistory::DidPrepareTiles() {
698 DCHECK_NE(base::TimeTicks(), prepare_tiles_start_time_);
700 base::TimeDelta prepare_tiles_duration = Now() - prepare_tiles_start_time_;
702 prepare_tiles_duration_history_.InsertSample(prepare_tiles_duration);
704 prepare_tiles_start_time_ = base::TimeTicks();
707 void CompositorTimingHistory::ReadyToActivate() {
708 DCHECK_NE(pending_tree_creation_time_, base::TimeTicks());
709 DCHECK_EQ(pending_tree_ready_to_activate_time_, base::TimeTicks());
711 pending_tree_ready_to_activate_time_ = Now();
712 if (!pending_tree_is_impl_side_) {
713 base::TimeDelta time_since_commit =
714 pending_tree_ready_to_activate_time_ - pending_tree_creation_time_;
716 // Before adding the new data point to the timing history, see what we would
717 // have predicted for this frame. This allows us to keep track of the
718 // accuracy of our predictions.
720 base::TimeDelta commit_to_ready_to_activate_estimate =
721 CommitToReadyToActivateDurationEstimate();
722 rendering_stats_instrumentation_->AddCommitToActivateDuration(
723 time_since_commit, commit_to_ready_to_activate_estimate);
726 commit_to_ready_to_activate_duration_history_.InsertSample(
728 if (duration_estimates_enabled_)
729 bmf_start_to_ready_to_activate_duration_ += time_since_commit;
734 void CompositorTimingHistory::WillActivate() {
735 DCHECK_EQ(base::TimeTicks(), activate_start_time_);
737 activate_start_time_ = Now();
739 pending_tree_is_impl_side_ = false;
740 pending_tree_creation_time_ = base::TimeTicks();
743 void CompositorTimingHistory::DidActivate() {
744 DCHECK_NE(base::TimeTicks(), activate_start_time_);
745 base::TimeTicks activate_end_time = Now();
746 base::TimeDelta activate_duration = activate_end_time - activate_start_time_;
749 activate_duration_history_.InsertSample(activate_duration);
751 if (duration_estimates_enabled_) {
752 if (pending_tree_on_critical_path_) {
753 base::TimeDelta time_since_ready_to_activate =
754 activate_end_time - pending_tree_ready_to_activate_time_;
755 DCHECK_NE(pending_tree_bmf_queue_duration_, base::TimeDelta());
756 bmf_queue_to_activate_critical_history_.InsertSample(
757 bmf_start_to_ready_to_activate_duration_ +
758 time_since_ready_to_activate + pending_tree_bmf_queue_duration_);
760 bmf_start_to_ready_to_activate_duration_ = base::TimeDelta();
761 pending_tree_on_critical_path_ = false;
765 pending_tree_ready_to_activate_time_ = base::TimeTicks();
766 activate_start_time_ = base::TimeTicks();
769 void CompositorTimingHistory::WillDraw() {
770 DCHECK_EQ(base::TimeTicks(), draw_start_time_);
771 draw_start_time_ = Now();
774 void CompositorTimingHistory::DidDraw(bool used_new_active_tree,
775 bool has_custom_property_animations) {
776 DCHECK_NE(base::TimeTicks(), draw_start_time_);
777 base::TimeTicks draw_end_time = Now();
778 base::TimeDelta draw_duration = draw_end_time - draw_start_time_;
780 // Before adding the new data point to the timing history, see what we would
781 // have predicted for this frame. This allows us to keep track of the accuracy
782 // of our predictions.
783 base::TimeDelta draw_estimate = DrawDurationEstimate();
784 rendering_stats_instrumentation_->AddDrawDuration(draw_duration,
787 uma_reporter_->AddDrawDuration(draw_duration);
790 draw_duration_history_.InsertSample(draw_duration);
793 SetCompositorDrawingContinuously(true);
794 if (!draw_end_time_prev_.is_null()) {
795 base::TimeDelta draw_interval = draw_end_time - draw_end_time_prev_;
796 uma_reporter_->AddDrawInterval(draw_interval);
797 // Emit a trace event to highlight a long time lapse between the draw times
798 // of back-to-back BeginImplFrames.
799 if (draw_interval > kDrawIntervalTraceThreshold) {
800 TRACE_EVENT_NESTABLE_ASYNC_BEGIN_WITH_TIMESTAMP0(
801 "latency", "Long Draw Interval",
802 TRACE_ID_WITH_SCOPE("Long Draw Interval", g_num_long_draw_intervals),
804 TRACE_EVENT_NESTABLE_ASYNC_END_WITH_TIMESTAMP0(
805 "latency", "Long Draw Interval",
806 TRACE_ID_WITH_SCOPE("Long Draw Interval", g_num_long_draw_intervals),
808 g_num_long_draw_intervals++;
810 if (has_custom_property_animations &&
811 previous_frame_had_custom_property_animations_)
812 uma_reporter_->AddDrawIntervalWithCustomPropertyAnimations(draw_interval);
814 previous_frame_had_custom_property_animations_ =
815 has_custom_property_animations;
816 draw_end_time_prev_ = draw_end_time;
818 if (used_new_active_tree)
819 new_active_tree_draw_end_time_prev_ = draw_end_time;
820 draw_start_time_ = base::TimeTicks();
823 void CompositorTimingHistory::RecordDeadlineMode(DeadlineMode deadline_mode) {
825 uma_reporter_->AddImplFrameDeadlineType(deadline_mode);
828 void CompositorTimingHistory::ClearHistory() {
829 TRACE_EVENT0("cc,benchmark", "CompositorTimingHistory::ClearHistory");
831 begin_main_frame_queue_duration_history_.Clear();
832 begin_main_frame_queue_duration_critical_history_.Clear();
833 begin_main_frame_queue_duration_not_critical_history_.Clear();
834 begin_main_frame_start_to_ready_to_commit_duration_history_.Clear();
835 commit_duration_history_.Clear();
836 commit_to_ready_to_activate_duration_history_.Clear();
837 prepare_tiles_duration_history_.Clear();
838 activate_duration_history_.Clear();
839 draw_duration_history_.Clear();
840 bmf_start_to_ready_to_commit_critical_history_.Clear();
841 bmf_start_to_ready_to_commit_not_critical_history_.Clear();
842 bmf_queue_to_activate_critical_history_.Clear();
845 size_t CompositorTimingHistory::CommitDurationSampleCountForTesting() const {
846 return commit_duration_history_.sample_count();