Capture the request time for performance data and support forced shutdown

pkg/analysis_server/lib/src/plugin/plugin_manager.dart

Index: pkg/analysis_server/lib/src/plugin/plugin_manager.dart
diff --git a/pkg/analysis_server/lib/src/plugin/plugin_manager.dart b/pkg/analysis_server/lib/src/plugin/plugin_manager.dart
index 01e26286effe3480b6c17c5250826d95a0e991a9..b321d30d9756c79798601f788bddacc48e464885 100644
--- a/pkg/analysis_server/lib/src/plugin/plugin_manager.dart
+++ b/pkg/analysis_server/lib/src/plugin/plugin_manager.dart
@@ -235,6 +235,14 @@ abstract class PluginInfo {
  */
 class PluginManager {
   /**
+   * A table, keyed by both a plugin and a request method, to a list of the
+   * times that it took the plugin to return a response to requests with the
+   * method.
+   */
+  static Map<PluginInfo, Map<String, List<int>>> pluginResponseTimes =
+      <PluginInfo, Map<String, List<int>>>{};
+
+  /**
    * The resource provider used to access the file system.
    */
   final ResourceProvider resourceProvider;
@@ -567,6 +575,17 @@ class PluginManager {
     List<int> bytes = md5.convert(path.codeUnits).bytes;
     return hex.encode(bytes);
   }
+
+  /**
+   * Record the fact that the given [plugin] responded to a request with the
+   * given [method] in the given [time].
+   */
+  static void recordResponseTime(PluginInfo plugin, String method, int time) {
+    pluginResponseTimes
+        .putIfAbsent(plugin, () => <String, List<int>>{})
+        .putIfAbsent(method, () => <int>[])
+        .add(time);
+  }
 }
 
 /**
@@ -575,6 +594,19 @@ class PluginManager {
 @visibleForTesting
 class PluginSession {
   /**
+   * The maximum number of milliseconds that server should wait for a response
+   * from a plugin before deciding that the plugin is hung.
+   */
+  static const Duration MAXIMUM_RESPONSE_TIME = const Duration(minutes: 2);
+
+  /**
+   * The length of time to wait after sending a 'plugin.shutdown' request before
+   * a failure to terminate will cause the isolate to be killed.
+   */
+  static const Duration WAIT_FOR_SHUTDOWN_DURATION =
+      const Duration(seconds: 10);
+
+  /**
    * The information about the plugin being executed.
    */
   final PluginInfo info;
@@ -598,8 +630,7 @@ class PluginSession {
    * A table mapping the id's of requests to the functions used to handle the
    * response to those requests.
    */
-  Map<String, Completer<Response>> pendingRequests =
-      <String, Completer<Response>>{};
+  Map<String, _PendingRequest> pendingRequests = <String, _PendingRequest>{};
 
   /**
    * A boolean indicating whether the plugin is compatible with the version of
@@ -689,13 +720,34 @@ class PluginSession {
    * created when the request was sent.
    */
   void handleResponse(Response response) {
-    Completer<Response> completer = pendingRequests.remove(response.id);
+    _PendingRequest requestData = pendingRequests.remove(response.id);
+    int responseTime = new DateTime.now().millisecondsSinceEpoch;
+    int duration = responseTime - requestData.requestTime;
+    PluginManager.recordResponseTime(info, requestData.method, duration);
+    Completer<Response> completer = requestData.completer;
     if (completer != null) {
       completer.complete(response);
     }
   }
 
   /**
+   * Return `true` if there are any requests that have not been responded to
+   * within the maximum allowed amount of time.
+   */
+  bool isNonResponsive() {
+    // TODO(brianwilkerson) Figure out when to invoke this method in order to
+    // identify non-responsive plugins and kill them.
+    int cutOffTime = new DateTime.now().millisecondsSinceEpoch -
+        MAXIMUM_RESPONSE_TIME.inMilliseconds;
+    for (var requestData in pendingRequests.values) {
+      if (requestData.requestTime < cutOffTime) {
+        return true;
+      }
+    }
+    return false;
+  }
+
+  /**
    * Send a request, based on the given [parameters]. Return a future that will
    * complete when a response is received.
    */
@@ -706,8 +758,11 @@ class PluginSession {
     }
     String id = nextRequestId;
     Completer<Response> completer = new Completer();
-    pendingRequests[id] = completer;
-    channel.sendRequest(parameters.toRequest(id));
+    int requestTime = new DateTime.now().millisecondsSinceEpoch;
+    Request request = parameters.toRequest(id);
+    pendingRequests[id] =
+        new _PendingRequest(request.method, requestTime, completer);
+    channel.sendRequest(request);
     return completer.future;
   }
 
@@ -757,9 +812,40 @@ class PluginSession {
     if (channel == null) {
       throw new StateError('Cannot stop a plugin that is not running.');
     }
-    // TODO(brianwilkerson) Ensure that the isolate is killed if it does not
-    // terminate normally.
     sendRequest(new PluginShutdownParams());
+    new Future.delayed(WAIT_FOR_SHUTDOWN_DURATION, () {
+      if (channel != null) {
+        channel.kill();
+        channel = null;
+      }
+    });
     return pluginStoppedCompleter.future;
   }
 }
+
+/**
+ * Information about a request that has been sent but for which a response has
+ * not yet been received.
+ */
+class _PendingRequest {
+  /**
+   * The method of the request.
+   */
+  final String method;
+
+  /**
+   * The time at which the request was sent to the plugin.
+   */
+  final int requestTime;

[scheglov, 2017/05/18 21:36:16]

Or you could use new Stopwatch()..start() instead.

[Brian Wilkerson, 2017/05/18 21:51:39]

I hadn't considered that, but now that I think about it, I have concerns
(possibly unwarranted) about the memory management issues of creating more
objects and holding on to them just until the plugin has responded. If they
never graduate from new space it shouldn't be a problem, but...

Unless there's a compelling reason to change it, I think I'll leave it as is.

[scheglov, 2017/05/18 21:55:55]

It's fine with my any way, just thought about other way, which could be simpler.

+
+  /**
+   * The completer that will be used to complete the future when the response is
+   * received from the plugin.
+   */
+  final Completer<Response> completer;
+
+  /**
+   * Initialize a pending request.
+   */
+  _PendingRequest(this.method, this.requestTime, this.completer);
+}