Skip to content

fix: ensure background work is finished when response has 3xx or 5xx status code #2742

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 3 commits into from
Jan 22, 2025
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
39 changes: 18 additions & 21 deletions src/run/handlers/server.ts
Original file line number Diff line number Diff line change
Expand Up @@ -113,34 +113,31 @@ export default async (request: Request) => {
setVaryHeaders(response.headers, request, nextConfig)
setCacheStatusHeader(response.headers)

// Temporary workaround for an issue where sending a response with an empty
// body causes an unhandled error. This doesn't catch everything, but redirects are the
// most common case of sending empty bodies. We can't check it directly because these are streams.
// The side effect is that responses which do contain data will not be streamed to the client,
// but that's fine for redirects.
// TODO: Remove once a fix has been rolled out.
if ((response.status > 300 && response.status < 400) || response.status >= 500) {
const body = await response.text()
return new Response(body || null, response)
async function waitForBackgroundWork() {
// it's important to keep the stream open until the next handler has finished
await nextHandlerPromise

// Next.js relies on `close` event emitted by response to trigger running callback variant of `next/after`
// however @fastly/http-compute-js never actually emits that event - so we have to emit it ourselves,
// otherwise Next would never run the callback variant of `next/after`
res.emit('close')

// We have to keep response stream open until tracked background promises that are don't use `context.waitUntil`
// are resolved. If `context.waitUntil` is available, `requestContext.backgroundWorkPromise` will be empty
// resolved promised and so awaiting it is no-op
await requestContext.backgroundWorkPromise
}

const keepOpenUntilNextFullyRendered = new TransformStream({
async flush() {
// it's important to keep the stream open until the next handler has finished
await nextHandlerPromise

// Next.js relies on `close` event emitted by response to trigger running callback variant of `next/after`
// however @fastly/http-compute-js never actually emits that event - so we have to emit it ourselves,
// otherwise Next would never run the callback variant of `next/after`
res.emit('close')

// We have to keep response stream open until tracked background promises that are don't use `context.waitUntil`
// are resolved. If `context.waitUntil` is available, `requestContext.backgroundWorkPromise` will be empty
// resolved promised and so awaiting it is no-op
await requestContext.backgroundWorkPromise
await waitForBackgroundWork()
},
})

if (!response.body) {
await waitForBackgroundWork()
}

return new Response(response.body?.pipeThrough(keepOpenUntilNextFullyRendered), response)
})
}
39 changes: 39 additions & 0 deletions tests/e2e/page-router.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -494,6 +494,45 @@ test.describe('Simple Page Router (no basePath, no i18n)', () => {
'.env.production.local': 'defined in .env.production.local',
})
})

test('ISR pages that are the same after regeneration execute background getStaticProps uninterrupted', async ({
page,
pageRouter,
}) => {
const slug = Date.now()

await page.goto(new URL(`always-the-same-body/${slug}`, pageRouter.url).href)

await new Promise((resolve) => setTimeout(resolve, 15_000))

await page.goto(new URL(`always-the-same-body/${slug}`, pageRouter.url).href)

await new Promise((resolve) => setTimeout(resolve, 15_000))

await page.goto(new URL(`always-the-same-body/${slug}`, pageRouter.url).href)

await new Promise((resolve) => setTimeout(resolve, 15_000))

// keep lambda executing to allow for background getStaticProps to finish in case background work execution was suspended
await fetch(new URL(`api/sleep-5`, pageRouter.url).href)
Comment on lines +504 to +517
Copy link
Contributor Author

@pieh pieh Jan 16, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's a bit unclear to me why I need to make 3 requests, but this whole thing result in following logs that I've added to getStaticProps function that is being tested with those routes (+ some commentary I added to hopefully explain the logs):

# first request - this will always be very first request for this path, because it's
# not prerendered - this has `fallback: 'blocking'` so very first request is
# expected to execute `getStaticProps` in foreground and not background
Jan 16, 09:10:57 PM: 4f18552f INFO   [timestamp] 1737058256930 getStaticProps start
Jan 16, 09:10:57 PM: 4f18552f INFO   [timestamp] 1737058256930 getStaticProps start stored
Jan 16, 09:11:02 PM: 4f18552f INFO   [timestamp] 1737058256930 getStaticProps end (duration: 5s)
Jan 16, 09:11:02 PM: 4f18552f INFO   [timestamp] 1737058256930 getStaticProps end stored
Jan 16, 09:11:02 PM: 4f18552f Duration: 5136.12 ms	Memory Usage: 177 MB
# second request 15s after first one finished - this should generate exactly
# same thing - however response is 200 not 304 🤷 
Jan 16, 09:11:17 PM: 21a21fc8 INFO   [timestamp] 1737058256930 getStaticProps start
Jan 16, 09:11:18 PM: 21a21fc8 INFO   [timestamp] 1737058256930 getStaticProps start stored
Jan 16, 09:11:22 PM: 21a21fc8 INFO   [timestamp] 1737058256930 getStaticProps end (duration: 5s)
Jan 16, 09:11:23 PM: 21a21fc8 INFO   [timestamp] 1737058256930 getStaticProps end stored
Jan 16, 09:11:23 PM: 21a21fc8 Duration: 5119.96 ms	Memory Usage: 177 MB
# third request 15s after second one finished (but only 10 seconds after
# getStaticProps triggered by second request finished - that's because
# it was executing in background) - we can see that we DO start executing
# getStaticProps - but it doesn't finish before lambda execution finishes/suspends
# this one is 304 response (which is currently problematic one)
Jan 16, 09:11:33 PM: 13effc77 INFO   [timestamp] 1737058256930 getStaticProps start
Jan 16, 09:11:33 PM: 13effc77 Duration: 63.11 ms	Memory Usage: 177 MB
# now we were just sleeping for 15 seconds and after we are hitting
# an api endpoint that is being handled by same next.js server handler
# which allows to resume previously suspended execution - you can also
# see it has same execution context as previous request (13effc77) despite
# lambda execution seemingly was finished (log line with Duration and
# Memory Usage signifies end of execution) - you can see that now
# logged duration inside getStaticProps says 15s instead of expected ~5s 
Jan 16, 09:11:48 PM: 13effc77 INFO   [timestamp] 1737058256930 getStaticProps end (duration: 15.722s)
Jan 16, 09:11:48 PM: 13effc77 INFO   [timestamp] 1737058256930 getStaticProps start stored
Jan 16, 09:11:48 PM: 4974d6c2 INFO   [timestamp] 1737058256930 getStaticProps end stored
Jan 16, 09:11:53 PM: 4974d6c2 Duration: 5009.36 ms	Memory Usage: 177 MB


const response = await fetch(new URL(`read-static-props-blobs/${slug}`, pageRouter.url).href)
expect(response.ok, 'response for stored data status should not fail').toBe(true)

const data = await response.json()

expect(typeof data.start, 'timestamp of getStaticProps start should be a number').toEqual(
'number',
)
expect(typeof data.end, 'timestamp of getStaticProps end should be a number').toEqual('number')

// duration should be around 5s overall, due to 5s timeout, but this is not exact so let's be generous and allow 10 seconds
// which is still less than 15 seconds between requests
expect(
data.end - data.start,
'getStaticProps duration should not be longer than 10 seconds',
).toBeLessThan(10_000)
})
})

test.describe('Page Router with basePath and i18n', () => {
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
import { getDeployStore } from '@netlify/blobs'
import { Context } from '@netlify/functions'

function numberOrNull(value: string | null) {
if (!value) {
return null
}

const maybeNumber = parseInt(value)
return isNaN(maybeNumber) ? null : maybeNumber
}

// intentionally using Netlify Function to not hit Next.js server handler function instance
// to avoid potentially resuming suspended execution
export default async function handler(_request: Request, context: Context) {
const slug = context.params['slug']

const store = getDeployStore({ name: 'get-static-props-tracker', consistency: 'strong' })

const [start, end] = await Promise.all([store.get(`${slug}-start`), store.get(`${slug}-end`)])

return Response.json({ slug, start: numberOrNull(start), end: numberOrNull(end) })
}

export const config = {
path: '/read-static-props-blobs/:slug',
}
1 change: 1 addition & 0 deletions tests/fixtures/page-router/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
"build": "next build"
},
"dependencies": {
"@netlify/blobs": "^8.1.0",
"@netlify/functions": "^2.7.0",
"next": "latest",
"react": "18.2.0",
Expand Down
50 changes: 50 additions & 0 deletions tests/fixtures/page-router/pages/always-the-same-body/[slug].js
Original file line number Diff line number Diff line change
@@ -0,0 +1,50 @@
import { getDeployStore } from '@netlify/blobs'

const Show = ({ slug }) => {
// ensure that the content is stable to trigger 304 responses
return <pre>{slug}</pre>
}

/** @type {import('next').getStaticPaths} */
export async function getStaticPaths() {
return {
paths: [],
fallback: 'blocking',
}
}

/** @type {import('next').GetStaticProps} */
export async function getStaticProps({ params }) {
const store = getDeployStore({ name: 'get-static-props-tracker', consistency: 'strong' })

const start = Date.now()

console.log(`[timestamp] ${params.slug} getStaticProps start`)

const storeStartPromise = store.set(`${params.slug}-start`, start).then(() => {
console.log(`[timestamp] ${params.slug} getStaticProps start stored`)
})

// simulate a long running operation
await new Promise((resolve) => setTimeout(resolve, 5000))

const storeEndPromise = store.set(`${params.slug}-end`, Date.now()).then(() => {
console.log(`[timestamp] ${params.slug} getStaticProps end stored`)
})

console.log(
`[timestamp] ${params.slug} getStaticProps end (duration: ${(Date.now() - start) / 1000}s)`,
)

await Promise.all([storeStartPromise, storeEndPromise])

// ensure that the data is stable and always the same to trigger 304 responses
return {
props: {
slug: params.slug,
},
revalidate: 5,
}
}

export default Show
5 changes: 5 additions & 0 deletions tests/fixtures/page-router/pages/api/sleep-5.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
export default async function handler(req, res) {
await new Promise((resolve) => setTimeout(resolve, 5000))

res.json({ message: 'ok' })
}
Loading