Weird Timeouts with custom ASP.NET FormsAuthentication
Ah, life. For me, in what I tend to do day to day, it always seems to come down to debugging weird stuff. So, here's something weird that happened today (actually it's been happening over the last week in QA).
Someone logs into an ASP.NET application successfully and does some stuff. They wait for 10.5 minutes. That means no clicking, just waiting. Then they click and get the next page successfully. Then the click on the NEXT (the second since they've been waiting) and get kicked out to the login page.
Since our FormsAuthentication stuff not only authorizes the user into ASP.NET but also carries with it tokens into other "session-like" systems, folks dug around in those systems initially looking at Audit data, logs, everything. It just doesn't make sense.
The FormsAuthentication timeout is set to 20 minutes and folks are getting "logged out" at 10.5 minutes. They set the timeout to 600 minutes and folks get kicked at 10.5 minutes. Is the timeout value being ignored?
As with most things, we return to first principles and pull out ieHttpHeaders. Why? Because in the context of a Web Application, clicking and looking at HTML only tells you that you clicked and look at some HTML.
TIP: When using ieHttpHeaders or any sniffers, turn OFF Images in your browser. Chances are they aren't the issue (although they might well be) but initially you'll save yourself some clutter in initial debugging.)
So, here's what we saw (abridged and #commented):
#LOGGING IN
POST /fooapp/Login.aspx HTTP/1.1
Content-Type: application/x-www-form-urlencoded
Accept-Encoding: gzip, deflate
User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)
Host: foo.corillian.net
Content-Length: 104
FI=fooapp&Destination=Accounts%2Ffooapp%2Fsummary.aspx&UserName=BAR#LOGIN COOL, REDIRECTING and setting NEW AUTH COOKIE
HTTP/1.1 302 Found
Date: Mon, 11 Jul 2005 18:54:31 GMT
Server: Microsoft-IIS/6.0
Location: http://foo.corillian.net/fooapp/somepath.aspx
Set-Cookie: AuthenticationTicket=32EFESNIPCC65879; path=/
Content-Type: text/html; charset=utf-8
Content-Length: 182#GOING WHERE YOU SAID, RETURNING NEW AUTH COOKIE
GET /fooapp/somepath.aspx HTTP/1.1
Accept-Encoding: gzip, deflate
User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)
Host: foo.corillian.net
Cookie: AuthenticationTicket=32EFESNIPCC65879#GOT TO WHERE I WAS GOING
HTTP/1.1 200 OK
Date: Mon, 11 Jul 2005 18:54:32 GMT
Server: Microsoft-IIS/6.0
Content-Type: text/html; charset=utf-8
Content-Length: 18224WAIT 10.5 MINUTES HERE
#CLICK AND GO TO A NEW PAGE
GET /fooapp/newpage.aspx HTTP/1.1
Referer: http://foo.corillian.net/fooapp/somepath.aspx
User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)
Host: foo.corillian.net
Cookie: AuthenticationTicket=32EFESNIPCC65879;#GOT TO THAT NEW PAGE
HTTP/1.1 200 OK
Date: Mon, 11 Jul 2005 19:05:18 GMT
Server: Microsoft-IIS/6.0
Set-Cookie: AuthenticationTicket=AB4665AB0B7495; path=/; secure
Content-Type: text/html; charset=utf-8
Content-Length: 75510#CLICK AND GO TO THE SECOND PAGE SINCE WE WAITED
GET /fooapp/secondpage.aspx HTTP/1.1
Referer: http://foo.corillian.net/fooapp/newpage.aspx
User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)
Host: foo.corillian.net
Connection: Keep-Alive#NO COOKIES WERE PASSED IN, REDIRECTED TO LOGIN!
HTTP/1.1 302 Found
Date: Mon, 11 Jul 2005 19:05:27 GMT
Server: Microsoft-IIS/6.0
Location: http://foo.corillian.net/fooapp/login.aspx?ReturnUrl=%2ffooapp%2fnewpage.aspx
Content-Type: text/html; charset=utf-8
Content-Length: 209
Where did it all go wrong? Well, we waited 10.5 minutes the clicked. Notice after we waited, we passed in the AuthenticationTicket we had, "32EFESNIPCC65879." This is the one that we generated ourselves in Login.aspx via:
FormsAuthenticationTicket authTicket = new
FormsAuthenticationTicket(1, //version
userName, // user name
DateTime.Now, //creation
DateTime.Now.AddMinutes(Timeout), //Expiration
false};
string encryptedTicket = FormsAuthentication.Encrypt(authTicket);
HttpCookie authCookie = new HttpCookie(
FormsAuthentication.FormsCookieName,encryptedTicket);HttpContext.Current.Response.Cookies.Add(authCookie);
This is a pretty typical thing to do when you're doing FormsAuthentication because you want might more control of the Ticket, or you might want to include user specific data in the cookie, etc.
But, after we waited and passed in the value we had, we got issued a NEW AuthenticationTicket with the value "AB4665AB0B7495" which is OK. Because the age of our original AuthenticationTicket was over 50% of the 20 minute timeout, the FormsAuthenticationModule was kind enough to renew the ticket. How nice of them. And a good thing too. They did it because the <forms> section of our web.config had slidingExpiration="true."
However, then the next GET request includes No AuthenticationTicket at all! Why not? Notice the difference between the first issuance and the second. The second issuing of the cookie included "secure" at its end. Why? Because of this setting in the web.config:
<forms requireSSL="true"
slidingExpiration="true"
loginUrl="~/login.aspx"
name="AuthenticationTicket"
protection="All"
timeout="20" />
Ah! The first time the AuthenticationTicket was issued, it was issued by our custom code, and we didn't respect this setting! Later - 10.5 minutes later - when FormsAuthentication saw fit to issue a new cookie, they DID respect this flag.
Why was this a problem? Because in development were weren't running under SSL (https://). Had we been running under SSL this never would have been found. Had we gone live without SLL we would have seen flaky (read: impossible to reproduce) bugs with folks getting timeouts that didn't jive with our timeout settings.
The Fix - respect the RequiresSSL flag in the inital issuing of the AuthenticationTicket and we would have seen the problem in development immediately upon login:
// Create the authentication ticket
FormsAuthenticationTicket authTicket = new
FormsAuthenticationTicket(1, //version
userName, // user name
DateTime.Now, //creation
DateTime.Now.AddMinutes(Timeout), //Expiration
false}
string encryptedTicket = FormsAuthentication.Encrypt(authTicket);
HttpCookie authCookie = new HttpCookie(FormsAuthentication.FormsCookieName,encryptedTicket);
//Make sure we mark the cookie as "Secure" if RequireSSL is set in the web.config.
// If we don't, the FIRST issuing of this cookie with not be secure
// (as we are the ones that did it) while the second issuing (when it's
// beign refreshed) will be secure. That would cause intermitant problems with
// timeout-like behaviors around "timeout/2" minutes into the user's session.
authCookie.Secure = FormsAuthentication.RequireSSL;HttpContext.Current.Response.Cookies.Add(authCookie);
And then I went to lunch.
About Scott
Scott Hanselman is a former professor, former Chief Architect in finance, now speaker, consultant, father, diabetic, and Microsoft employee. He is a failed stand-up comic, a cornrower, and a book author.
About Newsletter
My latest snag took me an entire 3 days to finally fix... I didn't sleep well until I fixed it.
Comments are closed.
Kinda gives me an idea to put together a book of the best "Debugging Detective Stories".