On 08.11.2010 21:25, Konstantin Kolinko wrote:
2010/11/8 Rainer Jung<rainer.j...@kippdata.de>:
A typical annoyance when combining Apache web server and Tomcat is the
difference in access log timestamp. Apache logs the beginning of the
request, Tomcat logs the end of the request.
According to the HTTPD docs [2], this changed between HTTPD 1.3 and 2.
1.3 logs the time when the request processing finished, 2+ logs when it started.
[2] http://httpd.apache.org/docs/1.3/logs.html
OK, but 1.3 isn't really relevant any longer ...
I added a feature to Apache trunk (will become 2.4) to make it configurable
for Apache, which time stamp to choose ([1]). Furthermore the Apache web
server allows to choose the format, in which the time stamp is being logged
as something different than just "Common Log Format". This is all configured
by an appropriate "format" in %{format}t.
Any a priori objections about porting the same functionality to Tomcat
trunk?
I thought about it already. I would like this feature.
My current idea with implementation is that the timestamp when request
processing started can be placed in a field in the request. Such
solution will be compatible with the recently added AccessLog
interface.
Since any single invocation of addElement() only needs either begin or
end time, I was thinking about deciding which timestamp to pass when
calling addElement(). But it might be a bit faster and more generic to
add the timestamp to the request and let the AccessLogElement retrieve
it from there.
There might be a caveat with caching of formatted timestamp strings in
the access log valve implementations.
Yes, but the momentary implementation isn't that nice, e.g. if you want
correct sub second resolution. I'm experimenting with something similar
to httpd, namely using a cyclic buffer of N formatted timestamps
(seconds granularity). That buffer could be thread local (like the
currentDateStruct right now). If a new timestamp is not contained in the
buffer, it could call out to a synchronized global buffer which then
does the actual formatting. That way there will not be to much locking
(only if a thread sees a second not in its local cache) and the
formatting is mostly only done once for each second.
What happens with async requests?
Good question, I need to see, what the momentary behaviour of the access
log is with respect to the async lifecycle.
Of course due to latency between Apache and Tomcat and due to different
timeouts, even when using the same time stamp (begin or end of request) in
both products, the timestamps will not always match exactly. But at the
moment matching the entries is much harder, than it could be.
If one needs to match them it would be better to do so by certain id,
not by a timestamp.
Something like %{forensic-id}n [3]
[3] http://httpd.apache.org/docs/current/mod/mod_log_forensic.html
Yes! There is mod_unique_id, which generates unique IDs also for
mod_log_forensic. One can set those as additional request headers and
that way pass them to Tomcat and log there. I was thinking about a
simple filter, that
- looks for an incoming ID by checking a configured header
- if the header is not set generates an own ID basically using an atomic
- Checks the presence of a few well known log frameworks and sets the ID
as a mapped diagnostic context (log4j terminology) or similar so that
you can configure your webapp logging and in case of log4j also Tomcat
logging to include the unique ID on each log line.
- optionally reflects the ID by setting a response header, which allows
to log it on the proxy and also to check its correctness on the proxy.
But first the access log ...
Regards,
Rainer
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org
