Changeset 202331 in webkit

Timestamp:

Jun 22, 2016 10:00:23 AM (8 years ago)

Author:

Chris Dumez

Message:

Add logging related to process assertions to help debug process suspension issues
​https://bugs.webkit.org/show_bug.cgi?id=159001

Reviewed by Antti Koivisto.

Add logging related to process assertions to help debug process suspension issues.

• UIProcess/Cocoa/NavigationState.mm:

(WebKit::NavigationState::didChangeIsLoading):

• UIProcess/Network/NetworkProcessProxy.cpp:

(WebKit::NetworkProcessProxy::fetchWebsiteData):
(WebKit::NetworkProcessProxy::deleteWebsiteData):
(WebKit::NetworkProcessProxy::deleteWebsiteDataForOrigins):
(WebKit::NetworkProcessProxy::setIsHoldingLockedFiles):

• UIProcess/WebPageProxy.cpp:

(WebKit::WebPageProxy::updateActivityToken):

• UIProcess/WebProcessProxy.cpp:

(WebKit::WebProcessProxy::setIsHoldingLockedFiles):

Location:

trunk/Source/WebKit2

Files:

• ChangeLog (modified) (1 diff)
• UIProcess/Cocoa/NavigationState.mm (modified) (1 diff)
• UIProcess/Network/NetworkProcessProxy.cpp (modified) (4 diffs)
• UIProcess/WebPageProxy.cpp (modified) (3 diffs)
• UIProcess/WebPageProxy.h (modified) (1 diff)
• UIProcess/WebProcessProxy.cpp (modified) (1 diff)

trunk/Source/WebKit2/ChangeLog

@@ +1 @@
+2016-06-22  Chris Dumez  <cdumez@apple.com>
+
+        Add logging related to process assertions to help debug process suspension issues
+        https://bugs.webkit.org/show_bug.cgi?id=159001
+
+        Reviewed by Antti Koivisto.
+
+        Add logging related to process assertions to help debug process suspension issues.
+
+        * UIProcess/Cocoa/NavigationState.mm:
+        (WebKit::NavigationState::didChangeIsLoading):
+        * UIProcess/Network/NetworkProcessProxy.cpp:
+        (WebKit::NetworkProcessProxy::fetchWebsiteData):
+        (WebKit::NetworkProcessProxy::deleteWebsiteData):
+        (WebKit::NetworkProcessProxy::deleteWebsiteDataForOrigins):
+        (WebKit::NetworkProcessProxy::setIsHoldingLockedFiles):
+        * UIProcess/WebPageProxy.cpp:
+        (WebKit::WebPageProxy::updateActivityToken):
+        * UIProcess/WebProcessProxy.cpp:
+        (WebKit::WebProcessProxy::setIsHoldingLockedFiles):
+
 2016-06-21  Sam Weinig  <sam@webkit.org>
 

trunk/Source/WebKit2/UIProcess/Cocoa/NavigationState.mm

@@ -822 +822 @@
 {
 #if PLATFORM(IOS)
-    if (m_webView->_page->pageLoadState().isLoading())
+    if (m_webView->_page->pageLoadState().isLoading()) {
+        LOG_ALWAYS(m_webView->_page->isAlwaysOnLoggingAllowed(), "UIProcess is taking a background assertion because a page load started");
         m_activityToken = m_webView->_page->process().throttler().backgroundActivityToken();
-    else
+    } else {
+        LOG_ALWAYS(m_webView->_page->isAlwaysOnLoggingAllowed(), "UIProcess is releasing a background assertion because a page load completed");
         m_activityToken = nullptr;
+    }
 #endif
 

trunk/Source/WebKit2/UIProcess/Network/NetworkProcessProxy.cpp

@@ -127 +127 @@
     uint64_t callbackID = generateCallbackID();
     auto token = throttler().backgroundActivityToken();
-
-    m_pendingFetchWebsiteDataCallbacks.add(callbackID, [token, completionHandler](WebsiteData websiteData) {
+    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is taking a background assertion because the Network process is fetching Website data");
+
+    m_pendingFetchWebsiteDataCallbacks.add(callbackID, [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");
     });
 
@@ -139 +141 @@
     auto callbackID = generateCallbackID();
     auto token = throttler().backgroundActivityToken();
-
-    m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [token, completionHandler] {
+    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is taking a background assertion because the Network process is deleting Website data");
+
+    m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [token, completionHandler, sessionID] {
         completionHandler();
+        LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is releasing a background assertion because the Network process is done deleting Website data");
     });
     send(Messages::NetworkProcess::DeleteWebsiteData(sessionID, dataTypes, modifiedSince, callbackID), 0);
@@ -152 +156 @@
     uint64_t callbackID = generateCallbackID();
     auto token = throttler().backgroundActivityToken();
-
-    m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [token, completionHandler] {
+    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is taking a background assertion because the Network process is deleting Website data for several origins");
+
+    m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [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");
     });
 
@@ -384 +390 @@
 {
     if (!isHoldingLockedFiles) {
+        LOG_ALWAYS(true, "UIProcess is releasing a background assertion because the Network process is no longer holding locked files");
         m_tokenForHoldingLockedFiles = nullptr;
         return;
     }
-    if (!m_tokenForHoldingLockedFiles)
+    if (!m_tokenForHoldingLockedFiles) {
+        LOG_ALWAYS(true, "UIProcess is taking a background assertion because the Network process is holding locked files");
         m_tokenForHoldingLockedFiles = m_throttler.backgroundActivityToken();
+    }
 }
 

trunk/Source/WebKit2/UIProcess/WebPageProxy.cpp

@@ -181 +181 @@
 #define MESSAGE_CHECK_URL(url) MESSAGE_CHECK_BASE(m_process->checkURLReceivedFromWebProcess(url), m_process->connection())
 
+#define WEBPAGEPROXY_LOG_ALWAYS(...) LOG_ALWAYS(isAlwaysOnLoggingAllowed(), __VA_ARGS__)
+
 using namespace WebCore;
 
@@ -1486 +1488 @@
 }
 
+bool WebPageProxy::isAlwaysOnLoggingAllowed() const
+{
+    return sessionID().isAlwaysOnLoggingAllowed();
+}
+
 void WebPageProxy::updateActivityToken()
 {
@@ -1494 +1501 @@
 
 #if PLATFORM(IOS)
-    if (!isViewVisible() && !m_alwaysRunsAtForegroundPriority)
+    if (!isViewVisible() && !m_alwaysRunsAtForegroundPriority) {
+        WEBPAGEPROXY_LOG_ALWAYS("UIProcess is releasing a foreground assertion because the view is no longer visible");
         m_activityToken = nullptr;
-    else if (!m_activityToken)
+    } else if (!m_activityToken) {
+        if (isViewVisible())
+            WEBPAGEPROXY_LOG_ALWAYS("UIProcess is taking a foreground assertion because the view is visible");
+        else
+            WEBPAGEPROXY_LOG_ALWAYS("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
 }

trunk/Source/WebKit2/UIProcess/WebPageProxy.h

@@ -1117 +1117 @@
     bool hasHadSelectionChangesFromUserInteraction() const { return m_hasHadSelectionChangesFromUserInteraction; }
 
+    bool isAlwaysOnLoggingAllowed() const;
+
 private:
     WebPageProxy(PageClient&, WebProcessProxy&, uint64_t pageID, Ref<API::PageConfiguration>&&);

trunk/Source/WebKit2/UIProcess/WebProcessProxy.cpp

@@ -988 +988 @@
 {
     if (!isHoldingLockedFiles) {
+        LOG_ALWAYS(true, "UIProcess is releasing a background assertion because the WebContent process is no longer holding locked files");
         m_tokenForHoldingLockedFiles = nullptr;
         return;
     }
-    if (!m_tokenForHoldingLockedFiles)
+    if (!m_tokenForHoldingLockedFiles) {
+        LOG_ALWAYS(true, "UIProcess is taking a background assertion because the WebContent process is holding locked files");
         m_tokenForHoldingLockedFiles = m_throttler.backgroundActivityToken();
+    }
 }