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 <brianwilkerson@google.com>
Reviewed-by: Phil Quitslund <pquitslund@google.com>
This commit is contained in:
Brian Wilkerson
2025-04-10 16:18:39 -07:00
committed by Commit Queue
parent 147c919973
commit d85ab6df0c
9 changed files with 135 additions and 69 deletions
@@ -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.
@@ -392,7 +392,7 @@ class LegacyAnalysisServer extends AnalysisServer {
super.dartFixPromptManager,
super.providedByteStore,
super.pluginManager,
super.retainDataForTesting,
super.messageSchedulerListener,
}) : lspClientConfiguration = lsp.LspClientConfiguration(
baseResourceProvider.pathContext,
),
@@ -162,7 +162,7 @@ class LspAnalysisServer extends AnalysisServer {
this.detachableFileSystemManager,
super.enableBlazeWatcher,
super.dartFixPromptManager,
super.retainDataForTesting,
super.messageSchedulerListener,
}) : lspClientConfiguration = LspClientConfiguration(
baseResourceProvider.pathContext,
),
@@ -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<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,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<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();
}
@@ -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);
@@ -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
@@ -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');
@@ -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();
@@ -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<String> messageLog = <String>[];
@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');
}
}