From 4c025b23da8b167c2fa056e9662bec8fd808ed71 Mon Sep 17 00:00:00 2001
From: Francis Tsui <ftsui@google.com>
Date: Wed, 27 Nov 2024 12:03:20 -0800
Subject: [PATCH] Add timing info for scanned advertisement decryption.

PiperOrigin-RevId: 700770034
---
 sharing/nearby_sharing_service_impl.cc | 24 +++++++++++++++---------
 sharing/nearby_sharing_service_impl.h  |  3 ++-
 2 files changed, 17 insertions(+), 10 deletions(-)

diff --git a/sharing/nearby_sharing_service_impl.cc b/sharing/nearby_sharing_service_impl.cc
index 73d55a55..88d9a926 100644
--- a/sharing/nearby_sharing_service_impl.cc
+++ b/sharing/nearby_sharing_service_impl.cc
@@ -1349,12 +1349,14 @@ void NearbySharingServiceImpl::OnEndpointDiscovered(
   // issue.
   std::vector<uint8_t> endpoint_info_copy{endpoint_info.begin(),
                                           endpoint_info.end()};
+  absl::Time start_time = context_->GetClock()->Now();
   RunOnNearbySharingServiceThread(
       "on_endpoint_discovered",
-      [this, endpoint_id = std::string(endpoint_id),
+      [this, start_time, endpoint_id = std::string(endpoint_id),
        endpoint_info_copy = std::move(endpoint_info_copy)]() {
-        AddEndpointDiscoveryEvent([this, endpoint_id, endpoint_info_copy]() {
-          HandleEndpointDiscovered(endpoint_id, endpoint_info_copy);
+        AddEndpointDiscoveryEvent([this, start_time, endpoint_id,
+                                   endpoint_info_copy]() {
+          HandleEndpointDiscovered(start_time, endpoint_id, endpoint_info_copy);
         });
       });
 }
@@ -1626,10 +1628,11 @@ void NearbySharingServiceImpl::AddEndpointDiscoveryEvent(
 }
 
 void NearbySharingServiceImpl::HandleEndpointDiscovered(
-    absl::string_view endpoint_id, absl::Span<const uint8_t> endpoint_info) {
+    absl::Time start_time, absl::string_view endpoint_id,
+    absl::Span<const uint8_t> endpoint_info) {
   VLOG(1) << __func__ << ": endpoint_id=" << endpoint_id
           << ", endpoint_info=" << nearby::utils::HexEncode(endpoint_info)
-          << " time: " << context_->GetClock()->Now();
+          << " time: " << start_time;
   if (!is_scanning_) {
     VLOG(1)
         << __func__
@@ -1673,15 +1676,18 @@ void NearbySharingServiceImpl::HandleEndpointDiscovered(
                                           endpoint_info.end()};
   GetCertificateManager()->GetDecryptedPublicCertificate(
       std::move(encrypted_metadata_key),
-      [this, endpoint_id_copy, endpoint_info_copy,
+      [this, start_time, endpoint_id_copy, endpoint_info_copy,
        advertisement_copy =
            *advertisement](std::optional<NearbyShareDecryptedPublicCertificate>
                                decrypted_public_certificate) {
         RunOnNearbySharingServiceThread(
             "outgoing_decrypted_certificate",
-            [this, endpoint_id_copy, endpoint_info_copy, advertisement_copy,
-             decrypted_public_certificate]() {
-              LOG(INFO) << __func__ << ": Decrypted public certificate";
+            [this, start_time, endpoint_id_copy, endpoint_info_copy,
+             advertisement_copy, decrypted_public_certificate]() {
+              absl::Time now = context_->GetClock()->Now();
+              LOG(INFO) << "Decrypted public certificate, success: "
+                        << decrypted_public_certificate.has_value()
+                        << ", latency: " << now - start_time;
               OnOutgoingDecryptedCertificate(
                   endpoint_id_copy, endpoint_info_copy, advertisement_copy,
                   decrypted_public_certificate);
diff --git a/sharing/nearby_sharing_service_impl.h b/sharing/nearby_sharing_service_impl.h
index 6dd8fa74..d5eb87f5 100644
--- a/sharing/nearby_sharing_service_impl.h
+++ b/sharing/nearby_sharing_service_impl.h
@@ -273,7 +273,8 @@ class NearbySharingServiceImpl
   // important because of the asynchronous steps required to process an
   // endpoint-discovered event.
   void AddEndpointDiscoveryEvent(std::function<void()> event);
-  void HandleEndpointDiscovered(absl::string_view endpoint_id,
+  void HandleEndpointDiscovered(absl::Time start_time,
+                                absl::string_view endpoint_id,
                                 absl::Span<const uint8_t> endpoint_info);
   void HandleEndpointLost(absl::string_view endpoint_id);
   void FinishEndpointDiscoveryEvent();