[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>
diff --git a/pkg/analysis_server/lib/src/plugin/plugin_manager.dart b/pkg/analysis_server/lib/src/plugin/plugin_manager.dart
index 96bb7b6..59afafd 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/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 @@
try {
plugin.stop();
} catch (e, st) {
- AnalysisEngine.instance.instrumentationService
+ instrumentationService
.logException(SilentException('Issue stopping a plugin', e, st));
}
}
@@ -594,7 +593,7 @@
try {
await info.stop();
} catch (e, st) {
- AnalysisEngine.instance.instrumentationService.logException(e, st);
+ instrumentationService.logException(e, st);
}
}));
}
@@ -616,12 +615,7 @@
.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 @@
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;