Monday, June 16, 2008

No Cookie for You!!



UPDATE:
A better explanation has surfaced. See this post for more info http://jochem.vandieten.net/2008/07/03/reserved-names-for-cookies/
I am leaving this entry as is as it still solved our issue. Call it a "work around".


So we've been noticing a lot of entries in one of our logs that look like this:
06/16 16:27:08 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:27:08 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:27:54 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:27:54 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:28:34 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:28:34 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:29:22 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:29:22 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:30:13 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:30:13 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:31:11 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT
06/16 16:31:11 error Cannot create cookie: expires = Wed 09-Jun-2038 16:17:42 GMT


I kept seeing postings from a couple of years ago that people would run into this issue as a result of a memory shortage in the JVM. This was not the case with us however as we have 400+ megs of memory free on average.

I decided to try and pair up the times of these errors with our IIS logs to see what I could find. I did find a matching entry that looked like this:
2008-06-16 00:00:01 W3SVC762671395 xxx.xxx.xxx.xxx GET /xxx/ xxx=5773E359497D4F1B 80 - 12.129.9.198 HTTP/1.1 Botster.LinkChecker/v.1.0 CFID=xxxxxxxx;+expires=Tue+08-Jun-2038+16:28:07+GMT;+CFTOKEN=xxxxxxx;+expires=Tue+08-Jun-2038+16:28:07+GMT;+JSESSIONID=xxxxxxx - www.xxxxxxxx.com 200 0 0 526 356 453

Not sure what to do about it yet. We could block Botster.LinkChecker at the IIS level as we have an ISAPI tool in place. But I'm wondering if there is something we can do at the code level too. The section of the log entry with +CFID, +expires, etc.. is part of the cs(Cookie) area. I'm assuming this is the area that reveals which cookies were requested to get set. Is it possible to check the user-agent for Botster and then redirect at the code level? I don't remember the order of operations there.

The rest of the story...
After looking at this for another day I finally realized what was going on. The key to this all lies within CF's client management. When the bot is hitting our site, cf wants to establish a session so it tries to write two permanent cookies, cfid and cftoken, to the visiting client. The problem comes in when bots don't allow the setting of permanent cookies. CF was noticing this and writing an error entry a couple times every minute, as often as the bot was hitting us.

CFID=7857398;
+expires=Thu+10-Jun-2038+13:51:18+GMT;
+CFTOKEN=1959af634c5b6ec3-96CB3B7F-17A4-A7F4-705CBC2B0F9052AA;
+expires=Thu+10-Jun-2038+13:51:18+GMT;
+JSESSIONID=2e3040ee771260d33446

The light turned on for me when I broke down the iis log entry cs(Cookie) area like this. It looks like the first item in the ';' delimited list is the cookie that was requested. If it is followed by an expires, that is a modifier to the previous item in the list. So when I saw this I realized that it was CF that was trying to set the cookie, not some renegade bot code. Notice that JSESSIONID doesn't have the expires modifier because it is always set as a session cookie and goes away when the browser is shut down (hence, not an issue for bots). I think its helpful to break the info down to simple lines, otherwise you get lost in the horizontal scrolling.

There are two solutions for this that I looked at. The first I mentioned before was filtering the bot at the ISAPI level. The second was using j2ee session management. We already had this turned on but we must have forgotten about the fact that the setclientcookies in the cfapplication tag defaults to true. Jsessionid replaces the need for cfid/cftoken though cf still seems to put cf still seems to append cfid/cftoken to the urls. Cflocation will append these variables if you have addtoken=true. We can solve our problem by simply adding the setclientcookies=false in the cfapplication tag for the app.

FYI: if you are using cfloginuser, cfid/cftoken perm cookies will still be set if in your cfapplication tag you have loginmanagement set to cookie. This seems to override the setclientcookie setting. I haven't tested it yet, but I bet if you set loginmanagement="session", you would not see the perm cookies being set. This is not a concern for us at the moment since the bot is not trying to log in, its simply hitting publically accessible data.

Additional info on J2EE session management can be found here:
How to write CFID and CFTOKEN as per-session cookies
http://kb.adobe.com/selfservice/viewContent.do?externalId=tn_17915

Hiding / Encrypting ColdFusion CFID And CFTOKEN Values
http://www.bennadel.com/blog/785-Ask-Ben-Hiding-Encrypting-ColdFusion-CFID-And-CFTOKEN-Values.htm

2 comments:

Charlie Arehart said...

Hi Teeps, you (and readers) may want to check out this blog entry that follows on to yours and offers a very different explanation for your problem.

http://jochem.vandieten.net/2008/07/03/reserved-names-for-cookies/

It would be interesting to hear if it is indeed the answer for you, in which case you may want to update your entry here.

Good to see your blog, though. I always enjoy seeing people share their experience trying to solve problems. We can all learn together.

Teeps (Terry Palmer) said...

Thanks for the heads up Charlie. It is indeed a better explanation. I've updated my post pointing Jochem's direction. However, our solution worked for us. We don't see the error entries in our logs anymore. So I'm curious why setclientcookies=false in the cfapplication worked for the reserved word issue.

ps... for Objective next year, we have to make sure there is another escalator for bowling.