diff --git a/src/workerd/api/BUILD.bazel b/src/workerd/api/BUILD.bazel index f02b4a6c72d..f3cc57fb6ed 100644 --- a/src/workerd/api/BUILD.bazel +++ b/src/workerd/api/BUILD.bazel @@ -428,6 +428,17 @@ wd_test( args = ["--experimental"], ) +wd_test( + src = "cache-test.wd-test", + args = ["--experimental"], + data = [ + "cache-instrumentation-test.js", + "cache-mock.js", + "cache-operations.js", + "tests/instrumentation-tail-worker.js", + ], +) + wd_test( src = "kv-test.wd-test", args = ["--experimental"], diff --git a/src/workerd/api/cache-instrumentation-test.js b/src/workerd/api/cache-instrumentation-test.js new file mode 100644 index 00000000000..62d18d2e5a8 --- /dev/null +++ b/src/workerd/api/cache-instrumentation-test.js @@ -0,0 +1,259 @@ +// Copyright (c) 2017-2023 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 +import * as assert from 'node:assert'; +import { + invocationPromises, + spans, + testTailHandler, +} from 'test:instumentation-tail'; + +// Use shared instrumentation test tail worker +export default testTailHandler; + +export const test = { + async test() { + // Wait for all the tailStream executions to finish + await Promise.allSettled(invocationPromises); + + // Recorded streaming tail worker events, in insertion order, + // filtering spans not associated with Cache + let received = Array.from(spans.values()); + + // spans emitted by cache-operations.js in execution order + let expected = [ + { + name: 'cache_match', + 'cache.request.url': 'https://example.com/conditional-etag', + 'cache.request.method': 'GET', + 'cache.request.header.if_none_match': 'abc123', + 'cache.response.status_code': 504n, + 'cache.response.body.size': 0n, + 'cache.response.cache_status': 'MISS', + 'cache.response.success': false, + closed: true, + }, + { + name: 'cache_match', + 'cache.request.url': 'https://example.com/conditional-last-modified', + 'cache.request.method': 'GET', + 'cache.request.header.if_modified_since': + 'Wed, 21 Oct 2020 07:28:00 GMT', + 'cache.response.status_code': 504n, + 'cache.response.body.size': 0n, + 'cache.response.cache_status': 'MISS', + 'cache.response.success': false, + closed: true, + }, + { + name: 'cache_delete', + 'cache.request.url': 'https://example.com/delete-exists', + 'cache.response.status_code': 200n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_delete', + 'cache.request.url': 'https://example.com/delete-not-exists', + 'cache.response.status_code': 404n, + 'cache.response.success': false, + closed: true, + }, + { + name: 'cache_delete', + 'cache.request.ignore_method': true, + 'cache.request.url': 'https://example.com/delete-with-options', + 'cache.response.status_code': 404n, + 'cache.response.success': false, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-cache-tag', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': 'public, max-age=3600', + 'cache.request.payload.header.cache_tag': 'tag1,tag2,tag3', + 'cache.request.payload.size': 143n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-etag', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': 'public, max-age=3600', + 'cache.request.payload.header.etag': '"abc123"', + 'cache.request.payload.size': 130n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-expires', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.expires': 'Wed, 21 Oct 2025 07:28:00 GMT', + 'cache.request.payload.size': 120n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-last-modified', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': 'public, max-age=3600', + 'cache.request.payload.header.last_modified': + 'Wed, 21 Oct 2020 07:28:00 GMT', + 'cache.request.payload.size': 169n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-set-cookie', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': 'public, max-age=3600', + 'cache.request.payload.size': 164n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-set-cookie-private', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': + 'public, max-age=3600, private=Set-Cookie', + 'cache.request.payload.size': 197n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-must-revalidate', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': + 'public, max-age=3600, must-revalidate', + 'cache.request.payload.size': 142n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-proxy-revalidate', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': + 'public, max-age=3600, proxy-revalidate', + 'cache.request.payload.size': 144n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-private', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': 'private, max-age=3600', + 'cache.request.payload.size': 118n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-no-cache', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': 'no-cache, max-age=3600', + 'cache.request.payload.size': 120n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_match', + 'cache.request.url': 'https://example.com/cached-resource', + 'cache.request.method': 'GET', + 'cache.response.status_code': 200n, + 'cache.response.body.size': 14n, + 'cache.response.cache_status': 'HIT', + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_match', + 'cache.request.url': 'https://example.com/not-cached', + 'cache.request.method': 'GET', + 'cache.response.status_code': 504n, + 'cache.response.body.size': 0n, + 'cache.response.cache_status': 'MISS', + 'cache.response.success': false, + closed: true, + }, + { + name: 'cache_match', + 'cache.request.ignore_method': false, + 'cache.request.url': 'https://example.com/cached-with-options', + 'cache.request.method': 'GET', + 'cache.response.status_code': 504n, + 'cache.response.body.size': 0n, + 'cache.response.cache_status': 'MISS', + 'cache.response.success': false, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-resource', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': 'public, max-age=3600', + 'cache.request.payload.size': 114n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-no-store', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': 'no-store', + 'cache.request.payload.size': 106n, + 'cache.response.success': true, + closed: true, + }, + { + name: 'cache_put', + 'cache.request.url': 'https://example.com/put-s-maxage', + 'cache.request.method': 'GET', + 'cache.request.payload.status_code': 200n, + 'cache.request.payload.header.cache_control': 's-maxage=7200, public', + 'cache.request.payload.size': 119n, + 'cache.response.success': true, + closed: true, + }, + ]; + + assert.equal( + received.length, + expected.length, + `Expected ${expected.length} received ${received.length} spans` + ); + let errors = []; + for (let i = 0; i < received.length; i++) { + try { + assert.deepStrictEqual(received[i], expected[i]); + } catch (e) { + console.error(`value: ${i} does not match`); + console.log(e); + errors.push(e); + } + } + if (errors.length > 0) { + throw 'cache spans are incorrect'; + } + }, +}; diff --git a/src/workerd/api/cache-mock.js b/src/workerd/api/cache-mock.js new file mode 100644 index 00000000000..1f994072b40 --- /dev/null +++ b/src/workerd/api/cache-mock.js @@ -0,0 +1,48 @@ +// Copyright (c) 2017-2023 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +// Mock cache backend - responds to GET (match), PUT (put), and PURGE (delete) +export default { + async fetch(request) { + const url = new URL(request.url); + const headers = new Headers(); + + // Handle cache.match() operations (GET requests) + if (request.method === 'GET') { + // Check if this is a cache.match() request (has only-if-cached) + const cacheControl = request.headers.get('cache-control'); + if (cacheControl?.includes('only-if-cached')) { + // Simulate cache HIT + if (url.pathname.includes('cached-resource')) { + headers.set('CF-Cache-Status', 'HIT'); + return new Response('Cached content', { status: 200, headers }); + } + // Simulate cache MISS + headers.set('CF-Cache-Status', 'MISS'); + return new Response(null, { status: 504, headers }); + } + } + + // Handle cache.put() operations (PUT requests) + if (request.method === 'PUT') { + // Read the body (which contains the serialized response to cache) + await request.text(); + + // Simulate successful cache write + return new Response(null, { status: 204 }); + } + + // Handle cache.delete() operations (PURGE requests) + if (request.method === 'PURGE') { + // Simulate successful deletion + if (url.pathname.includes('delete-exists')) { + return new Response(null, { status: 200 }); + } + // Simulate not found + return new Response(null, { status: 404 }); + } + + return new Response('Not Found', { status: 404 }); + }, +}; diff --git a/src/workerd/api/cache-operations.js b/src/workerd/api/cache-operations.js new file mode 100644 index 00000000000..52759acf5dd --- /dev/null +++ b/src/workerd/api/cache-operations.js @@ -0,0 +1,306 @@ +// Copyright (c) 2017-2023 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 +// +// Cache API operations for generating instrumentation telemetry. +// The actual validation of telemetry spans happens in cache-instrumentation-test.js + +import * as assert from 'node:assert'; + +// Note that these aren't really tests of the cache API. We run through a bunch +// of the cache API operations to emit telemetry for the tests in cache-instrumentation-test.js + +export const matchOperations = { + async test(ctrl, env, ctx) { + const cache = caches.default; + + // Test cache.match() - HIT case + const matchRequest1 = new Request('https://example.com/cached-resource', { + method: 'GET', + }); + let matchResult = await cache.match(matchRequest1); + assert.ok(matchResult !== undefined, 'Should have a cache HIT'); + assert.strictEqual(await matchResult.text(), 'Cached content'); + + // Test cache.match() - MISS case + const matchRequest2 = new Request('https://example.com/not-cached', { + method: 'GET', + }); + matchResult = await cache.match(matchRequest2); + assert.strictEqual(matchResult, undefined, 'Should be cache MISS'); + + // Test cache.match() with options + const matchRequest3 = new Request( + 'https://example.com/cached-with-options', + { + method: 'GET', + } + ); + matchResult = await cache.match(matchRequest3, { ignoreMethod: false }); + assert.strictEqual( + matchResult, + undefined, + 'Should be cache MISS with options' + ); + }, +}; + +export const putOperations = { + async test(ctrl, env, ctx) { + const cache = caches.default; + + // Test cache.put() with max-age + const putRequest1 = new Request('https://example.com/put-resource', { + method: 'GET', + }); + const putResponse1 = new Response('Test content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'public, max-age=3600', + }, + }); + await cache.put(putRequest1, putResponse1); + + // Test cache.put() with no-store + const putRequest2 = new Request('https://example.com/put-no-store', { + method: 'GET', + }); + const putResponse2 = new Response('No store content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'no-store', + }, + }); + await cache.put(putRequest2, putResponse2); + + // Test cache.put() with s-maxage + const putRequest3 = new Request('https://example.com/put-s-maxage', { + method: 'GET', + }); + const putResponse3 = new Response('S-maxage content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 's-maxage=7200, public', + }, + }); + await cache.put(putRequest3, putResponse3); + }, +}; + +export const deleteOperations = { + async test(ctrl, env, ctx) { + const cache = caches.default; + + // Test cache.delete() - exists + const deleteRequest1 = new Request('https://example.com/delete-exists', { + method: 'GET', + }); + let deleteResult = await cache.delete(deleteRequest1); + assert.strictEqual( + deleteResult, + true, + 'Should return true for successful delete' + ); + + // Test cache.delete() - doesn't exist + const deleteRequest2 = new Request( + 'https://example.com/delete-not-exists', + { + method: 'GET', + } + ); + deleteResult = await cache.delete(deleteRequest2); + assert.strictEqual( + deleteResult, + false, + 'Should return false when not found' + ); + + // Test cache.delete() with options + const deleteRequest3 = new Request( + 'https://example.com/delete-with-options', + { + method: 'POST', + } + ); + deleteResult = await cache.delete(deleteRequest3, { ignoreMethod: true }); + assert.strictEqual(deleteResult, false, 'Should handle options'); + }, +}; + +export const headersOperations = { + async test(ctrl, env, ctx) { + const cache = caches.default; + + // Test cache.put() with Cache-Tag header + const putRequest1 = new Request('https://example.com/put-cache-tag', { + method: 'GET', + }); + const putResponse1 = new Response('Tagged content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'public, max-age=3600', + 'Cache-Tag': 'tag1,tag2,tag3', + }, + }); + await cache.put(putRequest1, putResponse1); + + // Test cache.put() with ETag header + const putRequest2 = new Request('https://example.com/put-etag', { + method: 'GET', + }); + const putResponse2 = new Response('ETag content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'public, max-age=3600', + ETag: '"abc123"', + }, + }); + await cache.put(putRequest2, putResponse2); + + // Test cache.put() with Expires header + const putRequest3 = new Request('https://example.com/put-expires', { + method: 'GET', + }); + const putResponse3 = new Response('Expires content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + Expires: 'Wed, 21 Oct 2025 07:28:00 GMT', + }, + }); + await cache.put(putRequest3, putResponse3); + + // Test cache.put() with Last-Modified header + const putRequest4 = new Request('https://example.com/put-last-modified', { + method: 'GET', + }); + const putResponse4 = new Response('Last-Modified content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'public, max-age=3600', + 'Last-Modified': 'Wed, 21 Oct 2020 07:28:00 GMT', + }, + }); + await cache.put(putRequest4, putResponse4); + + // Test cache.put() with Set-Cookie header (should not cache or require special handling) + const putRequest5 = new Request('https://example.com/put-set-cookie', { + method: 'GET', + }); + const putResponse5 = new Response('Cookie content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'public, max-age=3600', + 'Set-Cookie': 'sessionid=abc123; Path=/; HttpOnly', + }, + }); + await cache.put(putRequest5, putResponse5); + + // Test cache.put() with Set-Cookie and Cache-Control: private=Set-Cookie + const putRequest6 = new Request( + 'https://example.com/put-set-cookie-private', + { + method: 'GET', + } + ); + const putResponse6 = new Response('Cookie content with private', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'public, max-age=3600, private=Set-Cookie', + 'Set-Cookie': 'sessionid=xyz789; Path=/; HttpOnly', + }, + }); + await cache.put(putRequest6, putResponse6); + + // Test cache.put() with must-revalidate + const putRequest7 = new Request('https://example.com/put-must-revalidate', { + method: 'GET', + }); + const putResponse7 = new Response('Must revalidate content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'public, max-age=3600, must-revalidate', + }, + }); + await cache.put(putRequest7, putResponse7); + + // Test cache.put() with proxy-revalidate + const putRequest8 = new Request( + 'https://example.com/put-proxy-revalidate', + { + method: 'GET', + } + ); + const putResponse8 = new Response('Proxy revalidate content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'public, max-age=3600, proxy-revalidate', + }, + }); + await cache.put(putRequest8, putResponse8); + + // Test cache.put() with private cache control + const putRequest9 = new Request('https://example.com/put-private', { + method: 'GET', + }); + const putResponse9 = new Response('Private content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'private, max-age=3600', + }, + }); + await cache.put(putRequest9, putResponse9); + + // Test cache.put() with no-cache + const putRequest10 = new Request('https://example.com/put-no-cache', { + method: 'GET', + }); + const putResponse10 = new Response('No-cache content', { + status: 200, + headers: { + 'Content-Type': 'text/plain', + 'Cache-Control': 'no-cache, max-age=3600', + }, + }); + await cache.put(putRequest10, putResponse10); + }, +}; + +export const conditionalRequestOperations = { + async test(ctrl, env, ctx) { + const cache = caches.default; + + // Test cache.match() with If-None-Match (should work with ETag) + const matchRequest1 = new Request('https://example.com/conditional-etag', { + method: 'GET', + headers: { + 'If-None-Match': 'abc123', + }, + }); + let matchResult = await cache.match(matchRequest1); + + // Test cache.match() with If-Modified-Since (should work with Last-Modified) + const matchRequest2 = new Request( + 'https://example.com/conditional-last-modified', + { + method: 'GET', + headers: { + 'If-Modified-Since': 'Wed, 21 Oct 2020 07:28:00 GMT', + }, + } + ); + matchResult = await cache.match(matchRequest2); + }, +}; diff --git a/src/workerd/api/cache-test.wd-test b/src/workerd/api/cache-test.wd-test new file mode 100644 index 00000000000..27c4e3740a4 --- /dev/null +++ b/src/workerd/api/cache-test.wd-test @@ -0,0 +1,39 @@ +using Workerd = import "/workerd/workerd.capnp"; + +const unitTests :Workerd.Config = ( + services = [ + ( name = "cache-test", + worker = ( + modules = [ + ( name = "worker", esModule = embed "cache-operations.js" ) + ], + cacheApiOutbound = "cache-backend", + compatibilityDate = "2023-07-24", + compatibilityFlags = ["nodejs_compat", "streaming_tail_worker"], + streamingTails = ["tail"], + ) + ), + ( name = "cache-backend", + worker = ( + modules = [ + ( name = "worker", esModule = embed "cache-mock.js" ) + ], + compatibilityDate = "2023-07-24", + ) + ), + (name = "tail", worker = .tailWorker, ), + ], + extensions = [ ( + modules = [ + ( name = "test:instumentation-tail", esModule = embed "tests/instrumentation-tail-worker.js" ), + ] + ) ] +); + +const tailWorker :Workerd.Worker = ( + modules = [ + (name = "worker", esModule = embed "cache-instrumentation-test.js") + ], + compatibilityDate = "2024-10-14", + compatibilityFlags = ["experimental", "nodejs_compat"], +); diff --git a/src/workerd/api/cache.c++ b/src/workerd/api/cache.c++ index 8245e1f0d91..9e981ce0c9a 100644 --- a/src/workerd/api/cache.c++ +++ b/src/workerd/api/cache.c++ @@ -76,6 +76,16 @@ jsg::Promise>> Cache::match(jsg::Lock& js, CompatibilityFlags::Reader flags) { // TODO(someday): Implement Cache API in preview. auto& context = IoContext::current(); + auto traceSpan = context.makeTraceSpan("cache_match"_kjc); + auto userSpan = context.makeUserTraceSpan("cache_match"_kjc); + TraceContext traceContext(kj::mv(traceSpan), kj::mv(userSpan)); + + KJ_IF_SOME(o, options) { + KJ_IF_SOME(ignoreMethod, o.ignoreMethod) { + traceContext.userSpan.setTag("cache.request.ignore_method"_kjc, ignoreMethod); + } + } + if (context.isFiddle()) { context.logWarningOnce(CACHE_API_PREVIEW_WARNING); return js.resolvedPromise(jsg::Optional>()); @@ -86,27 +96,51 @@ jsg::Promise>> Cache::match(jsg::Lock& js, return js.evalNow([&]() -> jsg::Promise>> { auto jsRequest = Request::coerce(js, kj::mv(requestOrUrl), kj::none); + traceContext.userSpan.setTag("cache.request.url"_kjc, kj::str(jsRequest->getUrl())); + traceContext.userSpan.setTag("cache.request.method"_kjc, kj::str(jsRequest->getMethodEnum())); + if (!options.orDefault({}).ignoreMethod.orDefault(false) && jsRequest->getMethodEnum() != kj::HttpMethod::GET) { return js.resolvedPromise(jsg::Optional>()); } - auto httpClient = getHttpClient(context, jsRequest->serializeCfBlobJson(js), "cache_match"_kjc, - jsRequest->getUrl(), kj::none, flags.getCacheApiCompatFlags()); + auto httpClient = getHttpClient( + context, jsRequest->serializeCfBlobJson(js), traceContext, flags.getCacheApiCompatFlags()); auto requestHeaders = kj::HttpHeaders(context.getHeaderTable()); jsRequest->shallowCopyHeadersTo(requestHeaders); + + auto headerIds = context.getHeaderIds(); + // parse each of the request headers to add info to span + KJ_IF_SOME(range, requestHeaders.get(headerIds.range)) { + traceContext.userSpan.setTag("cache.request.header.range"_kjc, kj::str(range)); + } + KJ_IF_SOME(ifModifiedSince, requestHeaders.get(headerIds.ifModifiedSince)) { + traceContext.userSpan.setTag( + "cache.request.header.if_modified_since"_kjc, kj::str(ifModifiedSince)); + } + KJ_IF_SOME(ifNoneMatch, requestHeaders.get(headerIds.ifNoneMatch)) { + traceContext.userSpan.setTag("cache.request.header.if_none_match"_kjc, kj::str(ifNoneMatch)); + } + requestHeaders.setPtr(context.getHeaderIds().cacheControl, "only-if-cached"); auto nativeRequest = httpClient->request( kj::HttpMethod::GET, validateUrl(jsRequest->getUrl()), requestHeaders, uint64_t(0)); return context.awaitIo(js, kj::mv(nativeRequest.response), - [httpClient = kj::mv(httpClient), &context](jsg::Lock& js, + [httpClient = kj::mv(httpClient), &context, traceContext = kj::mv(traceContext)]( + jsg::Lock& js, kj::HttpClient::Response&& response) mutable -> jsg::Optional> { response.body = response.body.attach(kj::mv(httpClient)); + traceContext.userSpan.setTag("cache.response.status_code"_kjc, int64_t(response.statusCode)); + KJ_IF_SOME(length, response.body->tryGetLength()) { + traceContext.userSpan.setTag("cache.response.body.size"_kjc, int64_t(length)); + } + kj::StringPtr cacheStatus; KJ_IF_SOME(cs, response.headers->get(context.getHeaderIds().cfCacheStatus)) { cacheStatus = cs; + traceContext.userSpan.setTag("cache.response.cache_status"_kjc, kj::str(cacheStatus)); } else { // This is an internal error representing a violation of the contract between us and // the cache. Since it is always conformant to return undefined from Cache::match() @@ -114,6 +148,7 @@ jsg::Promise>> Cache::match(jsg::Lock& js, // script fail. However, it might be indicative of a larger problem, and should be // investigated. LOG_CACHE_ERROR_ONCE("Response to Cache API GET has no CF-Cache-Status: ", response); + traceContext.userSpan.setTag("cache.response.success"_kjc, false); return kj::none; } @@ -127,13 +162,16 @@ jsg::Promise>> Cache::match(jsg::Lock& js, // this URL result in a 200, causing us to return true from Cache::delete_()? If so, that's // a small inconsistency: we shouldn't have a match failure but a delete success. if (cacheStatus == "MISS" || cacheStatus == "EXPIRED" || cacheStatus == "UPDATING") { + traceContext.userSpan.setTag("cache.response.success"_kjc, false); return kj::none; } else if (cacheStatus != "HIT") { // Another internal error. See above comment where we retrieve the CF-Cache-Status header. LOG_CACHE_ERROR_ONCE("Response to Cache API GET has invalid CF-Cache-Status: ", response); + traceContext.userSpan.setTag("cache.response.success"_kjc, false); return kj::none; } + traceContext.userSpan.setTag("cache.response.success"_kjc, true); return makeHttpResponse(js, kj::HttpMethod::GET, {}, response.statusCode, response.statusText, *response.headers, kj::mv(response.body), kj::none); }); @@ -244,6 +282,16 @@ jsg::Promise Cache::put(jsg::Lock& js, return js.evalNow([&] { auto jsRequest = Request::coerce(js, kj::mv(requestOrUrl), kj::none); + auto& context = IoContext::current(); + auto traceSpan = context.makeTraceSpan("cache_put"_kjc); + auto userSpan = context.makeUserTraceSpan("cache_put"_kjc); + TraceContext traceContext(kj::mv(traceSpan), kj::mv(userSpan)); + + traceContext.userSpan.setTag("cache.request.url"_kjc, kj::str(jsRequest->getUrl())); + traceContext.userSpan.setTag("cache.request.method"_kjc, kj::str(jsRequest->getMethodEnum())); + traceContext.userSpan.setTag( + "cache.request.payload.status_code"_kjc, int64_t(jsResponse->getStatus())); + // TODO(conform): Require that jsRequest's url has an http or https scheme. This is only // important if api::Request is changed to parse its URL eagerly (as required by spec), rather // than at fetch()-time. @@ -262,7 +310,23 @@ jsg::Promise Cache::put(jsg::Lock& js, "Cannot cache response with 'Vary: *' header."); } - auto& context = IoContext::current(); + KJ_IF_SOME(cacheControl, responseHeadersRef->getNoChecks(js, "cache-control"_kj)) { + traceContext.userSpan.setTag( + "cache.request.payload.header.cache_control"_kjc, kj::str(cacheControl)); + } + KJ_IF_SOME(cacheTag, responseHeadersRef->getNoChecks(js, "cache-tag"_kj)) { + traceContext.userSpan.setTag("cache.request.payload.header.cache_tag"_kjc, kj::str(cacheTag)); + } + KJ_IF_SOME(etag, responseHeadersRef->getNoChecks(js, "etag"_kj)) { + traceContext.userSpan.setTag("cache.request.payload.header.etag"_kjc, kj::str(etag)); + } + KJ_IF_SOME(expires, responseHeadersRef->getNoChecks(js, "expires"_kj)) { + traceContext.userSpan.setTag("cache.request.payload.header.expires"_kjc, kj::str(expires)); + } + KJ_IF_SOME(lastModified, responseHeadersRef->getNoChecks(js, "last-modified"_kj)) { + traceContext.userSpan.setTag( + "cache.request.payload.header.last_modified"_kjc, kj::str(lastModified)); + } if (jsResponse->getStatus() == 304) { // Silently discard 304 status responses to conditional requests. Caching 304s could be a @@ -291,6 +355,10 @@ jsg::Promise Cache::put(jsg::Lock& js, auto serializePromise = jsResponse->send(js, serializer, {}, kj::none); auto payload = serializer.getPayload(); + KJ_IF_SOME(length, payload.stream->tryGetLength()) { + traceContext.userSpan.setTag("cache.request.payload.size"_kjc, int64_t(length)); + } + // TODO(someday): Implement Cache API in preview. This bail-out lives all the way down here, // after all KJ_REQUIRE checks and the start of response serialization, so that Cache.put() // fulfills its contract, even in the preview. This prevents buggy code from working in the @@ -319,11 +387,12 @@ jsg::Promise Cache::put(jsg::Lock& js, [this, &context, jsRequest = kj::mv(jsRequest), cacheControl = kj::mv(cacheControl), serializePromise = kj::mv(serializePromise), writePayloadHeadersPromise = kj::mv(payload.writeHeadersPromise), - enableCompatFlags = flags.getCacheApiCompatFlags()](jsg::Lock& js, + enableCompatFlags = flags.getCacheApiCompatFlags(), + traceContext = kj::mv(traceContext)](jsg::Lock& js, IoOwn payloadStream) mutable -> jsg::Promise { // Make the PUT request to cache. - auto httpClient = getHttpClient(context, jsRequest->serializeCfBlobJson(js), "cache_put"_kjc, - jsRequest->getUrl(), kj::mv(cacheControl), enableCompatFlags); + auto httpClient = getHttpClient( + context, jsRequest->serializeCfBlobJson(js), traceContext, enableCompatFlags); auto requestHeaders = kj::HttpHeaders(context.getHeaderTable()); jsRequest->shallowCopyHeadersTo(requestHeaders); auto nativeRequest = httpClient->request(kj::HttpMethod::PUT, @@ -398,7 +467,8 @@ jsg::Promise Cache::put(jsg::Lock& js, kj::Promise responsePromise, kj::Own bodyStream, kj::Promise pumpRequestBodyPromise, kj::Promise writePayloadHeadersPromise, - kj::Own payloadStream) -> kj::Promise> { + kj::Own payloadStream, + TraceContext traceContext) -> kj::Promise> { // This is extremely odd and a bit annoying but we have to make sure // these are destroyed in a particular order due to cross-dependencies // for each. If the kj::Promise returned by handleSerialize is dropped @@ -447,8 +517,13 @@ jsg::Promise Cache::put(jsg::Lock& js, // ephemeral K/V store, and we never guaranteed the script we'd actually cache anything. if (response.statusCode != 204 && response.statusCode != 413) { LOG_CACHE_ERROR_ONCE("Response to Cache API PUT was neither 204 nor 413: ", response); + } else if (response.statusCode == 204) { + traceContext.userSpan.setTag("cache.response.success"_kjc, true); + } else if (response.statusCode == 413) { + traceContext.userSpan.setTag("cache.response.success"_kjc, false); } } catch (...) { + traceContext.userSpan.setTag("cache.response.success"_kjc, false); auto exception = kj::getCaughtExceptionAsKj(); if (exception.getType() != kj::Exception::Type::DISCONNECTED) { kj::throwFatalException(kj::mv(exception)); @@ -469,7 +544,7 @@ jsg::Promise Cache::put(jsg::Lock& js, handleSerialize(kj::mv(serializePromise), kj::mv(httpClient), kj::mv(nativeRequest.response), kj::mv(nativeRequest.body), kj::mv(pumpRequestBodyPromise), kj::mv(writePayloadHeadersPromise), - kj::mv(payloadStream))); + kj::mv(payloadStream), kj::mv(traceContext))); })); }); } @@ -480,6 +555,16 @@ jsg::Promise Cache::delete_(jsg::Lock& js, CompatibilityFlags::Reader flags) { // TODO(someday): Implement Cache API in preview. auto& context = IoContext::current(); + auto traceSpan = context.makeTraceSpan("cache_delete"_kjc); + auto userSpan = context.makeUserTraceSpan("cache_delete"_kjc); + TraceContext traceContext(kj::mv(traceSpan), kj::mv(userSpan)); + + KJ_IF_SOME(o, options) { + KJ_IF_SOME(ignoreMethod, o.ignoreMethod) { + traceContext.userSpan.setTag("cache.request.ignore_method"_kjc, ignoreMethod); + } + } + if (context.isFiddle()) { context.logWarningOnce(CACHE_API_PREVIEW_WARNING); return js.resolvedPromise(false); @@ -490,6 +575,7 @@ jsg::Promise Cache::delete_(jsg::Lock& js, return js.evalNow([&]() -> jsg::Promise { auto jsRequest = Request::coerce(js, kj::mv(requestOrUrl), kj::none); + traceContext.userSpan.setTag("cache.request.url"_kjc, kj::str(jsRequest->getUrl())); if (!options.orDefault({}).ignoreMethod.orDefault(false) && jsRequest->getMethodEnum() != kj::HttpMethod::GET) { return js.resolvedPromise(false); @@ -497,8 +583,8 @@ jsg::Promise Cache::delete_(jsg::Lock& js, // Make the PURGE request to cache. - auto httpClient = getHttpClient(context, jsRequest->serializeCfBlobJson(js), "cache_delete"_kjc, - jsRequest->getUrl(), kj::none, flags.getCacheApiCompatFlags()); + auto httpClient = getHttpClient( + context, jsRequest->serializeCfBlobJson(js), traceContext, flags.getCacheApiCompatFlags()); auto requestHeaders = kj::HttpHeaders(context.getHeaderTable()); jsRequest->shallowCopyHeadersTo(requestHeaders); // HACK: The cache doesn't permit PURGE requests from the outside world. It does this by @@ -512,12 +598,17 @@ jsg::Promise Cache::delete_(jsg::Lock& js, kj::HttpMethod::PURGE, validateUrl(jsRequest->getUrl()), requestHeaders, uint64_t(0)); return context.awaitIo(js, kj::mv(nativeRequest.response), - [httpClient = kj::mv(httpClient)](jsg::Lock&, kj::HttpClient::Response&& response) -> bool { + [httpClient = kj::mv(httpClient), traceContext = kj::mv(traceContext)]( + jsg::Lock&, kj::HttpClient::Response&& response) mutable -> bool { + traceContext.userSpan.setTag("cache.response.status_code"_kjc, int64_t(response.statusCode)); if (response.statusCode == 200) { + traceContext.userSpan.setTag("cache.response.success"_kjc, true); return true; } else if (response.statusCode == 404) { + traceContext.userSpan.setTag("cache.response.success"_kjc, false); return false; } else if (response.statusCode == 429) { + traceContext.userSpan.setTag("cache.response.success"_kjc, false); // Throw, but do not log the response to Sentry, as rate-limited subrequests are normal JSG_FAIL_REQUIRE( Error, "Unable to delete cached response. Subrequests are being rate-limited."); @@ -530,56 +621,12 @@ jsg::Promise Cache::delete_(jsg::Lock& js, kj::Own Cache::getHttpClient(IoContext& context, kj::Maybe cfBlobJson, - kj::LiteralStringConst operationName, - kj::StringPtr url, - kj::Maybe cacheControl, + TraceContext& traceContext, bool enableCompatFlags) { - auto span = context.makeTraceSpan(operationName); - auto userSpan = context.makeUserTraceSpan(operationName); - - userSpan.setTag("url.full"_kjc, kj::str(url)); - // TODO(o11y): Can we parse cacheControl more cleanly? For example, if tags are duplicated in the - // same category we should choose the last value. We should also support these tags for - // cache_match (where we should pull them from the returned response and need to keep the span - // alive until then). - KJ_IF_SOME(c, cacheControl) { - // cacheability - if (c.contains("no-store")) { - userSpan.setTag("cache_control.cacheability"_kjc, kj::str("no-store")); - } else if (c.contains("private")) { - userSpan.setTag("cache_control.cacheability"_kjc, kj::str("private")); - } else if (c.contains("public")) { - userSpan.setTag("cache_control.cacheability"_kjc, kj::str("public")); - } - - // expiration - if (c.contains("no-cache")) { - userSpan.setTag("cache_control.expiration"_kjc, kj::str("no-cache")); - } else KJ_IF_SOME(idx, c.find("max-age="_kj)) { - auto maybeNum = c.slice(idx + "max-age="_kj.size()).tryParseAs(); - KJ_IF_SOME(num, maybeNum) { - userSpan.setTag("cache_control.expiration"_kjc, kj::str(kj::str("max-age="), kj::str(num))); - } - } else KJ_IF_SOME(idx, c.find("s-maxage="_kj)) { - auto maybeNum = c.slice(idx + "s-maxage="_kj.size()).tryParseAs(); - KJ_IF_SOME(num, maybeNum) { - userSpan.setTag( - "cache_control.expiration"_kjc, kj::str(kj::str("s-maxage="), kj::str(num))); - } - } - - // revalidation. Note: There are also stale-while-revalidate and stale-if-error directives, but - // they are ignored by the Workers Cache API and we do not set them as tags accordingly. - if (c.contains("must-revalidate")) { - userSpan.setTag("cache_control.revalidation"_kjc, kj::str("must-revalidate")); - } else if (c.contains("proxy-revalidate")) { - userSpan.setTag("cache_control.revalidation"_kjc, kj::str("proxy-revalidate")); - } - } auto cacheClient = context.getCacheClient(); auto metadata = CacheClient::SubrequestMetadata{ .cfBlobJson = kj::mv(cfBlobJson), - .parentSpan = span, + .parentSpan = traceContext.span, .featureFlagsForFl = kj::none, }; if (enableCompatFlags) { @@ -589,7 +636,6 @@ kj::Own Cache::getHttpClient(IoContext& context, cacheName.map([&](kj::String& n) { return cacheClient->getNamespace(n, kj::mv(metadata)); }).orDefault([&]() { return cacheClient->getDefault(kj::mv(metadata)); }); - httpClient = httpClient.attach(kj::mv(span), kj::mv(userSpan), kj::mv(cacheClient)); return httpClient; } diff --git a/src/workerd/api/cache.h b/src/workerd/api/cache.h index 64a14f5a1ed..bafd161d7da 100644 --- a/src/workerd/api/cache.h +++ b/src/workerd/api/cache.h @@ -91,9 +91,7 @@ class Cache: public jsg::Object { kj::Own getHttpClient(IoContext& context, kj::Maybe cfBlobJson, - kj::LiteralStringConst operationName, - kj::StringPtr url, - kj::Maybe cacheControl, + TraceContext& traceContext, bool enableCompatFlags); }; diff --git a/src/workerd/io/io-thread-context.c++ b/src/workerd/io/io-thread-context.c++ index 00a8e286858..51c336eb8e2 100644 --- a/src/workerd/io/io-thread-context.c++ +++ b/src/workerd/io/io-thread-context.c++ @@ -9,6 +9,9 @@ ThreadContext::HeaderIdBundle::HeaderIdBundle(kj::HttpHeaderTable::Builder& buil cacheControl(builder.add("Cache-Control")), pragma(builder.add("Pragma")), cfCacheNamespace(builder.add("CF-Cache-Namespace")), + range(builder.add("Range")), + ifModifiedSince(builder.add("If-Modified-Since")), + ifNoneMatch(builder.add("If-None-Match")), cfKvMetadata(builder.add("CF-KV-Metadata")), cfR2ErrorHeader(builder.add("CF-R2-Error")), cfBlobMetadataSize(builder.add("CF-R2-Metadata-Size")), diff --git a/src/workerd/io/io-thread-context.h b/src/workerd/io/io-thread-context.h index 3ab58e1ac6a..3217573efe9 100644 --- a/src/workerd/io/io-thread-context.h +++ b/src/workerd/io/io-thread-context.h @@ -18,7 +18,10 @@ class ThreadContext { const kj::HttpHeaderId cfCacheStatus; // used by cache API implementation const kj::HttpHeaderId cacheControl; const kj::HttpHeaderId pragma; - const kj::HttpHeaderId cfCacheNamespace; // used by Cache binding implementation + const kj::HttpHeaderId cfCacheNamespace; // used by Cache binding implementation + const kj::HttpHeaderId range; + const kj::HttpHeaderId ifModifiedSince; + const kj::HttpHeaderId ifNoneMatch; const kj::HttpHeaderId cfKvMetadata; // used by KV binding implementation const kj::HttpHeaderId cfR2ErrorHeader; // used by R2 binding implementation const kj::HttpHeaderId cfBlobMetadataSize; // used by R2 binding implementation