RE: Response Time in Jasper Logs
> I would add that one good place to /start/ looking, > is the DNS name resolution of your customer's workstations. > Because if that is not working properly, then your server > won't even see the request for a while after they click.. Thanks for the suggestion. The clients connect by IP address and rDNS is disabled on the servers. I suspect WAN/Internet latency issues. -- Eric Robinson Disclaimer - July 6, 2009 This email and any files transmitted with it are confidential and intended solely for Tomcat Users List,a...@ice-sa.com. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management and Physician's Managed Care. Warning: Although Physician Select Management and Physician's Managed Care have taken reasonable precautions to ensure no viruses are present in this email, the companies cannot accept responsibility for any loss or damage arising from the use of this email or attachments. This disclaimer was added by Policy Patrol: http://www.policypatrol.com/ - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Response Time in Jasper Logs
Christopher Schultz wrote: -BEGIN PGP SIGNED MESSAGE- Hash: SHA1 Eric, On 7/5/2009 2:56 PM, Robinson, Eric wrote: TOTAL REQUESTS: 43865 AVERAGE RESPONSE TIME: 18 ms RESPONSE TIME BREAKDOWN: 0 -10 ms: 36454 (83.00%) 11 -50 ms: 6128 (13.00%) 51 - 100 ms: 436 (0%) 101 - 250 ms: 453 (1.00%) 251 - 500 ms: 230 (0%) 501 - 1000 ms: 62 (0%) 1001 - 2500 ms: 41 (0%) 2501 - 5000 ms: 7 (0%) 5001 - 1 ms: 54 (0%) 10001 - 2 ms: 0 (0%) 2+ ms: 0 (0%) To me, this looks like healthy response time. I agree. I would run a remote benchmark to confirm that it's the /customer's/ network that has problems; I suspect that's where you'll find the problem. I would add that one good place to /start/ looking, is the DNS name resolution of your customer's workstations. Because if that is not working properly, then your server won't even see the request for a while after they click.. A simple "nslookup your.server.name" from a customer workstation will already tell you some. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Response Time in Jasper Logs
-BEGIN PGP SIGNED MESSAGE- Hash: SHA1 Eric, On 7/5/2009 2:56 PM, Robinson, Eric wrote: > TOTAL REQUESTS: 43865 > AVERAGE RESPONSE TIME: 18 ms > RESPONSE TIME BREAKDOWN: > 0 -10 ms: 36454 (83.00%) >11 -50 ms: 6128 (13.00%) >51 - 100 ms: 436 (0%) > 101 - 250 ms: 453 (1.00%) > 251 - 500 ms: 230 (0%) > 501 - 1000 ms: 62 (0%) > 1001 - 2500 ms: 41 (0%) > 2501 - 5000 ms: 7 (0%) > 5001 - 1 ms: 54 (0%) > 10001 - 2 ms: 0 (0%) > 2+ ms: 0 (0%) > > To me, this looks like healthy response time. I agree. I would run a remote benchmark to confirm that it's the /customer's/ network that has problems; I suspect that's where you'll find the problem. - -chris -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.9 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkpSRZQACgkQ9CaO5/Lv0PAdxACfWNkKpa/irs/j0kdCHAZhPMDm HykAn16XqshdQExuIsUtwqmO3LwNDyOl =naOH -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
RE: Response Time in Jasper Logs
Chris, > Your question makes me think that perhaps what you're > seeing is a timing-out keep-alive request: It's not what I'm seeing in the logs, it's what the customer is seeing in the application. One of my customers says they are frequently seeing long application delays on all of the workstations in their office, but I'm not seeing anything like that in the jasper logs. They say they will click a button and it might take 60 seconds or more for the results to display. But from my analysis of the jasper logs, I don't see this from the server's perspective. For example, here's the jasper log analysis for one day last week (generated by a shell script). TOTAL REQUESTS: 43865 AVERAGE RESPONSE TIME: 18 ms RESPONSE TIME BREAKDOWN: 0 -10 ms: 36454 (83.00%) 11 -50 ms: 6128 (13.00%) 51 - 100 ms: 436 (0%) 101 - 250 ms: 453 (1.00%) 251 - 500 ms: 230 (0%) 501 - 1000 ms: 62 (0%) 1001 - 2500 ms: 41 (0%) 2501 - 5000 ms: 7 (0%) 5001 - 1 ms: 54 (0%) 10001 - 2 ms: 0 (0%) 2+ ms: 0 (0%) To me, this looks like healthy response time. -- Eric Robinson Disclaimer - July 5, 2009 This email and any files transmitted with it are confidential and intended solely for Tomcat Users List. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management and Physician's Managed Care. Warning: Although Physician Select Management and Physician's Managed Care have taken reasonable precautions to ensure no viruses are present in this email, the companies cannot accept responsibility for any loss or damage arising from the use of this email or attachments. This disclaimer was added by Policy Patrol: http://www.policypatrol.com/ - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Response Time in Jasper Logs
-BEGIN PGP SIGNED MESSAGE- Hash: SHA1 Eric, On 7/5/2009 10:07 AM, Robinson, Eric wrote: > That's very helpful, Chris. > >> The bytes are not guaranteed to have arrived at the client by the time >> the valve computes the elapsed time. > > Right, but is it generally correct to say that the response time value > represents the time from when the request was received to the time the > response was transmitted on the wire? Roughly. Tomcat sets up the request and response objects and then delegates to the first-configured Valve (which may be something other than you think it is, depending on your configuration). Throw an exception in your servlet code and read the stack trace to see all the things that are being run: if nothing else, you'll gain an appreciation for how must stuff is being done during request processing. There is no guarantee that the /entire/ request has been received by the time the timer starts. But, if your servlet reads all the input from the client, that time /will/ be counted in the timing (because your servlet will block waiting for all the data to arrive). It's not possible to tell if /any/ of the response data has been transmitted... the best your servlet can do is to flush the response and hope that the data is delivered to the client is a reasonable time. Your question makes me think that perhaps what you're seeing is a timing-out keep-alive request: your client is sending a keep-alive request to Tomcat which fulfills the first HTTP request coming-in on the TCP connection, but then the client does not make any more requests, and doesn't tell the server to close the connection. Both the client and the server wait for a while until the server gets bored (really a configurable timeout) and closes the connection. You might want to put the "Connection" header into the access log to see how many keep-alive requests you receive (my guess is that /most/ of them are keep-alive, but it might give you some good information). I'm not sure if it's possible to get Tomcat to report the time a connection is held open across requests (each individual HTTP request, even on a keep-alive connection) may/will be handled by a separate thread, so your webapp sees everything as individual requests. - -chris -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.9 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkpQuioACgkQ9CaO5/Lv0PAWGACcDHkOSSbUnkU7jVfhQHgvgZs0 AOkAn1Knoa8bd8UV7mZN8J74JXfJWpu0 =WaR5 -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
RE: Response Time in Jasper Logs
That's very helpful, Chris. > The bytes are not guaranteed to have arrived at the client by the time the valve computes the elapsed time. Right, but is it generally correct to say that the response time value represents the time from when the request was received to the time the response was transmitted on the wire? -- Eric Robinson Disclaimer - July 5, 2009 This email and any files transmitted with it are confidential and intended solely for Tomcat Users List. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management and Physician's Managed Care. Warning: Although Physician Select Management and Physician's Managed Care have taken reasonable precautions to ensure no viruses are present in this email, the companies cannot accept responsibility for any loss or damage arising from the use of this email or attachments. This disclaimer was added by Policy Patrol: http://www.policypatrol.com/ - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Response Time in Jasper Logs
-BEGIN PGP SIGNED MESSAGE- Hash: SHA1 Eric, On 7/3/2009 10:42 PM, Robinson, Eric wrote: > I just want to be sure of one thing. Does the value represent the total > time from the moment tomcat saw the client's request to the time it > successfully delivered the full response? You can always check the source code: http://svn.apache.org/repos/asf/tomcat/tc6.0.x/tags/TOMCAT_6_0_20/java/org/apache/catalina/valves/AccessLogValve.java > The reason I ask is that we have some users who are complaining that > certain requests are taking a long time (up to a minute). Yet when we > check the jasper logs, we see that 97% of all requests are satisfied in > < 50ms, and there are no requests that take longer than 20 seconds. So > I'm trying to reconcile what I'm hearing from users with what I'm seeing > in the logs. Technically speaking, the valve reports the amount of time spent executing everything "underneath" the valve itself. This may include other valves, your webapp's filters, and finally your webapp's servlet (or maybe DefaultServlet or whatever). The bytes are not guaranteed to have arrived at the client by the time the valve computes the elapsed time. If a webapp really wants to, it can launch a thread and continue to send data to the response's output stream, but that will likely cause an error somewhere down the line, as Tomcat will flush and close the output stream shortly after it regains control. The long response times experienced by your clients are more likely to be due to slow or unreliable networks than anything else: you have the data to prove that it's not your webapp. If you have the capability, try benchmarking your webapp from outside your own network. That will allow you to measure the response time that the client experiences. Tools such as JMeter are good for this type of sampling. Hope that helps, - -chris -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.9 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkpQsOIACgkQ9CaO5/Lv0PDRsQCcC6beKd95KWkGBIwWYsUYwlrQ 0XYAnjN/g83zPCZpVjctio53Mfv/JxBm =6NKS -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
