From 953e4076be80d665ba58742450d1dc801bb860c1 Mon Sep 17 00:00:00 2001
From: Danny Tuppeny <danny@tuppeny.com>
Date: Tue, 7 May 2024 16:27:55 +0000
Subject: [PATCH] [analysis_server] Record execution/timing of "pub upgrade"
 for plugins in instrumentation log

This will help identify issues like https://github.com/dart-lang/sdk/issues/55621 in future from the logs without needing to repro. Before, there was just a gap in the logs that wasn't obvious.

A sample log looks like:

```
1715080652096:Req:{"jsonrpc"::"2.0","id"::2,"result"::null,"clientRequestTime"::1715080652091}
1715080652253:Info:Running "pub upgrade" in "C::\Users\danny\AppData\Local\.dartServer\.plugin_manager\723cb7b2bec3011e09cd16421250ff7a\analyzer_plugin"
1715080653311:Info:Running "pub upgrade" took 0::00::01.057950
1715080653393:Res:{"id"::3,"jsonrpc"::"2.0","method"::"window/workDoneProgress/create","params"::{"token"::"ANALYZING"}}
```

(This was the only instance of `Process.runSync` in the server)

Change-Id: I2ccc5a7c538ae7a236a76df020c59014982a2e19
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/365602
Reviewed-by: Brian Wilkerson <brianwilkerson@google.com>
Commit-Queue: Brian Wilkerson <brianwilkerson@google.com>
Reviewed-by: Samuel Rawlins <srawlins@google.com>
---
 .../lib/src/plugin/plugin_manager.dart        | 39 ++++++++++++++-----
 1 file changed, 29 insertions(+), 10 deletions(-)

diff --git a/pkg/analysis_server/lib/src/plugin/plugin_manager.dart b/pkg/analysis_server/lib/src/plugin/plugin_manager.dart
index 96bb7b66b130..59afafd1f7b6 100644
--- a/pkg/analysis_server/lib/src/plugin/plugin_manager.dart
+++ b/pkg/analysis_server/lib/src/plugin/plugin_manager.dart
@@ -5,7 +5,7 @@
 import 'dart:async';
 import 'dart:collection';
 import 'dart:convert';
-import 'dart:io' show Platform, Process;
+import 'dart:io' show Platform, Process, ProcessResult;
 
 import 'package:analysis_server/src/analytics/percentile_calculator.dart';
 import 'package:analysis_server/src/plugin/notification_manager.dart';
@@ -13,7 +13,6 @@ import 'package:analyzer/dart/analysis/context_root.dart' as analyzer;
 import 'package:analyzer/exception/exception.dart';
 import 'package:analyzer/file_system/file_system.dart';
 import 'package:analyzer/instrumentation/instrumentation.dart';
-import 'package:analyzer/src/generated/engine.dart';
 import 'package:analyzer/src/generated/source.dart';
 import 'package:analyzer/src/test_utilities/package_config_file_builder.dart';
 import 'package:analyzer/src/util/file_paths.dart' as file_paths;
@@ -492,7 +491,7 @@ class PluginManager {
         try {
           plugin.stop();
         } catch (e, st) {
-          AnalysisEngine.instance.instrumentationService
+          instrumentationService
               .logException(SilentException('Issue stopping a plugin', e, st));
         }
       }
@@ -594,7 +593,7 @@ class PluginManager {
       try {
         await info.stop();
       } catch (e, st) {
-        AnalysisEngine.instance.instrumentationService.logException(e, st);
+        instrumentationService.logException(e, st);
       }
     }));
   }
@@ -616,12 +615,7 @@ class PluginManager {
         .getChildAssumingFolder(file_paths.dotDartTool)
         .getChildAssumingFile(file_paths.packageConfigJson);
     if (pubCommand != null) {
-      var result = Process.runSync(
-          Platform.executable, <String>['pub', pubCommand],
-          stderrEncoding: utf8,
-          stdoutEncoding: utf8,
-          workingDirectory: pluginFolder.path,
-          environment: {_pubEnvironmentKey: _getPubEnvironmentValue()});
+      var result = _runPubCommand(pubCommand, pluginFolder);
       if (result.exitCode != 0) {
         var buffer = StringBuffer();
         buffer.writeln('Failed to run pub $pubCommand');
@@ -762,6 +756,31 @@ class PluginManager {
     return const <String>[];
   }
 
+  /// Runs (and records timing to the instrumentation log) a Pub command
+  /// [pubCommand] in [folder].
+  ProcessResult _runPubCommand(String pubCommand, Folder folder) {
+    instrumentationService.logInfo(
+      'Running "pub $pubCommand" in "${folder.path}"',
+    );
+
+    var stopwatch = Stopwatch()..start();
+    var result = Process.runSync(
+      Platform.executable,
+      <String>['pub', pubCommand],
+      stderrEncoding: utf8,
+      stdoutEncoding: utf8,
+      workingDirectory: folder.path,
+      environment: {_pubEnvironmentKey: _getPubEnvironmentValue()},
+    );
+    stopwatch.stop();
+
+    instrumentationService.logInfo(
+      'Running "pub $pubCommand" took ${stopwatch.elapsed}',
+    );
+
+    return result;
+  }
+
   /// Return a hex-encoded MD5 signature of the given file [path].
   String _uniqueDirectoryName(String path) {
     var bytes = md5.convert(path.codeUnits).bytes;