Some slow request on tomcat 5.5

Hello,

we are testing our Tomcat 5.5 Server on a debian system. And we can see, that a few requests are very slow and can't find a reason therefore.

We did some tests with Apache benchmark like this:

#  ab -n 10 -c 1 http://localhost/demo/startseite
...
Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.1      0       0
Processing:    81  145 192.3     82     692
Waiting:       77  140 178.6     81     648
Total:         81  145 192.3     83     692

Percentage of the requests served within a certain time (ms)
  50%     83
  66%     83
  75%     85
  80%    104
  90%    692
  95%    692
  98%    692
  99%    692
 100%    692 (longest request)

Most times, we do this test with 10 requests, all responses are served within 70 - 100 ms. But sometimes there are these peaks. You can find the time in the Tomcat logs. The following logs came from the test above:

127.0.0.1 - - [02/Aug/2010:16:02:13 +0200] "GET /demo/startseite HTTP/1.0" 200 7385 685
127.0.0.1 - - [02/Aug/2010:16:02:13 +0200] "GET /demo/startseite HTTP/1.0" 200 7385 78
127.0.0.1 - - [02/Aug/2010:16:02:13 +0200] "GET /demo/startseite HTTP/1.0" 200 7385 77
127.0.0.1 - - [02/Aug/2010:16:02:13 +0200] "GET /demo/startseite HTTP/1.0" 200 7385 77
127.0.0.1 - - [02/Aug/2010:16:02:13 +0200] "GET /demo/startseite HTTP/1.0" 200 7385 76
127.0.0.1 - - [02/Aug/2010:16:02:13 +0200] "GET /demo/startseite HTTP/1.0" 200 7385 80
127.0.0.1 - - [02/Aug/2010:16:02:13 +0200] "GET /demo/startseite HTTP/1.0" 200 7385 80
127.0.0.1 - - [02/Aug/2010:16:02:13 +0200] "GET /demo/startseite HTTP/1.0" 200 7385 76
127.0.0.1 - - [02/Aug/2010:16:02:13 +0200] "GET /demo/startseite HTTP/1.0" 200 7385 78
127.0.0.1 - - [02/Aug/2010:16:02:13 +0200] "GET /demo/startseite HTTP/1.0" 200 7385 77

The last column (don't forget to scroll) shows the time (ms) for the request. We use the %D pattern: Time taken to process the request, in millis.

By the way: Does anybody know when tomcat exactly starts and stops the time for the request?

We did the test inclusive profiling tomcat with the YourKit Java Profiler. But the snapshot did not show the times from the test. There were only 400 ms for "All threads" and just 292 ms for "java.lang.Thread.run()". Also the snapshots shows, that there was no garbage collection while testing.

So, the profiler did not show all the time, but the tomcat log shows, that the time for processing the requests was spent on the tomcat server.

Has anybody an idea, where we can find the 600 ms of the slow request?

Thanks for any reply!

ansaurus

tags:

views:

answers:

Some slow request on tomcat 5.5

related questions