[WK2] Log total number of network cache queries using diagnostic logging
[WebKit-https.git] / Source / WebKit2 / NetworkProcess / cache / NetworkCache.cpp
1 /*
2  * Copyright (C) 2014-2015 Apple Inc. All rights reserved.
3  *
4  * Redistribution and use in source and binary forms, with or without
5  * modification, are permitted provided that the following conditions
6  * are met:
7  * 1. Redistributions of source code must retain the above copyright
8  *    notice, this list of conditions and the following disclaimer.
9  * 2. Redistributions in binary form must reproduce the above copyright
10  *    notice, this list of conditions and the following disclaimer in the
11  *    documentation and/or other materials provided with the distribution.
12  *
13  * THIS SOFTWARE IS PROVIDED BY APPLE INC. AND ITS CONTRIBUTORS ``AS IS''
14  * AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
15  * THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
16  * PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL APPLE INC. OR ITS CONTRIBUTORS
17  * BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
18  * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
19  * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
20  * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
21  * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
22  * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF
23  * THE POSSIBILITY OF SUCH DAMAGE.
24  */
25
26 #include "config.h"
27 #include "NetworkCache.h"
28
29 #if ENABLE(NETWORK_CACHE)
30
31 #include "Logging.h"
32 #include "NetworkCacheCoders.h"
33 #include "NetworkCacheStatistics.h"
34 #include "NetworkCacheStorage.h"
35 #include "NetworkResourceLoader.h"
36 #include "WebCoreArgumentCoders.h"
37 #include <JavaScriptCore/JSONObject.h>
38 #include <WebCore/CacheValidation.h>
39 #include <WebCore/FileSystem.h>
40 #include <WebCore/HTTPHeaderNames.h>
41 #include <WebCore/NetworkStorageSession.h>
42 #include <WebCore/PlatformCookieJar.h>
43 #include <WebCore/ResourceResponse.h>
44 #include <WebCore/SharedBuffer.h>
45 #include <wtf/NeverDestroyed.h>
46 #include <wtf/StringHasher.h>
47 #include <wtf/text/StringBuilder.h>
48
49 #if PLATFORM(COCOA)
50 #include <notify.h>
51 #endif
52
53 namespace WebKit {
54 namespace NetworkCache {
55
56 Cache& singleton()
57 {
58     static NeverDestroyed<Cache> instance;
59     return instance;
60 }
61
62 bool Cache::initialize(const String& cachePath, bool enableEfficacyLogging)
63 {
64     m_storage = Storage::open(cachePath);
65
66     if (enableEfficacyLogging)
67         m_statistics = Statistics::open(cachePath);
68
69 #if PLATFORM(COCOA)
70     // Triggers with "notifyutil -p com.apple.WebKit.Cache.dump".
71     if (m_storage) {
72         int token;
73         notify_register_dispatch("com.apple.WebKit.Cache.dump", &token, dispatch_get_main_queue(), ^(int) {
74             dumpContentsToFile();
75         });
76     }
77 #endif
78
79     LOG(NetworkCache, "(NetworkProcess) opened cache storage, success %d", !!m_storage);
80     return !!m_storage;
81 }
82
83 void Cache::setMaximumSize(size_t maximumSize)
84 {
85     if (!m_storage)
86         return;
87     m_storage->setMaximumSize(maximumSize);
88 }
89
90 static Key makeCacheKey(const WebCore::ResourceRequest& request)
91 {
92 #if ENABLE(CACHE_PARTITIONING)
93     String partition = request.cachePartition();
94 #else
95     String partition;
96 #endif
97     if (partition.isEmpty())
98         partition = ASCIILiteral("No partition");
99     return { request.httpMethod(), partition, request.url().string()  };
100 }
101
102 static String headerValueForVary(const WebCore::ResourceRequest& request, const String& headerName)
103 {
104     // Explicit handling for cookies is needed because they are added magically by the networking layer.
105     // FIXME: The value might have changed between making the request and retrieving the cookie here.
106     // We could fetch the cookie when making the request but that seems overkill as the case is very rare and it
107     // is a blocking operation. This should be sufficient to cover reasonable cases.
108     if (headerName == httpHeaderNameString(WebCore::HTTPHeaderName::Cookie))
109         return WebCore::cookieRequestHeaderFieldValue(WebCore::NetworkStorageSession::defaultStorageSession(), request.firstPartyForCookies(), request.url());
110     return request.httpHeaderField(headerName);
111 }
112
113 static Storage::Entry encodeStorageEntry(const WebCore::ResourceRequest& request, const WebCore::ResourceResponse& response, PassRefPtr<WebCore::SharedBuffer> responseData)
114 {
115     Encoder encoder;
116     encoder << response;
117
118     String varyValue = response.httpHeaderField(WebCore::HTTPHeaderName::Vary);
119     bool hasVaryingRequestHeaders = !varyValue.isEmpty();
120
121     encoder << hasVaryingRequestHeaders;
122
123     if (hasVaryingRequestHeaders) {
124         Vector<String> varyingHeaderNames;
125         varyValue.split(',', false, varyingHeaderNames);
126
127         Vector<std::pair<String, String>> varyingRequestHeaders;
128         for (auto& varyHeaderName : varyingHeaderNames) {
129             String headerName = varyHeaderName.stripWhiteSpace();
130             String headerValue = headerValueForVary(request, headerName);
131             varyingRequestHeaders.append(std::make_pair(headerName, headerValue));
132         }
133         encoder << varyingRequestHeaders;
134     }
135     encoder.encodeChecksum();
136
137     auto timeStamp = std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::system_clock::now().time_since_epoch());
138     Data header(encoder.buffer(), encoder.bufferSize());
139     Data body;
140     if (responseData)
141         body = { reinterpret_cast<const uint8_t*>(responseData->data()), responseData->size() };
142
143     return { makeCacheKey(request), timeStamp, header, body };
144 }
145
146 static bool verifyVaryingRequestHeaders(const Vector<std::pair<String, String>>& varyingRequestHeaders, const WebCore::ResourceRequest& request)
147 {
148     for (auto& varyingRequestHeader : varyingRequestHeaders) {
149         // FIXME: Vary: * in response would ideally trigger a cache delete instead of a store.
150         if (varyingRequestHeader.first == "*")
151             return false;
152         String headerValue = headerValueForVary(request, varyingRequestHeader.first);
153         if (headerValue != varyingRequestHeader.second)
154             return false;
155     }
156     return true;
157 }
158
159 static bool cachePolicyAllowsExpired(WebCore::ResourceRequestCachePolicy policy)
160 {
161     switch (policy) {
162     case WebCore::ReturnCacheDataElseLoad:
163     case WebCore::ReturnCacheDataDontLoad:
164         return true;
165     case WebCore::UseProtocolCachePolicy:
166     case WebCore::ReloadIgnoringCacheData:
167         return false;
168     }
169     ASSERT_NOT_REACHED();
170     return false;
171 }
172
173 static std::unique_ptr<Entry> decodeStorageEntry(const Storage::Entry& storageEntry, const WebCore::ResourceRequest& request, CachedEntryReuseFailure& failure)
174 {
175     Decoder decoder(storageEntry.header.data(), storageEntry.header.size());
176
177     WebCore::ResourceResponse cachedResponse;
178     if (!decoder.decode(cachedResponse)) {
179         LOG(NetworkCache, "(NetworkProcess) response decoding failed\n");
180         failure = CachedEntryReuseFailure::Other;
181         return nullptr;
182     }
183
184     bool hasVaryingRequestHeaders;
185     if (!decoder.decode(hasVaryingRequestHeaders)) {
186         failure = CachedEntryReuseFailure::Other;
187         return nullptr;
188     }
189
190     if (hasVaryingRequestHeaders) {
191         Vector<std::pair<String, String>> varyingRequestHeaders;
192         if (!decoder.decode(varyingRequestHeaders)) {
193             failure = CachedEntryReuseFailure::Other;
194             return nullptr;
195         }
196
197         if (!verifyVaryingRequestHeaders(varyingRequestHeaders, request)) {
198             LOG(NetworkCache, "(NetworkProcess) varying header mismatch\n");
199             failure = CachedEntryReuseFailure::VaryingHeaderMismatch;
200             return nullptr;
201         }
202     }
203     if (!decoder.verifyChecksum()) {
204         LOG(NetworkCache, "(NetworkProcess) checksum verification failure\n");
205         failure = CachedEntryReuseFailure::Other;
206         return nullptr;
207     }
208
209     bool allowExpired = cachePolicyAllowsExpired(request.cachePolicy()) && !cachedResponse.cacheControlContainsMustRevalidate();
210     auto timeStamp = std::chrono::duration_cast<std::chrono::duration<double>>(storageEntry.timeStamp);
211     double age = WebCore::computeCurrentAge(cachedResponse, timeStamp.count());
212     double lifetime = WebCore::computeFreshnessLifetimeForHTTPFamily(cachedResponse, timeStamp.count());
213     bool isExpired = age > lifetime;
214     bool needsRevalidation = (isExpired && !allowExpired) || cachedResponse.cacheControlContainsNoCache();
215
216     if (needsRevalidation) {
217         bool hasValidatorFields = cachedResponse.hasCacheValidatorFields();
218         LOG(NetworkCache, "(NetworkProcess) needsRevalidation hasValidatorFields=%d isExpired=%d age=%f lifetime=%f", isExpired, hasValidatorFields, age, lifetime);
219         if (!hasValidatorFields) {
220             failure = CachedEntryReuseFailure::MissingValidatorFields;
221             return nullptr;
222         }
223     }
224
225     auto entry = std::make_unique<Entry>();
226     entry->storageEntry = storageEntry;
227     entry->needsRevalidation = needsRevalidation;
228
229     cachedResponse.setSource(needsRevalidation ? WebCore::ResourceResponse::Source::DiskCacheAfterValidation : WebCore::ResourceResponse::Source::DiskCache);
230     entry->response = cachedResponse;
231
232 #if ENABLE(SHAREABLE_RESOURCE)
233     RefPtr<SharedMemory> sharedMemory = storageEntry.body.isMap() ? SharedMemory::createFromVMBuffer(const_cast<uint8_t*>(storageEntry.body.data()), storageEntry.body.size()) : nullptr;
234     RefPtr<ShareableResource> shareableResource = sharedMemory ? ShareableResource::create(sharedMemory.release(), 0, storageEntry.body.size()) : nullptr;
235
236     if (shareableResource && shareableResource->createHandle(entry->shareableResourceHandle))
237         entry->buffer = entry->shareableResourceHandle.tryWrapInSharedBuffer();
238     else
239 #endif
240         entry->buffer = WebCore::SharedBuffer::create(storageEntry.body.data(), storageEntry.body.size());
241
242     return entry;
243 }
244
245 static RetrieveDecision canRetrieve(const WebCore::ResourceRequest& request)
246 {
247     // FIXME: Support HEAD and OPTIONS requests.
248     if (request.httpMethod() != "GET")
249         return RetrieveDecision::NoDueToHTTPMethod;
250     // FIXME: We should be able to validate conditional requests using cache.
251     if (request.isConditional())
252         return RetrieveDecision::NoDueToConditionalRequest;
253     if (request.cachePolicy() == WebCore::ReloadIgnoringCacheData)
254         return RetrieveDecision::NoDueToReloadIgnoringCache;
255
256     return RetrieveDecision::Yes;
257 }
258
259 void Cache::retrieve(const WebCore::ResourceRequest& originalRequest, uint64_t webPageID, std::function<void (std::unique_ptr<Entry>)> completionHandler)
260 {
261     ASSERT(isEnabled());
262     ASSERT(originalRequest.url().protocolIsInHTTPFamily());
263
264     LOG(NetworkCache, "(NetworkProcess) retrieving %s priority %u", originalRequest.url().string().ascii().data(), originalRequest.priority());
265
266     if (m_statistics)
267         m_statistics->recordRetrievalRequest(webPageID);
268
269     Key storageKey = makeCacheKey(originalRequest);
270     RetrieveDecision retrieveDecision = canRetrieve(originalRequest);
271     if (retrieveDecision != RetrieveDecision::Yes) {
272         if (m_statistics)
273             m_statistics->recordNotUsingCacheForRequest(webPageID, storageKey, originalRequest, retrieveDecision);
274
275         completionHandler(nullptr);
276         return;
277     }
278
279     auto startTime = std::chrono::system_clock::now();
280     unsigned priority = originalRequest.priority();
281
282     m_storage->retrieve(storageKey, priority, [this, originalRequest, completionHandler, startTime, storageKey, webPageID](std::unique_ptr<Storage::Entry> entry) {
283         if (!entry) {
284             LOG(NetworkCache, "(NetworkProcess) not found in storage");
285
286             if (m_statistics)
287                 m_statistics->recordRetrievalFailure(webPageID, storageKey, originalRequest);
288
289             completionHandler(nullptr);
290             return false;
291         }
292         ASSERT(entry->key == storageKey);
293
294         CachedEntryReuseFailure failure = CachedEntryReuseFailure::None;
295         auto decodedEntry = decodeStorageEntry(*entry, originalRequest, failure);
296         bool success = !!decodedEntry;
297         if (m_statistics)
298             m_statistics->recordRetrievedCachedEntry(webPageID, storageKey, originalRequest, failure);
299
300 #if !LOG_DISABLED
301         auto elapsedMS = std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::system_clock::now() - startTime).count();
302 #endif
303         LOG(NetworkCache, "(NetworkProcess) retrieve complete success=%d priority=%u time=%lldms", success, originalRequest.priority(), elapsedMS);
304         completionHandler(WTF::move(decodedEntry));
305         return success;
306     });
307 }
308
309 static StoreDecision canStore(const WebCore::ResourceRequest& originalRequest, const WebCore::ResourceResponse& response)
310 {
311     if (!originalRequest.url().protocolIsInHTTPFamily() || !response.isHTTP()) {
312         LOG(NetworkCache, "(NetworkProcess) not HTTP");
313         return StoreDecision::NoDueToProtocol;
314     }
315     if (originalRequest.httpMethod() != "GET") {
316         LOG(NetworkCache, "(NetworkProcess) method %s", originalRequest.httpMethod().utf8().data());
317         return StoreDecision::NoDueToHTTPMethod;
318     }
319     if (response.isAttachment()) {
320         LOG(NetworkCache, "(NetworkProcess) attachment");
321         return StoreDecision::NoDueToAttachmentResponse;
322     }
323
324     switch (response.httpStatusCode()) {
325     case 200: // OK
326     case 203: // Non-Authoritative Information
327     case 300: // Multiple Choices
328     case 301: // Moved Permanently
329     case 302: // Found
330     case 307: // Temporary Redirect
331     case 410: // Gone
332         if (response.cacheControlContainsNoStore()) {
333             LOG(NetworkCache, "(NetworkProcess) Cache-control:no-store");
334             return StoreDecision::NoDueToNoStoreResponse;
335         }
336         return StoreDecision::Yes;
337     default:
338         LOG(NetworkCache, "(NetworkProcess) status code %d", response.httpStatusCode());
339     }
340
341     return StoreDecision::NoDueToHTTPStatusCode;
342 }
343
344 void Cache::store(const WebCore::ResourceRequest& originalRequest, const WebCore::ResourceResponse& response, RefPtr<WebCore::SharedBuffer>&& responseData, std::function<void (MappedBody&)> completionHandler)
345 {
346     ASSERT(isEnabled());
347     ASSERT(responseData);
348
349     LOG(NetworkCache, "(NetworkProcess) storing %s, partition %s", originalRequest.url().string().latin1().data(), originalRequest.cachePartition().latin1().data());
350
351     StoreDecision storeDecision = canStore(originalRequest, response);
352     if (storeDecision != StoreDecision::Yes) {
353         LOG(NetworkCache, "(NetworkProcess) didn't store");
354         if (m_statistics) {
355             auto key = makeCacheKey(originalRequest);
356             m_statistics->recordNotCachingResponse(key, storeDecision);
357         }
358         return;
359     }
360
361     auto storageEntry = encodeStorageEntry(originalRequest, response, WTF::move(responseData));
362
363     m_storage->store(storageEntry, [completionHandler](bool success, const Data& bodyData) {
364         MappedBody mappedBody;
365 #if ENABLE(SHAREABLE_RESOURCE)
366         if (bodyData.isMap()) {
367             RefPtr<SharedMemory> sharedMemory = SharedMemory::createFromVMBuffer(const_cast<uint8_t*>(bodyData.data()), bodyData.size());
368             mappedBody.shareableResource = sharedMemory ? ShareableResource::create(WTF::move(sharedMemory), 0, bodyData.size()) : nullptr;
369             if (mappedBody.shareableResource)
370                 mappedBody.shareableResource->createHandle(mappedBody.shareableResourceHandle);
371         }
372 #endif
373         completionHandler(mappedBody);
374         LOG(NetworkCache, "(NetworkProcess) store success=%d", success);
375     });
376 }
377
378 void Cache::update(const WebCore::ResourceRequest& originalRequest, const Entry& entry, const WebCore::ResourceResponse& validatingResponse)
379 {
380     LOG(NetworkCache, "(NetworkProcess) updating %s", originalRequest.url().string().latin1().data());
381
382     WebCore::ResourceResponse response = entry.response;
383     WebCore::updateResponseHeadersAfterRevalidation(response, validatingResponse);
384
385     auto updateEntry = encodeStorageEntry(originalRequest, response, entry.buffer);
386
387     m_storage->update(updateEntry, entry.storageEntry, [](bool success, const Data&) {
388         LOG(NetworkCache, "(NetworkProcess) updated, success=%d", success);
389     });
390 }
391
392 void Cache::remove(const Entry& entry)
393 {
394     ASSERT(isEnabled());
395
396     m_storage->remove(entry.storageEntry.key);
397 }
398
399 void Cache::traverse(std::function<void (const Entry*)>&& traverseHandler)
400 {
401     ASSERT(isEnabled());
402
403     m_storage->traverse([traverseHandler](const Storage::Entry* entry) {
404         if (!entry) {
405             traverseHandler(nullptr);
406             return;
407         }
408
409         Entry cacheEntry;
410         cacheEntry.storageEntry = *entry;
411
412         Decoder decoder(cacheEntry.storageEntry.header.data(), cacheEntry.storageEntry.header.size());
413         if (!decoder.decode(cacheEntry.response))
414             return;
415
416         traverseHandler(&cacheEntry);
417     });
418 }
419
420 String Cache::dumpFilePath() const
421 {
422     return WebCore::pathByAppendingComponent(m_storage->baseDirectoryPath(), "dump.json");
423 }
424
425 static bool entryAsJSON(StringBuilder& json, const Storage::Entry& entry)
426 {
427     Decoder decoder(entry.header.data(), entry.header.size());
428     WebCore::ResourceResponse cachedResponse;
429     if (!decoder.decode(cachedResponse))
430         return false;
431     json.append("{\n");
432     json.append("\"hash\": ");
433     JSC::appendQuotedJSONStringToBuilder(json, entry.key.hashAsString());
434     json.append(",\n");
435     json.append("\"partition\": ");
436     JSC::appendQuotedJSONStringToBuilder(json, entry.key.partition());
437     json.append(",\n");
438     json.append("\"timestamp\": ");
439     json.appendNumber(entry.timeStamp.count());
440     json.append(",\n");
441     json.append("\"URL\": ");
442     JSC::appendQuotedJSONStringToBuilder(json, cachedResponse.url().string());
443     json.append(",\n");
444     json.append("\"headers\": {\n");
445     bool firstHeader = true;
446     for (auto& header : cachedResponse.httpHeaderFields()) {
447         if (!firstHeader)
448             json.append(",\n");
449         firstHeader = false;
450         json.append("    ");
451         JSC::appendQuotedJSONStringToBuilder(json, header.key);
452         json.append(": ");
453         JSC::appendQuotedJSONStringToBuilder(json, header.value);
454     }
455     json.append("\n}\n");
456     json.append("}");
457     return true;
458 }
459
460 void Cache::dumpContentsToFile()
461 {
462     if (!m_storage)
463         return;
464     auto dumpFileHandle = WebCore::openFile(dumpFilePath(), WebCore::OpenForWrite);
465     if (!dumpFileHandle)
466         return;
467     WebCore::writeToFile(dumpFileHandle, "[\n", 2);
468     m_storage->traverse([dumpFileHandle](const Storage::Entry* entry) {
469         if (!entry) {
470             WebCore::writeToFile(dumpFileHandle, "{}\n]\n", 5);
471             auto handle = dumpFileHandle;
472             WebCore::closeFile(handle);
473             return;
474         }
475         StringBuilder json;
476         if (!entryAsJSON(json, *entry))
477             return;
478         json.append(",\n");
479         auto writeData = json.toString().utf8();
480         WebCore::writeToFile(dumpFileHandle, writeData.data(), writeData.length());
481     });
482 }
483
484 void Cache::clear()
485 {
486     LOG(NetworkCache, "(NetworkProcess) clearing cache");
487     if (m_storage) {
488         m_storage->clear();
489
490         auto queue = WorkQueue::create("com.apple.WebKit.Cache.delete");
491         StringCapture dumpFilePathCapture(dumpFilePath());
492         queue->dispatch([dumpFilePathCapture] {
493             WebCore::deleteFile(dumpFilePathCapture.string());
494         });
495     }
496     if (m_statistics)
497         m_statistics->clear();
498 }
499
500 String Cache::storagePath() const
501 {
502     return m_storage ? m_storage->directoryPath() : String();
503 }
504
505 }
506 }
507
508 #endif