Changeset 202575 in webkit


Ignore:
Timestamp:
Jun 28, 2016 11:08:39 AM (8 years ago)
Author:
Chris Dumez
Message:

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):

Location:
trunk/Source/WebKit2
Files:
5 edited

Legend:

Unmodified
Added
Removed

  • trunk/Source/WebKit2/ChangeLog

    r202574 r202575  
     12016-06-28  Chris Dumez  <cdumez@apple.com>
     2
     3        Add some more UIProcess-side logging related to process assertions
     4        https://bugs.webkit.org/show_bug.cgi?id=159188
     5
     6        Reviewed by Andreas Kling.
     7
     8        Add some more UIProcess-side logging related to process assertions
     9        to help debug process suspension issues.
     10
     11        * UIProcess/Network/NetworkProcessProxy.cpp:
     12        (WebKit::NetworkProcessProxy::fetchWebsiteData):
     13        (WebKit::NetworkProcessProxy::deleteWebsiteData):
     14        (WebKit::NetworkProcessProxy::deleteWebsiteDataForOrigins):
     15        * UIProcess/ProcessThrottler.cpp:
     16        (WebKit::ProcessThrottler::updateAssertionNow):
     17        (WebKit::ProcessThrottler::updateAssertion):
     18        * UIProcess/WebPageProxy.cpp:
     19        (WebKit::WebPageProxy::updateActivityToken):
     20        * UIProcess/WebProcessProxy.cpp:
     21        (WebKit::WebProcessProxy::fetchWebsiteData):
     22        (WebKit::WebProcessProxy::deleteWebsiteData):
     23        (WebKit::WebProcessProxy::deleteWebsiteDataForOrigins):
     24        (WebKit::WebProcessProxy::didSetAssertionState):
     25
    1262016-06-28  Chris Dumez  <cdumez@apple.com>
    227

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

    r202511 r202575  
    127127    uint64_t callbackID = generateCallbackID();
    128128    auto token = throttler().backgroundActivityToken();
    129     LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is taking a background assertion because the Network process is fetching Website data");
    130 
    131     m_pendingFetchWebsiteDataCallbacks.add(callbackID, [token, completionHandler, sessionID](WebsiteData websiteData) {
     129    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is taking a background assertion because the Network process is fetching Website data", this);
     130
     131    m_pendingFetchWebsiteDataCallbacks.add(callbackID, [this, token, completionHandler, sessionID](WebsiteData websiteData) {
    132132        completionHandler(WTFMove(websiteData));
    133         LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is releasing a background assertion because the Network process is done fetching Website data");
     133        LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is releasing a background assertion because the Network process is done fetching Website data", this);
    134134    });
    135135
    … …  
    141141    auto callbackID = generateCallbackID();
    142142    auto token = throttler().backgroundActivityToken();
    143     LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is taking a background assertion because the Network process is deleting Website data");
    144 
    145     m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [token, completionHandler, sessionID] {
     143    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is taking a background assertion because the Network process is deleting Website data", this);
     144
     145    m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [this, token, completionHandler, sessionID] {
    146146        completionHandler();
    147         LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is releasing a background assertion because the Network process is done deleting Website data");
     147        LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is releasing a background assertion because the Network process is done deleting Website data", this);
    148148    });
    149149    send(Messages::NetworkProcess::DeleteWebsiteData(sessionID, dataTypes, modifiedSince, callbackID), 0);
    … …  
    156156    uint64_t callbackID = generateCallbackID();
    157157    auto token = throttler().backgroundActivityToken();
    158     LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is taking a background assertion because the Network process is deleting Website data for several origins");
    159 
    160     m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [token, completionHandler, sessionID] {
     158    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is taking a background assertion because the Network process is deleting Website data for several origins", this);
     159
     160    m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [this, token, completionHandler, sessionID] {
    161161        completionHandler();
    162         LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "UIProcess is releasing a background assertion because the Network process is done deleting Website data for several origins");
     162        LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - NetworkProcessProxy is releasing a background assertion because the Network process is done deleting Website data for several origins", this);
    163163    });
    164164

  • trunk/Source/WebKit2/UIProcess/ProcessThrottler.cpp

    r197360 r202575  
    5757    m_suspendTimer.stop();
    5858    if (m_assertion) {
     59        if (m_assertion->state() != assertionState())
     60            LOG_ALWAYS(true, "%p - ProcessThrottler::updateAssertionNow() updating process assertion state to %u (foregroundActivities: %lu, backgroundActivities: %lu)", this, assertionState(), m_foregroundCounter.value(), m_backgroundCounter.value());
    5961        m_assertion->setState(assertionState());
    6062        m_process.didSetAssertionState(assertionState());
    … …  
    6971    if (m_assertion && m_assertion->state() != AssertionState::Suspended && !m_foregroundCounter.value() && !m_backgroundCounter.value()) {
    7072        ++m_suspendMessageCount;
     73        LOG_ALWAYS(true, "%p - ProcessThrottler::updateAssertion() sending PrepareToSuspend IPC", this);
    7174        m_process.sendPrepareToSuspend();
    7275        m_suspendTimer.startOneShot(processSuspensionTimeout);
    … …  
    7578        return;
    7679    }
    77    
     80
    7881    bool shouldBeRunnable = m_foregroundCounter.value() || m_backgroundCounter.value();
    7982

  • trunk/Source/WebKit2/UIProcess/WebPageProxy.cpp

    r202574 r202575  
    15081508#if PLATFORM(IOS)
    15091509    if (!isViewVisible() && !m_alwaysRunsAtForegroundPriority) {
    1510         WEBPAGEPROXY_LOG_ALWAYS("UIProcess is releasing a foreground assertion because the view is no longer visible");
    1511         m_activityToken = nullptr;
     1510        if (m_activityToken) {
     1511            WEBPAGEPROXY_LOG_ALWAYS("%p - UIProcess is releasing a foreground assertion because the view is no longer visible", this);
     1512            m_activityToken = nullptr;
     1513        }
    15121514    } else if (!m_activityToken) {
    15131515        if (isViewVisible())
    1514             WEBPAGEPROXY_LOG_ALWAYS("UIProcess is taking a foreground assertion because the view is visible");
     1516            WEBPAGEPROXY_LOG_ALWAYS("%p - UIProcess is taking a foreground assertion because the view is visible", this);
    15151517        else
    1516             WEBPAGEPROXY_LOG_ALWAYS("UIProcess is taking a foreground assertion even though the view is not visible because m_alwaysRunsAtForegroundPriority is true");
     1518            WEBPAGEPROXY_LOG_ALWAYS("%p - UIProcess is taking a foreground assertion even though the view is not visible because m_alwaysRunsAtForegroundPriority is true", this);
    15171519        m_activityToken = m_process->throttler().foregroundActivityToken();
    15181520    }

  • trunk/Source/WebKit2/UIProcess/WebProcessProxy.cpp

    r202331 r202575  
    728728    uint64_t callbackID = generateCallbackID();
    729729    auto token = throttler().backgroundActivityToken();
    730 
    731     m_pendingFetchWebsiteDataCallbacks.add(callbackID, [token, completionHandler](WebsiteData websiteData) {
     730    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is taking a background assertion because the Web process is fetching Website data", this);
     731
     732    m_pendingFetchWebsiteDataCallbacks.add(callbackID, [this, token, completionHandler, sessionID](WebsiteData websiteData) {
    732733        completionHandler(WTFMove(websiteData));
     734        LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is releasing a background assertion because the Web process is done fetching Website data", this);
    733735    });
    734736
    … …  
    742744    uint64_t callbackID = generateCallbackID();
    743745    auto token = throttler().backgroundActivityToken();
    744 
    745     m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [token, completionHandler] {
     746    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is taking a background assertion because the Web process is deleting Website data", this);
     747
     748    m_pendingDeleteWebsiteDataCallbacks.add(callbackID, [this, token, completionHandler, sessionID] {
    746749        completionHandler();
     750        LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is releasing a background assertion because the Web process is done deleting Website data", this);
    747751    });
    748752    send(Messages::WebProcess::DeleteWebsiteData(sessionID, dataTypes, modifiedSince, callbackID), 0);
    … …  
    755759    uint64_t callbackID = generateCallbackID();
    756760    auto token = throttler().backgroundActivityToken();
    757 
    758     m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [token, completionHandler] {
     761    LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is taking a background assertion because the Web process is deleting Website data for several origins", this);
     762
     763    m_pendingDeleteWebsiteDataForOriginsCallbacks.add(callbackID, [this, token, completionHandler, sessionID] {
    759764        completionHandler();
     765        LOG_ALWAYS(sessionID.isAlwaysOnLoggingAllowed(), "%p - WebProcessProxy is releasing a background assertion because the Web process is done deleting Website data for several origins", this);
    760766    });
    761767
    … …  
    960966    switch (state) {
    961967    case AssertionState::Suspended:
     968        LOG_ALWAYS(true, "%p - WebProcessProxy::didSetAssertionState(Suspended) release all assertions for network process", this);
    962969        m_foregroundTokenForNetworkProcess = nullptr;
    963970        m_backgroundTokenForNetworkProcess = nullptr;
    … …  
    967974
    968975    case AssertionState::Background:
     976        LOG_ALWAYS(true, "%p - WebProcessProxy::didSetAssertionState(Background) taking background assertion for network process", this);
    969977        m_backgroundTokenForNetworkProcess = processPool().ensureNetworkProcess().throttler().backgroundActivityToken();
    970978        m_foregroundTokenForNetworkProcess = nullptr;
    … …  
    972980   
    973981    case AssertionState::Foreground:
     982        LOG_ALWAYS(true, "%p - WebProcessProxy::didSetAssertionState(Foreground) taking foreground assertion for network process", this);
    974983        m_foregroundTokenForNetworkProcess = processPool().ensureNetworkProcess().throttler().foregroundActivityToken();
    975984        m_backgroundTokenForNetworkProcess = nullptr;
Note: See TracChangeset for help on using the changeset viewer.