Scott Hanselman

Weird Timeouts with custom ASP.NET FormsAuthentication

July 12, '05 Comments [7] Posted in ASP.NET | Bugs
Sponsored By

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: 18224

WAIT 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.

facebook twitter subscribe
About   Newsletter
Sponsored By
Hosting By
Dedicated Windows Server Hosting by ORCS Web
Tuesday, July 12, 2005 2:01:04 AM UTC
This is just like watching a an episode of Colombo. There I was, sitting there wondering "WhatDunnit?" rather than "WhoDunnit?".

Kinda gives me an idea to put together a book of the best "Debugging Detective Stories".
Tuesday, July 12, 2005 4:54:45 AM UTC
So does this mean your QA department runs tests for timeouts along the 20minute timeline or was it a random find?
Tuesday, July 12, 2005 6:12:07 AM UTC
We run long test to find this stuff.
Tuesday, July 12, 2005 11:16:29 AM UTC
I ran into a similar thing a while back, although fortunately it ocurred to me that this might happen before I released the code. Problem is that the MSDN samples for handling custom data in tickets all use this method which bypasses the config settings. It still appears to be the same in the Whidbey docs too :-(. It's not too hard to fix once you've found it - there's an blog here http://weblogs.asp.net/hernandl/archive/2004/07/30/FormsAuthRolesRev.aspx which describes a workaround (use FormsAuthentication.GetAuthCookie to create a dummy cookie and ticket with the correct config settings and then add in your custom data).
Liam
Tuesday, July 12, 2005 5:35:02 PM UTC
Awesome find.
Tuesday, July 12, 2005 6:10:48 PM UTC
Awesome find Scott! That would've caused real pain in the future if you hadn't found the cause.
Tuesday, July 12, 2005 9:36:14 PM UTC
I can't believe you found that before lunch! That's saying something right there.

My latest snag took me an entire 3 days to finally fix... I didn't sleep well until I fixed it.
Comments are closed.

Disclaimer: The opinions expressed herein are my own personal opinions and do not represent my employer's view in any way.