tomcat-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Robert McKay" <rob...@mckay.com>
Subject Re: new access log valve implementation
Date Fri, 05 Jan 2007 11:23:37 GMT
On 1/5/07, Takayuki Kaneko <kanekotky@gmail.com> wrote:
> Hi Tomcat developers,
>
> I made 'FastAccessLogValve' that was modified and tuned based on AccessLogValve.
> It can output any log element specified by the pattern string like
> AccessLogValve.
> And it is as fast as FastCommonAccessLogValve.
>
> I made a quick test program. It outputs the access log using valves.
> And it can specify the number of count and threads.
>
> Here are the results of the test with 1000 count x 10 threads.
>
> C:\newaccesslog>test 1000 10
> AccessLogValve's elapsed Time is 688 msec.
> AccessLogValve's elapsed Time is 547 msec.
> AccessLogValve's elapsed Time is 906 msec.
> FastCommonAccessLogValve's elapsed Time is 344 msec.
> FastCommonAccessLogValve's elapsed Time is 265 msec.
> FastCommonAccessLogValve's elapsed Time is 344 msec.
> FastAccessLogValve's elapsed Time is 313 msec.
> FastAccessLogValve's elapsed Time is 313 msec.
> FastAccessLogValve's elapsed Time is 312 msec.
>
> Actually, I really want to output the processing time by using %D pattern.
> But AccessLogValve was slower than FastCommonAccessLogValve.
> So, I made the new one.

I had a very nasty problem recently with AccessLogValve and NFS
because it uses small (one log line message), non-blocking write()
calls. NFS always would return the write() call with 0 bytes written -
I think this is because it assumes that if it gets a small nonbocking
write and returns right away that it may get a larger write later and
it can save a round trip on the network if it waits for the larger
write buffer to come along. This was on solaris 9 by the way.

The problem (I think) is that because of the Valve system a larger
write is not forthcoming. With AccessLogValve even if there is loads
of log data building up behind the valve it keeps hammering out the
exact same small write() for the one log message that has been allowed
through the valve. This never succeeds and the process slows to a
crawl as almost all of it's time is spent attempting to write out the
same log message over and over.

The FastCommonAccessLogValve appeared to fix this issue although I
must admit I didn't really delve into what it was doing but I assume
it's buffered log writing results in larger write() calls that make
NFS happy. Unfortunately I don't have an identical test environment
(this happened in production) or I'd try your logger and see if it has
this issue or not.

> Is this beneficial?

Always nice to have options :)

Robert.

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


Mime
View raw message