Diff
Modified: trunk/Source/WTF/ChangeLog (197727 => 197728)
--- trunk/Source/WTF/ChangeLog 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WTF/ChangeLog 2016-03-08 06:44:59 UTC (rev 197728)
@@ -1,3 +1,19 @@
+2016-03-07 Keith Rollin <[email protected]>
+
+ Enhance logging: Use "always on" macros
+ https://bugs.webkit.org/show_bug.cgi?id=154499
+ <rdar://problem/24757730>
+
+ Reviewed by Chris Dumez.
+
+ Update LOG_ALWAYS and LOG_ALWAYS_ERROR macros to take an _expression_ to
+ be evaluated. If the _expression_ evaluates to True, the associated
+ message is logged. This facility is used to prevent logging from being
+ performed in private sessions, but it could be extended to prevent
+ logging under other circumstances as well.
+
+ * wtf/Assertions.h:
+
2016-03-04 Alex Christensen <[email protected]>
Remove vcxproj build system
Modified: trunk/Source/WTF/wtf/Assertions.h (197727 => 197728)
--- trunk/Source/WTF/wtf/Assertions.h 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WTF/wtf/Assertions.h 2016-03-08 06:44:59 UTC (rev 197728)
@@ -384,12 +384,12 @@
#define WTF_LOGGING_PREFIX "#WK: "
#if LOG_ALWAYS_DISABLED
-#define LOG_ALWAYS(format, ...) ((void)0)
-#define LOG_ALWAYS_ERROR(format, ...) WTFReportError(__FILE__, __LINE__, WTF_PRETTY_FUNCTION, format, ##__VA_ARGS__)
+#define LOG_ALWAYS(isAllowed, format, ...) ((void)0)
+#define LOG_ALWAYS_ERROR(isAllowed, format, ...) WTFReportError(__FILE__, __LINE__, WTF_PRETTY_FUNCTION, format, ##__VA_ARGS__)
#else
#define WTF_LOG_DEFAULT OS_LOG_DEFAULT
-#define LOG_ALWAYS(format, ...) os_log(WTF_LOG_DEFAULT, WTF_LOGGING_PREFIX format, ##__VA_ARGS__)
-#define LOG_ALWAYS_ERROR(format, ...) os_log_error(WTF_LOG_DEFAULT, WTF_LOGGING_PREFIX format, ##__VA_ARGS__)
+#define LOG_ALWAYS(isAllowed, format, ...) do { if (isAllowed) os_log(WTF_LOG_DEFAULT, WTF_LOGGING_PREFIX format, ##__VA_ARGS__); } while (0)
+#define LOG_ALWAYS_ERROR(isAllowed, format, ...) do { if (isAllowed) os_log_error(WTF_LOG_DEFAULT, WTF_LOGGING_PREFIX format, ##__VA_ARGS__); } while (0)
#endif
/* RELEASE_ASSERT */
Modified: trunk/Source/WebCore/ChangeLog (197727 => 197728)
--- trunk/Source/WebCore/ChangeLog 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/ChangeLog 2016-03-08 06:44:59 UTC (rev 197728)
@@ -1,3 +1,51 @@
+2016-03-07 Keith Rollin <[email protected]>
+
+ Enhance logging: Use "always on" macros
+ https://bugs.webkit.org/show_bug.cgi?id=154499
+ <rdar://problem/24757730>
+
+ Reviewed by Chris Dumez.
+
+ Make use of new logging macros by reporting on frame and resource
+ load activity.
+
+ Add new logging to memory pressure handler to show when it's called
+ and its effectiveness. As part of this change, the various
+ platform-specific implementations have been unified.
+
+ No new tests. No new basic functionality has been added. Only new
+ logging has been added in release mode or has been enabled to execute
+ in release mode as well as debug mode.
+
+ * loader/FrameLoader.cpp:
+ (WebCore::FrameLoader::prepareForLoadStart):
+ (WebCore::FrameLoader::checkLoadCompleteForThisFrame):
+ (WebCore::FrameLoader::isAlwaysOnLoggingAllowed):
+ * loader/FrameLoader.h:
+ * loader/ResourceLoader.cpp:
+ (WebCore::ResourceLoader::isAlwaysOnLoggingAllowed):
+ * loader/ResourceLoader.h:
+ * page/Frame.cpp:
+ (WebCore::Frame::isAlwaysOnLoggingAllowed):
+ * page/Frame.h:
+ * page/Page.cpp:
+ (WebCore::Page::isAlwaysOnLoggingAllowed):
+ * page/Page.h:
+ * page/SessionID.h:
+ (WebCore::SessionID::isAlwaysOnLoggingAllowed):
+ * platform/MemoryPressureHandler.cpp:
+ (WebCore::MemoryPressureHandler::ReliefLogger::logMemoryUsageChange):
+ (WebCore::MemoryPressureHandler::ReliefLogger::platformLog): Deleted.
+ * platform/MemoryPressureHandler.h:
+ (WebCore::MemoryPressureHandler::ReliefLogger::ReliefLogger):
+ (WebCore::MemoryPressureHandler::ReliefLogger::~ReliefLogger):
+ * platform/cocoa/MemoryPressureHandlerCocoa.mm:
+ (WebCore::MemoryPressureHandler::ReliefLogger::platformLog): Deleted.
+ * platform/linux/MemoryPressureHandlerLinux.cpp:
+ (WebCore::MemoryPressureHandler::ReliefLogger::platformLog): Deleted.
+ * platform/win/MemoryPressureHandlerWin.cpp:
+ (WebCore::MemoryPressureHandler::ReliefLogger::platformLog): Deleted.
+
2016-03-07 Chris Dumez <[email protected]>
Align HTMLCanvasElement.width / height with the specification
Modified: trunk/Source/WebCore/loader/FrameLoader.cpp (197727 => 197728)
--- trunk/Source/WebCore/loader/FrameLoader.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/loader/FrameLoader.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -140,6 +140,8 @@
#include "WKContentObservation.h"
#endif
+#define FRAMELOADER_LOG_ALWAYS(...) LOG_ALWAYS(isAlwaysOnLoggingAllowed(), __VA_ARGS__)
+
namespace WebCore {
using namespace HTMLNames;
@@ -1084,6 +1086,8 @@
void FrameLoader::prepareForLoadStart()
{
+ FRAMELOADER_LOG_ALWAYS("Starting frame load, frame = %p, main = %d", &m_frame, m_frame.isMainFrame());
+
m_progressTracker->progressStarted();
m_client.dispatchDidStartProvisionalLoad();
@@ -2277,9 +2281,11 @@
AXObjectCache::AXLoadingEvent loadingEvent;
if (!error.isNull()) {
+ FRAMELOADER_LOG_ALWAYS("Finished frame load with error, frame = %p, main = %d, isTimeout = %d, isCancellation = %d, errorCode = %d", &m_frame, m_frame.isMainFrame(), error.isTimeout(), error.isCancellation(), error.errorCode());
m_client.dispatchDidFailLoad(error);
loadingEvent = AXObjectCache::AXLoadingFailed;
} else {
+ FRAMELOADER_LOG_ALWAYS("Finished frame load without error, frame = %p, main = %d", &m_frame, m_frame.isMainFrame());
#if ENABLE(DATA_DETECTION)
if (m_frame.settings().dataDetectorTypes() != DataDetectorTypeNone) {
RefPtr<Range> documentRange = makeRange(firstPositionInNode(m_frame.document()->documentElement()), lastPositionInNode(m_frame.document()->documentElement()));
@@ -3566,6 +3572,11 @@
documentLoader.setShouldOpenExternalURLsPolicy(shouldOpenExternalURLsPolicyToApply(m_frame, propagatedPolicy));
}
+bool FrameLoader::isAlwaysOnLoggingAllowed() const
+{
+ return frame().isAlwaysOnLoggingAllowed();
+}
+
bool FrameLoaderClient::hasHTMLView() const
{
return true;
Modified: trunk/Source/WebCore/loader/FrameLoader.h (197727 => 197728)
--- trunk/Source/WebCore/loader/FrameLoader.h 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/loader/FrameLoader.h 2016-03-08 06:44:59 UTC (rev 197728)
@@ -296,6 +296,8 @@
const URL& provisionalLoadErrorBeingHandledURL() const { return m_provisionalLoadErrorBeingHandledURL; }
void setProvisionalLoadErrorBeingHandledURL(const URL& url) { m_provisionalLoadErrorBeingHandledURL = url; }
+ bool isAlwaysOnLoggingAllowed() const;
+
private:
enum FormSubmissionCacheLoadPolicy {
MayAttemptCacheOnlyLoadForFormSubmissionItem,
Modified: trunk/Source/WebCore/loader/ResourceLoader.cpp (197727 => 197728)
--- trunk/Source/WebCore/loader/ResourceLoader.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/loader/ResourceLoader.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -754,4 +754,9 @@
}
#endif
+bool ResourceLoader::isAlwaysOnLoggingAllowed() const
+{
+ return frameLoader() && frameLoader()->isAlwaysOnLoggingAllowed();
}
+
+}
Modified: trunk/Source/WebCore/loader/ResourceLoader.h (197727 => 197728)
--- trunk/Source/WebCore/loader/ResourceLoader.h 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/loader/ResourceLoader.h 2016-03-08 06:44:59 UTC (rev 197728)
@@ -145,6 +145,8 @@
void unschedule(WTF::SchedulePair&);
#endif
+ WEBCORE_EXPORT bool isAlwaysOnLoggingAllowed() const;
+
protected:
ResourceLoader(Frame*, ResourceLoaderOptions);
Modified: trunk/Source/WebCore/page/Frame.cpp (197727 => 197728)
--- trunk/Source/WebCore/page/Frame.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/page/Frame.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -1053,4 +1053,9 @@
return true;
}
+bool Frame::isAlwaysOnLoggingAllowed() const
+{
+ return page() && page()->isAlwaysOnLoggingAllowed();
+}
+
} // namespace WebCore
Modified: trunk/Source/WebCore/page/Frame.h (197727 => 197728)
--- trunk/Source/WebCore/page/Frame.h 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/page/Frame.h 2016-03-08 06:44:59 UTC (rev 197728)
@@ -272,6 +272,7 @@
bool activeDOMObjectsAndAnimationsSuspended() const { return m_activeDOMObjectsAndAnimationsSuspendedCount > 0; }
bool isURLAllowed(const URL&) const;
+ bool isAlwaysOnLoggingAllowed() const;
// ========
Modified: trunk/Source/WebCore/page/Page.cpp (197727 => 197728)
--- trunk/Source/WebCore/page/Page.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/page/Page.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -2003,4 +2003,9 @@
}
#endif
+bool Page::isAlwaysOnLoggingAllowed() const
+{
+ return m_sessionID.isAlwaysOnLoggingAllowed();
+}
+
} // namespace WebCore
Modified: trunk/Source/WebCore/page/Page.h (197727 => 197728)
--- trunk/Source/WebCore/page/Page.h 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/page/Page.h 2016-03-08 06:44:59 UTC (rev 197728)
@@ -507,6 +507,8 @@
bool isControlledByAutomation() const { return m_controlledByAutomation; }
void setControlledByAutomation(bool controlled) { m_controlledByAutomation = controlled; }
+ bool isAlwaysOnLoggingAllowed() const;
+
private:
WEBCORE_EXPORT void initGroup();
Modified: trunk/Source/WebCore/page/SessionID.h (197727 => 197728)
--- trunk/Source/WebCore/page/SessionID.h 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/page/SessionID.h 2016-03-08 06:44:59 UTC (rev 197728)
@@ -42,6 +42,7 @@
uint64_t sessionID() const { return m_sessionID; }
bool operator==(SessionID sessionID) const { return m_sessionID == sessionID.m_sessionID; }
bool operator!=(SessionID sessionID) const { return m_sessionID != sessionID.m_sessionID; }
+ bool isAlwaysOnLoggingAllowed() const { return !isEphemeral(); }
static SessionID emptySessionID() { return SessionID(0); }
static SessionID defaultSessionID() { return SessionID(1); }
Modified: trunk/Source/WebCore/platform/MemoryPressureHandler.cpp (197727 => 197728)
--- trunk/Source/WebCore/platform/MemoryPressureHandler.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/platform/MemoryPressureHandler.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -180,13 +180,37 @@
}
}
+void MemoryPressureHandler::ReliefLogger::logMemoryUsageChange()
+{
+#if !LOG_ALWAYS_DISABLED
+#define STRING_SPECIFICATION "%{public}s"
+#define MEMORYPRESSURE_LOG(...) LOG_ALWAYS(true, __VA_ARGS__)
+#else
+#define STRING_SPECIFICATION "%s"
+#define MEMORYPRESSURE_LOG(...) WTFLogAlways(__VA_ARGS__)
+#endif
+
+ size_t currentMemory = platformMemoryUsage();
+ if (currentMemory == static_cast<size_t>(-1) || m_initialMemory == static_cast<size_t>(-1)) {
+ MEMORYPRESSURE_LOG("Memory pressure relief: " STRING_SPECIFICATION ": (Unable to get dirty memory information for process)", m_logString);
+ return;
+ }
+
+ ssize_t memoryDiff = currentMemory - m_initialMemory;
+ if (memoryDiff < 0)
+ MEMORYPRESSURE_LOG("Memory pressure relief: " STRING_SPECIFICATION ": -dirty %ld bytes (from %lu to %lu)", m_logString, (memoryDiff * -1), m_initialMemory, currentMemory);
+ else if (memoryDiff > 0)
+ MEMORYPRESSURE_LOG("Memory pressure relief: " STRING_SPECIFICATION ": +dirty %ld bytes (from %lu to %lu)", m_logString, memoryDiff, m_initialMemory, currentMemory);
+ else
+ MEMORYPRESSURE_LOG("Memory pressure relief: " STRING_SPECIFICATION ": =dirty (at %lu bytes)", m_logString, currentMemory);
+}
+
#if !PLATFORM(COCOA) && !OS(LINUX) && !PLATFORM(WIN)
void MemoryPressureHandler::install() { }
void MemoryPressureHandler::uninstall() { }
void MemoryPressureHandler::holdOff(unsigned) { }
void MemoryPressureHandler::respondToMemoryPressure(Critical, Synchronous) { }
void MemoryPressureHandler::platformReleaseMemory(Critical) { }
-void MemoryPressureHandler::ReliefLogger::platformLog() { }
size_t MemoryPressureHandler::ReliefLogger::platformMemoryUsage() { return 0; }
#endif
Modified: trunk/Source/WebCore/platform/MemoryPressureHandler.h (197727 => 197728)
--- trunk/Source/WebCore/platform/MemoryPressureHandler.h 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/platform/MemoryPressureHandler.h 2016-03-08 06:44:59 UTC (rev 197728)
@@ -87,14 +87,22 @@
public:
explicit ReliefLogger(const char *log)
: m_logString(log)
+#if !LOG_ALWAYS_DISABLED
+ , m_initialMemory(platformMemoryUsage())
+#else
, m_initialMemory(s_loggingEnabled ? platformMemoryUsage() : 0)
+#endif
{
}
~ReliefLogger()
{
+#if !LOG_ALWAYS_DISABLED
+ logMemoryUsageChange();
+#else
if (s_loggingEnabled)
- platformLog();
+ logMemoryUsageChange();
+#endif
}
const char* logString() const { return m_logString; }
@@ -103,7 +111,7 @@
private:
size_t platformMemoryUsage();
- void platformLog();
+ void logMemoryUsageChange();
const char* m_logString;
size_t m_initialMemory;
Modified: trunk/Source/WebCore/platform/cocoa/MemoryPressureHandlerCocoa.mm (197727 => 197728)
--- trunk/Source/WebCore/platform/cocoa/MemoryPressureHandlerCocoa.mm 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/platform/cocoa/MemoryPressureHandlerCocoa.mm 2016-03-08 06:44:59 UTC (rev 197728)
@@ -234,23 +234,6 @@
return static_cast<size_t>(vmInfo.internal);
}
-void MemoryPressureHandler::ReliefLogger::platformLog()
-{
- size_t currentMemory = platformMemoryUsage();
- if (currentMemory == static_cast<size_t>(-1) || m_initialMemory == static_cast<size_t>(-1)) {
- NSLog(@"%s (Unable to get dirty memory information for process)\n", m_logString);
- return;
- }
-
- ssize_t memoryDiff = currentMemory - m_initialMemory;
- if (memoryDiff < 0)
- NSLog(@"Pressure relief: %s: -dirty %ld bytes (from %ld to %ld)\n", m_logString, (memoryDiff * -1), m_initialMemory, currentMemory);
- else if (memoryDiff > 0)
- NSLog(@"Pressure relief: %s: +dirty %ld bytes (from %ld to %ld)\n", m_logString, memoryDiff, m_initialMemory, currentMemory);
- else
- NSLog(@"Pressure relief: %s: =dirty (at %ld bytes)\n", m_logString, currentMemory);
-}
-
#if PLATFORM(IOS)
static void respondToMemoryPressureCallback(CFRunLoopObserverRef observer, CFRunLoopActivity /*activity*/, void* /*info*/)
{
Modified: trunk/Source/WebCore/platform/linux/MemoryPressureHandlerLinux.cpp (197727 => 197728)
--- trunk/Source/WebCore/platform/linux/MemoryPressureHandlerLinux.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/platform/linux/MemoryPressureHandlerLinux.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -207,23 +207,6 @@
#endif
}
-void MemoryPressureHandler::ReliefLogger::platformLog()
-{
- size_t currentMemory = platformMemoryUsage();
- if (currentMemory == static_cast<size_t>(-1) || m_initialMemory == static_cast<size_t>(-1)) {
- LOG(MemoryPressure, "%s (Unable to get dirty memory information for process)", m_logString);
- return;
- }
-
- ssize_t memoryDiff = currentMemory - m_initialMemory;
- if (memoryDiff < 0)
- LOG(MemoryPressure, "Pressure relief: %s: -dirty %lu bytes (from %lu to %lu)", m_logString, static_cast<unsigned long>(memoryDiff * -1), static_cast<unsigned long>(m_initialMemory), static_cast<unsigned long>(currentMemory));
- else if (memoryDiff > 0)
- LOG(MemoryPressure, "Pressure relief: %s: +dirty %lu bytes (from %lu to %lu)", m_logString, static_cast<unsigned long>(memoryDiff), static_cast<unsigned long>(m_initialMemory), static_cast<unsigned long>(currentMemory));
- else
- LOG(MemoryPressure, "Pressure relief: %s: =dirty (at %lu bytes)", m_logString, static_cast<unsigned long>(currentMemory));
-}
-
size_t MemoryPressureHandler::ReliefLogger::platformMemoryUsage()
{
FILE* file = fopen(s_processStatus, "r");
Modified: trunk/Source/WebCore/platform/win/MemoryPressureHandlerWin.cpp (197727 => 197728)
--- trunk/Source/WebCore/platform/win/MemoryPressureHandlerWin.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebCore/platform/win/MemoryPressureHandlerWin.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -128,8 +128,4 @@
return 0;
}
-void MemoryPressureHandler::ReliefLogger::platformLog()
-{
-}
-
} // namespace WebCore
Modified: trunk/Source/WebKit2/ChangeLog (197727 => 197728)
--- trunk/Source/WebKit2/ChangeLog 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebKit2/ChangeLog 2016-03-08 06:44:59 UTC (rev 197728)
@@ -1,3 +1,44 @@
+2016-03-07 Keith Rollin <[email protected]>
+
+ Enhance logging: Use "always on" macros
+ https://bugs.webkit.org/show_bug.cgi?id=154499
+ <rdar://problem/24757730>
+
+ Reviewed by Chris Dumez.
+
+ Make use of new logging macros by reporting on frame and resource
+ load activity.
+
+ Connection updated to report IPC errors, helping us identify when
+ messaging between processes breaks down.
+
+ ChildProcess updated to log if it is terminating early. Some
+ sysdiagnose logging from customers indicate that this is happening in
+ the wild.
+
+ * NetworkProcess/NetworkResourceLoader.cpp:
+ (WebKit::NetworkResourceLoader::startNetworkLoad):
+ (WebKit::NetworkResourceLoader::didFinishLoading):
+ (WebKit::NetworkResourceLoader::didFailLoading):
+ (WebKit::NetworkResourceLoader::continueWillSendRequest):
+ (WebKit::NetworkResourceLoader::isAlwaysOnLoggingAllowed):
+ * NetworkProcess/NetworkResourceLoader.h:
+ * Platform/IPC/Connection.cpp:
+ (IPC::Connection::waitForSyncReply):
+ * Shared/ChildProcess.cpp:
+ (WebKit::didCloseOnConnectionWorkQueue):
+ * WebProcess/Network/WebLoaderStrategy.cpp:
+ (WebKit::WebLoaderStrategy::scheduleLoad):
+ * WebProcess/Network/WebResourceLoader.cpp:
+ (WebKit::WebResourceLoader::willSendRequest):
+ (WebKit::WebResourceLoader::didReceiveResponse):
+ (WebKit::WebResourceLoader::didReceiveData):
+ (WebKit::WebResourceLoader::didFinishResourceLoad):
+ (WebKit::WebResourceLoader::didFailResourceLoad):
+ (WebKit::WebResourceLoader::didReceiveResource):
+ (WebKit::WebResourceLoader::isAlwaysOnLoggingAllowed):
+ * WebProcess/Network/WebResourceLoader.h:
+
2016-03-07 Brent Fulgham <[email protected]>
Reduce startup and shutdown cost of resource load statistics
Modified: trunk/Source/WebKit2/NetworkProcess/NetworkResourceLoader.cpp (197727 => 197728)
--- trunk/Source/WebKit2/NetworkProcess/NetworkResourceLoader.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebKit2/NetworkProcess/NetworkResourceLoader.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -46,6 +46,9 @@
using namespace WebCore;
+#define NETWORKRESOURCELOADER_LOG_ALWAYS(...) LOG_ALWAYS(isAlwaysOnLoggingAllowed(), __VA_ARGS__)
+#define NETWORKRESOURCELOADER_LOG_ALWAYS_ERROR(...) LOG_ALWAYS_ERROR(isAlwaysOnLoggingAllowed(), __VA_ARGS__)
+
namespace WebKit {
struct NetworkResourceLoader::SynchronousLoadData {
@@ -200,6 +203,8 @@
m_bufferedDataForCache = SharedBuffer::create();
#endif
+ NETWORKRESOURCELOADER_LOG_ALWAYS("Starting network resource load: loader = %p, pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d", this, m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous());
+
NetworkLoadParameters parameters = m_parameters;
parameters.defersLoading = m_defersLoading;
parameters.request = request;
@@ -271,6 +276,8 @@
auto NetworkResourceLoader::didReceiveResponse(const ResourceResponse& receivedResponse) -> ShouldContinueDidReceiveResponse
{
+ NETWORKRESOURCELOADER_LOG_ALWAYS("Received network resource response: loader = %p, pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d, httpStatusCode = %d", this, m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous(), receivedResponse.httpStatusCode());
+
m_response = receivedResponse;
// For multipart/x-mixed-replace didReceiveResponseAsync gets called multiple times and buffering would require special handling.
@@ -296,13 +303,16 @@
shouldSendDidReceiveResponse = !m_cacheEntryForValidation;
#endif
- bool shouldWaitContinueDidReceiveResponse = originalRequest().requester() == ResourceRequest::Requester::Main;
+ bool shouldWaitContinueDidReceiveResponse = isMainResource();
if (shouldSendDidReceiveResponse) {
if (isSynchronous())
m_synchronousLoadData->response = m_response;
else {
- if (!sendAbortingOnFailure(Messages::WebResourceLoader::DidReceiveResponse(m_response, shouldWaitContinueDidReceiveResponse)))
+ NETWORKRESOURCELOADER_LOG_ALWAYS("Sending didReceiveResponse message to the WebContent process: loader = %p, pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d", this, m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous());
+ if (!sendAbortingOnFailure(Messages::WebResourceLoader::DidReceiveResponse(m_response, shouldWaitContinueDidReceiveResponse))) {
+ NETWORKRESOURCELOADER_LOG_ALWAYS_ERROR("Failed to send the didReceiveResponse IPC message to the WebContent process: loader = %p, pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d", this, m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous());
return ShouldContinueDidReceiveResponse::No;
+ }
}
}
@@ -312,7 +322,13 @@
shouldContinueDidReceiveResponse = shouldContinueDidReceiveResponse || m_cacheEntryForValidation;
#endif
- return shouldContinueDidReceiveResponse ? ShouldContinueDidReceiveResponse::Yes : ShouldContinueDidReceiveResponse::No;
+ if (shouldContinueDidReceiveResponse) {
+ NETWORKRESOURCELOADER_LOG_ALWAYS("Should wait for message from WebContent process before continuing resource load: loader = %p, pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d", this, m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous());
+ return ShouldContinueDidReceiveResponse::Yes;
+ }
+
+ NETWORKRESOURCELOADER_LOG_ALWAYS("Should not wait for message from WebContent process before continuing resource load: loader = %p, pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d", this, m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous());
+ return ShouldContinueDidReceiveResponse::No;
}
void NetworkResourceLoader::didReceiveBuffer(RefPtr<SharedBuffer>&& buffer, int reportedEncodedDataLength)
@@ -344,6 +360,8 @@
void NetworkResourceLoader::didFinishLoading(double finishTime)
{
+ NETWORKRESOURCELOADER_LOG_ALWAYS("Finished loading network resource: loader = %p, pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d", this, m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous());
+
#if ENABLE(NETWORK_CACHE)
if (m_cacheEntryForValidation) {
// 304 Not Modified
@@ -375,6 +393,8 @@
void NetworkResourceLoader::didFailLoading(const ResourceError& error)
{
+ NETWORKRESOURCELOADER_LOG_ALWAYS("Failed loading network resource: loader = %p, pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d, isTimeout = %d, isCancellation = %d, errCode = %d", this, m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous(), error.isTimeout(), error.isCancellation(), error.errorCode());
+
ASSERT(!error.isNull());
#if ENABLE(NETWORK_CACHE)
@@ -419,6 +439,8 @@
void NetworkResourceLoader::continueWillSendRequest(const ResourceRequest& newRequest)
{
+ NETWORKRESOURCELOADER_LOG_ALWAYS("Following redirect of network resource: loader = %p, pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d", this, m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous());
+
#if ENABLE(NETWORK_CACHE)
if (m_isWaitingContinueWillSendRequestForCachedRedirect) {
LOG(NetworkCache, "(NetworkProcess) Retrieving cached redirect");
@@ -510,7 +532,7 @@
m_synchronousLoadData->response = entry->response();
sendReplyToSynchronousRequest(*m_synchronousLoadData, entry->buffer());
} else {
- bool needsContinueDidReceiveResponseMessage = originalRequest().requester() == ResourceRequest::Requester::Main;
+ bool needsContinueDidReceiveResponseMessage = isMainResource();
sendAbortingOnFailure(Messages::WebResourceLoader::DidReceiveResponse(entry->response(), needsContinueDidReceiveResponseMessage));
#if ENABLE(SHAREABLE_RESOURCE)
@@ -624,4 +646,9 @@
}
#endif
+bool NetworkResourceLoader::isAlwaysOnLoggingAllowed() const
+{
+ return sessionID().isAlwaysOnLoggingAllowed();
+}
+
} // namespace WebKit
Modified: trunk/Source/WebKit2/NetworkProcess/NetworkResourceLoader.h (197727 => 197728)
--- trunk/Source/WebKit2/NetworkProcess/NetworkResourceLoader.h 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebKit2/NetworkProcess/NetworkResourceLoader.h 2016-03-08 06:44:59 UTC (rev 197728)
@@ -98,6 +98,9 @@
void didConvertToDownload();
+ bool isMainResource() const { return m_parameters.request.requester() == WebCore::ResourceRequest::Requester::Main; }
+ bool isAlwaysOnLoggingAllowed() const;
+
private:
NetworkResourceLoader(const NetworkResourceLoadParameters&, NetworkConnectionToWebProcess&, RefPtr<Messages::NetworkConnectionToWebProcess::PerformSynchronousLoad::DelayedReply>&&);
Modified: trunk/Source/WebKit2/Platform/IPC/Connection.cpp (197727 => 197728)
--- trunk/Source/WebKit2/Platform/IPC/Connection.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebKit2/Platform/IPC/Connection.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -34,6 +34,8 @@
#include <wtf/text/WTFString.h>
#include <wtf/threads/BinarySemaphore.h>
+#define CONNECTION_LOG_ALWAYS_ERROR(...) LOG_ALWAYS_ERROR(true, __VA_ARGS__)
+
namespace IPC {
struct WaitForMessageState {
@@ -575,6 +577,7 @@
// If that happens, we need to stop waiting, or we'll hang since we won't get
// any more incoming messages.
if (!isValid()) {
+ CONNECTION_LOG_ALWAYS_ERROR("Connection::waitForSyncReply: Connection no longer valid, id = %" PRIu64, syncRequestID);
didReceiveSyncReply(syncSendFlags);
return nullptr;
}
@@ -585,6 +588,7 @@
timedOut = !SyncMessageState::singleton().wait(absoluteTime);
}
+ CONNECTION_LOG_ALWAYS_ERROR("Connection::waitForSyncReply: Timed-out while waiting for reply, id = %" PRIu64, syncRequestID);
didReceiveSyncReply(syncSendFlags);
return nullptr;
Modified: trunk/Source/WebKit2/Shared/ChildProcess.cpp (197727 => 197728)
--- trunk/Source/WebKit2/Shared/ChildProcess.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebKit2/Shared/ChildProcess.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -29,6 +29,8 @@
#include "SandboxInitializationParameters.h"
#include <unistd.h>
+#define CHILDPROCESS_LOG_ALWAYS_ERROR(...) LOG_ALWAYS_ERROR(true, __VA_ARGS__)
+
namespace WebKit {
ChildProcess::ChildProcess()
@@ -53,6 +55,7 @@
// We use _exit here since the watchdog callback is called from another thread and we don't want
// global destructors or atexit handlers to be called from this thread while the main thread is busy
// doing its thing.
+ CHILDPROCESS_LOG_ALWAYS_ERROR("Exiting process early due to unacknowledged closed-connection");
_exit(EXIT_FAILURE);
});
}
Modified: trunk/Source/WebKit2/WebProcess/Network/WebLoaderStrategy.cpp (197727 => 197728)
--- trunk/Source/WebKit2/WebProcess/Network/WebLoaderStrategy.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebKit2/WebProcess/Network/WebLoaderStrategy.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -57,6 +57,9 @@
using namespace WebCore;
+#define WEBLOADERSTRATEGY_LOG_ALWAYS(...) LOG_ALWAYS(loadParameters.sessionID.isAlwaysOnLoggingAllowed(), __VA_ARGS__)
+#define WEBLOADERSTRATEGY_LOG_ALWAYS_ERROR(...) LOG_ALWAYS_ERROR(loadParameters.sessionID.isAlwaysOnLoggingAllowed(), __VA_ARGS__)
+
namespace WebKit {
WebLoaderStrategy::WebLoaderStrategy()
@@ -170,7 +173,7 @@
}
#endif
- LOG(NetworkScheduling, "(WebProcess) WebLoaderStrategy::scheduleLoad, url '%s' will be scheduled with the NetworkProcess with priority %d", resourceLoader->url().string().utf8().data(), static_cast<int>(resourceLoader->request().priority()));
+ LOG(NetworkScheduling, "(WebProcess) WebLoaderStrategy::scheduleLoad, url '%s' will be scheduled with the NetworkProcess with priority %d", resourceLoader->url().string().latin1().data(), static_cast<int>(resourceLoader->request().priority()));
ContentSniffingPolicy contentSniffingPolicy = resourceLoader->shouldSniffContent() ? SniffContent : DoNotSniffContent;
StoredCredentials allowStoredCredentials = resourceLoader->shouldUseCredentialStorage() ? AllowStoredCredentials : DoNotAllowStoredCredentials;
@@ -200,13 +203,16 @@
ASSERT((loadParameters.webPageID && loadParameters.webFrameID) || loadParameters.clientCredentialPolicy == DoNotAskClientForAnyCredentials);
if (!WebProcess::singleton().networkConnection()->connection()->send(Messages::NetworkConnectionToWebProcess::ScheduleResourceLoad(loadParameters), 0)) {
+ WEBLOADERSTRATEGY_LOG_ALWAYS_ERROR("WebLoaderStrategy::scheduleLoad: Unable to schedule resource with the NetworkProcess with priority = %d, pageID = %llu, frameID = %llu", static_cast<int>(resourceLoader->request().priority()), loadParameters.webPageID, 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);
return;
}
-
- m_webResourceLoaders.set(identifier, WebResourceLoader::create(resourceLoader));
+
+ auto webResourceLoader = WebResourceLoader::create(resourceLoader);
+ WEBLOADERSTRATEGY_LOG_ALWAYS("WebLoaderStrategy::scheduleLoad: Resource will be scheduled with the NetworkProcess with priority = %d, pageID = %llu, frameID = %llu, WebResourceLoader = %p", static_cast<int>(resourceLoader->request().priority()), loadParameters.webPageID, loadParameters.webFrameID, webResourceLoader.ptr());
+ m_webResourceLoaders.set(identifier, WTFMove(webResourceLoader));
}
void WebLoaderStrategy::scheduleInternallyFailedLoad(WebCore::ResourceLoader* resourceLoader)
Modified: trunk/Source/WebKit2/WebProcess/Network/WebResourceLoader.cpp (197727 => 197728)
--- trunk/Source/WebKit2/WebProcess/Network/WebResourceLoader.cpp 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebKit2/WebProcess/Network/WebResourceLoader.cpp 2016-03-08 06:44:59 UTC (rev 197728)
@@ -42,6 +42,8 @@
using namespace WebCore;
+#define WEBRESOURCELOADER_LOG_ALWAYS(...) LOG_ALWAYS(isAlwaysOnLoggingAllowed(), __VA_ARGS__)
+
namespace WebKit {
Ref<WebResourceLoader> WebResourceLoader::create(PassRefPtr<ResourceLoader> coreLoader)
@@ -75,7 +77,8 @@
void WebResourceLoader::willSendRequest(const ResourceRequest& proposedRequest, const ResourceResponse& redirectResponse)
{
- LOG(Network, "(WebProcess) WebResourceLoader::willSendRequest to '%s'", proposedRequest.url().string().utf8().data());
+ LOG(Network, "(WebProcess) WebResourceLoader::willSendRequest to '%s'", proposedRequest.url().string().latin1().data());
+ WEBRESOURCELOADER_LOG_ALWAYS("WebResourceLoader::willSendRequest, WebResourceLoader = %p", this);
RefPtr<WebResourceLoader> protect(this);
@@ -98,7 +101,8 @@
void WebResourceLoader::didReceiveResponse(const ResourceResponse& response, bool needsContinueDidReceiveResponseMessage)
{
- LOG(Network, "(WebProcess) WebResourceLoader::didReceiveResponse for '%s'. Status %d.", m_coreLoader->url().string().utf8().data(), response.httpStatusCode());
+ LOG(Network, "(WebProcess) WebResourceLoader::didReceiveResponse for '%s'. Status %d.", m_coreLoader->url().string().latin1().data(), response.httpStatusCode());
+ WEBRESOURCELOADER_LOG_ALWAYS("WebResourceLoader::didReceiveResponse, WebResourceLoader = %p, status = %d.", this, response.httpStatusCode());
Ref<WebResourceLoader> protect(*this);
@@ -129,7 +133,8 @@
void WebResourceLoader::didReceiveData(const IPC::DataReference& data, int64_t encodedDataLength)
{
- LOG(Network, "(WebProcess) WebResourceLoader::didReceiveData of size %i for '%s'", (int)data.size(), m_coreLoader->url().string().utf8().data());
+ LOG(Network, "(WebProcess) WebResourceLoader::didReceiveData of size %lu for '%s'", data.size(), m_coreLoader->url().string().latin1().data());
+ WEBRESOURCELOADER_LOG_ALWAYS("WebResourceLoader::didReceiveData, WebResourceLoader = %p, size = %lu", this, data.size());
#if USE(QUICK_LOOK)
if (QuickLookHandle* quickLookHandle = m_coreLoader->documentLoader()->quickLookHandle()) {
@@ -142,7 +147,8 @@
void WebResourceLoader::didFinishResourceLoad(double finishTime)
{
- LOG(Network, "(WebProcess) WebResourceLoader::didFinishResourceLoad for '%s'", m_coreLoader->url().string().utf8().data());
+ LOG(Network, "(WebProcess) WebResourceLoader::didFinishResourceLoad for '%s'", m_coreLoader->url().string().latin1().data());
+ WEBRESOURCELOADER_LOG_ALWAYS("WebResourceLoader::didFinishResourceLoad, WebResourceLoader = %p", this);
#if USE(QUICK_LOOK)
if (QuickLookHandle* quickLookHandle = m_coreLoader->documentLoader()->quickLookHandle()) {
@@ -155,8 +161,9 @@
void WebResourceLoader::didFailResourceLoad(const ResourceError& error)
{
- LOG(Network, "(WebProcess) WebResourceLoader::didFailResourceLoad for '%s'", m_coreLoader->url().string().utf8().data());
-
+ LOG(Network, "(WebProcess) WebResourceLoader::didFailResourceLoad for '%s'", m_coreLoader->url().string().latin1().data());
+ WEBRESOURCELOADER_LOG_ALWAYS("WebResourceLoader::didFailResourceLoad, WebResourceLoader = %p", this);
+
#if USE(QUICK_LOOK)
if (QuickLookHandle* quickLookHandle = m_coreLoader->documentLoader()->quickLookHandle())
quickLookHandle->didFail();
@@ -169,7 +176,8 @@
#if ENABLE(SHAREABLE_RESOURCE)
void WebResourceLoader::didReceiveResource(const ShareableResource::Handle& handle, double finishTime)
{
- LOG(Network, "(WebProcess) WebResourceLoader::didReceiveResource for '%s'", m_coreLoader->url().string().utf8().data());
+ LOG(Network, "(WebProcess) WebResourceLoader::didReceiveResource for '%s'", m_coreLoader->url().string().latin1().data());
+ WEBRESOURCELOADER_LOG_ALWAYS("WebResourceLoader::didReceiveResource, WebResourceLoader = %p", this);
RefPtr<SharedBuffer> buffer = handle.tryWrapInSharedBuffer();
@@ -213,4 +221,9 @@
}
#endif
+bool WebResourceLoader::isAlwaysOnLoggingAllowed() const
+{
+ return resourceLoader() && resourceLoader()->isAlwaysOnLoggingAllowed();
+}
+
} // namespace WebKit
Modified: trunk/Source/WebKit2/WebProcess/Network/WebResourceLoader.h (197727 => 197728)
--- trunk/Source/WebKit2/WebProcess/Network/WebResourceLoader.h 2016-03-08 06:42:51 UTC (rev 197727)
+++ trunk/Source/WebKit2/WebProcess/Network/WebResourceLoader.h 2016-03-08 06:44:59 UTC (rev 197728)
@@ -66,6 +66,8 @@
void detachFromCoreLoader();
+ bool isAlwaysOnLoggingAllowed() const;
+
private:
WebResourceLoader(PassRefPtr<WebCore::ResourceLoader>);
