Skip to content

Commit e38caf7

Browse files
conico974Nicolas Dorseuil
conico974
and
Nicolas Dorseuil
authored
Implement consistent logging across the application (#3368)
Co-authored-by: Nicolas Dorseuil <[email protected]>
1 parent 0a8dd67 commit e38caf7

File tree

15 files changed

+254
-258
lines changed

15 files changed

+254
-258
lines changed

‎packages/gitbook/openNext/customWorkers/defaultWrangler.jsonc

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -16,7 +16,8 @@
1616
"env": {
1717
"dev": {
1818
"vars": {
19-
"STAGE": "dev"
19+
"STAGE": "dev",
20+
"OPEN_NEXT_REQUEST_ID_HEADER": "true"
2021
},
2122
"r2_buckets": [
2223
{
@@ -84,6 +85,9 @@
8485
}
8586
},
8687
"staging": {
88+
"vars": {
89+
"OPEN_NEXT_REQUEST_ID_HEADER": "true"
90+
},
8791
"r2_buckets": [
8892
{
8993
"binding": "NEXT_INC_CACHE_R2_BUCKET",
@@ -125,7 +129,8 @@
125129
"vars": {
126130
// This is a bit misleading, but it means that we can have 500 concurrent revalidations
127131
// This means that we'll have up to 100 durable objects instance running at the same time
128-
"MAX_REVALIDATE_CONCURRENCY": "100"
132+
"MAX_REVALIDATE_CONCURRENCY": "100",
133+
"OPEN_NEXT_REQUEST_ID_HEADER": "true"
129134
},
130135
"r2_buckets": [
131136
{

‎packages/gitbook/openNext/customWorkers/middlewareWrangler.jsonc

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -21,7 +21,8 @@
2121
"dev": {
2222
"vars": {
2323
"STAGE": "dev",
24-
"NEXT_PRIVATE_DEBUG_CACHE": "true"
24+
"NEXT_PRIVATE_DEBUG_CACHE": "true",
25+
"OPEN_NEXT_REQUEST_ID_HEADER": "true"
2526
},
2627
"r2_buckets": [
2728
{
@@ -85,7 +86,8 @@
8586
"staging": {
8687
"vars": {
8788
"STAGE": "staging",
88-
"WORKER_VERSION_ID": "TO_REPLACE"
89+
"WORKER_VERSION_ID": "TO_REPLACE",
90+
"OPEN_NEXT_REQUEST_ID_HEADER": "true"
8991
},
9092
"routes": [
9193
{
@@ -153,7 +155,8 @@
153155
// TODO: remove this once the issue is fixed
154156
"DEBUG_CLOUDFLARE": "true",
155157
"WORKER_VERSION_ID": "TO_REPLACE",
156-
"STAGE": "production"
158+
"STAGE": "production",
159+
"OPEN_NEXT_REQUEST_ID_HEADER": "true"
157160
},
158161
"routes": [
159162
{

‎packages/gitbook/openNext/incrementalCache.ts

Lines changed: 73 additions & 100 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,4 @@
11
import { createHash } from 'node:crypto';
2-
3-
import { trace } from '@/lib/tracing';
42
import type {
53
CacheEntryType,
64
CacheValue,
@@ -34,41 +32,31 @@ class GitbookIncrementalCache implements IncrementalCache {
3432
cacheType?: CacheType
3533
): Promise<WithLastModified<CacheValue<CacheType>> | null> {
3634
const cacheKey = this.getR2Key(key, cacheType);
37-
return trace(
38-
{
39-
operation: 'openNextIncrementalCacheGet',
40-
name: cacheKey,
41-
},
42-
async (span) => {
43-
span.setAttribute('cacheType', cacheType ?? 'cache');
44-
const r2 = getCloudflareContext().env[BINDING_NAME];
45-
const localCache = await this.getCacheInstance();
46-
if (!r2) throw new Error('No R2 bucket');
47-
try {
48-
// Check local cache first if available
49-
const localCacheEntry = await localCache.match(this.getCacheUrlKey(cacheKey));
50-
if (localCacheEntry) {
51-
span.setAttribute('cacheHit', 'local');
52-
const result = (await localCacheEntry.json()) as WithLastModified<
53-
CacheValue<CacheType>
54-
>;
55-
return this.returnNullOn404(result);
56-
}
5735

58-
const r2Object = await r2.get(cacheKey);
59-
if (!r2Object) return null;
60-
61-
span.setAttribute('cacheHit', 'r2');
62-
return this.returnNullOn404({
63-
value: await r2Object.json(),
64-
lastModified: r2Object.uploaded.getTime(),
65-
});
66-
} catch (e) {
67-
console.error('Failed to get from cache', e);
68-
return null;
69-
}
36+
const r2 = getCloudflareContext().env[BINDING_NAME];
37+
const localCache = await this.getCacheInstance();
38+
if (!r2) throw new Error('No R2 bucket');
39+
try {
40+
// Check local cache first if available
41+
const localCacheEntry = await localCache.match(this.getCacheUrlKey(cacheKey));
42+
if (localCacheEntry) {
43+
const result = (await localCacheEntry.json()) as WithLastModified<
44+
CacheValue<CacheType>
45+
>;
46+
return this.returnNullOn404(result);
7047
}
71-
);
48+
49+
const r2Object = await r2.get(cacheKey);
50+
if (!r2Object) return null;
51+
52+
return this.returnNullOn404({
53+
value: await r2Object.json(),
54+
lastModified: r2Object.uploaded.getTime(),
55+
});
56+
} catch (e) {
57+
console.error('Failed to get from cache', e);
58+
return null;
59+
}
7260
}
7361

7462
//TODO: This is a workaround to handle 404 responses in the cache.
@@ -89,75 +77,60 @@ class GitbookIncrementalCache implements IncrementalCache {
8977
cacheType?: CacheType
9078
): Promise<void> {
9179
const cacheKey = this.getR2Key(key, cacheType);
92-
return trace(
93-
{
94-
operation: 'openNextIncrementalCacheSet',
95-
name: cacheKey,
96-
},
97-
async (span) => {
98-
span.setAttribute('cacheType', cacheType ?? 'cache');
99-
const localCache = await this.getCacheInstance();
100-
101-
try {
102-
await this.writeToR2(cacheKey, JSON.stringify(value));
103-
104-
//TODO: Check if there is any places where we don't have tags
105-
// Ideally we should always have tags, but in case we don't, we need to decide how to handle it
106-
// For now we default to a build ID tag, which allow us to invalidate the cache in case something is wrong in this deployment
107-
const tags = this.getTagsFromCacheEntry(value) ?? [
108-
`build_id/${process.env.NEXT_BUILD_ID}`,
109-
];
110-
111-
// We consider R2 as the source of truth, so we update the local cache
112-
// only after a successful R2 write
113-
await localCache.put(
114-
this.getCacheUrlKey(cacheKey),
115-
new Response(
116-
JSON.stringify({
117-
value,
118-
// Note: `Date.now()` returns the time of the last IO rather than the actual time.
119-
// See https://developers.cloudflare.com/workers/reference/security-model/
120-
lastModified: Date.now(),
121-
}),
122-
{
123-
headers: {
124-
// Cache-Control default to 30 minutes, will be overridden by `revalidate`
125-
// In theory we should always get the `revalidate` value
126-
'cache-control': `max-age=${value.revalidate ?? 60 * 30}`,
127-
'cache-tag': tags.join(','),
128-
},
129-
}
130-
)
131-
);
132-
} catch (e) {
133-
console.error('Failed to set to cache', e);
134-
}
135-
}
136-
);
80+
81+
const localCache = await this.getCacheInstance();
82+
83+
try {
84+
await this.writeToR2(cacheKey, JSON.stringify(value));
85+
86+
//TODO: Check if there is any places where we don't have tags
87+
// Ideally we should always have tags, but in case we don't, we need to decide how to handle it
88+
// For now we default to a build ID tag, which allow us to invalidate the cache in case something is wrong in this deployment
89+
const tags = this.getTagsFromCacheEntry(value) ?? [
90+
`build_id/${process.env.NEXT_BUILD_ID}`,
91+
];
92+
93+
// We consider R2 as the source of truth, so we update the local cache
94+
// only after a successful R2 write
95+
await localCache.put(
96+
this.getCacheUrlKey(cacheKey),
97+
new Response(
98+
JSON.stringify({
99+
value,
100+
// Note: `Date.now()` returns the time of the last IO rather than the actual time.
101+
// See https://developers.cloudflare.com/workers/reference/security-model/
102+
lastModified: Date.now(),
103+
}),
104+
{
105+
headers: {
106+
// Cache-Control default to 30 minutes, will be overridden by `revalidate`
107+
// In theory we should always get the `revalidate` value
108+
'cache-control': `max-age=${value.revalidate ?? 60 * 30}`,
109+
'cache-tag': tags.join(','),
110+
},
111+
}
112+
)
113+
);
114+
} catch (e) {
115+
console.error('Failed to set to cache', e);
116+
}
137117
}
138118

139119
async delete(key: string): Promise<void> {
140120
const cacheKey = this.getR2Key(key);
141-
return trace(
142-
{
143-
operation: 'openNextIncrementalCacheDelete',
144-
name: cacheKey,
145-
},
146-
async () => {
147-
const r2 = getCloudflareContext().env[BINDING_NAME];
148-
const localCache = await this.getCacheInstance();
149-
if (!r2) throw new Error('No R2 bucket');
150-
151-
try {
152-
await r2.delete(cacheKey);
153-
154-
// Here again R2 is the source of truth, so we delete from local cache first
155-
await localCache.delete(this.getCacheUrlKey(cacheKey));
156-
} catch (e) {
157-
console.error('Failed to delete from cache', e);
158-
}
159-
}
160-
);
121+
122+
const r2 = getCloudflareContext().env[BINDING_NAME];
123+
const localCache = await this.getCacheInstance();
124+
if (!r2) throw new Error('No R2 bucket');
125+
126+
try {
127+
await r2.delete(cacheKey);
128+
129+
// Here again R2 is the source of truth, so we delete from local cache first
130+
await localCache.delete(this.getCacheUrlKey(cacheKey));
131+
} catch (e) {
132+
console.error('Failed to delete from cache', e);
133+
}
161134
}
162135

163136
async writeToR2(key: string, value: string): Promise<void> {

‎packages/gitbook/openNext/queue/middleware.ts

Lines changed: 2 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1,14 +1,11 @@
1-
import { trace } from '@/lib/tracing';
21
import type { Queue } from '@opennextjs/aws/types/overrides.js';
32
import { getCloudflareContext } from '@opennextjs/cloudflare';
43
import doQueue from '@opennextjs/cloudflare/overrides/queue/do-queue';
54

65
export default {
76
name: 'GitbookISRQueue',
87
send: async (msg) => {
9-
return trace({ operation: 'gitbookISRQueueSend', name: msg.MessageBody.url }, async () => {
10-
const { ctx } = getCloudflareContext();
11-
ctx.waitUntil(doQueue.send(msg));
12-
});
8+
const { ctx } = getCloudflareContext();
9+
ctx.waitUntil(doQueue.send(msg));
1310
},
1411
} satisfies Queue;

‎packages/gitbook/openNext/queue/server.ts

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,11 @@
1+
import { getLogger } from '@/lib/logger';
12
import type { Queue } from '@opennextjs/aws/types/overrides.js';
23

34
export default {
45
name: 'GitbookISRQueue',
56
send: async (msg) => {
7+
const logger = getLogger().subLogger('GitbookISRQueue');
68
// We should never reach this point in the server. If that's the case, we should log it.
7-
console.warn('GitbookISRQueue: send called on server side, this should not happen.', msg);
9+
logger.warn('send called on server side, this should not happen.', msg);
810
},
911
} satisfies Queue;

‎packages/gitbook/openNext/tagCache/middleware.ts

Lines changed: 13 additions & 45 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
import { trace } from '@/lib/tracing';
1+
import { getLogger } from '@/lib/logger';
22
import type { NextModeTagCache } from '@opennextjs/aws/types/overrides.js';
33
import doShardedTagCache from '@opennextjs/cloudflare/overrides/tag-cache/do-sharded-tag-cache';
44
import { softTagFilter } from '@opennextjs/cloudflare/overrides/tag-cache/tag-cache-filter';
@@ -23,59 +23,27 @@ export default {
2323
getLastRevalidated: async (tags: string[]) => {
2424
const tagsToCheck = tags.filter(softTagFilter);
2525
if (tagsToCheck.length === 0) {
26-
// If we reach here, it probably means that there is an issue that we'll need to address.
27-
console.warn(
28-
'getLastRevalidated - No valid tags to check for last revalidation, original tags:',
29-
tags
30-
);
3126
return 0; // If no tags to check, return 0
3227
}
33-
return trace(
34-
{
35-
operation: 'gitbookTagCacheGetLastRevalidated',
36-
name: tagsToCheck.join(', '),
37-
},
38-
async () => {
39-
return await originalTagCache.getLastRevalidated(tagsToCheck);
40-
}
41-
);
28+
29+
return await originalTagCache.getLastRevalidated(tagsToCheck);
4230
},
4331
hasBeenRevalidated: async (tags: string[], lastModified?: number) => {
4432
const tagsToCheck = tags.filter(softTagFilter);
4533
if (tagsToCheck.length === 0) {
46-
// If we reach here, it probably means that there is an issue that we'll need to address.
47-
console.warn(
48-
'hasBeenRevalidated - No valid tags to check for revalidation, original tags:',
49-
tags
50-
);
5134
return false; // If no tags to check, return false
5235
}
53-
return trace(
54-
{
55-
operation: 'gitbookTagCacheHasBeenRevalidated',
56-
name: tagsToCheck.join(', '),
57-
},
58-
async () => {
59-
const result = await originalTagCache.hasBeenRevalidated(tagsToCheck, lastModified);
60-
return result;
61-
}
62-
);
36+
37+
return await originalTagCache.hasBeenRevalidated(tagsToCheck, lastModified);
6338
},
6439
writeTags: async (tags: string[]) => {
65-
return trace(
66-
{
67-
operation: 'gitbookTagCacheWriteTags',
68-
name: tags.join(', '),
69-
},
70-
async () => {
71-
const tagsToWrite = tags.filter(softTagFilter);
72-
if (tagsToWrite.length === 0) {
73-
console.warn('writeTags - No valid tags to write');
74-
return; // If no tags to write, exit early
75-
}
76-
// Write only the filtered tags
77-
await originalTagCache.writeTags(tagsToWrite);
78-
}
79-
);
40+
const tagsToWrite = tags.filter(softTagFilter);
41+
if (tagsToWrite.length === 0) {
42+
const logger = getLogger().subLogger('gitbookTagCache');
43+
logger.warn('writeTags - No valid tags to write');
44+
return; // If no tags to write, exit early
45+
}
46+
// Write only the filtered tags
47+
await originalTagCache.writeTags(tagsToWrite);
8048
},
8149
} satisfies NextModeTagCache;

‎packages/gitbook/src/app/~gitbook/revalidate/route.ts

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
import { type NextRequest, NextResponse } from 'next/server';
22

3+
import { getLogger } from '@/lib/logger';
34
import { withVerifySignature } from '@/lib/routes';
45
import { revalidateTag } from 'next/cache';
56

@@ -12,6 +13,7 @@ interface JsonBody {
1213
* The body should be a JSON with { tags: string[] }
1314
*/
1415
export async function POST(req: NextRequest) {
16+
const logger = getLogger().subLogger('revalidate');
1517
return withVerifySignature<JsonBody>(req, async (body) => {
1618
if (!body.tags || !Array.isArray(body.tags)) {
1719
return NextResponse.json(
@@ -23,8 +25,7 @@ export async function POST(req: NextRequest) {
2325
}
2426

2527
body.tags.forEach((tag) => {
26-
// biome-ignore lint/suspicious/noConsole: we want to log here
27-
console.log(`Revalidating tag: ${tag}`);
28+
logger.log(`Revalidating tag: ${tag}`);
2829
revalidateTag(tag);
2930
});
3031

0 commit comments

Comments
 (0)