You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomcat.apache.org by Takayuki Kaneko <ka...@gmail.com> on 2007/01/05 06:09:21 UTC

new access log valve implementation

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.

Is this beneficial?

Thanks.

-Takayuki

Re: new access log valve implementation

Posted by Remy Maucherat <re...@apache.org>.
Robert McKay wrote:
> non-blocking write()

???
Ok, so you get to point out where a non blocking write is made in 
AccessLogValve.

Personally, I think it would be wise to consider upgrading certain 
components of your system, starting with the OS and the JVM.

Rémy

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


Re: new access log valve implementation

Posted by Yoav Shapira <yo...@apache.org>.
Hi,

On 1/5/07, Robert McKay <ro...@mckay.com> wrote:
> On 1/5/07, Takayuki Kaneko <ka...@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.

Takayuki, thanks for your contribution.

> > Is this beneficial?
>
> Always nice to have options :)
>
> Robert.

It's also nice to have unbloated software.  We don't need three Valves
that do the same thing, and actually we shouldn't even need two: one
should suffice.  Maybe it's Takayuki's  new one.   If it weren't for
some insistent users (with decent reasons), I'd argue for scrapping
this Valve altogether in favor of a Filter.

Yoav

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


Re: new access log valve implementation

Posted by Robert McKay <ro...@mckay.com>.
On 1/5/07, Takayuki Kaneko <ka...@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


Re: new access log valve implementation

Posted by Mladen Turk <mt...@apache.org>.
Takayuki Kaneko wrote:
> 
> Is this beneficial?
>

I doubt.
The same could be done by simply
buffering the log and then flushing to the disk on overflow.
Is it beneficial? No, its misleading, because you
will never know if your log data is the correct one
or there is something in the write buffer waiting to be
written to the log file.

Regards,
Mladen.

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


Re: new access log valve implementation

Posted by Remy Maucherat <re...@apache.org>.
Peter Rossbach wrote:
> Good news,
> 
> please, open a bug report with the a AccessLogValve patch.

It looks good enough to me right now. Now there's the question of 
potentially replacing the other access log valves, since it provides a 
superset of the functionality (the other valves - except the 
ExtendedAccessLogValve for now - could become empty classes which extend 
this new valve, to provide compatibility).

Rémy

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


Re: new access log valve implementation

Posted by Peter Rossbach <pr...@objektpark.de>.
Good news,

please, open a bug report with the a AccessLogValve patch.

Thanks
Peter


Am 06.01.2007 um 09:00 schrieb Takayuki Kaneko:

> Hi,
>
> I modified AccessLogValve in about five points.
>
> 1) use buffering like FastCommonAccessLogValve
> 2) generate the date character string on each 1000ms like
> FastCommonAccessLogValve
> 3) move the parsing pattern into the initail phase, it was executed on
> each requst
> 4) manage "common" and "combine" and any pattern by the same flow
> 5) remove DecimalFormat because it isn't threadsafe
>
> On 1/5/07, Mladen Turk <mt...@apache.org> wrote:
>> The same could be done by simply
>> buffering the log and then flushing to the disk on overflow.
>
> Yeah, I think buffering has the most impact for the performance.
> So, I implemented 1).
>
> But I think 2) and 3) has the bigger impact under the high load.
> It was ludicrous to process same things many times.
>
> On 1/5/07, Yoav Shapira <yo...@apache.org> wrote:
>> It's also nice to have unbloated software.  We don't need three  
>> Valves
>> that do the same thing, and actually we shouldn't even need two: one
>> should suffice.  Maybe it's Takayuki's  new one.
>
> I'd like to integrate these Valves, too.
> But my modification was a little big, so I made it as another Valves.
>
> I think my Valve has the same function AccessLogValve has.
> I will make a patch on the trunk of AccessLogValve if you want.
>
> On 1/5/07, Remy Maucherat <re...@apache.org> wrote:
>> Not bad, the pattern processing is very cheap (that's the only  
>> addition,
>> basically), so it's the same performance as the fast valve. I like  
>> it.
>
> I appreciate your comment.
>
> Thanks,
>
> -Takayuki
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: dev-help@tomcat.apache.org
>
>


Re: new access log valve implementation

Posted by Takayuki Kaneko <ka...@gmail.com>.
Hi,

I modified AccessLogValve in about five points.

1) use buffering like FastCommonAccessLogValve
2) generate the date character string on each 1000ms like
FastCommonAccessLogValve
3) move the parsing pattern into the initail phase, it was executed on
each requst
4) manage "common" and "combine" and any pattern by the same flow
5) remove DecimalFormat because it isn't threadsafe

On 1/5/07, Mladen Turk <mt...@apache.org> wrote:
> The same could be done by simply
> buffering the log and then flushing to the disk on overflow.

Yeah, I think buffering has the most impact for the performance.
So, I implemented 1).

But I think 2) and 3) has the bigger impact under the high load.
It was ludicrous to process same things many times.

On 1/5/07, Yoav Shapira <yo...@apache.org> wrote:
> It's also nice to have unbloated software.  We don't need three Valves
> that do the same thing, and actually we shouldn't even need two: one
> should suffice.  Maybe it's Takayuki's  new one.

I'd like to integrate these Valves, too.
But my modification was a little big, so I made it as another Valves.

I think my Valve has the same function AccessLogValve has.
I will make a patch on the trunk of AccessLogValve if you want.

On 1/5/07, Remy Maucherat <re...@apache.org> wrote:
> Not bad, the pattern processing is very cheap (that's the only addition,
> basically), so it's the same performance as the fast valve. I like it.

I appreciate your comment.

Thanks,

-Takayuki

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


Re: new access log valve implementation

Posted by Remy Maucherat <re...@apache.org>.
Takayuki Kaneko wrote:
> So, I made the new one.

Not bad, the pattern processing is very cheap (that's the only addition, 
basically), so it's the same performance as the fast valve. I like it.

Rémy


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