Commit 29c35165 authored by Hongbo Song's avatar Hongbo Song Committed by Commit Bot

Add event processing time UKM for the first input.

UKM privacy review: https://docs.google.com/document/d/1ARnhXk3M_hbsRWYjGRf3vg0XWoJkW1_rz0GfrQwdu5Q/edit?usp=sharing

Change-Id: I5529743c3961f28564bf85502391e6c6c592772b
Bug: 1093402
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2239968
Commit-Queue: Hongbo Song <hbsong@google.com>
Reviewed-by: default avatarRobert Kaplow <rkaplow@chromium.org>
Reviewed-by: default avatarAlex Gough <ajgo@chromium.org>
Reviewed-by: default avatarSteve Kobes <skobes@chromium.org>
Reviewed-by: default avatarCharlie Harrison <csharrison@chromium.org>
Cr-Commit-Position: refs/heads/master@{#777521}
parent d61b7cfd
......@@ -440,6 +440,12 @@ void UkmPageLoadMetricsObserver::RecordTimingMetrics(
builder.SetInteractiveTiming_LongestInputTimestamp4(
longest_input_timestamp.InMilliseconds());
}
if (timing.interactive_timing->first_input_processing_time) {
base::TimeDelta first_input_processing_time =
timing.interactive_timing->first_input_processing_time.value();
builder.SetInteractiveTiming_FirstInputProcessingTimes(
first_input_processing_time.InMilliseconds());
}
builder.SetCpuTime(total_foreground_cpu_time_.InMilliseconds());
// Use a bucket spacing factor of 1.3 for bytes.
......
......@@ -1054,7 +1054,8 @@ TEST_F(UkmPageLoadMetricsObserverTest,
}
}
TEST_F(UkmPageLoadMetricsObserverTest, FirstInputDelayAndTimestamp) {
TEST_F(UkmPageLoadMetricsObserverTest,
FirstInputDelayAndTimestampAndProcessingTime) {
page_load_metrics::mojom::PageLoadTiming timing;
page_load_metrics::InitPageLoadTimingForTest(&timing);
timing.navigation_start = base::Time::FromDoubleT(1);
......@@ -1062,6 +1063,8 @@ TEST_F(UkmPageLoadMetricsObserverTest, FirstInputDelayAndTimestamp) {
base::TimeDelta::FromMilliseconds(50);
timing.interactive_timing->first_input_timestamp =
base::TimeDelta::FromMilliseconds(712);
timing.interactive_timing->first_input_processing_time =
base::TimeDelta::FromMilliseconds(25);
PopulateRequiredTimingFields(&timing);
NavigateAndCommit(GURL(kTestUrl1));
......@@ -1083,6 +1086,9 @@ TEST_F(UkmPageLoadMetricsObserverTest, FirstInputDelayAndTimestamp) {
tester()->test_ukm_recorder().ExpectEntryMetric(
kv.second.get(), PageLoad::kInteractiveTiming_FirstInputTimestamp4Name,
712);
tester()->test_ukm_recorder().ExpectEntryMetric(
kv.second.get(),
PageLoad::kInteractiveTiming_FirstInputProcessingTimesName, 25);
}
}
......
......@@ -359,6 +359,10 @@ class PageLoadTimingMerger {
// associated first input delay.
target_interactive_timing->first_input_delay =
new_interactive_timing.first_input_delay;
if (new_interactive_timing.first_input_processing_time.has_value()) {
target_interactive_timing->first_input_processing_time =
new_interactive_timing.first_input_processing_time;
}
}
if (new_interactive_timing.longest_input_delay.has_value()) {
......
......@@ -108,6 +108,9 @@ struct InteractiveTiming {
// The timestamp of the event whose delay is reported as longest_input_delay.
mojo_base.mojom.TimeDelta? longest_input_timestamp;
// The duration of event handlers processing the first input event.
mojo_base.mojom.TimeDelta? first_input_processing_time;
};
// PageLoadTiming contains timing metrics associated with a page load. Many of
......
......@@ -20,7 +20,8 @@ bool IsEmpty(const page_load_metrics::mojom::DocumentTiming& timing) {
bool IsEmpty(const page_load_metrics::mojom::InteractiveTiming& timing) {
return !timing.first_input_delay && !timing.first_input_timestamp &&
!timing.longest_input_delay && !timing.longest_input_timestamp;
!timing.longest_input_delay && !timing.longest_input_timestamp &&
!timing.first_input_processing_time;
}
bool IsEmpty(const page_load_metrics::mojom::InputTiming& timing) {
......
......@@ -425,6 +425,10 @@ MetricsRenderFrameObserver::Timing MetricsRenderFrameObserver::GetTiming()
timing->interactive_timing->longest_input_timestamp =
ClampDelta((*perf.LongestInputTimestamp()).InSecondsF(), start);
}
if (perf.FirstInputProcessingTime().has_value()) {
timing->interactive_timing->first_input_processing_time =
*perf.FirstInputProcessingTime();
}
if (perf.ResponseStart() > 0.0)
timing->response_start = ClampDelta(perf.ResponseStart(), start);
if (perf.DomContentLoadedEventStart() > 0.0) {
......
......@@ -112,6 +112,7 @@ class WebPerformance {
BLINK_EXPORT base::Optional<base::TimeDelta> FirstInputTimestamp() const;
BLINK_EXPORT base::Optional<base::TimeDelta> LongestInputDelay() const;
BLINK_EXPORT base::Optional<base::TimeDelta> LongestInputTimestamp() const;
BLINK_EXPORT base::Optional<base::TimeDelta> FirstInputProcessingTime() const;
BLINK_EXPORT double ParseStart() const;
BLINK_EXPORT double ParseStop() const;
BLINK_EXPORT double ParseBlockedOnScriptLoadDuration() const;
......
......@@ -227,6 +227,11 @@ base::Optional<base::TimeDelta> WebPerformance::LongestInputTimestamp() const {
return private_->timing()->LongestInputTimestamp();
}
base::Optional<base::TimeDelta> WebPerformance::FirstInputProcessingTime()
const {
return private_->timing()->FirstInputProcessingTime();
}
double WebPerformance::ParseStart() const {
return MillisecondsToSeconds(private_->timing()->ParseStart());
}
......
......@@ -154,6 +154,11 @@ base::Optional<base::TimeTicks> InteractiveDetector::GetLongestInputTimestamp()
return page_event_times_.longest_input_timestamp;
}
base::Optional<base::TimeDelta>
InteractiveDetector::GetFirstInputProcessingTime() const {
return page_event_times_.first_input_processing_time;
}
bool InteractiveDetector::PageWasBackgroundedSinceEvent(
base::TimeTicks event_time) {
DCHECK(GetSupplementable());
......@@ -646,6 +651,13 @@ void InteractiveDetector::RecordInputEventTimingUKM(
.SetInteractiveTiming_InputDelay(input_delay.InMilliseconds())
.SetInteractiveTiming_ProcessingTime(processing_time.InMilliseconds())
.Record(GetUkmRecorder());
if (!page_event_times_.first_input_processing_time) {
page_event_times_.first_input_processing_time = processing_time;
if (GetSupplementable()->Loader()) {
GetSupplementable()->Loader()->DidChangePerformanceTiming();
}
}
}
} // namespace blink
......@@ -100,6 +100,9 @@ class CORE_EXPORT InteractiveDetector
// GetLongestInputDelay().
base::Optional<base::TimeTicks> GetLongestInputTimestamp() const;
// The duration of event handlers processing the first input event.
base::Optional<base::TimeDelta> GetFirstInputProcessingTime() const;
// Process an input event, updating first_input_delay and
// first_input_timestamp if needed.
void HandleForInputDelay(const Event&,
......@@ -147,6 +150,7 @@ class CORE_EXPORT InteractiveDetector
base::Optional<base::TimeDelta> longest_input_delay;
base::Optional<base::TimeTicks> first_input_timestamp;
base::Optional<base::TimeTicks> longest_input_timestamp;
base::Optional<base::TimeDelta> first_input_processing_time;
} page_event_times_;
struct VisibilityChangeEvent {
......
......@@ -21,6 +21,7 @@
namespace blink {
using InputEvent = ukm::builders::InputEvent;
using PageLoad = ukm::builders::PageLoad;
class NetworkActivityCheckerForTest
: public InteractiveDetector::NetworkActivityChecker {
......@@ -589,6 +590,9 @@ TEST_F(InteractiveDetectorTest, RecordInputDelayUKM) {
test_ukm_recorder.ExpectEntryMetric(
entry, InputEvent::kInteractiveTiming_ProcessingTimeName,
processing_time.InMilliseconds());
EXPECT_EQ(
GetDetector()->GetFirstInputProcessingTime().value().InMilliseconds(),
processing_time.InMilliseconds());
}
// In tests for Total Blocking Time (TBT) we call SetTimeToInteractive() instead
......
......@@ -509,6 +509,15 @@ base::Optional<base::TimeDelta> PerformanceTiming::LongestInputTimestamp()
interactive_detector->GetLongestInputTimestamp());
}
base::Optional<base::TimeDelta> PerformanceTiming::FirstInputProcessingTime()
const {
const InteractiveDetector* interactive_detector = GetInteractiveDetector();
if (!interactive_detector)
return base::nullopt;
return interactive_detector->GetFirstInputProcessingTime();
}
uint64_t PerformanceTiming::ParseStart() const {
const DocumentParserTiming* timing = GetDocumentParserTiming();
if (!timing)
......
......@@ -156,6 +156,8 @@ class CORE_EXPORT PerformanceTiming final : public ScriptWrappable,
base::Optional<base::TimeDelta> LongestInputDelay() const;
// The timestamp of the event whose delay is reported by LongestInputDelay().
base::Optional<base::TimeDelta> LongestInputTimestamp() const;
// The duration of event handlers processing the first input event.
base::Optional<base::TimeDelta> FirstInputProcessingTime() const;
uint64_t ParseStart() const;
uint64_t ParseStop() const;
......
......@@ -7849,6 +7849,24 @@ be describing additional metrics about the same event.
</history>
</aggregation>
</metric>
<metric name="InteractiveTiming.FirstInputProcessingTimes">
<summary>
Measures First Input Processing Time, the duration of event handlers
processing the first input event. In ms.
</summary>
<aggregation>
<history>
<index fields="profile.country"/>
<index fields="profile.country,profile.system_ram"/>
<index fields="profile.is_dominant_version"/>
<index fields="profile.is_latest_version"/>
<index fields="profile.system_ram"/>
<statistics>
<quantiles type="std-percentiles"/>
</statistics>
</history>
</aggregation>
</metric>
<metric name="InteractiveTiming.FirstInputTimestamp">
<obsolete>
Deprecated on January 2019 in favor of
......
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