add a "skip" cache type to verbose logging mode (#53275)
When verbose logging is enabled and a cache MISS is logged due to either `revalidate: 0`,`cache: no-store` or `cache-control: no-store`, this logs a slightly different message, ie: ``` - GET / 200 in 804ms ├─── GET <url> in 205ms (cache: SKIP, reason: cache: no-cache) ├────── GET <url> 200 in 0ms (cache: HIT) ├────── GET <url> 200 in 373ms (cache: SKIP, reason: revalidate: 0) └────── GET <url> 200 in 111ms (cache: SKIP, reason: cache-control: no-cache (hard refresh)) ``` Closes NEXT-1412
This commit is contained in:
Zack Tanner
GitHub
parent
16a5aa74d0
commit
afa9f96515
5 changed files with 120 additions and 23 deletions
|
|
@ -43,7 +43,8 @@ export interface StaticGenerationStore {
|
|||
start: number
|
||||
method: string
|
||||
status: number
|
||||
cacheStatus: 'hit' | 'miss'
|
||||
cacheReason: string
|
||||
cacheStatus: 'hit' | 'miss' | 'skip'
|
||||
}>
|
||||
|
||||
isDraftMode?: boolean
|
||||
|
|
|
|||
|
|
@ -33,7 +33,7 @@ function trackFetchMetric(
|
|||
status: number
|
||||
method: string
|
||||
cacheReason: string
|
||||
cacheStatus: 'hit' | 'miss'
|
||||
cacheStatus: 'hit' | 'miss' | 'skip'
|
||||
start: number
|
||||
}
|
||||
) {
|
||||
|
|
@ -56,6 +56,7 @@ function trackFetchMetric(
|
|||
staticGenerationStore.fetchMetrics.push({
|
||||
url: ctx.url,
|
||||
cacheStatus: ctx.cacheStatus,
|
||||
cacheReason: ctx.cacheReason,
|
||||
status: ctx.status,
|
||||
method: ctx.method,
|
||||
start: ctx.start,
|
||||
|
|
@ -176,6 +177,7 @@ export function patchFetch({
|
|||
staticGenerationStore.fetchCache === 'force-no-store'
|
||||
|
||||
let _cache = getRequestMeta('cache')
|
||||
let cacheReason = ''
|
||||
|
||||
if (
|
||||
typeof _cache === 'string' &&
|
||||
|
|
@ -192,12 +194,12 @@ export function patchFetch({
|
|||
}
|
||||
if (['no-cache', 'no-store'].includes(_cache || '')) {
|
||||
curRevalidate = 0
|
||||
cacheReason = `cache: ${_cache}`
|
||||
}
|
||||
if (typeof curRevalidate === 'number' || curRevalidate === false) {
|
||||
revalidate = curRevalidate
|
||||
}
|
||||
|
||||
let cacheReason = ''
|
||||
const _headers = getRequestMeta('headers')
|
||||
const initHeaders: Headers =
|
||||
typeof _headers?.get === 'function'
|
||||
|
|
@ -342,7 +344,10 @@ export function patchFetch({
|
|||
const normalizedRevalidate =
|
||||
typeof revalidate !== 'number' ? CACHE_ONE_YEAR : revalidate
|
||||
|
||||
const doOriginalFetch = async (isStale?: boolean) => {
|
||||
const doOriginalFetch = async (
|
||||
isStale?: boolean,
|
||||
cacheReasonOverride?: string
|
||||
) => {
|
||||
// add metadata to init without editing the original
|
||||
const clonedInit = {
|
||||
...init,
|
||||
|
|
@ -354,8 +359,9 @@ export function patchFetch({
|
|||
trackFetchMetric(staticGenerationStore, {
|
||||
start: fetchStart,
|
||||
url: fetchUrl,
|
||||
cacheReason,
|
||||
cacheStatus: 'miss',
|
||||
cacheReason: cacheReasonOverride || cacheReason,
|
||||
cacheStatus:
|
||||
revalidate === 0 || cacheReasonOverride ? 'skip' : 'miss',
|
||||
status: res.status,
|
||||
method: clonedInit.method || 'GET',
|
||||
})
|
||||
|
|
@ -403,6 +409,7 @@ export function patchFetch({
|
|||
}
|
||||
|
||||
let handleUnlock = () => Promise.resolve()
|
||||
let cacheReasonOverride
|
||||
|
||||
if (cacheKey && staticGenerationStore.incrementalCache) {
|
||||
handleUnlock = await staticGenerationStore.incrementalCache.lock(
|
||||
|
|
@ -421,6 +428,9 @@ export function patchFetch({
|
|||
|
||||
if (entry) {
|
||||
await handleUnlock()
|
||||
} else {
|
||||
// in dev, incremental cache response will be null in case the browser adds `cache-control: no-cache` in the request headers
|
||||
cacheReasonOverride = 'cache-control: no-cache (hard refresh)'
|
||||
}
|
||||
|
||||
if (entry?.value && entry.value.kind === 'FETCH') {
|
||||
|
|
@ -545,7 +555,7 @@ export function patchFetch({
|
|||
}
|
||||
}
|
||||
|
||||
return doOriginalFetch().finally(handleUnlock)
|
||||
return doOriginalFetch(false, cacheReasonOverride).finally(handleUnlock)
|
||||
}
|
||||
)
|
||||
}
|
||||
|
|
|
|||
|
|
@ -1125,11 +1125,14 @@ export default class NextNodeServer extends BaseServer {
|
|||
for (let i = 0; i < fetchMetrics.length; i++) {
|
||||
const metric = fetchMetrics[i]
|
||||
const lastItem = i === fetchMetrics.length - 1
|
||||
let cacheStatus = metric.cacheStatus
|
||||
let { cacheStatus, cacheReason } = metric
|
||||
|
||||
const duration = metric.end - metric.start
|
||||
|
||||
if (cacheStatus === 'hit') {
|
||||
cacheStatus = chalk.green('HIT')
|
||||
} else if (cacheStatus === 'skip') {
|
||||
cacheStatus = `${chalk.yellow('SKIP')}, reason: ${cacheReason}`
|
||||
} else {
|
||||
cacheStatus = chalk.yellow('MISS')
|
||||
}
|
||||
|
|
|
|||
|
|
@ -1,7 +1,30 @@
|
|||
import path from 'path'
|
||||
import { createNextDescribe, FileRef } from 'e2e-utils'
|
||||
import { createNextDescribe, FileRef } from '../../../lib/e2e-utils'
|
||||
import stripAnsi from 'strip-ansi'
|
||||
|
||||
function parseLogsFromCli(cliOutput: string) {
|
||||
return stripAnsi(cliOutput)
|
||||
.split('\n')
|
||||
.filter((log) => log.includes('cache:'))
|
||||
.map((log) => {
|
||||
const trimmedLog = log.replace(/^[^a-zA-Z]+/, '')
|
||||
const parts = trimmedLog.split(' ')
|
||||
const method = parts[0]
|
||||
const url = parts[1]
|
||||
const statusCode = parseInt(parts[2])
|
||||
const responseTime = parseInt(parts[4])
|
||||
const cache = parts.slice(5).join(' ')
|
||||
|
||||
return {
|
||||
method,
|
||||
url,
|
||||
statusCode,
|
||||
responseTime,
|
||||
cache,
|
||||
}
|
||||
})
|
||||
}
|
||||
|
||||
createNextDescribe(
|
||||
'app-dir - data fetching with cache logging',
|
||||
{
|
||||
|
|
@ -15,21 +38,65 @@ createNextDescribe(
|
|||
},
|
||||
},
|
||||
({ next, isNextDev }) => {
|
||||
function runTests({ isVerbose }: { isVerbose: boolean }) {
|
||||
it('should not log fetching hits in dev mode by default', async () => {
|
||||
describe('with verbose logging', () => {
|
||||
it('should only log requests in dev mode', async () => {
|
||||
await next.fetch('/default-cache')
|
||||
|
||||
const logs = stripAnsi(next.cliOutput)
|
||||
if (isVerbose && isNextDev) {
|
||||
|
||||
if (isNextDev) {
|
||||
expect(logs).toContain('GET /default-cache 200')
|
||||
} else {
|
||||
expect(logs).not.toContain('GET /default-cache 200')
|
||||
}
|
||||
})
|
||||
}
|
||||
|
||||
describe('with logging verbose', () => {
|
||||
runTests({ isVerbose: true })
|
||||
await next.stop()
|
||||
})
|
||||
|
||||
if (isNextDev) {
|
||||
it("should log 'skip' cache status with a reason when cache: 'no-cache' is used", async () => {
|
||||
await next.start()
|
||||
await next.fetch('/default-cache')
|
||||
const logs = parseLogsFromCli(next.cliOutput)
|
||||
const logEntry = logs.find((log) =>
|
||||
log.url.includes('api/random?no-cache')
|
||||
)
|
||||
|
||||
expect(logEntry?.cache).toMatchInlineSnapshot(
|
||||
`"(cache: SKIP, reason: cache: no-cache)"`
|
||||
)
|
||||
await next.stop()
|
||||
})
|
||||
|
||||
it("should log 'skip' cache status with a reason when revalidate: 0 is used", async () => {
|
||||
await next.start()
|
||||
await next.fetch('/default-cache')
|
||||
const logs = parseLogsFromCli(next.cliOutput)
|
||||
const logEntry = logs.find((log) =>
|
||||
log.url.includes('api/random?revalidate-0')
|
||||
)
|
||||
|
||||
expect(logEntry?.cache).toMatchInlineSnapshot(
|
||||
`"(cache: SKIP, reason: revalidate: 0)"`
|
||||
)
|
||||
await next.stop()
|
||||
})
|
||||
|
||||
it("should log 'skip' cache status with a reason when the browser indicates caching should be ignored", async () => {
|
||||
await next.start()
|
||||
await next.fetch('/default-cache', {
|
||||
headers: { 'Cache-Control': 'no-cache' },
|
||||
})
|
||||
const logs = parseLogsFromCli(next.cliOutput)
|
||||
const logEntry = logs.find((log) =>
|
||||
log.url.includes('api/random?auto-cache')
|
||||
)
|
||||
|
||||
expect(logEntry?.cache).toMatchInlineSnapshot(
|
||||
`"(cache: SKIP, reason: cache-control: no-cache (hard refresh))"`
|
||||
)
|
||||
await next.stop()
|
||||
})
|
||||
}
|
||||
})
|
||||
|
||||
describe('with default logging', () => {
|
||||
|
|
@ -38,7 +105,13 @@ createNextDescribe(
|
|||
await next.deleteFile('next.config.js')
|
||||
await next.start()
|
||||
})
|
||||
runTests({ isVerbose: false })
|
||||
|
||||
it('should not log fetch requests at all', async () => {
|
||||
await next.fetch('/default-cache')
|
||||
const logs = stripAnsi(next.cliOutput)
|
||||
|
||||
expect(logs).not.toContain('GET /default-cache 200')
|
||||
})
|
||||
})
|
||||
}
|
||||
)
|
||||
|
|
|
|||
|
|
@ -2,21 +2,30 @@ export const fetchCache = 'default-cache'
|
|||
|
||||
export default async function Page() {
|
||||
const dataNoCache = await fetch(
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?a1',
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?no-cache',
|
||||
{
|
||||
cache: 'no-cache',
|
||||
}
|
||||
).then((res) => res.text())
|
||||
|
||||
const dataForceCache = await fetch(
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?b2',
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?force-cache',
|
||||
{
|
||||
cache: 'force-cache',
|
||||
}
|
||||
).then((res) => res.text())
|
||||
|
||||
const dataRevalidate0 = await fetch(
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?revalidate-0',
|
||||
{
|
||||
next: {
|
||||
revalidate: 0,
|
||||
},
|
||||
}
|
||||
).then((res) => res.text())
|
||||
|
||||
const dataRevalidateCache = await fetch(
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?c3',
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?revalidate-3',
|
||||
{
|
||||
next: {
|
||||
revalidate: 3,
|
||||
|
|
@ -25,7 +34,7 @@ export default async function Page() {
|
|||
).then((res) => res.text())
|
||||
|
||||
const dataRevalidateAndFetchCache = await fetch(
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?d4',
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?revalidate-3-force-cache',
|
||||
{
|
||||
next: {
|
||||
revalidate: 3,
|
||||
|
|
@ -35,7 +44,7 @@ export default async function Page() {
|
|||
).then((res) => res.text())
|
||||
|
||||
const dataAutoCache = await fetch(
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?d4'
|
||||
'https://next-data-api-endpoint.vercel.app/api/random?auto-cache'
|
||||
).then((res) => res.text())
|
||||
|
||||
return (
|
||||
|
|
@ -43,6 +52,7 @@ export default async function Page() {
|
|||
<p>/force-cache</p>
|
||||
<p id="data-no-cache">"cache: no-cache" {dataNoCache}</p>
|
||||
<p id="data-force-cache">"cache: force-cache" {dataForceCache}</p>
|
||||
<p id="data-revalidate-0">"revalidate: 0" {dataRevalidate0}</p>
|
||||
<p id="data-revalidate-cache">"revalidate: 3" {dataRevalidateCache}</p>
|
||||
<p id="data-revalidate-and-fetch-cache">
|
||||
"revalidate: 3 and cache: force-cache" {dataRevalidateAndFetchCache}
|
||||
|
|
|
|||
Loading…
Reference in a new issue