Thank you Konstantin, for the clarification of details - now I got a
much better understanding of the issues involved.
My understanding is that the logAccess(...) call happens when the output
buffer has been flushed and closed (in http/1.0 that would also close
the tcp connection, thus I called it 'teardown'), and the timestamp
recorded is of the call time of the logAccess(...).
I would like to use the log's <timestamp> to measure request
inter-arrival time intervals.
It seems that to get a valid timestamp for the calculation (i.e. a more
accurate approximation of the request arrival time), I need to subtract
the <time taken> from the <timestamp> written in the log.
Can you please confirm this?
(I think that I can get away with considering the Request Arrival Time
the same as Response Processing Start i.e. negligible time for reading
and parsing the http request line etc.)
About the processing time recorded <time taken> it seems that it
contains the whole of transmission as well (i.e. pushing the data to the
network layer and closing the output). Chris put an interesting question
(thank you for bringing it up) that I'm not sure how to handle at the
moment (beyond not using such "forwarding" servlets in the initial
experimental setups):
On 2/28/2011 5:57 PM, Christopher Schultz wrote:
On the other hand, your servlet can issue a "forward" which is
essentially a server-side redirect that allows a second (or third, or
fourth, ...) servlet to generate a response after the first servlet does
it's work. I'm not sure where the Valve chain fits into that (does the
AccessLogValve time the calls to each individual forward, or does it
time the entire request/response as the client sees it?), but the answer
to that question can significantly change the timings that you observe.
Can you provide any feedback on that?
For the modeling scheme to work, the web server needs be configured with
blocking (traditional sockets) threads on read and - especially - on
write. I read the Connector configuration
http://tomcat.apache.org/tomcat-7.0-doc/config/http.html and it states
in the introduction:
"Each incoming request requires a thread for the duration of that
request. If more simultaneous requests are received than can be handled
by the currently available request processing threads, additional
threads will be created up to the configured maximum (the value of
the|maxThreads|attribute). If still more simultaneous requests are
received, they are stacked up inside the server socket created by
the*Connector*, up to the configured maximum (the value of
the|acceptCount|attribute. Any further simultaneous requests will
receive "connection refused" errors, until resources are available to
process them."
and I'm perfectly happy with that. But at the page bottom (comparison of
the connectors) I don't understand:
a) How can I choose one of the three connectors to use in server config?
b) What does "Sim Blocking" in the Java Nio Blocking Connectormean?
On 2/27/2011 9:43 PM, Konstantin Kolinko wrote:
2011/2/21 Antonios Kogias<co...@hua.gr>:
Thank you very much for the detailed answer. Now there's just one more thing
to ask.
If we use tomcat 7.0.8, the "timing for the whole request processing cycle"
will incorporate transmit time?
e.g. if using HTTP/1.0, will it represent the total time until the teardown
of the connection? Or will it be the net processing time /before/
transmission starts (i.e. time to prepare the http response and push it to
the network layer)?
In TC 7.0.8 and later:
The start time:
= when org.apache.coyote.Request#setStartTime() is called
That is done by processors. Some initial processing is already done at
that point (e.g. reading the request line).
The end time:
= when org.apache.catalina.connector.CoyoteAdapter#service() calls logAccess(..)
That is done when service() completes processing the request. At that
point the content is already generated and response.finishResponse()
is already called (which closes output buffer and writes remaining
data to the socket).
After that Tomcat performs cleaning of its internal state and is ready
to process next request.
I am not sure what you mean by "teardown".
A correction: I wrote:
In latest versions of TC7 (7.0.8 and later) (...)
That version prints timestamp when request was received
That is not true. With %t the AccessLogValve still prints the current
time when logging is performed, not when processing was started.
(There was a patch discussed on dev@ to change the behaviour, but it
has not been applied yet).
BTW, if you want to debug Tomcat,
http://wiki.apache.org/tomcat/FAQ/Developing
Best regards,
Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
