[Payments] Add verbose logging to support debugging.

Verbose logging messages can be turned on with the following flags:
--enable-logging=stderr --vmodule=*/payments/*=2

Bug: 1130768
Change-Id: I9a76a9e7705d69a1f388ec3680b19ce1a46e261f
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2485538Reviewed-by: Sahel Sharify <sahel@chromium.org>
Commit-Queue: Danyao Wang <danyao@chromium.org>
Cr-Commit-Position: refs/heads/master@{#818984}

components/payments/content/payment_request.cc

@@ -10,6 +10,7 @@
 
 #include "base/bind.h"
 #include "base/feature_list.h"
+#include "base/logging.h"
 #include "base/stl_util.h"
 #include "base/strings/string_util.h"
 #include "components/payments/content/can_make_payment_query_factory.h"
@@ -68,7 +69,6 @@ mojom::PaymentAddressPtr RedactShippingAddress(
   address->address_line.clear();
   return address;
 }
-
 }  // namespace
 
 PaymentRequest::PaymentRequest(
@@ -221,6 +221,26 @@ void PaymentRequest::Init(
     delegate_->set_dialog_type(
         PaymentRequestDelegate::DialogType::SECURE_PAYMENT_CONFIRMATION);
   }
+
+  if (VLOG_IS_ON(2)) {
+    std::vector<std::string> payment_method_identifiers(
+        spec_->payment_method_identifiers_set().begin(),
+        spec_->payment_method_identifiers_set().end());
+    std::string total = spec_->details().total
+                            ? (spec_->details().total->amount->currency +
+                               spec_->details().total->amount->value)
+                            : "N/A";
+    VLOG(2) << "Initialized PaymentRequest (" << *spec_->details().id << ")"
+            << "\n    Top origin: " << top_level_origin_.spec()
+            << "\n    Frame origin: " << frame_origin_.spec()
+            << "\n    Requested methods: "
+            << base::JoinString(payment_method_identifiers, ", ")
+            << "\n    Total: " << total
+            << "\n    Options: shipping = " << spec_->request_shipping()
+            << ", name = " << spec_->request_payer_name()
+            << ", phone = " << spec_->request_payer_phone()
+            << ", email = " << spec_->request_payer_email();
+  }
 }
 
 void PaymentRequest::Show(bool is_user_gesture, bool wait_for_updated_details) {
@@ -311,6 +331,9 @@ void PaymentRequest::Retry(mojom::PaymentValidationErrorsPtr errors) {
     return;
   }
 
+  VLOG(2) << "PaymentRequest (" << *spec_->details().id
+          << ") retry with error: " << error;
+
   state()->SetAvailablePaymentAppForRetry();
   spec()->Retry(std::move(errors));
   display_handle_->Retry();
@@ -570,6 +593,8 @@ void PaymentRequest::AreRequestedMethodsSupportedCallback(
     if (SatisfiesSkipUIConstraints())
       Pay();
   } else {
+    VLOG(2) << "PaymentRequest (" << *spec_->details().id
+            << "): requested method not supported.";
     DCHECK(!has_recorded_completion_);
     has_recorded_completion_ = true;
     journey_logger_.SetNotShown(
@@ -799,6 +824,9 @@ void PaymentRequest::Pay() {
   journey_logger_.RecordCheckoutStep(
       JourneyLogger::CheckoutFunnelStep::kPaymentHandlerInvoked);
   DCHECK(state_->selected_app());
+  VLOG(2) << "PaymentRequest (" << *spec_->details().id
+          << "): paying with app: " << state_->selected_app()->GetLabel();
+
   state_->selected_app()->SetPaymentHandlerHost(
       payment_handler_host_->AsWeakPtr());
   state_->GeneratePaymentResponse();
@@ -836,6 +864,8 @@ void PaymentRequest::RecordFirstAbortReason(
 }
 
 void PaymentRequest::CanMakePaymentCallback(bool can_make_payment) {
+  VLOG(2) << "PaymentRequest (" << *spec_->details().id
+          << "): canMakePayment = " << can_make_payment;
   client_->OnCanMakePayment(
       can_make_payment ? mojom::CanMakePaymentQueryResult::CAN_MAKE_PAYMENT
                        : mojom::CanMakePaymentQueryResult::CANNOT_MAKE_PAYMENT);
@@ -852,6 +882,9 @@ void PaymentRequest::HasEnrolledInstrumentCallback(
   if (!rfh)
     return;
 
+  VLOG(2) << "PaymentRequest (" << *spec_->details().id
+          << "): hasEnrolledInstrument = " << has_enrolled_instrument;
+
   if (!spec_ || CanMakePaymentQueryFactory::GetInstance()
                     ->GetForContext(rfh->GetBrowserContext())
                     ->CanQuery(top_level_origin_, frame_origin_,
@@ -888,6 +921,8 @@ void PaymentRequest::RespondToHasEnrolledInstrumentQuery(
 }
 
 void PaymentRequest::OnAbortResult(bool aborted) {
+  VLOG(2) << "PaymentRequest (" << *spec_->details().id
+          << "): abort = " << aborted;
   if (client_.is_bound())
     client_->OnAbort(aborted);
 

third_party/blink/renderer/modules/payments/payment_request.cc

@@ -10,6 +10,7 @@
 
 #include "base/bind.h"
 #include "base/location.h"
+#include "base/logging.h"
 #include "base/stl_util.h"
 #include "build/build_config.h"
 #include "third_party/blink/public/common/browser_interface_broker_proxy.h"
@@ -831,6 +832,8 @@ ScriptPromise PaymentRequest::show(ScriptState* script_state,
     return ScriptPromise();
   }
 
+  VLOG(2) << "Renderer: PaymentRequest (" << id_.Utf8() << "): show()";
+
   UseCounter::Count(GetExecutionContext(), WebFeature::kPaymentRequestShow);
 
   is_waiting_for_show_promise_to_resolve_ = !details_promise.IsEmpty();
@@ -876,6 +879,8 @@ ScriptPromise PaymentRequest::abort(ScriptState* script_state,
     return ScriptPromise();
   }
 
+  VLOG(2) << "Renderer: PaymentRequest (" << id_.Utf8() << "): abort()";
+
   abort_resolver_ = MakeGarbageCollected<ScriptPromiseResolver>(script_state);
   payment_provider_->Abort();
   return abort_resolver_->Promise();
@@ -895,6 +900,9 @@ ScriptPromise PaymentRequest::canMakePayment(ScriptState* script_state,
     return ScriptPromise();
   }
 
+  VLOG(2) << "Renderer: PaymentRequest (" << id_.Utf8()
+          << "): canMakePayment()";
+
   payment_provider_->CanMakePayment();
 
   can_make_payment_resolver_ =
@@ -917,6 +925,9 @@ ScriptPromise PaymentRequest::hasEnrolledInstrument(
     return ScriptPromise();
   }
 
+  VLOG(2) << "Renderer: PaymentRequest (" << id_.Utf8()
+          << "): hasEnrolledInstrument()";
+
   payment_provider_->HasEnrolledInstrument();
 
   has_enrolled_instrument_resolver_ =
@@ -1222,6 +1233,8 @@ PaymentRequest::PaymentRequest(
   validated_details->id = id_ =
       details->hasId() ? details->id() : WTF::CreateCanonicalUUIDString();
 
+  VLOG(2) << "Renderer: New PaymentRequest (" << id_.Utf8() << ")";
+
   // This flag is set to true by ValidateAndConvertPaymentMethodData() if this
   // request is eligible for the Skip-to-GPay experimental flow and the GPay
   // payment method data has been patched to delegate shipping and contact

third_party/blink/renderer/modules/payments/payment_response.cc

@@ -4,6 +4,7 @@
 
 #include "third_party/blink/renderer/modules/payments/payment_response.h"
 
+#include "base/logging.h"
 #include "third_party/blink/renderer/bindings/core/v8/v8_binding_for_core.h"
 #include "third_party/blink/renderer/bindings/core/v8/v8_object_builder.h"
 #include "third_party/blink/renderer/bindings/modules/v8/v8_payment_validation_errors.h"
@@ -112,6 +113,8 @@ ScriptValue PaymentResponse::details(ScriptState* script_state) const {
 ScriptPromise PaymentResponse::complete(ScriptState* script_state,
                                         const String& result,
                                         ExceptionState& exception_state) {
+  VLOG(2) << "Renderer: PaymentRequest (" << requestId().Utf8()
+          << "): complete(" << result << ")";
   PaymentStateResolver::PaymentComplete converted_result =
       PaymentStateResolver::PaymentComplete::kUnknown;
   if (result == "success")
@@ -126,6 +129,7 @@ ScriptPromise PaymentResponse::retry(
     ScriptState* script_state,
     const PaymentValidationErrors* error_fields,
     ExceptionState& exception_state) {
+  VLOG(2) << "Renderer: PaymentRequest (" << requestId().Utf8() << "): retry()";
   return payment_state_resolver_->Retry(script_state, error_fields,
                                         exception_state);
 }