1 /* 2 * Copyright (C) 2022 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17 package com.android.adservices.service.stats; 18 19 import static android.adservices.common.AdServicesStatusUtils.STATUS_SUCCESS; 20 21 import static com.android.adservices.data.adselection.AdSelectionDatabase.DATABASE_NAME; 22 import static com.android.adservices.service.stats.AdServicesLoggerUtil.FIELD_UNSET; 23 import static com.android.adservices.service.stats.AdServicesStatsLog.RUN_AD_SCORING_PROCESS_REPORTED__GET_AD_SELECTION_LOGIC_SCRIPT_TYPE__JAVASCRIPT; 24 import static com.android.adservices.service.stats.AdServicesStatsLog.RUN_AD_SCORING_PROCESS_REPORTED__GET_AD_SELECTION_LOGIC_SCRIPT_TYPE__UNSET; 25 26 import android.adservices.common.AdSelectionSignals; 27 import android.adservices.common.CallerMetadata; 28 import android.annotation.NonNull; 29 import android.annotation.Nullable; 30 import android.content.Context; 31 32 import com.android.adservices.LoggerFactory; 33 import com.android.adservices.data.adselection.DBAdSelection; 34 import com.android.adservices.data.customaudience.DBCustomAudience; 35 import com.android.adservices.service.adselection.AdBiddingOutcome; 36 import com.android.internal.annotations.VisibleForTesting; 37 38 import java.util.List; 39 import java.util.Objects; 40 import java.util.stream.Collectors; 41 42 /** 43 * Class for logging the run ad selection process. It provides the functions to collect and log the 44 * corresponding ad selection process and its subcomponent processes and log the data into the 45 * statsd logs. This class collect data for the telemetry atoms: 46 * 47 * <ul> 48 * <li>RunAdBiddingProcessReportedStats for bidding stage: 49 * <ul> 50 * <li>Subprocess: 51 * <ul> 52 * <li>getBuyerCustomAudience 53 * <li>RunAdBidding 54 * </ul> 55 * </ul> 56 * <li>RunAdScoringProcessReportedStats for scoring stage: 57 * <ul> 58 * <li>Subprocess: 59 * <ul> 60 * <li>RunAdScoring 61 * <li>GetAdScores 62 * <li>scoreAds 63 * </ul> 64 * </ul> 65 * <li>RunAdSelectionProcessReportedStats for overall ad selection: 66 * <ul> 67 * <li>Subprocess: 68 * <ul> 69 * <li>persistAdSelection 70 * </ul> 71 * </ul> 72 * </ul> 73 * 74 * <p>Each complete parent process (bidding, scoring, and overall ad selection) should call its 75 * corresponding start and end methods to record its states and log the generated atom proto into 76 * the statsd logger. 77 * 78 * <p>Each subprocess should call its corresponding start method if it starts, and only call the end 79 * method for successful completion. In failure cases, the exceptions thrown should propagate to the 80 * end of the parent process, and unset ending timestamps will be clearly communicated in the logged 81 * atom. 82 */ 83 // TODO(b/259332713): Refactor the logger for individual bidding, scoring process etc. 84 public class AdSelectionExecutionLogger extends ApiServiceLatencyCalculator { 85 private static final LoggerFactory.Logger sLogger = LoggerFactory.getFledgeLogger(); 86 87 @VisibleForTesting 88 public static final int SCRIPT_JAVASCRIPT = 89 RUN_AD_SCORING_PROCESS_REPORTED__GET_AD_SELECTION_LOGIC_SCRIPT_TYPE__JAVASCRIPT; 90 91 @VisibleForTesting 92 static final int SCRIPT_UNSET = 93 RUN_AD_SCORING_PROCESS_REPORTED__GET_AD_SELECTION_LOGIC_SCRIPT_TYPE__UNSET; 94 95 @VisibleForTesting 96 static final String REPEATED_START_PERSIST_AD_SELECTION = 97 "The logger has already set the start of the persist-ad-selection process."; 98 99 @VisibleForTesting 100 static final String REPEATED_END_PERSIST_AD_SELECTION = 101 "The logger has already set the end of the persist-ad-selection process."; 102 103 @VisibleForTesting 104 static final String MISSING_START_PERSIST_AD_SELECTION = 105 "The logger should set the start of the persist-ad-selection process."; 106 107 @VisibleForTesting 108 static final String MISSING_END_PERSIST_AD_SELECTION = 109 "The logger should set the end of the persist-ad-selection process."; 110 111 @VisibleForTesting 112 static final String MISSING_PERSIST_AD_SELECTION = 113 "The ad selection execution logger should log the persist-ad-selection process."; 114 115 @VisibleForTesting 116 static final String REPEATED_END_BIDDING_STAGE = 117 "The logger has already set the end state of the bidding stage."; 118 119 @VisibleForTesting 120 static final String MISSING_START_RUN_AD_BIDDING = 121 "The logger should set the start of the run-ad-selection process."; 122 123 @VisibleForTesting 124 static final String REPEATED_START_BIDDING_STAGE = 125 "The logger has already set the start of the bidding stage."; 126 127 @VisibleForTesting 128 static final String REPEATED_END_GET_BUYERS_CUSTOM_AUDIENCE = 129 "The logger has already set the end of the get-buyers-custom-audience process."; 130 131 @VisibleForTesting 132 static final String MISSING_START_BIDDING_STAGE = 133 "The logger should set the start state of the bidding stage."; 134 135 @VisibleForTesting 136 static final String MISSING_END_GET_BUYERS_CUSTOM_AUDIENCE = 137 "The logger should set the end of the get-buyers-custom-audience process."; 138 139 @VisibleForTesting 140 static final String REPEATED_START_RUN_AD_BIDDING = 141 "The logger has already set the start of the run-ad-bidding process."; 142 143 @VisibleForTesting 144 static final String MISSING_GET_BUYERS_CUSTOM_AUDIENCE = 145 "The logger should set the start of the bidding stage and the " 146 + "get-buyers-custom-audience process."; 147 148 @VisibleForTesting static final float RATIO_OF_CAS_UNSET = -1.0f; 149 150 @VisibleForTesting 151 static final String REPEATED_START_RUN_AD_SCORING = 152 "The logger has already set the start of the run-ad-scoring process."; 153 154 @VisibleForTesting 155 static final String MISSING_START_RUN_AD_SCORING = 156 "The logger should set the start of the run-ad-scoring process."; 157 158 @VisibleForTesting 159 static final String REPEATED_END_RUN_AD_SCORING = 160 "The logger has already set the end of the run-ad-scoring process."; 161 162 @VisibleForTesting 163 static final String MISSING_START_GET_AD_SELECTION_LOGIC = 164 "The logger should set the start of the get-ad-selection-logic process."; 165 166 @VisibleForTesting 167 static final String REPEATED_END_GET_AD_SELECTION_LOGIC = 168 "The logger has already set the end of the get-ad-selection-logic process."; 169 170 @VisibleForTesting 171 static final String REPEATED_START_GET_TRUSTED_SCORING_SIGNALS = 172 "The logger has already set the start of the get-trusted-scoring-signals process."; 173 174 @VisibleForTesting 175 static final String MISSING_START_GET_TRUSTED_SCORING_SIGNALS = 176 "The logger should set the start of the get-trusted-scoring-signals process."; 177 178 @VisibleForTesting 179 static final String REPEATED_END_GET_TRUSTED_SCORING_SIGNALS = 180 "The logger has already set the end of the get-trusted-scoring-signals process."; 181 182 @VisibleForTesting 183 static final String REPEATED_START_SCORE_ADS = 184 "The logger has already set the start of the score-ads process."; 185 186 @VisibleForTesting 187 static final String MISSING_START_SCORE_ADS = 188 "The logger should set the start of the score-ads process."; 189 190 @VisibleForTesting 191 static final String REPEATED_END_SCORE_ADS = 192 "The logger has already set the end of the score-ads process."; 193 194 @VisibleForTesting 195 static final String REPEATED_START_GET_AD_SELECTION_LOGIC = 196 "The logger has already set the start of the get-ad-selection-logic process."; 197 198 @VisibleForTesting 199 static final String MISSING_GET_TRUSTED_SCORING_SIGNALS_PROCESS = 200 "The logger should set the get-trusted-scoring-signals process."; 201 202 @VisibleForTesting 203 static final String MISSING_END_SCORE_ADS = 204 "The logger should set the end of the score-ads process."; 205 206 @VisibleForTesting 207 static final String REPEATED_START_GET_AD_SCORES = 208 "The logger has already set the get-ad-scores progress."; 209 210 @VisibleForTesting 211 static final String MISSING_START_GET_AD_SCORES = 212 "The logger should set the start of the get-ad-scores process."; 213 214 @VisibleForTesting 215 static final String REPEATED_END_GET_AD_SCORES = 216 "The logger has already set the ned of the get-ad-scores process."; 217 218 @VisibleForTesting 219 static final String MISSING_END_GET_AD_SELECTION_LOGIC = 220 "The logger should set the end of the get-ad-selection-logic process."; 221 222 private final Context mContext; 223 private final long mBinderElapsedTimestamp; 224 225 // Bidding stage. 226 private long mBiddingStageStartTimestamp; 227 private long mGetBuyersCustomAudienceEndTimestamp; 228 private long mRunAdBiddingStartTimestamp; 229 private long mRunAdBiddingEndTimestamp; 230 private long mBiddingStageEndTimestamp; 231 private int mNumBuyersRequested; 232 private int mNumBuyersFetched; 233 private int mNumOfAdsEnteringBidding; 234 private int mNumOfCAsEnteringBidding; 235 private int mNumOfCAsPostBidding; 236 237 // Scoring stage. 238 private long mRunAdScoringStartTimestamp; 239 private int mNumOfCAsEnteringScoring; 240 private int mNumOfRmktAdsEnteringScoring; 241 private long mGetAdSelectionLogicStartTimestamp; 242 private long mGetAdSelectionLogicEndTimestamp; 243 private int mGetAdSelectionLogicScriptSizeInBytes; 244 private long mGetAdScoresStartTimestamp; 245 private long mGetTrustedScoringSignalsStartTimestamp; 246 private long mGetTrustedScoringSignalsEndTimestamp; 247 private int mFetchedTrustedScoringSignalsDataSizeInBytes; 248 private long mGetAdScoresEndTimestamp; 249 private long mScoreAdsStartTimestamp; 250 private long mScoreAdsEndTimestamp; 251 private long mRunAdScoringEndTimestamp; 252 253 // Persist ad selection. 254 private boolean mIsRemarketingAdsWon; 255 private long mPersistAdSelectionStartTimestamp; 256 private long mPersistAdSelectionEndTimestamp; 257 private long mDBAdSelectionSizeInBytes; 258 259 private AdServicesLogger mAdServicesLogger; 260 261 AdSelectionExecutionLogger( @onNull CallerMetadata callerMetadata, @NonNull Clock clock, @NonNull Context context, @NonNull AdServicesLogger adServicesLogger)262 public AdSelectionExecutionLogger( 263 @NonNull CallerMetadata callerMetadata, 264 @NonNull Clock clock, 265 @NonNull Context context, 266 @NonNull AdServicesLogger adServicesLogger) { 267 super(clock); 268 Objects.requireNonNull(callerMetadata); 269 Objects.requireNonNull(clock); 270 Objects.requireNonNull(context); 271 Objects.requireNonNull(adServicesLogger); 272 this.mBinderElapsedTimestamp = callerMetadata.getBinderElapsedTimestamp(); 273 this.mContext = context; 274 this.mAdServicesLogger = adServicesLogger; 275 sLogger.v("AdSelectionExecutionLogger starts."); 276 } 277 278 /** records the start state of a bidding process. */ startBiddingProcess(int numBuyersRequested)279 public void startBiddingProcess(int numBuyersRequested) throws IllegalStateException { 280 if (mBiddingStageStartTimestamp > 0L) { 281 throw new IllegalStateException(REPEATED_START_BIDDING_STAGE); 282 } 283 sLogger.v("Start the bidding process."); 284 this.mBiddingStageStartTimestamp = getServiceElapsedTimestamp(); 285 this.mNumBuyersRequested = numBuyersRequested; 286 sLogger.v("The bidding process start timestamp is %d", mBiddingStageStartTimestamp); 287 sLogger.v("With number of buyers requested: %d", mNumBuyersRequested); 288 } 289 290 /** records the end state of a successful get-buyers-custom-audience process. */ endGetBuyersCustomAudience(int numBuyersFetched)291 public void endGetBuyersCustomAudience(int numBuyersFetched) throws IllegalStateException { 292 if (mBiddingStageStartTimestamp == 0L) { 293 throw new IllegalStateException((MISSING_START_BIDDING_STAGE)); 294 } 295 if (mGetBuyersCustomAudienceEndTimestamp > 0L) { 296 throw new IllegalStateException(REPEATED_END_GET_BUYERS_CUSTOM_AUDIENCE); 297 } 298 sLogger.v("End the get-buyers-custom-audience process."); 299 this.mGetBuyersCustomAudienceEndTimestamp = getServiceElapsedTimestamp(); 300 this.mNumBuyersFetched = numBuyersFetched; 301 sLogger.v( 302 "The get-buyers-custom-audience process ends at %d with" 303 + " num of buyers fetched %d:", 304 mGetBuyersCustomAudienceEndTimestamp, mNumBuyersFetched); 305 } 306 307 /** records the start state of the run-ad-bidding process. */ startRunAdBidding(@onNull List<DBCustomAudience> customAudiences)308 public void startRunAdBidding(@NonNull List<DBCustomAudience> customAudiences) 309 throws IllegalStateException { 310 Objects.requireNonNull(customAudiences); 311 if (mBiddingStageStartTimestamp == 0L || mGetBuyersCustomAudienceEndTimestamp == 0L) { 312 throw new IllegalStateException(MISSING_GET_BUYERS_CUSTOM_AUDIENCE); 313 } 314 if (mRunAdBiddingStartTimestamp > 0L) { 315 throw new IllegalStateException(REPEATED_START_RUN_AD_BIDDING); 316 } 317 sLogger.v("Starts the run-ad-bidding process."); 318 this.mRunAdBiddingStartTimestamp = getServiceElapsedTimestamp(); 319 if (customAudiences.isEmpty()) return; 320 this.mNumOfAdsEnteringBidding = 321 customAudiences.stream() 322 .filter(a -> Objects.nonNull(a)) 323 .map(a -> a.getAds().size()) 324 .reduce(0, (a, b) -> a + b); 325 this.mNumOfCAsEnteringBidding = customAudiences.size(); 326 sLogger.v( 327 "Entering bidding NO of Ads: %d:, NO of CAs : %d", 328 mNumOfAdsEnteringBidding, mNumOfCAsEnteringBidding); 329 } 330 331 /** 332 * records the end state of the bidding process and log the generated {@link 333 * RunAdBiddingProcessReportedStats} into the {@link AdServicesLogger}. 334 */ endBiddingProcess(@ullable List<AdBiddingOutcome> result, int resultCode)335 public void endBiddingProcess(@Nullable List<AdBiddingOutcome> result, int resultCode) 336 throws IllegalStateException { 337 sLogger.v("End the BiddingProcess with resultCode %d.", resultCode); 338 // The start of the get-buyers-custom-audience must be set as the start of the bidding 339 // process. 340 if (mBiddingStageStartTimestamp == 0L) { 341 throw new IllegalStateException(MISSING_START_BIDDING_STAGE); 342 } 343 if (mBiddingStageEndTimestamp > 0L) { 344 throw new IllegalStateException(REPEATED_END_BIDDING_STAGE); 345 } 346 if (resultCode == STATUS_SUCCESS) { 347 // Throws IllegalStateException if the buyers-custom-audience process has not been 348 // set correctly. 349 if (mGetBuyersCustomAudienceEndTimestamp == 0L) { 350 throw new IllegalStateException(MISSING_END_GET_BUYERS_CUSTOM_AUDIENCE); 351 } else if (mRunAdBiddingStartTimestamp == 0L) { 352 throw new IllegalStateException(MISSING_START_RUN_AD_BIDDING); 353 } else if (mRunAdBiddingEndTimestamp > 0L || mBiddingStageEndTimestamp > 0L) { 354 throw new IllegalStateException(REPEATED_END_BIDDING_STAGE); 355 } 356 this.mRunAdBiddingEndTimestamp = getServiceElapsedTimestamp(); 357 this.mBiddingStageEndTimestamp = mRunAdBiddingEndTimestamp; 358 this.mNumOfCAsPostBidding = 359 result.stream() 360 .filter(Objects::nonNull) 361 .map(a -> a.getCustomAudienceBiddingInfo()) 362 .filter(Objects::nonNull) 363 .map(a -> a.getCustomAudienceSignals().hashCode()) 364 .collect(Collectors.toSet()) 365 .size(); 366 sLogger.v( 367 "Ends of a successful run-ad-bidding process with num of CAs post " 368 + "bidding %d. with end timestamp: %d ", 369 mNumOfCAsPostBidding, mRunAdBiddingEndTimestamp); 370 } else { 371 sLogger.v("Ends of a failed run-ad-bidding process."); 372 this.mBiddingStageEndTimestamp = getServiceElapsedTimestamp(); 373 } 374 sLogger.v("Log the AdRunBiddingProcessReportedStats to the AdServicesLog."); 375 RunAdBiddingProcessReportedStats runAdBiddingProcessReportedStats = 376 getRunAdBiddingProcessReportedStats(resultCode); 377 mAdServicesLogger.logRunAdBiddingProcessReportedStats(runAdBiddingProcessReportedStats); 378 } 379 380 /** start the run-ad-scoring process. */ startRunAdScoring(List<AdBiddingOutcome> adBiddingOutcomes)381 public void startRunAdScoring(List<AdBiddingOutcome> adBiddingOutcomes) 382 throws IllegalStateException { 383 if (mRunAdScoringStartTimestamp > 0L) { 384 throw new IllegalStateException(REPEATED_START_RUN_AD_SCORING); 385 } 386 sLogger.v("Start the run-ad-scoring process."); 387 this.mRunAdScoringStartTimestamp = getServiceElapsedTimestamp(); 388 this.mNumOfRmktAdsEnteringScoring = 389 adBiddingOutcomes.stream() 390 .filter(Objects::nonNull) 391 .map(AdBiddingOutcome::getAdWithBid) 392 .filter(Objects::nonNull) 393 .collect(Collectors.toSet()) 394 .size(); 395 this.mNumOfCAsEnteringScoring = 396 adBiddingOutcomes.stream() 397 .filter(Objects::nonNull) 398 .map(a -> a.getCustomAudienceBiddingInfo()) 399 .filter(Objects::nonNull) 400 .map(a -> a.getCustomAudienceSignals().hashCode()) 401 .collect(Collectors.toSet()) 402 .size(); 403 } 404 405 /** start the get-ad-selection-logic process. */ startGetAdSelectionLogic()406 public void startGetAdSelectionLogic() throws IllegalStateException { 407 if (mRunAdScoringStartTimestamp == 0L) { 408 throw new IllegalStateException(MISSING_START_RUN_AD_SCORING); 409 } 410 if (mGetAdSelectionLogicStartTimestamp > 0L) { 411 throw new IllegalStateException(REPEATED_START_GET_AD_SELECTION_LOGIC); 412 } 413 sLogger.v("Start the get-ad-selection-logic process."); 414 this.mGetAdSelectionLogicStartTimestamp = getServiceElapsedTimestamp(); 415 } 416 417 /** end a successful get-ad-selection-logic process. */ endGetAdSelectionLogic(@onNull String adSelectionLogic)418 public void endGetAdSelectionLogic(@NonNull String adSelectionLogic) 419 throws IllegalStateException { 420 if (mGetAdSelectionLogicStartTimestamp == 0L) { 421 throw new IllegalStateException(MISSING_START_GET_AD_SELECTION_LOGIC); 422 } 423 if (mGetAdSelectionLogicEndTimestamp > 0L) { 424 throw new IllegalStateException(REPEATED_END_GET_AD_SELECTION_LOGIC); 425 } 426 sLogger.v("End a successful get-ad-selection-logic process."); 427 this.mGetAdSelectionLogicScriptSizeInBytes = adSelectionLogic.getBytes().length; 428 this.mGetAdSelectionLogicEndTimestamp = getServiceElapsedTimestamp(); 429 } 430 431 /** start the get-ad-scores process. */ startGetAdScores()432 public void startGetAdScores() throws IllegalStateException { 433 if (mGetAdSelectionLogicEndTimestamp == 0L) { 434 throw new IllegalStateException(MISSING_END_GET_AD_SELECTION_LOGIC); 435 } 436 if (mGetAdScoresStartTimestamp > 0L) { 437 throw new IllegalStateException(REPEATED_START_GET_AD_SCORES); 438 } 439 sLogger.v("Start the get-ad-scores process."); 440 this.mGetAdScoresStartTimestamp = getServiceElapsedTimestamp(); 441 } 442 443 /** start the get-trusted-scoring-signals process. */ startGetTrustedScoringSignals()444 public void startGetTrustedScoringSignals() throws IllegalStateException { 445 if (mGetAdScoresStartTimestamp == 0L) { 446 throw new IllegalStateException(MISSING_START_GET_AD_SCORES); 447 } 448 if (mGetTrustedScoringSignalsStartTimestamp > 0L) { 449 throw new IllegalStateException(REPEATED_START_GET_TRUSTED_SCORING_SIGNALS); 450 } 451 sLogger.v("Starts the get-trusted-scoring-signals."); 452 this.mGetTrustedScoringSignalsStartTimestamp = getServiceElapsedTimestamp(); 453 } 454 455 /** end a successful get-trusted-scoring-signals process. */ endGetTrustedScoringSignals(@onNull AdSelectionSignals adSelectionSignals)456 public void endGetTrustedScoringSignals(@NonNull AdSelectionSignals adSelectionSignals) 457 throws IllegalStateException { 458 if (mGetTrustedScoringSignalsStartTimestamp == 0L) { 459 throw new IllegalStateException(MISSING_START_GET_TRUSTED_SCORING_SIGNALS); 460 } 461 if (mGetTrustedScoringSignalsEndTimestamp > 0L) { 462 throw new IllegalStateException(REPEATED_END_GET_TRUSTED_SCORING_SIGNALS); 463 } 464 sLogger.v("End a successful get-trusted-signals process."); 465 this.mFetchedTrustedScoringSignalsDataSizeInBytes = 466 adSelectionSignals.toString().getBytes().length; 467 this.mGetTrustedScoringSignalsEndTimestamp = getServiceElapsedTimestamp(); 468 } 469 470 /** start scoreAds script execution process. */ startScoreAds()471 public void startScoreAds() throws IllegalStateException { 472 if (mGetTrustedScoringSignalsEndTimestamp == 0L) { 473 throw new IllegalStateException(MISSING_GET_TRUSTED_SCORING_SIGNALS_PROCESS); 474 } 475 if (mScoreAdsStartTimestamp > 0L) { 476 throw new IllegalStateException(REPEATED_START_SCORE_ADS); 477 } 478 sLogger.v("Start the execution of the scoreAds script."); 479 this.mScoreAdsStartTimestamp = getServiceElapsedTimestamp(); 480 } 481 482 /** end a complete execution of the scoreAds script. */ endScoreAds()483 public void endScoreAds() throws IllegalStateException { 484 if (mScoreAdsStartTimestamp == 0L) throw new IllegalStateException(MISSING_START_SCORE_ADS); 485 if (mScoreAdsEndTimestamp > 0L) { 486 throw new IllegalStateException(REPEATED_END_SCORE_ADS); 487 } 488 sLogger.v("End the execution of the scoreAds script successfully."); 489 this.mScoreAdsEndTimestamp = getServiceElapsedTimestamp(); 490 } 491 492 /** end a successful get-ad-scores process. */ endGetAdScores()493 public void endGetAdScores() throws IllegalStateException { 494 if (mScoreAdsEndTimestamp == 0L) { 495 throw new IllegalStateException(MISSING_END_SCORE_ADS); 496 } 497 if (mGetAdScoresEndTimestamp > 0L) { 498 throw new IllegalStateException(REPEATED_END_GET_AD_SCORES); 499 } 500 sLogger.v("End the get-ad-scores process."); 501 this.mGetAdScoresEndTimestamp = getServiceElapsedTimestamp(); 502 } 503 504 /** 505 * end a run-ad-scoring process and log the {@link RunAdScoringProcessReportedStats} atom into 506 * the {@link AdServicesLogger}. 507 */ endRunAdScoring(int resultCode)508 public void endRunAdScoring(int resultCode) throws IllegalStateException { 509 if (mRunAdScoringStartTimestamp == 0L) { 510 throw new IllegalStateException(MISSING_START_RUN_AD_SCORING); 511 } 512 if (mRunAdScoringEndTimestamp > 0L) { 513 throw new IllegalStateException(REPEATED_END_RUN_AD_SCORING); 514 } 515 sLogger.v("End Running Ad Scoring."); 516 this.mRunAdScoringEndTimestamp = getServiceElapsedTimestamp(); 517 RunAdScoringProcessReportedStats runAdScoringProcessReportedStats = 518 getRunAdScoringProcessReportedStats(resultCode); 519 sLogger.v("Log the RunAdScoringProcessReportedStats into the AdServicesLogger."); 520 mAdServicesLogger.logRunAdScoringProcessReportedStats(runAdScoringProcessReportedStats); 521 } 522 523 /** records the start state of the persist-ad-selection process. */ startPersistAdSelection(DBAdSelection dbAdSelection)524 public void startPersistAdSelection(DBAdSelection dbAdSelection) throws IllegalStateException { 525 if (mPersistAdSelectionStartTimestamp > 0L) { 526 throw new IllegalStateException(REPEATED_START_PERSIST_AD_SELECTION); 527 } 528 sLogger.v("Starts the persisting ad selection."); 529 this.mIsRemarketingAdsWon = Objects.nonNull(dbAdSelection.getBiddingLogicUri()); 530 this.mPersistAdSelectionStartTimestamp = getServiceElapsedTimestamp(); 531 } 532 533 /** records the end state of a finished persist-ad-selection process. */ endPersistAdSelection()534 public void endPersistAdSelection() throws IllegalStateException { 535 if (mPersistAdSelectionStartTimestamp == 0L) { 536 throw new IllegalStateException(MISSING_START_PERSIST_AD_SELECTION); 537 } 538 if (mPersistAdSelectionEndTimestamp > 0L) { 539 throw new IllegalStateException(REPEATED_END_PERSIST_AD_SELECTION); 540 } 541 sLogger.v("Ends the persisting ad selection."); 542 this.mPersistAdSelectionEndTimestamp = getServiceElapsedTimestamp(); 543 this.mDBAdSelectionSizeInBytes = mContext.getDatabasePath(DATABASE_NAME).length(); 544 sLogger.v("The persistAdSelection end timestamp is %d:", mPersistAdSelectionEndTimestamp); 545 sLogger.v("The database file size is %d", mDBAdSelectionSizeInBytes); 546 } 547 548 /** 549 * This method should be called at the end of an ad selection process to generate and log the 550 * {@link RunAdSelectionProcessReportedStats} into the {@link AdServicesLogger}. 551 */ close(int resultCode)552 public void close(int resultCode) throws IllegalStateException { 553 sLogger.v("Log the RunAdSelectionProcessReportedStats to the AdServicesLog."); 554 if (resultCode == STATUS_SUCCESS) { 555 if (mPersistAdSelectionStartTimestamp == 0L 556 && mPersistAdSelectionEndTimestamp == 0L 557 && mDBAdSelectionSizeInBytes == 0L) { 558 throw new IllegalStateException(MISSING_PERSIST_AD_SELECTION); 559 } else if (mPersistAdSelectionEndTimestamp == 0L || mDBAdSelectionSizeInBytes == 0L) { 560 throw new IllegalStateException(MISSING_END_PERSIST_AD_SELECTION); 561 } 562 sLogger.v( 563 "Log RunAdSelectionProcessReportedStats for a successful ad selection " 564 + "run."); 565 } else { 566 sLogger.v("Log RunAdSelectionProcessReportedStats for a failed ad selection run."); 567 } 568 RunAdSelectionProcessReportedStats runAdSelectionProcessReportedStats = 569 getRunAdSelectionProcessReportedStats( 570 resultCode, getApiServiceInternalFinalLatencyInMs()); 571 mAdServicesLogger.logRunAdSelectionProcessReportedStats(runAdSelectionProcessReportedStats); 572 } 573 574 /** @return the overall latency in milliseconds of selectAds called by the client interface. */ getRunAdSelectionOverallLatencyInMs()575 public int getRunAdSelectionOverallLatencyInMs() { 576 return getBinderLatencyInMs(mBinderElapsedTimestamp) 577 + getApiServiceInternalFinalLatencyInMs(); 578 } 579 getRunAdSelectionProcessReportedStats( int runAdSelectionResultCode, int runAdSelectionLatencyInMs)580 private RunAdSelectionProcessReportedStats getRunAdSelectionProcessReportedStats( 581 int runAdSelectionResultCode, int runAdSelectionLatencyInMs) { 582 return RunAdSelectionProcessReportedStats.builder() 583 .setIsRemarketingAdsWon(mIsRemarketingAdsWon) 584 .setDBAdSelectionSizeInBytes(getDbAdSelectionSizeInBytes()) 585 .setPersistAdSelectionLatencyInMillis(getPersistAdSelectionLatencyInMs()) 586 .setPersistAdSelectionResultCode( 587 getPersistAdSelectionResultCode(runAdSelectionResultCode)) 588 .setRunAdSelectionLatencyInMillis(runAdSelectionLatencyInMs) 589 .setRunAdSelectionResultCode(runAdSelectionResultCode) 590 .build(); 591 } 592 getRunAdBiddingProcessReportedStats(int resultCode)593 private RunAdBiddingProcessReportedStats getRunAdBiddingProcessReportedStats(int resultCode) { 594 return RunAdBiddingProcessReportedStats.builder() 595 .setGetBuyersCustomAudienceLatencyInMills(getGetBuyersCustomAudienceLatencyInMs()) 596 .setGetBuyersCustomAudienceResultCode( 597 getGetBuyersCustomAudienceResultCode(resultCode)) 598 .setNumBuyersRequested(getNumBuyersRequested()) 599 .setNumBuyersFetched(getNumBuyersFetched()) 600 .setNumOfAdsEnteringBidding(getNumOfAdsEnteringBidding()) 601 .setNumOfCasEnteringBidding(getNumOfCAsEnteringBidding()) 602 .setNumOfCasPostBidding(getNumOfCAsPostBidding()) 603 .setRatioOfCasSelectingRmktAds(getRatioOfCasSelectingRmktAds()) 604 .setRunAdBiddingLatencyInMillis(getRunAdBiddingLatencyInMs()) 605 .setRunAdBiddingResultCode(getRunAdBiddingResultCode(resultCode)) 606 .setTotalAdBiddingStageLatencyInMillis(getTotalAdBiddingStageLatencyInMs()) 607 .build(); 608 } 609 getRunAdScoringProcessReportedStats(int resultCode)610 private RunAdScoringProcessReportedStats getRunAdScoringProcessReportedStats(int resultCode) { 611 return RunAdScoringProcessReportedStats.builder() 612 .setGetAdSelectionLogicLatencyInMillis(getAdSelectionLogicLatencyInMs()) 613 .setGetAdSelectionLogicResultCode(getGetAdSelectionLogicResultCode(resultCode)) 614 .setGetAdSelectionLogicScriptType(getGetAdSelectionLogicScriptType()) 615 .setFetchedAdSelectionLogicScriptSizeInBytes( 616 getFetchedAdSelectionLogicScriptSizeInBytes()) 617 .setGetTrustedScoringSignalsLatencyInMillis( 618 getGetTrustedScoringSignalsLatencyInMs()) 619 .setGetTrustedScoringSignalsResultCode( 620 getGetTrustedScoringSignalsResultCode(resultCode)) 621 .setFetchedTrustedScoringSignalsDataSizeInBytes( 622 getFetchedTrustedScoringSignalsDataSizeInBytes()) 623 .setScoreAdsLatencyInMillis(getScoreAdsLatencyInMs()) 624 .setGetAdScoresLatencyInMillis(getAdScoresLatencyInMs()) 625 .setGetAdScoresResultCode(getAdScoresResultCode(resultCode)) 626 .setNumOfCasEnteringScoring(getNumOfCAsEnteringScoring()) 627 .setNumOfRemarketingAdsEnteringScoring(getNumOfRemarketingAdsEnteringScoring()) 628 .setNumOfContextualAdsEnteringScoring(FIELD_UNSET) 629 .setRunAdScoringLatencyInMillis(getRunScoringLatencyInMs()) 630 .setRunAdScoringResultCode(resultCode) 631 .build(); 632 } 633 getGetAdSelectionLogicScriptType()634 private int getGetAdSelectionLogicScriptType() { 635 if (mGetAdSelectionLogicEndTimestamp > 0L) return SCRIPT_JAVASCRIPT; 636 return SCRIPT_UNSET; 637 } 638 getRunScoringLatencyInMs()639 private int getRunScoringLatencyInMs() { 640 if (mRunAdScoringStartTimestamp == 0L) { 641 return FIELD_UNSET; 642 } 643 return (int) (mRunAdScoringEndTimestamp - mRunAdScoringStartTimestamp); 644 } 645 getNumOfCAsEnteringScoring()646 private int getNumOfCAsEnteringScoring() { 647 if (mRunAdScoringStartTimestamp == 0L) { 648 return FIELD_UNSET; 649 } 650 return mNumOfCAsEnteringScoring; 651 } 652 getNumOfRemarketingAdsEnteringScoring()653 private int getNumOfRemarketingAdsEnteringScoring() { 654 if (mRunAdScoringStartTimestamp == 0L) { 655 return FIELD_UNSET; 656 } 657 return mNumOfRmktAdsEnteringScoring; 658 } 659 getAdScoresResultCode(int resultCode)660 private int getAdScoresResultCode(int resultCode) { 661 if (mGetAdScoresStartTimestamp == 0L) { 662 return FIELD_UNSET; 663 } 664 if (mGetAdScoresEndTimestamp == 0L) { 665 return resultCode; 666 } 667 return STATUS_SUCCESS; 668 } 669 getAdScoresLatencyInMs()670 private int getAdScoresLatencyInMs() { 671 if (mGetAdScoresStartTimestamp == 0L) { 672 return FIELD_UNSET; 673 } 674 if (mGetAdScoresEndTimestamp == 0L) { 675 return (int) (mRunAdScoringEndTimestamp - mGetAdScoresStartTimestamp); 676 } 677 return (int) (mGetAdScoresEndTimestamp - mGetAdScoresStartTimestamp); 678 } 679 getScoreAdsLatencyInMs()680 private int getScoreAdsLatencyInMs() { 681 if (mScoreAdsStartTimestamp == 0L) { 682 return FIELD_UNSET; 683 } else if (mScoreAdsEndTimestamp == 0L) { 684 return (int) (mRunAdScoringEndTimestamp - mScoreAdsStartTimestamp); 685 } 686 return (int) (mScoreAdsEndTimestamp - mScoreAdsStartTimestamp); 687 } 688 getFetchedTrustedScoringSignalsDataSizeInBytes()689 private int getFetchedTrustedScoringSignalsDataSizeInBytes() { 690 if (mGetTrustedScoringSignalsEndTimestamp > 0L) { 691 return mFetchedTrustedScoringSignalsDataSizeInBytes; 692 } 693 return FIELD_UNSET; 694 } 695 getGetTrustedScoringSignalsResultCode(int resultCode)696 private int getGetTrustedScoringSignalsResultCode(int resultCode) { 697 if (mGetTrustedScoringSignalsStartTimestamp == 0L) { 698 return FIELD_UNSET; 699 } else if (mGetTrustedScoringSignalsEndTimestamp > 0L) { 700 return STATUS_SUCCESS; 701 } 702 return resultCode; 703 } 704 getGetTrustedScoringSignalsLatencyInMs()705 private int getGetTrustedScoringSignalsLatencyInMs() { 706 if (mGetTrustedScoringSignalsStartTimestamp == 0L) { 707 return FIELD_UNSET; 708 } else if (mGetTrustedScoringSignalsEndTimestamp == 0L) { 709 return (int) (mRunAdScoringEndTimestamp - mGetTrustedScoringSignalsStartTimestamp); 710 } 711 return (int) 712 (mGetTrustedScoringSignalsEndTimestamp - mGetTrustedScoringSignalsStartTimestamp); 713 } 714 getFetchedAdSelectionLogicScriptSizeInBytes()715 private int getFetchedAdSelectionLogicScriptSizeInBytes() { 716 if (mGetAdSelectionLogicEndTimestamp > 0) { 717 return mGetAdSelectionLogicScriptSizeInBytes; 718 } 719 return FIELD_UNSET; 720 } 721 getGetAdSelectionLogicResultCode(int resultCode)722 private int getGetAdSelectionLogicResultCode(int resultCode) { 723 if (mGetAdSelectionLogicStartTimestamp == 0L) { 724 return FIELD_UNSET; 725 } else if (mGetAdSelectionLogicEndTimestamp > 0L) { 726 return STATUS_SUCCESS; 727 } 728 return resultCode; 729 } 730 getAdSelectionLogicLatencyInMs()731 private int getAdSelectionLogicLatencyInMs() { 732 if (mGetAdSelectionLogicStartTimestamp == 0L) { 733 return FIELD_UNSET; 734 } else if (mGetAdSelectionLogicEndTimestamp == 0L) { 735 return (int) (mRunAdScoringEndTimestamp - mGetAdSelectionLogicStartTimestamp); 736 } 737 return (int) (mGetAdSelectionLogicEndTimestamp - mGetAdSelectionLogicStartTimestamp); 738 } 739 getNumBuyersFetched()740 private int getNumBuyersFetched() { 741 if (mGetBuyersCustomAudienceEndTimestamp > 0L) { 742 return mNumBuyersFetched; 743 } 744 return FIELD_UNSET; 745 } 746 getNumBuyersRequested()747 private int getNumBuyersRequested() { 748 if (mBiddingStageStartTimestamp > 0L) { 749 return mNumBuyersRequested; 750 } 751 return FIELD_UNSET; 752 } 753 getNumOfAdsEnteringBidding()754 private int getNumOfAdsEnteringBidding() { 755 if (mRunAdBiddingStartTimestamp > 0L) { 756 return mNumOfAdsEnteringBidding; 757 } 758 return FIELD_UNSET; 759 } 760 getNumOfCAsEnteringBidding()761 private int getNumOfCAsEnteringBidding() { 762 if (mRunAdBiddingStartTimestamp > 0L) { 763 return mNumOfCAsEnteringBidding; 764 } 765 return FIELD_UNSET; 766 } 767 getNumOfCAsPostBidding()768 private int getNumOfCAsPostBidding() { 769 if (mRunAdBiddingEndTimestamp > 0L) { 770 return mNumOfCAsPostBidding; 771 } 772 return FIELD_UNSET; 773 } 774 getRatioOfCasSelectingRmktAds()775 private float getRatioOfCasSelectingRmktAds() { 776 if (mRunAdBiddingEndTimestamp > 0L) { 777 return ((float) mNumOfCAsPostBidding) / mNumOfCAsEnteringBidding; 778 } 779 return RATIO_OF_CAS_UNSET; 780 } 781 getDbAdSelectionSizeInBytes()782 private int getDbAdSelectionSizeInBytes() { 783 if (mPersistAdSelectionEndTimestamp > 0L) { 784 return (int) mDBAdSelectionSizeInBytes; 785 } 786 return FIELD_UNSET; 787 } 788 getGetBuyersCustomAudienceResultCode(int resultCode)789 private int getGetBuyersCustomAudienceResultCode(int resultCode) { 790 if (mBiddingStageStartTimestamp == 0) { 791 return FIELD_UNSET; 792 } 793 if (mGetBuyersCustomAudienceEndTimestamp > 0L) { 794 return STATUS_SUCCESS; 795 } 796 return resultCode; 797 } 798 getRunAdBiddingResultCode(int resultCode)799 private int getRunAdBiddingResultCode(int resultCode) { 800 if (mRunAdBiddingStartTimestamp == 0L) { 801 return FIELD_UNSET; 802 } else if (mRunAdBiddingEndTimestamp > 0L) { 803 return STATUS_SUCCESS; 804 } 805 return resultCode; 806 } 807 getPersistAdSelectionResultCode(int resultCode)808 private int getPersistAdSelectionResultCode(int resultCode) { 809 if (mPersistAdSelectionStartTimestamp == 0L) { 810 return FIELD_UNSET; 811 } else if (mPersistAdSelectionEndTimestamp > 0L) { 812 return STATUS_SUCCESS; 813 } 814 return resultCode; 815 } 816 817 /** 818 * @return the latency in milliseconds of the get-buyers-custom-audience process if started, 819 * otherwise the {@link AdServicesLoggerUtil#FIELD_UNSET}. 820 */ getGetBuyersCustomAudienceLatencyInMs()821 private int getGetBuyersCustomAudienceLatencyInMs() { 822 if (mBiddingStageStartTimestamp == 0L) { 823 return FIELD_UNSET; 824 } else if (mGetBuyersCustomAudienceEndTimestamp == 0L) { 825 return (int) (mBiddingStageEndTimestamp - mBiddingStageStartTimestamp); 826 } 827 return (int) (mGetBuyersCustomAudienceEndTimestamp - mBiddingStageStartTimestamp); 828 } 829 830 /** 831 * @return the latency in milliseconds of the run-ad-bidding process if started, otherwise the 832 * {@link AdServicesLoggerUtil#FIELD_UNSET}. 833 */ getRunAdBiddingLatencyInMs()834 private int getRunAdBiddingLatencyInMs() { 835 if (mRunAdBiddingStartTimestamp == 0L) { 836 return FIELD_UNSET; 837 } else if (mRunAdBiddingEndTimestamp == 0L) { 838 return (int) (mBiddingStageEndTimestamp - mRunAdBiddingStartTimestamp); 839 } 840 return (int) (mRunAdBiddingEndTimestamp - mRunAdBiddingStartTimestamp); 841 } 842 843 /** @return the total latency of ad bidding stage. */ getTotalAdBiddingStageLatencyInMs()844 private int getTotalAdBiddingStageLatencyInMs() { 845 if (mBiddingStageStartTimestamp == 0L) { 846 return FIELD_UNSET; 847 } 848 return (int) (mBiddingStageEndTimestamp - mBiddingStageStartTimestamp); 849 } 850 851 /** 852 * @return the latency in milliseconds of the persist-ad-selection process if started, otherwise 853 * the {@link AdServicesLoggerUtil#FIELD_UNSET}. 854 */ getPersistAdSelectionLatencyInMs()855 private int getPersistAdSelectionLatencyInMs() { 856 if (mPersistAdSelectionStartTimestamp == 0L) { 857 return FIELD_UNSET; 858 } else if (mPersistAdSelectionEndTimestamp == 0L) { 859 return (int) (getServiceElapsedTimestamp() - mPersistAdSelectionStartTimestamp); 860 } 861 return (int) (mPersistAdSelectionEndTimestamp - mPersistAdSelectionStartTimestamp); 862 } 863 getBinderLatencyInMs(long binderElapsedTimestamp)864 private int getBinderLatencyInMs(long binderElapsedTimestamp) { 865 return (int) (getStartElapsedTimestamp() - binderElapsedTimestamp) * 2; 866 } 867 } 868