diff --git a/cobalt/xhr/BUILD.gn b/cobalt/xhr/BUILD.gn index 0770a60105cb..5c50b75ccbf6 100644 --- a/cobalt/xhr/BUILD.gn +++ b/cobalt/xhr/BUILD.gn @@ -32,6 +32,8 @@ static_library("xhr") { "xml_http_request.h", "xml_http_request_event_target.cc", "xml_http_request_event_target.h", + "xml_http_request_metrics.cc", + "xml_http_request_metrics.h", ] public_deps = [ ":xhr_settings" ] @@ -67,6 +69,7 @@ target(gtest_target_type, "xhr_test") { sources = [ "fetch_buffer_pool_test.cc", "xhr_settings_test.cc", + "xml_http_request_metrics_test.cc", "xml_http_request_test.cc", ] deps = [ diff --git a/cobalt/xhr/xml_http_request.cc b/cobalt/xhr/xml_http_request.cc index 7f052ab7b354..2ecf526d89dc 100644 --- a/cobalt/xhr/xml_http_request.cc +++ b/cobalt/xhr/xml_http_request.cc @@ -1217,6 +1217,7 @@ void XMLHttpRequestImpl::WillDestroyCurrentMessageLoop() { void XMLHttpRequestImpl::ReportLoadTimingInfo( const net::LoadTimingInfo& timing_info) { load_timing_info_ = timing_info; + metrics_.ReportResourceTimingMetrics(timing_info); } void XMLHttpRequestImpl::GetLoadTimingInfoAndCreateResourceTiming() { diff --git a/cobalt/xhr/xml_http_request.h b/cobalt/xhr/xml_http_request.h index da8529c9ece2..193da6ae8fc8 100644 --- a/cobalt/xhr/xml_http_request.h +++ b/cobalt/xhr/xml_http_request.h @@ -40,6 +40,7 @@ #include "cobalt/web/environment_settings.h" #include "cobalt/xhr/url_fetcher_buffer_writer.h" #include "cobalt/xhr/xml_http_request_event_target.h" +#include "cobalt/xhr/xml_http_request_metrics.h" #include "cobalt/xhr/xml_http_request_upload.h" #include "net/base/load_timing_info.h" #include "net/http/http_request_headers.h" @@ -455,6 +456,8 @@ class XMLHttpRequestImpl prevent_gc_until_send_complete_; std::string request_body_text_; + + XMLHttpRequestMetrics metrics_; }; class DOMXMLHttpRequestImpl : public XMLHttpRequestImpl { diff --git a/cobalt/xhr/xml_http_request_metrics.cc b/cobalt/xhr/xml_http_request_metrics.cc new file mode 100644 index 000000000000..078db7a42815 --- /dev/null +++ b/cobalt/xhr/xml_http_request_metrics.cc @@ -0,0 +1,76 @@ +// Copyright 2024 The Cobalt Authors. All Rights Reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +#include "cobalt/xhr/xml_http_request_metrics.h" + +#include "base/metrics/histogram_macros.h" +#include "net/base/load_timing_info.h" + +namespace cobalt { +namespace xhr { + +void XMLHttpRequestMetrics::ReportResourceTimingMetrics( + const net::LoadTimingInfo& timing_info) { + if (!(timing_info.connect_timing.connect_start.is_null() || + timing_info.connect_timing.connect_end.is_null())) { + base::TimeDelta tcp_handshake_time = + timing_info.connect_timing.connect_end - + timing_info.connect_timing.connect_start; + UMA_HISTOGRAM_TIMES("Cobalt.Media.XHR.ResourceTiming.TcpHandshakeTime", + tcp_handshake_time); + } + + if (!(timing_info.connect_timing.dns_start.is_null() || + timing_info.connect_timing.dns_end.is_null())) { + base::TimeDelta dns_lookup_time = timing_info.connect_timing.dns_end - + timing_info.connect_timing.dns_start; + UMA_HISTOGRAM_TIMES("Cobalt.Media.XHR.ResourceTiming.DnsLookupTime", + dns_lookup_time); + } + + if (!(timing_info.send_start.is_null() || + timing_info.receive_headers_end.is_null())) { + base::TimeDelta request_time = + timing_info.receive_headers_end - timing_info.send_start; + UMA_HISTOGRAM_TIMES("Cobalt.Media.XHR.ResourceTiming.RequestTime", + request_time); + } + + if (!(timing_info.connect_timing.ssl_start.is_null() || + timing_info.send_start.is_null())) { + base::TimeDelta tls_negotiation_time = + timing_info.send_start - timing_info.connect_timing.ssl_start; + UMA_HISTOGRAM_TIMES("Cobalt.Media.XHR.ResourceTiming.TlsNegotiationTime", + tls_negotiation_time); + } + + if (!(timing_info.request_start.is_null())) { + base::TimeDelta time_to_fetch = + clock_->NowTicks() - timing_info.request_start; + UMA_HISTOGRAM_TIMES("Cobalt.Media.XHR.ResourceTiming.TimeToFetch", + time_to_fetch); + } + + if (!(timing_info.service_worker_start_time.is_null() || + timing_info.request_start.is_null())) { + base::TimeDelta service_worker_processing_time = + timing_info.request_start - timing_info.service_worker_start_time; + UMA_HISTOGRAM_TIMES( + "Cobalt.Media.XHR.ResourceTiming.ServiceWorkerProcessingTime", + service_worker_processing_time); + } +} + +} // namespace xhr +} // namespace cobalt diff --git a/cobalt/xhr/xml_http_request_metrics.h b/cobalt/xhr/xml_http_request_metrics.h new file mode 100644 index 000000000000..4a3218b2c756 --- /dev/null +++ b/cobalt/xhr/xml_http_request_metrics.h @@ -0,0 +1,44 @@ +// Copyright 2024 The Cobalt Authors. All Rights Reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +#ifndef COBALT_XHR_XML_HTTP_REQUEST_METRICS_H_ +#define COBALT_XHR_XML_HTTP_REQUEST_METRICS_H_ + +#include "base/time/default_tick_clock.h" +#include "base/time/tick_clock.h" +#include "net/base/load_timing_info.h" + +namespace cobalt { +namespace xhr { + +class XMLHttpRequestMetrics { + public: + XMLHttpRequestMetrics( + const base::TickClock* clock = base::DefaultTickClock::GetInstance()) + : clock_(clock) {} + ~XMLHttpRequestMetrics() = default; + + void ReportResourceTimingMetrics(const net::LoadTimingInfo& timing_info); + + private: + XMLHttpRequestMetrics(const XMLHttpRequestMetrics&) = delete; + XMLHttpRequestMetrics& operator=(const XMLHttpRequestMetrics&) = delete; + + const base::TickClock* clock_; +}; + +} // namespace xhr +} // namespace cobalt + +#endif // COBALT_XHR_XML_HTTP_REQUEST_METRICS_H_ diff --git a/cobalt/xhr/xml_http_request_metrics_test.cc b/cobalt/xhr/xml_http_request_metrics_test.cc new file mode 100644 index 000000000000..e77a47da3f3b --- /dev/null +++ b/cobalt/xhr/xml_http_request_metrics_test.cc @@ -0,0 +1,288 @@ +// Copyright 2024 The Cobalt Authors. All Rights Reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +#include "cobalt/xhr/xml_http_request_metrics.h" + +#include + +#include + +#include "base/test/metrics/histogram_tester.h" +#include "base/test/simple_test_tick_clock.h" +#include "base/time/time.h" +#include "net/base/load_timing_info.h" +#include "starboard/types.h" +#include "testing/gtest/include/gtest/gtest.h" + +namespace cobalt { +namespace xhr { +namespace { +constexpr char kUmaPrefix[] = "Cobalt.Media.XHR.ResourceTiming."; + + +class XMLHttpRequestMetricsTest : public ::testing::Test { + protected: + XMLHttpRequestMetricsTest() : metrics_(&clock_) {} + + void SetUp() override { clock_.SetNowTicks(base::TimeTicks()); } + + struct LoadTimingTickInfo { + uint32_t request_start; + uint32_t proxy_start; + uint32_t proxy_end; + uint32_t dns_start; + uint32_t dns_end; + uint32_t connect_start; + uint32_t ssl_start; + uint32_t ssl_end; + uint32_t connect_end; + uint32_t send_start; + uint32_t send_end; + uint32_t response_start; + uint32_t worker_start; + uint32_t request_end; + }; + + net::LoadTimingInfo SetClockState(const LoadTimingTickInfo& ticks) { + net::LoadTimingInfo info = {}; + auto start_ticks = base::TimeTicks(); + + if (ticks.request_start > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.request_start)); + info.request_start = clock_.NowTicks(); + } + + if (ticks.proxy_start > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.proxy_start)); + info.proxy_resolve_start = clock_.NowTicks(); + } + + if (ticks.proxy_end > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.proxy_end)); + info.proxy_resolve_end = clock_.NowTicks(); + } + + if (ticks.dns_start > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.dns_start)); + info.connect_timing.dns_start = clock_.NowTicks(); + } + + if (ticks.dns_end > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.dns_end)); + info.connect_timing.dns_end = clock_.NowTicks(); + } + + if (ticks.connect_start > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.connect_start)); + info.connect_timing.connect_start = clock_.NowTicks(); + } + + if (ticks.ssl_start > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.ssl_start)); + info.connect_timing.ssl_start = clock_.NowTicks(); + } + + if (ticks.ssl_end > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.ssl_end)); + info.connect_timing.ssl_end = clock_.NowTicks(); + } + + if (ticks.connect_end > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.connect_end)); + info.connect_timing.connect_end = clock_.NowTicks(); + } + + if (ticks.send_start > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.send_start)); + info.send_start = clock_.NowTicks(); + } + + if (ticks.send_end > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.send_end)); + info.send_end = clock_.NowTicks(); + } + + if (ticks.response_start > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.response_start)); + info.receive_headers_end = clock_.NowTicks(); + } + + if (ticks.worker_start > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.worker_start)); + info.service_worker_start_time = clock_.NowTicks(); + } + + if (ticks.request_end > 0) { + clock_.SetNowTicks(start_ticks); + clock_.Advance(base::TimeDelta::FromMilliseconds(ticks.request_end)); + } + + return info; + } + + base::HistogramTester histogram_tester_; + base::SimpleTestTickClock clock_; + + XMLHttpRequestMetrics metrics_; +}; + +TEST_F(XMLHttpRequestMetricsTest, HandlesEmptyTimingInfo) { + metrics_.ReportResourceTimingMetrics(net::LoadTimingInfo{}); + + auto counts = histogram_tester_.GetTotalCountsForPrefix(kUmaPrefix); + + EXPECT_EQ(0, counts.size()); +} + +TEST_F(XMLHttpRequestMetricsTest, ReportsTcpHandshakeTime) { + XMLHttpRequestMetricsTest::LoadTimingTickInfo data = {}; + data.connect_start = 7; + data.connect_end = 13; + auto info = SetClockState(data); + + metrics_.ReportResourceTimingMetrics(info); + + auto counts = histogram_tester_.GetTotalCountsForPrefix(kUmaPrefix); + EXPECT_EQ(1, counts.size()); + + histogram_tester_.ExpectUniqueSample( + std::string(kUmaPrefix) + "TcpHandshakeTime", 6, 1); +} + +TEST_F(XMLHttpRequestMetricsTest, ReportsDnsLookupTime) { + XMLHttpRequestMetricsTest::LoadTimingTickInfo data = {}; + data.dns_start = 7; + data.dns_end = 13; + auto info = SetClockState(data); + + metrics_.ReportResourceTimingMetrics(info); + + auto counts = histogram_tester_.GetTotalCountsForPrefix(kUmaPrefix); + EXPECT_EQ(1, counts.size()); + + histogram_tester_.ExpectUniqueSample( + std::string(kUmaPrefix) + "DnsLookupTime", 6, 1); +} + +TEST_F(XMLHttpRequestMetricsTest, ReportsRequestTime) { + XMLHttpRequestMetricsTest::LoadTimingTickInfo data = {}; + data.send_start = 7; + data.response_start = 13; + auto info = SetClockState(data); + + metrics_.ReportResourceTimingMetrics(info); + + auto counts = histogram_tester_.GetTotalCountsForPrefix(kUmaPrefix); + EXPECT_EQ(1, counts.size()); + + histogram_tester_.ExpectUniqueSample(std::string(kUmaPrefix) + "RequestTime", + 6, 1); +} + +TEST_F(XMLHttpRequestMetricsTest, ReportsTlsNegotiationTime) { + XMLHttpRequestMetricsTest::LoadTimingTickInfo data = {}; + data.ssl_start = 7; + data.send_start = 13; + auto info = SetClockState(data); + + metrics_.ReportResourceTimingMetrics(info); + + auto counts = histogram_tester_.GetTotalCountsForPrefix(kUmaPrefix); + EXPECT_EQ(1, counts.size()); + + histogram_tester_.ExpectUniqueSample( + std::string(kUmaPrefix) + "TlsNegotiationTime", 6, 1); +} + +TEST_F(XMLHttpRequestMetricsTest, ReportsTimeToFetch) { + XMLHttpRequestMetricsTest::LoadTimingTickInfo data = {}; + data.request_start = 7; + data.request_end = 13; + auto info = SetClockState(data); + + metrics_.ReportResourceTimingMetrics(info); + + auto counts = histogram_tester_.GetTotalCountsForPrefix(kUmaPrefix); + EXPECT_EQ(1, counts.size()); + + histogram_tester_.ExpectUniqueSample(std::string(kUmaPrefix) + "TimeToFetch", + 6, 1); +} + +TEST_F(XMLHttpRequestMetricsTest, ReportsServiceWorkerStartTime) { + XMLHttpRequestMetricsTest::LoadTimingTickInfo data = {}; + data.worker_start = 7; + data.request_start = 13; + auto info = SetClockState(data); + + metrics_.ReportResourceTimingMetrics(info); + + // This also includes a TimeToFetch event. + auto counts = histogram_tester_.GetTotalCountsForPrefix(kUmaPrefix); + EXPECT_EQ(2, counts.size()); + + histogram_tester_.ExpectUniqueSample( + std::string(kUmaPrefix) + "ServiceWorkerProcessingTime", 6, 1); +} + +TEST_F(XMLHttpRequestMetricsTest, CanReportAllMetricsSimultaneously) { + XMLHttpRequestMetricsTest::LoadTimingTickInfo data = {}; + data.worker_start = 1; + data.request_start = 2; + data.proxy_start = 4; + data.proxy_end = 8; + data.dns_start = 16; + data.dns_end = 32; + data.connect_start = 64; + data.ssl_start = 128; + data.ssl_end = 256; + data.connect_end = 512; + data.send_start = 1024; + data.send_end = 2048; + data.response_start = 4096; + data.request_end = 8192; + auto info = SetClockState(data); + + metrics_.ReportResourceTimingMetrics(info); + + histogram_tester_.ExpectUniqueSample( + std::string(kUmaPrefix) + "TcpHandshakeTime", 448, 1); + histogram_tester_.ExpectUniqueSample( + std::string(kUmaPrefix) + "DnsLookupTime", 16, 1); + histogram_tester_.ExpectUniqueSample(std::string(kUmaPrefix) + "RequestTime", + 3072, 1); + histogram_tester_.ExpectUniqueSample( + std::string(kUmaPrefix) + "TlsNegotiationTime", 896, 1); + histogram_tester_.ExpectUniqueSample(std::string(kUmaPrefix) + "TimeToFetch", + 8190, 1); + histogram_tester_.ExpectUniqueSample( + std::string(kUmaPrefix) + "ServiceWorkerProcessingTime", 1, 1); +} + +} // namespace +} // namespace xhr +} // namespace cobalt diff --git a/tools/metrics/histograms/metadata/cobalt/histograms.xml b/tools/metrics/histograms/metadata/cobalt/histograms.xml index 13f4d9d71a57..f438809dd7eb 100644 --- a/tools/metrics/histograms/metadata/cobalt/histograms.xml +++ b/tools/metrics/histograms/metadata/cobalt/histograms.xml @@ -185,6 +185,72 @@ Always run the pretty print utility on this file after editing: + + + + async@google.com + cobalt-team@google.com + + Timing data for the TCP handshake of XHR requests. + + + + + + + async@google.com + cobalt-team@google.com + + Timing data for the DNS lookup of XHR requests. + + + + + + + async@google.com + cobalt-team@google.com + + Timing data for the request of XHR requests. + + + + + + + async@google.com + cobalt-team@google.com + + Timing data for TLS negotiation of XHR requests. + + + + + + + async@google.com + cobalt-team@google.com + + Timing data for the full fetch of XHR requests. + + + + + + + async@google.com + cobalt-team@google.com + + Timing data for the service worker processing time of XHR requests. + + +