add some StopWatch to get time on what happened here

git-svn-id: https://svn.apache.org/repos/asf/archiva/trunk@1423874 13f79535-47bb-0310-9956-ffa450edef68

5 files changed, 70 insertions, 23 deletions

diff --git a/archiva-modules/archiva-scheduler/archiva-scheduler-repository/src/main/java/org/apache/archiva/scheduler/repository/DefaultRepositoryArchivaTaskScheduler.java b/archiva-modules/archiva-scheduler/archiva-scheduler-repository/src/main/java/org/apache/archiva/scheduler/repository/DefaultRepositoryArchivaTaskScheduler.java
index bb031cf3e..1fc88a9be 100644
--- a/archiva-modules/archiva-scheduler/archiva-scheduler-repository/src/main/java/org/apache/archiva/scheduler/repository/DefaultRepositoryArchivaTaskScheduler.java
+++ b/archiva-modules/archiva-scheduler/archiva-scheduler-repository/src/main/java/org/apache/archiva/scheduler/repository/DefaultRepositoryArchivaTaskScheduler.java
@@ -35,6 +35,7 @@ import org.apache.archiva.redback.components.taskqueue.TaskQueue;
 import org.apache.archiva.redback.components.taskqueue.TaskQueueException;
 import org.apache.archiva.scheduler.repository.model.RepositoryArchivaTaskScheduler;
 import org.apache.archiva.scheduler.repository.model.RepositoryTask;
+import org.apache.commons.lang.time.StopWatch;
 import org.quartz.SchedulerException;
 import org.quartz.impl.JobDetailImpl;
 import org.quartz.impl.triggers.CronTriggerImpl;
@@ -55,7 +56,7 @@ import java.util.Set;
 /**
  * Default implementation of a scheduling component for archiva.
  */
-@Service ("archivaTaskScheduler#repository")
+@Service("archivaTaskScheduler#repository")
 public class DefaultRepositoryArchivaTaskScheduler
     implements RepositoryArchivaTaskScheduler, ConfigurationListener
 {
@@ -74,7 +75,7 @@ public class DefaultRepositoryArchivaTaskScheduler
      *
      */
     @Inject
-    @Named (value = "taskQueue#repository-scanning")
+    @Named(value = "taskQueue#repository-scanning")
     private TaskQueue repositoryScanningQueue;
 
     /**
@@ -87,7 +88,7 @@ public class DefaultRepositoryArchivaTaskScheduler
      *
      */
     @Inject
-    @Named (value = "repositoryStatisticsManager#default")
+    @Named(value = "repositoryStatisticsManager#default")
     private RepositoryStatisticsManager repositoryStatisticsManager;
 
     /**
@@ -116,6 +117,10 @@ public class DefaultRepositoryArchivaTaskScheduler
     public void startup()
         throws ArchivaException
     {
+
+        StopWatch stopWatch = new StopWatch();
+        stopWatch.start();
+
         archivaConfiguration.addListener( this );
 
         List<ManagedRepositoryConfiguration> repositories =
@@ -158,6 +163,8 @@ public class DefaultRepositoryArchivaTaskScheduler
             repositorySession.close();
         }
 
+        stopWatch.stop();
+        log.info( "Time to initalize DefaultRepositoryArchivaTaskScheduler: {} ms", stopWatch.getTime() );
     }
 
 
@@ -174,7 +181,7 @@ public class DefaultRepositoryArchivaTaskScheduler
 
     }
 
-    @SuppressWarnings ("unchecked")
+    @SuppressWarnings("unchecked")
     public boolean isProcessingRepositoryTask( String repositoryId )
     {
         synchronized ( repositoryScanningQueue )
@@ -298,7 +305,6 @@ public class DefaultRepositoryArchivaTaskScheduler
         }
     }
 
-    @SuppressWarnings ("unchecked")
     private boolean isPreviouslyScanned( ManagedRepositoryConfiguration repoConfig,
                                          MetadataRepository metadataRepository )
         throws MetadataRepositoryException
diff --git a/archiva-modules/archiva-web/archiva-webapp-js/src/test/tomcat/log4j2-test.xml b/archiva-modules/archiva-web/archiva-webapp-js/src/test/tomcat/log4j2-test.xml
index fe93856d3..ee5a09b0a 100644
--- a/archiva-modules/archiva-web/archiva-webapp-js/src/test/tomcat/log4j2-test.xml
+++ b/archiva-modules/archiva-web/archiva-webapp-js/src/test/tomcat/log4j2-test.xml
@@ -20,12 +20,38 @@
 
 
 <configuration status="debug">
+
+  <properties>
+    <property name="logsDirectory">${sys:appserver.base}/logs</property>
+  </properties>
+
   <appenders>
     <Console name="console" target="SYSTEM_OUT">
       <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
     </Console>
+
+    <!--RollingFile name="console" fileName="${logsDirectory}/archiva.log"
+                 filePattern="${logsDirectory}/archiva-%d{MM-dd-yyyy}.log">
+      <PatternLayout>
+        <pattern>%d [%t] %-5p %c %x - %m%n</pattern>
+      </PatternLayout>
+      <Policies>
+        <TimeBasedTriggeringPolicy />
+      </Policies>
+    </RollingFile-->
+
   </appenders>
   <loggers>
+
+    <!-- apache httpclient debug content transfer-->
+    <!--
+    <logger name="org.apache.http.wire">
+      <level value="debug"/>
+    </logger>
+    <logger name="org.apache.http.headers" level="debug"/>
+    -->
+
+
     <logger name="org.apache.archiva.indexer.search.MavenRepositorySearch" level="info"/>
 
     <logger name="org.apache.archiva.common.plexusbridge.MavenIndexerUtils" level="info"/>
@@ -38,16 +64,6 @@
 
     <logger name="org.apache.archiva.admin.repository.managed" level="info"/>
 
-
-    <!-- apache httpclient debug content transfer-->
-    <!--
-    <logger name="org.apache.http.wire">
-      <level value="debug"/>
-    </logger>
-    -->
-    <logger name="org.apache.http.headers" level="debug"/>
-
-
     <logger name="org.springframework" level="info"/>
 
 
@@ -63,6 +79,8 @@
 
     <logger name="org.apache.archiva.indexer.merger" level="info"/>
 
+    <logger name="org.apache.archiva.metadata.repository.stats.DefaultRepositoryStatisticsManager" level="debug" />
+
     <root level="info">
       <appender-ref ref="console"/>
     </root>
diff --git a/archiva-modules/plugins/metadata-store-jcr/src/main/java/org/apache/archiva/metadata/repository/jcr/JcrMetadataRepository.java b/archiva-modules/plugins/metadata-store-jcr/src/main/java/org/apache/archiva/metadata/repository/jcr/JcrMetadataRepository.java
index 46655b901..a53a176f2 100644
--- a/archiva-modules/plugins/metadata-store-jcr/src/main/java/org/apache/archiva/metadata/repository/jcr/JcrMetadataRepository.java
+++ b/archiva-modules/plugins/metadata-store-jcr/src/main/java/org/apache/archiva/metadata/repository/jcr/JcrMetadataRepository.java
@@ -75,6 +75,7 @@ import java.util.Set;
 public class JcrMetadataRepository
     implements MetadataRepository
 {
+
     private static final String JCR_LAST_MODIFIED = "jcr:lastModified";
 
     static final String NAMESPACE_NODE_TYPE = "archiva:namespace";
@@ -108,6 +109,7 @@ public class JcrMetadataRepository
     static void initialize( Session session )
         throws RepositoryException
     {
+
         // TODO: consider using namespaces for facets instead of the current approach:
         // (if used, check if actually called by normal injection)
 //        for ( String facetId : metadataFacetFactories.keySet() )
@@ -130,6 +132,7 @@ public class JcrMetadataRepository
         registerMixinNodeType( nodeTypeManager, JcrMetadataRepository.ARTIFACT_NODE_TYPE );
         registerMixinNodeType( nodeTypeManager, JcrMetadataRepository.FACET_NODE_TYPE );
         registerMixinNodeType( nodeTypeManager, JcrMetadataRepository.DEPENDENCY_NODE_TYPE );
+
     }
 
     private static void registerMixinNodeType( NodeTypeManager nodeTypeManager, String name )
diff --git a/archiva-modules/plugins/metadata-store-jcr/src/main/java/org/apache/archiva/metadata/repository/jcr/JcrRepositorySessionFactory.java b/archiva-modules/plugins/metadata-store-jcr/src/main/java/org/apache/archiva/metadata/repository/jcr/JcrRepositorySessionFactory.java
index 5f9fde8e5..2f41d4d6f 100644
--- a/archiva-modules/plugins/metadata-store-jcr/src/main/java/org/apache/archiva/metadata/repository/jcr/JcrRepositorySessionFactory.java
+++ b/archiva-modules/plugins/metadata-store-jcr/src/main/java/org/apache/archiva/metadata/repository/jcr/JcrRepositorySessionFactory.java
@@ -25,6 +25,9 @@ import org.apache.archiva.metadata.repository.MetadataResolver;
 import org.apache.archiva.metadata.repository.RepositorySession;
 import org.apache.archiva.metadata.repository.RepositorySessionFactory;
 import org.apache.commons.lang.StringUtils;
+import org.apache.commons.lang.time.StopWatch;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import org.springframework.context.ApplicationContext;
 import org.springframework.stereotype.Service;
 
@@ -38,11 +41,13 @@ import java.util.Map;
 /**
  *
  */
-@Service( "repositorySessionFactory#jcr" )
+@Service("repositorySessionFactory#jcr")
 public class JcrRepositorySessionFactory
     implements RepositorySessionFactory
 {
 
+    private Logger logger = LoggerFactory.getLogger( getClass() );
+
     @Inject
     private ApplicationContext applicationContext;
 
@@ -87,6 +92,9 @@ public class JcrRepositorySessionFactory
     public void initialize()
         throws Exception
     {
+        StopWatch stopWatch = new StopWatch();
+        stopWatch.start();
+
         metadataFacetFactories = applicationContext.getBeansOfType( MetadataFacetFactory.class );
         // olamy with spring the "id" is now "metadataFacetFactory#hint"
         // whereas was only hint with plexus so let remove  metadataFacetFactory#
@@ -118,5 +126,8 @@ public class JcrRepositorySessionFactory
                 metadataRepository.close();
             }
         }
+
+        stopWatch.stop();
+        logger.info( "time to initialize JcrRepositorySessionFactory: {}", stopWatch.getTime() );
     }
 }
diff --git a/archiva-modules/plugins/repository-statistics/src/main/java/org/apache/archiva/metadata/repository/stats/DefaultRepositoryStatisticsManager.java b/archiva-modules/plugins/repository-statistics/src/main/java/org/apache/archiva/metadata/repository/stats/DefaultRepositoryStatisticsManager.java
index f87414adc..f75a53147 100644
--- a/archiva-modules/plugins/repository-statistics/src/main/java/org/apache/archiva/metadata/repository/stats/DefaultRepositoryStatisticsManager.java
+++ b/archiva-modules/plugins/repository-statistics/src/main/java/org/apache/archiva/metadata/repository/stats/DefaultRepositoryStatisticsManager.java
@@ -24,6 +24,7 @@ import org.apache.archiva.metadata.model.maven2.MavenArtifactFacet;
 import org.apache.archiva.metadata.repository.MetadataRepository;
 import org.apache.archiva.metadata.repository.MetadataRepositoryException;
 import org.apache.archiva.metadata.repository.MetadataResolutionException;
+import org.apache.commons.lang.time.StopWatch;
 import org.apache.jackrabbit.commons.JcrUtils;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
@@ -61,9 +62,11 @@ public class DefaultRepositoryStatisticsManager
     public RepositoryStatistics getLastStatistics( MetadataRepository metadataRepository, String repositoryId )
         throws MetadataRepositoryException
     {
+        StopWatch stopWatch = new StopWatch();
+        stopWatch.start();
         // TODO: consider a more efficient implementation that directly gets the last one from the content repository
         List<String> scans = metadataRepository.getMetadataFacets( repositoryId, RepositoryStatistics.FACET_ID );
-        if (scans == null)
+        if ( scans == null )
         {
             return null;
         }
@@ -71,8 +74,12 @@ public class DefaultRepositoryStatisticsManager
         if ( !scans.isEmpty() )
         {
             String name = scans.get( scans.size() - 1 );
-            return (RepositoryStatistics) metadataRepository.getMetadataFacet( repositoryId,
-                                                                               RepositoryStatistics.FACET_ID, name );
+            RepositoryStatistics repositoryStatistics =
+                (RepositoryStatistics) metadataRepository.getMetadataFacet( repositoryId, RepositoryStatistics.FACET_ID,
+                                                                            name );
+            stopWatch.stop();
+            log.debug( "time to find last RepositoryStatistics: {} ms", stopWatch.getTime() );
+            return repositoryStatistics;
         }
         else
         {
@@ -105,8 +112,8 @@ public class DefaultRepositoryStatisticsManager
                         stats.setTotalArtifactCount( stats.getTotalArtifactCount() + 1 );
                         stats.setTotalArtifactFileSize( stats.getTotalArtifactFileSize() + artifact.getSize() );
 
-                        MavenArtifactFacet facet = (MavenArtifactFacet) artifact.getFacet(
-                            MavenArtifactFacet.FACET_ID );
+                        MavenArtifactFacet facet =
+                            (MavenArtifactFacet) artifact.getFacet( MavenArtifactFacet.FACET_ID );
                         if ( facet != null )
                         {
                             String type = facet.getType();
@@ -268,8 +275,10 @@ public class DefaultRepositoryStatisticsManager
                 if ( ( startTime == null || !date.before( startTime ) ) && ( endTime == null || !date.after(
                     endTime ) ) )
                 {
-                    RepositoryStatistics stats = (RepositoryStatistics) metadataRepository.getMetadataFacet(
-                        repositoryId, RepositoryStatistics.FACET_ID, name );
+                    RepositoryStatistics stats =
+                        (RepositoryStatistics) metadataRepository.getMetadataFacet( repositoryId,
+                                                                                    RepositoryStatistics.FACET_ID,
+                                                                                    name );
                     results.add( stats );
                 }
             }