Log messages regarding why app banners aren't displayed to the console

chrome/browser/banners/app_banner_data_fetcher.cc

Index: chrome/browser/banners/app_banner_data_fetcher.cc
diff --git a/chrome/browser/banners/app_banner_data_fetcher.cc b/chrome/browser/banners/app_banner_data_fetcher.cc
index 0fadc96e1887986533662a16c1fe3367d1c3195c..0911c949b1dea5c7e5896e09eb4b72cd02a20473 100644
--- a/chrome/browser/banners/app_banner_data_fetcher.cc
+++ b/chrome/browser/banners/app_banner_data_fetcher.cc
@@ -5,8 +5,10 @@
 #include "chrome/browser/banners/app_banner_data_fetcher.h"
 
 #include "base/bind.h"
+#include "base/command_line.h"

[benwells, 2015/05/11 08:08:40]

I don't think this include is needed now.

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

Done.

 #include "base/strings/string_util.h"
 #include "base/strings/utf_string_conversions.h"
+#include "chrome/browser/banners/app_banner_debug_log.h"
 #include "chrome/browser/banners/app_banner_metrics.h"
 #include "chrome/browser/banners/app_banner_settings_helper.h"
 #include "chrome/browser/bitmap_fetcher/bitmap_fetcher.h"
@@ -14,6 +16,7 @@
 #include "chrome/browser/infobars/infobar_service.h"
 #include "chrome/browser/manifest/manifest_icon_selector.h"
 #include "chrome/browser/profiles/profile.h"
+#include "chrome/common/chrome_switches.h"

[benwells, 2015/05/11 08:08:40]

This too.

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

Done.

 #include "chrome/common/render_messages.h"
 #include "components/infobars/core/infobar.h"
 #include "components/rappor/rappor_utils.h"
@@ -72,6 +75,7 @@ AppBannerDataFetcher::AppBannerDataFetcher(
       ideal_icon_size_(ideal_icon_size),
       weak_delegate_(delegate),
       is_active_(false),
+      log_err_(false),
       event_request_id_(-1) {
 }
 
@@ -140,13 +144,18 @@ void AppBannerDataFetcher::OnBannerPromptReply(
     int request_id,
     blink::WebAppBannerPromptReply reply) {
   content::WebContents* web_contents = GetWebContents();
-  if (!is_active_ || !web_contents || request_id != event_request_id_) {
+  if (!CheckFetcherIsStillAlive(web_contents, "user navigated") ||
+      request_id != event_request_id_) {
     Cancel();
     return;
   }
 
   // The renderer might have requested the prompt to be canceled.
   if (reply == blink::WebAppBannerPromptReply::Cancel) {
+    // TODO(mlamouri,benwells): we should probably record that to behave

[benwells, 2015/05/11 08:08:40]

This TODO has been removed, it must have come back in your rebase.

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

Done.

+    // differently with regard to showing the banner.
+    SendDebugMessage(web_contents,
+        "not shown: renderer has requested the banner prompt be cancelled");
     Cancel();
     return;
   }
@@ -231,7 +240,10 @@ void AppBannerDataFetcher::RecordDidShowBanner(const std::string& event_name) {
 void AppBannerDataFetcher::OnDidGetManifest(
     const content::Manifest& manifest) {
   content::WebContents* web_contents = GetWebContents();
-  if (!is_active_ || !web_contents || manifest.IsEmpty()) {
+  if (!CheckFetcherIsStillAlive(web_contents, "manifest checking") ||
+      manifest.IsEmpty()) {
+    if (manifest.IsEmpty())

[benwells, 2015/05/11 08:08:40]

This is a little convoluted. It would probably be nicer to pull the manifest
emptiness check out into a new if clause.

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

Done.

+      SendDebugMessage(web_contents, "not shown: manifest is empty");
     Cancel();
     return;
   }
@@ -246,7 +258,7 @@ void AppBannerDataFetcher::OnDidGetManifest(
     }
   }
 
-  if (!IsManifestValidForWebApp(manifest)) {
+  if (!IsManifestValidForWebApp(manifest, web_contents)) {
     Cancel();
     return;
   }
@@ -274,7 +286,7 @@ void AppBannerDataFetcher::OnDidGetManifest(
 void AppBannerDataFetcher::OnDidCheckHasServiceWorker(
     bool has_service_worker) {
   content::WebContents* web_contents = GetWebContents();
-  if (!is_active_ || !web_contents) {
+  if (!CheckFetcherIsStillAlive(web_contents, "service worker checking")) {
     Cancel();
     return;
   }
@@ -290,8 +302,14 @@ void AppBannerDataFetcher::OnDidCheckHasServiceWorker(
       FetchIcon(icon_url);
       return;
     }
+    SendDebugMessage(web_contents,
+                     "not shown: could not find icon specified in manifest");

[benwells, 2015/05/11 08:08:40]

I don't really understand how this could happen as I haven't looked at the
FindBestMatchingIcon code, but I'm guessing it shouldn't happen based on our
manifest checks.

Despite that, in its current form it sounds more like we couldn't download the
icon, so it should be rephrased as 'could not determine the best icon to use.'
or something.

[dominickn (DO NOT USE), 2015/05/12 07:41:30]

Done.

   } else {
     TrackDisplayEvent(DISPLAY_EVENT_LACKS_SERVICE_WORKER);
+    SendDebugMessage(web_contents,
+                     "not shown: no service worker detected. You may need to "
+                     "reload the page, or check that the manifest URL matches "
+                     "the page URL");

[benwells, 2015/05/11 08:08:40]

This error is great but could still be improved. The exact rules for how the
matching needs to work are kind of confusing. The matching is coded here:
https://code.google.com/p/chromium/codesearch#chromium/src/content/browser/se...

The rule is that the service worker that is registered for the current page
needs to also control the start URL from the manifest.

I think a message that captures this would be something like: 'no matching
service worker detected. You may need to reload the page, or check that the
service worker for the current page also controls the start URL from the
manifest.'

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

Done.

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

Done.

   }
 
   Cancel();
@@ -307,17 +325,21 @@ void AppBannerDataFetcher::OnFetchComplete(const GURL& url,
 
 void AppBannerDataFetcher::ShowBanner(const SkBitmap* icon) {
   content::WebContents* web_contents = GetWebContents();
-  if (!is_active_ || !web_contents || !icon) {
+  if (!CheckFetcherIsStillAlive(web_contents, "banner display") || !icon) {
+    if (!icon)
+      SendDebugMessage(web_contents, "not shown: no icon available to display");

[benwells, 2015/05/11 08:08:40]

Ditto about separating into two ifs.

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

Done.

     Cancel();
     return;
   }
 
   RecordCouldShowBanner();
   if (!CheckIfShouldShowBanner()) {
+    SendDebugMessage(web_contents, "not shown: engagement checks failed");

[benwells, 2015/05/11 08:08:40]

This one is tricky. The only way a message will get printed here is if the
banner has been added to the homescreen. As that might be confusing for
developers it would be good to be more specific about it, but I'd also add a
comment as it might not be obvious that this is the only case that can cause
debug output.

[dominickn (DO NOT USE), 2015/05/12 07:41:30]

Done.

     Cancel();
     return;
   }
 
+  SendDebugMessage(web_contents, "shown");

[benwells, 2015/05/11 08:08:40]

I don't think it is necessary to output this. This means the 'not shown' bit can
move into SendDebugMessage.

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

Done.

   app_icon_.reset(new SkBitmap(*icon));
   event_request_id_ = ++gCurrentRequestID;
   web_contents->GetMainFrame()->Send(
@@ -345,17 +367,42 @@ bool AppBannerDataFetcher::CheckIfShouldShowBanner() {
       web_contents, validated_url_, GetAppIdentifier(), GetCurrentTime());
 }
 
+bool AppBannerDataFetcher::CheckFetcherIsStillAlive(
+    content::WebContents* web_contents,
+    const std::string& section) {
+  if (!is_active_) {
+    SendDebugMessage(web_contents,
+                     "not shown: display pipeline halted before " + section);

[benwells, 2015/05/11 08:08:40]

This message is too detailed. Please update to something like 'the user
navigated before the banner could be shown.'. Also, the section is not needed.

[dominickn (DO NOT USE), 2015/05/12 07:41:30]

Done.

+    return false;
+  }
+  if (!web_contents)
+    return false;

[benwells, 2015/05/11 08:08:40]

For completeness a message here would be good, like 'web contents closed.'

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

But if the web_contents pointer doesn't exist, we can't actually log a message
to the console, because that requires a valid web_contents pointer.

+  return true;
+}
+
 // static
 bool AppBannerDataFetcher::IsManifestValidForWebApp(
-    const content::Manifest& manifest) {
-  if (manifest.IsEmpty())
+    const content::Manifest& manifest,
+    content::WebContents* web_contents) {
+  if (manifest.IsEmpty()) {
+    SendDebugMessage(web_contents, "not shown: manifest is empty");
     return false;
-  if (!manifest.start_url.is_valid())
+  }
+  if (!manifest.start_url.is_valid()) {
+    SendDebugMessage(web_contents,
+                     "not shown: start URL in manifest is not valid");
     return false;
-  if (manifest.name.is_null() && manifest.short_name.is_null())
+  }
+  if (manifest.name.is_null() && manifest.short_name.is_null()) {
+    SendDebugMessage(web_contents,
+                     "not shown: manifest name and short name are missing");

[benwells, 2015/05/11 08:08:40]

It would be good to capture in the error that only one of them needs to be
present. Something like 'one of manifest name or short name need to be
specified.'

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

Done.

     return false;
-  if (!DoesManifestContainRequiredIcon(manifest))
+  }
+  if (!DoesManifestContainRequiredIcon(manifest)) {
+    SendDebugMessage(web_contents,
+                     "not shown: manifest does not contain a suitable icon");

[benwells, 2015/05/11 08:08:40]

It would be good to capture more details about what a suitable icon is.

[dominickn (DO NOT USE), 2015/05/12 07:41:31]

Done.

     return false;
+  }
   return true;
 }