You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@archiva.apache.org by br...@apache.org on 2010/12/06 16:56:36 UTC
svn commit: r1042689 - in /archiva/branches/archiva-1.3.x/archiva-modules:
archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/
archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/rep...
Author: brett
Date: Mon Dec 6 15:56:35 2010
New Revision: 1042689
URL: http://svn.apache.org/viewvc?rev=1042689&view=rev
Log:
[MRM-1442] track time spent in each consumer during a scan, to help diagnose poor scanning performance
Modified:
archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/RepositoryScanStatistics.java
archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/RepositoryScannerInstance.java
archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/functors/ConsumerProcessFileClosure.java
archiva/branches/archiva-1.3.x/archiva-modules/archiva-web/archiva-webapp/src/main/webapp/WEB-INF/jsp/admin/systemStatus.jsp
Modified: archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/RepositoryScanStatistics.java
URL: http://svn.apache.org/viewvc/archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/RepositoryScanStatistics.java?rev=1042689&r1=1042688&r2=1042689&view=diff
==============================================================================
--- archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/RepositoryScanStatistics.java (original)
+++ archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/RepositoryScanStatistics.java Mon Dec 6 15:56:35 2010
@@ -25,6 +25,7 @@ import org.apache.maven.archiva.model.Re
import java.text.SimpleDateFormat;
import java.util.List;
+import java.util.Map;
/**
* RepositoryScanStatistics - extension to the RepositoryContentStatistics model.
@@ -42,6 +43,10 @@ public class RepositoryScanStatistics
private SimpleDateFormat df = new SimpleDateFormat();
+ private Map<String, Long> consumerCounts;
+
+ private Map<String, Long> consumerTimings;
+
public void triggerStart()
{
startTimestamp = System.currentTimeMillis();
@@ -94,6 +99,17 @@ public class RepositoryScanStatistics
for ( String id : knownConsumers )
{
buf.append( "\n " ).append( id );
+ if ( consumerTimings.containsKey( id ) )
+ {
+ long time = consumerTimings.get( id );
+ buf.append( " (Total: " ).append( time ).append( "ms" );
+ if ( consumerCounts.containsKey( id ) )
+ {
+ long total = consumerCounts.get( id );
+ buf.append( "; Avg.: " + ( time / total ) + "; Count: " + total );
+ }
+ buf.append( ")" );
+ }
}
}
else
@@ -108,6 +124,17 @@ public class RepositoryScanStatistics
for ( String id : invalidConsumers )
{
buf.append( "\n " ).append( id );
+ if ( consumerTimings.containsKey( id ) )
+ {
+ long time = consumerTimings.get( id );
+ buf.append( " (Total: " ).append( time ).append( "ms" );
+ if ( consumerCounts.containsKey( id ) )
+ {
+ long total = consumerCounts.get( id );
+ buf.append( "; Avg.: " + ( time / total ) + "ms; Count: " + total );
+ }
+ buf.append( ")" );
+ }
}
}
else
@@ -142,4 +169,14 @@ public class RepositoryScanStatistics
return buf.toString();
}
+
+ public void setConsumerCounts( Map<String, Long> consumerCounts )
+ {
+ this.consumerCounts = consumerCounts;
+ }
+
+ public void setConsumerTimings( Map<String, Long> consumerTimings )
+ {
+ this.consumerTimings = consumerTimings;
+ }
}
Modified: archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/RepositoryScannerInstance.java
URL: http://svn.apache.org/viewvc/archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/RepositoryScannerInstance.java?rev=1042689&r1=1042688&r2=1042689&view=diff
==============================================================================
--- archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/RepositoryScannerInstance.java (original)
+++ archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/RepositoryScannerInstance.java Mon Dec 6 15:56:35 2010
@@ -21,7 +21,9 @@ package org.apache.maven.archiva.reposit
import java.io.File;
import java.util.Date;
+import java.util.HashMap;
import java.util.List;
+import java.util.Map;
import org.apache.archiva.repository.scanner.functors.TriggerScanCompletedClosure;
import org.apache.commons.collections.Closure;
@@ -32,6 +34,7 @@ import org.apache.maven.archiva.common.u
import org.apache.maven.archiva.configuration.ManagedRepositoryConfiguration;
import org.apache.maven.archiva.consumers.InvalidRepositoryContentConsumer;
import org.apache.maven.archiva.consumers.KnownRepositoryContentConsumer;
+import org.apache.maven.archiva.consumers.RepositoryContentConsumer;
import org.apache.maven.archiva.repository.scanner.functors.ConsumerProcessFileClosure;
import org.apache.maven.archiva.repository.scanner.functors.ConsumerWantsFilePredicate;
import org.apache.maven.archiva.repository.scanner.functors.TriggerBeginScanClosure;
@@ -68,6 +71,10 @@ public class RepositoryScannerInstance
private ConsumerWantsFilePredicate consumerWantsFile;
+ private Map<String, Long> consumerTimings;
+
+ private Map<String, Long> consumerCounts;
+
public RepositoryScannerInstance( ManagedRepositoryConfiguration repository,
List<KnownRepositoryContentConsumer> knownConsumerList,
List<InvalidRepositoryContentConsumer> invalidConsumerList )
@@ -76,7 +83,14 @@ public class RepositoryScannerInstance
this.knownConsumers = knownConsumerList;
this.invalidConsumers = invalidConsumerList;
+ consumerTimings = new HashMap<String,Long>();
+ consumerCounts = new HashMap<String,Long>();
+
this.consumerProcessFile = new ConsumerProcessFileClosure();
+ consumerProcessFile.setExecuteOnEntireRepo( true );
+ consumerProcessFile.setConsumerTimings( consumerTimings );
+ consumerProcessFile.setConsumerCounts( consumerCounts );
+
this.consumerWantsFile = new ConsumerWantsFilePredicate();
stats = new RepositoryScanStatistics();
@@ -109,6 +123,16 @@ public class RepositoryScannerInstance
return stats;
}
+ public Map<String, Long> getConsumerTimings()
+ {
+ return consumerTimings;
+ }
+
+ public Map<String, Long> getConsumerCounts()
+ {
+ return consumerCounts;
+ }
+
public void directoryWalkStarting( File basedir )
{
log.info( "Walk Started: [" + this.repository.getId() + "] " + this.repository.getLocation() );
@@ -123,20 +147,19 @@ public class RepositoryScannerInstance
// consume files regardless - the predicate will check the timestamp
BaseFile basefile = new BaseFile( repository.getLocation(), file );
-
+
// Timestamp finished points to the last successful scan, not this current one.
if ( file.lastModified() >= changesSince )
{
- stats.increaseNewFileCount();
+ stats.increaseNewFileCount();
}
-
+
consumerProcessFile.setBasefile( basefile );
- consumerProcessFile.setExecuteOnEntireRepo( true );
consumerWantsFile.setBasefile( basefile );
-
+
Closure processIfWanted = IfClosure.getInstance( consumerWantsFile, consumerProcessFile );
CollectionUtils.forAllDo( this.knownConsumers, processIfWanted );
-
+
if ( consumerWantsFile.getWantedFileCount() <= 0 )
{
// Nothing known processed this file. It is invalid!
@@ -150,6 +173,9 @@ public class RepositoryScannerInstance
CollectionUtils.forAllDo( knownConsumers, scanCompletedClosure );
CollectionUtils.forAllDo( invalidConsumers, scanCompletedClosure );
+
+ stats.setConsumerTimings( consumerTimings );
+ stats.setConsumerCounts( consumerCounts );
log.info( "Walk Finished: [" + this.repository.getId() + "] " + this.repository.getLocation() );
stats.triggerFinished();
Modified: archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/functors/ConsumerProcessFileClosure.java
URL: http://svn.apache.org/viewvc/archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/functors/ConsumerProcessFileClosure.java?rev=1042689&r1=1042688&r2=1042689&view=diff
==============================================================================
--- archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/functors/ConsumerProcessFileClosure.java (original)
+++ archiva/branches/archiva-1.3.x/archiva-modules/archiva-base/archiva-repository-layer/src/main/java/org/apache/maven/archiva/repository/scanner/functors/ConsumerProcessFileClosure.java Mon Dec 6 15:56:35 2010
@@ -25,6 +25,9 @@ import org.apache.maven.archiva.consumer
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
+import java.util.HashMap;
+import java.util.Map;
+
/**
* ConsumerProcessFileClosure
*
@@ -39,24 +42,43 @@ public class ConsumerProcessFileClosure
private boolean executeOnEntireRepo;
+ private Map<String,Long> consumerTimings;
+
+ private Map<String,Long> consumerCounts;
+
public void execute( Object input )
{
if ( input instanceof RepositoryContentConsumer )
{
RepositoryContentConsumer consumer = (RepositoryContentConsumer) input;
+ String id = consumer.getId();
try
{
- log.debug( "Sending to consumer: " + consumer.getId() );
+ log.debug( "Sending to consumer: " + id );
+ long startTime = System.currentTimeMillis();
consumer.processFile( basefile.getRelativePath(), executeOnEntireRepo );
+ long endTime = System.currentTimeMillis();
+
+ if ( consumerTimings != null )
+ {
+ Long value = consumerTimings.get( id );
+ consumerTimings.put( id, ( value != null ? value : 0 ) + endTime - startTime );
+ }
+
+ if ( consumerCounts != null )
+ {
+ Long value = consumerCounts.get( id );
+ consumerCounts.put( id, ( value != null ? value : 0 ) + 1 );
+ }
}
catch ( Exception e )
{
/* Intentionally Catch all exceptions.
* So that the discoverer processing can continue.
*/
- log.error( "Consumer [" + consumer.getId() + "] had an error when processing file ["
+ log.error( "Consumer [" + id + "] had an error when processing file ["
+ basefile.getAbsolutePath() + "]: " + e.getMessage(), e );
}
}
@@ -82,6 +104,16 @@ public class ConsumerProcessFileClosure
this.executeOnEntireRepo = executeOnEntireRepo;
}
+ public void setConsumerTimings( Map<String, Long> consumerTimings )
+ {
+ this.consumerTimings = consumerTimings;
+ }
+
+ public void setConsumerCounts( Map<String, Long> consumerCounts )
+ {
+ this.consumerCounts = consumerCounts;
+ }
+
public Logger getLogger()
{
return log;
Modified: archiva/branches/archiva-1.3.x/archiva-modules/archiva-web/archiva-webapp/src/main/webapp/WEB-INF/jsp/admin/systemStatus.jsp
URL: http://svn.apache.org/viewvc/archiva/branches/archiva-1.3.x/archiva-modules/archiva-web/archiva-webapp/src/main/webapp/WEB-INF/jsp/admin/systemStatus.jsp?rev=1042689&r1=1042688&r2=1042689&view=diff
==============================================================================
--- archiva/branches/archiva-1.3.x/archiva-modules/archiva-web/archiva-webapp/src/main/webapp/WEB-INF/jsp/admin/systemStatus.jsp (original)
+++ archiva/branches/archiva-1.3.x/archiva-modules/archiva-web/archiva-webapp/src/main/webapp/WEB-INF/jsp/admin/systemStatus.jsp Mon Dec 6 15:56:35 2010
@@ -49,7 +49,7 @@
<c:set var="queue" value="${queueEntry.value.queueSnapshot}"/>
<tr>
<td>${queueEntry.key}</td>
- <td>${fn:length(queue)}</td>
+ <td align="right">${fn:length(queue)}</td>
</tr>
</c:forEach>
</table>
@@ -67,8 +67,29 @@
<c:forEach var="scan" items="${scanner.inProgressScans}">
<tr>
<td>${scan.repository.name} (${scan.repository.id})</td>
- <td>${scan.stats.totalFileCount}</td>
- <td>${scan.stats.newFileCount}</td>
+ <td align="right">${scan.stats.totalFileCount}</td>
+ <td align="right">${scan.stats.newFileCount}</td>
+ </tr>
+ <tr>
+ <td colspan="3">
+ <table>
+ <tr>
+ <th>Name</th>
+ <th>Total</th>
+ <th>Average</th>
+ <th>Invocations</th>
+ </tr>
+ <c:forEach var="entry" items="${scan.consumerTimings}">
+ <tr>
+ <c:set var="total" value="${scan.consumerCounts[entry.key]}"/>
+ <td>${entry.key}</td>
+ <td align="right">${entry.value}ms</td>
+ <td align="right"><fmt:formatNumber value="${entry.value / total}" pattern="#"/>ms</td>
+ <td align="right">${total}</td>
+ </tr>
+ </c:forEach>
+ </table>
+ </td>
</tr>
</c:forEach>
</table>
@@ -92,10 +113,10 @@
<c:forEach var="cacheEntry" items="${caches}">
<tr>
<td>${cacheEntry.key}</td>
- <td>${cacheEntry.value.statistics.size}</td>
- <td>${cacheEntry.value.statistics.cacheHits}</td>
- <td>${cacheEntry.value.statistics.cacheMiss}</td>
- <td><fmt:formatNumber value="${cacheEntry.value.statistics.cacheHitRate}" pattern="#%"/></td>
+ <td align="right">${cacheEntry.value.statistics.size}</td>
+ <td align="right">${cacheEntry.value.statistics.cacheHits}</td>
+ <td align="right">${cacheEntry.value.statistics.cacheMiss}</td>
+ <td align="right"><fmt:formatNumber value="${cacheEntry.value.statistics.cacheHitRate}" pattern="#%"/></td>
<td><a href="javascript:alert('Not yet implemented')">Flush</a></td>
</tr>
</c:forEach>