From 9d4342e25a8876b89b23eb51622b3d64f7635408 Mon Sep 17 00:00:00 2001
From: Nikolay Chashnikov <Nikolay.Chashnikov@jetbrains.com>
Date: Wed, 15 Dec 2021 19:39:07 +0300
Subject: [PATCH] [maven] log duration of different phases of Maven import
 (IDEA-284414)

GitOrigin-RevId: a1a64fa8bd7fe26133065f8d077efb61b0013f0a
---
 .../idea/maven/importing/MavenProjectImporter.java     |  9 +++++++--
 .../idea/maven/project/MavenProjectsProcessor.java     | 10 ++++++++--
 2 files changed, 15 insertions(+), 4 deletions(-)

diff --git a/plugins/maven/src/main/java/org/jetbrains/idea/maven/importing/MavenProjectImporter.java b/plugins/maven/src/main/java/org/jetbrains/idea/maven/importing/MavenProjectImporter.java
index 5a41afd354b6..219bf947f163 100644
--- a/plugins/maven/src/main/java/org/jetbrains/idea/maven/importing/MavenProjectImporter.java
+++ b/plugins/maven/src/main/java/org/jetbrains/idea/maven/importing/MavenProjectImporter.java
@@ -34,7 +34,6 @@ import com.intellij.workspaceModel.ide.WorkspaceModel;
 import com.intellij.workspaceModel.ide.legacyBridge.ModuleBridge;
 import com.intellij.workspaceModel.storage.WorkspaceEntityStorage;
 import com.intellij.workspaceModel.storage.WorkspaceEntityStorageBuilder;
-import com.intellij.workspaceModel.storage.WorkspaceEntityStorageDiffBuilder;
 import org.jetbrains.annotations.NotNull;
 import org.jetbrains.annotations.Nullable;
 import org.jetbrains.idea.maven.importing.configurers.MavenModuleConfigurer;
@@ -94,13 +93,16 @@ public class MavenProjectImporter {
 
   @Nullable
   public List<MavenProjectsProcessorTask> importProject() {
+    long startTime = System.currentTimeMillis();
     if (MavenUtil.newModelEnabled(myProject)) {
       myModelsProvider = new ModifiableModelsProviderProxyImpl(myProject, myDiff);
     } else {
       myModelsProvider = new ModifiableModelsProviderProxyWrapper(myIdeModifiableModelsProvider);
     }
     myModuleModel = myModelsProvider.getModuleModelProxy();
-    return importProjectOldWay();
+    List<MavenProjectsProcessorTask> tasks = importProjectOldWay();
+    LOG.info("[maven import] applying models took " + (System.currentTimeMillis() - startTime) + "ms");
+    return tasks;
   }
 
   @Nullable
@@ -195,6 +197,8 @@ public class MavenProjectImporter {
 
     MavenUtil.runInBackground(myProject, MavenProjectBundle.message("command.name.configuring.projects"), false, indicator -> {
       float count = 0;
+      long startTime = System.currentTimeMillis();
+      LOG.info("[maven import] applying " + configurers.size() + " configurers to " + myAllProjects.size() + " Maven projects");
       for (MavenProject mavenProject : myAllProjects) {
         Module module = myMavenProjectToModule.get(mavenProject);
         if (module == null) {
@@ -206,6 +210,7 @@ public class MavenProjectImporter {
           configurer.configure(mavenProject, myProject, module);
         }
       }
+      LOG.info("[maven import] configuring projects took " + (System.currentTimeMillis() - startTime) + "ms");
     });
   }
 
diff --git a/plugins/maven/src/main/java/org/jetbrains/idea/maven/project/MavenProjectsProcessor.java b/plugins/maven/src/main/java/org/jetbrains/idea/maven/project/MavenProjectsProcessor.java
index 2ba6aeb2bedf..2a33a64fde22 100644
--- a/plugins/maven/src/main/java/org/jetbrains/idea/maven/project/MavenProjectsProcessor.java
+++ b/plugins/maven/src/main/java/org/jetbrains/idea/maven/project/MavenProjectsProcessor.java
@@ -16,14 +16,15 @@
 package org.jetbrains.idea.maven.project;
 
 import com.intellij.internal.statistic.StructuredIdeActivity;
-import com.intellij.openapi.application.ApplicationManager;
 import com.intellij.openapi.application.ReadAction;
 import com.intellij.openapi.diagnostic.ControlFlowException;
+import com.intellij.openapi.diagnostic.Logger;
 import com.intellij.openapi.externalSystem.statistics.ExternalSystemStatUtilKt;
 import com.intellij.openapi.externalSystem.statistics.ProjectImportCollector;
 import com.intellij.openapi.project.Project;
 import com.intellij.openapi.util.Condition;
 import com.intellij.openapi.util.NlsContexts;
+import com.intellij.openapi.util.text.StringUtil;
 import com.intellij.util.ExceptionUtil;
 import com.intellij.util.concurrency.Semaphore;
 import org.jetbrains.annotations.NotNull;
@@ -35,6 +36,7 @@ import java.util.LinkedList;
 import java.util.Queue;
 
 public class MavenProjectsProcessor {
+  private static final Logger LOG = Logger.getInstance(MavenProjectsProcessor.class);
   private final Project myProject;
   private final @NlsContexts.Command String myTitle;
   private final boolean myCancellable;
@@ -140,7 +142,7 @@ public class MavenProjectsProcessor {
         StructuredIdeActivity activity = ExternalSystemStatUtilKt.importActivityStarted(myProject, MavenUtil.SYSTEM_ID, () ->
           Collections.singletonList(ProjectImportCollector.TASK_CLASS.with(finalTask.getClass()))
         );
-
+        long startTime = System.currentTimeMillis();
         try {
           final MavenGeneralSettings mavenGeneralSettings = MavenProjectsManager.getInstance(myProject).getGeneralSettings();
           task.perform(myProject, myEmbeddersManager,
@@ -155,6 +157,10 @@ public class MavenProjectsProcessor {
         }
         finally {
           activity.finished();
+          long duration = System.currentTimeMillis() - startTime;
+          if (duration > 10) {
+            LOG.info("[maven import] " + StringUtil.getShortName(task.getClass()) + " took " + duration + "ms");
+          }
         }
 
         synchronized (myQueue) {