Add instrumentation for AppCache-related crash when S13nSW is enabled.

Bug: 857005
Change-Id: Ib94a898048dfaa68dfc68cbaafd181980432df9a
Reviewed-on: https://chromium-review.googlesource.com/1119740Reviewed-by: Makoto Shimazu <shimazu@chromium.org>
Reviewed-by: Kinuko Yasuda <kinuko@chromium.org>
Commit-Queue: Matt Falkenhagen <falken@chromium.org>
Cr-Commit-Position: refs/heads/master@{#571813}

content/browser/appcache/appcache_navigation_handle_core.cc

@@ -9,10 +9,12 @@
 
 #include "base/bind.h"
 #include "base/lazy_instance.h"
+#include "base/strings/stringprintf.h"
 #include "content/browser/appcache/appcache_host.h"
 #include "content/browser/appcache/appcache_navigation_handle.h"
 #include "content/browser/appcache/appcache_service_impl.h"
 #include "content/browser/appcache/chrome_appcache_service.h"
+#include "content/common/service_worker/service_worker_utils.h"
 #include "content/public/browser/browser_thread.h"
 
 namespace {
@@ -36,6 +38,9 @@ AppCacheNavigationHandleCore::AppCacheNavigationHandleCore(
     : appcache_service_(appcache_service),
       appcache_host_id_(appcache_host_id),
       ui_handle_(ui_handle) {
+  if (ServiceWorkerUtils::IsServicificationEnabled())
+    debug_log_ = base::make_optional<std::vector<std::string>>();
+
   // The AppCacheNavigationHandleCore is created on the UI thread but
   // should only be accessed from the IO thread afterwards.
   DCHECK_CURRENTLY_ON(BrowserThread::UI);
@@ -56,6 +61,9 @@ void AppCacheNavigationHandleCore::Initialize() {
   DCHECK(g_appcache_handle_map.Get().find(appcache_host_id_) ==
          g_appcache_handle_map.Get().end());
   g_appcache_handle_map.Get()[appcache_host_id_] = this;
+
+  if (debug_log_)
+    debug_log_->emplace_back("Init:" + std::to_string(appcache_host_id_));
 }
 
 // static
@@ -66,7 +74,14 @@ std::unique_ptr<AppCacheHost> AppCacheNavigationHandleCore::GetPrecreatedHost(
   if (index != g_appcache_handle_map.Get().end()) {
     AppCacheNavigationHandleCore* instance = index->second;
     DCHECK(instance);
-    return std::move(instance->precreated_host_);
+    auto host = std::move(instance->precreated_host_);
+    if (instance->debug_log_) {
+      instance->debug_log_->emplace_back(
+          host ? base::StringPrintf("Get:id=%d,host=%d", host_id,
+                                    host->host_id())
+               : base::StringPrintf("Get:id=%d,host=null", host_id));
+    }
+    return host;
   }
   return std::unique_ptr<AppCacheHost>();
 }
@@ -75,6 +90,22 @@ AppCacheServiceImpl* AppCacheNavigationHandleCore::GetAppCacheService() {
   return static_cast<AppCacheServiceImpl*>(appcache_service_.get());
 }
 
+void AppCacheNavigationHandleCore::AddRequestToDebugLog(const GURL& url) {
+  DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  if (debug_log_)
+    debug_log_->emplace_back("Req:" + url.spec().substr(0, 64));
+}
+
+std::string AppCacheNavigationHandleCore::GetDebugLog() {
+  DCHECK_CURRENTLY_ON(BrowserThread::IO);
+  if (!debug_log_)
+    return "debug log is not enabled";
+  std::string log;
+  for (const auto& event : *debug_log_)
+    log += event + " ";
+  return log;
+}
+
 void AppCacheNavigationHandleCore::OnCacheSelected(int host_id,
                                                    const AppCacheInfo& info) {
   DCHECK(false);

content/browser/appcache/appcache_navigation_handle_core.h

@@ -6,6 +6,7 @@
 #define CONTENT_BROWSER_APPCACHE_APPCACHE_NAVIGATION_HANDLE_CORE_H_
 
 #include <memory>
+#include <sstream>
 
 #include "base/macros.h"
 #include "base/memory/ref_counted.h"
@@ -46,6 +47,9 @@ class AppCacheNavigationHandleCore : public AppCacheFrontend {
 
   AppCacheServiceImpl* GetAppCacheService();
 
+  void AddRequestToDebugLog(const GURL& url);
+  std::string GetDebugLog();
+
  protected:
   // AppCacheFrontend methods
   // We don't expect calls on the AppCacheFrontend methods while the
@@ -75,6 +79,9 @@ class AppCacheNavigationHandleCore : public AppCacheFrontend {
   int appcache_host_id_;
   base::WeakPtr<AppCacheNavigationHandle> ui_handle_;
 
+  // For https://crbug.com/857005.
+  base::Optional<std::vector<std::string>> debug_log_;
+
   DISALLOW_COPY_AND_ASSIGN(AppCacheNavigationHandleCore);
 };
 

content/browser/loader/resource_dispatcher_host_impl.cc

@@ -264,6 +264,14 @@ void LogBackForwardNavigationFlagsHistogram(int load_flags) {
     RecordCacheFlags(HISTOGRAM_DISABLE_CACHE);
 }
 
+// https://crbug.com/857005.
+void CrashOnNoAppCacheHost(const GURL& url,
+                           AppCacheNavigationHandleCore* core) {
+  DEBUG_ALIAS_FOR_GURL(debug_url, url);
+  DEBUG_ALIAS_FOR_CSTR(debug_log, core->GetDebugLog().c_str(), 1024);
+  CHECK(false);
+}
+
 }  // namespace
 
 class ResourceDispatcherHostImpl::ScheduledResourceRequestAdapter final
@@ -1706,6 +1714,11 @@ void ResourceDispatcherHostImpl::BeginNavigationRequest(
 
   // Have the appcache associate its extra info with the request.
   if (appcache_handle_core) {
+    appcache_handle_core->AddRequestToDebugLog(new_request->url());
+    if (!appcache_handle_core->host()) {
+      CrashOnNoAppCacheHost(new_request->url(), appcache_handle_core);
+      return;
+    }
     AppCacheInterceptor::SetExtraRequestInfoForHost(
         new_request.get(), appcache_handle_core->host(), resource_type, false);
   }

content/browser/service_worker/service_worker_controllee_request_handler.cc

@@ -316,10 +316,11 @@ void ServiceWorkerControlleeRequestHandler::
 
   const bool need_to_update = !force_update_started_ && registration &&
                               context_->force_update_on_page_load();
-
   if (provider_host_ && !need_to_update)
     provider_host_->SetAllowAssociation(true);
-  if (status != blink::SERVICE_WORKER_OK || !provider_host_ || !context_) {
+  if (status != blink::SERVICE_WORKER_OK) {
+    int fallback_reason = 0;
+    base::debug::Alias(&fallback_reason);
     url_job_->FallbackToNetwork();
     TRACE_EVENT_ASYNC_END1(
         "ServiceWorker",
@@ -329,9 +330,33 @@ void ServiceWorkerControlleeRequestHandler::
   }
   DCHECK(registration.get());
 
+  if (!provider_host_) {
+    int fallback_reason = 1;
+    base::debug::Alias(&fallback_reason);
+    url_job_->FallbackToNetwork();
+    TRACE_EVENT_ASYNC_END1(
+        "ServiceWorker",
+        "ServiceWorkerControlleeRequestHandler::PrepareForMainResource",
+        url_job_.get(), "Status", status);
+    return;
+  }
+
+  if (!context_) {
+    int fallback_reason = 2;
+    base::debug::Alias(&fallback_reason);
+    url_job_->FallbackToNetwork();
+    TRACE_EVENT_ASYNC_END1(
+        "ServiceWorker",
+        "ServiceWorkerControlleeRequestHandler::PrepareForMainResource",
+        url_job_.get(), "Status", status);
+    return;
+  }
+
   if (!GetContentClient()->browser()->AllowServiceWorker(
           registration->pattern(), provider_host_->topmost_frame_url(),
           resource_context_, provider_host_->web_contents_getter())) {
+    int fallback_reason = 3;
+    base::debug::Alias(&fallback_reason);
     url_job_->FallbackToNetwork();
     TRACE_EVENT_ASYNC_END2(
         "ServiceWorker",
@@ -343,6 +368,8 @@ void ServiceWorkerControlleeRequestHandler::
   if (!provider_host_->IsContextSecureForServiceWorker()) {
     // TODO(falken): Figure out a way to surface in the page's DevTools
     // console that the service worker was blocked for security.
+    int fallback_reason = 4;
+    base::debug::Alias(&fallback_reason);
     url_job_->FallbackToNetwork();
     TRACE_EVENT_ASYNC_END1(
         "ServiceWorker",
@@ -393,6 +420,8 @@ void ServiceWorkerControlleeRequestHandler::
 
   if (!active_version.get() ||
       active_version->status() != ServiceWorkerVersion::ACTIVATED) {
+    int fallback_reason = 5;
+    base::debug::Alias(&fallback_reason);
     url_job_->FallbackToNetwork();
     TRACE_EVENT_ASYNC_END2(
         "ServiceWorker",