Diff
Modified: trunk/Source/WebCore/ChangeLog (239456 => 239457)
--- trunk/Source/WebCore/ChangeLog 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebCore/ChangeLog 2018-12-20 19:23:20 UTC (rev 239457)
@@ -1,3 +1,75 @@
+2018-12-20 Keith Rollin <[email protected]>
+
+ Improve release-level page-load logging
+ https://bugs.webkit.org/show_bug.cgi?id=192872
+ <rdar://problem/46850309>
+
+ Reviewed by Chris Dumez.
+
+ There are a number of reported bugs that are difficult or impossible
+ to track down with our current level of logging. Additionally, some
+ software groups lower in the page-loading stack have requested logging
+ sufficient for tracking a user-visible error message down to the
+ requested resource that caused the message. Add more-comprehensive
+ logging to address these issues/requests.
+
+ No new tests -- no changed functionality.
+
+ * loader/DocumentLoader.cpp:
+ (WebCore::DocumentLoader::setMainDocumentError):
+ (WebCore::DocumentLoader::mainReceivedError):
+ (WebCore::DocumentLoader::stopLoading):
+ (WebCore::DocumentLoader::notifyFinished):
+ (WebCore::DocumentLoader::willSendRequest):
+ (WebCore::DocumentLoader::continueAfterContentPolicy):
+ (WebCore::DocumentLoader::startLoadingMainResource):
+ (WebCore::DocumentLoader::loadMainResource):
+ (WebCore::DocumentLoader::cancelMainResourceLoad):
+ * loader/FrameLoader.cpp:
+ (WebCore::FrameLoader::urlSelected):
+ (WebCore::FrameLoader::loadURLIntoChildFrame):
+ (WebCore::FrameLoader::loadArchive):
+ (WebCore::FrameLoader::loadInSameDocument):
+ (WebCore::FrameLoader::loadFrameRequest):
+ (WebCore::FrameLoader::loadURL):
+ (WebCore::FrameLoader::load):
+ (WebCore::FrameLoader::loadWithNavigationAction):
+ (WebCore::FrameLoader::loadWithDocumentLoader):
+ (WebCore::FrameLoader::reloadWithOverrideEncoding):
+ (WebCore::FrameLoader::reload):
+ (WebCore::FrameLoader::setState):
+ (WebCore::FrameLoader::checkLoadCompleteForThisFrame):
+ (WebCore::FrameLoader::loadPostRequest):
+ (WebCore::FrameLoader::continueLoadAfterNavigationPolicy):
+ (WebCore::FrameLoader::loadDifferentDocumentItem):
+ * loader/ProgressTracker.cpp:
+ (WebCore::ProgressItem::ProgressItem):
+ (WebCore::ProgressTracker::reset):
+ (WebCore::ProgressTracker::progressStarted):
+ (WebCore::ProgressTracker::progressCompleted):
+ (WebCore::ProgressTracker::finalProgressComplete):
+ (WebCore::ProgressTracker::incrementProgress):
+ (WebCore::ProgressTracker::completeProgress):
+ (WebCore::ProgressTracker::isAlwaysOnLoggingAllowed const):
+ * loader/ProgressTracker.h:
+ * loader/ResourceLoader.cpp:
+ (WebCore::ResourceLoader::loadDataURL):
+ (WebCore::ResourceLoader::willSendRequestInternal):
+ (WebCore::ResourceLoader::didFinishLoading):
+ (WebCore::ResourceLoader::didFail):
+ (WebCore::ResourceLoader::willSendRequestAsync):
+ (WebCore::ResourceLoader::wasBlocked):
+ (WebCore::ResourceLoader::cannotShowURL):
+ * loader/SubresourceLoader.cpp:
+ (WebCore::SubresourceLoader::willSendRequestInternal):
+ (WebCore::=):
+ (WebCore::SubresourceLoader::didReceiveResponse):
+ (WebCore::SubresourceLoader::didFinishLoading):
+ (WebCore::SubresourceLoader::didFail):
+ (WebCore::SubresourceLoader::willCancel):
+ * loader/cache/CachedResource.cpp:
+ (WebCore::CachedResource::load):
+
2018-12-20 Jeremy Jones <[email protected]>
Switch tabs before retuning PiP video to inline.
Modified: trunk/Source/WebCore/loader/DocumentLoader.cpp (239456 => 239457)
--- trunk/Source/WebCore/loader/DocumentLoader.cpp 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebCore/loader/DocumentLoader.cpp 2018-12-20 19:23:20 UTC (rev 239457)
@@ -228,6 +228,9 @@
void DocumentLoader::setMainDocumentError(const ResourceError& error)
{
+ if (!error.isNull())
+ RELEASE_LOG_IF_ALLOWED("setMainDocumentError: (frame = %p, main = %d, type = %d, code = %d)", m_frame, m_frame->isMainFrame(), static_cast<int>(error.type()), error.errorCode());
+
m_mainDocumentError = error;
frameLoader()->client().setMainDocumentError(this, error);
}
@@ -239,6 +242,9 @@
if (!frameLoader())
return;
+ if (!error.isNull())
+ RELEASE_LOG_IF_ALLOWED("mainReceivedError: (frame = %p, main = %d, type = %d, code = %d)", m_frame, m_frame->isMainFrame(), static_cast<int>(error.type()), error.errorCode());
+
if (m_identifierForLoadWithoutResourceLoader) {
ASSERT(!mainResourceLoader());
frameLoader()->client().dispatchDidFailLoading(this, m_identifierForLoadWithoutResourceLoader, error);
@@ -325,6 +331,7 @@
// The frame may have been detached from this document by the onunload handler
if (auto* frameLoader = DocumentLoader::frameLoader()) {
+ RELEASE_LOG_IF_ALLOWED("stopLoading: canceling load (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
if (isLoadingMainResource()) {
// Stop the main resource loader and let it send the cancelled message.
cancelMainResourceLoad(frameLoader->cancelledError(m_request));
@@ -390,6 +397,9 @@
return;
}
+ if (!m_mainResource->resourceError().isNull())
+ RELEASE_LOG_IF_ALLOWED("notifyFinished: canceling load (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
+
mainReceivedError(m_mainResource->resourceError());
}
@@ -562,6 +572,7 @@
bool didReceiveRedirectResponse = !redirectResponse.isNull();
if (!frameLoader()->checkIfFormActionAllowedByCSP(newRequest.url(), didReceiveRedirectResponse)) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequest: canceling - form action not allowed by CSP (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
cancelMainResourceLoad(frameLoader()->cancelledError(newRequest));
return completionHandler(WTFMove(newRequest));
}
@@ -572,11 +583,13 @@
// then block the redirect.
Ref<SecurityOrigin> redirectingOrigin(SecurityOrigin::create(redirectResponse.url()));
if (!redirectingOrigin.get().canDisplay(newRequest.url())) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequest: canceling - redirecting URL not allowed to display content from target(frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
FrameLoader::reportLocalLoadFailed(m_frame, newRequest.url().string());
cancelMainResourceLoad(frameLoader()->cancelledError(newRequest));
return completionHandler(WTFMove(newRequest));
}
if (!portAllowed(newRequest.url())) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequest: canceling - port not allowed (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
FrameLoader::reportBlockedPortFailed(m_frame, newRequest.url().string());
cancelMainResourceLoad(frameLoader()->blockedError(newRequest));
return completionHandler(WTFMove(newRequest));
@@ -892,6 +905,7 @@
case PolicyAction::Download: {
// m_mainResource can be null, e.g. when loading a substitute resource from application cache.
if (!m_mainResource) {
+ RELEASE_LOG_IF_ALLOWED("continueAfterContentPolicy: cannot show URL (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
mainReceivedError(frameLoader()->client().cannotShowURLError(m_request));
return;
}
@@ -1725,22 +1739,30 @@
// FIXME: Implement local URL interception by getting the service worker of the parent.
auto url = ""
matchRegistration(url, [request = WTFMove(request), protectedThis = WTFMove(protectedThis), this] (auto&& registrationData) mutable {
- if (!m_mainDocumentError.isNull() || !m_frame)
+ if (!m_mainDocumentError.isNull() || !m_frame) {
+ RELEASE_LOG_IF_ALLOWED("startLoadingMainResource callback: Load canceled because of main document error (frame = %p, main = %d)", m_frame, m_frame ? m_frame->isMainFrame() : false);
return;
+ }
m_serviceWorkerRegistrationData = WTFMove(registrationData);
// Prefer existing substitute data (from WKWebView.loadData etc) over service worker fetch.
- if (this->tryLoadingSubstituteData())
+ if (this->tryLoadingSubstituteData()) {
+ RELEASE_LOG_IF_ALLOWED("startLoadingMainResource callback: Load canceled because of substitute data (frame = %p, main = %d)", m_frame, m_frame ? m_frame->isMainFrame() : false);
return;
+ }
// Try app cache only if there is no service worker.
- if (!m_serviceWorkerRegistrationData && this->tryLoadingRequestFromApplicationCache())
+ if (!m_serviceWorkerRegistrationData && this->tryLoadingRequestFromApplicationCache()) {
+ RELEASE_LOG_IF_ALLOWED("startLoadingMainResource callback: Loaded from Application Cache (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
return;
+ }
this->loadMainResource(WTFMove(request));
});
#else
- if (tryLoadingRequestFromApplicationCache())
+ if (tryLoadingRequestFromApplicationCache()) {
+ RELEASE_LOG_IF_ALLOWED("startLoadingMainResource: Loaded from Application Cache (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
return;
+ }
loadMainResource(WTFMove(request));
#endif
});
@@ -1823,16 +1845,18 @@
if (!m_mainResource) {
// The frame may have gone away if this load was cancelled synchronously and this was the last pending load.
// This is because we may have fired the load event in a parent frame.
- if (!m_frame)
+ if (!m_frame) {
+ RELEASE_LOG_IF_ALLOWED("loadMainResource: Unable to load main resource, frame has gone away (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
return;
+ }
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());
+ RELEASE_LOG_IF_ALLOWED("loadMainResource: 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());
+ RELEASE_LOG_IF_ALLOWED("loadMainResource: 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
@@ -1847,7 +1871,7 @@
#if ENABLE(CONTENT_EXTENSIONS)
if (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());
+ RELEASE_LOG_IF_ALLOWED("loadMainResource: Blocked by content blocker error (frame = %p, main = %d)", m_frame, m_frame->isMainFrame());
cancelMainResourceLoad(frameLoader()->blockedByContentBlockerError(m_request));
return;
}
@@ -1885,6 +1909,8 @@
Ref<DocumentLoader> protectedThis(*this);
ResourceError error = resourceError.isNull() ? frameLoader()->cancelledError(m_request) : resourceError;
+ RELEASE_LOG_IF_ALLOWED("cancelMainResourceLoad: (frame = %p, main = %d, type = %d, code = %d)", m_frame, m_frame->isMainFrame(), static_cast<int>(error.type()), error.errorCode());
+
m_dataLoadTimer.stop();
cancelPolicyCheckIfNeeded();
Modified: trunk/Source/WebCore/loader/FrameLoader.cpp (239456 => 239457)
--- trunk/Source/WebCore/loader/FrameLoader.cpp 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebCore/loader/FrameLoader.cpp 2018-12-20 19:23:20 UTC (rev 239457)
@@ -390,6 +390,8 @@
void FrameLoader::urlSelected(FrameLoadRequest&& frameRequest, Event* triggeringEvent)
{
+ RELEASE_LOG_IF_ALLOWED("urlSelected: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
Ref<Frame> protect(m_frame);
if (m_frame.script().executeIfJavaScriptURL(frameRequest.resourceRequest().url(), frameRequest.shouldReplaceDocumentIfJavaScriptURL()))
@@ -953,6 +955,8 @@
void FrameLoader::loadURLIntoChildFrame(const URL& url, const String& referer, Frame* childFrame)
{
+ RELEASE_LOG_IF_ALLOWED("loadURLIntoChildFrame: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
ASSERT(childFrame);
#if ENABLE(WEB_ARCHIVE) || ENABLE(MHTML)
@@ -986,6 +990,8 @@
void FrameLoader::loadArchive(Ref<Archive>&& archive)
{
+ RELEASE_LOG_IF_ALLOWED("loadArchive: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
ArchiveResource* mainResource = archive->mainResource();
ASSERT(mainResource);
if (!mainResource)
@@ -1112,6 +1118,8 @@
// that a higher level already checked that the URLs match and the scrolling is the right thing to do.
void FrameLoader::loadInSameDocument(const URL& url, SerializedScriptValue* stateObject, bool isNewNavigation)
{
+ RELEASE_LOG_IF_ALLOWED("loadInSameDocument: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
// If we have a state object, we cannot also be a new navigation.
ASSERT(!stateObject || (stateObject && !isNewNavigation));
@@ -1234,6 +1242,8 @@
void FrameLoader::loadFrameRequest(FrameLoadRequest&& request, Event* event, RefPtr<FormState>&& formState)
{
+ RELEASE_LOG_IF_ALLOWED("loadFrameRequest: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
// Protect frame from getting blown away inside dispatchBeforeLoadEvent in loadWithDocumentLoader.
auto protectFrame = makeRef(m_frame);
@@ -1321,6 +1331,8 @@
void FrameLoader::loadURL(FrameLoadRequest&& frameLoadRequest, const String& referrer, FrameLoadType newLoadType, Event* event, RefPtr<FormState>&& formState, CompletionHandler<void()>&& completionHandler)
{
+ RELEASE_LOG_IF_ALLOWED("loadURL: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
CompletionHandlerCallingScope completionHandlerCaller(WTFMove(completionHandler));
if (m_inStopAllLoaders || m_inClearProvisionalLoadForPolicyCheck)
return;
@@ -1432,6 +1444,8 @@
void FrameLoader::load(FrameLoadRequest&& request)
{
+ RELEASE_LOG_IF_ALLOWED("load (FrameLoadRequest): frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
if (m_inStopAllLoaders || m_inClearProvisionalLoadForPolicyCheck)
return;
@@ -1476,6 +1490,8 @@
void FrameLoader::loadWithNavigationAction(const ResourceRequest& request, NavigationAction&& action, LockHistory lockHistory, FrameLoadType type, RefPtr<FormState>&& formState, AllowNavigationToInvalidURL allowNavigationToInvalidURL, CompletionHandler<void()>&& completionHandler)
{
+ RELEASE_LOG_IF_ALLOWED("loadWithNavigationAction: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
Ref<DocumentLoader> loader = m_client.createDocumentLoader(request, defaultSubstituteDataForURL(request.url()));
applyShouldOpenExternalURLsPolicyToNewDocumentLoader(m_frame, loader, action.initiatedByMainFrame(), action.shouldOpenExternalURLsPolicy());
@@ -1491,6 +1507,8 @@
void FrameLoader::load(DocumentLoader& newDocumentLoader)
{
+ RELEASE_LOG_IF_ALLOWED("load (DocumentLoader): frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
ResourceRequest& r = newDocumentLoader.request();
addExtraFieldsToMainResourceRequest(r);
FrameLoadType type;
@@ -1530,6 +1548,8 @@
void FrameLoader::loadWithDocumentLoader(DocumentLoader* loader, FrameLoadType type, RefPtr<FormState>&& formState, AllowNavigationToInvalidURL allowNavigationToInvalidURL, ShouldTreatAsContinuingLoad, CompletionHandler<void()>&& completionHandler)
{
+ RELEASE_LOG_IF_ALLOWED("loadWithDocumentLoader: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
// Retain because dispatchBeforeLoadEvent may release the last reference to it.
Ref<Frame> protect(m_frame);
@@ -1558,6 +1578,7 @@
// Log main frame navigation types.
if (m_frame.isMainFrame()) {
if (auto* page = m_frame.page()) {
+ RELEASE_LOG_IF_ALLOWED("loadWithDocumentLoader: main frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
page->mainFrameLoadStarted(newURL, type);
page->performanceLogging().didReachPointOfInterest(PerformanceLogging::MainFrameLoadStarted);
}
@@ -1704,6 +1725,8 @@
if (!m_documentLoader)
return;
+ RELEASE_LOG_IF_ALLOWED("reloadWithOverrideEncoding: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
ResourceRequest request = m_documentLoader->request();
URL unreachableURL = m_documentLoader->unreachableURL();
if (!unreachableURL.isEmpty())
@@ -1733,6 +1756,8 @@
if (m_documentLoader->request().url().isEmpty())
return;
+ RELEASE_LOG_IF_ALLOWED("reload: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
// Replace error-page URL with the URL we were trying to reach.
ResourceRequest initialRequest = m_documentLoader->request();
URL unreachableURL = m_documentLoader->unreachableURL();
@@ -1931,8 +1956,10 @@
frameLoadCompleted();
if (m_documentLoader)
m_documentLoader->stopRecordingResponses();
- if (m_frame.isMainFrame() && oldState != newState)
+ if (m_frame.isMainFrame() && oldState != newState) {
+ RELEASE_LOG_IF_ALLOWED("setState: main frame load completed (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
m_frame.page()->performanceLogging().didReachPointOfInterest(PerformanceLogging::MainFrameLoadCompleted);
+ }
}
}
@@ -2425,6 +2452,7 @@
// Only reset if we aren't already going to a new provisional item.
bool shouldReset = !history().provisionalItem();
if (!pdl->isLoadingInAPISense() || pdl->isStopping()) {
+ RELEASE_LOG_IF_ALLOWED("checkLoadCompleteForThisFrame: Failed provisional load (frame = %p, main = %d, isTimeout = %d, isCancellation = %d, errorCode = %d)", &m_frame, m_frame.isMainFrame(), error.isTimeout(), error.isCancellation(), error.errorCode());
m_provisionalLoadErrorBeingHandledURL = m_provisionalDocumentLoader->url();
m_client.dispatchDidFailProvisionalLoad(error);
#if ENABLE(CONTENT_FILTERING)
@@ -2925,6 +2953,8 @@
void FrameLoader::loadPostRequest(FrameLoadRequest&& request, const String& referrer, FrameLoadType loadType, Event* event, RefPtr<FormState>&& formState, CompletionHandler<void()>&& completionHandler)
{
+ RELEASE_LOG_IF_ALLOWED("loadPostRequest: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
String frameName = request.frameName();
LockHistory lockHistory = request.lockHistory();
AllowNavigationToInvalidURL allowNavigationToInvalidURL = request.allowNavigationToInvalidURL();
@@ -3316,6 +3346,18 @@
bool canContinue = shouldContinue != ShouldContinue::No && shouldClose() && !urlIsDisallowed;
if (!canContinue) {
+ RELEASE_LOG_IF_ALLOWED("continueLoadAfterNavigationPolicy: can't continue loading frame due to the following reasons ("
+ "frame = %p, "
+ "main = %d, "
+ "allowNavigationToInvalidURL = %d, "
+ "requestURLIsValid = %d, "
+ "shouldContinue = %d)",
+ &m_frame,
+ m_frame.isMainFrame(),
+ static_cast<int>(allowNavigationToInvalidURL),
+ request.url().isValid(),
+ static_cast<int>(shouldContinue));
+
// If we were waiting for a quick redirect, but the policy delegate decided to ignore it, then we
// need to report that the client redirect was cancelled.
// FIXME: The client should be told about ignored non-quick redirects, too.
@@ -3344,8 +3386,10 @@
// <rdar://problem/6250856> - In certain circumstances on pages with multiple frames, stopAllLoaders()
// might detach the current FrameLoader, in which case we should bail on this newly defunct load.
- if (!m_frame.page())
+ if (!m_frame.page()) {
+ RELEASE_LOG_IF_ALLOWED("continueLoadAfterNavigationPolicy: can't continue loading frame because it became defunct (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
return;
+ }
setProvisionalDocumentLoader(m_policyDocumentLoader.get());
m_loadType = type;
@@ -3358,6 +3402,7 @@
if (history().provisionalItem()->isInPageCache()) {
diagnosticLoggingClient.logDiagnosticMessageWithResult(DiagnosticLoggingKeys::pageCacheKey(), DiagnosticLoggingKeys::retrievalKey(), DiagnosticLoggingResultPass, ShouldSample::Yes);
loadProvisionalItemFromCachedPage();
+ RELEASE_LOG_IF_ALLOWED("continueLoadAfterNavigationPolicy: can't continue loading frame because it will be loaded from cache (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
return;
}
diagnosticLoggingClient.logDiagnosticMessageWithResult(DiagnosticLoggingKeys::pageCacheKey(), DiagnosticLoggingKeys::retrievalKey(), DiagnosticLoggingResultFail, ShouldSample::Yes);
@@ -3364,8 +3409,10 @@
}
CompletionHandler<void()> completionHandler = [this, protectedFrame = makeRef(m_frame)] () mutable {
- if (!m_provisionalDocumentLoader)
+ if (!m_provisionalDocumentLoader) {
+ RELEASE_LOG_IF_ALLOWED("continueLoadAfterNavigationPolicy completionHandler: Frame load canceled #1 (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
return;
+ }
prepareForLoadStart([this, protectedFrame = WTFMove(protectedFrame)] {
@@ -3372,13 +3419,13 @@
// The load might be cancelled inside of prepareForLoadStart(), nulling out the m_provisionalDocumentLoader,
// so we need to null check it again.
if (!m_provisionalDocumentLoader) {
- RELEASE_LOG_IF_ALLOWED("dispatchWillSubmitForm completionHandler: Frame load canceled (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+ RELEASE_LOG_IF_ALLOWED("prepareForLoadStart completionHandler: Frame load canceled #2 (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
return;
}
DocumentLoader* activeDocLoader = activeDocumentLoader();
if (activeDocLoader && activeDocLoader->isLoadingMainResource()) {
- RELEASE_LOG_IF_ALLOWED("dispatchWillSubmitForm completionHandler: Main frame already being loaded (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+ RELEASE_LOG_IF_ALLOWED("prepareForLoadStart completionHandler: Main frame already being loaded (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
return;
}
@@ -3602,6 +3649,8 @@
// methods of FrameLoader.
void FrameLoader::loadDifferentDocumentItem(HistoryItem& item, FrameLoadType loadType, FormSubmissionCacheLoadPolicy cacheLoadPolicy, ShouldTreatAsContinuingLoad shouldTreatAsContinuingLoad)
{
+ RELEASE_LOG_IF_ALLOWED("loadDifferentDocumentItem: frame load started (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
+
// History items should not be reported to the parent.
m_shouldReportResourceTimingToParentFrame = false;
Modified: trunk/Source/WebCore/loader/ProgressTracker.cpp (239456 => 239457)
--- trunk/Source/WebCore/loader/ProgressTracker.cpp 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebCore/loader/ProgressTracker.cpp 2018-12-20 19:23:20 UTC (rev 239457)
@@ -1,5 +1,5 @@
/*
- * Copyright (C) 2007 Apple Inc. All rights reserved.
+ * Copyright (C) 2007, 2018 Apple Inc. All rights reserved.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions
@@ -20,7 +20,7 @@
* PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY
* OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
* (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
- * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+ * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/
#include "config.h"
@@ -37,12 +37,14 @@
#include "ResourceResponse.h"
#include <wtf/text/CString.h>
+#define RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(isAlwaysOnLoggingAllowed(), Network, "%p - ProgressTracker::" fmt, this, ##__VA_ARGS__)
+
namespace WebCore {
-// Always start progress at initialProgressValue. This helps provide feedback as
+// Always start progress at initialProgressValue. This helps provide feedback as
// soon as a load starts.
static const double initialProgressValue = 0.1;
-
+
// Similarly, always leave space at the end. This helps show the user that we're not done
// until we're done.
static const double finalProgressValue = 0.9; // 1.0 - initialProgressValue
@@ -63,12 +65,12 @@
struct ProgressItem {
WTF_MAKE_NONCOPYABLE(ProgressItem); WTF_MAKE_FAST_ALLOCATED;
public:
- ProgressItem(long long length)
+ ProgressItem(long long length)
: bytesReceived(0)
, estimatedLength(length)
{
}
-
+
long long bytesReceived;
long long estimatedLength;
};
@@ -93,7 +95,7 @@
void ProgressTracker::reset()
{
- m_progressItems.clear();
+ m_progressItems.clear();
m_totalPageAndResourceBytesToLoad = 0;
m_totalBytesReceived = 0;
@@ -116,7 +118,7 @@
LOG(Progress, "Progress started (%p) - frame %p(\"%s\"), value %f, tracked frames %d, originating frame %p", this, &frame, frame.tree().uniqueName().string().utf8().data(), m_progressValue, m_numProgressTrackedFrames, m_originatingProgressFrame.get());
m_client.willChangeEstimatedProgress();
-
+
if (!m_numProgressTrackedFrames || m_originatingProgressFrame == &frame) {
reset();
m_progressValue = initialProgressValue;
@@ -135,6 +137,8 @@
}
m_numProgressTrackedFrames++;
+ RELEASE_LOG_IF_ALLOWED("progressStarted: frame %p, value %f, tracked frames %d, originating frame %p, isMainLoad %d", &frame, m_progressValue, m_numProgressTrackedFrames, m_originatingProgressFrame.get(), m_isMainLoad);
+
m_client.didChangeEstimatedProgress();
InspectorInstrumentation::frameStartedLoading(frame);
}
@@ -142,16 +146,17 @@
void ProgressTracker::progressCompleted(Frame& frame)
{
LOG(Progress, "Progress completed (%p) - frame %p(\"%s\"), value %f, tracked frames %d, originating frame %p", this, &frame, frame.tree().uniqueName().string().utf8().data(), m_progressValue, m_numProgressTrackedFrames, m_originatingProgressFrame.get());
-
+ RELEASE_LOG_IF_ALLOWED("progressCompleted: frame %p, value %f, tracked frames %d, originating frame %p, isMainLoad %d", &frame, m_progressValue, m_numProgressTrackedFrames, m_originatingProgressFrame.get(), m_isMainLoad);
+
if (m_numProgressTrackedFrames <= 0)
return;
-
+
m_client.willChangeEstimatedProgress();
-
+
m_numProgressTrackedFrames--;
if (!m_numProgressTrackedFrames || m_originatingProgressFrame == &frame)
finalProgressComplete();
-
+
m_client.didChangeEstimatedProgress();
}
@@ -158,9 +163,10 @@
void ProgressTracker::finalProgressComplete()
{
LOG(Progress, "Final progress complete (%p)", this);
-
+ RELEASE_LOG_IF_ALLOWED("finalProgressComplete: value %f, tracked frames %d, originating frame %p, isMainLoad %d, isMainLoadProgressing %d", m_progressValue, m_numProgressTrackedFrames, m_originatingProgressFrame.get(), m_isMainLoad, isMainLoadProgressing());
+
auto frame = WTFMove(m_originatingProgressFrame);
-
+
// Before resetting progress value be sure to send client a least one notification
// with final progress value.
if (!m_finalProgressChangedSent) {
@@ -186,11 +192,11 @@
if (m_numProgressTrackedFrames <= 0)
return;
-
+
long long estimatedLength = response.expectedContentLength();
if (estimatedLength < 0)
estimatedLength = progressItemDefaultEstimatedLength;
-
+
m_totalPageAndResourceBytesToLoad += estimatedLength;
auto& item = m_progressItems.add(identifier, nullptr).iterator->value;
@@ -198,7 +204,7 @@
item = std::make_unique<ProgressItem>(estimatedLength);
return;
}
-
+
item->bytesReceived = 0;
item->estimatedLength = estimatedLength;
}
@@ -206,24 +212,24 @@
void ProgressTracker::incrementProgress(unsigned long identifier, unsigned bytesReceived)
{
ProgressItem* item = m_progressItems.get(identifier);
-
+
// FIXME: Can this ever happen?
if (!item)
return;
RefPtr<Frame> frame = m_originatingProgressFrame;
-
+
m_client.willChangeEstimatedProgress();
-
+
double increment, percentOfRemainingBytes;
long long remainingBytes, estimatedBytesForPendingRequests;
-
+
item->bytesReceived += bytesReceived;
if (item->bytesReceived > item->estimatedLength) {
m_totalPageAndResourceBytesToLoad += ((item->bytesReceived * 2) - item->estimatedLength);
item->estimatedLength = item->bytesReceived * 2;
}
-
+
int numPendingOrLoadingRequests = frame->loader().numPendingOrLoadingRequests(true);
estimatedBytesForPendingRequests = static_cast<long long>(progressItemDefaultEstimatedLength) * numPendingOrLoadingRequests;
remainingBytes = ((m_totalPageAndResourceBytesToLoad + estimatedBytesForPendingRequests) - m_totalBytesReceived);
@@ -231,7 +237,7 @@
percentOfRemainingBytes = (double)bytesReceived / (double)remainingBytes;
else
percentOfRemainingBytes = 1.0;
-
+
// For documents that use WebCore's layout system, treat first layout as the half-way point.
// FIXME: The hasHTMLView function is a sort of roundabout way of asking "do you use WebCore's layout system".
bool useClampedMaxProgress = frame->loader().client().hasHTMLView()
@@ -241,18 +247,18 @@
m_progressValue += increment;
m_progressValue = std::min(m_progressValue, maxProgressValue);
ASSERT(m_progressValue >= initialProgressValue);
-
+
m_totalBytesReceived += bytesReceived;
-
+
auto now = MonotonicTime::now();
auto notifiedProgressTimeDelta = now - m_lastNotifiedProgressTime;
-
+
LOG(Progress, "Progress incremented (%p) - value %f, tracked frames %d", this, m_progressValue, m_numProgressTrackedFrames);
if ((notifiedProgressTimeDelta >= progressNotificationTimeInterval || m_progressValue == 1) && m_numProgressTrackedFrames > 0) {
if (!m_finalProgressChangedSent) {
if (m_progressValue == 1)
m_finalProgressChangedSent = true;
-
+
m_client.progressEstimateChanged(*frame);
m_lastNotifiedProgressValue = m_progressValue;
@@ -259,7 +265,7 @@
m_lastNotifiedProgressTime = now;
}
}
-
+
m_client.didChangeEstimatedProgress();
}
@@ -272,7 +278,7 @@
return;
ProgressItem& item = *it->value;
-
+
// Adjust the total expected bytes to account for any overage/underage.
long long delta = item.bytesReceived - item.estimatedLength;
m_totalPageAndResourceBytesToLoad += delta;
@@ -312,4 +318,12 @@
m_progressHeartbeatTimer.stop();
}
+bool ProgressTracker::isAlwaysOnLoggingAllowed() const
+{
+ if (!m_originatingProgressFrame)
+ return false;
+
+ return m_originatingProgressFrame->isAlwaysOnLoggingAllowed();
}
+
+}
Modified: trunk/Source/WebCore/loader/ProgressTracker.h (239456 => 239457)
--- trunk/Source/WebCore/loader/ProgressTracker.h 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebCore/loader/ProgressTracker.h 2018-12-20 19:23:20 UTC (rev 239457)
@@ -1,5 +1,5 @@
/*
- * Copyright (C) 2007 Apple Inc. All rights reserved.
+ * Copyright (C) 2007, 2018 Apple Inc. All rights reserved.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions
@@ -20,7 +20,7 @@
* PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY
* OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
* (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
- * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+ * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/
#pragma once
@@ -50,7 +50,7 @@
void progressStarted(Frame&);
void progressCompleted(Frame&);
-
+
void incrementProgress(unsigned long identifier, const ResourceResponse&);
void incrementProgress(unsigned long identifier, unsigned bytesReceived);
void completeProgress(unsigned long identifier);
@@ -65,9 +65,10 @@
void finalProgressComplete();
void progressHeartbeatTimerFired();
-
+ bool isAlwaysOnLoggingAllowed() const;
+
static unsigned long s_uniqueIdentifier;
-
+
ProgressTrackerClient& m_client;
RefPtr<Frame> m_originatingProgressFrame;
HashMap<unsigned long, std::unique_ptr<ProgressItem>> m_progressItems;
@@ -89,5 +90,5 @@
bool m_finalProgressChangedSent { false };
bool m_isMainLoad { false };
};
-
+
} // namespace WebCore
Modified: trunk/Source/WebCore/loader/ResourceLoader.cpp (239456 => 239457)
--- trunk/Source/WebCore/loader/ResourceLoader.cpp 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebCore/loader/ResourceLoader.cpp 2018-12-20 19:23:20 UTC (rev 239457)
@@ -41,6 +41,7 @@
#include "FrameLoaderClient.h"
#include "InspectorInstrumentation.h"
#include "LoaderStrategy.h"
+#include "Logging.h"
#include "Page.h"
#include "PlatformStrategies.h"
#include "ProgressTracker.h"
@@ -60,6 +61,9 @@
#include "PreviewLoader.h"
#endif
+#undef RELEASE_LOG_IF_ALLOWED
+#define RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(isAlwaysOnLoggingAllowed(), Network, "%p - ResourceLoader::" fmt, this, ##__VA_ARGS__)
+
namespace WebCore {
ResourceLoader::ResourceLoader(Frame& frame, ResourceLoaderOptions options)
@@ -256,6 +260,7 @@
if (this->reachedTerminalState())
return;
if (!decodeResult) {
+ RELEASE_LOG_IF_ALLOWED("loadDataURL: decoding of data failed (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
protectedThis->didFail(ResourceError(errorDomainWebKitInternal, 0, url, "Data URL decoding failed"));
return;
}
@@ -353,6 +358,7 @@
auto blockedStatus = page->userContentProvider().processContentExtensionRulesForLoad(request.url(), m_resourceType, *m_documentLoader);
applyBlockedStatusToRequest(blockedStatus, page, request);
if (blockedStatus.blockedLoad) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequestinternal: resource load canceled because of content blocker (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
didFail(blockedByContentBlockerError());
completionHandler({ });
return;
@@ -362,6 +368,7 @@
#endif
if (request.isNull()) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequestinternal: resource load canceled because of empty request (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
didFail(cannotShowURLError());
completionHandler({ });
return;
@@ -517,6 +524,8 @@
void ResourceLoader::didFinishLoading(const NetworkLoadMetrics& networkLoadMetrics)
{
+ RELEASE_LOG_IF_ALLOWED("didFinishLoading: (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
+
didFinishLoadingOnePart(networkLoadMetrics);
// If the load has been cancelled by a delegate in response to didFinishLoad(), do not release
@@ -543,6 +552,8 @@
void ResourceLoader::didFail(const ResourceError& error)
{
+ RELEASE_LOG_IF_ALLOWED("didFail: (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
+
if (wasCancelled())
return;
ASSERT(!m_reachedTerminalState);
@@ -646,6 +657,7 @@
{
RefPtr<ResourceHandle> protectedHandle(handle);
if (documentLoader()->applicationCacheHost().maybeLoadFallbackForRedirect(this, request, redirectResponse)) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequestAsync: exiting early because maybeLoadFallbackForRedirect returned false (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
completionHandler(WTFMove(request));
return;
}
@@ -691,11 +703,13 @@
void ResourceLoader::wasBlocked(ResourceHandle*)
{
+ RELEASE_LOG_IF_ALLOWED("wasBlocked: resource load canceled because of content blocker (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
didFail(blockedError());
}
void ResourceLoader::cannotShowURL(ResourceHandle*)
{
+ RELEASE_LOG_IF_ALLOWED("wasBlocked: resource load canceled because of invalid URL (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
didFail(cannotShowURLError());
}
Modified: trunk/Source/WebCore/loader/SubresourceLoader.cpp (239456 => 239457)
--- trunk/Source/WebCore/loader/SubresourceLoader.cpp 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebCore/loader/SubresourceLoader.cpp 2018-12-20 19:23:20 UTC (rev 239457)
@@ -1,5 +1,5 @@
/*
- * Copyright (C) 2006-2017 Apple Inc. All rights reserved.
+ * Copyright (C) 2006-2018 Apple Inc. All rights reserved.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions
@@ -66,6 +66,11 @@
#include "PreviewLoader.h"
#endif
+#undef RELEASE_LOG_IF_ALLOWED
+#undef RELEASE_LOG_ERROR_IF_ALLOWED
+#define RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(isAlwaysOnLoggingAllowed(), ResourceLoading, "%p - SubresourceLoader::" fmt, this, ##__VA_ARGS__)
+#define RELEASE_LOG_ERROR_IF_ALLOWED(fmt, ...) RELEASE_LOG_ERROR_IF(isAlwaysOnLoggingAllowed(), ResourceLoading, "%p - SubresourceLoader::" fmt, this, ##__VA_ARGS__)
+
namespace WebCore {
DEFINE_DEBUG_ONLY_GLOBAL(WTF::RefCountedLeakCounter, subresourceLoaderCounter, ("SubresourceLoader"));
@@ -214,6 +219,8 @@
if (m_frame && m_frame->document())
m_frame->document()->addConsoleMessage(MessageSource::Security, MessageLevel::Error, error.localizedDescription());
+ RELEASE_LOG_IF_ALLOWED("willSendRequestinternal: resource load canceled because not allowed to follow a redirect (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
+
cancel(error);
return completionHandler(WTFMove(newRequest));
}
@@ -222,13 +229,18 @@
opaqueRedirectedResponse.setType(ResourceResponse::Type::Opaqueredirect);
opaqueRedirectedResponse.setTainting(ResourceResponse::Tainting::Opaqueredirect);
m_resource->responseReceived(opaqueRedirectedResponse);
- if (reachedTerminalState())
+ if (reachedTerminalState()) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequestinternal: reached terminal state (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
return;
+ }
+ RELEASE_LOG_IF_ALLOWED("willSendRequestinternal: resource load completed (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
+
NetworkLoadMetrics emptyMetrics;
didFinishLoading(emptyMetrics);
return completionHandler(WTFMove(newRequest));
} else if (m_redirectCount++ >= options().maxRedirectCount) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequestinternal: resource load canceled because too many redirects (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
cancel(ResourceError(String(), 0, request().url(), "Too many redirections"_s, ResourceError::Type::General));
return completionHandler(WTFMove(newRequest));
}
@@ -245,6 +257,7 @@
}
if (!m_documentLoader->cachedResourceLoader().updateRequestAfterRedirection(m_resource->type(), newRequest, options())) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequestinternal: resource load canceled because something about updateRequestAfterRedirection (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
cancel();
return completionHandler(WTFMove(newRequest));
}
@@ -254,11 +267,13 @@
String errorMessage = "Cross-origin redirection to " + newRequest.url().string() + " denied by Cross-Origin Resource Sharing policy: " + errorDescription;
if (m_frame && m_frame->document())
m_frame->document()->addConsoleMessage(MessageSource::Security, MessageLevel::Error, errorMessage);
+ RELEASE_LOG_IF_ALLOWED("willSendRequestinternal: resource load canceled because crosss-origin redirection denied by CORS policy (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
cancel(ResourceError(String(), 0, request().url(), errorMessage, ResourceError::Type::AccessControl));
return completionHandler(WTFMove(newRequest));
}
if (m_resource->isImage() && m_documentLoader->cachedResourceLoader().shouldDeferImageLoad(newRequest.url())) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequestinternal: resource load canceled because it's an image that should be defered (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
cancel();
return completionHandler(WTFMove(newRequest));
}
@@ -312,6 +327,7 @@
if (response.source() == ResourceResponse::Source::ServiceWorker && response.url() != request().url()) {
auto& loader = m_documentLoader->cachedResourceLoader();
if (!loader.allowedByContentSecurityPolicy(m_resource->type(), response.url(), options(), ContentSecurityPolicy::RedirectResponseReceived::Yes)) {
+ RELEASE_LOG_IF_ALLOWED("didReceiveResponse: canceling load because not allowed by content policy (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
cancel(ResourceError({ }, 0, response.url(), { }, ResourceError::Type::General));
return;
}
@@ -356,6 +372,7 @@
if (!checkResponseCrossOriginAccessControl(response, errorDescription)) {
if (m_frame && m_frame->document())
m_frame->document()->addConsoleMessage(MessageSource::Security, MessageLevel::Error, errorDescription);
+ RELEASE_LOG_IF_ALLOWED("didReceiveResponse: canceling load because of cross origin access control (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
cancel(ResourceError(String(), 0, request().url(), errorDescription, ResourceError::Type::AccessControl));
return;
}
@@ -379,6 +396,7 @@
// We don't count multiParts in a CachedResourceLoader's request count
m_requestCountTracker = WTF::nullopt;
if (!m_resource->isImage()) {
+ RELEASE_LOG_IF_ALLOWED("didReceiveResponse: canceling load because something about a multi-part non-image (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
cancel();
return;
}
@@ -596,6 +614,8 @@
void SubresourceLoader::didFinishLoading(const NetworkLoadMetrics& networkLoadMetrics)
{
+ RELEASE_LOG_IF_ALLOWED("didFinishLoading: (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
+
#if USE(QUICK_LOOK)
if (auto previewLoader = m_previewLoader.get()) {
if (previewLoader->didFinishLoading())
@@ -633,8 +653,10 @@
m_state = Finishing;
m_resource->finishLoading(resourceData());
- if (wasCancelled())
+ if (wasCancelled()) {
+ RELEASE_LOG_IF_ALLOWED("didFinishLoading: was canceled (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
return;
+ }
m_resource->finish();
ASSERT(!reachedTerminalState());
@@ -641,13 +663,16 @@
didFinishLoadingOnePart(networkLoadMetrics);
notifyDone(LoadCompletionType::Finish);
- if (reachedTerminalState())
+ if (reachedTerminalState()) {
+ RELEASE_LOG_IF_ALLOWED("didFinishLoading: reached terminal state (frame = %p, frameLoader = %p, resourceID = %lu)", frame(), frameLoader(), identifier());
return;
+ }
releaseResources();
}
void SubresourceLoader::didFail(const ResourceError& error)
{
+ RELEASE_LOG_IF_ALLOWED("didFail: (frame = %p, frameLoader = %p, resourceID = %lu, type = %d, code = %d)", frame(), frameLoader(), identifier(), static_cast<int>(error.type()), error.errorCode());
#if USE(QUICK_LOOK)
if (auto previewLoader = m_previewLoader.get())
@@ -656,8 +681,10 @@
if (m_state != Initialized)
return;
+
ASSERT(!reachedTerminalState());
LOG(ResourceLoading, "Failed to load '%s'.\n", m_resource->url().string().latin1().data());
+
if (m_frame->document() && error.isAccessControl())
m_frame->document()->addConsoleMessage(MessageSource::Security, MessageLevel::Error, error.localizedDescription());
@@ -684,6 +711,8 @@
void SubresourceLoader::willCancel(const ResourceError& error)
{
+ RELEASE_LOG_IF_ALLOWED("willCancel: (frame = %p, frameLoader = %p, resourceID = %lu, type = %d, code = %d)", frame(), frameLoader(), identifier(), static_cast<int>(error.type()), error.errorCode());
+
#if PLATFORM(IOS_FAMILY)
// Since we defer initialization to scheduling time on iOS but
// CachedResourceLoader stores resources in the memory cache immediately,
@@ -693,6 +722,7 @@
if (m_state != Initialized)
#endif
return;
+
ASSERT(!reachedTerminalState());
LOG(ResourceLoading, "Cancelled load of '%s'.\n", m_resource->url().string().latin1().data());
@@ -786,3 +816,6 @@
}
}
+
+#undef RELEASE_LOG_IF_ALLOWED
+#undef RELEASE_LOG_ERROR_IF_ALLOWED
Modified: trunk/Source/WebCore/loader/cache/CachedResource.cpp (239456 => 239457)
--- trunk/Source/WebCore/loader/cache/CachedResource.cpp 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebCore/loader/cache/CachedResource.cpp 2018-12-20 19:23:20 UTC (rev 239457)
@@ -3,7 +3,7 @@
Copyright (C) 2001 Dirk Mueller ([email protected])
Copyright (C) 2002 Waldo Bastian ([email protected])
Copyright (C) 2006 Samuel Weinig ([email protected])
- Copyright (C) 2004-2011, 2014 Apple Inc. All rights reserved.
+ Copyright (C) 2004-2011, 2014, 2018 Apple Inc. All rights reserved.
This library is free software; you can redistribute it and/or
modify it under the terms of the GNU Library General Public
@@ -208,9 +208,11 @@
// Beacons are allowed to go through in 'pagehide' event handlers.
if (shouldUsePingLoad(type()))
break;
- FALLTHROUGH;
+ RELEASE_LOG_IF_ALLOWED("load: About to enter page cache (frame = %p)", &frame);
+ failBeforeStarting();
+ return;
case Document::InPageCache:
- RELEASE_LOG_IF_ALLOWED("load: Already in page cache or being added to it (frame = %p)", &frame);
+ RELEASE_LOG_IF_ALLOWED("load: Already in page cache (frame = %p)", &frame);
failBeforeStarting();
return;
}
@@ -217,15 +219,19 @@
}
FrameLoader& frameLoader = frame.loader();
- if (m_options.securityCheck == SecurityCheckPolicy::DoSecurityCheck && !shouldUsePingLoad(type()) && (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;
+ if (m_options.securityCheck == SecurityCheckPolicy::DoSecurityCheck && !shouldUsePingLoad(type())) {
+ while (true) {
+ 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);
+ else
+ break;
+ failBeforeStarting();
+ return;
+ }
}
m_loading = true;
Modified: trunk/Source/WebKit/ChangeLog (239456 => 239457)
--- trunk/Source/WebKit/ChangeLog 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebKit/ChangeLog 2018-12-20 19:23:20 UTC (rev 239457)
@@ -1,3 +1,74 @@
+2018-12-20 Keith Rollin <[email protected]>
+
+ Improve release-level page-load logging
+ https://bugs.webkit.org/show_bug.cgi?id=192872
+ <rdar://problem/46850309>
+
+ Reviewed by Chris Dumez.
+
+ There are a number of reported bugs that are difficult or impossible
+ to track down with our current level of logging. Additionally, some
+ software groups lower in the page-loading stack have requested logging
+ sufficient for tracking a user-visible error message down to the
+ requested resource that caused the message. Add more-comprehensive
+ logging to address these issues/requests.
+
+ * UIProcess/WebPageProxy.cpp:
+ (WebKit::m_editableImageController):
+ (WebKit::WebPageProxy::~WebPageProxy):
+ (WebKit::WebPageProxy::reattachToWebProcess):
+ (WebKit::WebPageProxy::swapToWebProcess):
+ (WebKit::WebPageProxy::reattachToWebProcessForReload):
+ (WebKit::WebPageProxy::reattachToWebProcessWithItem):
+ (WebKit::WebPageProxy::close):
+ (WebKit::WebPageProxy::tryClose):
+ (WebKit::WebPageProxy::loadRequest):
+ (WebKit::WebPageProxy::loadRequestWithNavigation):
+ (WebKit::WebPageProxy::loadFile):
+ (WebKit::WebPageProxy::loadData):
+ (WebKit::WebPageProxy::loadDataWithNavigation):
+ (WebKit::WebPageProxy::loadAlternateHTML):
+ (WebKit::WebPageProxy::loadWebArchiveData):
+ (WebKit::WebPageProxy::navigateToPDFLinkWithSimulatedClick):
+ (WebKit::WebPageProxy::stopLoading):
+ (WebKit::WebPageProxy::reload):
+ (WebKit::WebPageProxy::goToBackForwardItem):
+ (WebKit::WebPageProxy::tryRestoreScrollPosition):
+ (WebKit::WebPageProxy::updateThrottleState):
+ (WebKit::WebPageProxy::receivedNavigationPolicyDecision):
+ (WebKit::WebPageProxy::continueNavigationInNewProcess):
+ (WebKit::WebPageProxy::restoreFromSessionState):
+ (WebKit::WebPageProxy::didStartProvisionalLoadForFrame):
+ (WebKit::WebPageProxy::didReceiveServerRedirectForProvisionalLoadForFrame):
+ (WebKit::WebPageProxy::willPerformClientRedirectForFrame):
+ (WebKit::WebPageProxy::didCancelClientRedirectForFrame):
+ (WebKit::WebPageProxy::didFailProvisionalLoadForFrame):
+ (WebKit::WebPageProxy::didCommitLoadForFrame):
+ (WebKit::WebPageProxy::didFinishDocumentLoadForFrame):
+ (WebKit::WebPageProxy::didFinishLoadForFrame):
+ (WebKit::WebPageProxy::didFailLoadForFrame):
+ (WebKit::WebPageProxy::didSameDocumentNavigationForFrame):
+ (WebKit::WebPageProxy::didNavigateWithNavigationData):
+ (WebKit::WebPageProxy::didPerformClientRedirect):
+ (WebKit::WebPageProxy::didPerformServerRedirect):
+ (WebKit::WebPageProxy::processDidBecomeUnresponsive):
+ (WebKit::WebPageProxy::processDidBecomeResponsive):
+ (WebKit::WebPageProxy::processDidTerminate):
+ (WebKit::WebPageProxy::dispatchProcessDidTerminate):
+ (WebKit::WebPageProxy::tryReloadAfterProcessTermination):
+ (WebKit::WebPageProxy::didExceedInactiveMemoryLimitWhileActive):
+ (WebKit::WebPageProxy::didExceedBackgroundCPULimitWhileInForeground):
+ * WebProcess/Network/WebLoaderStrategy.cpp:
+ (WebKit::WebLoaderStrategy::scheduleLoad):
+ (WebKit::WebLoaderStrategy::scheduleLoadFromNetworkProcess):
+ (WebKit::WebLoaderStrategy::loadResourceSynchronously):
+ * WebProcess/Network/WebResourceLoader.cpp:
+ (WebKit::WebResourceLoader::willSendRequest):
+ (WebKit::WebResourceLoader::didReceiveResponse):
+ * WebProcess/WebCoreSupport/WebFrameLoaderClient.cpp:
+ (WebKit::WebFrameLoaderClient::dispatchDidFailProvisionalLoad):
+ (WebKit::WebFrameLoaderClient::dispatchDidFailLoad):
+
2018-12-20 Wenson Hsieh <[email protected]>
[iOS] Replace "node assistance" terminology in WebKit with "focused element"
Modified: trunk/Source/WebKit/UIProcess/WebPageProxy.cpp (239456 => 239457)
--- trunk/Source/WebKit/UIProcess/WebPageProxy.cpp 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebKit/UIProcess/WebPageProxy.cpp 2018-12-20 19:23:20 UTC (rev 239457)
@@ -243,7 +243,7 @@
#define MESSAGE_CHECK(assertion) MESSAGE_CHECK_BASE(assertion, m_process->connection())
#define MESSAGE_CHECK_URL(url) MESSAGE_CHECK_BASE(checkURLReceivedFromCurrentOrPreviousWebProcess(url), m_process->connection())
-#define RELEASE_LOG_IF_ALLOWED(channel, ...) RELEASE_LOG_IF(isAlwaysOnLoggingAllowed(), channel, __VA_ARGS__)
+#define RELEASE_LOG_IF_ALLOWED(channel, fmt, ...) RELEASE_LOG_IF(isAlwaysOnLoggingAllowed(), channel, "%p - WebPageProxy::" fmt, this, ##__VA_ARGS__)
// Represents the number of wheel events we can hold in the queue before we start pushing them preemptively.
static const unsigned wheelEventQueueSizeThreshold = 10;
@@ -444,6 +444,8 @@
, m_editableImageController(std::make_unique<EditableImageController>(*this))
#endif
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "constructor: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
m_webProcessLifetimeTracker.addObserver(m_visitedLinkStore);
m_webProcessLifetimeTracker.addObserver(m_websiteDataStore);
@@ -509,6 +511,8 @@
WebPageProxy::~WebPageProxy()
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "destructor: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
ASSERT(m_process->webPage(m_pageID) != this);
#if !ASSERT_DISABLED
for (WebPageProxy* page : m_process->pages())
@@ -726,8 +730,9 @@
{
ASSERT(!m_isClosed);
ASSERT(!isValid());
- RELEASE_LOG_IF_ALLOWED(Process, "%p WebPageProxy::reattachToWebProcess\n", this);
+ RELEASE_LOG_IF_ALLOWED(Loading, "reattachToWebProcess: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
m_process->removeWebPage(*this, m_pageID, WebProcessProxy::EndsUsingDataStore::Yes);
m_process->removeMessageReceiver(Messages::WebPageProxy::messageReceiverName(), m_pageID);
@@ -770,7 +775,7 @@
void WebPageProxy::swapToWebProcess(Ref<WebProcessProxy>&& process, std::unique_ptr<SuspendedPageProxy>&& destinationSuspendedPage, ShouldDelayAttachingDrawingArea shouldDelayAttachingDrawingArea)
{
ASSERT(!m_isClosed);
- RELEASE_LOG_IF_ALLOWED(Process, "%p WebPageProxy::swapToWebProcess\n", this);
+ RELEASE_LOG_IF_ALLOWED(Loading, "swapToWebProcess: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
m_process = WTFMove(process);
m_isValid = true;
@@ -852,14 +857,20 @@
RefPtr<API::Navigation> WebPageProxy::reattachToWebProcessForReload()
{
- if (m_isClosed)
+ RELEASE_LOG_IF_ALLOWED(Loading, "reattachToWebProcessForReload: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
+ if (m_isClosed) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "reattachToWebProcessForReload: page is closed: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return nullptr;
+ }
ASSERT(!isValid());
reattachToWebProcess();
- if (!m_backForwardList->currentItem())
+ if (!m_backForwardList->currentItem()) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "reattachToWebProcessForReload: no current item to reload: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return nullptr;
+ }
auto navigation = m_navigationState->createReloadNavigation();
@@ -872,8 +883,12 @@
RefPtr<API::Navigation> WebPageProxy::reattachToWebProcessWithItem(WebBackForwardListItem& item)
{
- if (m_isClosed)
+ RELEASE_LOG_IF_ALLOWED(Loading, "reattachToWebProcessWithItem: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
+ if (m_isClosed) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "reattachToWebProcessWithItem: page is closed: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return nullptr;
+ }
ASSERT(!isValid());
reattachToWebProcess();
@@ -939,6 +954,8 @@
if (m_isClosed)
return;
+ RELEASE_LOG_IF_ALLOWED(Loading, "close: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
m_isClosed = true;
#if ENABLE(MEDIA_STREAM)
@@ -1013,6 +1030,8 @@
if (!isValid())
return true;
+ RELEASE_LOG_IF_ALLOWED(Loading, "tryClose: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
// Close without delay if the process allows it. Our goal is to terminate
// the process, so we check a per-process status bit.
if (m_process->isSuddenTerminationEnabled())
@@ -1049,6 +1068,8 @@
if (m_isClosed)
return nullptr;
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadRequest: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
auto navigation = m_navigationState->createLoadRequestNavigation(ResourceRequest(request), m_backForwardList->currentItem());
loadRequestWithNavigation(navigation.get(), WTFMove(request), shouldOpenExternalURLsPolicy, userData, ShouldTreatAsContinuingLoad::No);
return WTFMove(navigation);
@@ -1058,6 +1079,8 @@
{
ASSERT(!m_isClosed);
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadRequestWithNavigation: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
auto transaction = m_pageLoadState.transaction();
auto url = ""
@@ -1087,15 +1110,21 @@
RefPtr<API::Navigation> WebPageProxy::loadFile(const String& fileURLString, const String& resourceDirectoryURLString, API::Object* userData)
{
- if (m_isClosed)
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadFile: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
+ if (m_isClosed) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadFile: page is closed: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return nullptr;
+ }
if (!isValid())
reattachToWebProcess();
URL fileURL = URL(URL(), fileURLString);
- if (!fileURL.isLocalFile())
+ if (!fileURL.isLocalFile()) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadFile: file is not local: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return nullptr;
+ }
URL resourceDirectoryURL;
if (resourceDirectoryURLString.isNull())
@@ -1102,8 +1131,10 @@
resourceDirectoryURL = URL({ }, "file:///"_s);
else {
resourceDirectoryURL = URL(URL(), resourceDirectoryURLString);
- if (!resourceDirectoryURL.isLocalFile())
+ if (!resourceDirectoryURL.isLocalFile()) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadFile: resource URL is not local: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return nullptr;
+ }
}
auto navigation = m_navigationState->createLoadRequestNavigation(ResourceRequest(fileURL), m_backForwardList->currentItem());
@@ -1131,8 +1162,12 @@
RefPtr<API::Navigation> WebPageProxy::loadData(const IPC::DataReference& data, const String& MIMEType, const String& encoding, const String& baseURL, API::Object* userData)
{
- if (m_isClosed)
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadData: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
+ if (m_isClosed) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadData: page is closed: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return nullptr;
+ }
auto navigation = m_navigationState->createLoadDataNavigation(std::make_unique<API::SubstituteData>(data.vector(), MIMEType, encoding, baseURL, userData));
loadDataWithNavigation(navigation, data, MIMEType, encoding, baseURL, userData, ShouldTreatAsContinuingLoad::No);
@@ -1141,6 +1176,8 @@
void WebPageProxy::loadDataWithNavigation(API::Navigation& navigation, const IPC::DataReference& data, const String& MIMEType, const String& encoding, const String& baseURL, API::Object* userData, ShouldTreatAsContinuingLoad shouldTreatAsContinuingLoad, Optional<WebsitePoliciesData>&& websitePolicies)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadDataWithNavigation: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
ASSERT(!m_isClosed);
auto transaction = m_pageLoadState.transaction();
@@ -1168,11 +1205,15 @@
void WebPageProxy::loadAlternateHTML(const IPC::DataReference& htmlData, const String& encoding, const URL& baseURL, const URL& unreachableURL, API::Object* userData)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadAlternateHTML: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
// When the UIProcess is in the process of handling a failing provisional load, do not attempt to
// start a second alternative HTML load as this will prevent the page load state from being
// handled properly.
- if (m_isClosed || m_isLoadingAlternateHTMLStringForFailingProvisionalLoad)
+ if (m_isClosed || m_isLoadingAlternateHTMLStringForFailingProvisionalLoad) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadAlternateHTML: page is closed (or other): webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return;
+ }
if (!m_failingProvisionalLoadURL.isEmpty())
m_isLoadingAlternateHTMLStringForFailingProvisionalLoad = true;
@@ -1207,8 +1248,12 @@
void WebPageProxy::loadWebArchiveData(API::Data* webArchiveData, API::Object* userData)
{
- if (m_isClosed)
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadWebArchiveData: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
+ if (m_isClosed) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "loadWebArchiveData: page is closed: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return;
+ }
if (!isValid())
reattachToWebProcess();
@@ -1230,8 +1275,12 @@
void WebPageProxy::navigateToPDFLinkWithSimulatedClick(const String& url, IntPoint documentPoint, IntPoint screenPoint)
{
- if (m_isClosed)
+ RELEASE_LOG_IF_ALLOWED(Loading, "navigateToPDFLinkWithSimulatedClick: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
+ if (m_isClosed) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "navigateToPDFLinkWithSimulatedClick: page is closed: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return;
+ }
if (WTF::protocolIsJavaScript(url))
return;
@@ -1245,8 +1294,12 @@
void WebPageProxy::stopLoading()
{
- if (!isValid())
+ RELEASE_LOG_IF_ALLOWED(Loading, "stopLoading: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
+ if (!isValid()) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "navigateToPDFLinkWithSimulatedClick: page is not valid: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return;
+ }
m_process->send(Messages::WebPage::StopLoading(), m_pageID);
m_process->responsivenessTimer().start();
@@ -1254,6 +1307,8 @@
RefPtr<API::Navigation> WebPageProxy::reload(OptionSet<WebCore::ReloadOption> options)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "reload: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
SandboxExtension::Handle sandboxExtensionHandle;
String url = ""
@@ -1324,6 +1379,7 @@
RefPtr<API::Navigation> WebPageProxy::goToBackForwardItem(WebBackForwardListItem& item, FrameLoadType frameLoadType)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "goToBackForwardItem: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
LOG(Loading, "WebPageProxy %p goToBackForwardItem to item URL %s", this, item.url().utf8().data());
if (!isValid())
@@ -1345,8 +1401,12 @@
void WebPageProxy::tryRestoreScrollPosition()
{
- if (!isValid())
+ RELEASE_LOG_IF_ALLOWED(Loading, "tryRestoreScrollPosition: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
+ if (!isValid()) {
+ RELEASE_LOG_IF_ALLOWED(Loading, "tryRestoreScrollPosition: page is not valid: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
return;
+ }
m_process->send(Messages::WebPage::TryRestoreScrollPosition(), m_pageID);
}
@@ -1740,18 +1800,18 @@
bool isAudible = m_activityState.contains(ActivityState::IsAudible);
if (!isViewVisible() && !m_alwaysRunsAtForegroundPriority && !isCapturingMedia && !isAudible) {
if (m_activityToken) {
- RELEASE_LOG_IF_ALLOWED(ProcessSuspension, "%p - UIProcess is releasing a foreground assertion because the view is no longer visible", this);
+ RELEASE_LOG_IF_ALLOWED(ProcessSuspension, "updateThrottleState: UIProcess is releasing a foreground assertion because the view is no longer visible");
m_activityToken = nullptr;
}
} else if (!m_activityToken) {
if (isViewVisible())
- RELEASE_LOG_IF_ALLOWED(ProcessSuspension, "%p - UIProcess is taking a foreground assertion because the view is visible", this);
+ RELEASE_LOG_IF_ALLOWED(ProcessSuspension, "updateThrottleState: UIProcess is taking a foreground assertion because the view is visible");
else if (isAudible)
- RELEASE_LOG_IF_ALLOWED(ProcessSuspension, "%p - UIProcess is taking a foreground assertion because we are playing audio", this);
+ RELEASE_LOG_IF_ALLOWED(ProcessSuspension, "updateThrottleState: UIProcess is taking a foreground assertion because we are playing audio");
else if (isCapturingMedia)
- RELEASE_LOG_IF_ALLOWED(ProcessSuspension, "%p - UIProcess is taking a foreground assertion because media capture is active", this);
+ RELEASE_LOG_IF_ALLOWED(ProcessSuspension, "updateThrottleState: UIProcess is taking a foreground assertion because media capture is active");
else
- RELEASE_LOG_IF_ALLOWED(ProcessSuspension, "%p - UIProcess is taking a foreground assertion even though the view is not visible because m_alwaysRunsAtForegroundPriority is true", this);
+ RELEASE_LOG_IF_ALLOWED(ProcessSuspension, "updateThrottleState: UIProcess is taking a foreground assertion even though the view is not visible because m_alwaysRunsAtForegroundPriority is true");
m_activityToken = m_process->throttler().foregroundActivityToken();
}
#endif
@@ -2641,10 +2701,10 @@
if (processForNavigation.ptr() != &process()) {
policyAction = isPageOpenedByDOMShowingInitialEmptyDocument() ? WebPolicyAction::Ignore : WebPolicyAction::Suspend;
- RELEASE_LOG_IF_ALLOWED(ProcessSwapping, "%p - WebPageProxy::decidePolicyForNavigationAction, swapping process %i with process %i for navigation, reason: %{public}s", this, processIdentifier(), processForNavigation->processIdentifier(), reason.utf8().data());
+ RELEASE_LOG_IF_ALLOWED(ProcessSwapping, "decidePolicyForNavigationAction, swapping process %i with process %i for navigation, reason: %{public}s", processIdentifier(), processForNavigation->processIdentifier(), reason.utf8().data());
LOG(ProcessSwapping, "(ProcessSwapping) Switching from process %i to new process (%i) for navigation %" PRIu64 " '%s'", processIdentifier(), processForNavigation->processIdentifier(), navigation->navigationID(), navigation->loggingString());
} else
- RELEASE_LOG_IF_ALLOWED(ProcessSwapping, "%p - WebPageProxy::decidePolicyForNavigationAction, keep using process %i for navigation, reason: %{public}s", this, processIdentifier(), reason.utf8().data());
+ RELEASE_LOG_IF_ALLOWED(ProcessSwapping, "decidePolicyForNavigationAction: keep using process %i for navigation, reason: %{public}s", processIdentifier(), reason.utf8().data());
bool shouldProcessSwap = processForNavigation.ptr() != &process();
receivedPolicyDecision(policyAction, navigation.ptr(), shouldProcessSwap ? WTF::nullopt : WTFMove(data), WTFMove(sender));
@@ -2688,6 +2748,7 @@
void WebPageProxy::continueNavigationInNewProcess(API::Navigation& navigation, std::unique_ptr<SuspendedPageProxy>&& suspendedPageProxy, Ref<WebProcessProxy>&& process, ProcessSwapRequestedByClient processSwapRequestedByClient, Optional<WebsitePoliciesData>&& websitePolicies)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "continueNavigationInNewProcess: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
LOG(Loading, "Continuing navigation %" PRIu64 " '%s' in a new web process", navigation.navigationID(), navigation.loggingString());
Ref<WebProcessProxy> previousProcess = m_process.copyRef();
@@ -2898,6 +2959,8 @@
RefPtr<API::Navigation> WebPageProxy::restoreFromSessionState(SessionState sessionState, bool navigate)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "restoreFromSessionState: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
m_sessionRestorationRenderTreeSize = 0;
m_hitRenderTreeSizeThreshold = false;
@@ -3744,6 +3807,7 @@
}
LOG(Loading, "WebPageProxy %" PRIu64 " in process pid %i didStartProvisionalLoadForFrame to frameID %" PRIu64 ", navigationID %" PRIu64 ", url %s", m_pageID, m_process->processIdentifier(), frameID, navigationID, url.string().utf8().data());
+ RELEASE_LOG_IF_ALLOWED(Loading, "didStartProvisionalLoadForFrame: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64, m_process->processIdentifier(), m_pageID, frameID);
auto transaction = m_pageLoadState.transaction();
@@ -3770,6 +3834,7 @@
void WebPageProxy::didReceiveServerRedirectForProvisionalLoadForFrame(uint64_t frameID, uint64_t navigationID, ResourceRequest&& request, const UserData& userData)
{
LOG(Loading, "WebPageProxy::didReceiveServerRedirectForProvisionalLoadForFrame to frameID %" PRIu64 ", navigationID %" PRIu64 ", url %s", frameID, navigationID, request.url().string().utf8().data());
+ RELEASE_LOG_IF_ALLOWED(Loading, "didReceiveServerRedirectForProvisionalLoadForFrame: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64, m_process->processIdentifier(), m_pageID, frameID);
PageClientProtector protector(pageClient());
@@ -3798,6 +3863,8 @@
void WebPageProxy::willPerformClientRedirectForFrame(uint64_t frameID, const String& url, double delay, WebCore::LockBackForwardList)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "willPerformClientRedirectForFrame: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64, m_process->processIdentifier(), m_pageID, frameID);
+
PageClientProtector protector(pageClient());
WebFrameProxy* frame = m_process->webFrame(frameID);
@@ -3809,6 +3876,8 @@
void WebPageProxy::didCancelClientRedirectForFrame(uint64_t frameID)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "didCancelClientRedirectForFrame: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64, m_process->processIdentifier(), m_pageID, frameID);
+
PageClientProtector protector(pageClient());
WebFrameProxy* frame = m_process->webFrame(frameID);
@@ -3840,6 +3909,7 @@
void WebPageProxy::didFailProvisionalLoadForFrame(uint64_t frameID, const SecurityOriginData& frameSecurityOrigin, uint64_t navigationID, const String& provisionalURL, const ResourceError& error, const UserData& userData)
{
LOG(Loading, "(Loading) WebPageProxy %" PRIu64 " in web process pid %i didFailProvisionalLoadForFrame to provisionalURL %s", m_pageID, m_process->processIdentifier(), provisionalURL.utf8().data());
+ RELEASE_LOG_IF_ALLOWED(Process, "didFailProvisionalLoadForFrame: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64 ", domain = %s, code = %d", m_process->processIdentifier(), m_pageID, frameID, error.domain().utf8().data(), error.errorCode());
PageClientProtector protector(pageClient());
@@ -3896,6 +3966,7 @@
{
LOG(Loading, "(Loading) WebPageProxy %" PRIu64 " didCommitLoadForFrame in navigation %" PRIu64, m_pageID, m_navigationID);
LOG(BackForward, "(Back/Forward) After load commit, back/forward list is now:%s", m_backForwardList->loggingString());
+ RELEASE_LOG_IF_ALLOWED(Loading, "didCommitLoadForFrame: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64, m_process->processIdentifier(), m_pageID, frameID);
PageClientProtector protector(pageClient());
@@ -3989,6 +4060,8 @@
void WebPageProxy::didFinishDocumentLoadForFrame(uint64_t frameID, uint64_t navigationID, const UserData& userData)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "didFinishDocumentLoadForFrame: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64, m_process->processIdentifier(), m_pageID, frameID);
+
PageClientProtector protector(pageClient());
WebFrameProxy* frame = m_process->webFrame(frameID);
@@ -4011,6 +4084,7 @@
void WebPageProxy::didFinishLoadForFrame(uint64_t frameID, uint64_t navigationID, const UserData& userData)
{
LOG(Loading, "WebPageProxy::didFinishLoadForFrame - WebPageProxy %p with navigationID %" PRIu64 " didFinishLoad", this, navigationID);
+ RELEASE_LOG_IF_ALLOWED(Loading, "didFinishLoadForFrame: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64, m_process->processIdentifier(), m_pageID, frameID);
PageClientProtector protector(pageClient());
@@ -4055,6 +4129,8 @@
void WebPageProxy::didFailLoadForFrame(uint64_t frameID, uint64_t navigationID, const ResourceError& error, const UserData& userData)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "didFailLoadForFrame: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64 ", domain = %s, code = %d", m_process->processIdentifier(), m_pageID, frameID, error.domain().utf8().data(), error.errorCode());
+
PageClientProtector protector(pageClient());
WebFrameProxy* frame = m_process->webFrame(frameID);
@@ -4095,6 +4171,8 @@
void WebPageProxy::didSameDocumentNavigationForFrame(uint64_t frameID, uint64_t navigationID, uint32_t opaqueSameDocumentNavigationType, URL&& url, const UserData& userData)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "didSameDocumentNavigationForFrame: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64, m_process->processIdentifier(), m_pageID, frameID);
+
PageClientProtector protector(pageClient());
WebFrameProxy* frame = m_process->webFrame(frameID);
@@ -4518,6 +4596,8 @@
void WebPageProxy::didNavigateWithNavigationData(const WebNavigationDataStore& store, uint64_t frameID)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "didNavigateWithNavigationData: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
PageClientProtector protector(pageClient());
WebFrameProxy* frame = m_process->webFrame(frameID);
@@ -4531,6 +4611,8 @@
void WebPageProxy::didPerformClientRedirect(const String& sourceURLString, const String& destinationURLString, uint64_t frameID)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "didPerformClientRedirect: webPID = %i, pageID = %" PRIu64 ", frameID = %" PRIu64, m_process->processIdentifier(), m_pageID, frameID);
+
PageClientProtector protector(pageClient());
if (sourceURLString.isEmpty() || destinationURLString.isEmpty())
@@ -4551,6 +4633,8 @@
void WebPageProxy::didPerformServerRedirect(const String& sourceURLString, const String& destinationURLString, uint64_t frameID)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "didPerformServerRedirect: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
PageClientProtector protector(pageClient());
if (sourceURLString.isEmpty() || destinationURLString.isEmpty())
@@ -6183,6 +6267,8 @@
void WebPageProxy::processDidBecomeUnresponsive()
{
+ RELEASE_LOG_IF_ALLOWED(Process, "processDidBecomeUnresponsive: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
if (!isValid())
return;
@@ -6193,6 +6279,8 @@
void WebPageProxy::processDidBecomeResponsive()
{
+ RELEASE_LOG_IF_ALLOWED(Process, "processDidBecomeResponsive: webPID = %i, pageID = %" PRIu64, m_process->processIdentifier(), m_pageID);
+
if (!isValid())
return;
@@ -6222,7 +6310,7 @@
void WebPageProxy::processDidTerminate(ProcessTerminationReason reason)
{
if (reason != ProcessTerminationReason::NavigationSwap)
- RELEASE_LOG_IF_ALLOWED(Process, "%p - WebPageProxy::processDidTerminate (pid %d), reason %d", this, processIdentifier(), reason);
+ RELEASE_LOG_IF_ALLOWED(Process, "processDidTerminate: (pid %d), reason %d", processIdentifier(), reason);
ASSERT(m_isValid);
@@ -6273,6 +6361,8 @@
void WebPageProxy::dispatchProcessDidTerminate(ProcessTerminationReason reason)
{
+ RELEASE_LOG_IF_ALLOWED(Loading, "dispatchProcessDidTerminate: webPID = %i, reason = %d", m_process->processIdentifier(), reason);
+
bool handledByClient = false;
if (m_loaderClient)
handledByClient = reason != ProcessTerminationReason::RequestedByClient && m_loaderClient->processDidCrash(*this);
@@ -6288,11 +6378,11 @@
m_resetRecentCrashCountTimer.stop();
if (++m_recentCrashCount > maximumWebProcessRelaunchAttempts) {
- RELEASE_LOG_IF_ALLOWED(Process, "%p - WebPageProxy's process crashed and the client did not handle it, not reloading the page because we reached the maximum number of attempts", this);
+ RELEASE_LOG_IF_ALLOWED(Process, "tryReloadAfterProcessTermination: process crashed and the client did not handle it, not reloading the page because we reached the maximum number of attempts");
m_recentCrashCount = 0;
return;
}
- RELEASE_LOG_IF_ALLOWED(Process, "%p - WebPageProxy's process crashed and the client did not handle it, reloading the page", this);
+ RELEASE_LOG_IF_ALLOWED(Process, "tryReloadAfterProcessTermination: process crashed and the client did not handle it, reloading the page");
reload(ReloadOption::ExpiredOnly);
}
@@ -7800,13 +7890,13 @@
void WebPageProxy::didExceedInactiveMemoryLimitWhileActive()
{
- RELEASE_LOG_IF_ALLOWED(PerformanceLogging, "%p - WebPageProxy::didExceedInactiveMemoryLimitWhileActive()", this);
+ RELEASE_LOG_IF_ALLOWED(PerformanceLogging, "didExceedInactiveMemoryLimitWhileActive");
m_uiClient->didExceedBackgroundResourceLimitWhileInForeground(*this, kWKResourceLimitMemory);
}
void WebPageProxy::didExceedBackgroundCPULimitWhileInForeground()
{
- RELEASE_LOG_IF_ALLOWED(PerformanceLogging, "%p - WebPageProxy::didExceedBackgroundCPULimitWhileInForeground()", this);
+ RELEASE_LOG_IF_ALLOWED(PerformanceLogging, "didExceedBackgroundCPULimitWhileInForeground");
m_uiClient->didExceedBackgroundResourceLimitWhileInForeground(*this, kWKResourceLimitCPU);
}
Modified: trunk/Source/WebKit/WebProcess/Network/WebLoaderStrategy.cpp (239456 => 239457)
--- trunk/Source/WebKit/WebProcess/Network/WebLoaderStrategy.cpp 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebKit/WebProcess/Network/WebLoaderStrategy.cpp 2018-12-20 19:23:20 UTC (rev 239457)
@@ -1,5 +1,5 @@
/*
- * Copyright (C) 2012, 2015 Apple Inc. All rights reserved.
+ * Copyright (C) 2012, 2015, 2018 Apple Inc. All rights reserved.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions
@@ -207,12 +207,14 @@
#endif
#if ENABLE(SERVICE_WORKER)
- WebServiceWorkerProvider::singleton().handleFetch(resourceLoader, resource, sessionID, shouldClearReferrerOnHTTPSToHTTPRedirect, [trackingParameters, sessionID, shouldClearReferrerOnHTTPSToHTTPRedirect, maximumBufferingTime = maximumBufferingTime(resource), resourceLoader = makeRef(resourceLoader)] (ServiceWorkerClientFetch::Result result) mutable {
+ WebServiceWorkerProvider::singleton().handleFetch(resourceLoader, resource, sessionID, shouldClearReferrerOnHTTPSToHTTPRedirect, [this, trackingParameters, identifier, sessionID, shouldClearReferrerOnHTTPSToHTTPRedirect, maximumBufferingTime = maximumBufferingTime(resource), resourceLoader = makeRef(resourceLoader)] (ServiceWorkerClientFetch::Result result) mutable {
if (result != ServiceWorkerClientFetch::Result::Unhandled) {
LOG(NetworkScheduling, "(WebProcess) WebLoaderStrategy::scheduleLoad, url '%s' will be scheduled through ServiceWorker handle fetch algorithm", resourceLoader->url().string().latin1().data());
+ RELEASE_LOG_IF_ALLOWED(resourceLoader.get(), "scheduleLoad: URL will be scheduled through ServiceWorker handle fetch algorithm (frame = %p, pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", resourceLoader->frame(), trackingParameters.pageID, trackingParameters.frameID, identifier);
return;
}
if (resourceLoader->options().serviceWorkersMode == ServiceWorkersMode::Only) {
+ RELEASE_LOG_ERROR_IF_ALLOWED(resourceLoader.get(), "scheduleLoad: unable to schedule URL through ServiceWorker handle fetch algorithm (frame = %p, pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", resourceLoader->frame(), trackingParameters.pageID, trackingParameters.frameID, identifier);
callOnMainThread([resourceLoader = WTFMove(resourceLoader)] {
auto error = internalError(resourceLoader->request().url());
error.setType(ResourceError::Type::Cancellation);
@@ -223,10 +225,14 @@
if (!WebProcess::singleton().webLoaderStrategy().tryLoadingUsingURLSchemeHandler(resourceLoader))
WebProcess::singleton().webLoaderStrategy().scheduleLoadFromNetworkProcess(resourceLoader.get(), resourceLoader->request(), trackingParameters, sessionID, shouldClearReferrerOnHTTPSToHTTPRedirect, maximumBufferingTime);
+ else
+ RELEASE_LOG_IF_ALLOWED(resourceLoader.get(), "scheduleLoad: URL not handled by any handlers (frame = %p, pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", resourceLoader->frame(), trackingParameters.pageID, trackingParameters.frameID, identifier);
});
#else
if (!tryLoadingUsingURLSchemeHandler(resourceLoader))
scheduleLoadFromNetworkProcess(resourceLoader, resourceLoader.request(), trackingParameters, sessionID, shouldClearReferrerOnHTTPSToHTTPRedirect, maximumBufferingTime(resource));
+ else
+ RELEASE_LOG_IF_ALLOWED(resourceLoader, "scheduleLoad: URL not handled by any handlers (frame = %p, pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", resourceLoader.frame(), trackingParameters.pageID, trackingParameters.frameID, identifier);
#endif
}
@@ -317,6 +323,7 @@
if (loadParameters.options.mode != FetchOptions::Mode::Navigate) {
ASSERT(loadParameters.sourceOrigin);
if (!loadParameters.sourceOrigin) {
+ RELEASE_LOG_ERROR_IF_ALLOWED(resourceLoader, "scheduleLoad: no sourceOrigin (frame = %p, priority = %d, pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", resourceLoader.frame(), static_cast<int>(resourceLoader.request().priority()), loadParameters.webPageID, loadParameters.webFrameID, loadParameters.identifier);
scheduleInternallyFailedLoad(resourceLoader);
return;
}
@@ -496,13 +503,23 @@
void WebLoaderStrategy::loadResourceSynchronously(FrameLoader& frameLoader, unsigned long resourceLoadIdentifier, const ResourceRequest& request, ClientCredentialPolicy clientCredentialPolicy, const FetchOptions& options, const HTTPHeaderMap& originalRequestHeaders, ResourceError& error, ResourceResponse& response, Vector<char>& data)
{
+ WebFrameLoaderClient* webFrameLoaderClient = toWebFrameLoaderClient(frameLoader.client());
+ WebFrame* webFrame = webFrameLoaderClient ? webFrameLoaderClient->webFrame() : nullptr;
+ WebPage* webPage = webFrame ? webFrame->page() : nullptr;
+
+ auto pageID = webPage ? webPage->pageID() : 0;
+ auto frameID = webFrame ? webFrame->frameID() : 0;
+ auto sessionID = webPage ? webPage->sessionID() : PAL::SessionID::defaultSessionID();
+
auto* document = frameLoader.frame().document();
if (!document) {
+ RELEASE_LOG_ERROR_IF_ALLOWED(sessionID, "loadResourceSynchronously: no document (pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %lu)", pageID, frameID, resourceLoadIdentifier);
error = internalError(request.url());
return;
}
if (auto syncLoadResult = tryLoadingSynchronouslyUsingURLSchemeHandler(frameLoader, resourceLoadIdentifier, request)) {
+ RELEASE_LOG_ERROR_IF_ALLOWED(sessionID, "loadResourceSynchronously: failed calling tryLoadingSynchronouslyUsingURLSchemeHandler (pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %lu, error = %d)", pageID, frameID, resourceLoadIdentifier, syncLoadResult->error.errorCode());
error = WTFMove(syncLoadResult->error);
response = WTFMove(syncLoadResult->response);
data = ""
@@ -509,15 +526,11 @@
return;
}
- WebFrameLoaderClient* webFrameLoaderClient = toWebFrameLoaderClient(frameLoader.client());
- WebFrame* webFrame = webFrameLoaderClient ? webFrameLoaderClient->webFrame() : nullptr;
- WebPage* webPage = webFrame ? webFrame->page() : nullptr;
-
NetworkResourceLoadParameters loadParameters;
loadParameters.identifier = resourceLoadIdentifier;
- loadParameters.webPageID = webPage ? webPage->pageID() : 0;
- loadParameters.webFrameID = webFrame ? webFrame->frameID() : 0;
- loadParameters.sessionID = webPage ? webPage->sessionID() : PAL::SessionID::defaultSessionID();
+ loadParameters.webPageID = pageID;
+ loadParameters.webFrameID = frameID;
+ loadParameters.sessionID = sessionID;
loadParameters.request = request;
loadParameters.contentSniffingPolicy = ContentSniffingPolicy::SniffContent;
loadParameters.contentEncodingSniffingPolicy = ContentEncodingSniffingPolicy::Sniff;
@@ -539,8 +552,8 @@
HangDetectionDisabler hangDetectionDisabler;
if (!WebProcess::singleton().ensureNetworkProcessConnection().connection().sendSync(Messages::NetworkConnectionToWebProcess::PerformSynchronousLoad(loadParameters), Messages::NetworkConnectionToWebProcess::PerformSynchronousLoad::Reply(error, response, data), 0)) {
- RELEASE_LOG_ERROR_IF_ALLOWED(loadParameters.sessionID, "loadResourceSynchronously: failed sending synchronous network process message (pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", loadParameters.webPageID, loadParameters.webFrameID, loadParameters.identifier);
- if (auto* page = webPage->corePage())
+ RELEASE_LOG_ERROR_IF_ALLOWED(sessionID, "loadResourceSynchronously: failed sending synchronous network process message (pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %lu)", pageID, frameID, resourceLoadIdentifier);
+ if (auto* page = webPage ? webPage->corePage() : nullptr)
page->diagnosticLoggingClient().logDiagnosticMessage(WebCore::DiagnosticLoggingKeys::internalErrorKey(), WebCore::DiagnosticLoggingKeys::synchronousMessageFailedKey(), WebCore::ShouldSample::No);
response = ResourceResponse();
error = internalError(request.url());
Modified: trunk/Source/WebKit/WebProcess/Network/WebResourceLoader.cpp (239456 => 239457)
--- trunk/Source/WebKit/WebProcess/Network/WebResourceLoader.cpp 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebKit/WebProcess/Network/WebResourceLoader.cpp 2018-12-20 19:23:20 UTC (rev 239457)
@@ -1,5 +1,5 @@
/*
- * Copyright (C) 2012-2017 Apple Inc. All rights reserved.
+ * Copyright (C) 2012-2018 Apple Inc. All rights reserved.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions
@@ -88,12 +88,16 @@
LOG(Network, "(WebProcess) WebResourceLoader::willSendRequest to '%s'", proposedRequest.url().string().latin1().data());
RELEASE_LOG_IF_ALLOWED("willSendRequest: (pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID);
- if (m_coreLoader->documentLoader()->applicationCacheHost().maybeLoadFallbackForRedirect(m_coreLoader.get(), proposedRequest, redirectResponse))
+ if (m_coreLoader->documentLoader()->applicationCacheHost().maybeLoadFallbackForRedirect(m_coreLoader.get(), proposedRequest, redirectResponse)) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequest: exiting early because maybeLoadFallbackForRedirect returned false (pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID);
return;
+ }
m_coreLoader->willSendRequest(WTFMove(proposedRequest), redirectResponse, [this, protectedThis = makeRef(*this)](ResourceRequest&& request) {
- if (!m_coreLoader || !m_coreLoader->identifier())
+ if (!m_coreLoader || !m_coreLoader->identifier()) {
+ RELEASE_LOG_IF_ALLOWED("willSendRequest: exiting early because no coreloader or identifier (pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID);
return;
+ }
send(Messages::NetworkResourceLoader::ContinueWillSendRequest(request, m_coreLoader->isAllowedToAskUserForCredentials()));
});
@@ -111,8 +115,10 @@
Ref<WebResourceLoader> protectedThis(*this);
- if (m_coreLoader->documentLoader()->applicationCacheHost().maybeLoadFallbackForResponse(m_coreLoader.get(), response))
+ if (m_coreLoader->documentLoader()->applicationCacheHost().maybeLoadFallbackForResponse(m_coreLoader.get(), response)) {
+ RELEASE_LOG_IF_ALLOWED("didReceiveResponse: not continuing load because the content is already cached (pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID);
return;
+ }
CompletionHandler<void()> policyDecisionCompletionHandler;
if (needsContinueDidReceiveResponseMessage) {
@@ -126,6 +132,8 @@
// If m_coreLoader becomes null as a result of the didReceiveResponse callback, we can't use the send function().
if (m_coreLoader && m_coreLoader->identifier())
send(Messages::NetworkResourceLoader::ContinueDidReceiveResponse());
+ else
+ RELEASE_LOG_IF_ALLOWED("didReceiveResponse: not continuing load because no coreLoader or no ID (pageID = %" PRIu64 ", frameID = %" PRIu64 ", resourceID = %" PRIu64 ")", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID);
};
}
Modified: trunk/Source/WebKit/WebProcess/WebCoreSupport/WebFrameLoaderClient.cpp (239456 => 239457)
--- trunk/Source/WebKit/WebProcess/WebCoreSupport/WebFrameLoaderClient.cpp 2018-12-20 19:18:17 UTC (rev 239456)
+++ trunk/Source/WebKit/WebProcess/WebCoreSupport/WebFrameLoaderClient.cpp 2018-12-20 19:23:20 UTC (rev 239457)
@@ -528,6 +528,8 @@
if (!webPage)
return;
+ RELEASE_LOG(Network, "%p - WebFrameLoaderClient::dispatchDidFailProvisionalLoad: (pageID = %" PRIu64 ", frameID = %" PRIu64 ")", this, webPage->pageID(), m_frame->frameID());
+
RefPtr<API::Object> userData;
// Notify the bundle client.
@@ -562,6 +564,8 @@
if (!webPage)
return;
+ RELEASE_LOG(Network, "%p - WebFrameLoaderClient::dispatchDidFailLoad: (pageID = %" PRIu64 ", frameID = %" PRIu64 ")", this, webPage->pageID(), m_frame->frameID());
+
RefPtr<API::Object> userData;
auto navigationID = static_cast<WebDocumentLoader&>(*m_frame->coreFrame()->loader().documentLoader()).navigationID();
