Next.js middleware breaks api request

[AliYusuf95]

I'm trying to implement Self-Service login flow. I checked the repo mentioned in the documentation page (kratos-selfservice-ui-react-nextjs).

The project works fine until [email protected]. However after [email protected] it seems the changes introduce in the middleware logic, specifically this PR vercel/next.js#34519 breaks the integration with ory kratos. Where transforming the request body to web stream and convert it back to nodejs stream somehow breaks proxying requests of nexjs integration, which leads to send all requests as GET requests to kratos.

The request was malformed or contained invalid parameters reason:Unable to decode body because HTTP Request Method was "GET" but only [POST PUT PATCH] are supported

To reproduce the issue use kratos-selfservice-ui-react-nextjs and upgrade next to [email protected] or latest and add a basic middleware:

//pages/_middleware.ts
import {NextRequest, NextResponse} from 'next/server';

export default (req: NextRequest) => {
    return NextResponse.next();
}

From the browser network I can see the login POST request http://localhost:3000/api/.ory/self-service/login?flow={id} is responded with redirect (303) to http://localhost:3000/login?flow={id}

And this is the log from kratos instance:

time=2022-06-12T14:01:57Z level=info msg=started handling request func=github.com/ory/x/reqlog.(*Middleware).ServeHTTP file=/go/pkg/mod/github.com/ory/[email protected]/reqlog/middleware.go:131 http_request=map[headers:map[accept-encoding:gzip, deflate connection:close] host:localhost:4433 method:GET path:/self-service/login query:flow=40013f4d-bd56-4769-8d58-30598972762c remote:172.18.0.1:60604 scheme:http]
2022-06-12T14:01:57.086820106Z time=2022-06-12T14:01:57Z level=info msg=Encountered self-service login error. func=github.com/ory/kratos/selfservice/flow/login.(*ErrorHandler).WriteFlowError file=/project/selfservice/flow/login/error.go:78 audience=audit error=map[debug: message:The request was malformed or contained invalid parameters reason:Unable to decode body because HTTP Request Method was "GET" but only [POST PUT PATCH] are supported. stack_trace:
2022-06-12T14:01:57.086955040Z github.com/ory/x/decoderx.(*HTTP).validateRequest
2022-06-12T14:01:57.086984233Z 	/go/pkg/mod/github.com/ory/[email protected]/decoderx/http.go:228
2022-06-12T14:01:57.087011332Z github.com/ory/x/decoderx.(*HTTP).Decode
2022-06-12T14:01:57.087039059Z 	/go/pkg/mod/github.com/ory/[email protected]/decoderx/http.go:271
2022-06-12T14:01:57.087064830Z github.com/ory/kratos/selfservice/strategy/webauthn.(*Strategy).Login
2022-06-12T14:01:57.087091789Z 	/project/selfservice/strategy/webauthn/login.go:198
2022-06-12T14:01:57.087120424Z github.com/ory/kratos/selfservice/flow/login.(*Handler).submitFlow
2022-06-12T14:01:57.087137535Z 	/project/selfservice/flow/login/handler.go:592
2022-06-12T14:01:57.087154157Z github.com/ory/kratos/x.NoCacheHandle.func1
2022-06-12T14:01:57.087199764Z 	/project/x/nocache.go:18
2022-06-12T14:01:57.087238246Z github.com/ory/kratos/x.NoCacheHandle.func1
2022-06-12T14:01:57.087263599Z 	/project/x/nocache.go:18
2022-06-12T14:01:57.087307040Z github.com/julienschmidt/httprouter.(*Router).ServeHTTP
2022-06-12T14:01:57.087339237Z 	/go/pkg/mod/github.com/julienschmidt/[email protected]/router.go:387
2022-06-12T14:01:57.087371224Z github.com/ory/nosurf.(*CSRFHandler).handleSuccess
2022-06-12T14:01:57.087401395Z 	/go/pkg/mod/github.com/ory/[email protected]/handler.go:234
2022-06-12T14:01:57.087427586Z github.com/ory/nosurf.(*CSRFHandler).ServeHTTP
2022-06-12T14:01:57.087469910Z 	/go/pkg/mod/github.com/ory/[email protected]/handler.go:185
2022-06-12T14:01:57.087501897Z github.com/urfave/negroni.Wrap.func1
2022-06-12T14:01:57.087537097Z 	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:46
2022-06-12T14:01:57.087663929Z github.com/urfave/negroni.HandlerFunc.ServeHTTP
2022-06-12T14:01:57.087752976Z 	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:29
2022-06-12T14:01:57.087788735Z github.com/urfave/negroni.middleware.ServeHTTP
2022-06-12T14:01:57.087841465Z 	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38
2022-06-12T14:01:57.087902995Z github.com/ory/kratos/x.glob..func1
2022-06-12T14:01:57.087985618Z 	/project/x/clean_url.go:12
2022-06-12T14:01:57.088030246Z github.com/urfave/negroni.HandlerFunc.ServeHTTP
2022-06-12T14:01:57.088060557Z 	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:29
2022-06-12T14:01:57.088085491Z github.com/urfave/negroni.middleware.ServeHTTP
2022-06-12T14:01:57.088124253Z 	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38
2022-06-12T14:01:57.088178100Z net/http.HandlerFunc.ServeHTTP
2022-06-12T14:01:57.088206456Z 	/usr/local/go/src/net/http/server.go:2047
2022-06-12T14:01:57.088228316Z github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerResponseSize.func1
2022-06-12T14:01:57.088259815Z 	/go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:198
2022-06-12T14:01:57.088284957Z net/http.HandlerFunc.ServeHTTP
2022-06-12T14:01:57.088306189Z 	/usr/local/go/src/net/http/server.go:2047
2022-06-12T14:01:57.088330564Z github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerCounter.func1
2022-06-12T14:01:57.088366323Z 	/go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:101
2022-06-12T14:01:57.088409205Z net/http.HandlerFunc.ServeHTTP
2022-06-12T14:01:57.088435675Z 	/usr/local/go/src/net/http/server.go:2047
2022-06-12T14:01:57.088461935Z github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerDuration.func1
2022-06-12T14:01:57.088476323Z 	/go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:68
2022-06-12T14:01:57.088526748Z net/http.HandlerFunc.ServeHTTP
2022-06-12T14:01:57.088554684Z 	/usr/local/go/src/net/http/server.go:2047
2022-06-12T14:01:57.088573751Z github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerDuration.func2
2022-06-12T14:01:57.088602037Z 	/go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:76
2022-06-12T14:01:57.088624526Z net/http.HandlerFunc.ServeHTTP
2022-06-12T14:01:57.088657072Z 	/usr/local/go/src/net/http/server.go:2047
2022-06-12T14:01:57.088681656Z github.com/prometheus/client_golang/prometheus/promhttp.InstrumentHandlerRequestSize.func1
2022-06-12T14:01:57.088710361Z 	/go/pkg/mod/github.com/prometheus/[email protected]/prometheus/promhttp/instrument_server.go:165
2022-06-12T14:01:57.088869389Z net/http.HandlerFunc.ServeHTTP
2022-06-12T14:01:57.088906964Z 	/usr/local/go/src/net/http/server.go:2047
2022-06-12T14:01:57.088930221Z github.com/ory/x/prometheusx.Metrics.instrumentHandlerStatusBucket.func1
2022-06-12T14:01:57.088957738Z 	/go/pkg/mod/github.com/ory/[email protected]/prometheusx/metrics.go:108
2022-06-12T14:01:57.088986513Z net/http.HandlerFunc.ServeHTTP
2022-06-12T14:01:57.089015986Z 	/usr/local/go/src/net/http/server.go:2047
2022-06-12T14:01:57.089041758Z github.com/ory/x/prometheusx.(*MetricsManager).ServeHTTP
2022-06-12T14:01:57.089064875Z 	/go/pkg/mod/github.com/ory/[email protected]/prometheusx/middleware.go:30
2022-06-12T14:01:57.089116627Z github.com/urfave/negroni.middleware.ServeHTTP
2022-06-12T14:01:57.089135275Z 	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38
2022-06-12T14:01:57.089159091Z github.com/ory/x/metricsx.(*Service).ServeHTTP
2022-06-12T14:01:57.089179834Z 	/go/pkg/mod/github.com/ory/[email protected]/metricsx/middleware.go:275
2022-06-12T14:01:57.089193313Z github.com/urfave/negroni.middleware.ServeHTTP
2022-06-12T14:01:57.089240316Z 	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38 status:Bad Request status_code:400] http_request=map[headers:map[accept-encoding:gzip, deflate connection:close] host:localhost:4433 method:GET path:/self-service/login query:flow=40013f4d-bd56-4769-8d58-30598972762c remote:172.18.0.1:60604 scheme:http] login_flow=&{40013f4d-bd56-4769-8d58-30598972762c 1ea7c4c7-0aea-4341-b96d-29685ee01608 browser 2022-06-12 14:11:55.119654028 +0000 UTC 2022-06-12 14:01:55.119654028 +0000 UTC [123 125] http://localhost:4433/self-service/login/browser?refresh=false   0xc000a61b30 2022-06-12 14:01:55.128828 +0000 UTC 2022-06-12 14:01:55.128828 +0000 UTC iA302rcrVp4ruSXCbhVHnd79ucSev0mrw0YOBoXeG2wElpkgrxDAB1UvyeZCXBH1H3yFWKDV+WxlpZ9lEM1xOA== false aal1} service_name=Ory Kratos service_version=v0.10.1
2022-06-12T14:01:57.100084711Z time=2022-06-12T14:01:57Z level=info msg=completed handling request func=github.com/ory/x/reqlog.(*Middleware).ServeHTTP file=/go/pkg/mod/github.com/ory/[email protected]/reqlog/middleware.go:139 http_request=map[headers:map[accept-encoding:gzip, deflate connection:close] host:localhost:4433 method:GET path:/self-service/login query:flow=40013f4d-bd56-4769-8d58-30598972762c remote:172.18.0.1:60604 scheme:http] http_response=map[headers:map[cache-control:private, no-cache, no-store, must-revalidate content-type:text/html; charset=utf-8 location:http://localhost:3000/login?flow=40013f4d-bd56-4769-8d58-30598972762c vary:Origin] size:101 status:303 text_status:See Other took:17.525062ms]

[aeneasr]

Thank you so much for the report! If you have any ideas how to fix that easily for NextJS >= 12.1.1 we'd be very thankful :)

[AliYusuf95]

@aeneasr I don't have much experience in streams, and since next request implementation can be changed at any time, I think it's better to send a new request instead of stream it.

[aeneasr]

@AliYusuf95 I can not reproduce the issue you're describing. I have upgraded NextJS ( ory/kratos-selfservice-ui-react-nextjs#35 ) and added a middleware ( ory/kratos-selfservice-ui-react-nextjs#36 ) but could not reproduce the described issue. Can you double check?

[AliYusuf95]

@aeneasr I think you need to update next in the dependencies to take the effect.

[aeneasr]

I did: https://github.com/ory/kratos-selfservice-ui-react-nextjs/pull/35/files#diff-7ae45ad102eab3b6d7e7896acd08c427a9b25b346470d7bc6507b6481575d519R35

[AliYusuf95]

@aeneasr the change is in peerDependencies

[aeneasr]

🤦

[aeneasr]

I can reproduce this now :)

[aeneasr]

I looked into it but am not really sure what's broken. I did see that they had other issues with the middleware and API handling in general. The problem probably is that they're now automatically reading the body in the middleware and are not respecting the bodyParser: false instruction. I think that leads to the request having a "spoiled" body buffer which then breaks the request piping. But I'm not sure how to fix that, maybe it has to be reported at NextJS as a bug / regression, because I think it actually is a regression in NextJS. Would you be down to open such an issue?

[AliYusuf95]

@aeneasr Sure, I think I identified the reason that cause the issue .. I'll open an issue in NextJS to fix it

[AliYusuf95]

The issue has fixed by vercel/next.js#37806, and available in [email protected]

[aeneasr]

Great job!!