vercel / next.js

The React Framework
https://nextjs.org
MIT License
126.38k stars 26.9k forks source link

`NextResponse.next()` returns incorrect response in middleware #31569

Closed samuela closed 2 years ago

samuela commented 2 years ago

What version of Next.js are you using?

next@12.0.2

What version of Node.js are you using?

v16.13.0

What browser are you using?

n/a

What operating system are you using?

macOS 12.0.1

How are you deploying your application?

Local development

Describe the Bug

I'm attempting to set up some logging middleware:

import { NextFetchEvent, NextRequest, NextResponse } from "next/server";
import * as pino from "pino";

// pino types seem to be incorrect
const logger = (pino as any)() as pino.P.Logger;

export function middleware(req: NextRequest, ev: NextFetchEvent) {
  logger.info({ req, ev }, `--> ${req.method} ${req.url}`);
  // process.hrtime is not available in the environment that these functions are run in
  const t0 = new Date();
  const res = NextResponse.next();
  const elapsedMs = new Date().getTime() - t0.getTime();
  logger.info(
    { res, elapsedMs },
    `<-- ${req.method} ${req.url} ${res.status} ${elapsedMs} ms`
  );
  return res;
}

Simple enough. It runs fine, but I realized something was off when no matter the request the logs were showing each request finishing in 0ms. Furthermore, even when the request fails and returns, say, a 400 status the res.status is reported as 200.

Why is NextResponse.next() not returning the correct response object?

Expected Behavior

NextResponse.next() to return the correct response as reported in the documentation.

To Reproduce

Set up a _middleware.ts file with:

import { NextFetchEvent, NextRequest, NextResponse } from "next/server";
import * as pino from "pino";

// pino types seem to be incorrect
const logger = (pino as any)() as pino.P.Logger;

export function middleware(req: NextRequest, ev: NextFetchEvent) {
  logger.info({ req, ev }, `--> ${req.method} ${req.url}`);
  // process.hrtime is not available in the environment that these functions are run in
  const t0 = new Date();
  const res = NextResponse.next();
  const elapsedMs = new Date().getTime() - t0.getTime();
  logger.info(
    { res, elapsedMs },
    `<-- ${req.method} ${req.url} ${res.status} ${elapsedMs} ms`
  );
  return res;
}

and an endpoint that sleeps for a second before returning some failure error code, eg. 400.

Hit up the endpoint and note that the logs are incorrect.

javivelasco commented 2 years ago

Hi! I've been looking into this issue and from what I see I understand that you were expecting Next.js middleware to work the same as an Express middleware were it gets called back once the handler is done so you can read the response before the request finishes. Middleware in Next.js doesn't work this way.

In Express the signature has (req, res, next) => void so the Response object middleware sees is the same as the one that the actual route handler will see. Therefore you can log the res.status being the one that the handler set. Like I said, this is not how Next.js middleware works.

In Next.js the middleware signature is (req, context) => Promise<Response> and as you can see there is no given response in the arguments. The response you use in middleware tells what should happen in terms of routing so you can do things like rewrite or redirect. This response is not reused by API routes and pages.

Therefore the example you described works as expected. The status code is always 200 because that's the status code that the response generated from NextResponse.next() holds and the time for the request is ~0 because that's the amount of time it takes to create the response object. Since it is all working as expected I'm going to close this issue. Thanks! 🙏

samuela commented 2 years ago

Hmm, I'm a bit confused... In Next.js, why is the middleware Response disconnected from the rest of the API routes/pages behavior? Why is it called Response in this case if it (AFAIU) it never makes it back to the HTTP client?

github-actions[bot] commented 2 years ago

This closed issue has been automatically locked because it had no new activity for a month. If you are running into a similar issue, please create a new issue with the steps to reproduce. Thank you.