Add new logging for network resource loading
authorkrollin@apple.com <krollin@apple.com@268f45cc-cd09-0410-ab3c-d52691b4dbfc>
Wed, 21 Sep 2016 00:27:17 +0000 (00:27 +0000)
committerkrollin@apple.com <krollin@apple.com@268f45cc-cd09-0410-ab3c-d52691b4dbfc>
Wed, 21 Sep 2016 00:27:17 +0000 (00:27 +0000)
https://bugs.webkit.org/show_bug.cgi?id=162237

Reviewed by Antti Koivisto.

Add new logging along the non-main path for resource loading. This
logging should allow us to differentiate between lack-of-logging due
execution along a path that doesn't have logging statements and
lack-of-logging due to a hung process.

Source/WebCore:

No new tests -- there are no tests for logging.

* loader/DocumentLoader.cpp:
(WebCore::DocumentLoader::startLoadingMainResource):
(WebCore::DocumentLoader::isAlwaysOnLoggingAllowed):
* loader/DocumentLoader.h:
* loader/FrameLoader.cpp:
(WebCore::FrameLoader::continueLoadAfterWillSubmitForm):
* loader/cache/CachedResource.cpp:
(WebCore::CachedResource::load):
* loader/cache/CachedResourceLoader.cpp:
(WebCore::CachedResourceLoader::requestResource):
(WebCore::CachedResourceLoader::isAlwaysOnLoggingAllowed):
* loader/cache/CachedResourceLoader.h:
* page/Frame.h:

Source/WebKit2:

* NetworkProcess/NetworkResourceLoader.cpp:
(WebKit::NetworkResourceLoader::start):
(WebKit::NetworkResourceLoader::startNetworkLoad):
(WebKit::NetworkResourceLoader::setDefersLoading):
(WebKit::NetworkResourceLoader::abort):
(WebKit::NetworkResourceLoader::didReceiveBuffer):
* NetworkProcess/NetworkResourceLoader.h:
* WebProcess/Network/WebLoaderStrategy.cpp:
(WebKit::WebLoaderStrategy::loadResource):
(WebKit::WebLoaderStrategy::scheduleLoad):

git-svn-id: https://svn.webkit.org/repository/webkit/trunk@206189 268f45cc-cd09-0410-ab3c-d52691b4dbfc

12 files changed:
Source/WebCore/ChangeLog
Source/WebCore/loader/DocumentLoader.cpp
Source/WebCore/loader/DocumentLoader.h
Source/WebCore/loader/FrameLoader.cpp
Source/WebCore/loader/cache/CachedResource.cpp
Source/WebCore/loader/cache/CachedResourceLoader.cpp
Source/WebCore/loader/cache/CachedResourceLoader.h
Source/WebCore/page/Frame.h
Source/WebKit2/ChangeLog
Source/WebKit2/NetworkProcess/NetworkResourceLoader.cpp
Source/WebKit2/NetworkProcess/NetworkResourceLoader.h
Source/WebKit2/WebProcess/Network/WebLoaderStrategy.cpp

index e943502..2beb0ee 100644 (file)
@@ -1,3 +1,31 @@
+2016-09-20  Keith Rollin  <krollin@apple.com>
+
+        Add new logging for network resource loading
+        https://bugs.webkit.org/show_bug.cgi?id=162237
+
+        Reviewed by Antti Koivisto.
+
+        Add new logging along the non-main path for resource loading. This
+        logging should allow us to differentiate between lack-of-logging due
+        execution along a path that doesn't have logging statements and
+        lack-of-logging due to a hung process.
+
+        No new tests -- there are no tests for logging.
+
+        * loader/DocumentLoader.cpp:
+        (WebCore::DocumentLoader::startLoadingMainResource):
+        (WebCore::DocumentLoader::isAlwaysOnLoggingAllowed):
+        * loader/DocumentLoader.h:
+        * loader/FrameLoader.cpp:
+        (WebCore::FrameLoader::continueLoadAfterWillSubmitForm):
+        * loader/cache/CachedResource.cpp:
+        (WebCore::CachedResource::load):
+        * loader/cache/CachedResourceLoader.cpp:
+        (WebCore::CachedResourceLoader::requestResource):
+        (WebCore::CachedResourceLoader::isAlwaysOnLoggingAllowed):
+        * loader/cache/CachedResourceLoader.h:
+        * page/Frame.h:
+
 2016-09-20  Zalan Bujtas  <zalan@apple.com>
 
         REGRESSION (r204552): Athlete search on Strava gives bad rendering.
index 5c80a6a..58265c6 100644 (file)
@@ -81,6 +81,8 @@
 #include "ContentFilter.h"
 #endif
 
+#define RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(isAlwaysOnLoggingAllowed(), Network, "%p - DocumentLoader::" fmt, this, ##__VA_ARGS__)
+
 namespace WebCore {
 
 static void cancelAll(const ResourceLoaderMap& loaders)
@@ -1471,8 +1473,10 @@ void DocumentLoader::startLoadingMainResource()
     ASSERT(!m_loadingMainResource);
     m_loadingMainResource = true;
 
-    if (maybeLoadEmpty())
+    if (maybeLoadEmpty()) {
+        RELEASE_LOG_IF_ALLOWED("startLoadingMainResource: Returning empty document (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
         return;
+    }
 
 #if ENABLE(CONTENT_FILTERING)
     m_contentFilter = !m_substituteData.isValid() ? ContentFilter::create(*this) : nullptr;
@@ -1491,12 +1495,15 @@ void DocumentLoader::startLoadingMainResource()
     willSendRequest(m_request, ResourceResponse());
 
     // willSendRequest() may lead to our Frame being detached or cancelling the load via nulling the ResourceRequest.
-    if (!m_frame || m_request.isNull())
+    if (!m_frame || m_request.isNull()) {
+        RELEASE_LOG_IF_ALLOWED("startLoadingMainResource: Load canceled after willSendRequest (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
         return;
+    }
 
     m_applicationCacheHost->maybeLoadMainResource(m_request, m_substituteData);
 
     if (m_substituteData.isValid() && m_frame->page()) {
+        RELEASE_LOG_IF_ALLOWED("startLoadingMainResource: Returning cached main resource (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
         m_identifierForLoadWithoutResourceLoader = m_frame->page()->progress().createUniqueIdentifier();
         frameLoader()->notifier().assignIdentifierToInitialRequest(m_identifierForLoadWithoutResourceLoader, this, m_request);
         frameLoader()->notifier().dispatchWillSendRequest(this, m_identifierForLoadWithoutResourceLoader, m_request, ResourceResponse());
@@ -1509,11 +1516,14 @@ void DocumentLoader::startLoadingMainResource()
     // If this is a reload the cache layer might have made the previous request conditional. DocumentLoader can't handle 304 responses itself.
     request.makeUnconditional();
 
+    RELEASE_LOG_IF_ALLOWED("startLoadingMainResource: Starting load (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
+
     static NeverDestroyed<ResourceLoaderOptions> mainResourceLoadOptions(SendCallbacks, SniffContent, BufferData, AllowStoredCredentials, ClientCredentialPolicy::MayAskClientForCredentials, FetchOptions::Credentials::Include, SkipSecurityCheck, FetchOptions::Mode::NoCors, IncludeCertificateInfo, ContentSecurityPolicyImposition::DoPolicyCheck, DefersLoadingPolicy::AllowDefersLoading, CachingPolicy::AllowCaching);
     m_mainResource = m_cachedResourceLoader->requestMainResource(CachedResourceRequest(ResourceRequest(request), mainResourceLoadOptions));
 
 #if ENABLE(CONTENT_EXTENSIONS)
     if (m_mainResource && m_mainResource->errorOccurred() && m_frame->page() && m_mainResource->resourceError().domain() == ContentExtensions::WebKitContentBlockerDomain) {
+        RELEASE_LOG_IF_ALLOWED("startLoadingMainResource: Blocked by content blocker error (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
         cancelMainResourceLoad(frameLoader()->blockedByContentBlockerError(m_request));
         return;
     }
@@ -1521,10 +1531,13 @@ void DocumentLoader::startLoadingMainResource()
 
     if (!m_mainResource) {
         if (!m_request.url().isValid()) {
+            RELEASE_LOG_IF_ALLOWED("startLoadingMainResource: Unable to load main resource, URL is invalid (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
             cancelMainResourceLoad(frameLoader()->client().cannotShowURLError(m_request));
             return;
         }
 
+        RELEASE_LOG_IF_ALLOWED("startLoadingMainResource: Unable to load main resource, returning empty document (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
+
         setRequest(ResourceRequest());
         // If the load was aborted by clearing m_request, it's possible the ApplicationCacheHost
         // is now in a state where starting an empty load will be inconsistent. Replace it with
@@ -1711,4 +1724,9 @@ ContentFilter* DocumentLoader::contentFilter() const
 }
 #endif
 
+bool DocumentLoader::isAlwaysOnLoggingAllowed() const
+{
+    return m_frame ? m_frame->isAlwaysOnLoggingAllowed() : true;
+}
+
 } // namespace WebCore
index 7095447..bfd8787 100644 (file)
@@ -286,6 +286,8 @@ namespace WebCore {
         ContentFilter* contentFilter() const;
 #endif
 
+        bool isAlwaysOnLoggingAllowed() const;
+
     protected:
         WEBCORE_EXPORT DocumentLoader(const ResourceRequest&, const SubstituteData&);
 
index 1f431f3..0cdb4b0 100644 (file)
@@ -2360,12 +2360,16 @@ void FrameLoader::continueLoadAfterWillSubmitForm()
     
     // The load might be cancelled inside of prepareForLoadStart(), nulling out the m_provisionalDocumentLoader, 
     // so we need to null check it again.
-    if (!m_provisionalDocumentLoader)
+    if (!m_provisionalDocumentLoader) {
+        RELEASE_LOG_IF_ALLOWED("continueLoadAfterWillSubmitForm: Frame load canceled (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
         return;
+    }
 
     DocumentLoader* activeDocLoader = activeDocumentLoader();
-    if (activeDocLoader && activeDocLoader->isLoadingMainResource())
+    if (activeDocLoader && activeDocLoader->isLoadingMainResource()) {
+        RELEASE_LOG_IF_ALLOWED("continueLoadAfterWillSubmitForm: Main frame already being loaded (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
         return;
+    }
 
     m_loadingFromCachedPage = false;
     m_provisionalDocumentLoader->startLoadingMainResource();
index 373fde5..9fef2c6 100644 (file)
@@ -62,6 +62,8 @@
 
 using namespace WTF;
 
+#define RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(cachedResourceLoader.isAlwaysOnLoggingAllowed(), Network, "%p - CachedResource::" fmt, this, ##__VA_ARGS__)
+
 namespace WebCore {
 
 ResourceLoadPriority CachedResource::defaultPriorityForResourceType(Type type)
@@ -263,6 +265,7 @@ void CachedResource::computeOrigin(CachedResourceLoader& loader)
 void CachedResource::load(CachedResourceLoader& cachedResourceLoader)
 {
     if (!cachedResourceLoader.frame()) {
+        RELEASE_LOG_IF_ALLOWED("load: No associated frame");
         failBeforeStarting();
         return;
     }
@@ -274,6 +277,7 @@ void CachedResource::load(CachedResourceLoader& cachedResourceLoader)
     // cache.
     if (auto* topDocument = frame.mainFrame().document()) {
         if (topDocument->pageCacheState() != Document::NotInPageCache) {
+            RELEASE_LOG_IF_ALLOWED("load: Already in page cache or being added to it (frame = %p)", &frame);
             failBeforeStarting();
             return;
         }
@@ -281,6 +285,12 @@ void CachedResource::load(CachedResourceLoader& cachedResourceLoader)
 
     FrameLoader& frameLoader = frame.loader();
     if (m_options.securityCheck == DoSecurityCheck && (frameLoader.state() == FrameStateProvisional || !frameLoader.activeDocumentLoader() || frameLoader.activeDocumentLoader()->isStopping())) {
+        if (frameLoader.state() == FrameStateProvisional)
+            RELEASE_LOG_IF_ALLOWED("load: Failed security check -- state is provisional (frame = %p)", &frame);
+        else if (!frameLoader.activeDocumentLoader())
+            RELEASE_LOG_IF_ALLOWED("load: Failed security check -- not active document (frame = %p)", &frame);
+        else if (frameLoader.activeDocumentLoader()->isStopping())
+            RELEASE_LOG_IF_ALLOWED("load: Failed security check -- active loader is stopping (frame = %p)", &frame);
         failBeforeStarting();
         return;
     }
@@ -337,6 +347,7 @@ void CachedResource::load(CachedResourceLoader& cachedResourceLoader)
 
     m_loader = platformStrategies()->loaderStrategy()->loadResource(frame, *this, request, m_options);
     if (!m_loader) {
+        RELEASE_LOG_IF_ALLOWED("load: Unable to create SubresourceLoader (frame = %p)", &frame);
         failBeforeStarting();
         return;
     }
index ac02725..f692c2d 100644 (file)
@@ -80,6 +80,8 @@
 
 #define PRELOAD_DEBUG 0
 
+#define RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(isAlwaysOnLoggingAllowed(), Network, "%p - CachedResourceLoader::" fmt, this, ##__VA_ARGS__)
+
 namespace WebCore {
 
 static CachedResource* createResource(CachedResource::Type type, CachedResourceRequest&& request, SessionID sessionID)
@@ -607,11 +609,15 @@ CachedResourceHandle<CachedResource> CachedResourceLoader::requestResource(Cache
     // If only the fragment identifiers differ, it is the same resource.
     url = MemoryCache::removeFragmentIdentifierIfNeeded(url);
 
-    if (!url.isValid())
+    if (!url.isValid()) {
+        RELEASE_LOG_IF_ALLOWED("requestResource: URL is invalid (frame = %p)", frame());
         return nullptr;
+    }
 
-    if (!canRequest(type, url, request.options(), request.forPreload()))
+    if (!canRequest(type, url, request.options(), request.forPreload())) {
+        RELEASE_LOG_IF_ALLOWED("requestResource: Not allowed to request resource (frame = %p)", frame());
         return nullptr;
+    }
 
 #if ENABLE(CONTENT_EXTENSIONS)
     if (frame() && frame()->mainFrame().page() && m_documentLoader) {
@@ -619,6 +625,7 @@ CachedResourceHandle<CachedResource> CachedResourceLoader::requestResource(Cache
         auto blockedStatus = frame()->mainFrame().page()->userContentProvider().processContentExtensionRulesForLoad(resourceRequest.url(), toResourceType(type), *m_documentLoader);
         applyBlockedStatusToRequest(blockedStatus, resourceRequest);
         if (blockedStatus.blockedLoad) {
+            RELEASE_LOG_IF_ALLOWED("requestResource: Resource blocked by content blocker (frame = %p)", frame());
             if (type == CachedResource::Type::MainResource) {
                 auto resource = createResource(type, WTFMove(request), sessionID());
                 ASSERT(resource);
@@ -1290,4 +1297,9 @@ const ResourceLoaderOptions& CachedResourceLoader::defaultCachedResourceOptions(
     return options;
 }
 
+bool CachedResourceLoader::isAlwaysOnLoggingAllowed() const
+{
+    return m_documentLoader ? m_documentLoader->isAlwaysOnLoggingAllowed() : true;
+}
+
 }
index 5af71d2..1da241a 100644 (file)
@@ -145,6 +145,8 @@ public:
     ResourceTimingInformation& resourceTimingInformation() { return m_resourceTimingInfo; }
 #endif
 
+    bool isAlwaysOnLoggingAllowed() const;
+
 private:
     explicit CachedResourceLoader(DocumentLoader*);
 
index f8aaabe..abf8368 100644 (file)
@@ -264,7 +264,7 @@ namespace WebCore {
         bool activeDOMObjectsAndAnimationsSuspended() const { return m_activeDOMObjectsAndAnimationsSuspendedCount > 0; }
 
         bool isURLAllowed(const URL&) const;
-        bool isAlwaysOnLoggingAllowed() const;
+        WEBCORE_EXPORT bool isAlwaysOnLoggingAllowed() const;
 
     // ========
 
index 0721326..6cd22d8 100644 (file)
@@ -1,3 +1,26 @@
+2016-09-20  Keith Rollin  <krollin@apple.com>
+
+        Add new logging for network resource loading
+        https://bugs.webkit.org/show_bug.cgi?id=162237
+
+        Reviewed by Antti Koivisto.
+
+        Add new logging along the non-main path for resource loading. This
+        logging should allow us to differentiate between lack-of-logging due
+        execution along a path that doesn't have logging statements and
+        lack-of-logging due to a hung process.
+
+        * NetworkProcess/NetworkResourceLoader.cpp:
+        (WebKit::NetworkResourceLoader::start):
+        (WebKit::NetworkResourceLoader::startNetworkLoad):
+        (WebKit::NetworkResourceLoader::setDefersLoading):
+        (WebKit::NetworkResourceLoader::abort):
+        (WebKit::NetworkResourceLoader::didReceiveBuffer):
+        * NetworkProcess/NetworkResourceLoader.h:
+        * WebProcess/Network/WebLoaderStrategy.cpp:
+        (WebKit::WebLoaderStrategy::loadResource):
+        (WebKit::WebLoaderStrategy::scheduleLoad):
+
 2016-09-20  Anders Carlsson  <andersca@apple.com>
 
         Can't present a payment sheet if a sheet is already active in another window
index 5761ca1..dc9dbef 100644 (file)
@@ -148,11 +148,14 @@ void NetworkResourceLoader::start()
 {
     ASSERT(RunLoop::isMain());
 
-    if (m_defersLoading)
+    if (m_defersLoading) {
+        RELEASE_LOG_IF_ALLOWED("start: Loading is deferred (pageID = %llu, frameID = %llu, resourceID = %llu, isMainResource = %d, isSynchronous = %d)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier, isMainResource(), isSynchronous());
         return;
+    }
 
 #if ENABLE(NETWORK_CACHE)
     if (canUseCache(originalRequest())) {
+        RELEASE_LOG_IF_ALLOWED("start: Retrieving resource from cache (pageID = %llu, frameID = %llu, resourceID = %llu, isMainResource = %d, isSynchronous = %d)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier, isMainResource(), isSynchronous());
         retrieveCacheEntry(originalRequest());
         return;
     }
@@ -195,6 +198,8 @@ void NetworkResourceLoader::retrieveCacheEntry(const ResourceRequest& request)
 
 void NetworkResourceLoader::startNetworkLoad(const ResourceRequest& request)
 {
+    RELEASE_LOG_IF_ALLOWED("startNetworkLoad: (pageID = %llu, frameID = %llu, resourceID = %llu, isMainResource = %d, isSynchronous = %d)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier, isMainResource(), isSynchronous());
+
     consumeSandboxExtensions();
 
     if (isSynchronous() || m_parameters.maximumBufferingTime > 0ms)
@@ -205,8 +210,6 @@ void NetworkResourceLoader::startNetworkLoad(const ResourceRequest& request)
         m_bufferedDataForCache = SharedBuffer::create();
 #endif
 
-    RELEASE_LOG_IF_ALLOWED("startNetworkLoad: (pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d)", m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous());
-
     NetworkLoadParameters parameters = m_parameters;
     parameters.defersLoading = m_defersLoading;
     parameters.request = request;
@@ -215,6 +218,7 @@ void NetworkResourceLoader::startNetworkLoad(const ResourceRequest& request)
     auto* networkSession = SessionTracker::networkSession(parameters.sessionID);
     if (!networkSession) {
         WTFLogAlways("Attempted to create a NetworkLoad with a session (id=%" PRIu64 ") that does not exist.", parameters.sessionID.sessionID());
+        RELEASE_LOG_IF_ALLOWED("startNetworkLoad: Attempted to create a NetworkLoad with a session that does not exist (pageID = %llu, frameID = %llu, resourceID = %llu, sessionID=%llu)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier, parameters.sessionID.sessionID());
         didFailLoading(internalError(request.url()));
         return;
     }
@@ -222,6 +226,11 @@ void NetworkResourceLoader::startNetworkLoad(const ResourceRequest& request)
 #else
     m_networkLoad = std::make_unique<NetworkLoad>(*this, WTFMove(parameters));
 #endif
+
+    if (m_defersLoading) {
+        RELEASE_LOG_IF_ALLOWED("startNetworkLoad: Created, but deferred (pageID = %llu, frameID = %llu, resourceID = %llu)",
+            m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier);
+    }
 }
 
 void NetworkResourceLoader::setDefersLoading(bool defers)
@@ -230,6 +239,11 @@ void NetworkResourceLoader::setDefersLoading(bool defers)
         return;
     m_defersLoading = defers;
 
+    if (defers)
+        RELEASE_LOG_IF_ALLOWED("setDefersLoading: Deferring resource load (pageID = %llu, frameID = %llu, resourceID = %llu)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier);
+    else
+        RELEASE_LOG_IF_ALLOWED("setDefersLoading: Resuming deferred resource load (pageID = %llu, frameID = %llu, resourceID = %llu)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier);
+
     if (m_networkLoad) {
         m_networkLoad->setDefersLoading(defers);
         return;
@@ -237,6 +251,8 @@ void NetworkResourceLoader::setDefersLoading(bool defers)
 
     if (!m_defersLoading)
         start();
+    else
+        RELEASE_LOG_IF_ALLOWED("setDefersLoading: defers = TRUE, but nothing to stop (pageID = %llu, frameID = %llu, resourceID = %llu)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier);
 }
 
 void NetworkResourceLoader::cleanup()
@@ -273,6 +289,9 @@ void NetworkResourceLoader::abort()
 {
     ASSERT(RunLoop::isMain());
 
+    RELEASE_LOG_IF_ALLOWED("abort: Canceling resource load (pageID = %llu, frameID = %llu, resourceID = %llu)",
+        m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier);
+
     if (m_networkLoad && !m_didConvertToDownload) {
 #if ENABLE(NETWORK_CACHE)
         if (canUseCache(m_networkLoad->currentRequest())) {
@@ -320,10 +339,8 @@ auto NetworkResourceLoader::didReceiveResponse(ResourceResponse&& receivedRespon
     if (shouldSendDidReceiveResponse) {
         if (isSynchronous())
             m_synchronousLoadData->response = m_response;
-        else {
-            RELEASE_LOG_IF_ALLOWED("didReceiveResponse: Sending didReceiveResponse message to the WebContent process (pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d)", static_cast<unsigned long long>(m_parameters.webPageID), static_cast<unsigned long long>(m_parameters.webFrameID), isMainResource(), isSynchronous());
+        else
             send(Messages::WebResourceLoader::DidReceiveResponse(m_response, shouldWaitContinueDidReceiveResponse));
-        }
     }
 
     // For main resources, the web process is responsible for sending back a NetworkResourceLoader::ContinueDidReceiveResponse message.
@@ -343,6 +360,11 @@ auto NetworkResourceLoader::didReceiveResponse(ResourceResponse&& receivedRespon
 
 void NetworkResourceLoader::didReceiveBuffer(Ref<SharedBuffer>&& buffer, int reportedEncodedDataLength)
 {
+    if (!m_hasReceivedData) {
+        RELEASE_LOG_IF_ALLOWED("didReceiveBuffer: Started receiving data (pageID = %llu, frameID = %llu, resourceID = %llu)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier);
+        m_hasReceivedData = true;
+    }
+
 #if ENABLE(NETWORK_CACHE)
     ASSERT(!m_cacheEntryForValidation);
 
index 1d8f2b8..7dd2829 100644 (file)
@@ -153,6 +153,7 @@ private:
     bool m_didConvertToDownload { false };
     bool m_didConsumeSandboxExtensions { false };
     bool m_defersLoading { false };
+    bool m_hasReceivedData { false };
 
     WebCore::Timer m_bufferingTimer;
 #if ENABLE(NETWORK_CACHE)
index 0a7579e..f8cb93d 100644 (file)
@@ -57,8 +57,8 @@
 
 using namespace WebCore;
 
-#define RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(loadParameters.sessionID.isAlwaysOnLoggingAllowed(), Network, "%p - WebLoaderStrategy::" fmt, this, ##__VA_ARGS__)
-#define RELEASE_LOG_ERROR_IF_ALLOWED(fmt, ...) RELEASE_LOG_ERROR_IF(loadParameters.sessionID.isAlwaysOnLoggingAllowed(), Network, "%p - WebLoaderStrategy::" fmt, this, ##__VA_ARGS__)
+#define RELEASE_LOG_IF_ALLOWED(permissionChecker, fmt, ...) RELEASE_LOG_IF(permissionChecker.isAlwaysOnLoggingAllowed(), Network, "%p - WebLoaderStrategy::" fmt, this, ##__VA_ARGS__)
+#define RELEASE_LOG_ERROR_IF_ALLOWED(permissionChecker, fmt, ...) RELEASE_LOG_ERROR_IF(permissionChecker.isAlwaysOnLoggingAllowed(), Network, "%p - WebLoaderStrategy::" fmt, this, ##__VA_ARGS__)
 
 namespace WebKit {
 
@@ -76,6 +76,8 @@ RefPtr<SubresourceLoader> WebLoaderStrategy::loadResource(Frame& frame, CachedRe
     RefPtr<SubresourceLoader> loader = SubresourceLoader::create(frame, resource, request, options);
     if (loader)
         scheduleLoad(*loader, &resource, frame.document()->referrerPolicy() == ReferrerPolicy::Default);
+    else
+        RELEASE_LOG_ERROR_IF_ALLOWED(frame, "loadResource: Unable to create SubresourceLoader (frame = %p", &frame);
     return loader;
 }
 
@@ -149,6 +151,7 @@ void WebLoaderStrategy::scheduleLoad(ResourceLoader& resourceLoader, CachedResou
     // then we should remember the ResourceLoader in our records but not schedule it in the NetworkProcess.
     if (resourceLoader.documentLoader()->scheduleArchiveLoad(resourceLoader, resourceLoader.request())) {
         LOG(NetworkScheduling, "(WebProcess) WebLoaderStrategy::scheduleLoad, url '%s' will be handled as an archive resource.", resourceLoader.url().string().utf8().data());
+        RELEASE_LOG_IF_ALLOWED(resourceLoader, "scheduleLoad: URL will be handled as an archive resource (frame = %p, resourceID = %llu)", resourceLoader.frame(), identifier);
         m_webResourceLoaders.set(identifier, WebResourceLoader::create(resourceLoader, trackingParameters));
         return;
     }
@@ -156,12 +159,14 @@ void WebLoaderStrategy::scheduleLoad(ResourceLoader& resourceLoader, CachedResou
 
     if (resourceLoader.documentLoader()->applicationCacheHost()->maybeLoadResource(resourceLoader, resourceLoader.request(), resourceLoader.request().url())) {
         LOG(NetworkScheduling, "(WebProcess) WebLoaderStrategy::scheduleLoad, url '%s' will be loaded from application cache.", resourceLoader.url().string().utf8().data());
+        RELEASE_LOG_IF_ALLOWED(resourceLoader, "scheduleLoad: URL will be loaded from application cache (frame = %p, resourceID = %llu)", resourceLoader.frame(), identifier);
         m_webResourceLoaders.set(identifier, WebResourceLoader::create(resourceLoader, trackingParameters));
         return;
     }
 
     if (resourceLoader.request().url().protocolIsData()) {
         LOG(NetworkScheduling, "(WebProcess) WebLoaderStrategy::scheduleLoad, url '%s' will be loaded as data.", resourceLoader.url().string().utf8().data());
+        RELEASE_LOG_IF_ALLOWED(resourceLoader, "scheduleLoad: URL will be loaded as data (frame = %p, resourceID = %llu)", resourceLoader.frame(), identifier);
         startLocalLoad(resourceLoader);
         return;
     }
@@ -169,6 +174,7 @@ void WebLoaderStrategy::scheduleLoad(ResourceLoader& resourceLoader, CachedResou
 #if USE(QUICK_LOOK)
     if (resourceLoader.request().url().protocolIs(QLPreviewProtocol())) {
         LOG(NetworkScheduling, "(WebProcess) WebLoaderStrategy::scheduleLoad, url '%s' will be handled as a QuickLook resource.", resourceLoader.url().string().utf8().data());
+        RELEASE_LOG_IF_ALLOWED(resourceLoader, "scheduleLoad: URL will be handled as a QuickLook resource (frame = %p, resourceID = %llu)", resourceLoader.frame(), identifier);
         startLocalLoad(resourceLoader);
         return;
     }
@@ -179,6 +185,7 @@ void WebLoaderStrategy::scheduleLoad(ResourceLoader& resourceLoader, CachedResou
     // https://blogs.gnome.org/alexl/2012/01/26/resources-in-glib/
     if (resourceLoader.request().url().protocolIs("resource")) {
         LOG(NetworkScheduling, "(WebProcess) WebLoaderStrategy::scheduleLoad, url '%s' will be handled as a GResource.", resourceLoader.url().string().utf8().data());
+        RELEASE_LOG_IF_ALLOWED(resourceLoader, "scheduleLoad: URL will be handled as a GResource (frame = %p, resourceID = %llu)", resourceLoader.frame(), identifier);
         startLocalLoad(resourceLoader);
         return;
     }
@@ -207,7 +214,7 @@ void WebLoaderStrategy::scheduleLoad(ResourceLoader& resourceLoader, CachedResou
     ASSERT((loadParameters.webPageID && loadParameters.webFrameID) || loadParameters.clientCredentialPolicy == ClientCredentialPolicy::CannotAskClientForCredentials);
 
     if (!WebProcess::singleton().networkConnection().connection().send(Messages::NetworkConnectionToWebProcess::ScheduleResourceLoad(loadParameters), 0)) {
-        RELEASE_LOG_ERROR_IF_ALLOWED("scheduleLoad: Unable to schedule resource with the NetworkProcess (frame = %p, priority = %d, pageID = %llu, frameID = %llu, resourceID = %llu)", resourceLoader.frame(), static_cast<int>(resourceLoader.request().priority()), loadParameters.webPageID, loadParameters.identifier, loadParameters.webFrameID);
+        RELEASE_LOG_ERROR_IF_ALLOWED(resourceLoader, "scheduleLoad: Unable to schedule resource with the NetworkProcess (frame = %p, priority = %d, pageID = %llu, frameID = %llu, resourceID = %llu)", resourceLoader.frame(), static_cast<int>(resourceLoader.request().priority()), loadParameters.webPageID, loadParameters.identifier, loadParameters.webFrameID);
         // We probably failed to schedule this load with the NetworkProcess because it had crashed.
         // This load will never succeed so we will schedule it to fail asynchronously.
         scheduleInternallyFailedLoad(resourceLoader);
@@ -215,7 +222,7 @@ void WebLoaderStrategy::scheduleLoad(ResourceLoader& resourceLoader, CachedResou
     }
 
     auto webResourceLoader = WebResourceLoader::create(resourceLoader, trackingParameters);
-    RELEASE_LOG_IF_ALLOWED("scheduleLoad: Resource has been queued for scheduling with the NetworkProcess (frame = %p, priority = %d, pageID = %llu, frameID = %llu, resourceID = %llu, WebResourceLoader = %p)", resourceLoader.frame(), static_cast<int>(resourceLoader.request().priority()), loadParameters.webPageID, loadParameters.webFrameID, loadParameters.identifier, webResourceLoader.ptr());
+    RELEASE_LOG_IF_ALLOWED(resourceLoader, "scheduleLoad: Resource has been queued for scheduling with the NetworkProcess (frame = %p, priority = %d, pageID = %llu, frameID = %llu, resourceID = %llu, WebResourceLoader = %p)", resourceLoader.frame(), static_cast<int>(resourceLoader.request().priority()), loadParameters.webPageID, loadParameters.webFrameID, loadParameters.identifier, webResourceLoader.ptr());
     m_webResourceLoaders.set(identifier, WTFMove(webResourceLoader));
 }