ory / integrations

Apache License 2.0
19 stars 24 forks source link

Next.js middleware breaks api request #34

Closed AliYusuf95 closed 2 years ago

AliYusuf95 commented 2 years ago

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 next@12.1.0. However after next@12.1.1 it seems the changes introduce in the middleware logic, specifically this PR https://github.com/vercel/next.js/pull/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 next@12.1.1 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/x@v0.0.392/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/x@v0.0.392/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/x@v0.0.392/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/httprouter@v1.3.0/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/nosurf@v1.2.7/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/nosurf@v1.2.7/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/negroni@v1.0.0/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/negroni@v1.0.0/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/negroni@v1.0.0/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/negroni@v1.0.0/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/negroni@v1.0.0/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/client_golang@v1.11.0/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/client_golang@v1.11.0/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/client_golang@v1.11.0/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/client_golang@v1.11.0/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/client_golang@v1.11.0/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/x@v0.0.392/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/x@v0.0.392/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/negroni@v1.0.0/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/x@v0.0.392/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/negroni@v1.0.0/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/x@v0.0.392/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 commented 2 years ago

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 commented 2 years ago

@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 commented 2 years ago

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

AliYusuf95 commented 2 years ago

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

aeneasr commented 2 years ago

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

AliYusuf95 commented 2 years ago

@aeneasr the change is in peerDependencies

aeneasr commented 2 years ago

🤦

aeneasr commented 2 years ago

I can reproduce this now :)

aeneasr commented 2 years ago

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 commented 2 years ago

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

AliYusuf95 commented 2 years ago

The issue has fixed by https://github.com/vercel/next.js/pull/37806, and available in next@v12.1.7-canary.50

aeneasr commented 2 years ago

Great job!!