From 56f5fa1fbe57af80928ea8d14d4d79788be2a003 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Samy=20Pess=C3=A9?= Date: Sun, 29 Sep 2024 10:31:27 +0200 Subject: [PATCH] Lower usage of KV cache to 30% of tags (#2500) --- .changeset/light-pots-dress.md | 5 + packages/cache-do/src/CacheObject.ts | 183 ++++++++++-------- packages/cache-do/wrangler.toml | 11 ++ .../gitbook/src/lib/cache/cloudflare-kv.ts | 2 +- 4 files changed, 121 insertions(+), 80 deletions(-) create mode 100644 .changeset/light-pots-dress.md diff --git a/.changeset/light-pots-dress.md b/.changeset/light-pots-dress.md new file mode 100644 index 000000000..d08dbf16d --- /dev/null +++ b/.changeset/light-pots-dress.md @@ -0,0 +1,5 @@ +--- +'@gitbook/cache-do': patch +--- + +Enable Workers observability with a sampling of 0.1 diff --git a/packages/cache-do/src/CacheObject.ts b/packages/cache-do/src/CacheObject.ts index 9730839f5..8349aa7ec 100644 --- a/packages/cache-do/src/CacheObject.ts +++ b/packages/cache-do/src/CacheObject.ts @@ -53,16 +53,20 @@ export class CacheObject extends DurableObject { * Get the value of a property. */ public async get(key: string) { - return timeFn(`get: ${key}`, async () => { + return this.logOperation({ operation: 'get', key }, async (setLog) => { // Try the memory state first. const memoryEntry = this.lru.get(key); if (memoryEntry) { - console.log(`get: (memory, ${!!memoryEntry.match}) ${key}`); + setLog({ memory: true }); + setLog({ memoryMatch: !!memoryEntry.match }); if (!memoryEntry.match) { return; } - if (memoryEntry.match.expiresAt > Date.now()) { + const isExpired = memoryEntry.match.expiresAt < Date.now(); + setLog({ memoryExpired: isExpired }); + + if (!isExpired) { return memoryEntry.match.value as Value; } } @@ -75,28 +79,31 @@ export class CacheObject extends DurableObject { * Get the value of a property from the DO storage. */ public async getFromStorage(key: string) { - const entries = await this.ctx.storage.list({ - prefix: getStoragePropKey(key), - noCache: true, - }); - if (entries.size) { - const entry = decodeChunks>(entries); - if (entry && entry.expiresAt > Date.now()) { - // Found - this.lru.set(key, { match: entry }); - return entry.value; + return this.logOperation({ operation: 'getFromStorage', key }, async (setLog) => { + const entries = await this.ctx.storage.list({ + prefix: getStoragePropKey(key), + noCache: true, + }); + if (entries.size) { + const entry = decodeChunks>(entries); + setLog({ chunks: entries.size, chunksSize: entry?.size ?? 0 }); + if (entry && entry.value.expiresAt > Date.now()) { + // Found + this.lru.set(key, { match: entry.value }); + return entry.value.value; + } } - } - // Not found - this.lru.set(key, { match: undefined }); + // Not found + this.lru.set(key, { match: undefined }); + }); } /** * Set a value in the cache object. */ public async set(key: string, value: Value, expiresAt: number) { - return timeFn(`set: ${key}`, async () => { + return this.logOperation({ operation: 'set', key }, async (setLog) => { const prop: CacheObjectProp = { value, expiresAt, @@ -105,10 +112,12 @@ export class CacheObject extends DurableObject { this.lru.set(key, { match: prop }); await this.ctx.storage.transaction(async (tx) => { const entries = encodeChunks(key, prop); + const chunks = Object.keys(entries).length; + setLog({ chunks }); const clockValue: CacheObjectExp = { k: key, - c: Object.keys(entries).length, + c: chunks, }; await tx.put(getGCClockKey(key, expiresAt), clockValue); @@ -127,76 +136,101 @@ export class CacheObject extends DurableObject { * Purge all keys in the cache object. */ public async purge() { - let result = new Set(); + return this.logOperation({ operation: 'purge' }, async (setLog) => { + let result = new Set(); - try { - // List all the keys in the cache object. - const entries = await this.ctx.storage.list({ - prefix: 'exp.', - noCache: true, - }); - console.log(`purge: ${entries.size} entries`); - entries.forEach((exp) => { - result.add(exp.k); - }); - } catch (error) { - // If an error occurs, reset the cache object. - // This is a safety mechanism to prevent the cache object from being stuck in a bad state. - console.error('Error during purge, resetting the cache object', error); - } + try { + // List all the keys in the cache object. + const entries = await this.ctx.storage.list({ + prefix: 'exp.', + noCache: true, + }); + setLog({ entries: entries.size }); + entries.forEach((exp) => { + result.add(exp.k); + }); + } catch (error) { + // If an error occurs, reset the cache object. + // This is a safety mechanism to prevent the cache object from being stuck in a bad state. + console.error('Error during purge, resetting the cache object', error); + } - await this.reset(); - - console.log(`purge returns`, Array.from(result)); - return Array.from(result); + await this.reset(); + return Array.from(result); + }); } /** * Alarm to garbage collect all entries that have expired. */ async alarm() { - try { - const entries = await this.ctx.storage.list({ - prefix: 'exp.', - noCache: true, - }); - const toDeleteSet = new Set(); + return this.logOperation({ operation: 'alarm' }, async (setLog) => { + try { + const entries = await this.ctx.storage.list({ + prefix: 'exp.', + noCache: true, + }); + setLog({ entries: entries.size }); + const toDeleteSet = new Set(); - for (const [key, exp] of entries) { - const timestamp = parseInt(key.split('.')[1]); - if (timestamp < Date.now()) { - toDeleteSet.add(key); - for (let i = 0; i < exp.c; i++) { - toDeleteSet.add(getStoragePropChunkKey(exp.k, i)); + for (const [key, exp] of entries) { + const timestamp = parseInt(key.split('.')[1]); + if (timestamp < Date.now()) { + toDeleteSet.add(key); + for (let i = 0; i < exp.c; i++) { + toDeleteSet.add(getStoragePropChunkKey(exp.k, i)); + } } } - } - // Delete the keys by batch of 128. - const toDelete = Array.from(toDeleteSet); - for (let i = 0; i < toDelete.length; i += 128) { - await this.ctx.storage.delete(toDelete.slice(i, i + 128)); - } + // Delete the keys by batch of 128. + const toDelete = Array.from(toDeleteSet); + setLog({ toDelete: toDelete.length }); + for (let i = 0; i < toDelete.length; i += 128) { + await this.ctx.storage.delete(toDelete.slice(i, i + 128)); + } - // If there are still keys to delete, set an alarm to continue the deletion in 12h. - if (toDelete.length) { - await this.ctx.storage.setAlarm(Date.now() + 12 * 60 * 60 * 1000); + // If there are still keys to delete, set an alarm to continue the deletion in 12h. + if (toDelete.length) { + await this.ctx.storage.setAlarm(Date.now() + 12 * 60 * 60 * 1000); + } + } catch (error) { + // If an error occurs, reset the cache object. + // This is a safety mechanism to prevent the cache object from being stuck in a bad state. + console.error('Error during alarm, reset the cache object', error); + await this.reset(); } - } catch (error) { - // If an error occurs, reset the cache object. - // This is a safety mechanism to prevent the cache object from being stuck in a bad state. - console.error('Error during alarm, reset the cache object', error); - await this.reset(); - } + }); } /** * Reset the cache object. */ async reset() { - console.log('reset: clear all entries'); - this.lru.clear(); - await this.ctx.storage.deleteAll(); + return this.logOperation({ operation: 'reset' }, async () => { + this.lru.clear(); + await this.ctx.storage.deleteAll(); + }); + } + + /** + * Time and log an operation. + */ + async logOperation( + log: Record, + fn: (update: (log: Record) => void) => Promise, + ): Promise { + const objectId = this.ctx.id.name ?? this.ctx.id.toString(); + let update: Record = {}; + const start = performance.now(); + try { + return await fn((arg) => { + Object.assign(update, arg); + }); + } finally { + const duration = performance.now() - start; + console.log({ ...log, ...update, objectId, duration }); + } } } @@ -228,7 +262,7 @@ function encodeChunks(key: string, value: T): Record { return entries; } -function decodeChunks(entries: Map): T | undefined { +function decodeChunks(entries: Map): { value: T; size: number } | undefined { const chunks = Array.from(entries.entries()) .map(([key, value]) => { const index = parseInt(key.split('.').pop()!); @@ -242,7 +276,7 @@ function decodeChunks(entries: Map): T | undefined { } const buf = mergeUint8Array(chunks); - return decode(buf) as T; + return { value: decode(buf) as T, size: buf.length }; } function chunkUint8Array(input: Uint8Array, chunkSize: number): Uint8Array[] { @@ -263,12 +297,3 @@ function mergeUint8Array(chunks: Uint8Array[]): Uint8Array { } return result; } - -async function timeFn(message: string, fn: () => Promise): Promise { - const start = performance.now(); - try { - return await fn(); - } finally { - console.log(`${message} (${performance.now() - start}ms)`); - } -} diff --git a/packages/cache-do/wrangler.toml b/packages/cache-do/wrangler.toml index cf9eae37a..bf0a716d5 100644 --- a/packages/cache-do/wrangler.toml +++ b/packages/cache-do/wrangler.toml @@ -10,8 +10,19 @@ migrations = [ {tag = "v1", new_classes = ["CacheObject"]} ] +[observability] +enabled = true +head_sampling_rate = 0.01 + [env.preview] name = "gitbook-open-cache-preview" durable_objects.bindings = [ {name = "CACHE", class_name = "CacheObject"} ] +migrations = [ + {tag = "v1", new_classes = ["CacheObject"]} +] + +[env.preview.observability] +enabled = true +head_sampling_rate = 1 diff --git a/packages/gitbook/src/lib/cache/cloudflare-kv.ts b/packages/gitbook/src/lib/cache/cloudflare-kv.ts index b32767f32..c4aa270ad 100644 --- a/packages/gitbook/src/lib/cache/cloudflare-kv.ts +++ b/packages/gitbook/src/lib/cache/cloudflare-kv.ts @@ -32,7 +32,7 @@ function shouldUseKVForTag(tag: string): boolean { const hash = tag.split('').reduce((acc, char) => { return acc + char.charCodeAt(0); }, 0); - if (hash % 100 <= 60) { + if (hash % 100 <= 30) { return true; }