Add performance logging for slow cache retrieves
authorantti@apple.com <antti@apple.com@268f45cc-cd09-0410-ab3c-d52691b4dbfc>
Tue, 12 Jun 2018 17:53:02 +0000 (17:53 +0000)
committerantti@apple.com <antti@apple.com@268f45cc-cd09-0410-ab3c-d52691b4dbfc>
Tue, 12 Jun 2018 17:53:02 +0000 (17:53 +0000)
commit74955a9a3d6261f5df368f7d22f6219d5f7fdf69
tree65cb92cb6480efd9bbf66fe7f9c6b4f2c80dda87
parentccb7082ccc9f1cc391a6f26ccd95e3cdcb4f4f51
Add performance logging for slow cache retrieves
https://bugs.webkit.org/show_bug.cgi?id=186520
<rdar://problem/41002070>

Reviewed by Chris Dumez.

We sometimes see slow cache retrieves in logs. Add some more logging to better analyze these cases.

This patch adds timings to all cache storage retrieve operations and passes them up to the client.
We then log the timings on NetworkResourceLoader levels if needed. Items logged include

- total retrieve time
- dispatch delay and number of resources dispatched before this one
- record I/O time
- blob I/O time
- whether cache shrink was in progress
- whether cache synchronization was in progress
- cancellation

* NetworkProcess/NetworkResourceLoader.cpp:
(WebKit::NetworkResourceLoader::retrieveCacheEntry):
(WebKit::NetworkResourceLoader::logSlowCacheRetrieveIfNeeded):

Log if the retrieve took more than 1s.

* NetworkProcess/NetworkResourceLoader.h:
* NetworkProcess/cache/CacheStorageEngineCaches.cpp:
(WebKit::CacheStorage::Caches::readRecord):
* NetworkProcess/cache/NetworkCache.cpp:
(WebKit::NetworkCache::Cache::retrieve):
(WebKit::NetworkCache::Cache::completeRetrieve):
(WebKit::NetworkCache::Cache::retrieveData):
* NetworkProcess/cache/NetworkCache.h:
* NetworkProcess/cache/NetworkCacheSpeculativeLoadManager.cpp:
(WebKit::NetworkCache::SpeculativeLoadManager::retrieveEntryFromStorage):
(WebKit::NetworkCache::SpeculativeLoadManager::retrieveSubresourcesEntry):

SpeculativeLoadManager does not records specific timings yet but at least we do log when they occur.

* NetworkProcess/cache/NetworkCacheStorage.cpp:
(WebKit::NetworkCache::Storage::ReadOperation::cancel):
(WebKit::NetworkCache::Storage::ReadOperation::finish):

Record timing info in ReadOperations.

(WebKit::NetworkCache::Storage::dispatchReadOperation):
(WebKit::NetworkCache::retrieveFromMemory):
(WebKit::NetworkCache::Storage::retrieve):
* NetworkProcess/cache/NetworkCacheStorage.h:

git-svn-id: https://svn.webkit.org/repository/webkit/trunk@232759 268f45cc-cd09-0410-ab3c-d52691b4dbfc
Source/WebKit/ChangeLog
Source/WebKit/NetworkProcess/NetworkResourceLoader.cpp
Source/WebKit/NetworkProcess/NetworkResourceLoader.h
Source/WebKit/NetworkProcess/cache/CacheStorageEngineCaches.cpp
Source/WebKit/NetworkProcess/cache/NetworkCache.cpp
Source/WebKit/NetworkProcess/cache/NetworkCache.h
Source/WebKit/NetworkProcess/cache/NetworkCacheSpeculativeLoadManager.cpp
Source/WebKit/NetworkProcess/cache/NetworkCacheStorage.cpp
Source/WebKit/NetworkProcess/cache/NetworkCacheStorage.h