Mailing-List: contact users-help@tomcat.apache.org; run by ezmlm
Precedence: bulk
Reply-To: "Tomcat Users List" <users@tomcat.apache.org>
Received-SPF: neutral (nike.apache.org: local policy)
Message-ID: <4B8D9686.60209@christopherschultz.net>
Date: Tue, 02 Mar 2010 17:51:50 -0500
From: Christopher Schultz <chris@christopherschultz.net>
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US;
 rv:1.9.1.8) Gecko/20100216 Thunderbird/3.0.2
MIME-Version: 1.0
To: Tomcat Users List <users@tomcat.apache.org>
Subject: Re: Access Log /Filter/?
References: <4B88381F.3030502@christopherschultz.net>
	 <bb3c6c8d1002261333n70ebcb7am73780b4c07992ba2@mail.gmail.com>
	 <4B8D4DE5.9090508@christopherschultz.net>
	 <bb3c6c8d1003021157w452917e0l5fed0bdc477666ad@mail.gmail.com>
	 <4B8D78E9.9050000@christopherschultz.net>
 <bb3c6c8d1003021258g45e4e57ay908c864d4cf9e5de@mail.gmail.com>
In-Reply-To: <bb3c6c8d1003021258g45e4e57ay908c864d4cf9e5de@mail.gmail.com>
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

-----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 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 count higher than 2^31 - 1?

>     protected AccessLogElement[] createLogElements() {

This method (historical, I know) seems way more complicated than it
really needs to be.

For instance, there's no need to keep a separate "buf" buffer just to
keep track of non-patterned text: just keep an index to the start and
end positions of the text, then create a "StringElement" out of that: no
need to create lots of StringBuffer objects for this.

Also, if desired, it would be almost trivial to create a pluggable
LogElement capability into this class with a set of defaults equal to
the current behavior: instead of using hard-coded switch statements to
determine which pattern letter corresponds to which LogElement class, a
registry could be used which would shorten-up the code a bit, too.

So, those are my thoughts on this class.

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkuNloUACgkQ9CaO5/Lv0PD2IQCgtLggELEMQw8iNYf+gXOnnm9B
3cAAoKZL2qIu+LxsYHUoCC3N1L3cA50s
=aLcF
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org