On 18/02/2010 20:23, George Baxter wrote:
> So we think we've found a threading problem in the cookie handling.
Hmm. Each request has its own Cookies object. The only way these would
be shared between threads is if two threads were using the same request
object. That usually happens when custom filters/valves wrap requests
and mix up the request/response objects. Putting requests and responses
into the session is another sign of things going awry.
I'd add some logging to check which request and cookies objects are
being used and see if you can track down where they are getting mixed
up. My money is on application code.
Mark
>
> Running on Solaris 10, jdk 1.5, tomcat 6.0.24.
>
> We built our 'own' version of 6.0.24, adding logging in some places, and
> ultimately, this is what we discovered:
>
> A bit of information: in these log entries, we're looking at 2 threads : 66
> and 228.
> We're also looking at 2 Cookies entities : 2021596579 and 1706042601.
>
> Here's the modified 'getCookieCount()' method in Cookies:
> public int getCookieCount() {
> log("processed = " + !unprocessed);
> if( unprocessed ) {
> unprocessed=false;
> log("calling process cookies");
> processCookies(headers);
> }
> return cookieCount;
> }
>
>
> First, thread 66 receives a request (from a monitoring process, has no
> cookies):
> Feb 18, 2010 11:31:04 AM org.apache.catalina.connector.CoyoteAdapter
> parseSessionCookiesId
> INFO: 66-parseSessionCookie for request: R( /)
>
> Next, it's checking its cookie count, and here's something wrong already :
> the unprocessed flag in Cookies is already set to false.. for Cookies
> 1706042601.
> Feb 18, 2010 11:31:04 AM org.apache.tomcat.util.http.Cookies log
> INFO: 66,1706042601-C:processed = true
>
> Next, we jump to thread 228: it seems to be busy ending a request using
> Cookies 2021596579
> Feb 18, 2010 11:31:04 AM org.apache.tomcat.util.http.Cookies log
> INFO: 228,2021596579-C:recycling Cookies
>
> Back to thread 66, who suddenly seems to be using THE SAME COOKIES OBJECT:
> Feb 18, 2010 11:31:04 AM org.apache.tomcat.util.http.Cookies log
> INFO: 66,2021596579-C:processed = false
> Feb 18, 2010 11:31:04 AM org.apache.tomcat.util.http.Cookies log
> INFO: 66,2021596579-C:calling process cookies
>
> Then, its now recycling Cookies.. in fact, it's recycling Cookies 1706042601
> twice!
> Feb 18, 2010 11:31:04 AM org.apache.tomcat.util.http.Cookies log
> INFO: 66,1706042601-C:recycling Cookies
> Feb 18, 2010 11:31:04 AM org.apache.tomcat.util.http.Cookies log
> INFO: 66,1706042601-C:recycling Cookies
>
> Back to 228, which is going to try to handle a new request. Note that at
> this time, 2021596579 has not yet been recycled:
> Feb 18, 2010 11:31:04 AM org.apache.catalina.connector.CoyoteAdapter
> parseSessionCookiesId
> INFO: 228-parseSessionCookie for request: R( /nav/mysfly.sfly)
> Feb 18, 2010 11:31:04 AM org.apache.tomcat.util.http.Cookies log
> INFO: 228,2021596579-C:processed = true
> Feb 18, 2010 11:31:04 AM org.apache.tomcat.util.http.Cookies log
> INFO: 228,2021596579-C:recycling Cookies
>
> And thus, we've lost our session reference.
>
> God I hope the formatting holds when I send this....
>
> -George
>
> On Feb 17, 2010, at 12:00 PM, George Baxter wrote:
>
> Downloaded src code of tomcat for debugging purposes and sure enough, our
> cookies are of type byte, so the fact that the code can parse the cookie
> 'string' just fine means diddly-squat.
>
> Next plan, build my own tomcat 6.0.24 version with lots of logging and checks
> for debugging purposes...
>
> -g.
>
> On Feb 16, 2010, at 4:22 PM, George Baxter wrote:
>
> Well.. we parsed the header that failed, and it parsed just fine.
>
> Note that we're parsing via the 'old deprecated' parse by string entity. I
> guess I'll try parsing by bytes next.
>
> -g.
>
> On Feb 16, 2010, at 2:47 PM, Konstantin Kolinko wrote:
>
> 2010/2/17 George Baxter
> <gbax...@shutterfly.com<mailto:gbax...@shutterfly.com>>:
> Hi Konstantin,
>
> Thanks for your reply.
>
> Yes, the getHeaders("cookie") returns what seems to be a valid set of
> cookies, thus we're not losing them in any of the proxies we might have set
> up. (Currently, we're only in development mode for tomcat 6 and we're not
> going through any proxies, just directly to the server.)
>
> We get this problem in all sorts of browsers (FF, Safari, IE).
>
> The thing that really bugs me is the inconsistency. It's almost as if there
> were a race condition going on, but the request is basically single threaded,
> isn't it? My only fear is some parser used in the tomcat code is being used
> in a non-thread safe manner, but then *everybody* would be having this
> problem, neh?
>
> I'm finding out about the connectors, but we may not be using any as :
>
> Jan 28, 2010 6:52:56 PM org.apache.catalina.core.AprLifecycleListener init
> INFO: The APR based Apache Tomcat Native library which allows optimal
> performance in production environments was not found on the
> java.library.path: /dist/sfsite/obj
>
> Hopefully, this is just in our development environments!
>
> Thanks,
>
> -George
>
>
> On Feb 12, 2010, at 2:32 PM, Konstantin Kolinko wrote:
>
> 2010/2/13 George Baxter
> <gbax...@shutterfly.com<mailto:gbax...@shutterfly.com>>:
>
> Hello,
>
> We're running into an issue with tomcat 6.0.18 running on solaris.
> Occasionally a request will come through that has cookies in the header, but
> the request.getCookies() returns no cookies.
>
> How do you observe that? You mean that it is present in
> HttpServletRequest.getHeaders("Cookie") ?
>
> This causes the user to lose
> session since even the JSESSIONID cookie is not recognized, and of course
> all our custom cookies are lost. It seems to happen randomly, across our
> web site, and varies in frequency from every 2-3 requests to over 200
> requests before it happens again.
>
> There's no change to the cookie values (or very little) between requests.
>
> In addition, this only seems to be a problem on solaris. Running on MacOSx
> or Linux and we don't see the issue. Also, we don't have the problem in
> Tomcat 5.5.
>
> Any other details on your configuration?
>
> What connectors are you using? HTTP/AJP? Nio/Bio/Apr? (usually some
> org.apache.coyote.* class is mentioned in the startup log in a
> "Starting Coyote .." message) Do you have Apache HTTPD in front of
> Tomcat? Do you have HTTP proxies around? Are failing requests
> coming from some specific client? Are they coming from some specific
> browser?
>
> Best regards,
> Konstantin Kolinko
>
>
>
> 1. What is the default character encoding for your environment?
>
> 2. Cookies are parsed in
> org.apache.tomcat.util.http.Cookies.processCookies()
>
> You may
> 1) Look in your logs for a WARN message with the text "Cookies:
> Parsing cookie as String. Expected bytes."
>
> 2) You can consider enabling FINE logging for the above mentioned
> class. Add this to the logging.properties:
>
> org.apache.tomcat.util.http.Cookies.level=FINE
>
> It will log what headers it parsed.
> Though it might be hard to match what is logged to your specific
> request, so it might be useless.
>
> 3) When an issue is encountered, log the headers.
> Then post them here or try to parse them yourselves,
> copying the code from Cookies.processCookieHeader() for the Tomcat
> version that you are using.
>
> 3. Have you considered trying it with a more recent Tomcat version?
>
>
> Best regards,
> Konstantin Kolinko
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail:
> users-unsubscr...@tomcat.apache.org<mailto:users-unsubscr...@tomcat.apache.org>
> For additional commands, e-mail:
> users-h...@tomcat.apache.org<mailto:users-h...@tomcat.apache.org>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail:
> users-unsubscr...@tomcat.apache.org<mailto:users-unsubscr...@tomcat.apache.org>
> For additional commands, e-mail:
> users-h...@tomcat.apache.org<mailto:users-h...@tomcat.apache.org>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail:
> users-unsubscr...@tomcat.apache.org<mailto:users-unsubscr...@tomcat.apache.org>
> For additional commands, e-mail:
> users-h...@tomcat.apache.org<mailto:users-h...@tomcat.apache.org>
>
>
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
