Skip to content
This repository has been archived by the owner on Apr 14, 2022. It is now read-only.

Better progress reporting #96

Merged
merged 7 commits into from
Sep 17, 2018
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions src/LanguageServer/Impl/Definitions/ILogger.cs
Original file line number Diff line number Diff line change
Expand Up @@ -19,5 +19,6 @@
namespace Microsoft.Python.LanguageServer {
public interface ILogger {
void TraceMessage(IFormattable message);
void TraceMessage(string message);
Copy link
Contributor

@AlexanderSher AlexanderSher Sep 14, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This has an issue of creating strings (lots of strings) even when logging is switched off or doesn't meet the required severity. It creates noticeable performance impact. If we need to get formatted strings from resources and can't use IFormattable, we can add TraceMessageFormat(string format, params object[] parameters) and do formatting only when logging is enabled.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OK

}
}
85 changes: 85 additions & 0 deletions src/LanguageServer/Impl/Implementation/AnalysisProgressReporter.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,85 @@
// Python Tools for Visual Studio
// Copyright(c) Microsoft Corporation
// All rights reserved.
//
// Licensed under the Apache License, Version 2.0 (the License); you may not use
// this file except in compliance with the License. You may obtain a copy of the
// License at http://www.apache.org/licenses/LICENSE-2.0
//
// THIS CODE IS PROVIDED ON AN *AS IS* BASIS, WITHOUT WARRANTIES OR CONDITIONS
// OF ANY KIND, EITHER EXPRESS OR IMPLIED, INCLUDING WITHOUT LIMITATION ANY
// IMPLIED WARRANTIES OR CONDITIONS OF TITLE, FITNESS FOR A PARTICULAR PURPOSE,
// MERCHANTABLITY OR NON-INFRINGEMENT.
//
// See the Apache Version 2.0 License for specific language governing
// permissions and limitations under the License.

using System;
using System.Collections.Generic;
using Microsoft.PythonTools.Analysis.Infrastructure;

namespace Microsoft.Python.LanguageServer.Implementation {
sealed class AnalysisProgressReporter : IDisposable {
private readonly DisposableBag _disposables = new DisposableBag(nameof(AnalysisProgressReporter));
private readonly Dictionary<Uri, int> _activeAnalysis = new Dictionary<Uri, int>();
private readonly IProgressService _progressService;
private readonly ILogger _logger;
private readonly Server _server;
private readonly object _lock = new object();
private IProgress _progress;

public AnalysisProgressReporter(Server server, IProgressService progressService, ILogger logger) {
_progressService = progressService;
_logger = logger;

_server = server;
_server.OnAnalysisQueued += OnAnalysisQueued;
_server.OnAnalysisComplete += OnAnalysisComplete;
_disposables
.Add(() => _server.OnAnalysisQueued -= OnAnalysisQueued)
.Add(() => _server.OnAnalysisComplete -= OnAnalysisComplete)
.Add(() => _progress?.Dispose());
}

public void Dispose() {
_disposables.TryDispose();
}

private void OnAnalysisQueued(object sender, AnalysisQueuedEventArgs e) {
lock (_lock) {
if (_activeAnalysis.ContainsKey(e.uri)) {
_activeAnalysis[e.uri]++;
} else {
_activeAnalysis[e.uri] = 1;
}
UpdateProgressMessage();
}
}
private void OnAnalysisComplete(object sender, AnalysisCompleteEventArgs e) {
lock (_lock) {
if (_activeAnalysis.TryGetValue(e.uri, out var count)) {
if (count > 1) {
_activeAnalysis[e.uri]--;
Copy link
Contributor

@AlexanderSher AlexanderSher Sep 14, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

PythonAnalyzer.AnalyzeQueuedEntries may exit before raising OnAnalysisComplete. While this one may happen only when server is disposed, I'm not sure these events (OnAnalysisQueued and OnAnalysisComplete) are actually guaranteed to be raised in pairs.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Interesting. This may explain stale messages in the status bar. I will check it out.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OK then, back to monitoring queue. The important part is to make sure we do NOT display progress when nothing is being analyzed.

} else {
_activeAnalysis.Remove(e.uri);
}
} else {
_logger.TraceMessage($"Analysis completed for {e.uri} that is not in the dictionary.");
}
UpdateProgressMessage();
}
}

private void UpdateProgressMessage() {
if(_activeAnalysis.Count > 0) {
_progress = _progress ?? _progressService.BeginProgress();
_progress.Report(_activeAnalysis.Count == 1
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So this is more like a status message rather than a progress, cause _activeAnalysis.Count may actually go up, correct?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah. This is how progresss is reported in VSC - via spinner and message in the status bar. I am not 100% about count but since analysis is recursive and event may fire from threads, I better be safe

? Resources.AnalysisProgress_SingleItemRemaining
: Resources.AnalysisProgress_MultipleItemsRemaining.FormatInvariant(_activeAnalysis.Count)).DoNotWait();
} else {
_progress?.Dispose();
_progress = null;
}
}
}
}
7 changes: 5 additions & 2 deletions src/LanguageServer/Impl/Implementation/Server.cs
Original file line number Diff line number Diff line change
Expand Up @@ -123,11 +123,14 @@ private void Analysis_UnhandledException(object sender, UnhandledExceptionEventA

public void Dispose() => _disposableBag.TryDispose();

public void TraceMessage(IFormattable message) {
#region ILogger
public void TraceMessage(IFormattable message) => TraceMessage(message.ToString());
public void TraceMessage(string message) {
if (_traceLogging) {
LogMessage(MessageType.Log, message.ToString());
LogMessage(MessageType.Log, message);
}
}
#endregion

#region Client message handling
internal InitializeResult GetInitializeResult() => new InitializeResult {
Expand Down
41 changes: 7 additions & 34 deletions src/LanguageServer/Impl/LanguageServer.cs
Original file line number Diff line number Diff line change
Expand Up @@ -43,31 +43,30 @@ public sealed partial class LanguageServer: IDisposable {
private IServiceContainer _services;
private IUIService _ui;
private ITelemetryService _telemetry;
private IProgressService _progress;

private JsonRpc _rpc;
private bool _filesLoaded;
private Task _progressReportingTask;
private PathsWatcher _pathsWatcher;
private IdleTimeTracker _idleTimeTracker;
private AnalysisProgressReporter _analysisProgressReporter;

public CancellationToken Start(IServiceContainer services, JsonRpc rpc) {
_services = services;
_ui = services.GetService<IUIService>();
_telemetry = services.GetService<ITelemetryService>();
_progress = services.GetService<IProgressService>();

_rpc = rpc;

var progress = services.GetService<IProgressService>();
_analysisProgressReporter = new AnalysisProgressReporter(_server, progress, _server);

_server.OnLogMessage += OnLogMessage;
_server.OnShowMessage += OnShowMessage;
_server.OnTelemetry += OnTelemetry;
_server.OnPublishDiagnostics += OnPublishDiagnostics;
_server.OnApplyWorkspaceEdit += OnApplyWorkspaceEdit;
_server.OnRegisterCapability += OnRegisterCapability;
_server.OnUnregisterCapability += OnUnregisterCapability;
_server.OnAnalysisQueued += OnAnalysisQueued;
_server.OnAnalysisComplete += OnAnalysisComplete;

_disposables
.Add(() => _server.OnLogMessage -= OnLogMessage)
Expand All @@ -77,40 +76,14 @@ public CancellationToken Start(IServiceContainer services, JsonRpc rpc) {
.Add(() => _server.OnApplyWorkspaceEdit -= OnApplyWorkspaceEdit)
.Add(() => _server.OnRegisterCapability -= OnRegisterCapability)
.Add(() => _server.OnUnregisterCapability -= OnUnregisterCapability)
.Add(() => _server.OnAnalysisQueued -= OnAnalysisQueued)
.Add(() => _server.OnAnalysisComplete -= OnAnalysisComplete)
.Add(_prioritizer);
.Add(_prioritizer)
.Add(_analysisProgressReporter)
.Add(() => _pathsWatcher?.Dispose());

return _sessionTokenSource.Token;
}

private void OnAnalysisQueued(object sender, AnalysisQueuedEventArgs e) => HandleAnalysisQueueEvent();
private void OnAnalysisComplete(object sender, AnalysisCompleteEventArgs e) => HandleAnalysisQueueEvent();

private void HandleAnalysisQueueEvent()
=> _progressReportingTask = _progressReportingTask ?? ProgressWorker();

private async Task ProgressWorker() {
await Task.Delay(1000);

var remaining = _server.EstimateRemainingWork();
if (remaining > 0) {
using (var p = _progress.BeginProgress()) {
while (remaining > 0) {
var items = remaining > 1 ? "items" : "item";
// TODO: in localization this needs to be two different messages
// since not all languages allow sentence construction.
await p.Report($"Analyzing workspace, {remaining} {items} remaining...");
await Task.Delay(100);
remaining = _server.EstimateRemainingWork();
}
}
}
_progressReportingTask = null;
}

public void Dispose() {
_pathsWatcher?.Dispose();
_disposables.TryDispose();
_server.Dispose();
}
Expand Down
18 changes: 18 additions & 0 deletions src/LanguageServer/Impl/Resources.Designer.cs

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

6 changes: 6 additions & 0 deletions src/LanguageServer/Impl/Resources.resx
Original file line number Diff line number Diff line change
Expand Up @@ -117,6 +117,12 @@
<resheader name="writer">
<value>System.Resources.ResXResourceWriter, System.Windows.Forms, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089</value>
</resheader>
<data name="AnalysisProgress_MultipleItemsRemaining" xml:space="preserve">
Copy link
Contributor

@AlexanderSher AlexanderSher Sep 14, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If those strings go directly to the client, how do we choose the culture?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is to be determined.... Unfortunately, LSP does not specify locale, so we'll have to add some custom notification. Which reminds me to file #98

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can't we have those strings on VSC side and provide only numbers?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

VSC is not the only client. LSP is public and supported by Eclipse, Vim, Emacs and more. So there is actually a plan to try LS with one of those.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, but isn't this part of the LS protocol is python specific and we will have to add something to the client-side anyway?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Something like python/setLocale. If client doesn't send it, we'll just use English. Also, clients typically expect string in exceptions which they display in UI. We throw with descriptive message when we cannot rename, for example.

<value>Analyzing workspace, {0} items remaining...</value>
</data>
<data name="AnalysisProgress_SingleItemRemaining" xml:space="preserve">
<value>Analyzing workspace, 1 item remaining...</value>
</data>
<data name="RenameVariable_CannotRename" xml:space="preserve">
<value>Cannot rename</value>
</data>
Expand Down
3 changes: 2 additions & 1 deletion src/LanguageServer/Impl/Services/UIService.cs
Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,8 @@ public Task LogMessage(string message, MessageType messageType) {
public Task SetStatusBarMessage(string message)
=> _rpc.NotifyWithParameterObjectAsync("window/setStatusBarMessage", message);

public void TraceMessage(IFormattable message) => LogMessage(message.ToString(), MessageType.Info);
public void TraceMessage(string message) => LogMessage(message.ToString(), MessageType.Info);
public void TraceMessage(IFormattable message) => TraceMessage(message.ToString());

public void SetLogLevel(MessageType logLevel) => _logLevel = logLevel;
}
Expand Down