Attachment 349872 Details for Bug 189651 – Patch

[patch] Patch

bug-189651-20180916082218.patch (text/plain), 11.58 KB, created by Simon Fraser (smfr) on 2018-09-16 08:22:19 PDT

(hide)

Description:

Filename:

MIME Type:

Creator: Simon Fraser (smfr)

Created: 2018-09-16 08:22:19 PDT

Size: 11.58 KB

patch

obsolete

>Subversion Revision: 235830
>diff --git a/Source/WebCore/ChangeLog b/Source/WebCore/ChangeLog
>index 6a7042c483c29c4b0cb9465fc833e1c18ad6e357..099c7eef00549df273bd830789c42db59e9d877b 100644
>--- a/Source/WebCore/ChangeLog
>+++ b/Source/WebCore/ChangeLog
>@@ -1,3 +1,26 @@
>+2018-09-16  Simon Fraser  <simon.fraser@apple.com>
>+
>+        Add more ResourceLoading logging, particularly in MemoryCache code
>+        https://bugs.webkit.org/show_bug.cgi?id=189651
>+
>+        Reviewed by NOBODY (OOPS!).
>+
>+        Adding more logging to the ResourceLoading log channel, which I found useful
>+        when trying to understand cached SVGImage lifetimes (bug 189437).
>+
>+        * loader/cache/CachedResource.cpp:
>+        (WebCore::CachedResource::deleteIfPossible):
>+        * loader/cache/CachedResourceLoader.cpp:
>+        (WebCore::CachedResourceLoader::requestResource):
>+        (WebCore::CachedResourceLoader::garbageCollectDocumentResources):
>+        * loader/cache/MemoryCache.cpp:
>+        (WebCore::MemoryCache::add):
>+        (WebCore::MemoryCache::pruneLiveResourcesToSize):
>+        (WebCore::MemoryCache::pruneDeadResources):
>+        (WebCore::MemoryCache::pruneDeadResourcesToSize):
>+        (WebCore::MemoryCache::remove):
>+        (WebCore::MemoryCache::dumpLRULists const):
>+
> 2018-09-15  Simon Fraser  <simon.fraser@apple.com>
> 
>         Many modern media control tests leak documents in testing
>diff --git a/Source/WebCore/loader/cache/CachedResource.cpp b/Source/WebCore/loader/cache/CachedResource.cpp
>index b40f130e6b755e7e375005b915f88764d9dc37d2..5e1e3f1d3cd14a46a2749a48a1939ca2d6388b4c 100644
>--- a/Source/WebCore/loader/cache/CachedResource.cpp
>+++ b/Source/WebCore/loader/cache/CachedResource.cpp
>@@ -612,6 +612,7 @@ void CachedResource::decodedDataDeletionTimerFired()
> bool CachedResource::deleteIfPossible()
> {
>     if (canDelete()) {
>+        LOG(ResourceLoading, "CachedResource %p deleteIfPossible - can delete, in cache %d", this, inCache());
>         if (!inCache()) {
>             InspectorInstrumentation::willDestroyCachedResource(*this);
>             delete this;
>@@ -620,6 +621,8 @@ bool CachedResource::deleteIfPossible()
>         if (m_data)
>             m_data->hintMemoryNotNeededSoon();
>     }
>+
>+    LOG(ResourceLoading, "CachedResource %p deleteIfPossible - can't delete (hasClients %d loader %p preloadCount %u handleCount %u resourceToRevalidate %p proxyResource %p)", this, hasClients(), m_loader.get(), m_preloadCount, m_handleCount, m_resourceToRevalidate, m_proxyResource);
>     return false;
> }
> 
>diff --git a/Source/WebCore/loader/cache/CachedResourceLoader.cpp b/Source/WebCore/loader/cache/CachedResourceLoader.cpp
>index 9d3d108113cc379335b52f94e28e30952294f8f7..b501a856a1a3289dd1cd5d42aa02e9a5134539cc 100644
>--- a/Source/WebCore/loader/cache/CachedResourceLoader.cpp
>+++ b/Source/WebCore/loader/cache/CachedResourceLoader.cpp
>@@ -789,7 +789,7 @@ ResourceErrorOr<CachedResourceHandle<CachedResource>> CachedResourceLoader::requ
>     request.updateReferrerPolicy(document() ? document()->referrerPolicy() : ReferrerPolicy::NoReferrerWhenDowngrade);
>     URL url = request.resourceRequest().url();
> 
>-    LOG(ResourceLoading, "CachedResourceLoader::requestResource '%s', charset '%s', priority=%d, forPreload=%u", url.stringCenterEllipsizedToLength().latin1().data(), request.charset().latin1().data(), request.priority() ? static_cast<int>(request.priority().value()) : -1, forPreload == ForPreload::Yes);
>+    LOG(ResourceLoading, "CachedResourceLoader::requestResource '%.255s', charset '%s', priority=%d, forPreload=%u", url.stringCenterEllipsizedToLength().latin1().data(), request.charset().latin1().data(), request.priority() ? static_cast<int>(request.priority().value()) : -1, forPreload == ForPreload::Yes);
> 
>     if (!url.isValid()) {
>         RELEASE_LOG_IF_ALLOWED("requestResource: URL is invalid (frame = %p)", frame());
>@@ -1329,10 +1329,14 @@ void CachedResourceLoader::loadDone(LoadCompletionType type, bool shouldPerformP
> // remove it from the map.
> void CachedResourceLoader::garbageCollectDocumentResources()
> {
>+    LOG(ResourceLoading, "CachedResourceLoader %p garbageCollectDocumentResources", this);
>+
>     typedef Vector<String, 10> StringVector;
>     StringVector resourcesToDelete;
> 
>     for (auto& resource : m_documentResources) {
>+        LOG(ResourceLoading, "  cached resource %p - hasOneHandle %d", resource.value.get(), resource.value->hasOneHandle());
>+
>         if (resource.value->hasOneHandle()) {
>             resourcesToDelete.append(resource.key);
>             resource.value->setOwningCachedResourceLoader(nullptr);
>diff --git a/Source/WebCore/loader/cache/MemoryCache.cpp b/Source/WebCore/loader/cache/MemoryCache.cpp
>index ce1779d352cf3e952fbbea5c0f873bf566b190c0..96e7b543a885309ed67553952f5c5f4be4210b9e 100644
>--- a/Source/WebCore/loader/cache/MemoryCache.cpp
>+++ b/Source/WebCore/loader/cache/MemoryCache.cpp
>@@ -122,7 +122,7 @@ bool MemoryCache::add(CachedResource& resource)
>     
>     resourceAccessed(resource);
>     
>-    LOG(ResourceLoading, "MemoryCache::add Added '%s', resource %p\n", resource.url().string().latin1().data(), &resource);
>+    LOG(ResourceLoading, "MemoryCache::add Added '%.255s', resource %p\n", resource.url().string().latin1().data(), &resource);
>     return true;
> }
> 
>@@ -297,6 +297,9 @@ void MemoryCache::pruneLiveResourcesToSize(unsigned targetSize, bool shouldDestr
> {
>     if (m_inPruneResources)
>         return;
>+
>+    LOG(ResourceLoading, "MemoryCache::pruneLiveResourcesToSize(%d, shouldDestroyDecodedDataForAllLiveResources = %d)", targetSize, shouldDestroyDecodedDataForAllLiveResources);
>+
>     SetForScope<bool> reentrancyProtector(m_inPruneResources, true);
> 
>     MonotonicTime currentTime = FrameView::currentPaintTimeStamp();
>@@ -315,6 +318,8 @@ void MemoryCache::pruneLiveResourcesToSize(unsigned targetSize, bool shouldDestr
>     while (it != m_liveDecodedResources.end()) {
>         auto* current = *it;
> 
>+        LOG(ResourceLoading, " live resource %p %.255s - loaded %d, decodedSize %u", current, current->url().string().utf8().data(), current->isLoaded(), current->decodedSize());
>+
>         // Increment the iterator now because the call to destroyDecodedData() below
>         // may cause a call to ListHashSet::remove() and invalidate the current
>         // iterator. Note that this is safe because unlike iteration of most
>@@ -327,8 +332,10 @@ void MemoryCache::pruneLiveResourcesToSize(unsigned targetSize, bool shouldDestr
>         if (current->isLoaded() && current->decodedSize()) {
>             // Check to see if the remaining resources are too new to prune.
>             Seconds elapsedTime = currentTime - current->m_lastDecodedAccessTime;
>-            if (!shouldDestroyDecodedDataForAllLiveResources && elapsedTime < cMinDelayBeforeLiveDecodedPrune)
>+            if (!shouldDestroyDecodedDataForAllLiveResources && elapsedTime < cMinDelayBeforeLiveDecodedPrune) {
>+                LOG(ResourceLoading, " current time is less than min delay before pruning (%.3fms)", elapsedTime.milliseconds());
>                 return;
>+            }
> 
>             // Destroy our decoded data. This will remove us from m_liveDecodedResources, and possibly move us
>             // to a different LRU list in m_allResources.
>@@ -342,6 +349,8 @@ void MemoryCache::pruneLiveResourcesToSize(unsigned targetSize, bool shouldDestr
> 
> void MemoryCache::pruneDeadResources()
> {
>+    LOG(ResourceLoading, "MemoryCache::pruneDeadResources");
>+
>     unsigned capacity = deadCapacity();
>     if (capacity && m_deadSize <= capacity)
>         return;
>@@ -354,6 +363,9 @@ void MemoryCache::pruneDeadResourcesToSize(unsigned targetSize)
> {
>     if (m_inPruneResources)
>         return;
>+
>+    LOG(ResourceLoading, "MemoryCache::pruneDeadResourcesToSize(%d)", targetSize);
>+
>     SetForScope<bool> reentrancyProtector(m_inPruneResources, true);
>  
>     if (targetSize && m_deadSize <= targetSize)
>@@ -365,9 +377,12 @@ void MemoryCache::pruneDeadResourcesToSize(unsigned targetSize)
>         // destroyDecodedData() can alter the LRUList.
>         auto lruList = copyToVector(*m_allResources[i]);
> 
>+        LOG(ResourceLoading, " lru list (size %lu) - flushing stage", lruList.size());
>+
>         // First flush all the decoded data in this queue.
>         // Remove from the head, since this is the least frequently accessed of the objects.
>         for (auto& resource : lruList) {
>+            LOG(ResourceLoading, " lru resource %p - in cache %d, has clients %d, preloaded %d, loaded %d", resource, resource->inCache(), resource->hasClients(), resource->isPreloaded(), resource->isLoaded());
>             if (!resource->inCache())
>                 continue;
> 
>@@ -375,6 +390,9 @@ void MemoryCache::pruneDeadResourcesToSize(unsigned targetSize)
>                 // Destroy our decoded data. This will remove us from 
>                 // m_liveDecodedResources, and possibly move us to a different 
>                 // LRU list in m_allResources.
>+
>+                LOG(ResourceLoading, " lru resource %p destroyDecodedData", resource);
>+
>                 resource->destroyDecodedData();
> 
>                 if (targetSize && m_deadSize <= targetSize)
>@@ -382,9 +400,12 @@ void MemoryCache::pruneDeadResourcesToSize(unsigned targetSize)
>             }
>         }
> 
>+        LOG(ResourceLoading, " lru list (size %lu) - eviction stage", lruList.size());
>+
>         // Now evict objects from this list.
>         // Remove from the head, since this is the least frequently accessed of the objects.
>         for (auto& resource : lruList) {
>+            LOG(ResourceLoading, " lru resource %p - in cache %d, has clients %d, preloaded %d, loaded %d", resource, resource->inCache(), resource->hasClients(), resource->isPreloaded(), resource->isLoaded());
>             if (!resource->inCache())
>                 continue;
> 
>@@ -417,7 +438,7 @@ void MemoryCache::setCapacities(unsigned minDeadBytes, unsigned maxDeadBytes, un
> void MemoryCache::remove(CachedResource& resource)
> {
>     ASSERT(WTF::isMainThread());
>-    LOG(ResourceLoading, "Evicting resource %p for '%s' from cache", &resource, resource.url().string().latin1().data());
>+    LOG(ResourceLoading, "Evicting resource %p for '%.255s' from cache", &resource, resource.url().string().latin1().data());
>     // The resource may have already been removed by someone other than our caller,
>     // who needed a fresh copy for a reload. See <http://bugs.webkit.org/show_bug.cgi?id=12479#c6>.
>     if (auto* resources = sessionResourceMap(resource.sessionID())) {
>@@ -436,8 +457,10 @@ void MemoryCache::remove(CachedResource& resource)
>             removeFromLRUList(resource);
>             removeFromLiveDecodedResourcesList(resource);
>             adjustSize(resource.hasClients(), -static_cast<long long>(resource.size()));
>-        } else
>+        } else {
>             ASSERT(resources->get(key) != &resource);
>+            LOG(ResourceLoading, "  resource %p is not in cache", &resource);
>+        }
>     }
> 
>     resource.deleteIfPossible();
>@@ -780,7 +803,7 @@ void MemoryCache::dumpLRULists(bool includeLive) const
>         WTFLogAlways("\nList %d:\n", i);
>         for (auto* resource : *m_allResources[i]) {
>             if (includeLive || !resource->hasClients())
>-                WTFLogAlways("  %.100s %.1fK, %.1fK, accesses: %u, clients: %d\n", resource->url().string().utf8().data(), resource->decodedSize() / 1024.0f, (resource->encodedSize() + resource->overheadSize()) / 1024.0f, resource->accessCount(), resource->numberOfClients());
>+                WTFLogAlways("  %p %.255s %.1fK, %.1fK, accesses: %u, clients: %d\n", resource, resource->url().string().utf8().data(), resource->decodedSize() / 1024.0f, (resource->encodedSize() + resource->overheadSize()) / 1024.0f, resource->accessCount(), resource->numberOfClients());
>         }
>     }
> }

Actions: View | Formatted Diff | Diff

Attachments on bug 189651: 349872