You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@directory.apache.org by el...@apache.org on 2010/05/08 18:00:25 UTC
svn commit: r942408 - in
/directory/apacheds/trunk/core/src/main/java/org/apache/directory/server/core/logger:
./ TimerInterceptor.java
Author: elecharny
Date: Sat May 8 16:00:24 2010
New Revision: 942408
URL: http://svn.apache.org/viewvc?rev=942408&view=rev
Log:
Added a Timer interceptor that can be used to get some information about operations duration.
Added:
directory/apacheds/trunk/core/src/main/java/org/apache/directory/server/core/logger/
directory/apacheds/trunk/core/src/main/java/org/apache/directory/server/core/logger/TimerInterceptor.java
Added: directory/apacheds/trunk/core/src/main/java/org/apache/directory/server/core/logger/TimerInterceptor.java
URL: http://svn.apache.org/viewvc/directory/apacheds/trunk/core/src/main/java/org/apache/directory/server/core/logger/TimerInterceptor.java?rev=942408&view=auto
==============================================================================
--- directory/apacheds/trunk/core/src/main/java/org/apache/directory/server/core/logger/TimerInterceptor.java (added)
+++ directory/apacheds/trunk/core/src/main/java/org/apache/directory/server/core/logger/TimerInterceptor.java Sat May 8 16:00:24 2010
@@ -0,0 +1,749 @@
+/*
+ * 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.directory.server.core.logger;
+
+import java.util.Set;
+import java.util.concurrent.atomic.AtomicInteger;
+import java.util.concurrent.atomic.AtomicLong;
+
+import org.apache.directory.server.core.DirectoryService;
+import org.apache.directory.server.core.entry.ClonedServerEntry;
+import org.apache.directory.server.core.filtering.EntryFilteringCursor;
+import org.apache.directory.server.core.interceptor.Interceptor;
+import org.apache.directory.server.core.interceptor.NextInterceptor;
+import org.apache.directory.server.core.interceptor.context.AddContextPartitionOperationContext;
+import org.apache.directory.server.core.interceptor.context.AddOperationContext;
+import org.apache.directory.server.core.interceptor.context.BindOperationContext;
+import org.apache.directory.server.core.interceptor.context.CompareOperationContext;
+import org.apache.directory.server.core.interceptor.context.DeleteOperationContext;
+import org.apache.directory.server.core.interceptor.context.EntryOperationContext;
+import org.apache.directory.server.core.interceptor.context.GetMatchedNameOperationContext;
+import org.apache.directory.server.core.interceptor.context.GetRootDSEOperationContext;
+import org.apache.directory.server.core.interceptor.context.GetSuffixOperationContext;
+import org.apache.directory.server.core.interceptor.context.ListOperationContext;
+import org.apache.directory.server.core.interceptor.context.ListSuffixOperationContext;
+import org.apache.directory.server.core.interceptor.context.LookupOperationContext;
+import org.apache.directory.server.core.interceptor.context.ModifyOperationContext;
+import org.apache.directory.server.core.interceptor.context.MoveAndRenameOperationContext;
+import org.apache.directory.server.core.interceptor.context.MoveOperationContext;
+import org.apache.directory.server.core.interceptor.context.RemoveContextPartitionOperationContext;
+import org.apache.directory.server.core.interceptor.context.RenameOperationContext;
+import org.apache.directory.server.core.interceptor.context.SearchOperationContext;
+import org.apache.directory.server.core.interceptor.context.UnbindOperationContext;
+import org.apache.directory.shared.ldap.entry.Entry;
+import org.apache.directory.shared.ldap.name.DN;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+/**
+ * An interceptor used to log times to process each operation.
+ *
+ * The way it works is that it gathers the time to process an operation
+ * into a global counter, which is logged every 1000 operations (when
+ * using the OPERATION_STATS logger). It's also possible to get the time for
+ * each single operation if activating the OPERATION_TIME logger.
+ *
+ * Thos two loggers must be set to DEBUG.
+ *
+ * @author <a href="mailto:dev@directory.apache.org">Apache Directory Project</a>
+ * @version $Rev$, $Date$
+ */
+public class TimerInterceptor implements Interceptor
+{
+ /** A aggregating logger */
+ private static final Logger OPERATION_STATS = LoggerFactory.getLogger( "OPERATION_STATS" );
+
+ /** An operation logger */
+ private static final Logger OPERATION_TIME = LoggerFactory.getLogger( "OPERATION_TIME" );
+
+ /** Speedup for logs */
+ private static final boolean IS_DEBUG_STATS = OPERATION_STATS.isDebugEnabled();
+ private static final boolean IS_DEBUG_TIME = OPERATION_TIME.isDebugEnabled();
+
+ /** The Logger's name */
+ private String name;
+
+ /** Stats for the add operation */
+ private static AtomicLong totalAdd = new AtomicLong( 0 );
+ private static AtomicInteger nbAddCalls = new AtomicInteger( 0 );
+
+ /** Stats for the AddContextPartition operation */
+ private static AtomicLong totalAddContextPartition = new AtomicLong( 0 );
+ private static AtomicInteger nbAddContextPartitionCalls = new AtomicInteger( 0 );
+
+ /** Stats for the bind operation */
+ private static AtomicLong totalBind = new AtomicLong( 0 );
+ private static AtomicInteger nbBindCalls = new AtomicInteger( 0 );
+
+ /** Stats for the compare operation */
+ private static AtomicLong totalCompare = new AtomicLong( 0 );
+ private static AtomicInteger nbCompareCalls = new AtomicInteger( 0 );
+
+ /** Stats for the delete operation */
+ private static AtomicLong totalDelete = new AtomicLong( 0 );
+ private static AtomicInteger nbDeleteCalls = new AtomicInteger( 0 );
+
+ /** Stats for the GetMatchedName operation */
+ private static AtomicLong totalGetMatchedName = new AtomicLong( 0 );
+ private static AtomicInteger nbGetMatchedNameCalls = new AtomicInteger( 0 );
+
+ /** Stats for the GetRootDSE operation */
+ private static AtomicLong totalGetRootDSE = new AtomicLong( 0 );
+ private static AtomicInteger nbGetRootDSECalls = new AtomicInteger( 0 );
+
+ /** Stats for the GetSuffix operation */
+ private static AtomicLong totalGetSuffix = new AtomicLong( 0 );
+ private static AtomicInteger nbGetSuffixCalls = new AtomicInteger( 0 );
+
+ /** Stats for the HasEntry operation */
+ private static AtomicLong totalHasEntry = new AtomicLong( 0 );
+ private static AtomicInteger nbHasEntryCalls = new AtomicInteger( 0 );
+
+ /** Stats for the list operation */
+ private static AtomicLong totalList = new AtomicLong( 0 );
+ private static AtomicInteger nbListCalls = new AtomicInteger( 0 );
+
+ /** Stats for the ListSuffixes operation */
+ private static AtomicLong totalListSuffixes = new AtomicLong( 0 );
+ private static AtomicInteger nbListSuffixesCalls = new AtomicInteger( 0 );
+
+ /** Stats for the lookup operation */
+ private static AtomicLong totalLookup = new AtomicLong( 0 );
+ private static AtomicInteger nbLookupCalls = new AtomicInteger( 0 );
+
+ /** Stats for the modify operation */
+ private static AtomicLong totalModify = new AtomicLong( 0 );
+ private static AtomicInteger nbModifyCalls = new AtomicInteger( 0 );
+
+ /** Stats for the move operation */
+ private static AtomicLong totalMove = new AtomicLong( 0 );
+ private static AtomicInteger nbMoveCalls = new AtomicInteger( 0 );
+
+ /** Stats for the moveAndRename operation */
+ private static AtomicLong totalMoveAndRename = new AtomicLong( 0 );
+ private static AtomicInteger nbMoveAndRenameCalls = new AtomicInteger( 0 );
+
+ /** Stats for the RemoveContextPartition operation */
+ private static AtomicLong totalRemoveContextPartition = new AtomicLong( 0 );
+ private static AtomicInteger nbRemoveContextPartitionCalls = new AtomicInteger( 0 );
+
+ /** Stats for the rename operation */
+ private static AtomicLong totalRename = new AtomicLong( 0 );
+ private static AtomicInteger nbRenameCalls = new AtomicInteger( 0 );
+
+ /** Stats for the search operation */
+ private static AtomicLong totalSearch = new AtomicLong( 0 );
+ private static AtomicInteger nbSearchCalls = new AtomicInteger( 0 );
+
+ /** Stats for the unbind operation */
+ private static AtomicLong totalUnbind = new AtomicLong( 0 );
+ private static AtomicInteger nbUnbindCalls = new AtomicInteger( 0 );
+
+ /**
+ *
+ * Creates a new instance of TimerInterceptor.
+ *
+ * @param name This interceptor's name
+ */
+ public TimerInterceptor( String name )
+ {
+ this.name = name;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void add( NextInterceptor next, AddOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ next.add( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbAddCalls.incrementAndGet();
+ totalAdd.getAndAdd( delta );
+
+ if ( nbAddCalls.get() % 1000 == 0 )
+ {
+ long average = totalAdd.get()/(nbAddCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average add = {} microseconds, nb adds = {}", average, nbAddCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta add = {}", name, delta );
+ }
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void addContextPartition( NextInterceptor next, AddContextPartitionOperationContext opContext )
+ throws Exception
+ {
+ long t0 = System.nanoTime();
+ next.addContextPartition( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbAddContextPartitionCalls.incrementAndGet();
+ totalAddContextPartition.getAndAdd( delta );
+
+ if ( nbAddContextPartitionCalls.get() % 1000 == 0 )
+ {
+ long average = totalAddContextPartition.get()/(nbAddContextPartitionCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average addContextPartition = {} microseconds, nb addContextPartitions = {}", average, nbAddContextPartitionCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta add = {}", name, delta );
+ }
+
+ System.out.println( "{} : Delta addContextPartition = " + delta );
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void bind( NextInterceptor next, BindOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ next.bind( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbBindCalls.incrementAndGet();
+ totalBind.getAndAdd( delta );
+
+ if ( nbBindCalls.get() % 1000 == 0 )
+ {
+ long average = totalBind.get()/(nbBindCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average bind = {} microseconds, nb binds = {}", average, nbBindCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta bind = {}", name, delta );
+ }
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public boolean compare( NextInterceptor next, CompareOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ boolean compare = next.compare( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbCompareCalls.incrementAndGet();
+ totalCompare.getAndAdd( delta );
+
+ if ( nbCompareCalls.get() % 1000 == 0 )
+ {
+ long average = totalCompare.get()/(nbCompareCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average compare = {} microseconds, nb compares = {}", average, nbCompareCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta compare = {}", name, delta );
+ }
+
+ return compare;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void delete( NextInterceptor next, DeleteOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ next.delete( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbDeleteCalls.incrementAndGet();
+ totalDelete.getAndAdd( delta );
+
+ if ( nbDeleteCalls.get() % 1000 == 0 )
+ {
+ long average = totalDelete.get()/(nbDeleteCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average delete = {} microseconds, nb deletes = {}", average, nbDeleteCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta delete = {}", name, delta );
+ }
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void destroy()
+ {
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public String getName()
+ {
+ return name;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public ClonedServerEntry getRootDSE( NextInterceptor next, GetRootDSEOperationContext opContext )
+ throws Exception
+ {
+ long t0 = System.nanoTime();
+ Entry rootDSE = next.getRootDSE( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbGetRootDSECalls.incrementAndGet();
+ totalGetRootDSE.getAndAdd( delta );
+
+ if ( nbGetRootDSECalls.get() % 1000 == 0 )
+ {
+ long average = totalGetRootDSE.get()/(nbGetRootDSECalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average getRootDSE = {} microseconds, nb getRootDSEs = {}", average, nbGetRootDSECalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta getRootDSE = {}", name, delta );
+ }
+
+ return (ClonedServerEntry)rootDSE;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public boolean hasEntry( NextInterceptor next, EntryOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ boolean hasEntry = next.hasEntry( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbHasEntryCalls.incrementAndGet();
+ totalHasEntry.getAndAdd( delta );
+
+ if ( nbHasEntryCalls.get() % 1000 == 0 )
+ {
+ long average = totalHasEntry.get()/(nbHasEntryCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average hasEntry = {} microseconds, nb hasEntrys = {}", average, nbHasEntryCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta hasEntry = {}", name, delta );
+ }
+
+ return hasEntry;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void init( DirectoryService directoryService ) throws Exception
+ {
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public EntryFilteringCursor list( NextInterceptor next, ListOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ EntryFilteringCursor cursor = next.list( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbListCalls.incrementAndGet();
+ totalList.getAndAdd( delta );
+
+ if ( nbListCalls.get() % 1000 == 0 )
+ {
+ long average = totalList.get()/(nbListCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average list = {} microseconds, nb lists = {}", average, nbListCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta list = {}", name, delta );
+ }
+
+ return cursor;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public Entry lookup( NextInterceptor next, LookupOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ Entry entry = next.lookup( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbLookupCalls.incrementAndGet();
+ totalLookup.getAndAdd( delta );
+
+ if ( nbLookupCalls.get() % 1000 == 0 )
+ {
+ long average = totalLookup.get()/(nbLookupCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average lookup = {} microseconds, nb lookups = {}", average, nbLookupCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta lookup = {}", name, delta );
+ }
+
+ return entry;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void modify( NextInterceptor next, ModifyOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ next.modify( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbModifyCalls.incrementAndGet();
+ totalModify.getAndAdd( delta );
+
+ if ( nbModifyCalls.get() % 1000 == 0 )
+ {
+ long average = totalModify.get()/(nbModifyCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average modify = {} microseconds, nb modifys = {}", average, nbModifyCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta modify = {}", name, delta );
+ }
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void move( NextInterceptor next, MoveOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ next.move( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbMoveCalls.incrementAndGet();
+ totalMove.getAndAdd( delta );
+
+ if ( nbMoveCalls.get() % 1000 == 0 )
+ {
+ long average = totalMove.get()/(nbMoveCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average move = {} microseconds, nb moves = {}", average, nbMoveCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta move = {}", name, delta );
+ }
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void moveAndRename( NextInterceptor next, MoveAndRenameOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ next.moveAndRename( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbMoveAndRenameCalls.incrementAndGet();
+ totalMoveAndRename.getAndAdd( delta );
+
+ if ( nbMoveAndRenameCalls.get() % 1000 == 0 )
+ {
+ long average = totalMoveAndRename.get()/(nbMoveAndRenameCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average moveAndRename = {} microseconds, nb moveAndRenames = {}", average, nbMoveAndRenameCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta moveAndRename = {}", name, delta );
+ }
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void rename( NextInterceptor next, RenameOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ next.rename( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbRenameCalls.incrementAndGet();
+ totalRename.getAndAdd( delta );
+
+ if ( nbRenameCalls.get() % 1000 == 0 )
+ {
+ long average = totalRename.get()/(nbRenameCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average rename = {} microseconds, nb renames = {}", average, nbRenameCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta rename = {}", name, delta );
+ }
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public EntryFilteringCursor search( NextInterceptor next, SearchOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ EntryFilteringCursor cursor = next.search( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbSearchCalls.incrementAndGet();
+ totalSearch.getAndAdd( delta );
+
+ if ( nbSearchCalls.get() % 1000 == 0 )
+ {
+ long average = totalSearch.get()/(nbSearchCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average search = {} microseconds, nb searches = {}", average, nbSearchCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta search = {}", name, delta );
+ }
+
+ return cursor;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void unbind( NextInterceptor next, UnbindOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ next.unbind( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbUnbindCalls.incrementAndGet();
+ totalUnbind.getAndAdd( delta );
+
+ if ( nbUnbindCalls.get() % 1000 == 0 )
+ {
+ long average = totalUnbind.get()/(nbUnbindCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average unbind = {} microseconds, nb unbinds = {}", average, nbUnbindCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta unbind = {}", name, delta );
+ }
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public DN getMatchedName( NextInterceptor next, GetMatchedNameOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ DN dn = next.getMatchedName( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbGetMatchedNameCalls.incrementAndGet();
+ totalGetMatchedName.getAndAdd( delta );
+
+ if ( nbGetMatchedNameCalls.get() % 1000 == 0 )
+ {
+ long average = totalGetMatchedName.get()/(nbGetMatchedNameCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average getMatchedName = {} microseconds, nb getMatchedNames = {}", average, nbGetMatchedNameCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta getMatchedName = {}", name, delta );
+ }
+
+ return dn;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public DN getSuffix( NextInterceptor next, GetSuffixOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ DN dn = next.getSuffix( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbGetSuffixCalls.incrementAndGet();
+ totalGetSuffix.getAndAdd( delta );
+
+ if ( nbGetSuffixCalls.get() % 1000 == 0 )
+ {
+ long average = totalGetSuffix.get()/(nbGetSuffixCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average getSuffix = {} microseconds, nb getSuffixes = {}", average, nbGetSuffixCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta getSuffix = {}", name, delta );
+ }
+
+ return dn;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public Set<String> listSuffixes( NextInterceptor next, ListSuffixOperationContext opContext ) throws Exception
+ {
+ long t0 = System.nanoTime();
+ Set<String> suffixes = next.listSuffixes( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbListSuffixesCalls.incrementAndGet();
+ totalListSuffixes.getAndAdd( delta );
+
+ if ( nbListSuffixesCalls.get() % 1000 == 0 )
+ {
+ long average = totalListSuffixes.get()/(nbListSuffixesCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average listSuffixes = {} microseconds, nb listSuffixes = {}", average, nbListSuffixesCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta listSuffixes = {}", name, delta );
+ }
+
+ return suffixes;
+ }
+
+
+ /**
+ * {@inheritDoc}
+ */
+ public void removeContextPartition( NextInterceptor next, RemoveContextPartitionOperationContext opContext )
+ throws Exception
+ {
+ long t0 = System.nanoTime();
+ next.removeContextPartition( opContext );
+ long delta = System.nanoTime() - t0;
+
+ if ( IS_DEBUG_STATS )
+ {
+ nbRemoveContextPartitionCalls.incrementAndGet();
+ totalRemoveContextPartition.getAndAdd( delta );
+
+ if ( nbRemoveContextPartitionCalls.get() % 1000 == 0 )
+ {
+ long average = totalRemoveContextPartition.get()/(nbRemoveContextPartitionCalls.get() * 1000);
+ OPERATION_STATS.debug( name + " : Average removeContextPartition = {} microseconds, nb removeContextPartitions = {}", average, nbRemoveContextPartitionCalls.get() );
+ }
+ }
+
+ if ( IS_DEBUG_TIME )
+ {
+ OPERATION_TIME.debug( "{} : Delta removeContextPartition = {}", name, delta );
+ }
+ }
+}