<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.1//EN"
"http://www.w3.org/TR/xhtml11/DTD/xhtml11.dtd">
<html xmlns="http://www.w3.org/1999/xhtml">
<head><meta http-equiv="content-type" content="text/html; charset=utf-8" />
<title>[202331] trunk/Source/WebKit2</title>
</head>
<body>

<style type="text/css"><!--
#msg dl.meta { border: 1px #006 solid; background: #369; padding: 6px; color: #fff; }
#msg dl.meta dt { float: left; width: 6em; font-weight: bold; }
#msg dt:after { content:':';}
#msg dl, #msg dt, #msg ul, #msg li, #header, #footer, #logmsg { font-family: verdana,arial,helvetica,sans-serif; font-size: 10pt;  }
#msg dl a { font-weight: bold}
#msg dl a:link    { color:#fc3; }
#msg dl a:active  { color:#ff0; }
#msg dl a:visited { color:#cc6; }
h3 { font-family: verdana,arial,helvetica,sans-serif; font-size: 10pt; font-weight: bold; }
#msg pre { overflow: auto; background: #ffc; border: 1px #fa0 solid; padding: 6px; }
#logmsg { background: #ffc; border: 1px #fa0 solid; padding: 1em 1em 0 1em; }
#logmsg p, #logmsg pre, #logmsg blockquote { margin: 0 0 1em 0; }
#logmsg p, #logmsg li, #logmsg dt, #logmsg dd { line-height: 14pt; }
#logmsg h1, #logmsg h2, #logmsg h3, #logmsg h4, #logmsg h5, #logmsg h6 { margin: .5em 0; }
#logmsg h1:first-child, #logmsg h2:first-child, #logmsg h3:first-child, #logmsg h4:first-child, #logmsg h5:first-child, #logmsg h6:first-child { margin-top: 0; }
#logmsg ul, #logmsg ol { padding: 0; list-style-position: inside; margin: 0 0 0 1em; }
#logmsg ul { text-indent: -1em; padding-left: 1em; }#logmsg ol { text-indent: -1.5em; padding-left: 1.5em; }
#logmsg > ul, #logmsg > ol { margin: 0 0 1em 0; }
#logmsg pre { background: #eee; padding: 1em; }
#logmsg blockquote { border: 1px solid #fa0; border-left-width: 10px; padding: 1em 1em 0 1em; background: white;}
#logmsg dl { margin: 0; }
#logmsg dt { font-weight: bold; }
#logmsg dd { margin: 0; padding: 0 0 0.5em 0; }
#logmsg dd:before { content:'\00bb';}
#logmsg table { border-spacing: 0px; border-collapse: collapse; border-top: 4px solid #fa0; border-bottom: 1px solid #fa0; background: #fff; }
#logmsg table th { text-align: left; font-weight: normal; padding: 0.2em 0.5em; border-top: 1px dotted #fa0; }
#logmsg table td { text-align: right; border-top: 1px dotted #fa0; padding: 0.2em 0.5em; }
#logmsg table thead th { text-align: center; border-bottom: 1px solid #fa0; }
#logmsg table th.Corner { text-align: left; }
#logmsg hr { border: none 0; border-top: 2px dashed #fa0; height: 1px; }
#header, #footer { color: #fff; background: #636; border: 1px #300 solid; padding: 6px; }
#patch { width: 100%; }
#patch h4 {font-family: verdana,arial,helvetica,sans-serif;font-size:10pt;padding:8px;background:#369;color:#fff;margin:0;}
#patch .propset h4, #patch .binary h4 {margin:0;}
#patch pre {padding:0;line-height:1.2em;margin:0;}
#patch .diff {width:100%;background:#eee;padding: 0 0 10px 0;overflow:auto;}
#patch .propset .diff, #patch .binary .diff  {padding:10px 0;}
#patch span {display:block;padding:0 10px;}
#patch .modfile, #patch .addfile, #patch .delfile, #patch .propset, #patch .binary, #patch .copfile {border:1px solid #ccc;margin:10px 0;}
#patch ins {background:#dfd;text-decoration:none;display:block;padding:0 10px;}
#patch del {background:#fdd;text-decoration:none;display:block;padding:0 10px;}
#patch .lines, .info {color:#888;background:#fff;}
--></style>
<div id="msg">
<dl class="meta">
<dt>Revision</dt> <dd><a href="http://trac.webkit.org/projects/webkit/changeset/202331">202331</a></dd>
<dt>Author</dt> <dd>cdumez@apple.com</dd>
<dt>Date</dt> <dd>2016-06-22 10:00:23 -0700 (Wed, 22 Jun 2016)</dd>
</dl>

<h3>Log Message</h3>
<pre>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):</pre>

<h3>Modified Paths</h3>
<ul>
<li><a href="#trunkSourceWebKit2ChangeLog">trunk/Source/WebKit2/ChangeLog</a></li>
<li><a href="#trunkSourceWebKit2UIProcessCocoaNavigationStatemm">trunk/Source/WebKit2/UIProcess/Cocoa/NavigationState.mm</a></li>
<li><a href="#trunkSourceWebKit2UIProcessNetworkNetworkProcessProxycpp">trunk/Source/WebKit2/UIProcess/Network/NetworkProcessProxy.cpp</a></li>
<li><a href="#trunkSourceWebKit2UIProcessWebPageProxycpp">trunk/Source/WebKit2/UIProcess/WebPageProxy.cpp</a></li>
<li><a href="#trunkSourceWebKit2UIProcessWebPageProxyh">trunk/Source/WebKit2/UIProcess/WebPageProxy.h</a></li>
<li><a href="#trunkSourceWebKit2UIProcessWebProcessProxycpp">trunk/Source/WebKit2/UIProcess/WebProcessProxy.cpp</a></li>
</ul>

</div>
<div id="patch">
<h3>Diff</h3>
<a id="trunkSourceWebKit2ChangeLog"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebKit2/ChangeLog (202330 => 202331)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/WebKit2/ChangeLog        2016-06-22 16:58:17 UTC (rev 202330)
+++ trunk/Source/WebKit2/ChangeLog        2016-06-22 17:00:23 UTC (rev 202331)
</span><span class="lines">@@ -1,3 +1,24 @@
</span><ins>+2016-06-22  Chris Dumez  &lt;cdumez@apple.com&gt;
+
+        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):
+
</ins><span class="cx"> 2016-06-21  Sam Weinig  &lt;sam@webkit.org&gt;
</span><span class="cx"> 
</span><span class="cx">         WKWebView with no WKNavigationDelegate does not follow universal links
</span></span></pre></div>
<a id="trunkSourceWebKit2UIProcessCocoaNavigationStatemm"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebKit2/UIProcess/Cocoa/NavigationState.mm (202330 => 202331)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/WebKit2/UIProcess/Cocoa/NavigationState.mm        2016-06-22 16:58:17 UTC (rev 202330)
+++ trunk/Source/WebKit2/UIProcess/Cocoa/NavigationState.mm        2016-06-22 17:00:23 UTC (rev 202331)
</span><span class="lines">@@ -821,10 +821,13 @@
</span><span class="cx"> void NavigationState::didChangeIsLoading()
</span><span class="cx"> {
</span><span class="cx"> #if PLATFORM(IOS)
</span><del>-    if (m_webView-&gt;_page-&gt;pageLoadState().isLoading())
</del><ins>+    if (m_webView-&gt;_page-&gt;pageLoadState().isLoading()) {
+        LOG_ALWAYS(m_webView-&gt;_page-&gt;isAlwaysOnLoggingAllowed(), &quot;UIProcess is taking a background assertion because a page load started&quot;);
</ins><span class="cx">         m_activityToken = m_webView-&gt;_page-&gt;process().throttler().backgroundActivityToken();
</span><del>-    else
</del><ins>+    } else {
+        LOG_ALWAYS(m_webView-&gt;_page-&gt;isAlwaysOnLoggingAllowed(), &quot;UIProcess is releasing a background assertion because a page load completed&quot;);
</ins><span class="cx">         m_activityToken = nullptr;
</span><ins>+    }
</ins><span class="cx"> #endif
</span><span class="cx"> 
</span><span class="cx">     [m_webView didChangeValueForKey:@&quot;loading&quot;];
</span></span></pre></div>
<a id="trunkSourceWebKit2UIProcessNetworkNetworkProcessProxycpp"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebKit2/UIProcess/Network/NetworkProcessProxy.cpp (202330 => 202331)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/WebKit2/UIProcess/Network/NetworkProcessProxy.cpp        2016-06-22 16:58:17 UTC (rev 202330)
+++ trunk/Source/WebKit2/UIProcess/Network/NetworkProcessProxy.cpp        2016-06-22 17:00:23 UTC (rev 202331)
</span><span class="lines">@@ -126,9 +126,11 @@
</span><span class="cx"> 
</span><span class="cx">     uint64_t callbackID = generateCallbackID();
</span><span class="cx">     auto token = throttler().backgroundActivityToken();
</span><ins>+    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), &quot;UIProcess is taking a background assertion because the Network process is fetching Website data&quot;);
</ins><span class="cx"> 
</span><del>-    m_pendingFetchWebsiteDataCallbacks.add(callbackID, [token, completionHandler](WebsiteData websiteData) {
</del><ins>+    m_pendingFetchWebsiteDataCallbacks.add(callbackID, [token, completionHandler, sessionID](WebsiteData websiteData) {
</ins><span class="cx">         completionHandler(WTFMove(websiteData));
</span><ins>+        LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), &quot;UIProcess is releasing a background assertion because the Network process is done fetching Website data&quot;);
</ins><span class="cx">     });
</span><span class="cx"> 
</span><span class="cx">     send(Messages::NetworkProcess::FetchWebsiteData(sessionID, dataTypes, fetchOptions, callbackID), 0);
</span><span class="lines">@@ -138,9 +140,11 @@
</span><span class="cx"> {
</span><span class="cx">     auto callbackID = generateCallbackID();
</span><span class="cx">     auto token = throttler().backgroundActivityToken();
</span><ins>+    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), &quot;UIProcess is taking a background assertion because the Network process is deleting Website data&quot;);
</ins><span class="cx"> 
</span><del>-    m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [token, completionHandler] {
</del><ins>+    m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [token, completionHandler, sessionID] {
</ins><span class="cx">         completionHandler();
</span><ins>+        LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), &quot;UIProcess is releasing a background assertion because the Network process is done deleting Website data&quot;);
</ins><span class="cx">     });
</span><span class="cx">     send(Messages::NetworkProcess::DeleteWebsiteData(sessionID, dataTypes, modifiedSince, callbackID), 0);
</span><span class="cx"> }
</span><span class="lines">@@ -151,9 +155,11 @@
</span><span class="cx"> 
</span><span class="cx">     uint64_t callbackID = generateCallbackID();
</span><span class="cx">     auto token = throttler().backgroundActivityToken();
</span><ins>+    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), &quot;UIProcess is taking a background assertion because the Network process is deleting Website data for several origins&quot;);
</ins><span class="cx"> 
</span><del>-    m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [token, completionHandler] {
</del><ins>+    m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [token, completionHandler, sessionID] {
</ins><span class="cx">         completionHandler();
</span><ins>+        LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), &quot;UIProcess is releasing a background assertion because the Network process is done deleting Website data for several origins&quot;);
</ins><span class="cx">     });
</span><span class="cx"> 
</span><span class="cx">     Vector&lt;SecurityOriginData&gt; originData;
</span><span class="lines">@@ -383,11 +389,14 @@
</span><span class="cx"> void NetworkProcessProxy::setIsHoldingLockedFiles(bool isHoldingLockedFiles)
</span><span class="cx"> {
</span><span class="cx">     if (!isHoldingLockedFiles) {
</span><ins>+        LOG_ALWAYS(true, &quot;UIProcess is releasing a background assertion because the Network process is no longer holding locked files&quot;);
</ins><span class="cx">         m_tokenForHoldingLockedFiles = nullptr;
</span><span class="cx">         return;
</span><span class="cx">     }
</span><del>-    if (!m_tokenForHoldingLockedFiles)
</del><ins>+    if (!m_tokenForHoldingLockedFiles) {
+        LOG_ALWAYS(true, &quot;UIProcess is taking a background assertion because the Network process is holding locked files&quot;);
</ins><span class="cx">         m_tokenForHoldingLockedFiles = m_throttler.backgroundActivityToken();
</span><ins>+    }
</ins><span class="cx"> }
</span><span class="cx"> 
</span><span class="cx"> } // namespace WebKit
</span></span></pre></div>
<a id="trunkSourceWebKit2UIProcessWebPageProxycpp"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebKit2/UIProcess/WebPageProxy.cpp (202330 => 202331)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/WebKit2/UIProcess/WebPageProxy.cpp        2016-06-22 16:58:17 UTC (rev 202330)
+++ trunk/Source/WebKit2/UIProcess/WebPageProxy.cpp        2016-06-22 17:00:23 UTC (rev 202331)
</span><span class="lines">@@ -180,6 +180,8 @@
</span><span class="cx"> #define MESSAGE_CHECK(assertion) MESSAGE_CHECK_BASE(assertion, m_process-&gt;connection())
</span><span class="cx"> #define MESSAGE_CHECK_URL(url) MESSAGE_CHECK_BASE(m_process-&gt;checkURLReceivedFromWebProcess(url), m_process-&gt;connection())
</span><span class="cx"> 
</span><ins>+#define WEBPAGEPROXY_LOG_ALWAYS(...) LOG_ALWAYS(isAlwaysOnLoggingAllowed(), __VA_ARGS__)
+
</ins><span class="cx"> using namespace WebCore;
</span><span class="cx"> 
</span><span class="cx"> // Represents the number of wheel events we can hold in the queue before we start pushing them preemptively.
</span><span class="lines">@@ -1485,6 +1487,11 @@
</span><span class="cx">     m_viewWasEverInWindow |= isNowInWindow;
</span><span class="cx"> }
</span><span class="cx"> 
</span><ins>+bool WebPageProxy::isAlwaysOnLoggingAllowed() const
+{
+    return sessionID().isAlwaysOnLoggingAllowed();
+}
+
</ins><span class="cx"> void WebPageProxy::updateActivityToken()
</span><span class="cx"> {
</span><span class="cx">     if (m_viewState &amp; ViewState::IsVisuallyIdle)
</span><span class="lines">@@ -1493,10 +1500,16 @@
</span><span class="cx">         m_pageIsUserObservableCount = m_process-&gt;processPool().userObservablePageCount();
</span><span class="cx"> 
</span><span class="cx"> #if PLATFORM(IOS)
</span><del>-    if (!isViewVisible() &amp;&amp; !m_alwaysRunsAtForegroundPriority)
</del><ins>+    if (!isViewVisible() &amp;&amp; !m_alwaysRunsAtForegroundPriority) {
+        WEBPAGEPROXY_LOG_ALWAYS(&quot;UIProcess is releasing a foreground assertion because the view is no longer visible&quot;);
</ins><span class="cx">         m_activityToken = nullptr;
</span><del>-    else if (!m_activityToken)
</del><ins>+    } else if (!m_activityToken) {
+        if (isViewVisible())
+            WEBPAGEPROXY_LOG_ALWAYS(&quot;UIProcess is taking a foreground assertion because the view is visible&quot;);
+        else
+            WEBPAGEPROXY_LOG_ALWAYS(&quot;UIProcess is taking a foreground assertion even though the view is not visible because m_alwaysRunsAtForegroundPriority is true&quot;);
</ins><span class="cx">         m_activityToken = m_process-&gt;throttler().foregroundActivityToken();
</span><ins>+    }
</ins><span class="cx"> #endif
</span><span class="cx"> }
</span><span class="cx"> 
</span></span></pre></div>
<a id="trunkSourceWebKit2UIProcessWebPageProxyh"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebKit2/UIProcess/WebPageProxy.h (202330 => 202331)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/WebKit2/UIProcess/WebPageProxy.h        2016-06-22 16:58:17 UTC (rev 202330)
+++ trunk/Source/WebKit2/UIProcess/WebPageProxy.h        2016-06-22 17:00:23 UTC (rev 202331)
</span><span class="lines">@@ -1116,6 +1116,8 @@
</span><span class="cx"> 
</span><span class="cx">     bool hasHadSelectionChangesFromUserInteraction() const { return m_hasHadSelectionChangesFromUserInteraction; }
</span><span class="cx"> 
</span><ins>+    bool isAlwaysOnLoggingAllowed() const;
+
</ins><span class="cx"> private:
</span><span class="cx">     WebPageProxy(PageClient&amp;, WebProcessProxy&amp;, uint64_t pageID, Ref&lt;API::PageConfiguration&gt;&amp;&amp;);
</span><span class="cx">     void platformInitialize();
</span></span></pre></div>
<a id="trunkSourceWebKit2UIProcessWebProcessProxycpp"></a>
<div class="modfile"><h4>Modified: trunk/Source/WebKit2/UIProcess/WebProcessProxy.cpp (202330 => 202331)</h4>
<pre class="diff"><span>
<span class="info">--- trunk/Source/WebKit2/UIProcess/WebProcessProxy.cpp        2016-06-22 16:58:17 UTC (rev 202330)
+++ trunk/Source/WebKit2/UIProcess/WebProcessProxy.cpp        2016-06-22 17:00:23 UTC (rev 202331)
</span><span class="lines">@@ -987,11 +987,14 @@
</span><span class="cx"> void WebProcessProxy::setIsHoldingLockedFiles(bool isHoldingLockedFiles)
</span><span class="cx"> {
</span><span class="cx">     if (!isHoldingLockedFiles) {
</span><ins>+        LOG_ALWAYS(true, &quot;UIProcess is releasing a background assertion because the WebContent process is no longer holding locked files&quot;);
</ins><span class="cx">         m_tokenForHoldingLockedFiles = nullptr;
</span><span class="cx">         return;
</span><span class="cx">     }
</span><del>-    if (!m_tokenForHoldingLockedFiles)
</del><ins>+    if (!m_tokenForHoldingLockedFiles) {
+        LOG_ALWAYS(true, &quot;UIProcess is taking a background assertion because the WebContent process is holding locked files&quot;);
</ins><span class="cx">         m_tokenForHoldingLockedFiles = m_throttler.backgroundActivityToken();
</span><ins>+    }
</ins><span class="cx"> }
</span><span class="cx"> 
</span><span class="cx"> void WebProcessProxy::isResponsive(std::function&lt;void(bool isWebProcessResponsive)&gt; callback)
</span></span></pre>
</div>
</div>

</body>
</html>