Refactor the MessageSchedulerTestView for more flexibility

bwilkerson · Commit Queue · commit d85ab6df0c2b · 2025-04-10T16:18:39.000-07:00
There are no functional changes, just changes to the way the logging functionality is implemented. The motivation for the changes is to allow future CLs to explore ways of changing the expectations so that async handling of messages won't produce flaky tests. All references to the 'messageLog' outside the class have been replaced by higher-level methods with a semantic meaning. The class has been split into an interface and an implementation, which allows the test-specific aspects to be in the `test` directory. Some additional code cleanup was also done. Change-Id: Ie515f71153a96fb6e92eb8e2eb05f4b5e064bbd7 Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/421965 Commit-Queue: Brian Wilkerson <brianwilkerson@google.com> Reviewed-by: Phil Quitslund <pquitslund@google.com>
diff --git a/pkg/analysis_server/lib/src/analysis_server.dart b/pkg/analysis_server/lib/src/analysis_server.dart
@@ -283,16 +283,14 @@ abstract class AnalysisServer {
     DartFixPromptManager? dartFixPromptManager,
     this.providedByteStore,
     PluginManager? pluginManager,
-    bool retainDataForTesting = false,
+    MessageSchedulerListener? messageSchedulerListener,
   }) : resourceProvider = OverlayResourceProvider(baseResourceProvider),
        pubApi = PubApi(
          instrumentationService,
          httpClient,
          Platform.environment['PUB_HOSTED_URL'],
        ),
-       messageScheduler = MessageScheduler(
-         testView: retainDataForTesting ? MessageSchedulerTestView() : null,
-       ) {
+       messageScheduler = MessageScheduler(testView: messageSchedulerListener) {
     messageScheduler.setServer(this);
     // Set the default URI converter. This uses the resource providers path
     // context (unlike the initialized value) which allows tests to override it.
diff --git a/pkg/analysis_server/lib/src/legacy_analysis_server.dart b/pkg/analysis_server/lib/src/legacy_analysis_server.dart
@@ -392,7 +392,7 @@ class LegacyAnalysisServer extends AnalysisServer {
     super.dartFixPromptManager,
     super.providedByteStore,
     super.pluginManager,
-    super.retainDataForTesting,
+    super.messageSchedulerListener,
   }) : lspClientConfiguration = lsp.LspClientConfiguration(
          baseResourceProvider.pathContext,
        ),
diff --git a/pkg/analysis_server/lib/src/lsp/lsp_analysis_server.dart b/pkg/analysis_server/lib/src/lsp/lsp_analysis_server.dart
@@ -162,7 +162,7 @@ class LspAnalysisServer extends AnalysisServer {
     this.detachableFileSystemManager,
     super.enableBlazeWatcher,
     super.dartFixPromptManager,
-    super.retainDataForTesting,
+    super.messageSchedulerListener,
   }) : lspClientConfiguration = LspClientConfiguration(
          baseResourceProvider.pathContext,
        ),
diff --git a/pkg/analysis_server/lib/src/scheduler/message_scheduler.dart b/pkg/analysis_server/lib/src/scheduler/message_scheduler.dart
@@ -23,15 +23,15 @@ import 'package:meta/meta.dart';
 /// [AnalysisServer].
 ///
 /// Clients include IDE's (LSP and Legacy protocol), DTD, the Diagnostic server
-/// and file wathcers. The [MessageScheduler] acts as a hub for all incoming
+/// and file watchers. The [MessageScheduler] acts as a hub for all incoming
 /// messages and forwards the messages to the appropriate handlers.
 final class MessageScheduler {
   /// A flag to allow disabling overlapping message handlers.
   static bool allowOverlappingHandlers = true;
 
   /// A view into the [MessageScheduler] used for testing.
   @visibleForTesting
-  MessageSchedulerTestView? testView;
+  MessageSchedulerListener? testView;
 
   /// The [AnalysisServer] associated with the scheduler.
   // TODO(brianwilkerson): Make this field private.
@@ -60,9 +60,7 @@ final class MessageScheduler {
   /// atomically and it was decided that it was cleaner for the scheduler to
   /// have the nullable reference to the server rather than the other way
   /// around.
-  MessageScheduler({this.testView}) {
-    testView?.messageScheduler = this;
-  }
+  MessageScheduler({this.testView});
 
   /// Add the [message] to the end of the pending messages queue.
   ///
@@ -87,7 +85,7 @@ final class MessageScheduler {
   /// - The incoming [legacy.ANALYSIS_REQUEST_UPDATE_CONTENT] message cancels
   ///   any rename files request that is in progress.
   void add(ScheduledMessage message) {
-    testView?.logAddMessage(message);
+    testView?.addPendingMessage(message);
     if (message is LegacyMessage) {
       var request = message.request;
       var method = request.method;
@@ -109,9 +107,7 @@ final class MessageScheduler {
                   code: lsp.ErrorCodes.ContentModified.toJson(),
                   reason: 'File content was modified',
                 );
-                testView?.messageLog.add(
-                  'Canceled active request ${activeRequest.method}',
-                );
+                testView?.cancelActiveMessage(activeMessage);
               }
             }
           }
@@ -157,9 +153,7 @@ final class MessageScheduler {
               var message = activeMessage.message as lsp.RequestMessage;
               if (message.method == incomingMsgMethod) {
                 activeMessage.cancellationToken?.cancel(reason: reason);
-                testView?.messageLog.add(
-                  'Canceled active request ${message.method}',
-                );
+                testView?.cancelActiveMessage(activeMessage);
               }
             }
           }
@@ -168,9 +162,7 @@ final class MessageScheduler {
               var message = pendingMessage.message as lsp.RequestMessage;
               if (message.method == msg.method) {
                 pendingMessage.cancellationToken?.cancel(reason: reason);
-                testView?.messageLog.add(
-                  'Canceled pending request ${msg.method}',
-                );
+                testView?.cancelPendingMessage(pendingMessage);
               }
             }
           }
@@ -186,18 +178,18 @@ final class MessageScheduler {
   /// Dispatch the first message in the queue to be executed.
   void processMessages() async {
     _isProcessing = true;
-    testView?.messageLog.add('Entering process messages loop');
+    testView?.startProcessingMessages();
     try {
       while (_pendingMessages.isNotEmpty) {
         var currentMessage = _pendingMessages.removeFirst();
         _activeMessages.addLast(currentMessage);
+        testView?.addActiveMessage(currentMessage);
         completer = Completer<void>();
         unawaited(
           completer.future.then((_) {
             _activeMessages.remove(currentMessage);
           }),
         );
-        testView?.logHandleMessage(currentMessage);
         switch (currentMessage) {
           case LspMessage():
             var lspMessage = currentMessage.message;
@@ -242,9 +234,7 @@ final class MessageScheduler {
         // TODO(pq): if not awaited, consider adding a `then` so we can track
         // when the future completes. But note that we may see some flakiness in
         // tests as message handling gets non-deterministically interleaved.
-        testView?.messageLog.add(
-          '  Complete ${currentMessage.runtimeType}: ${currentMessage.toString()}',
-        );
+        testView?.messageCompleted(currentMessage);
       }
     } catch (error, stackTrace) {
       server.instrumentationService.logException(
@@ -254,7 +244,7 @@ final class MessageScheduler {
       );
     }
     _isProcessing = false;
-    testView?.messageLog.add('Exit process messages loop');
+    testView?.endProcessingMessages();
   }
 
   /// Set the [AnalysisServer].
@@ -358,7 +348,7 @@ final class MessageScheduler {
         var request = activeMessage.message as lsp.RequestMessage;
         if (request.id == params.id) {
           activeMessage.cancellationToken?.cancel();
-          testView?.messageLog.add('Canceled active request ${request.method}');
+          testView?.cancelActiveMessage(activeMessage);
           return;
         }
       }
@@ -368,9 +358,7 @@ final class MessageScheduler {
         var request = pendingMessage.message as lsp.RequestMessage;
         if (request.id == params.id) {
           pendingMessage.cancellationToken?.cancel();
-          testView?.messageLog.add(
-            'Canceled pending request ${request.method}',
-          );
+          testView?.cancelPendingMessage(pendingMessage);
           return;
         }
       }
@@ -403,7 +391,10 @@ final class MessageScheduler {
       return path != null ? Uri.file(path) : null;
     }
 
-    void checkAndCancelRefactor(LspMessage lspMessage) {
+    void checkAndCancelRefactor(
+      LspMessage lspMessage, {
+      required bool isActive,
+    }) {
       var request = lspMessage.message as lsp.RequestMessage;
       var execParams = _getCommandParams(request);
       if (execParams != null &&
@@ -414,14 +405,16 @@ final class MessageScheduler {
           lspMessage.cancellationToken?.cancel(
             code: lsp.ErrorCodes.ContentModified.toJson(),
           );
-          testView?.messageLog.add(
-            'Canceled in progress request ${request.method}',
-          );
+          if (isActive) {
+            testView?.cancelActiveMessage(lspMessage);
+          } else {
+            testView?.cancelPendingMessage(lspMessage);
+          }
         }
       }
     }
 
-    void checkAndCancelRename(LspMessage lspMessage) {
+    void checkAndCancelRename(LspMessage lspMessage, {required bool isActive}) {
       var request = lspMessage.message as lsp.RequestMessage;
       var renameParams = _getRenameParams(request);
       if (renameParams != null) {
@@ -430,9 +423,11 @@ final class MessageScheduler {
           lspMessage.cancellationToken?.cancel(
             code: lsp.ErrorCodes.ContentModified.toJson(),
           );
-          testView?.messageLog.add(
-            'Canceled in progress request ${request.method}',
-          );
+          if (isActive) {
+            testView?.cancelActiveMessage(lspMessage);
+          } else {
+            testView?.cancelPendingMessage(lspMessage);
+          }
         }
       }
     }
@@ -441,37 +436,44 @@ final class MessageScheduler {
       if (activeMessage is LspMessage && activeMessage.isRequest) {
         var request = activeMessage.message as lsp.RequestMessage;
         if (request.method == lsp.Method.workspace_executeCommand) {
-          checkAndCancelRefactor(activeMessage);
+          checkAndCancelRefactor(activeMessage, isActive: true);
         } else if (request.method == lsp.Method.textDocument_rename) {
-          checkAndCancelRename(activeMessage);
+          checkAndCancelRename(activeMessage, isActive: true);
         }
       }
     }
     for (var pendingMessage in _pendingMessages) {
       if (pendingMessage is LspMessage && pendingMessage.isRequest) {
         var request = pendingMessage.message as lsp.RequestMessage;
         if (request.method == lsp.Method.workspace_executeCommand) {
-          checkAndCancelRefactor(pendingMessage);
+          checkAndCancelRefactor(pendingMessage, isActive: false);
         } else if (request.method == lsp.Method.textDocument_rename) {
-          checkAndCancelRename(pendingMessage);
+          checkAndCancelRename(pendingMessage, isActive: false);
         }
       }
     }
   }
 }
 
-class MessageSchedulerTestView {
-  late final MessageScheduler messageScheduler;
+abstract class MessageSchedulerListener {
+  /// Report that the [message] was added to the active message queue.
+  void addActiveMessage(ScheduledMessage message);
 
-  List<String> messageLog = <String>[];
+  /// Report that the [message] was added to the pending message queue.
+  void addPendingMessage(ScheduledMessage message);
 
-  void logAddMessage(ScheduledMessage message) {
-    messageLog.add(
-      'Incoming ${message is LspMessage ? message.message.runtimeType : message.runtimeType}: ${message.toString()}',
-    );
-  }
+  /// Report that an active [message] was cancelled.
+  void cancelActiveMessage(ScheduledMessage message);
 
-  void logHandleMessage(ScheduledMessage message) {
-    messageLog.add('  Start ${message.runtimeType}: ${message.toString()}');
-  }
+  /// Report that a pending [message] was cancelled.
+  void cancelPendingMessage(ScheduledMessage message);
+
+  /// Report that the loop that processes messages has stopped running.
+  void endProcessingMessages();
+
+  /// Report that the [message] has been completed.
+  void messageCompleted(ScheduledMessage message);
+
+  /// Report that the loop that processes messages has started to run.
+  void startProcessingMessages();
 }
diff --git a/pkg/analysis_server/test/analysis_server_base.dart b/pkg/analysis_server/test/analysis_server_base.dart
@@ -28,6 +28,7 @@ import 'package:unified_analytics/unified_analytics.dart';
 import 'constants.dart';
 import 'mocks.dart';
 import 'support/configuration_files.dart';
+import 'utils/message_scheduler_test_view.dart';
 
 // TODO(scheglov): This is duplicate with pkg/linter/test/rule_test_support.dart.
 // Keep them as consistent with each other as they are today. Ultimately combine
@@ -96,6 +97,7 @@ abstract class ContextResolutionTest with ResourceProviderMixin {
 
   final TestPluginManager pluginManager = TestPluginManager();
   late final MockServerChannel serverChannel;
+  MessageSchedulerTestView? testView;
   late final LegacyAnalysisServer server;
 
   DartFixPromptManager? dartFixPromptManager;
@@ -198,6 +200,7 @@ abstract class ContextResolutionTest with ResourceProviderMixin {
 
     serverChannel.notifications.listen(processNotification);
 
+    testView = retainDataForTesting ? MessageSchedulerTestView() : null;
     server = LegacyAnalysisServer(
       serverChannel,
       resourceProvider,
@@ -209,7 +212,7 @@ abstract class ContextResolutionTest with ResourceProviderMixin {
       dartFixPromptManager: dartFixPromptManager,
       providedByteStore: _byteStore,
       pluginManager: pluginManager,
-      retainDataForTesting: retainDataForTesting,
+      messageSchedulerListener: testView,
     );
 
     server.completionState.budgetDuration = const Duration(seconds: 30);
diff --git a/pkg/analysis_server/test/integration/server/message_scheduler_test.dart b/pkg/analysis_server/test/integration/server/message_scheduler_test.dart
@@ -16,6 +16,7 @@ import 'package:test_reflective_loader/test_reflective_loader.dart';
 
 import '../../analysis_server_base.dart';
 import '../../lsp/code_actions_refactor_test.dart';
+import '../../utils/message_scheduler_test_view.dart';
 import '../../utils/test_code_extensions.dart';
 
 void main() {
@@ -25,8 +26,8 @@ void main() {
   });
 }
 
-void _assertLogContents(MessageScheduler messageScheduler, String expected) {
-  var actual = _getLogContents(messageScheduler.testView!.messageLog);
+void _assertLogContents(MessageSchedulerTestView testView, String expected) {
+  var actual = _getLogContents(testView.messageLog);
   if (actual != expected) {
     print('-------- Actual --------');
     print('$actual------------------------');
@@ -58,7 +59,7 @@ class LegacyServerMessageSchedulerTest extends PubPackageAnalysisServerTest {
   Future<void> test_initialize() async {
     await setRoots(included: [workspaceRootPath], excluded: []);
     await waitForTasksFinished();
-    _assertLogContents(messageScheduler, r'''
+    _assertLogContents(testView!, r'''
 Incoming LegacyMessage: analysis.setAnalysisRoots
 Entering process messages loop
   Start LegacyMessage: analysis.setAnalysisRoots
@@ -78,7 +79,7 @@ Exit process messages loop
     futures.add(handleSuccessfulRequest(request));
     await Future.wait(futures);
     await waitForTasksFinished();
-    _assertLogContents(messageScheduler, r'''
+    _assertLogContents(testView!, r'''
 Incoming LegacyMessage: analysis.setAnalysisRoots
 Entering process messages loop
   Start LegacyMessage: analysis.setAnalysisRoots
@@ -148,7 +149,7 @@ void f() {
       PerformRefactorCommandHandler.delayAfterResolveForTests = null;
     }
 
-    _assertLogContents(messageScheduler, r'''
+    _assertLogContents(testView!, r'''
 Incoming RequestMessage: initialize
 Entering process messages loop
   Start LspMessage: initialize
@@ -208,7 +209,7 @@ class B {
     await Future.wait(futures);
     await pumpEventQueue(times: 5000);
 
-    _assertLogContents(messageScheduler, r'''
+    _assertLogContents(testView!, r'''
 Incoming RequestMessage: initialize
 Entering process messages loop
   Start LspMessage: initialize
@@ -245,7 +246,7 @@ Exit process messages loop
     await initialize();
     await initialAnalysis;
     await pumpEventQueue(times: 5000);
-    _assertLogContents(messageScheduler, r'''
+    _assertLogContents(testView!, r'''
 Incoming RequestMessage: initialize
 Entering process messages loop
   Start LspMessage: initialize
@@ -275,7 +276,7 @@ void main() {
     await Future.wait(futures);
     await pumpEventQueue(times: 5000);
 
-    _assertLogContents(messageScheduler, r'''
+    _assertLogContents(testView!, r'''
 Incoming RequestMessage: initialize
 Entering process messages loop
   Start LspMessage: initialize
@@ -326,7 +327,7 @@ void f() {
     await executeCommand(codeAction.command!);
     await pumpEventQueue(times: 5000);
 
-    _assertLogContents(messageScheduler, r'''
+    _assertLogContents(testView!, r'''
 Incoming RequestMessage: initialize
 Entering process messages loop
   Start LspMessage: initialize
diff --git a/pkg/analysis_server/test/integration/server/test_all.dart b/pkg/analysis_server/test/integration/server/test_all.dart
diff --git a/pkg/analysis_server/test/lsp/server_abstract.dart b/pkg/analysis_server/test/lsp/server_abstract.dart
diff --git a/pkg/analysis_server/test/utils/message_scheduler_test_view.dart b/pkg/analysis_server/test/utils/message_scheduler_test_view.dart
