Re: Access Log /Filter/?
-BEGIN PGP SIGNED MESSAGE- Hash: SHA1 Xie, On 3/2/2010 6:20 PM, Xie Xiaodong wrote: Second, you are absolutely right about the log.info(). I first wrote like this for testing and forgot to get it back to debug level. Don't forget that calling log.debug() with a bunch of string concatenations still performs those string concatenations. It's better to do something like this: if(log.isDebugEnabled()) log.debug(something + something else + a third thing); In modern jvm, it does not matter much between StringBuffer and StringBuilder, jvm will change StringBuffer used in single thread scenario into StringBuilder automaticlly. No, it won't: if you ask for StringBuffer, you'll get a StringBuffer. If you just do a + b, the /compiler/ will use StringBuilder if your target is 1.5+ but the JVM doesn't do anything like what you describe. You could google this information. There are some benchmark test about it. I'd love to see an example demonstrating your claim. - -chis -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.10 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEUEARECAAYFAkuOid0ACgkQ9CaO5/Lv0PD7FQCYjz53of2knok9gwKfyShrecka JACgjWY1WBpOYTSTJJ5dlDOO5BAnJJ4= =8yWQ -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Access Log /Filter/?
-BEGIN PGP SIGNED MESSAGE-
Hash: SHA1
Jason,
On 3/2/2010 7:21 PM, Jason Brittain wrote:
Why does the request have to be an HTTP request in order to have the
access log run?
That does seem to be a bug.
Note that this is not actually a part of the AccessLogValve, it's just
part of Xie's implementation.
By default, the access logger logs the common
log web server
format, but of course it doesn't have to, so it should log non-HTTP requests
as well, but maybe
only if a non-default pattern is configured?
Fair enough: most of the information you'd want to log is from HTTP
requests (like the URI, for instance). The only things that are
available for non-HTTP requests are:
- - current date/time
- - transaction time
- - number of bytes read and sent
- - local address
- - remote address
- - request attributes
- - server name
Actually, that's quite a bit, but I've never seen an HTTP log that
doesn't log the URI :)
long t2 = System.currentTimeMillis();
long time = t2 - t1;
This isn't your choice, it's in the original code, but why not just do:
long elapsed = System.currentTimeMillis();
...
elapsed = System.currentTimeMillis() - elapsed;
??
Fewer items on the stack, etc.
Except that then it is more difficult to debug. Right? It isn't as easy to
inspect the value of
the current time if you perform the subtraction without first assigning the
current time to a
variable.
Fair enough, though debugging this timing code shouldn't really be required.
private Date getDate() {
// Only create a new Date once per second, max.
long systime = System.currentTimeMillis();
AccessDateStruct struct = currentDateStruct.get();
if ((systime - struct.currentDate.getTime()) 1000) {
struct.currentDate.setTime(systime);
struct.currentDateString = null;
}
return struct.currentDate;
}
I don't understand why this is ThreadLocal, instead of just synchronized
across the object. Maybe it's slightly faster to avoid the
synchronization and just use ThreadLocals, but I'm not sure how many
requests per second a single Thread is going to process, so I'm not
convinced that caching this data is worth the complexity it requires in
this class. I'd love to hear from a Tomcat dev about this.
Tomcat can (hopefully) answer a larger number of requests per second
every year on decently modern hardware. Benchmark it both ways on
a reasonably good/wide machine and you'll see why avoiding the sync
is helpful. I don't think it muddies the code very badly here.
Okay. Certainly avoiding object creation is a good idea, and avoiding
highly-contended synchronization is a good idea, too. I'd like to see a
performance comparison between these strategies, though. Maybe I'll run
one :)
The %b portion of the Combined Log Format is documented to be the size of
the object returned to the client, not including the response headers.
http://httpd.apache.org/docs/1.3/logs.html#common
Right. Presumably, the Content-Length is synonymous with the above, but
it might not be. Also, Content-Length is not always set, so you'll get a
lot of - written in the log even when response bodies actually has
content. In this implementation, %b is equivalent to %{Content-Length}o.
Counting bytes isn't that big of a deal, either. I'll submit a patch at
some point... maybe using a different pattern character.
- -chris
-BEGIN PGP SIGNATURE-
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAkuOjCAACgkQ9CaO5/Lv0PAAmgCgt9QVocFjXVNB3t4ib6fWOUIL
++YAoKdpBuT1uhobAIxasRsdw/PaK00e
=zS1q
-END PGP SIGNATURE-
-
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Access Log /Filter/?
Hello,
I think log.debug() method should first check current logging levels, or our
code will have those if() {} template everywhere.
I checked java.util.logging.Logger, and found this:
public void log(Level level, String msg, Object param1) {
if (level.intValue() levelValue || levelValue == offValue) {
return;
}
LogRecord lr = new LogRecord(level, msg);
Object params[] = { param1 };
lr.setParameters(params);
doLog(lr);
}
Java 6 hotspot can determine that the StringBuffer synchronization isn't
actually used across threads in many cases, and thus it doesn't bother
synchronizing. Thus, the performance of the two classes becomes identical.
http://www.javalobby.org/java/forums/t88518.html
But it is more secure to not depend on specific jvm version, so it is more
appropriate to use StringBuilder when necessary.
On Wed, Mar 3, 2010 at 5:19 PM, Christopher Schultz
ch...@christopherschultz.net wrote:
-BEGIN PGP SIGNED MESSAGE-
Hash: SHA1
Jason,
On 3/2/2010 7:21 PM, Jason Brittain wrote:
Why does the request have to be an HTTP request in order to have the
access log run?
That does seem to be a bug.
Note that this is not actually a part of the AccessLogValve, it's just
part of Xie's implementation.
By default, the access logger logs the common
log web server
format, but of course it doesn't have to, so it should log non-HTTP
requests
as well, but maybe
only if a non-default pattern is configured?
Fair enough: most of the information you'd want to log is from HTTP
requests (like the URI, for instance). The only things that are
available for non-HTTP requests are:
- - current date/time
- - transaction time
- - number of bytes read and sent
- - local address
- - remote address
- - request attributes
- - server name
Actually, that's quite a bit, but I've never seen an HTTP log that
doesn't log the URI :)
long t2 = System.currentTimeMillis();
long time = t2 - t1;
This isn't your choice, it's in the original code, but why not just do:
long elapsed = System.currentTimeMillis();
...
elapsed = System.currentTimeMillis() - elapsed;
??
Fewer items on the stack, etc.
Except that then it is more difficult to debug. Right? It isn't as easy
to
inspect the value of
the current time if you perform the subtraction without first assigning
the
current time to a
variable.
Fair enough, though debugging this timing code shouldn't really be
required.
private Date getDate() {
// Only create a new Date once per second, max.
long systime = System.currentTimeMillis();
AccessDateStruct struct = currentDateStruct.get();
if ((systime - struct.currentDate.getTime()) 1000) {
struct.currentDate.setTime(systime);
struct.currentDateString = null;
}
return struct.currentDate;
}
I don't understand why this is ThreadLocal, instead of just synchronized
across the object. Maybe it's slightly faster to avoid the
synchronization and just use ThreadLocals, but I'm not sure how many
requests per second a single Thread is going to process, so I'm not
convinced that caching this data is worth the complexity it requires in
this class. I'd love to hear from a Tomcat dev about this.
Tomcat can (hopefully) answer a larger number of requests per second
every year on decently modern hardware. Benchmark it both ways on
a reasonably good/wide machine and you'll see why avoiding the sync
is helpful. I don't think it muddies the code very badly here.
Okay. Certainly avoiding object creation is a good idea, and avoiding
highly-contended synchronization is a good idea, too. I'd like to see a
performance comparison between these strategies, though. Maybe I'll run
one :)
The %b portion of the Combined Log Format is documented to be the size
of
the object returned to the client, not including the response headers.
http://httpd.apache.org/docs/1.3/logs.html#common
Right. Presumably, the Content-Length is synonymous with the above, but
it might not be. Also, Content-Length is not always set, so you'll get a
lot of - written in the log even when response bodies actually has
content. In this implementation, %b is equivalent to
%{Content-Length}o.
Counting bytes isn't that big of a deal, either. I'll submit a patch at
some point... maybe using a different pattern character.
- -chris
-BEGIN PGP SIGNATURE-
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAkuOjCAACgkQ9CaO5/Lv0PAAmgCgt9QVocFjXVNB3t4ib6fWOUIL
++YAoKdpBuT1uhobAIxasRsdw/PaK00e
=zS1q
-END PGP SIGNATURE-
-
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
--
Sincerely yours and Best Regards,
Xie Xiaodong
Re: Access Log /Filter/?
Hello, Christopher,
For log.debug() part, seems I misunderstood your meaning. Sorry about that,
you are right. But I do not think it matters too much. :)
On Wed, Mar 3, 2010 at 5:54 PM, Xie Xiaodong xxd82...@gmail.com wrote:
Hello,
I think log.debug() method should first check current logging levels, or
our code will have those if() {} template everywhere.
I checked java.util.logging.Logger, and found this:
public void log(Level level, String msg, Object param1) {
if (level.intValue() levelValue || levelValue == offValue) {
return;
}
LogRecord lr = new LogRecord(level, msg);
Object params[] = { param1 };
lr.setParameters(params);
doLog(lr);
}
Java 6 hotspot can determine that the StringBuffer synchronization isn't
actually used across threads in many cases, and thus it doesn't bother
synchronizing. Thus, the performance of the two classes becomes identical.
http://www.javalobby.org/java/forums/t88518.html
But it is more secure to not depend on specific jvm version, so it is more
appropriate to use StringBuilder when necessary.
On Wed, Mar 3, 2010 at 5:19 PM, Christopher Schultz
ch...@christopherschultz.net wrote:
-BEGIN PGP SIGNED MESSAGE-
Hash: SHA1
Jason,
On 3/2/2010 7:21 PM, Jason Brittain wrote:
Why does the request have to be an HTTP request in order to have the
access log run?
That does seem to be a bug.
Note that this is not actually a part of the AccessLogValve, it's just
part of Xie's implementation.
By default, the access logger logs the common
log web server
format, but of course it doesn't have to, so it should log non-HTTP
requests
as well, but maybe
only if a non-default pattern is configured?
Fair enough: most of the information you'd want to log is from HTTP
requests (like the URI, for instance). The only things that are
available for non-HTTP requests are:
- - current date/time
- - transaction time
- - number of bytes read and sent
- - local address
- - remote address
- - request attributes
- - server name
Actually, that's quite a bit, but I've never seen an HTTP log that
doesn't log the URI :)
long t2 = System.currentTimeMillis();
long time = t2 - t1;
This isn't your choice, it's in the original code, but why not just do:
long elapsed = System.currentTimeMillis();
...
elapsed = System.currentTimeMillis() - elapsed;
??
Fewer items on the stack, etc.
Except that then it is more difficult to debug. Right? It isn't as
easy to
inspect the value of
the current time if you perform the subtraction without first assigning
the
current time to a
variable.
Fair enough, though debugging this timing code shouldn't really be
required.
private Date getDate() {
// Only create a new Date once per second, max.
long systime = System.currentTimeMillis();
AccessDateStruct struct = currentDateStruct.get();
if ((systime - struct.currentDate.getTime()) 1000) {
struct.currentDate.setTime(systime);
struct.currentDateString = null;
}
return struct.currentDate;
}
I don't understand why this is ThreadLocal, instead of just
synchronized
across the object. Maybe it's slightly faster to avoid the
synchronization and just use ThreadLocals, but I'm not sure how many
requests per second a single Thread is going to process, so I'm not
convinced that caching this data is worth the complexity it requires in
this class. I'd love to hear from a Tomcat dev about this.
Tomcat can (hopefully) answer a larger number of requests per second
every year on decently modern hardware. Benchmark it both ways on
a reasonably good/wide machine and you'll see why avoiding the sync
is helpful. I don't think it muddies the code very badly here.
Okay. Certainly avoiding object creation is a good idea, and avoiding
highly-contended synchronization is a good idea, too. I'd like to see a
performance comparison between these strategies, though. Maybe I'll run
one :)
The %b portion of the Combined Log Format is documented to be the size
of
the object returned to the client, not including the response headers.
http://httpd.apache.org/docs/1.3/logs.html#common
Right. Presumably, the Content-Length is synonymous with the above, but
it might not be. Also, Content-Length is not always set, so you'll get a
lot of - written in the log even when response bodies actually has
content. In this implementation, %b is equivalent to
%{Content-Length}o.
Counting bytes isn't that big of a deal, either. I'll submit a patch at
some point... maybe using a different pattern character.
- -chris
-BEGIN PGP SIGNATURE-
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
iEYEARECAAYFAkuOjCAACgkQ9CaO5/Lv0PAAmgCgt9QVocFjXVNB3t4ib6fWOUIL
++YAoKdpBuT1uhobAIxasRsdw/PaK00e
=zS1q
-END PGP SIGNATURE-
RE: Access Log /Filter/?
From: Xie Xiaodong [mailto:xxd82...@gmail.com] Subject: Re: Access Log /Filter/? http://www.javalobby.org/java/forums/t88518.html I think you're cherry-picking the data. The most useful comment about StringBuilder in that thread was this: Re: StringBuffer Thus, the performance of the two classes becomes identical. Reality is more complicated than that. - You can't rely on latest/hardest optimizations in the HotSpot Client VM, which is the VM you gotta use for most desktop apps, games and others. - Optimizations are not portable. Just because Sun has optimizations X it doesn't mean that IBM, BEA, GCJ etc. (even at the same Java SE level) have it too, and vice-versa. - Optimizations are fragile and difficult to predict. Say you have a StringBuffer that is non-escaping (thus benefits from lock elision etc) because it's a local var of a single method. Now if this method grows too big and you refactor it into multiple smaller, private helper methods, suddenly the StringBuffer is passed from one method to another and it's not anymore a non-escaping local... unless, thanks to inlining or smarter escape analysis, the optimized code can handle it again as non-escaping... but now you're depending on a combination of several optimizations, and it's increasingly difficult (at least for the average developer) to predict the compiler's behavior and to rely on its behavior. Conclusion (for this particular optimization): Using StringBuilder is no more complex than StringBuffer, so there's no excuse to not use it when you now the buffer is unshared. Unlike some other optimizations, this doesn't confuse your code, doesn't create maintenance problems or incur increased development cost. in cases like this - where writing optimal code is just as easy as non-optimal code - I'd optimize since version 0. - Chuck THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Access Log /Filter/?
-BEGIN PGP SIGNED MESSAGE-
Hash: SHA1
Xie,
On 3/3/2010 11:54 AM, Xie Xiaodong wrote:
I think log.debug() method should first check current logging levels, or our
code will have those if() {} template everywhere.
[snip]
For log.debug() part, seems I misunderstood your meaning. Sorry about that,
you are right. But I do not think it matters too much. :)
Well, if were using tricks to avoid synchronization, we probably ought
to avoid four object creations (StringBuilder, char[] in sb, String, and
char[] in s) plus the character-copy operations. This is a filter that
is supposed to avoid performance impact on the webapp: this is such a
cheap optimization, it would be foolish not to do it.
Java 6 hotspot can determine that the StringBuffer synchronization isn't
actually used across threads in many cases, and thus it doesn't bother
synchronizing. Thus, the performance of the two classes becomes identical.
http://www.javalobby.org/java/forums/t88518.html
It's a rough reference from a comment on a blog. Gimmie something I can
really read, not I remember a guy saying once...
Jeremy Manson says this:
A final note. Some people think that there is no performance impact to
using StringBuffer instead of StringBuilder, because of all of the
clever things JVMs do to eliminate synchronization (I can blog about
this, too, if you want). This is a little unclear. Whether it can even
perform these optimizing transformations definitely depends wildly on
which JDK you use; I wrote a microbenchmark to test it, and the results
differed on different JDKs -- but all that microbenchmarks really
demonstrate is the performance of the microbenchmark.
(http://jeremymanson.blogspot.com/2008/08/dont-use-stringbuffer.html
from 24 August 2008)
But it is more secure to not depend on specific jvm version, so it is more
appropriate to use StringBuilder when necessary.
I agree. Using my own microbenchmark (below), these are the results I get:
(On my OpenVZ dev box, Linux 2.6 kernel)
$ java -showversion BufferVsBuilder 1000
java version 1.6.0_12
Java(TM) SE Runtime Environment (build 1.6.0_12-b04)
Java HotSpot(TM) Server VM (build 11.2-b01, mixed mode)
Priming...
Running...
Builder: 24538
Buffer:25745
Overhead: 1657
$ java -showversion BufferVsBuilder 1000
java version 1.6.0_12
Java(TM) SE Runtime Environment (build 1.6.0_12-b04)
Java HotSpot(TM) Server VM (build 11.2-b01, mixed mode)
Priming...
Running...
Builder: 24175
Buffer:25416
Overhead: 1656
(On my laptop, W7 32-bit)
F:\Users\Chris\Desktopjava -showversion BufferVsBuilder 1000
java version 1.6.0_18
Java(TM) SE Runtime Environment (build 1.6.0_18-b07)
Java HotSpot(TM) Client VM (build 16.0-b13, mixed mode, sharing)
Priming...
Running...
Builder: 27507
Buffer:31525
Overhead: 1183
F:\Users\Chris\Desktopjava -showversion BufferVsBuilder 1000
java version 1.6.0_18
Java(TM) SE Runtime Environment (build 1.6.0_18-b07)
Java HotSpot(TM) Client VM (build 16.0-b13, mixed mode, sharing)
Priming...
Running...
Builder: 27339
Buffer:31346
Overhead: 1116
It seems that, in these two environments, StringBuilder outperforms
StringBuffer by a small margin (5% on average in my Linux environment,
13% in my Microsoft Windows environment), but consistently.
It seems that the JVM has to do some work to even determine if the
synchronization can be eliminated before it can actually do it, so why
bother making it do that work in the first place? Avoiding
synchronization is simply the right choice.
- -chris
The code:
public class BufferVsBuilder
{
static long elapsedBuilder = 0;
static long elapsedBuffer = 0;
static long elapsedNothing = 0;
public static void testBuilder(long iterations)
{
long elapsed = System.currentTimeMillis();
for(long i=iterations; i0; --i)
{
StringBuilder sb = new StringBuilder(128);
sb.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
;
}
elapsed = System.currentTimeMillis() - elapsed;
elapsedBuilder += elapsed;
}
public static void testBuffer(long iterations)
{
long elapsed = System.currentTimeMillis();
for(long i=iterations; i0; --i)
{
StringBuffer sb = new StringBuffer(128);
sb.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
.append(some text)
Re: Access Log /Filter/?
-BEGIN PGP SIGNED MESSAGE- Hash: SHA1 Xie, On 2/26/2010 4:33 PM, Xie Xiaodong wrote: No, there is no AccessLogFilter in Tomcat 7 for now. I've got my version of AccessLogFilter during Google Summer Code 2009, but has not yet submit it for some reason. Uh, why not submit it and get paid? Please attach your version so we could discuss it and make an AccessLogFilter in Tomcat 7. I don't have a version, yet. I was checking to see if someone had done it already. But if I give you my code so Google can pay you, I'd like some of that money :) - -chris -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.10 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkuNTeUACgkQ9CaO5/Lv0PCOOwCeM78myOdUfyyHxTTrbQloeb3W Ja8AnA4gDir14UAIIoG9hoc8YcKMEeJ6 =nst1 -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Access Log /Filter/?
Hello, Christopher, I submitted some code but not including the AccessLogFilter since I had something question about the implementation of it. Here I give you the version I wrote last summer. Hope you could check it and submit a patch. On Tue, Mar 2, 2010 at 6:41 PM, Christopher Schultz ch...@christopherschultz.net wrote: -BEGIN PGP SIGNED MESSAGE- Hash: SHA1 Xie, On 2/26/2010 4:33 PM, Xie Xiaodong wrote: No, there is no AccessLogFilter in Tomcat 7 for now. I've got my version of AccessLogFilter during Google Summer Code 2009, but has not yet submit it for some reason. Uh, why not submit it and get paid? Please attach your version so we could discuss it and make an AccessLogFilter in Tomcat 7. I don't have a version, yet. I was checking to see if someone had done it already. But if I give you my code so Google can pay you, I'd like some of that money :) - -chris -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.10 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkuNTeUACgkQ9CaO5/Lv0PCOOwCeM78myOdUfyyHxTTrbQloeb3W Ja8AnA4gDir14UAIIoG9hoc8YcKMEeJ6 =nst1 -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org -- Sincerely yours and Best Regards, Xie Xiaodong - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Access Log /Filter/?
-BEGIN PGP SIGNED MESSAGE- Hash: SHA1 Xie (or is it Xiaodong?), On 3/2/2010 2:57 PM, Xie Xiaodong wrote: I submitted some code but not including the AccessLogFilter since I had something question about the implementation of it. Here I give you the version I wrote last summer. Hope you could check it and submit a patch. Your attachment must have been stripped from the list. Please consider re-posting inline. - -chris -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.10 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkuNeOkACgkQ9CaO5/Lv0PBqXQCfUCrW3JCxOfU7tL1mnuJjwumC oRQAnRKH+Xizgh5iimVvQjq8rGZ1wTte =tCKO -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Access Log /Filter/?
/*
* Licensed to the Apache Software Foundation (ASF) under one or more
* contributor license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright ownership.
* The ASF licenses this file to You under the Apache License, Version 2.0
* (the License); you may not use this file except in compliance with
* the License. You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an AS IS BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package org.apache.catalina.filters;
import java.io.BufferedWriter;
import java.io.File;
import java.io.FileWriter;
import java.io.IOException;
import java.io.PrintWriter;
import java.net.InetAddress;
import java.text.SimpleDateFormat;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Date;
import java.util.Iterator;
import java.util.List;
import java.util.TimeZone;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.Cookie;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import javax.servlet.http.HttpSession;
import org.apache.juli.logging.Log;
import org.apache.juli.logging.LogFactory;
import org.apache.tomcat.util.res.StringManager;
/**
* pImplementation of the bFilter/b interface that generates a web
server
* access log with the detailed line contents matching a configurable
pattern.
* The syntax of the available patterns is similar to that supported by the
* Apache codemod_log_config/code module. As an additional feature,
* automatic rollover of log files when the date changes is also
supported./p
*
* pPatterns for the logged message may include constant text or any of
the
* following replacement strings, for which the corresponding information
* from the specified Response is substituted:/p
* ul
* lib%a/b - Remote IP address
* lib%A/b - Local IP address
* lib%b/b - Bytes sent, excluding HTTP headers, or '-' if no bytes
* were sent
* lib%B/b - Bytes sent, excluding HTTP headers
* lib%h/b - Remote host name
* lib%H/b - Request protocol
* lib%l/b - Remote logical username from identd (always returns '-')
* lib%m/b - Request method
* lib%p/b - Local port
* lib%q/b - Query string (prepended with a '?' if it exists,
otherwise
* an empty string
* lib%r/b - First line of the request
* lib%s/b - HTTP status code of the response
* lib%S/b - User session ID
* lib%t/b - Date and time, in Common Log Format format
* lib%u/b - Remote user that was authenticated
* lib%U/b - Requested URL path
* lib%v/b - Local server name
* lib%D/b - Time taken to process the request, in millis
* lib%T/b - Time taken to process the request, in seconds
* lib%I/b - current Request thread name (can compare later with
stacktraces)
* /ul
* pIn addition, the caller can specify one of the following aliases for
* commonly utilized patterns:/p
* ul
* libcommon/b - code%h %l %u %t %r %s %b/code
* libcombined/b -
* code%h %l %u %t %r %s %b %{Referer}i %{User-Agent}i/code
* /ul
*
* p
* There is also support to write information from the cookie, incoming
* header, the Session or something else in the ServletRequest.br
* It is modeled after the apache syntax:
* ul
* licode%{xxx}i/code for incoming headers
* licode%{xxx}o/code for outgoing response headers
* licode%{xxx}c/code for a specific cookie
* licode%{xxx}r/code xxx is an attribute in the ServletRequest
* licode%{xxx}s/code xxx is an attribute in the HttpSession
* /ul
* /p
*
* p
* Conditional logging is also supported. This can be done with the
* codecondition/code property.
* If the value returned from ServletRequest.getAttribute(condition)
* yields a non-null value. The logging will be skipped.
* /p
*
* @author Craig R. McClanahan
* @author Jason Brittain
* @author Remy Maucherat
* @author Takayuki Kaneko
* @author Peter Rossbach
*
*/
public class AccessLogFilter
extends FilterBase {
private static Log log = LogFactory.getLog(AccessLogFilter.class);
// - Instance
Variables
/**
* The as-of date for the currently open log file, or a zero-length
* string if there is no open log file.
*/
private volatile String dateStamp = ;
/**
* The directory in which log files are created.
*/
private String directory = logs;
/**
* The set of month abbreviations for log messages.
*/
protected static final String months[] =
{ Jan, Feb, Mar, Apr, May, Jun,
Jul, Aug, Sep, Oct, Nov,
Re: Access Log /Filter/?
-BEGIN PGP SIGNED MESSAGE-
Hash: SHA1
Xie,
On 3/2/2010 3:58 PM, Xie Xiaodong wrote:
public class AccessLogFilter
extends FilterBase {
For the most part, you've just replaced the invoke() method with a
doFilter() method and introduced init(), which calls start(). Then, you
removed all the Lifecycle stuff.
How will Filters be configured in TC7? If they will use the same
filter
init-param
...style of configuration, then you'll need to have your init() method
fetch all the init-param values and set those values on the
AccessLogFilter before calling start().
I might just re-name start() to init() and make whatever changes are
necessary.
private static Log log = LogFactory.getLog(AccessLogFilter.class);
Oh, the irony.
public void doFilter(ServletRequest request, ServletResponse response,
FilterChain chain) throws IOException, ServletException {
log.info(In AccessLogFilter doFilter. );
Obviously, you can't have this log message at the INFO level. I'll
assume that all logging currently in the code is for development
purposes and will be removed for a final version.
if (!isHttpServlet(request, response)) {
chain.doFilter(request, response);
return;
}
Why does the request have to be an HTTP request in order to have the
access log run? I would flip the logic around to only do the logging if
the request is an HTTP request, rather than having this mid-method return.
HttpServletRequest httpRequest = ((HttpServletRequest) request);
HttpServletResponse httpResponse = ((HttpServletResponse) response);
if (started getEnabled()) {
// Pass this request on to the next filter in the filterChain
long t1 = System.currentTimeMillis();
chain.doFilter(request, response);
long t2 = System.currentTimeMillis();
long time = t2 - t1;
This isn't your choice, it's in the original code, but why not just do:
long elapsed = System.currentTimeMillis();
...
elapsed = System.currentTimeMillis() - elapsed;
??
Fewer items on the stack, etc.
Date date = getDate();
StringBuffer result = new StringBuffer();
The original default size for the StringBuffer was 128 characters.
Presumably, this was done to avoid the cost of re-sizing the
StringBuffer whenever it grew too large. The default initial capacity of
a StringBuffer is 16 characters, which is almost certainly too small for
a reasonable access log entry. You should put the larger size back in.
While you're at it, use StringBuilder instead to avoid the overhead of
synchronization for an object in a single-threaded environment.
public void log(String message) {
Maybe re-write this method to avoid having to convert from
StringBuffer/StringBuilder to String: why do the work if you don't have to?
private static String lookup(String month) {
int index;
try {
index = Integer.parseInt(month) - 1;
Why not have a dummy month at index 0 and /not/ subtract? Come on...
we're smarter than the Sun engineers, right? 0 = January? Stupid...
private Date getDate() {
// Only create a new Date once per second, max.
long systime = System.currentTimeMillis();
AccessDateStruct struct = currentDateStruct.get();
if ((systime - struct.currentDate.getTime()) 1000) {
struct.currentDate.setTime(systime);
struct.currentDateString = null;
}
return struct.currentDate;
}
I don't understand why this is ThreadLocal, instead of just synchronized
across the object. Maybe it's slightly faster to avoid the
synchronization and just use ThreadLocals, but I'm not sure how many
requests per second a single Thread is going to process, so I'm not
convinced that caching this data is worth the complexity it requires in
this class. I'd love to hear from a Tomcat dev about this.
protected static class ByteSentElement implements AccessLogElement {
private boolean conversion;
/**
* if conversion is true, write '-' instead of 0 - %b
*/
public ByteSentElement(boolean conversion) {
this.conversion = conversion;
}
public void addElement(StringBuffer buf, Date date,
HttpServletRequest request, HttpServletResponse response,
long time) {
long length = 0;
if (response.getHeader(Content-Length) != null
!.equals(response.getHeader(Content-Length))) {
length =
Long.parseLong(response.getHeader(Content-Length));
}
if (length = 0 response.getHeader(content-length) != null
!.equals(response.getHeader(content-length))) {
length =
Long.parseLong(response.getHeader(content-length));
}
if (length = 0 conversion) {
buf.append('-');
} else {
buf.append(length);
}
}
}
Note that this class will only report what was sent with the
Content-Length header, rather than actually counting
Re: Access Log /Filter/?
Thank the comments. I should have rechecked this file before I sent it here.
:)
First, for the init() part: in the super class FilterBase, we have a init()
method which will do the initialization work you mentioned.
Second, you are absolutely right about the log.info(). I first wrote
like this for testing and forgot to get it back to debug level.
In modern jvm, it does not matter much between StringBuffer and
StringBuilder, jvm will change StringBuffer used in single
thread scenario into StringBuilder automaticlly. You could google this
information. There are some benchmark test about it.
I'll check the remaining part tomorrow morning. It is rather late now.
Wish you have a nice day.
Thanks for the comments.
On Tue, Mar 2, 2010 at 11:51 PM, Christopher Schultz
ch...@christopherschultz.net wrote:
-BEGIN PGP SIGNED MESSAGE-
Hash: SHA1
Xie,
On 3/2/2010 3:58 PM, Xie Xiaodong wrote:
public class AccessLogFilter
extends FilterBase {
For the most part, you've just replaced the invoke() method with a
doFilter() method and introduced init(), which calls start(). Then, you
removed all the Lifecycle stuff.
How will Filters be configured in TC7? If they will use the same
filter
init-param
...style of configuration, then you'll need to have your init() method
fetch all the init-param values and set those values on the
AccessLogFilter before calling start().
I might just re-name start() to init() and make whatever changes are
necessary.
private static Log log = LogFactory.getLog(AccessLogFilter.class);
Oh, the irony.
public void doFilter(ServletRequest request, ServletResponse response,
FilterChain chain) throws IOException, ServletException {
log.info(In AccessLogFilter doFilter. );
Obviously, you can't have this log message at the INFO level. I'll
assume that all logging currently in the code is for development
purposes and will be removed for a final version.
if (!isHttpServlet(request, response)) {
chain.doFilter(request, response);
return;
}
Why does the request have to be an HTTP request in order to have the
access log run? I would flip the logic around to only do the logging if
the request is an HTTP request, rather than having this mid-method return.
HttpServletRequest httpRequest = ((HttpServletRequest) request);
HttpServletResponse httpResponse = ((HttpServletResponse) response);
if (started getEnabled()) {
// Pass this request on to the next filter in the filterChain
long t1 = System.currentTimeMillis();
chain.doFilter(request, response);
long t2 = System.currentTimeMillis();
long time = t2 - t1;
This isn't your choice, it's in the original code, but why not just do:
long elapsed = System.currentTimeMillis();
...
elapsed = System.currentTimeMillis() - elapsed;
??
Fewer items on the stack, etc.
Date date = getDate();
StringBuffer result = new StringBuffer();
The original default size for the StringBuffer was 128 characters.
Presumably, this was done to avoid the cost of re-sizing the
StringBuffer whenever it grew too large. The default initial capacity of
a StringBuffer is 16 characters, which is almost certainly too small for
a reasonable access log entry. You should put the larger size back in.
While you're at it, use StringBuilder instead to avoid the overhead of
synchronization for an object in a single-threaded environment.
public void log(String message) {
Maybe re-write this method to avoid having to convert from
StringBuffer/StringBuilder to String: why do the work if you don't have to?
private static String lookup(String month) {
int index;
try {
index = Integer.parseInt(month) - 1;
Why not have a dummy month at index 0 and /not/ subtract? Come on...
we're smarter than the Sun engineers, right? 0 = January? Stupid...
private Date getDate() {
// Only create a new Date once per second, max.
long systime = System.currentTimeMillis();
AccessDateStruct struct = currentDateStruct.get();
if ((systime - struct.currentDate.getTime()) 1000) {
struct.currentDate.setTime(systime);
struct.currentDateString = null;
}
return struct.currentDate;
}
I don't understand why this is ThreadLocal, instead of just synchronized
across the object. Maybe it's slightly faster to avoid the
synchronization and just use ThreadLocals, but I'm not sure how many
requests per second a single Thread is going to process, so I'm not
convinced that caching this data is worth the complexity it requires in
this class. I'd love to hear from a Tomcat dev about this.
protected static class ByteSentElement implements AccessLogElement {
private boolean conversion;
/**
* if conversion is true, write '-' instead of 0 - %b
*/
public ByteSentElement(boolean
Re: Access Log /Filter/?
Hi Christopher.
On Tue, Mar 2, 2010 at 2:51 PM, Christopher Schultz
ch...@christopherschultz.net wrote:
-BEGIN PGP SIGNED MESSAGE-
Hash: SHA1
Xie,
[snip]
if (!isHttpServlet(request, response)) {
chain.doFilter(request, response);
return;
}
Why does the request have to be an HTTP request in order to have the
access log run?
That does seem to be a bug. By default, the access logger logs the common
log web server
format, but of course it doesn't have to, so it should log non-HTTP requests
as well, but maybe
only if a non-default pattern is configured?
long t2 = System.currentTimeMillis();
long time = t2 - t1;
This isn't your choice, it's in the original code, but why not just do:
long elapsed = System.currentTimeMillis();
...
elapsed = System.currentTimeMillis() - elapsed;
??
Fewer items on the stack, etc.
Except that then it is more difficult to debug. Right? It isn't as easy to
inspect the value of
the current time if you perform the subtraction without first assigning the
current time to a
variable.
Date date = getDate();
StringBuffer result = new StringBuffer();
The original default size for the StringBuffer was 128 characters.
Presumably, this was done to avoid the cost of re-sizing the
StringBuffer whenever it grew too large. The default initial capacity of
a StringBuffer is 16 characters, which is almost certainly too small for
a reasonable access log entry. You should put the larger size back in.
While you're at it, use StringBuilder instead to avoid the overhead of
synchronization for an object in a single-threaded environment.
Yes, using StringBuilder would probably make people worry less. :)
public void log(String message) {
Maybe re-write this method to avoid having to convert from
StringBuffer/StringBuilder to String: why do the work if you don't have to?
private static String lookup(String month) {
int index;
try {
index = Integer.parseInt(month) - 1;
Why not have a dummy month at index 0 and /not/ subtract? Come on...
we're smarter than the Sun engineers, right? 0 = January? Stupid...
There might be a small opportunity for optimization/cleanup there.
private Date getDate() {
// Only create a new Date once per second, max.
long systime = System.currentTimeMillis();
AccessDateStruct struct = currentDateStruct.get();
if ((systime - struct.currentDate.getTime()) 1000) {
struct.currentDate.setTime(systime);
struct.currentDateString = null;
}
return struct.currentDate;
}
I don't understand why this is ThreadLocal, instead of just synchronized
across the object. Maybe it's slightly faster to avoid the
synchronization and just use ThreadLocals, but I'm not sure how many
requests per second a single Thread is going to process, so I'm not
convinced that caching this data is worth the complexity it requires in
this class. I'd love to hear from a Tomcat dev about this.
Tomcat can (hopefully) answer a larger number of requests per second
every year on decently modern hardware. Benchmark it both ways on
a reasonably good/wide machine and you'll see why avoiding the sync
is helpful. I don't think it muddies the code very badly here.
protected static class ByteSentElement implements AccessLogElement {
private boolean conversion;
/**
* if conversion is true, write '-' instead of 0 - %b
*/
public ByteSentElement(boolean conversion) {
this.conversion = conversion;
}
public void addElement(StringBuffer buf, Date date,
HttpServletRequest request, HttpServletResponse response,
long time) {
long length = 0;
if (response.getHeader(Content-Length) != null
!.equals(response.getHeader(Content-Length)))
{
length =
Long.parseLong(response.getHeader(Content-Length));
}
if (length = 0 response.getHeader(content-length) !=
null
!.equals(response.getHeader(content-length)))
{
length =
Long.parseLong(response.getHeader(content-length));
}
if (length = 0 conversion) {
buf.append('-');
} else {
buf.append(length);
}
}
}
Note that this class will only report what was sent with the
Content-Length header, rather than actually counting the bytes that were
sent. Fixing this requires an architectural change: the BytesSentElement
must be able to observe the OutputStream/Writer used by the servlet and
count the bytes that were sent.
Also, this method can cause an error if the Content-Type exceeds 2^31-1,
which is bad. :( Why bother parsing the Content-Length in this case?
This leads to another question: if the class is improved to actually
count bytes, how will you
Access Log /Filter/?
-BEGIN PGP SIGNED MESSAGE- Hash: SHA1 All, I just started to write a filter that did request timing logging, and I looked at AccessLogValve for inspiration for how to parse a log pattern and then spit it out for every request. I realized that AccessLogValve can actually do everything I want it to do, already: log request time plus some request attributes. However, I may have occasion to want to /skip/ some of the transaction timing: that is, say, insert it between existing filters. That's not possible (that I know of) for Valves, because they are always before Filters in the pipeline. I believe Tomcat 7 is discarding Valves in favor of using the Filter interface. Is there already in existence an AccessLogFilter? I checked svn and I can see that AccessLogValve is in the 'valves' package, and that there /is/ a 'filters' package but it only has a subset of 'valves' that we've all grown to love. Is this just a class that hasn't been updated for TC7, yet? If so, I'd be happy to do the conversion and submit my code for inclusion. Thanks, - -chris -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.10 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkuIOB8ACgkQ9CaO5/Lv0PCS4ACfQxM/Oe2/4frguG3iKUbY2VmX FEgAn0N7e0FbuvNV5aNt2kSt3SedGCdV =vqsC -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Access Log /Filter/?
Hello, Christopher, No, there is no AccessLogFilter in Tomcat 7 for now. I've got my version of AccessLogFilter during Google Summer Code 2009, but has not yet submit it for some reason. Please attach your version so we could discuss it and make an AccessLogFilter in Tomcat 7. On Fri, Feb 26, 2010 at 10:07 PM, Christopher Schultz ch...@christopherschultz.net wrote: -BEGIN PGP SIGNED MESSAGE- Hash: SHA1 All, I just started to write a filter that did request timing logging, and I looked at AccessLogValve for inspiration for how to parse a log pattern and then spit it out for every request. I realized that AccessLogValve can actually do everything I want it to do, already: log request time plus some request attributes. However, I may have occasion to want to /skip/ some of the transaction timing: that is, say, insert it between existing filters. That's not possible (that I know of) for Valves, because they are always before Filters in the pipeline. I believe Tomcat 7 is discarding Valves in favor of using the Filter interface. Is there already in existence an AccessLogFilter? I checked svn and I can see that AccessLogValve is in the 'valves' package, and that there /is/ a 'filters' package but it only has a subset of 'valves' that we've all grown to love. Is this just a class that hasn't been updated for TC7, yet? If so, I'd be happy to do the conversion and submit my code for inclusion. Thanks, - -chris -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.10 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkuIOB8ACgkQ9CaO5/Lv0PCS4ACfQxM/Oe2/4frguG3iKUbY2VmX FEgAn0N7e0FbuvNV5aNt2kSt3SedGCdV =vqsC -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org -- Sincerely yours and Best Regards, Xie Xiaodong
