Skip to content

Commit

Permalink
[M116] Add metrics to FLEDGE Latency UKM on ScoreAd and its dependenc…
Browse files Browse the repository at this point in the history 
…ies.

IMPORTANT: This has one significant side effect on PrivateAggregationTimings! script_run_time and signals_fetch_time are recorded in InterestGroupAuction::OnScoreAdComplete(); prior to this change, a zero time is recorded for both of these when the script encounters an error, i.e. when SellerWorklet::V8State::PostScoreAdCallbackToUserThreadOnError was called; after this change, the actual script/signal-load times are recorded instead. This is because the same fields (scoring_latency and score_ad_dependency_latencies) are used for both PA Timings and the UKM metric.

Beyond that, the rest of this change is strictly the addition of new UKM metrics to the AdsInterestGroup.AuctionLatency.V2 event. In previous commits, reviewed as
https://chromium-review.googlesource.com/c/chromium/src/+/4359997 and
https://chromium-review.googlesource.com/c/chromium/src/+/4386873, we
added metrics for the latency of GenerateBid and its surrounding flow,
including metrics around delays caused by high-latency inputs to
GenerateBid. This commit adds the analogous metrics for ScoreAd and its
high-latency inputs.

As with those earlier commits, this adds several metrics:

1. ScoreAdFlowLatency reflects the latency of the entire ScoreAd flow,
   from InterestGroupAuction::ScoreBidIfReady to
   InterestGroupAuction::OnScoreAdComplete.

2. ScoreAdLatency reflects the latency of only the call to
   V8State::ScoreAd, a component of the flow reflected in (1).

3. ScoreAdCodeReadyLatency, ScoreAdDirectFromSellerSignalsLatency, and
   ScoreAdTrustedScoringSignalsLatency metrics reflect the latency and
   critical path latency (delay) of each of these dependencies that must
   be satisfied before V8State::ScoreAd can run.

(cherry picked from commit 9d5ce47)

Bug: 1424365
Change-Id: I1aaaa336991d818d142ba5e93ec9024d5ac053a3
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/4584089
Reviewed-by: Maks Orlovich <morlovich@chromium.org>
Reviewed-by: Daniel Cheng <dcheng@chromium.org>
Commit-Queue: Orr Bernstein <orrb@google.com>
Reviewed-by: Sun Yueru <yrsun@chromium.org>
Cr-Original-Commit-Position: refs/heads/main@{#1161948}
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/4643818
Reviewed-by: Robert Kaplow <rkaplow@chromium.org>
Bot-Commit: Rubber Stamper <rubber-stamper@appspot.gserviceaccount.com>
Cr-Commit-Position: refs/branch-heads/5845@{#184}
Cr-Branched-From: 5a5dff6-refs/heads/main@{#1160321}
  • Loading branch information
@orrb1
orrb1 authored and Chromium LUCI CQ committed Jun 28, 2023
1 parent 5fee6ac commit bd07d89
Show file tree
Hide file tree
Showing 11 changed files with 1,421 additions and 229 deletions.
124 changes: 124 additions & 0 deletions content/browser/interest_group/auction_metrics_recorder.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -160,6 +160,55 @@ void AuctionMetricsRecorder::OnAuctionEnd(AuctionResult auction_result) {
/*set_mean_function=*/
&UkmEntry::SetMeanTimeBidsQueuedWaitingForSellerWorkletInMillis);

MaybeSetMeanAndMaxLatency(score_ad_latency_aggregator_,
/*set_mean_function=*/
&UkmEntry::SetMeanScoreAdLatencyInMillis,
/*set_max_function=*/
&UkmEntry::SetMaxScoreAdLatencyInMillis);
MaybeSetMeanAndMaxLatency(
score_ad_flow_latency_aggregator_,
/*set_mean_function=*/&UkmEntry::SetMeanScoreAdFlowLatencyInMillis,
/*set_max_function=*/&UkmEntry::SetMaxScoreAdFlowLatencyInMillis);

MaybeSetMeanAndMaxLatency(score_ad_code_ready_latency_aggregator_,
/*set_mean_function=*/
&UkmEntry::SetMeanScoreAdCodeReadyLatencyInMillis,
/*set_max_function=*/
&UkmEntry::SetMaxScoreAdCodeReadyLatencyInMillis);
MaybeSetMeanAndMaxLatency(
score_ad_direct_from_seller_signals_latency_aggregator_,
/*set_mean_function=*/
&UkmEntry::SetMeanScoreAdDirectFromSellerSignalsLatencyInMillis,
/*set_max_function=*/
&UkmEntry::SetMaxScoreAdDirectFromSellerSignalsLatencyInMillis);
MaybeSetMeanAndMaxLatency(
score_ad_trusted_scoring_signals_latency_aggregator_,
/*set_mean_function=*/
&UkmEntry::SetMeanScoreAdTrustedScoringSignalsLatencyInMillis,
/*set_max_function=*/
&UkmEntry::SetMaxScoreAdTrustedScoringSignalsLatencyInMillis);

SetNumAndMaybeMeanLatency(
score_ad_code_ready_critical_path_aggregator_,
/*set_num_function=*/
&UkmEntry::SetNumScoreAdCodeReadyOnCriticalPath,
/*set_mean_function=*/
&UkmEntry::SetMeanScoreAdCodeReadyCriticalPathLatencyInMillis);
SetNumAndMaybeMeanLatency(
score_ad_direct_from_seller_signals_critical_path_aggregator_,
/*set_num_function=*/
&UkmEntry::SetNumScoreAdDirectFromSellerSignalsOnCriticalPath,
/*set_mean_function=*/
&UkmEntry::
SetMeanScoreAdDirectFromSellerSignalsCriticalPathLatencyInMillis);
SetNumAndMaybeMeanLatency(
score_ad_trusted_scoring_signals_critical_path_aggregator_,
/*set_num_function=*/
&UkmEntry::SetNumScoreAdTrustedScoringSignalsOnCriticalPath,
/*set_mean_function=*/
&UkmEntry::
SetMeanScoreAdTrustedScoringSignalsCriticalPathLatencyInMillis);

auto* ukm_recorder = ukm::UkmRecorder::Get();
builder_.Record(ukm_recorder->Get());
}
Expand Down Expand Up @@ -314,6 +363,37 @@ void AuctionMetricsRecorder::RecordBidQueuedWaitingForSellerWorklet(
bid_queued_waiting_for_seller_worklet_aggregator_.RecordLatency(delay);
}

void AuctionMetricsRecorder::RecordScoreAdFlowLatency(base::TimeDelta latency) {
score_ad_flow_latency_aggregator_.RecordLatency(latency);
}

void AuctionMetricsRecorder::RecordScoreAdLatency(base::TimeDelta latency) {
score_ad_latency_aggregator_.RecordLatency(latency);
}

void AuctionMetricsRecorder::RecordScoreAdDependencyLatencies(
const auction_worklet::mojom::ScoreAdDependencyLatencies&
score_ad_dependency_latencies) {
ScoreAdDependencyCriticalPath critical_path;

MaybeRecordScoreAdDependencyLatency(
ScoreAdDependencyCriticalPath::Dependency::kCodeReady,
score_ad_dependency_latencies.code_ready_latency,
score_ad_code_ready_latency_aggregator_, critical_path);

MaybeRecordScoreAdDependencyLatency(
ScoreAdDependencyCriticalPath::Dependency::kDirectFromSellerSignals,
score_ad_dependency_latencies.direct_from_seller_signals_latency,
score_ad_direct_from_seller_signals_latency_aggregator_, critical_path);

MaybeRecordScoreAdDependencyLatency(
ScoreAdDependencyCriticalPath::Dependency::kTrustedScoringSignals,
score_ad_dependency_latencies.trusted_scoring_signals_latency,
score_ad_trusted_scoring_signals_latency_aggregator_, critical_path);

RecordScoreAdDependencyLatencyCriticalPath(critical_path);
}

void AuctionMetricsRecorder::LatencyAggregator::RecordLatency(
base::TimeDelta latency) {
// Negative latencies are meaningless; don't record them at all.
Expand Down Expand Up @@ -416,4 +496,48 @@ void AuctionMetricsRecorder::RecordGenerateBidDependencyLatencyCriticalPath(
}
}

void AuctionMetricsRecorder::MaybeRecordScoreAdDependencyLatency(
ScoreAdDependencyCriticalPath::Dependency dependency,
absl::optional<base::TimeDelta> latency,
LatencyAggregator& aggregator,
ScoreAdDependencyCriticalPath& critical_path) {
if (latency) {
aggregator.RecordLatency(*latency);
if (*latency >= critical_path.last_resolved_dependency_latency) {
critical_path.last_resolved_dependency = dependency;
critical_path.penultimate_resolved_dependency_latency =
critical_path.last_resolved_dependency_latency;
critical_path.last_resolved_dependency_latency = *latency;
} else if (*latency >
critical_path.penultimate_resolved_dependency_latency) {
critical_path.penultimate_resolved_dependency_latency = *latency;
}
}
}

void AuctionMetricsRecorder::RecordScoreAdDependencyLatencyCriticalPath(
ScoreAdDependencyCriticalPath& critical_path) {
if (!critical_path.last_resolved_dependency.has_value()) {
return;
}
base::TimeDelta critical_path_latency =
critical_path.last_resolved_dependency_latency -
critical_path.penultimate_resolved_dependency_latency;
using Dependency = ScoreAdDependencyCriticalPath::Dependency;
switch (*critical_path.last_resolved_dependency) {
case Dependency::kCodeReady:
score_ad_code_ready_critical_path_aggregator_.RecordLatency(
critical_path_latency);
break;
case Dependency::kDirectFromSellerSignals:
score_ad_direct_from_seller_signals_critical_path_aggregator_
.RecordLatency(critical_path_latency);
break;
case Dependency::kTrustedScoringSignals:
score_ad_trusted_scoring_signals_critical_path_aggregator_.RecordLatency(
critical_path_latency);
break;
}
}

} // namespace content
46 changes: 46 additions & 0 deletions content/browser/interest_group/auction_metrics_recorder.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@
#include "content/browser/interest_group/auction_worklet_manager.h"
#include "content/common/content_export.h"
#include "content/services/auction_worklet/public/mojom/bidder_worklet.mojom-shared.h"
#include "content/services/auction_worklet/public/mojom/seller_worklet.mojom.h"
#include "services/metrics/public/cpp/ukm_builders.h"
#include "services/metrics/public/cpp/ukm_source_id.h"
#include "url/origin.h"
Expand Down Expand Up @@ -118,6 +119,17 @@ class CONTENT_EXPORT AuctionMetricsRecorder {
void RecordBidQueuedWaitingForConfigPromises(base::TimeDelta delay);
void RecordBidQueuedWaitingForSellerWorklet(base::TimeDelta delay);

// Latency of the entire ScoreAd flow, including signals requests, for
// a given Bid.
void RecordScoreAdFlowLatency(base::TimeDelta latency);
// Latency of just the call to ScoreAd.
void RecordScoreAdLatency(base::TimeDelta latency);

// Records latencies and critical path latencies of ScoreAd dependencies.
void RecordScoreAdDependencyLatencies(
const auction_worklet::mojom::ScoreAdDependencyLatencies&
score_ad_dependency_latencies);

private:
using UkmEntry = ukm::builders::AdsInterestGroup_AuctionLatency_V2;
using EntrySetFunction = UkmEntry& (UkmEntry::*)(int64_t value);
Expand Down Expand Up @@ -174,6 +186,24 @@ class CONTENT_EXPORT AuctionMetricsRecorder {
void RecordGenerateBidDependencyLatencyCriticalPath(
GenerateBidDependencyCriticalPath& critical_path);

struct ScoreAdDependencyCriticalPath {
enum class Dependency {
kCodeReady = 0,
kDirectFromSellerSignals = 2,
kTrustedScoringSignals = 3,
};
absl::optional<Dependency> last_resolved_dependency;
base::TimeDelta last_resolved_dependency_latency;
base::TimeDelta penultimate_resolved_dependency_latency;
};
void MaybeRecordScoreAdDependencyLatency(
ScoreAdDependencyCriticalPath::Dependency dependency,
absl::optional<base::TimeDelta> latency,
LatencyAggregator& aggregator,
ScoreAdDependencyCriticalPath& critical_path);
void RecordScoreAdDependencyLatencyCriticalPath(
ScoreAdDependencyCriticalPath& critical_path);

// The data structure we'll eventually record via the UkmRecorder.
// We incrementally build this in all of the methods of this class.
UkmEntry builder_;
Expand Down Expand Up @@ -209,6 +239,7 @@ class CONTENT_EXPORT AuctionMetricsRecorder {
// Various latency measurements.
LatencyAggregator component_auction_latency_aggregator_;

// GenerateBid latencies.
LatencyAggregator bid_for_one_interest_group_latency_aggregator_;
LatencyAggregator generate_single_bid_latency_aggregator_;

Expand All @@ -231,6 +262,21 @@ class CONTENT_EXPORT AuctionMetricsRecorder {
top_level_bid_queued_waiting_for_config_promises_aggregator_;
LatencyAggregator bid_queued_waiting_for_seller_worklet_aggregator_;
LatencyAggregator bid_queued_waiting_for_config_promises_aggregator_;

// ScoreAd latencies
LatencyAggregator score_ad_flow_latency_aggregator_;
LatencyAggregator score_ad_latency_aggregator_;

// Aggregated latencies of ScoreAd dependencies.
LatencyAggregator score_ad_code_ready_latency_aggregator_;
LatencyAggregator score_ad_direct_from_seller_signals_latency_aggregator_;
LatencyAggregator score_ad_trusted_scoring_signals_latency_aggregator_;

// Aggregated critical path latencies of ScoreAd dependencies.
LatencyAggregator score_ad_code_ready_critical_path_aggregator_;
LatencyAggregator
score_ad_direct_from_seller_signals_critical_path_aggregator_;
LatencyAggregator score_ad_trusted_scoring_signals_critical_path_aggregator_;
};

} // namespace content
Expand Down

0 comments on commit bd07d89

Please sign in to comment.