From d85ab6df0c2bee36c8ea843ef5d7329b5780b7b8 Mon Sep 17 00:00:00 2001 From: Brian Wilkerson Date: Thu, 10 Apr 2025 16:18:39 -0700 Subject: [PATCH] Refactor the MessageSchedulerTestView for more flexibility 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 Reviewed-by: Phil Quitslund --- .../lib/src/analysis_server.dart | 6 +- .../lib/src/legacy_analysis_server.dart | 2 +- .../lib/src/lsp/lsp_analysis_server.dart | 2 +- .../lib/src/scheduler/message_scheduler.dart | 98 ++++++++++--------- .../test/analysis_server_base.dart | 5 +- .../server/message_scheduler_test.dart | 19 ++-- .../test/integration/server/test_all.dart | 6 +- .../test/lsp/server_abstract.dart | 7 +- .../utils/message_scheduler_test_view.dart | 59 +++++++++++ 9 files changed, 135 insertions(+), 69 deletions(-) create mode 100644 pkg/analysis_server/test/utils/message_scheduler_test_view.dart diff --git a/pkg/analysis_server/lib/src/analysis_server.dart b/pkg/analysis_server/lib/src/analysis_server.dart index 3aac09cde78..8b394c3c18a 100644 --- 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 index 2d089182ea2..3b49fe27692 100644 --- 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 index 3090b17ea9f..cbfab393010 100644 --- 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 index 08a309efa8e..47ca80fc002 100644 --- a/pkg/analysis_server/lib/src/scheduler/message_scheduler.dart +++ b/pkg/analysis_server/lib/src/scheduler/message_scheduler.dart @@ -23,7 +23,7 @@ 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. @@ -31,7 +31,7 @@ final class MessageScheduler { /// 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(); 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,9 +436,9 @@ 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); } } } @@ -451,27 +446,34 @@ final class MessageScheduler { 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 messageLog = []; + /// 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 index 6b7276ea149..6561561a3d0 100644 --- 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 index b32ac19bcb8..7dcc12bab87 100644 --- 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 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 index ea0a87edc0c..b8c95d05dc2 100644 --- a/pkg/analysis_server/test/integration/server/test_all.dart +++ b/pkg/analysis_server/test/integration/server/test_all.dart @@ -7,7 +7,7 @@ import 'package:test_reflective_loader/test_reflective_loader.dart'; import 'blaze_changes_test.dart' as blaze_changes_test; import 'command_line_options_test.dart' as command_line_options_test; import 'get_version_test.dart' as get_version_test; -import 'message_scheduler_test.dart' as scheduler_test; +import 'message_scheduler_test.dart' as message_scheduler_test; import 'set_subscriptions_invalid_service_test.dart' as set_subscriptions_invalid_service_test; import 'set_subscriptions_test.dart' as set_subscriptions_test; @@ -19,9 +19,9 @@ void main() { blaze_changes_test.main(); command_line_options_test.main(); get_version_test.main(); - scheduler_test.main(); - set_subscriptions_test.main(); + message_scheduler_test.main(); set_subscriptions_invalid_service_test.main(); + set_subscriptions_test.main(); shutdown_test.main(); status_test.main(); }, name: 'server'); diff --git a/pkg/analysis_server/test/lsp/server_abstract.dart b/pkg/analysis_server/test/lsp/server_abstract.dart index 888459d0bcc..4004b4c87e1 100644 --- a/pkg/analysis_server/test/lsp/server_abstract.dart +++ b/pkg/analysis_server/test/lsp/server_abstract.dart @@ -37,6 +37,7 @@ import '../mocks.dart'; import '../mocks_lsp.dart'; import '../shared/shared_test_interface.dart'; import '../support/configuration_files.dart'; +import '../utils/message_scheduler_test_view.dart'; import 'change_verifier.dart'; import 'request_helpers_mixin.dart'; @@ -55,6 +56,7 @@ abstract class AbstractLspAnalysisServerTest late MockLspServerChannel channel; late ErrorNotifier errorNotifier; late TestPluginManager pluginManager; + MessageSchedulerTestView? testView; late LspAnalysisServer server; late MockProcessRunner processRunner; late MockHttpClient httpClient; @@ -279,6 +281,7 @@ abstract class AbstractLspAnalysisServerTest errorNotifier = ErrorNotifier(); pluginManager = TestPluginManager(); + testView = retainDataForTesting ? MessageSchedulerTestView() : null; server = LspAnalysisServer( channel, resourceProvider, @@ -290,7 +293,7 @@ abstract class AbstractLspAnalysisServerTest httpClient: httpClient, processRunner: processRunner, dartFixPromptManager: dartFixPromptManager, - retainDataForTesting: retainDataForTesting, + messageSchedulerListener: testView, ); errorNotifier.server = server; server.pluginManager = pluginManager; @@ -314,7 +317,7 @@ abstract class AbstractLspAnalysisServerTest newFile(analysisOptionsPath, ''' analyzer: enable-experiment: -$experiments +$experiments '''); writeTestPackageConfig(); diff --git a/pkg/analysis_server/test/utils/message_scheduler_test_view.dart b/pkg/analysis_server/test/utils/message_scheduler_test_view.dart new file mode 100644 index 00000000000..4bc8b012155 --- /dev/null +++ b/pkg/analysis_server/test/utils/message_scheduler_test_view.dart @@ -0,0 +1,59 @@ +// Copyright (c) 2025, the Dart project authors. Please see the AUTHORS file +// for details. All rights reserved. Use of this source code is governed by a +// BSD-style license that can be found in the LICENSE file. + +import 'package:analysis_server/lsp_protocol/protocol.dart' as lsp; +import 'package:analysis_server/src/scheduler/message_scheduler.dart'; +import 'package:analysis_server/src/scheduler/scheduled_message.dart'; + +class MessageSchedulerTestView implements MessageSchedulerListener { + List messageLog = []; + + @override + void addActiveMessage(ScheduledMessage message) { + messageLog.add(' Start ${message.runtimeType}: ${message.toString()}'); + } + + @override + void addPendingMessage(ScheduledMessage message) { + var messageType = + message is LspMessage + ? message.message.runtimeType + : message.runtimeType; + messageLog.add('Incoming $messageType: ${message.toString()}'); + } + + @override + void cancelActiveMessage(ScheduledMessage message) { + _cancelMessage(message, 'active'); + } + + @override + void cancelPendingMessage(ScheduledMessage message) { + _cancelMessage(message, 'pending'); + } + + @override + void endProcessingMessages() { + messageLog.add('Exit process messages loop'); + } + + @override + void messageCompleted(ScheduledMessage message) { + messageLog.add(' Complete ${message.runtimeType}: ${message.toString()}'); + } + + @override + void startProcessingMessages() { + messageLog.add('Entering process messages loop'); + } + + void _cancelMessage(ScheduledMessage message, String kind) { + var method = switch (message) { + LegacyMessage() => message.request.method, + LspMessage(message: lsp.RequestMessage lspMessage) => lspMessage.method, + _ => 'Unknown message of type ${message.runtimeType}', + }; + messageLog.add('Canceled $kind request $method'); + } +}