The CSRF value from the token does not match the CSRF value from the data store

[tangkhaiphuong]

I try to deploy v1.0.0-beta.5-alpine and test win consent from the source:
https://github.com/ory/hydra-login-consent-node

When login success and redirect, the error show:
The CSRF value from the token does not match the CSRF value from the data store

The log file:

Thank you for using ORY Hydra!
2018-07-12T07:15:06.728317500Z 
Take security seriously and subscribe to the ORY newsletter. Stay on top of new patches and security insights.                                                                                                
2018-07-12T07:15:06.728332000Z 
>> Subscribe now: http://eepurl.com/di390P <<    
time="2018-07-12T07:15:06Z" level=info msg="Connecting with postgres://*:*@ory-hydra-postgres:5432/hydra?sslmode=disable"
time="2018-07-12T07:15:06Z" level=info msg="Connected to SQL!"
time="2018-07-12T07:15:06Z" level=info msg="JSON Web Key Set hydra.openid.id-token does not exist yet, generating new key pair..."
time="2018-07-12T07:15:12Z" level=info msg="Setting up Prometheus middleware"
time="2018-07-12T07:15:12Z" level=info msg="Transmission of telemetry data is enabled, to learn more go to: https://www.ory.sh/docs/guides/latest/telemetry/"
time="2018-07-12T07:15:12Z" level=info msg="Detected local environment, skipping telemetry commit"
time="2018-07-12T07:15:12Z" level=info msg="Detected local environment, skipping telemetry commit"
time="2018-07-12T07:15:12Z" level=info msg="JSON Web Key Set hydra.https-tls does not exist yet, generating new key pair..."
time="2018-07-12T07:15:17Z" level=info msg="Setting up http server on :4444"
time="2018-07-12T07:15:19Z" level=info msg="started handling request" method=POST remote="172.18.0.4:33854" request=/clients
time="2018-07-12T07:15:19Z" level=info msg="completed handling request" measure#https://localhost:8080/.latency=85398200 method=POST remote="172.18.0.4:33854" request=/clients status=201 text_status=Created took=85.3982ms
time="2018-07-12T07:16:03Z" level=info msg="started handling request" method=GET remote="172.18.0.1:57848" request="/oauth2/auth?client_id=default-consumer&redirect_uri=http%3A%2F%2F127.0.0.1%3A9010%2Fcallback&response_type=code&scope=openid+offline+profile+email&state=shnarvluujhrgtwwtxuaptqt&nonce=vrvdzfxjuvfeobojxpdxjwyn&prompt=&max_age=0"
time="2018-07-12T07:16:03Z" level=info msg="completed handling request" measure#https://localhost:8080/.latency=12606200 method=GET remote="172.18.0.1:57848" request="/oauth2/auth?client_id=default-consumer&redirect_uri=http%3A%2F%2F127.0.0.1%3A9010%2Fcallback&response_type=code&scope=openid+offline+profile+email&state=shnarvluujhrgtwwtxuaptqt&nonce=vrvdzfxjuvfeobojxpdxjwyn&prompt=&max_age=0" status=302 text_status=Found took=12.6062ms
time="2018-07-12T07:16:03Z" level=info msg="started handling request" method=GET remote="172.18.0.1:57850" request=/oauth2/auth/requests/login/950d538cbe7443049609a96e44d3b6a5
time="2018-07-12T07:16:03Z" level=info msg="completed handling request" measure#https://localhost:8080/.latency=3562200 method=GET remote="172.18.0.1:57850" request=/oauth2/auth/requests/login/950d538cbe7443049609a96e44d3b6a5 status=200 text_status=OK took=3.5622ms
time="2018-07-12T07:16:16Z" level=info msg="started handling request" method=PUT remote="172.18.0.1:57852" request=/oauth2/auth/requests/login/950d538cbe7443049609a96e44d3b6a5/accept
time="2018-07-12T07:16:16Z" level=info msg="completed handling request" measure#https://localhost:8080/.latency=10174000 method=PUT remote="172.18.0.1:57852" request=/oauth2/auth/requests/login/950d538cbe7443049609a96e44d3b6a5/accept status=200 text_status=OK took=10.174ms
time="2018-07-12T07:16:22Z" level=info msg="started handling request" method=GET remote="172.18.0.1:57856" request="/oauth2/auth?client_id=default-consumer&login_verifier=214c25e1e0074b488c829cc796a2cdfe&max_age=0&nonce=vrvdzfxjuvfeobojxpdxjwyn&prompt=&redirect_uri=http%3A%2F%2F127.0.0.1%3A9010%2Fcallback&response_type=code&scope=openid+offline+profile+email&state=shnarvluujhrgtwwtxuaptqt"
time="2018-07-12T07:16:22Z" level=error msg="An error occurred" debug="The CSRF value from the token does not match the CSRF value from the data store" description="The request is not allowed" error=request_forbidden hint="You are not allowed to perform this action."
time="2018-07-12T07:16:22Z" level=debug msg="Stack trace: \ngithub.com/ory/hydra/consent.validateCsrfSession\n\t/go/src/github.com/ory/hydra/consent/helper.go:83\ngithub.com/ory/hydra/consent.(*DefaultStrategy).verifyAuthentication\n\t/go/src/github.com/ory/hydra/consent/strategy_default.go:276\ngithub.com/ory/hydra/consent.(*DefaultStrategy).HandleOAuth2AuthorizationRequest\n\t/go/src/github.com/ory/hydra/consent/strategy_default.go:507\ngithub.com/ory/hydra/oauth2.(*Handler).AuthHandler\n\t/go/src/github.com/ory/hydra/oauth2/handler.go:522\ngithub.com/ory/hydra/oauth2.(*Handler).AuthHandler-fm\n\t/go/src/github.com/ory/hydra/oauth2/handler.go:158\ngithub.com/ory/hydra/vendor/github.com/julienschmidt/httprouter.(*Router).ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/julienschmidt/httprouter/router.go:299\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.Wrap.func1\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:46\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.HandlerFunc.ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:29\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.(middleware).ServeHTTP-fm\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:38\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:1947\ngithub.com/ory/hydra/cmd/server.(*Handler).rejectInsecureRequests\n\t/go/src/github.com/ory/hydra/cmd/server/handler.go:181\ngithub.com/ory/hydra/cmd/server.(*Handler).(github.com/ory/hydra/cmd/server.rejectInsecureRequests)-fm\n\t/go/src/github.com/ory/hydra/cmd/server/handler.go:119\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.HandlerFunc.ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:29\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.(middleware).ServeHTTP-fm\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/hydra/vendor/github.com/ory/metrics-middleware.(*MetricsManager).ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/ory/metrics-middleware/middleware.go:160\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.(middleware).ServeHTTP-fm\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/hydra/metrics/prometheus.(*MetricsManager).ServeHTTP\n\t/go/src/github.com/ory/hydra/metrics/prometheus/middleware.go:26\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.(middleware).ServeHTTP-fm\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/hydra/vendor/github.com/meatballhat/negroni-logrus.(*Middleware).ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/meatballhat/negroni-logrus/middleware.go:136\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/hydra/vendor/github.com/urfave/negroni.(*Negroni).ServeHTTP\n\t/go/src/github.com/ory/hydra/vendor/github.com/urfave/negroni/negroni.go:96\ngithub.com/ory/hydra/vendor/github.com/rs/cors.(*Cors).Handler.func1\n\t/go/src/github.com/ory/hydra/vendor/github.com/rs/cors/cors.go:200\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:1947\ngithub.com/ory/hydra/vendor/github.com/gorilla/context.ClearHandler.func1\n\t/go/src/github.com/ory/hydra/vendor/github.com/gorilla/context/context.go:141\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:1947\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2694\nnet/http.initNPNRequest.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:3260\nnet/http.(*initNPNRequest).ServeHTTP\n\t<autogenerated>:1"
time="2018-07-12T07:16:22Z" level=info msg="completed handling request" measure#https://localhost:8080/.latency=8148000 method=GET remote="172.18.0.1:57856" request="/oauth2/auth?client_id=default-consumer&login_verifier=214c25e1e0074b488c829cc796a2cdfe&max_age=0&nonce=vrvdzfxjuvfeobojxpdxjwyn&prompt=&redirect_uri=http%3A%2F%2F127.0.0.1%3A9010%2Fcallback&response_type=code&scope=openid+offline+profile+email&state=shnarvluujhrgtwwtxuaptqt" status=302 text_status=Found took=8.148ms

What is the expected behavior?
It should pass and or if having the error, please log more detail

Which version of the software is affected?
v1.0.0-beta.5-alpine
v1.0.0-beta.6-alpine

[aeneasr]

If the CSRF value doesn't match, you might have started the oauth2 flow in two browsers or tabs, or something is wrong with the cookies.

If you're behind an API gateway or router, make sure the cookies make it through. Try to restart the flow and see if it works.

[tangkhaiphuong]

@arekkas I set up on my computer with docker installation, I close all browser, clear cache/cookie, the problem still occurs. I try another browser and issue doesn't go :(

There is minor log on Postgres I found:

PostgreSQL init process complete; ready for start up.
2018-07-12T07:14:55.854514700Z 
2018-07-12 07:14:55.860 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2018-07-12 07:14:55.861 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2018-07-12 07:14:55.872 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2018-07-12 07:14:55.904 UTC [45] LOG:  database system was shut down at 2018-07-12 07:14:55 UTC
2018-07-12 07:14:55.913 UTC [1] LOG:  database system is ready to accept connections
2018-07-12 09:13:16.574 UTC [53] ERROR:  duplicate key value violates unique constraint "hydra_oauth2_authentication_request_handled_pkey"
2018-07-12 09:13:16.574 UTC [53] DETAIL:  Key (challenge)=(525284388392497892f6a8256a9072d8) already exists.
2018-07-12 09:13:16.574 UTC [53] STATEMENT:  INSERT INTO hydra_oauth2_authentication_request_handled (challenge, subject, remember, remember_for, error, requested_at, authenticated_at, acr, was_used) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9)

[aeneasr]

Is hydra running behind a proxy (e.g. ngnix, kong, load balancer, ...)?

[tangkhaiphuong]

@arekkas I think the problem comes from Docker on Windows. I remove all containers (Postgress/Hydra). Restart docker and setup step by step again then it works.

[aeneasr]

Ok, that's weird, glad it works now.

[tech-sam]

@aeneasr I am getting same error

ERRO[2141] An error occurred  debug="The CSRF value from the token does not match the CSRF value from the data store" 
description="The request is not allowed" 
error=request_forbidden hint="You are not allowed to perform this action."

I have started the oauth2 flow in two tabs simultaneously , one flow successfully completed and one is failed .hydra is running in windows with binary not with docker and it is not behind any proxy server
version : 1.0.0-rc.5+oryOS.10

[aeneasr]

I have started the oauth2 flow in two tabs simultaneously

Hydra doesn't support two simoultaneous oauth2 auth code flows from the same browser.

[netrix]

Is there any way to work this around? I mean, when you try to login in second tab while being already logged in on the other tab (meaning that you have all the cookies from session and browser is sending them while trying to log in second time) it should just check whether cookies are still valid (might additionally check verify again if user is allowed with login and password since they're provided) and just redirect user to landing page (or where (s)he intended to go.

[aeneasr]

If you're initiating 2 OAuth2 Flows in separate browser tabs, then you will end up with 2 states, implying that at least on flow won't work, which is equal to how the CSRF value behaves.

[karelbilek]

We worked around that by sending messages between the multiple tabs in localstorage - when one tab is newer, disable the old tab in javascript and do something like "click here to log in again", which starts new oauth flow.

[esunea]

Hello,
I got the same issue, i was using a reverse proxy.
My self issuer url didn't matched the url i used for the first connection, hence the CSRF error.

try double checking the domain name everywhere you use it !