> -----Original Message----- > From: Jeffrey Janner [mailto:jeffrey.jan...@polydyne.com] > Sent: Thursday, May 23, 2013 11:24 AM > To: 'Tomcat Users List' > Subject: RE: Need AccessLogValve results clarification > > > -----Original Message----- > > From: Christopher Schultz [mailto:ch...@christopherschultz.net] > > Sent: Thursday, May 23, 2013 10:41 AM > > To: Tomcat Users List > > Subject: Re: Need AccessLogValve results clarification > > > > -----BEGIN PGP SIGNED MESSAGE----- > > Hash: SHA256 > > > > Jeffrey, > > > > On 5/22/13 6:30 PM, Jeffrey Janner wrote: > > >> -----Original Message----- From: Mark Thomas > > >> [mailto:ma...@apache.org] Sent: Wednesday, May 22, 2013 5:24 PM > > >> To: Tomcat Users List Subject: Re: Need AccessLogValve results > > >> clarification > > >> > > >> On 22/05/2013 23:13, Vanga Palli, Ravindra Kumar wrote: > > >>> The timer starts when the incoming socket is assigned to a > thread. > > >> So, what you see in logs is a processing time but not queuing > time. > > >> > > >> Not quite. The timer starts once the request line has been > > >> processed > > >> > > >> Mark > > >> > > >> > > >>> > > >>> Thanks, Ravi > > > > > > Thanks guys. I thought that was how it worked, but glad for the > > > clarification. Now, if only I can figure out why the log shows the > > > same request for the login.jsp from the same IP 8 times in the same > > > second (all with a very long processing time). Note: I don't think > > the > > > IP is PAT/NAT. > > > > Is the request GET? In any case, is there a Content-Length header? Is > > it non-zero? Maybe the client is sending a partial header and then > > waiting around before completing it. Tomcat would read the request > > line (and start the clock) and then wait around for the rest of the > > request before (likely) sending a fast response. > > > > Also, if you are talking about a mobile client, you may have trouble > > pushing data back to them quickly, resulting in a long response time. > > > > - -chris > > Chris - > The logged request is "GET /Login.jsp HTTP/1.1". The file itself is our > login form, which pulls some values from the application static cache > and one query back to the DB for a flag. No explicit Content-Length > header that I can tell. The user hasn't even logged in yet. > Suspicion is on the DB connection right now, or perhaps some other > load-related problem. I'm still doing a detail review of the log. > Wouldn't think it would be the DB response since the query is > essentially "select value from config_table where id='constant';" on a > table with maybe 2 dozen records in it. That should be sub-ms response > every time. > We are seeing these in clusters of poor response time, and the time is > several minutes (5-10). > Jeff
Don't think I'm going to worry too much about this right now. Most of the response codes on those requests were 500s, so I figure the EU was frustrated at the long response time and kept hitting refresh. And the client has admitted that there might be some maintenance activity going on with Oracle at that time that could be suspending all requests, or at least causing them to run slowly.
