Changeset 206166 in webkit


Ignore:
Timestamp:
Sep 20, 2016 1:03:45 PM (8 years ago)
Author:
Keith Rollin
Message:

Adjust current networking logging
​https://bugs.webkit.org/show_bug.cgi?id=162235

Reviewed by Antti Koivisto.

Update the "always on" network logging in order to better track the
loading of a particular resource and to better bind together the
resources downloaded for a particular page and frame. Do this by
consistently logging pageID, frameID, and resourceID.

Source/WebCore:

No new tests -- there are no tests for logging.

  • loader/FrameLoader.cpp:

(WebCore::FrameLoader::checkLoadCompleteForThisFrame):

  • loader/ResourceLoader.h:

(WebCore::ResourceLoader::frame):

Source/WebKit2:

  • NetworkProcess/NetworkResourceLoader.cpp:

(WebKit::NetworkResourceLoader::didFinishLoading):
(WebKit::NetworkResourceLoader::didFailLoading):
(WebKit::NetworkResourceLoader::continueWillSendRequest):

  • WebProcess/Network/WebLoaderStrategy.cpp:

(WebKit::WebLoaderStrategy::scheduleLoad):
(WebKit::WebLoaderStrategy::startLocalLoad):

  • WebProcess/Network/WebResourceLoader.cpp:

(WebKit::WebResourceLoader::create):
(WebKit::WebResourceLoader::WebResourceLoader):
(WebKit::WebResourceLoader::willSendRequest):
(WebKit::WebResourceLoader::didReceiveResponse):
(WebKit::WebResourceLoader::didReceiveData):
(WebKit::WebResourceLoader::didFinishResourceLoad):
(WebKit::WebResourceLoader::didFailResourceLoad):
(WebKit::WebResourceLoader::didReceiveResource):

  • WebProcess/Network/WebResourceLoader.h:
Location:
trunk/Source
Files:
8 edited

Legend:

Unmodified
Added
Removed

  • trunk/Source/WebCore/ChangeLog

    r206165 r206166  
     12016-09-20  Keith Rollin  <krollin@apple.com>
     2
     3        Adjust current networking logging
     4        https://bugs.webkit.org/show_bug.cgi?id=162235
     5
     6        Reviewed by Antti Koivisto.
     7
     8        Update the "always on" network logging in order to better track the
     9        loading of a particular resource and to better bind together the
     10        resources downloaded for a particular page and frame. Do this by
     11        consistently logging pageID, frameID, and resourceID.
     12
     13        No new tests -- there are no tests for logging.
     14
     15        * loader/FrameLoader.cpp:
     16        (WebCore::FrameLoader::checkLoadCompleteForThisFrame):
     17        * loader/ResourceLoader.h:
     18        (WebCore::ResourceLoader::frame):
     19
    1202016-09-20  Alex Christensen  <achristensen@webkit.org>
    221

  • trunk/Source/WebCore/loader/FrameLoader.cpp

    r206006 r206166  
    23102310                loadingEvent = AXObjectCache::AXLoadingFailed;
    23112311            } else {
    2312                 RELEASE_LOG_IF_ALLOWED("checkLoadCompleteForThisFrame: Finished frame load without error (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
     2312                RELEASE_LOG_IF_ALLOWED("checkLoadCompleteForThisFrame: Finished frame load (frame = %p, main = %d)", &m_frame, m_frame.isMainFrame());
    23132313#if ENABLE(DATA_DETECTION)
    23142314                auto* document = m_frame.document();

  • trunk/Source/WebCore/loader/ResourceLoader.h

    r204976 r206166  
    149149#endif
    150150
     151    const Frame* frame() const { return m_frame.get(); }
    151152    WEBCORE_EXPORT bool isAlwaysOnLoggingAllowed() const;
    152153

  • trunk/Source/WebKit2/ChangeLog

    r206135 r206166  
     12016-09-20  Keith Rollin  <krollin@apple.com>
     2
     3        Adjust current networking logging
     4        https://bugs.webkit.org/show_bug.cgi?id=162235
     5
     6        Reviewed by Antti Koivisto.
     7
     8        Update the "always on" network logging in order to better track the
     9        loading of a particular resource and to better bind together the
     10        resources downloaded for a particular page and frame. Do this by
     11        consistently logging pageID, frameID, and resourceID.
     12
     13        * NetworkProcess/NetworkResourceLoader.cpp:
     14        (WebKit::NetworkResourceLoader::didFinishLoading):
     15        (WebKit::NetworkResourceLoader::didFailLoading):
     16        (WebKit::NetworkResourceLoader::continueWillSendRequest):
     17        * WebProcess/Network/WebLoaderStrategy.cpp:
     18        (WebKit::WebLoaderStrategy::scheduleLoad):
     19        (WebKit::WebLoaderStrategy::startLocalLoad):
     20        * WebProcess/Network/WebResourceLoader.cpp:
     21        (WebKit::WebResourceLoader::create):
     22        (WebKit::WebResourceLoader::WebResourceLoader):
     23        (WebKit::WebResourceLoader::willSendRequest):
     24        (WebKit::WebResourceLoader::didReceiveResponse):
     25        (WebKit::WebResourceLoader::didReceiveData):
     26        (WebKit::WebResourceLoader::didFinishResourceLoad):
     27        (WebKit::WebResourceLoader::didFailResourceLoad):
     28        (WebKit::WebResourceLoader::didReceiveResource):
     29        * WebProcess/Network/WebResourceLoader.h:
     30
    1312016-09-19  Wenson Hsieh  <wenson_hsieh@apple.com>
    232

  • trunk/Source/WebKit2/NetworkProcess/NetworkResourceLoader.cpp

    r205817 r206166  
    290290auto NetworkResourceLoader::didReceiveResponse(ResourceResponse&& receivedResponse) -> ShouldContinueDidReceiveResponse
    291291{
    292     RELEASE_LOG_IF_ALLOWED("didReceiveResponse: (pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d, httpStatusCode = %d)", m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous(), receivedResponse.httpStatusCode());
     292    RELEASE_LOG_IF_ALLOWED("didReceiveResponse: (pageID = %llu, frameID = %llu, resourceID = %llu, httpStatusCode = %d, length = %lld)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier, receivedResponse.httpStatusCode(), receivedResponse.expectedContentLength());
    293293
    294294    m_response = WTFMove(receivedResponse);
    … …  
    334334
    335335    if (shouldContinueDidReceiveResponse) {
    336         RELEASE_LOG_IF_ALLOWED("didReceiveResponse: Should wait for message from WebContent process before continuing resource load (pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d)", static_cast<unsigned long long>(m_parameters.webPageID), static_cast<unsigned long long>(m_parameters.webFrameID), isMainResource(), isSynchronous());
     336        RELEASE_LOG_IF_ALLOWED("didReceiveResponse: Should wait for message from WebContent process before continuing resource load (pageID = %llu, frameID = %llu, resourceID = %llu)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier);
    337337        return ShouldContinueDidReceiveResponse::Yes;
    338338    }
    339339
    340     RELEASE_LOG_IF_ALLOWED("didReceiveResponse: Should not wait for message from WebContent process before continuing resource load (pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d)", static_cast<unsigned long long>(m_parameters.webPageID), static_cast<unsigned long long>(m_parameters.webFrameID), isMainResource(), isSynchronous());
     340    RELEASE_LOG_IF_ALLOWED("didReceiveResponse: Should not wait for message from WebContent process before continuing resource load (pageID = %llu, frameID = %llu, resourceID = %llu)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier);
    341341    return ShouldContinueDidReceiveResponse::No;
    342342}
    … …  
    371371void NetworkResourceLoader::didFinishLoading(double finishTime)
    372372{
    373     RELEASE_LOG_IF_ALLOWED("didFinishLoading: (pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d)", static_cast<unsigned long long>(m_parameters.webPageID), static_cast<unsigned long long>(m_parameters.webFrameID), isMainResource(), isSynchronous());
     373    RELEASE_LOG_IF_ALLOWED("didFinishLoading: (pageID = %llu, frameID = %llu, resourceID = %llu)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier);
    374374
    375375#if ENABLE(NETWORK_CACHE)
    … …  
    402402void NetworkResourceLoader::didFailLoading(const ResourceError& error)
    403403{
    404     RELEASE_LOG_IF_ALLOWED("didFailLoading: (pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d, isTimeout = %d, isCancellation = %d, errCode = %d)", m_parameters.webPageID, m_parameters.webFrameID, isMainResource(), isSynchronous(), error.isTimeout(), error.isCancellation(), error.errorCode());
     404    RELEASE_LOG_IF_ALLOWED("didFailLoading: (pageID = %llu, frameID = %llu, resourceID = %llu, isTimeout = %d, isCancellation = %d, errCode = %d)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier, error.isTimeout(), error.isCancellation(), error.errorCode());
    405405
    406406    ASSERT(!error.isNull());
    … …  
    448448void NetworkResourceLoader::continueWillSendRequest(ResourceRequest&& newRequest)
    449449{
    450     RELEASE_LOG_IF_ALLOWED("continueWillSendRequest: (pageID = %llu, frameID = %llu, isMainResource = %d, isSynchronous = %d)", static_cast<unsigned long long>(m_parameters.webPageID), static_cast<unsigned long long>(m_parameters.webFrameID), isMainResource(), isSynchronous());
     450    RELEASE_LOG_IF_ALLOWED("continueWillSendRequest: (pageID = %llu, frameID = %llu, resourceID = %llu)", m_parameters.webPageID, m_parameters.webFrameID, m_parameters.identifier);
    451451
    452452#if ENABLE(NETWORK_CACHE)

  • trunk/Source/WebKit2/WebProcess/Network/WebLoaderStrategy.cpp

    r205817 r206166  
    133133    ASSERT(identifier);
    134134
     135    // FIXME: Some entities in WebCore use WebCore's "EmptyFrameLoaderClient" instead of having a proper WebFrameLoaderClient.
     136    // EmptyFrameLoaderClient shouldn't exist and everything should be using a WebFrameLoaderClient,
     137    // but in the meantime we have to make sure not to mis-cast.
     138    WebFrameLoaderClient* webFrameLoaderClient = toWebFrameLoaderClient(resourceLoader.frameLoader()->client());
     139    WebFrame* webFrame = webFrameLoaderClient ? webFrameLoaderClient->webFrame() : nullptr;
     140    WebPage* webPage = webFrame ? webFrame->page() : nullptr;
     141
     142    WebResourceLoader::TrackingParameters trackingParameters;
     143    trackingParameters.pageID = webPage ? webPage->pageID() : 0;
     144    trackingParameters.frameID = webFrame ? webFrame->frameID() : 0;
     145    trackingParameters.resourceID = identifier;
     146
    135147#if ENABLE(WEB_ARCHIVE) || ENABLE(MHTML)
    136148    // If the DocumentLoader schedules this as an archive resource load,
    … …  
    138150    if (resourceLoader.documentLoader()->scheduleArchiveLoad(resourceLoader, resourceLoader.request())) {
    139151        LOG(NetworkScheduling, "(WebProcess) WebLoaderStrategy::scheduleLoad, url '%s' will be handled as an archive resource.", resourceLoader.url().string().utf8().data());
    140         m_webResourceLoaders.set(identifier, WebResourceLoader::create(resourceLoader));
     152        m_webResourceLoaders.set(identifier, WebResourceLoader::create(resourceLoader, trackingParameters));
    141153        return;
    142154    }
    … …  
    145157    if (resourceLoader.documentLoader()->applicationCacheHost()->maybeLoadResource(resourceLoader, resourceLoader.request(), resourceLoader.request().url())) {
    146158        LOG(NetworkScheduling, "(WebProcess) WebLoaderStrategy::scheduleLoad, url '%s' will be loaded from application cache.", resourceLoader.url().string().utf8().data());
    147         m_webResourceLoaders.set(identifier, WebResourceLoader::create(resourceLoader));
     159        m_webResourceLoaders.set(identifier, WebResourceLoader::create(resourceLoader, trackingParameters));
    148160        return;
    149161    }
    … …  
    177189    ContentSniffingPolicy contentSniffingPolicy = resourceLoader.shouldSniffContent() ? SniffContent : DoNotSniffContent;
    178190    StoredCredentials allowStoredCredentials = resourceLoader.shouldUseCredentialStorage() ? AllowStoredCredentials : DoNotAllowStoredCredentials;
    179 
    180     // FIXME: Some entities in WebCore use WebCore's "EmptyFrameLoaderClient" instead of having a proper WebFrameLoaderClient.
    181     // EmptyFrameLoaderClient shouldn't exist and everything should be using a WebFrameLoaderClient,
    182     // but in the meantime we have to make sure not to mis-cast.
    183     WebFrameLoaderClient* webFrameLoaderClient = toWebFrameLoaderClient(resourceLoader.frameLoader()->client());
    184     WebFrame* webFrame = webFrameLoaderClient ? webFrameLoaderClient->webFrame() : 0;
    185     WebPage* webPage = webFrame ? webFrame->page() : 0;
    186191
    187192    NetworkResourceLoadParameters loadParameters;
    … …  
    203208
    204209    if (!WebProcess::singleton().networkConnection().connection().send(Messages::NetworkConnectionToWebProcess::ScheduleResourceLoad(loadParameters), 0)) {
    205         RELEASE_LOG_ERROR_IF_ALLOWED("scheduleLoad: Unable to schedule resource with the NetworkProcess (priority = %d, pageID = %llu, frameID = %llu)", static_cast<int>(resourceLoader.request().priority()), static_cast<unsigned long long>(loadParameters.webPageID), static_cast<unsigned long long>(loadParameters.webFrameID));
     210        RELEASE_LOG_ERROR_IF_ALLOWED("scheduleLoad: Unable to schedule resource with the NetworkProcess (frame = %p, priority = %d, pageID = %llu, frameID = %llu, resourceID = %llu)", resourceLoader.frame(), static_cast<int>(resourceLoader.request().priority()), loadParameters.webPageID, loadParameters.identifier, loadParameters.webFrameID);
    206211        // We probably failed to schedule this load with the NetworkProcess because it had crashed.
    207212        // This load will never succeed so we will schedule it to fail asynchronously.
    … …  
    210215    }
    211216
    212     auto webResourceLoader = WebResourceLoader::create(resourceLoader);
    213     RELEASE_LOG_IF_ALLOWED("scheduleLoad: Resource will be scheduled with the NetworkProcess (priority = %d, pageID = %llu, frameID = %llu, WebResourceLoader = %p)", static_cast<int>(resourceLoader.request().priority()), static_cast<unsigned long long>(loadParameters.webPageID), static_cast<unsigned long long>(loadParameters.webFrameID), webResourceLoader.ptr());
     217    auto webResourceLoader = WebResourceLoader::create(resourceLoader, trackingParameters);
     218    RELEASE_LOG_IF_ALLOWED("scheduleLoad: Resource has been queued for scheduling with the NetworkProcess (frame = %p, priority = %d, pageID = %llu, frameID = %llu, resourceID = %llu, WebResourceLoader = %p)", resourceLoader.frame(), static_cast<int>(resourceLoader.request().priority()), loadParameters.webPageID, loadParameters.webFrameID, loadParameters.identifier, webResourceLoader.ptr());
    214219    m_webResourceLoaders.set(identifier, WTFMove(webResourceLoader));
    215220}
    … …  
    233238{
    234239    resourceLoader.start();
    235     m_webResourceLoaders.set(resourceLoader.identifier(), WebResourceLoader::create(resourceLoader));
     240    m_webResourceLoaders.set(resourceLoader.identifier(), WebResourceLoader::create(resourceLoader, { }));
    236241}
    237242

  • trunk/Source/WebKit2/WebProcess/Network/WebResourceLoader.cpp

    r206123 r206166  
    4747namespace WebKit {
    4848
    49 Ref<WebResourceLoader> WebResourceLoader::create(Ref<ResourceLoader>&& coreLoader)
    50 {
    51     return adoptRef(*new WebResourceLoader(WTFMove(coreLoader)));
    52 }
    53 
    54 WebResourceLoader::WebResourceLoader(Ref<WebCore::ResourceLoader>&& coreLoader)
     49Ref<WebResourceLoader> WebResourceLoader::create(Ref<ResourceLoader>&& coreLoader, const TrackingParameters& trackingParameters)
     50{
     51    return adoptRef(*new WebResourceLoader(WTFMove(coreLoader), trackingParameters));
     52}
     53
     54WebResourceLoader::WebResourceLoader(Ref<WebCore::ResourceLoader>&& coreLoader, const TrackingParameters& trackingParameters)
    5555    : m_coreLoader(WTFMove(coreLoader))
     56    , m_trackingParameters(trackingParameters)
    5657{
    5758}
    … …  
    7980{
    8081    LOG(Network, "(WebProcess) WebResourceLoader::willSendRequest to '%s'", proposedRequest.url().string().latin1().data());
    81     RELEASE_LOG_IF_ALLOWED("willSendRequest");
     82    RELEASE_LOG_IF_ALLOWED("willSendRequest: (pageID = %llu, frameID = %llu, resourceID = %llu)", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID);
    8283
    8384    RefPtr<WebResourceLoader> protectedThis(this);
    … …  
    102103{
    103104    LOG(Network, "(WebProcess) WebResourceLoader::didReceiveResponse for '%s'. Status %d.", m_coreLoader->url().string().latin1().data(), response.httpStatusCode());
    104     RELEASE_LOG_IF_ALLOWED("didReceiveResponse: (status = %d)", response.httpStatusCode());
     105    RELEASE_LOG_IF_ALLOWED("didReceiveResponse: (pageID = %llu, frameID = %llu, resourceID = %llu, status = %d)", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID, response.httpStatusCode());
    105106
    106107    Ref<WebResourceLoader> protect(*this);
    … …  
    136137
    137138    if (!m_hasReceivedData) {
    138         RELEASE_LOG_IF_ALLOWED("didReceiveData: (size = %lu)", data.size());
     139        RELEASE_LOG_IF_ALLOWED("didReceiveData: Started receiving data (pageID = %llu, frameID = %llu, resourceID = %llu)", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID);
    139140        m_hasReceivedData = true;
    140141    }
    … …  
    152153{
    153154    LOG(Network, "(WebProcess) WebResourceLoader::didFinishResourceLoad for '%s'", m_coreLoader->url().string().latin1().data());
    154     RELEASE_LOG_IF_ALLOWED("didFinishResourceLoad");
     155    RELEASE_LOG_IF_ALLOWED("didFinishResourceLoad: (pageID = %llu, frameID = %llu, resourceID = %llu)", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID);
    155156
    156157#if USE(QUICK_LOOK)
    … …  
    166167{
    167168    LOG(Network, "(WebProcess) WebResourceLoader::didFailResourceLoad for '%s'", m_coreLoader->url().string().latin1().data());
    168     RELEASE_LOG_IF_ALLOWED("didFailResourceLoad");
     169    RELEASE_LOG_IF_ALLOWED("didFailResourceLoad: (pageID = %llu, frameID = %llu, resourceID = %llu)", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID);
    169170
    170171#if USE(QUICK_LOOK)
    … …  
    181182{
    182183    LOG(Network, "(WebProcess) WebResourceLoader::didReceiveResource for '%s'", m_coreLoader->url().string().latin1().data());
    183     RELEASE_LOG_IF_ALLOWED("didReceiveResource");
     184    RELEASE_LOG_IF_ALLOWED("didReceiveResource: (pageID = %llu, frameID = %llu, resourceID = %llu)", m_trackingParameters.pageID, m_trackingParameters.frameID, m_trackingParameters.resourceID);
    184185
    185186    RefPtr<SharedBuffer> buffer = handle.tryWrapInSharedBuffer();

  • trunk/Source/WebKit2/WebProcess/Network/WebResourceLoader.h

    r206123 r206166  
    4242
    4343namespace WebCore {
    44 class CertificateInfo;
    45 class ProtectionSpace;
    4644class ResourceError;
    4745class ResourceLoader;
    … …  
    5654class WebResourceLoader : public RefCounted<WebResourceLoader>, public IPC::MessageSender {
    5755public:
    58     static Ref<WebResourceLoader> create(Ref<WebCore::ResourceLoader>&&);
     56    struct TrackingParameters {
     57        uint64_t pageID { 0 };
     58        uint64_t frameID { 0 };
     59        ResourceLoadIdentifier resourceID { 0 };
     60    };
     61
     62    static Ref<WebResourceLoader> create(Ref<WebCore::ResourceLoader>&&, const TrackingParameters&);
    5963
    6064    ~WebResourceLoader();
    … …  
    6973
    7074private:
    71     WebResourceLoader(Ref<WebCore::ResourceLoader>&&);
     75    WebResourceLoader(Ref<WebCore::ResourceLoader>&&, const TrackingParameters&);
    7276
    7377    // IPC::MessageSender
    … …  
    8690
    8791    RefPtr<WebCore::ResourceLoader> m_coreLoader;
     92    TrackingParameters m_trackingParameters;
    8893    bool m_hasReceivedData { false };
    8994};
Note: See TracChangeset for help on using the changeset viewer.