SONAR-1837:

* Add profiling logs to database optimization tasks
* Extend TimeProfiler to produce logs using debug level

1 files changed, 33 insertions, 12 deletions

diff --git a/sonar-core/src/main/java/org/sonar/core/purge/AbstractPurge.java b/sonar-core/src/main/java/org/sonar/core/purge/AbstractPurge.java
index fe1d9bf40b9..f698c14e778 100644
--- a/sonar-core/src/main/java/org/sonar/core/purge/AbstractPurge.java
+++ b/sonar-core/src/main/java/org/sonar/core/purge/AbstractPurge.java
@@ -23,16 +23,19 @@ import org.sonar.api.batch.Purge;
 import org.sonar.api.database.DatabaseSession;
 import org.sonar.api.database.model.*;
 import org.sonar.api.design.DependencyDto;
+import org.sonar.api.utils.TimeProfiler;
 
-import javax.persistence.Query;
 import java.util.List;
 
+import javax.persistence.Query;
+
 public abstract class AbstractPurge implements Purge {
 
   private static final int MAX_IN_ELEMENTS = 950;
 
   private int sqlInPageSize = MAX_IN_ELEMENTS;
   private DatabaseSession session;
+  private TimeProfiler profiler = new TimeProfiler().setLevelToDebug();
 
   public AbstractPurge(DatabaseSession session) {
     this.session = session;
@@ -54,64 +57,82 @@ public abstract class AbstractPurge implements Purge {
   }
 
   protected void deleteDependencies(List<Integer> snapshotIds) {
-    executeQuery(snapshotIds, "delete from " + DependencyDto.class.getSimpleName() + " d where d.fromSnapshotId in (:ids)");
-    executeQuery(snapshotIds, "delete from " + DependencyDto.class.getSimpleName() + " d where d.toSnapshotId in (:ids)");
+    executeQuery("deleteDependencies", snapshotIds, "delete from " + DependencyDto.class.getSimpleName() + " d where d.fromSnapshotId in (:ids)");
+    executeQuery("deleteDependencies", snapshotIds, "delete from " + DependencyDto.class.getSimpleName() + " d where d.toSnapshotId in (:ids)");
   }
 
   /**
    * Delete all measures, including MEASURE_DATA
    */
   protected void deleteMeasuresBySnapshotId(List<Integer> snapshotIds) {
-    executeQuery(snapshotIds, "delete from " + MeasureData.class.getSimpleName() + " m where m.snapshotId in (:ids)");
-    executeQuery(snapshotIds, "delete from " + MeasureModel.class.getSimpleName() + " m where m.snapshotId in (:ids)");
+    executeQuery("delete measures by snapshot id", snapshotIds, "delete from " + MeasureData.class.getSimpleName() + " m where m.snapshotId in (:ids)");
+    executeQuery("delete measures by snapshot id", snapshotIds, "delete from " + MeasureModel.class.getSimpleName() + " m where m.snapshotId in (:ids)");
   }
 
   /**
    * Delete all measures, including MEASURE_DATA
    */
   protected void deleteMeasuresById(List<Integer> measureIds) {
-    executeQuery(measureIds, "delete from " + MeasureData.class.getSimpleName() + " m where m.measure.id in (:ids)");
-    executeQuery(measureIds, "delete from " + MeasureModel.class.getSimpleName() + " m where m.id in (:ids)");
+    executeQuery("delete measures by id", measureIds, "delete from " + MeasureData.class.getSimpleName() + " m where m.measure.id in (:ids)");
+    executeQuery("delete measures by id", measureIds, "delete from " + MeasureModel.class.getSimpleName() + " m where m.id in (:ids)");
   }
 
   /**
    * Delete SNAPSHOT_SOURCES table
    */
   protected void deleteSources(List<Integer> snapshotIds) {
-    executeQuery(snapshotIds, "delete from " + SnapshotSource.class.getSimpleName() + " e where e.snapshotId in (:ids)");
+    executeQuery("delete sources", snapshotIds, "delete from " + SnapshotSource.class.getSimpleName() + " e where e.snapshotId in (:ids)");
   }
 
   /**
    * Delete violations (RULE_FAILURES table)
    */
   protected void deleteViolations(List<Integer> snapshotIds) {
-    executeQuery(snapshotIds, "delete from " + RuleFailureModel.class.getSimpleName() + " e where e.snapshotId in (:ids)");
+    executeQuery("delete violations", snapshotIds, "delete from " + RuleFailureModel.class.getSimpleName() + " e where e.snapshotId in (:ids)");
   }
 
   /**
    * Delete SNAPSHOTS table
    */
   protected void deleteSnapshots(List<Integer> snapshotIds) {
-    executeQuery(snapshotIds, "delete from " + Snapshot.class.getSimpleName() + " s where s.id in (:ids)");
+    executeQuery("delete snapshots", snapshotIds, "delete from " + Snapshot.class.getSimpleName() + " s where s.id in (:ids)");
   }
 
-
   /**
    * Paginate execution of SQL requests to avoid exceeding size of rollback segment
    */
-  protected void executeQuery(List<Integer> ids, String hql) {
+  private void executeQuery(String name, List<Integer> ids, String hql) {
     if (ids == null || ids.isEmpty()) {
       return;
     }
 
+    TimeProfiler profiler = new TimeProfiler().setLevelToDebug().start("Execute " + name);
+
+    int page = 1;
     int index = 0;
     while (index < ids.size()) {
+      TimeProfiler pageProfiler = new TimeProfiler().setLevelToDebug().start("Execute " + name + " " + page + " page");
       Query query = session.createQuery(hql);
       List<Integer> paginedSids = ids.subList(index, Math.min(ids.size(), index + sqlInPageSize));
       query.setParameter("ids", paginedSids);
       query.executeUpdate();
       index += sqlInPageSize;
+      page++;
       session.commit();
+      pageProfiler.stop();
     }
+
+    profiler.stop();
+  }
+
+  protected void executeQuery(List<Integer> ids, String hql) {
+    executeQuery("delete for " + getClass().getSimpleName(), ids, hql);
+  }
+
+  protected List<Integer> selectIds(Query query) {
+    profiler.start("Select IDs for " + getClass().getSimpleName());
+    List<Integer> result = query.getResultList();
+    profiler.stop();
+    return result;
   }
 }