Diff
Modified: trunk/Source/WebKit2/ChangeLog (202574 => 202575)
--- trunk/Source/WebKit2/ChangeLog 2016-06-28 18:07:05 UTC (rev 202574)
+++ trunk/Source/WebKit2/ChangeLog 2016-06-28 18:08:39 UTC (rev 202575)
@@ -1,5 +1,30 @@
2016-06-28 Chris Dumez <[email protected]>
+ Add some more UIProcess-side logging related to process assertions
+ https://bugs.webkit.org/show_bug.cgi?id=159188
+
+ Reviewed by Andreas Kling.
+
+ Add some more UIProcess-side logging related to process assertions
+ to help debug process suspension issues.
+
+ * UIProcess/Network/NetworkProcessProxy.cpp:
+ (WebKit::NetworkProcessProxy::fetchWebsiteData):
+ (WebKit::NetworkProcessProxy::deleteWebsiteData):
+ (WebKit::NetworkProcessProxy::deleteWebsiteDataForOrigins):
+ * UIProcess/ProcessThrottler.cpp:
+ (WebKit::ProcessThrottler::updateAssertionNow):
+ (WebKit::ProcessThrottler::updateAssertion):
+ * UIProcess/WebPageProxy.cpp:
+ (WebKit::WebPageProxy::updateActivityToken):
+ * UIProcess/WebProcessProxy.cpp:
+ (WebKit::WebProcessProxy::fetchWebsiteData):
+ (WebKit::WebProcessProxy::deleteWebsiteData):
+ (WebKit::WebProcessProxy::deleteWebsiteDataForOrigins):
+ (WebKit::WebProcessProxy::didSetAssertionState):
+
+2016-06-28 Chris Dumez <[email protected]>
+
[WK2] Do not suppress navigation snapshotting on session restore if we are not navigating right away
https://bugs.webkit.org/show_bug.cgi?id=159216
<rdar://problem/27058360>
Modified: trunk/Source/WebKit2/UIProcess/Network/NetworkProcessProxy.cpp (202574 => 202575)
--- trunk/Source/WebKit2/UIProcess/Network/NetworkProcessProxy.cpp 2016-06-28 18:07:05 UTC (rev 202574)
+++ trunk/Source/WebKit2/UIProcess/Network/NetworkProcessProxy.cpp 2016-06-28 18:08:39 UTC (rev 202575)
@@ -126,11 +126,11 @@
uint64_t callbackID = generateCallbackID();
auto token = throttler().backgroundActivityToken();
- LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is taking a background assertion because the Network process is fetching Website data");
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is taking a background assertion because the Network process is fetching Website data", this);
- m_pendingFetchWebsiteDataCallbacks.add(callbackID, [token, completionHandler, sessionID](WebsiteData websiteData) {
+ m_pendingFetchWebsiteDataCallbacks.add(callbackID, [this, token, completionHandler, sessionID](WebsiteData websiteData) {
completionHandler(WTFMove(websiteData));
- LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is releasing a background assertion because the Network process is done fetching Website data");
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is releasing a background assertion because the Network process is done fetching Website data", this);
});
send(Messages::NetworkProcess::FetchWebsiteData(sessionID, dataTypes, fetchOptions, callbackID), 0);
@@ -140,11 +140,11 @@
{
auto callbackID = generateCallbackID();
auto token = throttler().backgroundActivityToken();
- LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is taking a background assertion because the Network process is deleting Website data");
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is taking a background assertion because the Network process is deleting Website data", this);
- m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [token, completionHandler, sessionID] {
+ m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [this, token, completionHandler, sessionID] {
completionHandler();
- LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is releasing a background assertion because the Network process is done deleting Website data");
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is releasing a background assertion because the Network process is done deleting Website data", this);
});
send(Messages::NetworkProcess::DeleteWebsiteData(sessionID, dataTypes, modifiedSince, callbackID), 0);
}
@@ -155,11 +155,11 @@
uint64_t callbackID = generateCallbackID();
auto token = throttler().backgroundActivityToken();
- LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is taking a background assertion because the Network process is deleting Website data for several origins");
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is taking a background assertion because the Network process is deleting Website data for several origins", this);
- m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [token, completionHandler, sessionID] {
+ m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [this, token, completionHandler, sessionID] {
completionHandler();
- LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is releasing a background assertion because the Network process is done deleting Website data for several origins");
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is releasing a background assertion because the Network process is done deleting Website data for several origins", this);
});
Vector<SecurityOriginData> originData;
Modified: trunk/Source/WebKit2/UIProcess/ProcessThrottler.cpp (202574 => 202575)
--- trunk/Source/WebKit2/UIProcess/ProcessThrottler.cpp 2016-06-28 18:07:05 UTC (rev 202574)
+++ trunk/Source/WebKit2/UIProcess/ProcessThrottler.cpp 2016-06-28 18:08:39 UTC (rev 202575)
@@ -56,6 +56,8 @@
{
m_suspendTimer.stop();
if (m_assertion) {
+ if (m_assertion->state() != assertionState())
+ LOG_ALWAYS(true, "%p - ProcessThrottler::updateAssertionNow() updating process assertion state to %u (foregroundActivities: %lu, backgroundActivities: %lu)", this, assertionState(), m_foregroundCounter.value(), m_backgroundCounter.value());
m_assertion->setState(assertionState());
m_process.didSetAssertionState(assertionState());
}
@@ -68,6 +70,7 @@
// in the background for too long.
if (m_assertion && m_assertion->state() != AssertionState::Suspended && !m_foregroundCounter.value() && !m_backgroundCounter.value()) {
++m_suspendMessageCount;
+ LOG_ALWAYS(true, "%p - ProcessThrottler::updateAssertion() sending PrepareToSuspend IPC", this);
m_process.sendPrepareToSuspend();
m_suspendTimer.startOneShot(processSuspensionTimeout);
m_assertion->setState(AssertionState::Background);
@@ -74,7 +77,7 @@
m_process.didSetAssertionState(AssertionState::Background);
return;
}
-
+
bool shouldBeRunnable = m_foregroundCounter.value() || m_backgroundCounter.value();
// If we're currently waiting for the Web process to do suspension cleanup, but no longer need to be suspended, tell the Web process to cancel the cleanup.
Modified: trunk/Source/WebKit2/UIProcess/WebPageProxy.cpp (202574 => 202575)
--- trunk/Source/WebKit2/UIProcess/WebPageProxy.cpp 2016-06-28 18:07:05 UTC (rev 202574)
+++ trunk/Source/WebKit2/UIProcess/WebPageProxy.cpp 2016-06-28 18:08:39 UTC (rev 202575)
@@ -1507,13 +1507,15 @@
#if PLATFORM(IOS)
if (!isViewVisible() && !m_alwaysRunsAtForegroundPriority) {
- WEBPAGEPROXY_LOG_ALWAYS("UIProcess is releasing a foreground assertion because the view is no longer visible");
- m_activityToken = nullptr;
+ if (m_activityToken) {
+ WEBPAGEPROXY_LOG_ALWAYS("%p - UIProcess is releasing a foreground assertion because the view is no longer visible", this);
+ m_activityToken = nullptr;
+ }
} else if (!m_activityToken) {
if (isViewVisible())
- WEBPAGEPROXY_LOG_ALWAYS("UIProcess is taking a foreground assertion because the view is visible");
+ WEBPAGEPROXY_LOG_ALWAYS("%p - UIProcess is taking a foreground assertion because the view is visible", this);
else
- WEBPAGEPROXY_LOG_ALWAYS("UIProcess is taking a foreground assertion even though the view is not visible because m_alwaysRunsAtForegroundPriority is true");
+ WEBPAGEPROXY_LOG_ALWAYS("%p - UIProcess is taking a foreground assertion even though the view is not visible because m_alwaysRunsAtForegroundPriority is true", this);
m_activityToken = m_process->throttler().foregroundActivityToken();
}
#endif
Modified: trunk/Source/WebKit2/UIProcess/WebProcessProxy.cpp (202574 => 202575)
--- trunk/Source/WebKit2/UIProcess/WebProcessProxy.cpp 2016-06-28 18:07:05 UTC (rev 202574)
+++ trunk/Source/WebKit2/UIProcess/WebProcessProxy.cpp 2016-06-28 18:08:39 UTC (rev 202575)
@@ -727,9 +727,11 @@
uint64_t callbackID = generateCallbackID();
auto token = throttler().backgroundActivityToken();
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is taking a background assertion because the Web process is fetching Website data", this);
- m_pendingFetchWebsiteDataCallbacks.add(callbackID, [token, completionHandler](WebsiteData websiteData) {
+ m_pendingFetchWebsiteDataCallbacks.add(callbackID, [this, token, completionHandler, sessionID](WebsiteData websiteData) {
completionHandler(WTFMove(websiteData));
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is releasing a background assertion because the Web process is done fetching Website data", this);
});
send(Messages::WebProcess::FetchWebsiteData(sessionID, dataTypes, callbackID), 0);
@@ -741,9 +743,11 @@
uint64_t callbackID = generateCallbackID();
auto token = throttler().backgroundActivityToken();
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is taking a background assertion because the Web process is deleting Website data", this);
- m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [token, completionHandler] {
+ m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [this, token, completionHandler, sessionID] {
completionHandler();
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is releasing a background assertion because the Web process is done deleting Website data", this);
});
send(Messages::WebProcess::DeleteWebsiteData(sessionID, dataTypes, modifiedSince, callbackID), 0);
}
@@ -754,9 +758,11 @@
uint64_t callbackID = generateCallbackID();
auto token = throttler().backgroundActivityToken();
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is taking a background assertion because the Web process is deleting Website data for several origins", this);
- m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [token, completionHandler] {
+ m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [this, token, completionHandler, sessionID] {
completionHandler();
+ LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is releasing a background assertion because the Web process is done deleting Website data for several origins", this);
});
Vector<SecurityOriginData> originData;
@@ -959,6 +965,7 @@
switch (state) {
case AssertionState::Suspended:
+ LOG_ALWAYS(true, "%p - WebProcessProxy::didSetAssertionState(Suspended) release all assertions for network process", this);
m_foregroundTokenForNetworkProcess = nullptr;
m_backgroundTokenForNetworkProcess = nullptr;
for (auto& page : m_pageMap.values())
@@ -966,11 +973,13 @@
break;
case AssertionState::Background:
+ LOG_ALWAYS(true, "%p - WebProcessProxy::didSetAssertionState(Background) taking background assertion for network process", this);
m_backgroundTokenForNetworkProcess = processPool().ensureNetworkProcess().throttler().backgroundActivityToken();
m_foregroundTokenForNetworkProcess = nullptr;
break;
case AssertionState::Foreground:
+ LOG_ALWAYS(true, "%p - WebProcessProxy::didSetAssertionState(Foreground) taking foreground assertion for network process", this);
m_foregroundTokenForNetworkProcess = processPool().ensureNetworkProcess().throttler().foregroundActivityToken();
m_backgroundTokenForNetworkProcess = nullptr;
for (auto& page : m_pageMap.values())
