[Autofill Assistant] Add more logging for trigger scripts.

Bug: b/178098376
Change-Id: I10c80db6d54dc10c6b49d2ca48996c2271ef3d6a
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2642626Reviewed-by: Mathias Carlen <mcarlen@chromium.org>
Commit-Queue: Clemens Arbesser <arbesser@google.com>
Cr-Commit-Position: refs/heads/master@{#846080}

chrome/android/features/autofill_assistant/java/src/org/chromium/chrome/browser/autofill_assistant/AutofillAssistantModuleEntryImpl.java

@@ -18,6 +18,7 @@ import androidx.annotation.NonNull;
 import androidx.annotation.Nullable;
 
 import org.chromium.base.Callback;
+import org.chromium.base.Log;
 import org.chromium.base.annotations.UsedByReflection;
 import org.chromium.chrome.browser.ActivityTabProvider;
 import org.chromium.chrome.browser.autofill_assistant.metrics.LiteScriptFinishedState;
@@ -41,6 +42,9 @@ import java.util.Map;
  */
 @UsedByReflection("AutofillAssistantModuleEntryProvider.java")
 public class AutofillAssistantModuleEntryImpl implements AutofillAssistantModuleEntry {
+    /** Used for logging. */
+    private static final String TAG = "AutofillAssistant";
+
     @Override
     public void start(BottomSheetController bottomSheetController,
             BrowserControlsStateProvider browserControls, CompositorViewHolder compositorViewHolder,
@@ -55,6 +59,7 @@ public class AutofillAssistantModuleEntryImpl implements AutofillAssistantModule
                 // Opt-out users who have disabled the proactive help Chrome setting.
                 AutofillAssistantMetrics.recordLiteScriptStarted(
                         webContents, LiteScriptStarted.LITE_SCRIPT_PROACTIVE_TRIGGERING_DISABLED);
+                Log.v(TAG, "TriggerScript stopping: proactive help setting is turned off");
                 return;
             }
             if ((!TextUtils.isEmpty(parameters.get(PARAMETER_TRIGGER_FIRST_TIME_USER))
@@ -66,6 +71,10 @@ public class AutofillAssistantModuleEntryImpl implements AutofillAssistantModule
                 // off. The proactive help setting will appear disabled to the user.
                 AutofillAssistantMetrics.recordLiteScriptStarted(
                         webContents, LiteScriptStarted.LITE_SCRIPT_PROACTIVE_TRIGGERING_DISABLED);
+                Log.v(TAG,
+                        "TriggerScript stopping: MSBB is turned off, but required by at least one"
+                                + " script parameter (REQUEST_TRIGGER_SCRIPT, "
+                                + "TRIGGER_FIRST_TIME_USER, TRIGGER_RETURNING_USER)");
                 return;
             }
 

chrome/android/features/autofill_assistant/public/java/src/org/chromium/chrome/browser/autofill_assistant/AutofillAssistantFacade.java

@@ -13,6 +13,7 @@ import androidx.annotation.Nullable;
 
 import org.chromium.base.Callback;
 import org.chromium.base.FieldTrialList;
+import org.chromium.base.Log;
 import org.chromium.chrome.browser.ActivityTabProvider;
 import org.chromium.chrome.browser.app.ChromeActivity;
 import org.chromium.chrome.browser.autofill_assistant.metrics.DropOutReason;
@@ -30,6 +31,9 @@ import org.chromium.components.browser_ui.bottomsheet.BottomSheetControllerProvi
 
 /** Facade for starting Autofill Assistant on a custom tab. */
 public class AutofillAssistantFacade {
+    /** Used for logging. */
+    private static final String TAG = "AutofillAssistant";
+
     /**
      * Synthetic field trial names and group names should match those specified in
      * google3/analysis/uma/dashboards/
@@ -129,6 +133,7 @@ public class AutofillAssistantFacade {
                         AutofillAssistantMetrics.recordLiteScriptStarted(tab.getWebContents(),
                                 LiteScriptStarted.LITE_SCRIPT_CANCELED_TWO_TIMES);
                     }
+                    Log.v(TAG, "TriggerScript stopping: proactive help setting is turned off");
                     return;
                 }
 
@@ -138,6 +143,9 @@ public class AutofillAssistantFacade {
                         && !ChromeFeatureList.isEnabled(
                                 ChromeFeatureList
                                         .AUTOFILL_ASSISTANT_LOAD_DFM_FOR_TRIGGER_SCRIPTS)) {
+                    Log.v(TAG,
+                            "TriggerScript stopping: DFM module not available and on-demand"
+                                    + " installation is disabled.");
                     return;
                 }
             }
@@ -149,6 +157,7 @@ public class AutofillAssistantFacade {
                         if (arguments.containsTriggerScript()) {
                             AutofillAssistantMetrics.recordLiteScriptFinished(tab.getWebContents(),
                                     LiteScriptStarted.LITE_SCRIPT_DFM_UNAVAILABLE);
+                            Log.v(TAG, "TriggerScript stopping: failed to install DFM");
                         }
                         return;
                     }

components/autofill_assistant/browser/metrics.h

@@ -471,6 +471,101 @@ class Metrics {
         // Do not add default case to force compilation error for new values.
     }
     return out;
+#endif  // NDEBUG
+  }
+
+  friend std::ostream& operator<<(std::ostream& out,
+                                  const LiteScriptFinishedState& state) {
+#ifdef NDEBUG
+    // Non-debugging builds write the enum number.
+    out << static_cast<int>(state);
+    return out;
+#else
+    // Debugging builds write a string representation of |state|.
+    switch (state) {
+      case LiteScriptFinishedState::LITE_SCRIPT_GET_ACTIONS_FAILED:
+        out << "LITE_SCRIPT_GET_ACTIONS_FAILED";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_GET_ACTIONS_PARSE_ERROR:
+        out << "LITE_SCRIPT_GET_ACTIONS_PARSE_ERROR";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_PROMPT_FAILED_NAVIGATE:
+        out << "LITE_SCRIPT_PROMPT_FAILED_NAVIGATE";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_PROMPT_SUCCEEDED:
+        out << "LITE_SCRIPT_PROMPT_SUCCEEDED";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_PROMPT_FAILED_CANCEL_SESSION:
+        out << "LITE_SCRIPT_PROMPT_FAILED_CANCEL_SESSION";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_PROMPT_FAILED_CANCEL_FOREVER:
+        out << "LITE_SCRIPT_PROMPT_FAILED_CANCEL_FOREVER";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_TRIGGER_CONDITION_TIMEOUT:
+        out << "LITE_SCRIPT_TRIGGER_CONDITION_TIMEOUT";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_NAVIGATION_ERROR:
+        out << "LITE_SCRIPT_NAVIGATION_ERROR";
+        break;
+      case LiteScriptFinishedState::
+          LITE_SCRIPT_WEB_CONTENTS_DESTROYED_WHILE_VISIBLE:
+        out << "LITE_SCRIPT_WEB_CONTENTS_DESTROYED_WHILE_VISIBLE";
+        break;
+      case LiteScriptFinishedState::
+          LITE_SCRIPT_WEB_CONTENTS_DESTROYED_WHILE_INVISIBLE:
+        out << "LITE_SCRIPT_WEB_CONTENTS_DESTROYED_WHILE_INVISIBLE";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_NO_TRIGGER_SCRIPT_AVAILABLE:
+        out << "LITE_SCRIPT_NO_TRIGGER_SCRIPT_AVAILABLE";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_FAILED_TO_SHOW:
+        out << "LITE_SCRIPT_FAILED_TO_SHOW";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_DISABLED_PROACTIVE_HELP_SETTING:
+        out << "LITE_SCRIPT_DISABLED_PROACTIVE_HELP_SETTING";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_BASE64_DECODING_ERROR:
+        out << "LITE_SCRIPT_BASE64_DECODING_ERROR";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_BOTTOMSHEET_ONBOARDING_REJECTED:
+        out << "LITE_SCRIPT_BOTTOMSHEET_ONBOARDING_REJECTED";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_UNKNOWN_FAILURE:
+        out << "LITE_SCRIPT_UNKNOWN_FAILURE";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_SERVICE_DELETED:
+        out << "LITE_SCRIPT_SERVICE_DELETED";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_PATH_MISMATCH:
+        out << "LITE_SCRIPT_PATH_MISMATCH";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_UNSAFE_ACTIONS:
+        out << "LITE_SCRIPT_UNSAFE_ACTIONS";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_INVALID_SCRIPT:
+        out << "LITE_SCRIPT_INVALID_SCRIPT";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_BROWSE_FAILED_NAVIGATE:
+        out << "LITE_SCRIPT_BROWSE_FAILED_NAVIGATE";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_BROWSE_FAILED_OTHER:
+        out << "LITE_SCRIPT_BROWSE_FAILED_OTHER";
+        break;
+      case LiteScriptFinishedState::
+          LITE_SCRIPT_PROMPT_FAILED_CONDITION_NO_LONGER_TRUE:
+        out << "LITE_SCRIPT_PROMPT_FAILED_CONDITION_NO_LONGER_TRUE";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_PROMPT_FAILED_CLOSE:
+        out << "LITE_SCRIPT_PROMPT_FAILED_CLOSE";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_PROMPT_FAILED_OTHER:
+        out << "LITE_SCRIPT_PROMPT_FAILED_OTHER";
+        break;
+      case LiteScriptFinishedState::LITE_SCRIPT_PROMPT_SWIPE_DISMISSED:
+        out << "LITE_SCRIPT_PROMPT_SWIPE_DISMISSED";
+        // Do not add default case to force compilation error for new values.
+    }
+    return out;
 #endif  // NDEBUG
   }
 };

components/autofill_assistant/browser/trigger_scripts/trigger_script_coordinator.cc

@@ -249,6 +249,7 @@ void TriggerScriptCoordinator::OnProactiveHelpSettingChanged(
 }
 
 void TriggerScriptCoordinator::Stop(Metrics::LiteScriptFinishedState state) {
+  VLOG(2) << "Stopping with status " << state;
   HideTriggerScript();
   StopCheckingTriggerConditions();
   NotifyOnTriggerScriptFinished(state);
@@ -288,6 +289,14 @@ void TriggerScriptCoordinator::DidFinishNavigation(
   if (!url_utils::IsInDomainOrSubDomain(GetCurrentURL(), deeplink_url_) &&
       !url_utils::IsInDomainOrSubDomain(GetCurrentURL(),
                                         additional_allowed_domains_)) {
+#ifndef NDEBUG
+    VLOG(2) << "Unexpected navigation to " << GetCurrentURL();
+    VLOG(2) << "List of allowed domains:";
+    VLOG(2) << "\t" << deeplink_url_.host();
+    for (const auto& domain : additional_allowed_domains_) {
+      VLOG(2) << "\t" << domain;
+    }
+#endif
     Stop(Metrics::LiteScriptFinishedState::LITE_SCRIPT_PROMPT_FAILED_NAVIGATE);
     return;
   }
@@ -319,9 +328,11 @@ void TriggerScriptCoordinator::OnEffectiveVisibilityChanged() {
     // script that was shown before is still available, hence we need to fetch
     // it again.
     DCHECK(visible_trigger_script_ == -1);
+    VLOG(2) << "Restarting after tab became visible again";
     Start(deeplink_url_, std::move(trigger_context_));
   } else {
     // Hide UI on tab switch.
+    VLOG(2) << "Pausing after tab became invisible or non-interactable";
     StopCheckingTriggerConditions();
     HideTriggerScript();
   }
@@ -413,6 +424,7 @@ void TriggerScriptCoordinator::OnDynamicTriggerConditionsEvaluated(
     return;
   }
 
+  VLOG(3) << "Evaluating trigger conditions...";
   std::vector<bool> evaluated_trigger_conditions;
   for (const auto& trigger_script : trigger_scripts_) {
     evaluated_trigger_conditions.emplace_back(