Collect metrics over lifetime of working copies (#1591)

Capture metrics about the lifetime of working copies used, for example, by the merge and modify commands. Working copies are internal repository clones that can place a large load on the server. Therefore, these metrics can be helpful in identifying sources of large server load.

Co-authored-by: Sebastian Sdorra <sebastian.sdorra@cloudogu.com>

scm-core/src/main/java/sonia/scm/metrics/Metrics.java

@@ -26,6 +26,7 @@ package sonia.scm.metrics;
 
 import io.micrometer.core.instrument.MeterRegistry;
 import io.micrometer.core.instrument.Tag;
+import io.micrometer.core.instrument.Timer;
 import io.micrometer.core.instrument.binder.jvm.ExecutorServiceMetrics;
 
 import java.util.Collections;
@@ -56,4 +57,17 @@ public final class Metrics {
       Collections.singleton(Tag.of("type", type))
     ).bindTo(registry);
   }
+
+  /**
+   * Collect metrics from an {@link sonia.scm.repository.work.WorkingCopy}.
+   *
+   * @param registry meter registry
+   * @param type type of repository
+   */
+  public static Timer workingCopyTimer(MeterRegistry registry, String type) {
+    return Timer.builder("scm.workingcopy.duration")
+      .description("Duration of temporary working copy lifetime")
+      .tags("type", type)
+      .register(registry);
+  }
 }

scm-core/src/main/java/sonia/scm/repository/work/SimpleWorkingCopyFactory.java

@@ -24,8 +24,12 @@
 
 package sonia.scm.repository.work;
 
+import io.micrometer.core.instrument.MeterRegistry;
+import io.micrometer.core.instrument.Timer;
+import io.micrometer.core.instrument.composite.CompositeMeterRegistry;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
+import sonia.scm.metrics.Metrics;
 import sonia.scm.repository.Repository;
 import sonia.scm.repository.RepositoryProvider;
 
@@ -100,9 +104,28 @@ public abstract class SimpleWorkingCopyFactory<R, W, C extends RepositoryProvide
   private static final Logger LOG = LoggerFactory.getLogger(SimpleWorkingCopyFactory.class);
 
   private final WorkingCopyPool workingCopyPool;
+  private final MeterRegistry meterRegistry;
 
+  /**
+   * Constructs a new {@link SimpleWorkingCopyFactory}
+   *
+   * @param workingCopyPool pool which provides working copies
+   * @deprecated since 2.16.0 use {@link SimpleWorkingCopyFactory(WorkingCopyPool, MeterRegistry)} instead
+   */
+  @Deprecated
   public SimpleWorkingCopyFactory(WorkingCopyPool workingCopyPool) {
+    this(workingCopyPool, new CompositeMeterRegistry());
+  }
+
+  /**
+   * Constructs a new {@link SimpleWorkingCopyFactory}
+   *
+   * @param workingCopyPool pool which provides working copies
+   * @param meterRegistry registry to collect metrics
+   */
+  public SimpleWorkingCopyFactory(WorkingCopyPool workingCopyPool, MeterRegistry meterRegistry) {
     this.workingCopyPool = workingCopyPool;
+    this.meterRegistry = meterRegistry;
   }
 
   @Override
@@ -181,10 +204,12 @@ public abstract class SimpleWorkingCopyFactory<R, W, C extends RepositoryProvide
   public class WorkingCopyContext {
     private final String requestedBranch;
     private final C repositoryContext;
+    private final Timer.Sample sample;
 
     public WorkingCopyContext(String requestedBranch, C repositoryContext) {
       this.requestedBranch = requestedBranch;
       this.repositoryContext = repositoryContext;
+      sample = Timer.start(meterRegistry);
     }
 
     public Repository getScmRepository() {
@@ -204,6 +229,14 @@ public abstract class SimpleWorkingCopyFactory<R, W, C extends RepositoryProvide
     }
 
     private void close(ParentAndClone<R, W> parentAndClone) {
+      try {
+        closeResources(parentAndClone);
+      } finally {
+        sample.stop(Metrics.workingCopyTimer(meterRegistry, repositoryContext.get().getType()));
+      }
+    }
+
+    private void closeResources(ParentAndClone<R, W> parentAndClone) {
       try {
         closeWorkingCopy(parentAndClone.getClone());
       } catch (Exception e) {

scm-core/src/test/java/sonia/scm/repository/work/SimpleWorkingCopyFactoryTest.java

@@ -24,6 +24,9 @@
 
 package sonia.scm.repository.work;
 
+import io.micrometer.core.instrument.Meter;
+import io.micrometer.core.instrument.MeterRegistry;
+import io.micrometer.core.instrument.simple.SimpleMeterRegistry;
 import org.junit.Before;
 import org.junit.Rule;
 import org.junit.Test;
@@ -62,8 +65,11 @@ public class SimpleWorkingCopyFactoryTest {
   private boolean workdirIsCached = false;
   private File workdir;
 
+  private MeterRegistry meterRegistry;
+
   @Before
   public void initFactory() throws IOException {
+    meterRegistry = new SimpleMeterRegistry();
     WorkdirProvider workdirProvider = new WorkdirProvider(temporaryFolder.newFolder(), repositoryLocationResolver, false);
     WorkingCopyPool configurableTestWorkingCopyPool = new WorkingCopyPool() {
       @Override
@@ -83,7 +89,7 @@ public class SimpleWorkingCopyFactoryTest {
       public void shutdown() {
       }
     };
-    simpleWorkingCopyFactory = new SimpleWorkingCopyFactory<Closeable, Closeable, Context>(configurableTestWorkingCopyPool) {
+    simpleWorkingCopyFactory = new SimpleWorkingCopyFactory<Closeable, Closeable, Context>(configurableTestWorkingCopyPool, meterRegistry) {
       @Override
       protected void closeRepository(Closeable repository) throws IOException {
         repository.close();
@@ -126,6 +132,10 @@ public class SimpleWorkingCopyFactoryTest {
     try (WorkingCopy<Closeable, Closeable> workingCopy = simpleWorkingCopyFactory.createWorkingCopy(context, null)) {}
 
     verify(parent).close();
+    assertThat(meterRegistry.getMeters()).hasSize(1);
+    Meter.Id meterId = meterRegistry.getMeters().get(0).getId();
+    assertThat(meterId.getName()).isEqualTo("scm.workingcopy.duration");
+    assertThat(meterId.getTag("type")).isEqualTo("git");
   }
 
   @Test
@@ -134,6 +144,10 @@ public class SimpleWorkingCopyFactoryTest {
     try (WorkingCopy<Closeable, Closeable> workingCopy = simpleWorkingCopyFactory.createWorkingCopy(context, null)) {}
 
     verify(clone).close();
+    assertThat(meterRegistry.getMeters()).hasSize(1);
+    Meter.Id meterId = meterRegistry.getMeters().get(0).getId();
+    assertThat(meterId.getName()).isEqualTo("scm.workingcopy.duration");
+    assertThat(meterId.getTag("type")).isEqualTo("git");
   }
 
   @Test