Add watchers to calculate the time duration of requests

Author: MykolaYaremchuk

build.gradle.kts

@@ -20,6 +20,7 @@ plugins {
 
 
 dependencies{
+    implementation(libs.commons.lang3)
     implementation(project(":model"))
     implementation(project(":analytics-provider"))
     implementation(project(":ide-common"))

ide-common/src/main/java/org/digma/intellij/plugin/errors/ErrorsProvider.java

@@ -2,6 +2,7 @@
 
 import com.intellij.openapi.diagnostic.Logger;
 import com.intellij.openapi.project.Project;
+import org.apache.commons.lang3.time.StopWatch;
 import org.digma.intellij.plugin.analytics.AnalyticsService;
 import org.digma.intellij.plugin.analytics.AnalyticsServiceException;
 import org.digma.intellij.plugin.document.DocumentInfoService;
@@ -44,6 +45,7 @@ public ErrorsProvider(@NotNull Project project) {
     }
 
     public ErrorsListContainer getErrors(@NotNull MethodInfo methodInfo) {
+        var stopWatch = StopWatch.createStarted();
         try {
             final List<CodeObjectError> codeObjectErrors = analyticsService.getErrorsOfCodeObject(methodInfo.idWithType());
             Log.log(LOGGER::debug, "CodeObjectErrors for {}: {}", methodInfo.getId(), codeObjectErrors);
@@ -66,6 +68,9 @@ public ErrorsListContainer getErrors(@NotNull MethodInfo methodInfo) {
             //it may happen many times.
             Log.log(LOGGER::debug, "AnalyticsServiceException for getErrors for {}: {}", methodInfo.getId(), e.getMessage());
             return new ErrorsListContainer();
+        } finally {
+            stopWatch.stop();
+            Log.log(LOGGER::debug, "getErrors time took {} milliseconds", stopWatch.getTime(java.util.concurrent.TimeUnit.MILLISECONDS));
         }
     }
 

ide-common/src/main/java/org/digma/intellij/plugin/insights/InsightsProvider.java

@@ -2,6 +2,7 @@
 
 import com.intellij.openapi.diagnostic.Logger;
 import com.intellij.openapi.project.Project;
+import org.apache.commons.lang3.time.StopWatch;
 import org.digma.intellij.plugin.analytics.AnalyticsService;
 import org.digma.intellij.plugin.analytics.AnalyticsServiceException;
 import org.digma.intellij.plugin.insights.view.BuildersHolder;
@@ -37,6 +38,7 @@ public InsightsListContainer getInsights(@NotNull MethodInfo methodInfo) {
         objectIds.add(methodInfo.idWithType());
         objectIds.addAll(methodInfo.getRelatedCodeObjectIds());
         Log.log(LOGGER::debug, "Got following code object ids for method {}: {}",methodInfo.getId(),objectIds);
+        var stopWatch = StopWatch.createStarted();
 
         try {
             List<? extends CodeObjectInsight> codeObjectInsights = analyticsService.getInsights(objectIds);
@@ -47,13 +49,16 @@ public InsightsListContainer getInsights(@NotNull MethodInfo methodInfo) {
             List<ListViewItem<?>> listViewItems = insightsViewBuilder.build(project,methodInfo, codeObjectInsights);
             Log.log(LOGGER::debug, "ListViewItems for {}: {}", methodInfo.getId(), listViewItems);
             return new InsightsListContainer(listViewItems, codeObjectInsights.size(), usageStatus);
-        }catch (AnalyticsServiceException e){
+        } catch (AnalyticsServiceException e) {
             //if analyticsService.getInsights throws exception it means insights could not be loaded, usually when
             //the backend is not available. return an empty InsightsListContainer to keep everything running and don't
             //crash the plugin. don't log the exception, it was logged in AnalyticsService, keep the log quite because
             //it may happen many times.
             Log.log(LOGGER::debug, "AnalyticsServiceException for getInsights for {}: {}", methodInfo.getId(), e.getMessage());
             return new InsightsListContainer();
+        } finally {
+            stopWatch.stop();
+            Log.log(LOGGER::debug, "getInsights time took {} milliseconds", stopWatch.getTime(java.util.concurrent.TimeUnit.MILLISECONDS));
         }
     }
 

rider/build.gradle.kts

@@ -15,6 +15,7 @@ plugins {
 
 dependencies {
     implementation(libs.commons.collections4)
+    implementation(libs.commons.lang3)
     compileOnly(project(":ide-common"))
     compileOnly(project(":model"))
 }

rider/src/main/java/org/digma/intellij/plugin/rider/psi/csharp/CSharpLanguageService.java

@@ -9,6 +9,7 @@
 import com.jetbrains.rider.ideaInterop.fileTypes.csharp.CSharpLanguage;
 import kotlin.Pair;
 import org.apache.commons.collections4.map.LRUMap;
+import org.apache.commons.lang3.time.StopWatch;
 import org.digma.intellij.plugin.log.Log;
 import org.digma.intellij.plugin.model.discovery.DocumentInfo;
 import org.digma.intellij.plugin.model.discovery.MethodUnderCaret;
@@ -18,6 +19,7 @@
 import org.digma.intellij.plugin.rider.protocol.MethodNavigationHost;
 import org.jetbrains.annotations.NotNull;
 
+import java.util.concurrent.TimeUnit;
 import java.util.List;
 import java.util.Map;
 
@@ -96,7 +98,13 @@ public Map<String, String> findWorkspaceUrisForCodeObjectIds(List<String> codeOb
 
     @Override
     public Map<String, Pair<String, Integer>> findWorkspaceUrisForSpanIds(List<String> spanIds) {
-        return codeObjectHost.findWorkspaceUrisForSpanIds(spanIds);
+        var stopWatch = StopWatch.createStarted();
+        try {
+            return codeObjectHost.findWorkspaceUrisForSpanIds(spanIds);
+        } finally {
+            stopWatch.stop();
+            Log.log(LOGGER::debug, "findWorkspaceUrisForSpanIds time took {} milliseconds", stopWatch.getTime(TimeUnit.MILLISECONDS));
+        }
     }
 
     @Override

src/main/java/org/digma/intellij/plugin/service/EditorInteractionService.java

@@ -3,6 +3,7 @@
 import com.intellij.openapi.Disposable;
 import com.intellij.openapi.diagnostic.Logger;
 import com.intellij.openapi.project.Project;
+import org.apache.commons.lang3.time.StopWatch;
 import org.digma.intellij.plugin.analytics.AnalyticsService;
 import org.digma.intellij.plugin.analytics.BackendConnectionMonitor;
 import org.digma.intellij.plugin.common.Backgroundable;
@@ -107,7 +108,13 @@ public void contextChanged(MethodUnderCaret methodUnderCaret) {
 
         Backgroundable.ensureBackground(project, "Digma: Context change", () -> {
             Log.log(LOGGER::debug, "Executing contextChanged in background for {}", methodUnderCaret.getId());
-            contextChangedImpl(methodUnderCaret);
+            var stopWatch = StopWatch.createStarted();
+            try {
+                contextChangedImpl(methodUnderCaret);
+            } finally {
+                stopWatch.stop();
+                Log.log(LOGGER::debug, "contextChangedImpl time took {} milliseconds", stopWatch.getTime(java.util.concurrent.TimeUnit.MILLISECONDS));
+            }
         });
 
 //        if (SwingUtilities.isEventDispatchThread()) {