AntiForgery validation failed -- returning error page

[Maverik]

We've been developing with IdentityServer 2.0.0 series for a while now but I've recently updated nuget from 2.0.0-rc1 to rc2 & now rc3 and both of them are now rendering the message in title.

Could you please give any ideas on where should I look to fix this error? I have absolutely no detail available from log except for the above message and the fact that the log entry came from IdentityServer3.Core.Configuration.Hosting.ValidateAntiForgeryTokenAttribute.

We do have a nginx reverse proxy in front of the idServer if that matters.

Thanks in advance!

[loctanvo]

Have you tried incognito mode or clearing idserver-cookies? And were you already using nginx when things did work properly?

[Maverik]

Indeed, it's not a client side thing. Incognito makes no difference. Nginx was already operational and still is (with 2.0.0-rc1). I haven't been able to figure what updated to trigger this new error. As amazing a work as you guys do on the software itself, I wish a 10th went into some raw documentation too.. if nothing else just commit notes concatenated together to let us know what's changing.

Though in this particular case, I've read through commit log and still can't figure what I'd need to do to fix this. Another detail that may be relevant: We've used CustomVIewService sample to create a customized login page (mainly logo change & some js input validation). My original thought was that may have caused it to break, but even commenting it out makes no difference. Everything else is vanilla otherwise.

[loctanvo]

Hmm. Assuming everything is working as intended; an antiforgery validation error is caused by mismatch between the antiforgery value submitted in the form and the antiforgery cookie value. If you are doing some custom view service things, just double check that the antiforgery token is rendered in the view and submitted back in the post action.

[Maverik]

No that's what I thought as well. The token comes through in the custom view service (and of course that's how it's working in rc1), but I have the antiforgery issue even on DefaultViewService.

[jageall]

is the javascript getting loaded? iirc, the antiforgery token is added into
the form as a hidden field from the model.

On 3 August 2015 at 11:59, Maverik notifications@github.com wrote:

No that's what I thought as well. The token comes through in the custom
view service (and of course that's how it's working in rc1), but I have the
antiforgery issue even on DefaultViewService.

—
Reply to this email directly or view it on GitHub
#1672 (comment)
.

[Maverik]

Yes because our input validation is JS based and that's working fine. We've also confirmed that anti-forgery-token is present inside the form. Real head-scratcher here >.< Thanks for the ideas so far!

[loctanvo]

Just some loud thinking here. Seems like you already have done some extended research, but I think I'd look into:

1. Does the post action back to IdServer contain the antiforgery token (hidden field)? What is the name of the field posted back?
2. Does the post request contain the antiforgery token cookie? What is the name of the cookie?

IIRC, the antiforgery token cookie is protected with the default Owin data protector. If, for some reason, the server does not manage to unprotect the cookie, it'll also treat the scenario as an antiforgery validation failed. In a load balanced environment, unless you take control of configuring the servers to use the same protectors (eg. common machine key), mismatch may happen.

[Maverik]

The decryption idea is exactly what I was thinking as well. I'm not directly dealing with this right now, my fellow developer is. I'll ask him to see if i can get me dumps. Alternatively is there any sort of logging I can use to dump request in its raw form before IdentityServer has a chance to process it (thus confirming that the token is indeed reaching identityserver's pipeline).

As for research: Yes i've been at this for a day and I didn't want to create a ticket for something that's already been solved. My first attempt to solve this was to use the solution from the previous issue that happened on IIS using a mod. Unfortunately, I don't have the proxy headers issue (there's no protection in place right now. we've stripped things down to as minimum as we can to zero-in on this)

[SAAirey]

We are using the latest pre-release version (currently 2.0.0-build00174) and I have put together a paste of all the raw requests/responses here.

[brockallen]

So the browser is showing the anti-forgery error in the browser title tab, despite the HTML <title> containing your text?

[SAAirey]

The specific anti-forgery error never appears in the browser, we got that from our logs. I can't remember the exact wording of the error that is rendered in the browser but I will get that for you first thing in the morning.

[loctanvo]

Hmm, looking at the last raw request, the antiforgery tokens clearly are different:

FORM:
idsrv.xsrf=AQAAANCMnd8BFdERjHoAwE_Cl-sBAAAAoCbF28ZxN0Wn8prpiztQJAAAAAACAAAAAAADZgAAwAAAABAAAACDfgaB6DT_MFRMdcn-RIZvAAAAAASAAACgAAAAEAAAANG6_1-o0n7Wt1VjyHIq3ZgYAAAAfGgtuMc5ctODzwpTAg5gKcSYKCqjdbbwFAAAAEFLJn7i_BjANnapTTzFxmBqvOvN

COOKIE:
idsrv.xsrf=AQAAANCMnd8BFdERjHoAwE_Cl-sBAAAAoCbF28ZxN0Wn8prpiztQJAAAAAACAAAAAAADZgAAwAAAABAAAADHSEW9JVdL-dEJ3g_IYKrFAAAAAASAAACgAAAAEAAAAM5KlBG86DPKZGyjinWhLz8YAAAAbjOHgL9sNL4InJxxvXVCY_4xeiCWmNPPFAAAAOtzJpUKJ9sBEiSHXtY4R-fjsB4a

Not sure whether one can compare the raw values like that (IIRC, the token is protected and base64 encoded), but if one can, there clearly is a mismatch. Well, that doesn't help you much, but you can try to look into whether the antiforgery token is generated several times within the same request, or cookie is set on wrong request or something similar.

[snothub]

I have the same issue after upgrade

[brockallen]

Any updates or more info so I can help track this down?

[Maverik]

Other than the fact that we've simply updated nuget version to run into this problem: no sorry nothing concrete yet. My fellow developer (@SAAirey) is going to try and reproduce it in a sample project and perhaps we can track it down from there. But so far I'm afraid update is all the trigger we have for this problem (and we can fix the problem with a simple version revert)

[brockallen]

And so it always happens for every POST?

[Maverik]

Yes. We can see the login page, but from that moment on, it never gets past the forgery issue. As soon as you enter credentials, we're presented with There was an unexpected error page.

The log indicates the following sequence of events:

Timestamp (Desc)	Action
12 Aug 2015 20:25:35.193	AntiForgery validation failed -- returning error page
12 Aug 2015 20:25:29.901	rendering login page
12 Aug 2015 20:25:29.900	Login page requested
12 Aug 2015 20:25:29.872	Redirecting to login page
12 Aug 2015 20:25:29.872	End authorize request
12 Aug 2015 20:25:29.872	User is not authenticated. Redirecting to login.

[Maverik]

Exactly same process with rc1 instead gives successful result with this log sequence (some of the log events are our own service events but I've included them regardless - this just a portion of log events - I've also raised verbosity of log in this one)

Timestamp (Desc)	Action
12 Aug 2015 20:34:31.760	Login credentials successfully validated by user service
12 Aug 2015 20:34:31.758	"3" claims returned from store
12 Aug 2015 20:34:31.595	Requesting claims for the "xxx"
12 Aug 2015 20:34:31.595	Returning new LdapConnection for "xxx" "xxx" and "xxx"
12 Aug 2015 20:34:31.592	Store connection successfully bound
12 Aug 2015 20:34:31.505	Returning new LdapConnection for "xxx" "xxx" and "xxx"
12 Aug 2015 20:34:31.255	Login page submitted
12 Aug 2015 20:34:28.447	rendering login page
12 Aug 2015 20:34:28.399	Login page requested
12 Aug 2015 20:34:28.302	Redirecting to login page
12 Aug 2015 20:34:28.296	End authorize request
12 Aug 2015 20:34:28.288	User is not authenticated. Redirecting to login.

[brockallen]

Can you do a HTTP level trace to ensure the headers are making it to the server? Also, you can enable verbose HTTP logging in IdSvr so you can see it all in the logs.

[Maverik]

Http trace level? as in fiddler level trace or some logging option that I should enable?

Currently running with these options and the failed log is exactly as one above (just tested against 2.0.0 stable as well):

    LoggingOptions = new LoggingOptions
    {
        EnableHttpLogging = true,
        EnableWebApiDiagnostics = true,
        WebApiDiagnosticsIsVerbose = true,
    },

    EventsOptions = new EventsOptions
    {
        RaiseErrorEvents = true,
        RaiseFailureEvents = true,
        RaiseInformationEvents = true,
        RaiseSuccessEvents = true,
    },

[Maverik]

Here's the fiddler trace (with specific requests/responses that have the cookie involved):

GET https://idserver.host/login?signin=6aea00a31435f73d8f9ed33e7cb7c385 HTTP/1.1
Host: idserver.host
Connection: keep-alive
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.130 Safari/537.36
DNT: 1
Referer: https://clientapp.host/
Accept-Encoding: gzip, deflate, sdch
Accept-Language: en-GB
Cookie: SignInMessage.6aea00a31435f73d8f9ed33e7cb7c385=AQAAANCMnd8BFdERjHoAwE_Cl-sBAAAA2cA84Ke9oEmcBhRXabvK9AAAAAACAAAAAAAQZgAAAAEAACAAAACbua10AybYqnEEdaX4_wsZqou9bCmgF5TiYOMoOLLZmwAAAAAOgAAAAAIAACAAAACMrITS3hfljH--1xlLSWD1EnQnNn8cjnZPsSSq7vAwyoABAABzr15U-TufoARTyTLhTZtINlXfl31XrwWfTgCWKQB-g6iCVlX-IfqTvSwF2TuLB4PerODGB4c2fdsj0FfCPp8sXZNbY-N9dfxUdHaRXqJcO0Q1uQ5t2taA2ocgQbsB33UbG3gVUxJsJV1Ipwp1CRy2VpDgOudFa2IO347greUUv7sZNE-7V1L2UqS1t2H6DCHX6fIGhyTMg07NeH_dy5kB9x6Vb7ehR7rknJZ2MEf4VqZDTXDqPvxgytSVi0gkfh1ivv7IA4WL9Ct3sFDWTOyxqDqsNnYY_zChOPdkdSDRFq5TaKRFHj1OqAMuh-rh6Rrkn6JTggr63BpXISl3gLiawFsihG1tL4Miu8zTyU2YY-kLvh_e8zHn1cTh3qMiusIkb92KjP0r19aKLK8Qj41HOH93bXFRoegxEdwd3onAMa37cSDNWGU9cDvFbJS2uK8W5N4keUIeZQ81cDSRvMG74o4OLnU-xWpyxulJIXy7S1u7BX_8_LqYb69Qjr1brAFAAAAA3ZRREv1H3Tw2SpD5rO7gmod7PpA9pve_7M6n_1EZMaFNCRTOnmp63BZilF1WfZQEjCJfc0Zg_y88P-XvQDxxlw


HTTP/1.1 200 OK
Server: nginx
Date: Wed, 12 Aug 2015 19:59:01 GMT
Content-Type: text/html; charset=utf-8
Connection: keep-alive
Vary: Accept-Encoding
Cache-Control: no-store, no-cache, max-age=0, private
Pragma: no-cache
Set-Cookie: idsrv.xsrf=AQAAANCMnd8BFdERjHoAwE_Cl-sBAAAA2cA84Ke9oEmcBhRXabvK9AAAAAACAAAAAAAQZgAAAAEAACAAAAAQr-Bj7QowYP9iEBbcKO2C481ZZ1mkD37pyWXaBrU3kwAAAAAOgAAAAAIAACAAAAA6huzYA4Z008CJ8Z66QY3WVkvwmCONsL207X-QtMROLyAAAABsLiKuW_2BUD1mcE3YL7PFs585z_bVLOfvze4Nw73BGkAAAAAW32xuBD0fRCe6Nz3CXMH2cbHPpMK39uZt9y7_bjRJdiidPhKHT-rSqJnq05TEqtPRj8qvooItsdfO_rPxMRNO; path=/; secure; HttpOnly
X-Content-Type-Options: nosniff
X-Frame-Options: SAMEORIGIN
Content-Security-Policy: default-src 'self'; script-src 'self' https://localhost:44333 https://idserver.host 'unsafe-inline' 'unsafe-eval'; style-src 'self' 'unsafe-inline' https://localhost:44333 https://idserver.host https://fonts.googleapis.com; img-src *;font-src https://localhost:44333 https://idserver.host https://fonts.gstatic.com; report-uri https://idserver.host/csp/report
X-UA-Compatible: IE=Edge
Alternate-Protocol: 443:npn-spdy/3
Strict-Transport-Security: max-age=31536000;
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Content-Length: 5465



------------------------------------------------------------------
POST https://idserver.host/login?signin=6aea00a31435f73d8f9ed33e7cb7c385 HTTP/1.1
Host: idserver.host
Connection: keep-alive
Content-Length: 398
Cache-Control: max-age=0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Origin: https://idserver.host
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.130 Safari/537.36
Content-Type: application/x-www-form-urlencoded
DNT: 1
Referer: https://idserver.host/login?signin=6aea00a31435f73d8f9ed33e7cb7c385
Accept-Encoding: gzip, deflate
Accept-Language: en-GB
Cookie: SignInMessage.6aea00a31435f73d8f9ed33e7cb7c385=AQAAANCMnd8BFdERjHoAwE_Cl-sBAAAA2cA84Ke9oEmcBhRXabvK9AAAAAACAAAAAAAQZgAAAAEAACAAAACbua10AybYqnEEdaX4_wsZqou9bCmgF5TiYOMoOLLZmwAAAAAOgAAAAAIAACAAAACMrITS3hfljH--1xlLSWD1EnQnNn8cjnZPsSSq7vAwyoABAABzr15U-TufoARTyTLhTZtINlXfl31XrwWfTgCWKQB-g6iCVlX-IfqTvSwF2TuLB4PerODGB4c2fdsj0FfCPp8sXZNbY-N9dfxUdHaRXqJcO0Q1uQ5t2taA2ocgQbsB33UbG3gVUxJsJV1Ipwp1CRy2VpDgOudFa2IO347greUUv7sZNE-7V1L2UqS1t2H6DCHX6fIGhyTMg07NeH_dy5kB9x6Vb7ehR7rknJZ2MEf4VqZDTXDqPvxgytSVi0gkfh1ivv7IA4WL9Ct3sFDWTOyxqDqsNnYY_zChOPdkdSDRFq5TaKRFHj1OqAMuh-rh6Rrkn6JTggr63BpXISl3gLiawFsihG1tL4Miu8zTyU2YY-kLvh_e8zHn1cTh3qMiusIkb92KjP0r19aKLK8Qj41HOH93bXFRoegxEdwd3onAMa37cSDNWGU9cDvFbJS2uK8W5N4keUIeZQ81cDSRvMG74o4OLnU-xWpyxulJIXy7S1u7BX_8_LqYb69Qjr1brAFAAAAA3ZRREv1H3Tw2SpD5rO7gmod7PpA9pve_7M6n_1EZMaFNCRTOnmp63BZilF1WfZQEjCJfc0Zg_y88P-XvQDxxlw; idsrv.xsrf=AQAAANCMnd8BFdERjHoAwE_Cl-sBAAAA2cA84Ke9oEmcBhRXabvK9AAAAAACAAAAAAAQZgAAAAEAACAAAAAQr-Bj7QowYP9iEBbcKO2C481ZZ1mkD37pyWXaBrU3kwAAAAAOgAAAAAIAACAAAAA6huzYA4Z008CJ8Z66QY3WVkvwmCONsL207X-QtMROLyAAAABsLiKuW_2BUD1mcE3YL7PFs585z_bVLOfvze4Nw73BGkAAAAAW32xuBD0fRCe6Nz3CXMH2cbHPpMK39uZt9y7_bjRJdiidPhKHT-rSqJnq05TEqtPRj8qvooItsdfO_rPxMRNO

idsrv.xsrf=AQAAANCMnd8BFdERjHoAwE_Cl-sBAAAA2cA84Ke9oEmcBhRXabvK9AAAAAACAAAAAAAQZgAAAAEAACAAAADV5u15WetXz27kJyItwQ3l04jSS0iH7ZxQTBKCTS00UQAAAAAOgAAAAAIAACAAAAD0ajJQi3BXCEBAdt4XQXNw1hRujVzv1grW7788qL5gkiAAAAAkWSXgk4vmupt9wFmHVtN3pQ8jGuVyEEv5w9DLRwEl_UAAAABimyhMDPg_CCBD2QbYSic2khDXn3cYVSvjGNKOYCMb2pIfj8auDtTYEoJanHAo1TzvsQ98Ybzd3jjiaB05Lboy&username=xxx&password=xxx


HTTP/1.1 200 OK
Server: nginx
Date: Wed, 12 Aug 2015 19:59:07 GMT
Content-Type: text/html; charset=utf-8
Connection: keep-alive
Vary: Accept-Encoding
X-UA-Compatible: IE=Edge
Alternate-Protocol: 443:npn-spdy/3
Strict-Transport-Security: max-age=31536000;
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Content-Length: 2125



------------------------------------------------------------------

[Maverik]

I can see that the xsrf value is changing, but like I said, the only change between this working and not working is nuget version changing (anything past rc1 doesn't work for us) and nothing else. So I'm at a loss to explain how is it happening.

Also I'm afraid it's pretty late over here and I have to close office. I'll catch your responses back when I'm back in office tomorrow and join gitter so you can ping me in there whenever you come online.

[brockallen]

So it seems that you have a proxy... i wonder if it makes sense to test without the proxy and see if you still have the issue -- that will help us rule that out or not.

[snothub]

I don't have a proxy and experience the same issue after upgrade on my dev machine.

[SAAirey]

I still have this issue running and accessing IdentityServer on localhost on my dev machine.

[brockallen]

I'm having a hard time diagnosing this issue, so at this point I'd suggest getting the code and debugging into it.

[snothub]

Debugging, I end up at AntiForgeryToken.cs#L129 where form object evaluates to nothing where idsrv.xsrf should be, along with username and password.

EDIT: seems like the above scenario is valid when HttpLogging is enabled and code enters RequestResponseLogger where request.GetOwinContext().Request.ReadBodyAsStringAsync() is called and consumes the contents of the request. I've verified this by testing on the Selfhost (Minimal) in the Samples project with same outcome.

[Maverik]

Brilliant work @snothub!

I can confirm that by turning logging off, everything is working fine again! Not the ideal way to have things, but at least it gets us moving and we know what needs fixing :)

[brockallen]

Ok, this issue came up recently and I thought we got it sorted out. I'll try to repro and investigate further.

[brockallen]

Ok, confirmed that it's just the EnableHttpLogging that triggers this.

[brockallen]

I just made some changes to the http logging and pushed it to myget as build 2.0.1-build00176. Mind testing it for me?

[Maverik]

Thanks @brockallen! Just tested and I can confirm that 2.0.1-build00176 has fixed the problem.

[brockallen]

Just as a heads up, this will most likely get released as a patch this week.