directory-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Alex Karasulu <akaras...@apache.org>
Subject Re: Operation timing in logs
Date Thu, 16 May 2013 16:36:34 GMT
Hmm this is neat and could be pretty damn useful.

What about making this happen using a request control? Meaning if an
operation is issued with the TRACE request control then turn on the
production and output to the logs of such trace information? The control is
a simple marker control. This would reduce the amount of noise and logging
overhead if your'e interested in specific operations.

What would be uber bad-assery would be to collect this information and
report it not only in the logs but to return it in a buffer with a response
control. This makes sense to inspect production system issues that are
misbehaving without a shutdown.

Another idea in leu or in addition would be to enable some parameters in
the configuration that could hot enable/disable this feature.

In both cases, you would not have to shutdown the server and would still
have fine grained control over the quantity of logs produced with trace
information.

Just some thoughts.



On Thu, May 16, 2013 at 2:28 PM, Pierre-Arnaud Marcelot <pa@marcelot.net>wrote:

> Hi Emmanuel,
>
> That's an interesting option.
>
> Regards,
> Pierre-Arnaud
>
> On 8 mai 2013, at 12:48, Emmanuel L├ęcharny <elecharny@gmail.com> wrote:
>
> > Hi guys,
> >
> > FYI, I have added some timing for each operation. This is not activated
> > by default you have to modify the log4j.properties to get it :
> >
> > log4j.logger.org.apache.directory.server.OPERATION_TIME=DEBUG
> >
> > will produces such logs :
> >
> > [12:41:28] DEBUG [org.apache.directory.server.OPERATION_TIME] - Add
> > operation took 28404000 ns
> > [12:41:28] DEBUG [org.apache.directory.server.OPERATION_TIME] - Lookup
> > operation took 500000 ns
> > [12:41:28] DEBUG [org.apache.directory.server.OPERATION_TIME] - Lookup
> > operation took 278000 ns
> > [12:41:28] DEBUG [org.apache.directory.server.OPERATION_TIME] - Lookup
> > operation took 590000 ns
> > [12:41:28] DEBUG [org.apache.directory.server.OPERATION_TIME] - Bind
> > operation took 7820000 ns
> > [12:41:28] DEBUG [org.apache.directory.server.OPERATION_TIME] - Unbind
> > operation took 81000 ns
> > [12:41:28] DEBUG [org.apache.directory.server.OPERATION_TIME] - Lookup
> > operation took 305000 ns
> > [12:41:28] DEBUG [org.apache.directory.server.OPERATION_TIME] - Bind
> > operation took 94000 ns
> > [12:41:28] DEBUG [org.apache.directory.server.OPERATION_TIME] - Unbind
> > operation took 22000 ns
> > ...
> >
> > This could be useful for gathering the operation and tell how much time
> > it took to process eah operation.
> >
> > I'm considering offering more information, like the specific operation,
> > but this would be much verbose.
> >
> > I will commit that soon.
> >
> > --
> > Regards,
> > Cordialement,
> > Emmanuel L├ęcharny
> > www.iktek.com
> >
>
>


-- 
Best Regards,
-- Alex

Mime
View raw message