SONAR-4756 Use platform profiling in MeasureFilter

Use BASIC level for request/result profiling
Use FULL level for SQL request execution profiling

3 files changed, 31 insertions, 40 deletions

diff --git a/sonar-core/src/main/java/org/sonar/core/measure/MeasureFilterEngine.java b/sonar-core/src/main/java/org/sonar/core/measure/MeasureFilterEngine.java
index e1804d5af24..540e450d38b 100644
--- a/sonar-core/src/main/java/org/sonar/core/measure/MeasureFilterEngine.java
+++ b/sonar-core/src/main/java/org/sonar/core/measure/MeasureFilterEngine.java
@@ -19,12 +19,14 @@
  */
 package org.sonar.core.measure;
 
-import com.google.common.annotations.VisibleForTesting;
 import com.google.common.base.Joiner;
 import org.apache.commons.lang.SystemUtils;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 import org.sonar.api.ServerComponent;
+import org.sonar.core.profiling.Profiling;
+import org.sonar.core.profiling.Profiling.Level;
+import org.sonar.core.profiling.StopWatch;
 
 import javax.annotation.Nullable;
 
@@ -33,50 +35,49 @@ import java.util.Map;
 
 public class MeasureFilterEngine implements ServerComponent {
 
+  private static final Logger LOG = LoggerFactory.getLogger("org.sonar.MEASURE_FILTER");
+
   private final MeasureFilterFactory factory;
   private final MeasureFilterExecutor executor;
+  private final Profiling profiling;
 
-
-  public MeasureFilterEngine(MeasureFilterFactory factory, MeasureFilterExecutor executor) {
+  public MeasureFilterEngine(MeasureFilterFactory factory, MeasureFilterExecutor executor, Profiling profiling) {
     this.executor = executor;
     this.factory = factory;
+    this.profiling = profiling;
   }
 
   public MeasureFilterResult execute(Map<String, Object> filterMap, @Nullable Long userId) {
-    return execute(filterMap, userId, LoggerFactory.getLogger("org.sonar.MEASURE_FILTER"));
-  }
-
-  @VisibleForTesting
-  MeasureFilterResult execute(Map<String, Object> filterMap, @Nullable Long userId, Logger logger) {
-    long start = System.currentTimeMillis();
+    StopWatch watch = profiling.start("measures", Level.BASIC);
+    StopWatch sqlWatch = null;
     MeasureFilterResult result = new MeasureFilterResult();
     MeasureFilterContext context = new MeasureFilterContext();
     context.setUserId(userId);
     context.setData(String.format("{%s}", Joiner.on('|').withKeyValueSeparator("=").join(filterMap)));
     try {
       MeasureFilter filter = factory.create(filterMap);
+      sqlWatch = profiling.start("sql", Level.FULL);
       List<MeasureFilterRow> rows = executor.execute(filter, context);
       result.setRows(rows);
-      log(context, result, logger);
 
     } catch (Exception e) {
       result.setError(MeasureFilterResult.Error.UNKNOWN);
-      logger.error("Fail to execute measure filter: " + context, e);
+      LOG.error("Fail to execute measure filter: " + context, e);
     } finally {
-      result.setDurationInMs(System.currentTimeMillis() - start);
+      if (sqlWatch != null) {
+        sqlWatch.stop(context.getSql());
+      }
+      watch.stop(log(context, result));
     }
     return result;
   }
 
-  private void log(MeasureFilterContext context, MeasureFilterResult result, Logger logger) {
-    if (logger.isDebugEnabled()) {
-      StringBuilder log = new StringBuilder();
-      log.append(SystemUtils.LINE_SEPARATOR);
-      log.append("request: ").append(context.getData()).append(SystemUtils.LINE_SEPARATOR);
-      log.append(" result: ").append(result.toString()).append(SystemUtils.LINE_SEPARATOR);
-      log.append("    sql: ").append(context.getSql()).append(SystemUtils.LINE_SEPARATOR);
-      logger.debug(log.toString());
-    }
+  private String log(MeasureFilterContext context, MeasureFilterResult result) {
+    StringBuilder log = new StringBuilder();
+    log.append(SystemUtils.LINE_SEPARATOR);
+    log.append("request: ").append(context.getData()).append(SystemUtils.LINE_SEPARATOR);
+    log.append(" result: ").append(result.toString());
+    return log.toString();
   }
 
 }
diff --git a/sonar-core/src/main/java/org/sonar/core/measure/MeasureFilterResult.java b/sonar-core/src/main/java/org/sonar/core/measure/MeasureFilterResult.java
index 6e4a2f59bfe..63f42c790f9 100644
--- a/sonar-core/src/main/java/org/sonar/core/measure/MeasureFilterResult.java
+++ b/sonar-core/src/main/java/org/sonar/core/measure/MeasureFilterResult.java
@@ -31,7 +31,6 @@ public class MeasureFilterResult {
 
   private List<MeasureFilterRow> rows = null;
   private Error error = null;
-  private long durationInMs;
 
   MeasureFilterResult() {
   }
@@ -44,15 +43,6 @@ public class MeasureFilterResult {
     return error;
   }
 
-  public long getDurationInMs() {
-    return durationInMs;
-  }
-
-  MeasureFilterResult setDurationInMs(long l) {
-    this.durationInMs = l;
-    return this;
-  }
-
   MeasureFilterResult setRows(@Nullable List<MeasureFilterRow> rows) {
     this.rows = rows;
     return this;
@@ -76,7 +66,6 @@ public class MeasureFilterResult {
     if (error != null) {
       sb.append("error=").append(error).append(", ");
     }
-    sb.append(durationInMs).append("ms");
     return sb.toString();
   }
 }
diff --git a/sonar-core/src/test/java/org/sonar/core/measure/MeasureFilterEngineTest.java b/sonar-core/src/test/java/org/sonar/core/measure/MeasureFilterEngineTest.java
index a0260309e8e..409f46cf994 100644
--- a/sonar-core/src/test/java/org/sonar/core/measure/MeasureFilterEngineTest.java
+++ b/sonar-core/src/test/java/org/sonar/core/measure/MeasureFilterEngineTest.java
@@ -23,13 +23,17 @@ import com.google.common.collect.ImmutableMap;
 import org.hamcrest.BaseMatcher;
 import org.hamcrest.Description;
 import org.junit.Test;
-import org.slf4j.Logger;
+import org.sonar.api.config.Settings;
+import org.sonar.core.profiling.Profiling;
 
 import java.util.Map;
 
 import static org.fest.assertions.Assertions.assertThat;
 import static org.mockito.Matchers.argThat;
-import static org.mockito.Mockito.*;
+import static org.mockito.Matchers.refEq;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.when;
 
 public class MeasureFilterEngineTest {
 
@@ -40,13 +44,11 @@ public class MeasureFilterEngineTest {
     MeasureFilter filter = new MeasureFilter();
     when(factory.create(filterMap)).thenReturn(filter);
     MeasureFilterExecutor executor = mock(MeasureFilterExecutor.class);
-    Logger logger = mock(Logger.class);
-    when(logger.isDebugEnabled()).thenReturn(true);
 
-    MeasureFilterEngine engine = new MeasureFilterEngine(factory, executor);
+    MeasureFilterEngine engine = new MeasureFilterEngine(factory, executor, new Profiling(new Settings()));
 
     final long userId = 50L;
-    engine.execute(filterMap, userId, logger);
+    engine.execute(filterMap, userId);
     verify(executor).execute(refEq(filter), argThat(new BaseMatcher<MeasureFilterContext>() {
       public boolean matches(Object o) {
         MeasureFilterContext context = (MeasureFilterContext) o;
@@ -56,7 +58,6 @@ public class MeasureFilterEngineTest {
       public void describeTo(Description description) {
       }
     }));
-    verify(logger).debug(anyString());
   }
 
   @Test
@@ -66,7 +67,7 @@ public class MeasureFilterEngineTest {
     when(factory.create(filterMap)).thenThrow(new IllegalArgumentException());
     MeasureFilterExecutor executor = mock(MeasureFilterExecutor.class);
 
-    MeasureFilterEngine engine = new MeasureFilterEngine(factory, executor);
+    MeasureFilterEngine engine = new MeasureFilterEngine(factory, executor, new Profiling(new Settings()));
     MeasureFilterResult result = engine.execute(filterMap, 50L);
 
     assertThat(result.isSuccess()).isFalse();